-- Logs begin at Wed 2024-10-30 15:59:08 CET, end at Wed 2024-10-30 16:02:46 CET. -- Oct 30 16:01:01 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPause Oct 30 16:01:01 volumio-rivo volumio[3134]: info: CoreStateMachine::pause Oct 30 16:01:01 volumio-rivo volumio[3134]: info: CoreStateMachine::stPlaybackTimer Oct 30 16:01:01 volumio-rivo volumio[3134]: info: CoreStateMachine::servicePause Oct 30 16:01:01 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:01 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePause Oct 30 16:01:01 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand pause Oct 30 16:01:01 volumio-rivo volumio[3134]: info: sendMpdCommand pause took 3 milliseconds Oct 30 16:01:01 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:01 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:01:01 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:01 volumio-rivo volumio[3134]: verbose: STATE SERVICE {"status":"pause","service":"radio_paradise","type":"webradio","trackType":"flac","radioType":"rparadise","albumart":"https://img.radioparadise.com/covers/l/B01J1TDXVI.jpg","uri":"https://stream.radioparadise.com/world-etc-flac","name":"Zorba the Greek","title":"Zorba the Greek","artist":"Herb Alpert & the Tijuana Brass","album":"!!Going Places!!","streaming":true,"disableUiControls":true,"duration":258,"seek":2901,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Oct 30 16:01:01 volumio-rivo volumio[3134]: verbose: CURRENT POSITION 0 Oct 30 16:01:01 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState stateService pause Oct 30 16:01:01 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState currentStatus pause Oct 30 16:01:01 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:01:01 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:01 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 30 16:01:01 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:01:01 volumio-rivo volumio[3134]: info: CoreStateMachine::stPlaybackTimer Oct 30 16:01:01 volumio-rivo volumio[3134]: info: Oct 30 16:01:01 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:01:01 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:01:01 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:01:01 volumio-rivo volumio[3134]: info: Oct 30 16:01:01 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:01:01 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:01:01 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:01:01 volumio-rivo volumio[3134]: info: Oct 30 16:01:01 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:01:01 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:01:01 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:01:01 volumio-rivo volumio[3134]: info: Oct 30 16:01:01 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:01:01 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:01:01 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:01:01 volumio-rivo volumio[3134]: info: sendMpdCommand status took 16 milliseconds Oct 30 16:01:01 volumio-rivo volumio[3134]: info: sendMpdCommand status took 13 milliseconds Oct 30 16:01:01 volumio-rivo volumio[3134]: info: sendMpdCommand status took 11 milliseconds Oct 30 16:01:01 volumio-rivo volumio[3134]: info: sendMpdCommand status took 9 milliseconds Oct 30 16:01:01 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:01:01 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:01:01 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:01:01 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:01:01 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:01:01 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:01:01 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:01:01 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:01:01 volumio-rivo volumio[3134]: info: sendMpdCommand playlistinfo took 6 milliseconds Oct 30 16:01:01 volumio-rivo volumio[3134]: info: sendMpdCommand playlistinfo took 6 milliseconds Oct 30 16:01:01 volumio-rivo volumio[3134]: info: sendMpdCommand playlistinfo took 7 milliseconds Oct 30 16:01:01 volumio-rivo volumio[3134]: info: sendMpdCommand playlistinfo took 6 milliseconds Oct 30 16:01:01 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseTrackInfo Oct 30 16:01:01 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseTrackInfo Oct 30 16:01:01 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseTrackInfo Oct 30 16:01:01 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseTrackInfo Oct 30 16:01:01 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:01:01 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:01:01 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:01 volumio-rivo volumio[3134]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 30 16:01:01 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:01:01 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:01:01 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:01 volumio-rivo volumio[3134]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 30 16:01:01 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:01:01 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:01:01 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:01 volumio-rivo volumio[3134]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 30 16:01:01 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:01:01 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:01:01 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:01 volumio-rivo volumio[3134]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 30 16:01:01 volumio-rivo volumio[3134]: info: ------------------------------ 37ms Oct 30 16:01:01 volumio-rivo volumio[3134]: info: ------------------------------ 34ms Oct 30 16:01:01 volumio-rivo volumio[3134]: info: ------------------------------ 33ms Oct 30 16:01:01 volumio-rivo volumio[3134]: info: ------------------------------ 30ms Oct 30 16:01:02 volumio-rivo volumio[3134]: info: camilladsp spawned new process with pid 3795, instance 1, run: true Oct 30 16:01:05 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Oct 30 16:01:05 volumio-rivo volumio[3134]: info: handleBrowseUri took 83 milliseconds Oct 30 16:01:06 volumio-rivo volumio[3134]: info: Preload queue cleared Oct 30 16:01:06 volumio-rivo volumio[3134]: info: Preload queue cleared Oct 30 16:01:12 volumio-rivo volumiologrotate[2870]: ls: cannot access '/var/log/samba/log.wb-VOLUMIO': No such file or directory Oct 30 16:01:12 volumio-rivo volumiologrotate[2870]: ls: cannot access 'RIVO': No such file or directory Oct 30 16:01:13 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Oct 30 16:01:15 volumio-rivo volumio[3134]: info: handleBrowseUri took 1698 milliseconds Oct 30 16:01:15 volumio-rivo volumio[3134]: info: Preload queue cleared Oct 30 16:01:26 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Oct 30 16:01:26 volumio-rivo volumio[3134]: info: handleBrowseUri took 646 milliseconds Oct 30 16:01:26 volumio-rivo volumio[3134]: info: Preload queue cleared Oct 30 16:01:26 volumio-rivo volumio[3134]: info: Preloading song: qobuz://song/283027761 Oct 30 16:01:26 volumio-rivo volumio[3134]: info: Preloading song: qobuz://song/283027762 Oct 30 16:01:26 volumio-rivo volumio[3134]: info: Preloading song: qobuz://song/283027763 Oct 30 16:01:26 volumio-rivo volumio[3134]: info: Preloading song: qobuz://song/283027764 Oct 30 16:01:26 volumio-rivo volumio[3134]: info: Preloading song: qobuz://song/283027765 Oct 30 16:01:26 volumio-rivo volumio[3134]: info: Preloading song: qobuz://song/283027766 Oct 30 16:01:26 volumio-rivo volumio[3134]: info: Preloading song: qobuz://song/283027767 Oct 30 16:01:26 volumio-rivo volumio[3134]: info: Preloading song: qobuz://song/283027768 Oct 30 16:01:26 volumio-rivo volumio[3134]: info: Preloading song: qobuz://song/283027769 Oct 30 16:01:26 volumio-rivo volumio[3134]: info: Preloading song: qobuz://song/283027770 Oct 30 16:01:26 volumio-rivo volumio[3134]: info: Preloading song: qobuz://song/283027771 Oct 30 16:01:26 volumio-rivo volumio[3134]: info: Preloading song: qobuz://song/283027772 Oct 30 16:01:26 volumio-rivo volumio[3134]: info: Preloading song: qobuz://song/283027773 Oct 30 16:01:26 volumio-rivo volumio[3134]: info: Preloading song: qobuz://song/283027774 Oct 30 16:01:26 volumio-rivo volumio[3134]: info: Preloading song: qobuz://song/283027775 Oct 30 16:01:26 volumio-rivo volumio[3134]: info: Exploding uri qobuz://song/283027761 in service qobuz Oct 30 16:01:26 volumio-rivo volumio[3134]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 30 16:01:26 volumio-rivo volumio[3134]: info: Exploding uri qobuz://song/283027762 in service qobuz Oct 30 16:01:26 volumio-rivo volumio[3134]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 30 16:01:27 volumio-rivo volumio[3134]: info: Exploding uri qobuz://song/283027763 in service qobuz Oct 30 16:01:27 volumio-rivo volumio[3134]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 30 16:01:27 volumio-rivo volumio[3134]: info: Exploding uri qobuz://song/283027764 in service qobuz Oct 30 16:01:27 volumio-rivo volumio[3134]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 30 16:01:27 volumio-rivo volumio[3134]: info: Exploding uri qobuz://song/283027765 in service qobuz Oct 30 16:01:27 volumio-rivo volumio[3134]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 30 16:01:27 volumio-rivo volumio[3134]: info: Exploding uri qobuz://song/283027766 in service qobuz Oct 30 16:01:27 volumio-rivo volumio[3134]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 30 16:01:27 volumio-rivo volumio[3134]: info: Exploding uri qobuz://song/283027767 in service qobuz Oct 30 16:01:27 volumio-rivo volumio[3134]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 30 16:01:27 volumio-rivo volumio[3134]: info: Exploding uri qobuz://song/283027768 in service qobuz Oct 30 16:01:27 volumio-rivo volumio[3134]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 30 16:01:27 volumio-rivo volumio[3134]: info: Exploding uri qobuz://song/283027769 in service qobuz Oct 30 16:01:27 volumio-rivo volumio[3134]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 30 16:01:27 volumio-rivo volumio[3134]: info: Exploding uri qobuz://song/283027770 in service qobuz Oct 30 16:01:27 volumio-rivo volumio[3134]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 30 16:01:27 volumio-rivo volumio[3134]: info: Exploding uri qobuz://song/283027771 in service qobuz Oct 30 16:01:27 volumio-rivo volumio[3134]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 30 16:01:27 volumio-rivo volumio[3134]: info: explodeUri took 495 milliseconds Oct 30 16:01:27 volumio-rivo volumio[3134]: info: Exploding uri qobuz://song/283027772 in service qobuz Oct 30 16:01:27 volumio-rivo volumio[3134]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 30 16:01:27 volumio-rivo volumio[3134]: info: Exploding uri qobuz://song/283027773 in service qobuz Oct 30 16:01:27 volumio-rivo volumio[3134]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 30 16:01:27 volumio-rivo volumio[3134]: info: explodeUri took 452 milliseconds Oct 30 16:01:27 volumio-rivo volumio[3134]: info: Exploding uri qobuz://song/283027774 in service qobuz Oct 30 16:01:27 volumio-rivo volumio[3134]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 30 16:01:27 volumio-rivo volumio[3134]: info: Exploding uri qobuz://song/283027775 in service qobuz Oct 30 16:01:27 volumio-rivo volumio[3134]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 30 16:01:27 volumio-rivo volumio[3134]: info: explodeUri took 715 milliseconds Oct 30 16:01:27 volumio-rivo volumio[3134]: info: explodeUri took 687 milliseconds Oct 30 16:01:27 volumio-rivo volumio[3134]: info: explodeUri took 555 milliseconds Oct 30 16:01:27 volumio-rivo volumio[3134]: info: explodeUri took 471 milliseconds Oct 30 16:01:27 volumio-rivo volumio[3134]: info: explodeUri took 705 milliseconds Oct 30 16:01:27 volumio-rivo volumio[3134]: info: explodeUri took 624 milliseconds Oct 30 16:01:27 volumio-rivo volumio[3134]: info: explodeUri took 526 milliseconds Oct 30 16:01:27 volumio-rivo volumio[3134]: info: explodeUri took 491 milliseconds Oct 30 16:01:27 volumio-rivo volumio[3134]: info: Executing endpoint getSimilarAlbums Oct 30 16:01:27 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Oct 30 16:01:27 volumio-rivo volumio[3134]: info: Executing endpoint metavolumio Oct 30 16:01:27 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 30 16:01:27 volumio-rivo volumio[3134]: info: Executing endpoint metavolumio Oct 30 16:01:27 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 30 16:01:27 volumio-rivo volumio[3134]: info: Executing endpoint metavolumio Oct 30 16:01:27 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 30 16:01:27 volumio-rivo volumio[3134]: info: Executing endpoint metavolumio Oct 30 16:01:27 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 30 16:01:27 volumio-rivo volumio[3134]: info: Executing endpoint getSimilarAlbums Oct 30 16:01:27 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Oct 30 16:01:27 volumio-rivo volumio[3134]: info: explodeUri took 535 milliseconds Oct 30 16:01:28 volumio-rivo volumio[3134]: info: explodeUri took 557 milliseconds Oct 30 16:01:28 volumio-rivo volumio[3134]: info: explodeUri took 458 milliseconds Oct 30 16:01:28 volumio-rivo volumio[3134]: info: explodeUri took 539 milliseconds Oct 30 16:01:28 volumio-rivo volumio[3134]: info: explodeUri took 464 milliseconds Oct 30 16:01:31 volumio-rivo volumio[3134]: info: Preload queue cleared Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreStateMachine::ClearQueue Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreStateMachine::stop Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreStateMachine::updateTrackBlock Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrackBlock Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreStateMachine::stPlaybackTimer Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreStateMachine::serviceStop Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreCommandRouter::serviceStop Oct 30 16:01:31 volumio-rivo volumio[3134]: info: ControllerMpd::stop Oct 30 16:01:31 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand stop Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CorePlayQueue::clearPlayQueue Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CorePlayQueue::saveQueue Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushQueue Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreStateMachine::addQueueItems Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CorePlayQueue::addQueueItems Oct 30 16:01:31 volumio-rivo volumio[3134]: info: Preload queue cleared Oct 30 16:01:31 volumio-rivo volumio[3134]: info: Adding Item to queue: qobuz://album/wbjl275992f9a Oct 30 16:01:31 volumio-rivo volumio[3134]: info: Exploding uri qobuz://album/wbjl275992f9a in service qobuz Oct 30 16:01:31 volumio-rivo volumio[3134]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 30 16:01:31 volumio-rivo volumio[3134]: info: sendMpdCommand stop took 31 milliseconds Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:31 volumio-rivo volumio[3134]: verbose: STATE SERVICE {"status":"stop","service":"radio_paradise","type":"webradio","trackType":"flac","radioType":"rparadise","albumart":"https://img.radioparadise.com/covers/l/B01J1TDXVI.jpg","uri":"https://stream.radioparadise.com/world-etc-flac","name":"Zorba the Greek","title":"Zorba the Greek","artist":"Herb Alpert & the Tijuana Brass","album":"!!Going Places!!","streaming":true,"disableUiControls":true,"duration":258,"seek":2901,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Oct 30 16:01:31 volumio-rivo volumio[3134]: verbose: CURRENT POSITION 0 Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState stateService stop Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState currentStatus stop Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: No code Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: Oct 30 16:01:31 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:01:31 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:01:31 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:01:31 volumio-rivo volumio[3134]: info: Oct 30 16:01:31 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:01:31 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:01:31 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:01:31 volumio-rivo volumio[3134]: info: Oct 30 16:01:31 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:01:31 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:01:31 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:01:31 volumio-rivo volumio[3134]: info: Oct 30 16:01:31 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:01:31 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:01:31 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:01:31 volumio-rivo volumio[3134]: info: sendMpdCommand status took 31 milliseconds Oct 30 16:01:31 volumio-rivo volumio[3134]: info: sendMpdCommand status took 29 milliseconds Oct 30 16:01:31 volumio-rivo volumio[3134]: info: sendMpdCommand status took 27 milliseconds Oct 30 16:01:31 volumio-rivo volumio[3134]: info: sendMpdCommand status took 21 milliseconds Oct 30 16:01:31 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:01:31 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:01:31 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:01:31 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:01:31 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:01:31 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:01:31 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:01:31 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:01:31 volumio-rivo volumio[3134]: info: sendMpdCommand playlistinfo took 5 milliseconds Oct 30 16:01:31 volumio-rivo volumio[3134]: info: sendMpdCommand playlistinfo took 5 milliseconds Oct 30 16:01:31 volumio-rivo volumio[3134]: info: sendMpdCommand playlistinfo took 6 milliseconds Oct 30 16:01:31 volumio-rivo volumio[3134]: info: sendMpdCommand playlistinfo took 5 milliseconds Oct 30 16:01:31 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseTrackInfo Oct 30 16:01:31 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseTrackInfo Oct 30 16:01:31 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseTrackInfo Oct 30 16:01:31 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseTrackInfo Oct 30 16:01:31 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:31 volumio-rivo volumio[3134]: 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":"world-etc-flac","artist":"Radio Paradise World-Etc Mix (flac) - playlist: radioparadise.com","album":null,"uri":"https://stream.radioparadise.com/world-etc-flac","trackType":""} Oct 30 16:01:31 volumio-rivo volumio[3134]: verbose: CURRENT POSITION 0 Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState stateService stop Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState currentStatus stop Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: No code Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:31 volumio-rivo volumio[3134]: 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":"world-etc-flac","artist":"Radio Paradise World-Etc Mix (flac) - playlist: radioparadise.com","album":null,"uri":"https://stream.radioparadise.com/world-etc-flac","trackType":""} Oct 30 16:01:31 volumio-rivo volumio[3134]: verbose: CURRENT POSITION 0 Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState stateService stop Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState currentStatus stop Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: No code Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:31 volumio-rivo volumio[3134]: 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":"world-etc-flac","artist":"Radio Paradise World-Etc Mix (flac) - playlist: radioparadise.com","album":null,"uri":"https://stream.radioparadise.com/world-etc-flac","trackType":""} Oct 30 16:01:31 volumio-rivo volumio[3134]: verbose: CURRENT POSITION 0 Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState stateService stop Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState currentStatus stop Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: No code Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:31 volumio-rivo volumio[3134]: 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":"world-etc-flac","artist":"Radio Paradise World-Etc Mix (flac) - playlist: radioparadise.com","album":null,"uri":"https://stream.radioparadise.com/world-etc-flac","trackType":""} Oct 30 16:01:31 volumio-rivo volumio[3134]: verbose: CURRENT POSITION 0 Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState stateService stop Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState currentStatus stop Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: No code Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:31 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:01:31 volumio-rivo volumio[3134]: info: ------------------------------ 133ms Oct 30 16:01:31 volumio-rivo volumio[3134]: info: ------------------------------ 131ms Oct 30 16:01:31 volumio-rivo volumio[3134]: info: ------------------------------ 130ms Oct 30 16:01:31 volumio-rivo volumio[3134]: info: ------------------------------ 129ms Oct 30 16:01:32 volumio-rivo volumio[3134]: info: explodeUri took 645 milliseconds Oct 30 16:01:32 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushQueue Oct 30 16:01:32 volumio-rivo volumio[3134]: info: CorePlayQueue::saveQueue Oct 30 16:01:32 volumio-rivo volumio[3134]: info: CoreStateMachine::updateTrackBlock Oct 30 16:01:32 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrackBlock Oct 30 16:01:32 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPlay Oct 30 16:01:32 volumio-rivo volumio[3134]: info: CoreStateMachine::play index 0 Oct 30 16:01:32 volumio-rivo volumio[3134]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 30 16:01:32 volumio-rivo volumio[3134]: info: CoreStateMachine::stop Oct 30 16:01:32 volumio-rivo volumio[3134]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 30 16:01:32 volumio-rivo volumio[3134]: info: CoreStateMachine::play index undefined Oct 30 16:01:32 volumio-rivo volumio[3134]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 30 16:01:32 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:32 volumio-rivo volumio[3134]: info: CoreStateMachine::startPlaybackTimer Oct 30 16:01:32 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:32 volumio-rivo volumio[3134]: info: [1730300492115] ControllerQobuz::clearAddPlayTrack Oct 30 16:01:32 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand stop Oct 30 16:01:32 volumio-rivo volumio[3134]: info: sendMpdCommand stop took 7 milliseconds Oct 30 16:01:32 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand clear Oct 30 16:01:32 volumio-rivo volumio[3134]: info: Oct 30 16:01:32 volumio-rivo volumio[3134]: ---------------------------- MPD announces system playlist update Oct 30 16:01:32 volumio-rivo volumio[3134]: info: Ignoring MPD Status Update Oct 30 16:01:32 volumio-rivo volumio[3134]: info: sendMpdCommand clear took 2 milliseconds Oct 30 16:01:32 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/283027761" Oct 30 16:01:32 volumio-rivo volumio[3134]: info: Oct 30 16:01:32 volumio-rivo volumio[3134]: ---------------------------- MPD announces system playlist update Oct 30 16:01:32 volumio-rivo volumio[3134]: info: Ignoring MPD Status Update Oct 30 16:01:32 volumio-rivo volumio[3134]: info: Oct 30 16:01:32 volumio-rivo volumio[3134]: ---------------------------- MPD announces system playlist update Oct 30 16:01:32 volumio-rivo volumio[3134]: info: Ignoring MPD Status Update Oct 30 16:01:32 volumio-rivo volumio[3134]: info: Oct 30 16:01:32 volumio-rivo volumio[3134]: ---------------------------- MPD announces system playlist update Oct 30 16:01:32 volumio-rivo volumio[3134]: info: Ignoring MPD Status Update Oct 30 16:01:32 volumio-rivo volumio[3134]: error: updateQueue error: null Oct 30 16:01:32 volumio-rivo volumio[3134]: info: ------------------------------ 14ms Oct 30 16:01:32 volumio-rivo volumio[3134]: STREAMING PROXY: Handling url /?data=qobuz://song/283027761 Oct 30 16:01:32 volumio-rivo volumio[3134]: info: Executing endpoint getStreamUrlqobuz Oct 30 16:01:32 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 30 16:01:32 volumio-rivo volumio[3134]: info: getStreamUrl took 439 milliseconds Oct 30 16:01:32 volumio-rivo volumio[3134]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=2880200&eid=283027761&fmt=7&profile=raw&app_id=539451548&cid=2033386&etsp=1730304092&hmac=i72Sd5zG-LMKDzeKrEIExH_64ew Oct 30 16:01:32 volumio-rivo volumio[3134]: STREAMING PROXY: Response: 200, length: 31097572 Oct 30 16:01:32 volumio-rivo volumio[3134]: error: updateQueue error: null Oct 30 16:01:32 volumio-rivo volumio[3134]: error: updateQueue error: null Oct 30 16:01:32 volumio-rivo volumio[3134]: error: updateQueue error: null Oct 30 16:01:32 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/283027761" Oct 30 16:01:32 volumio-rivo volumio[3134]: info: ------------------------------ 667ms Oct 30 16:01:32 volumio-rivo volumio[3134]: info: ------------------------------ 665ms Oct 30 16:01:32 volumio-rivo volumio[3134]: info: ------------------------------ 664ms Oct 30 16:01:32 volumio-rivo volumio[3134]: info: Oct 30 16:01:32 volumio-rivo volumio[3134]: ---------------------------- MPD announces system playlist update Oct 30 16:01:32 volumio-rivo volumio[3134]: info: Ignoring MPD Status Update Oct 30 16:01:32 volumio-rivo volumio[3134]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/283027761" took 6 milliseconds Oct 30 16:01:32 volumio-rivo volumio[3134]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 30 16:01:32 volumio-rivo volumio[3134]: STREAMING PROXY: Client dropped request, destroying Oct 30 16:01:32 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand play Oct 30 16:01:32 volumio-rivo volumio[3134]: info: Oct 30 16:01:32 volumio-rivo volumio[3134]: ---------------------------- MPD announces system playlist update Oct 30 16:01:32 volumio-rivo volumio[3134]: info: Ignoring MPD Status Update Oct 30 16:01:32 volumio-rivo volumio[3134]: info: Oct 30 16:01:32 volumio-rivo volumio[3134]: ---------------------------- MPD announces system playlist update Oct 30 16:01:32 volumio-rivo volumio[3134]: info: Ignoring MPD Status Update Oct 30 16:01:32 volumio-rivo volumio[3134]: info: Oct 30 16:01:32 volumio-rivo volumio[3134]: ---------------------------- MPD announces system playlist update Oct 30 16:01:32 volumio-rivo volumio[3134]: STREAMING PROXY: Handling url /?data=qobuz://song/283027761 Oct 30 16:01:32 volumio-rivo volumio[3134]: info: Ignoring MPD Status Update Oct 30 16:01:32 volumio-rivo volumio[3134]: info: ------------------------------ 15ms Oct 30 16:01:32 volumio-rivo volumio[3134]: info: sendMpdCommand play took 10 milliseconds Oct 30 16:01:32 volumio-rivo volumio[3134]: info: ------------------------------ 9ms Oct 30 16:01:32 volumio-rivo volumio[3134]: info: ------------------------------ 7ms Oct 30 16:01:32 volumio-rivo volumio[3134]: info: ------------------------------ 6ms Oct 30 16:01:32 volumio-rivo volumio[3134]: info: Executing endpoint getStreamUrlqobuz Oct 30 16:01:32 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 30 16:01:33 volumio-rivo volumio[3134]: info: getStreamUrl took 566 milliseconds Oct 30 16:01:33 volumio-rivo volumio[3134]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=2880200&eid=283027761&fmt=7&profile=raw&app_id=539451548&cid=2033386&etsp=1730304093&hmac=c6Zn3akScPhd1vcuHZfyv2WZNtM Oct 30 16:01:33 volumio-rivo volumio[3134]: STREAMING PROXY: Response: 200, length: 31097572 Oct 30 16:01:33 volumio-rivo volumio[3134]: info: Oct 30 16:01:33 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:01:33 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:01:33 volumio-rivo volumio[3134]: info: Oct 30 16:01:33 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:01:33 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:01:33 volumio-rivo volumio[3134]: info: Oct 30 16:01:33 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:01:33 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:01:33 volumio-rivo volumio[3134]: info: Oct 30 16:01:33 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:01:33 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:01:33 volumio-rivo volumio[3134]: info: Oct 30 16:01:33 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:01:33 volumio-rivo volumio[3134]: info: sendMpdCommand status took 27 milliseconds Oct 30 16:01:33 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:01:33 volumio-rivo volumio[3134]: info: sendMpdCommand status took 23 milliseconds Oct 30 16:01:33 volumio-rivo volumio[3134]: info: sendMpdCommand status took 22 milliseconds Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:01:33 volumio-rivo volumio[3134]: info: Oct 30 16:01:33 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:01:33 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:01:33 volumio-rivo volumio[3134]: info: Oct 30 16:01:33 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:01:33 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:01:33 volumio-rivo volumio[3134]: info: Oct 30 16:01:33 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:01:33 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:01:33 volumio-rivo volumio[3134]: info: FusionDsp - ---- read samplerate, raw: 48000,S32_LE,2,32 Oct 30 16:01:33 volumio-rivo volumio[3134]: info: FusionDsp - ---- read samplerate from file: 48000 Oct 30 16:01:33 volumio-rivo volumio[3134]: info: camilladsp stopping service pid 3795... Oct 30 16:01:33 volumio-rivo volumio[3134]: info: camilladsp service terminated, instance 1 Oct 30 16:01:33 volumio-rivo volumio[3134]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 30 16:01:33 volumio-rivo volumio[3134]: info: FusionDsp - Nulleq applied Oct 30 16:01:33 volumio-rivo volumio[3134]: info: camilladsp service started and running in background, instance 1 Oct 30 16:01:33 volumio-rivo volumio[3134]: info: sendMpdCommand status took 87 milliseconds Oct 30 16:01:33 volumio-rivo volumio[3134]: info: sendMpdCommand status took 83 milliseconds Oct 30 16:01:33 volumio-rivo volumio[3134]: info: sendMpdCommand playlistinfo took 73 milliseconds Oct 30 16:01:33 volumio-rivo volumio[3134]: info: sendMpdCommand playlistinfo took 72 milliseconds Oct 30 16:01:33 volumio-rivo volumio[3134]: info: sendMpdCommand playlistinfo took 71 milliseconds Oct 30 16:01:33 volumio-rivo volumio[3134]: info: sendMpdCommand status took 68 milliseconds Oct 30 16:01:33 volumio-rivo volumio[3134]: info: sendMpdCommand status took 64 milliseconds Oct 30 16:01:33 volumio-rivo volumio[3134]: info: sendMpdCommand status took 61 milliseconds Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseTrackInfo Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseTrackInfo Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseTrackInfo Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:01:33 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":172,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"283027761","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/283027761","trackType":"qobuz"} Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: CURRENT POSITION 0 Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState stateService play Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState currentStatus stop Oct 30 16:01:33 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: STATE SERVICE {"status":"play","position":0,"seek":483,"duration":172,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1051 Kbps","isStreaming":false,"title":"283027761","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/283027761","trackType":"qobuz"} Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: CURRENT POSITION 0 Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState stateService play Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState currentStatus play Oct 30 16:01:33 volumio-rivo volumio[3134]: info: Received an update from plugin. extracting info from payload Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: STATE SERVICE {"status":"play","position":0,"seek":734,"duration":172,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1007 Kbps","isStreaming":false,"title":"283027761","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/283027761","trackType":"qobuz"} Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: CURRENT POSITION 0 Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState stateService play Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState currentStatus play Oct 30 16:01:33 volumio-rivo volumio[3134]: info: Received an update from plugin. extracting info from payload Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: ------------------------------ 178ms Oct 30 16:01:33 volumio-rivo volumio[3134]: info: ------------------------------ 195ms Oct 30 16:01:33 volumio-rivo volumio[3134]: info: ------------------------------ 190ms Oct 30 16:01:33 volumio-rivo volumio[3134]: info: camilladsp spawned new process with pid 3859, instance 1, run: true Oct 30 16:01:33 volumio-rivo volumio[3134]: info: sendMpdCommand playlistinfo took 146 milliseconds Oct 30 16:01:33 volumio-rivo volumio[3134]: info: sendMpdCommand playlistinfo took 145 milliseconds Oct 30 16:01:33 volumio-rivo volumio[3134]: info: sendMpdCommand playlistinfo took 140 milliseconds Oct 30 16:01:33 volumio-rivo volumio[3134]: info: sendMpdCommand playlistinfo took 141 milliseconds Oct 30 16:01:33 volumio-rivo volumio[3134]: info: sendMpdCommand playlistinfo took 143 milliseconds Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseTrackInfo Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseTrackInfo Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseTrackInfo Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseTrackInfo Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseTrackInfo Oct 30 16:01:33 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1112,"duration":172,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1039 Kbps","isStreaming":false,"title":"283027761","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/283027761","trackType":"qobuz"} Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: CURRENT POSITION 0 Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState stateService play Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState currentStatus play Oct 30 16:01:33 volumio-rivo volumio[3134]: info: Received an update from plugin. extracting info from payload Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1238,"duration":172,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1035 Kbps","isStreaming":false,"title":"283027761","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/283027761","trackType":"qobuz"} Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: CURRENT POSITION 0 Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState stateService play Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState currentStatus play Oct 30 16:01:33 volumio-rivo volumio[3134]: info: Received an update from plugin. extracting info from payload Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1354,"duration":172,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"978 Kbps","isStreaming":false,"title":"283027761","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/283027761","trackType":"qobuz"} Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: CURRENT POSITION 0 Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState stateService play Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState currentStatus play Oct 30 16:01:33 volumio-rivo volumio[3134]: info: Received an update from plugin. extracting info from payload Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1354,"duration":172,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"978 Kbps","isStreaming":false,"title":"283027761","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/283027761","trackType":"qobuz"} Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: CURRENT POSITION 0 Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState stateService play Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState currentStatus play Oct 30 16:01:33 volumio-rivo volumio[3134]: info: Received an update from plugin. extracting info from payload Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1354,"duration":172,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"978 Kbps","isStreaming":false,"title":"283027761","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/283027761","trackType":"qobuz"} Oct 30 16:01:33 volumio-rivo volumio[3134]: verbose: CURRENT POSITION 0 Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState stateService play Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState currentStatus play Oct 30 16:01:33 volumio-rivo volumio[3134]: info: Received an update from plugin. extracting info from payload Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:01:33 volumio-rivo volumio[3134]: info: ------------------------------ 396ms Oct 30 16:01:33 volumio-rivo volumio[3134]: info: ------------------------------ 392ms Oct 30 16:01:33 volumio-rivo volumio[3134]: info: ------------------------------ 373ms Oct 30 16:01:33 volumio-rivo volumio[3134]: info: ------------------------------ 372ms Oct 30 16:01:33 volumio-rivo volumio[3134]: info: ------------------------------ 368ms Oct 30 16:01:34 volumio-rivo volumio[3134]: STREAMING PROXY: Client dropped request, destroying Oct 30 16:01:40 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioGetState Oct 30 16:01:42 volumio-rivo volumio[3134]: info: Executing endpoint metavolumio Oct 30 16:01:42 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 30 16:01:42 volumio-rivo volumio[3134]: info: Executing endpoint metavolumio Oct 30 16:01:42 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 30 16:01:42 volumio-rivo volumio[3134]: info: Executing endpoint metavolumio Oct 30 16:01:42 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 30 16:01:43 volumio-rivo volumio[3134]: error: Failed request for metavolumio API Oct 30 16:01:43 volumio-rivo volumio[3134]: error: Failed request for metavolumio API Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioNext Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CoreStateMachine::next Oct 30 16:02:11 volumio-rivo volumio[3134]: info: [1730300531616] ControllerQobuz::next Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CoreStateMachine::next Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CoreStateMachine::stop Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CoreStateMachine::stPlaybackTimer Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CoreStateMachine::updateTrackBlock Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrackBlock Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CoreStateMachine::serviceStop Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 0 Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CoreCommandRouter::serviceStop Oct 30 16:02:11 volumio-rivo volumio[3134]: info: [1730300531629] ControllerQobuz::stop Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 30 16:02:11 volumio-rivo volumio[3134]: info: ControllerMpd::stop Oct 30 16:02:11 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand stop Oct 30 16:02:11 volumio-rivo volumio[3134]: info: sendMpdCommand stop took 24 milliseconds Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CoreStateMachine::play index undefined Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 1 Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CoreStateMachine::startPlaybackTimer Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 1 Oct 30 16:02:11 volumio-rivo volumio[3134]: info: [1730300531659] ControllerQobuz::clearAddPlayTrack Oct 30 16:02:11 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand stop Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CoreStateMachine::updateTrackBlock Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrackBlock Oct 30 16:02:11 volumio-rivo volumio[3134]: info: Oct 30 16:02:11 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:02:11 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:02:11 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:02:11 volumio-rivo volumio[3134]: info: sendMpdCommand stop took 3 milliseconds Oct 30 16:02:11 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand clear Oct 30 16:02:11 volumio-rivo volumio[3134]: info: Oct 30 16:02:11 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:02:11 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:02:11 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:02:11 volumio-rivo volumio[3134]: info: Oct 30 16:02:11 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:02:11 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:02:11 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:02:11 volumio-rivo volumio[3134]: info: Oct 30 16:02:11 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:02:11 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:02:11 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:02:11 volumio-rivo volumio[3134]: info: Oct 30 16:02:11 volumio-rivo volumio[3134]: ---------------------------- MPD announces system playlist update Oct 30 16:02:11 volumio-rivo volumio[3134]: info: Ignoring MPD Status Update Oct 30 16:02:11 volumio-rivo volumio[3134]: info: sendMpdCommand status took 11 milliseconds Oct 30 16:02:11 volumio-rivo volumio[3134]: info: sendMpdCommand clear took 11 milliseconds Oct 30 16:02:11 volumio-rivo volumio[3134]: info: sendMpdCommand status took 9 milliseconds Oct 30 16:02:11 volumio-rivo volumio[3134]: info: sendMpdCommand status took 6 milliseconds Oct 30 16:02:11 volumio-rivo volumio[3134]: info: sendMpdCommand status took 7 milliseconds Oct 30 16:02:11 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:02:11 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:02:11 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/283027762" Oct 30 16:02:11 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:02:11 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:02:11 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:02:11 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 1 Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:11 volumio-rivo volumio[3134]: STREAMING PROXY: Handling url /?data=qobuz://song/283027762 Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 1 Oct 30 16:02:11 volumio-rivo volumio[3134]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Oct 30 16:02:11 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 1 Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 1 Oct 30 16:02:11 volumio-rivo volumio[3134]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Oct 30 16:02:11 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 1 Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 1 Oct 30 16:02:11 volumio-rivo volumio[3134]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Oct 30 16:02:11 volumio-rivo volumio[3134]: info: ------------------------------ 54ms Oct 30 16:02:11 volumio-rivo volumio[3134]: info: ------------------------------ 58ms Oct 30 16:02:11 volumio-rivo volumio[3134]: info: ------------------------------ 57ms Oct 30 16:02:11 volumio-rivo volumio[3134]: info: Oct 30 16:02:11 volumio-rivo volumio[3134]: ---------------------------- MPD announces system playlist update Oct 30 16:02:11 volumio-rivo volumio[3134]: info: Ignoring MPD Status Update Oct 30 16:02:11 volumio-rivo volumio[3134]: info: Oct 30 16:02:11 volumio-rivo volumio[3134]: ---------------------------- MPD announces system playlist update Oct 30 16:02:11 volumio-rivo volumio[3134]: info: Ignoring MPD Status Update Oct 30 16:02:11 volumio-rivo volumio[3134]: info: Oct 30 16:02:11 volumio-rivo volumio[3134]: ---------------------------- MPD announces system playlist update Oct 30 16:02:11 volumio-rivo volumio[3134]: info: Ignoring MPD Status Update Oct 30 16:02:11 volumio-rivo volumio[3134]: error: updateQueue error: null Oct 30 16:02:11 volumio-rivo volumio[3134]: info: ------------------------------ 64ms Oct 30 16:02:11 volumio-rivo volumio[3134]: info: sendMpdCommand playlistinfo took 57 milliseconds Oct 30 16:02:11 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseTrackInfo Oct 30 16:02:11 volumio-rivo volumio[3134]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Oct 30 16:02:11 volumio-rivo volumio[3134]: info: ------------------------------ 79ms Oct 30 16:02:11 volumio-rivo volumio[3134]: info: Executing endpoint getStreamUrlqobuz Oct 30 16:02:11 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 30 16:02:12 volumio-rivo volumio[3134]: info: getStreamUrl took 581 milliseconds Oct 30 16:02:12 volumio-rivo volumio[3134]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=2880200&eid=283027762&fmt=7&profile=raw&app_id=539451548&cid=2033386&etsp=1730304132&hmac=GwWBGCHoOX3arifOQHcL6HIiwuQ Oct 30 16:02:12 volumio-rivo volumio[3134]: STREAMING PROXY: Response: 200, length: 97410350 Oct 30 16:02:12 volumio-rivo volumiologrotate[2870]: ls: cannot access '/var/log/samba/log.wb-VOLUMIO': No such file or directory Oct 30 16:02:12 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/283027762" Oct 30 16:02:12 volumio-rivo volumio[3134]: error: updateQueue error: null Oct 30 16:02:12 volumio-rivo volumio[3134]: error: updateQueue error: null Oct 30 16:02:12 volumio-rivo volumio[3134]: error: updateQueue error: null Oct 30 16:02:12 volumio-rivo volumio[3134]: info: Oct 30 16:02:12 volumio-rivo volumio[3134]: ---------------------------- MPD announces system playlist update Oct 30 16:02:12 volumio-rivo volumio[3134]: info: Ignoring MPD Status Update Oct 30 16:02:12 volumio-rivo volumio[3134]: info: ------------------------------ 719ms Oct 30 16:02:12 volumio-rivo volumio[3134]: info: ------------------------------ 719ms Oct 30 16:02:12 volumio-rivo volumio[3134]: info: ------------------------------ 717ms Oct 30 16:02:12 volumio-rivo volumio[3134]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/283027762" took 13 milliseconds Oct 30 16:02:12 volumio-rivo volumio[3134]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 30 16:02:12 volumio-rivo volumio[3134]: STREAMING PROXY: Client dropped request, destroying Oct 30 16:02:12 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand play Oct 30 16:02:12 volumio-rivo volumio[3134]: info: Oct 30 16:02:12 volumio-rivo volumio[3134]: ---------------------------- MPD announces system playlist update Oct 30 16:02:12 volumio-rivo volumio[3134]: info: Ignoring MPD Status Update Oct 30 16:02:12 volumio-rivo volumio[3134]: info: Oct 30 16:02:12 volumio-rivo volumio[3134]: ---------------------------- MPD announces system playlist update Oct 30 16:02:12 volumio-rivo volumio[3134]: info: Ignoring MPD Status Update Oct 30 16:02:12 volumio-rivo volumio[3134]: STREAMING PROXY: Handling url /?data=qobuz://song/283027762 Oct 30 16:02:12 volumio-rivo volumio[3134]: info: Oct 30 16:02:12 volumio-rivo volumio[3134]: ---------------------------- MPD announces system playlist update Oct 30 16:02:12 volumio-rivo volumio[3134]: info: Ignoring MPD Status Update Oct 30 16:02:12 volumio-rivo volumio[3134]: info: ------------------------------ 18ms Oct 30 16:02:12 volumio-rivo volumio[3134]: info: sendMpdCommand play took 12 milliseconds Oct 30 16:02:12 volumio-rivo volumio[3134]: info: ------------------------------ 12ms Oct 30 16:02:12 volumio-rivo volumio[3134]: info: ------------------------------ 9ms Oct 30 16:02:12 volumio-rivo volumio[3134]: info: ------------------------------ 6ms Oct 30 16:02:12 volumio-rivo volumiologrotate[2870]: ls: cannot access 'RIVO': No such file or directory Oct 30 16:02:12 volumio-rivo volumio[3134]: info: camilladsp spawned new process with pid 3971, instance 1, run: true Oct 30 16:02:12 volumio-rivo volumio[3134]: info: Executing endpoint getStreamUrlqobuz Oct 30 16:02:12 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 30 16:02:12 volumio-rivo volumio[3134]: info: getStreamUrl took 444 milliseconds Oct 30 16:02:12 volumio-rivo volumio[3134]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=2880200&eid=283027762&fmt=7&profile=raw&app_id=539451548&cid=2033386&etsp=1730304132&hmac=GwWBGCHoOX3arifOQHcL6HIiwuQ Oct 30 16:02:12 volumio-rivo volumio[3134]: STREAMING PROXY: Response: 200, length: 97410350 Oct 30 16:02:13 volumio-rivo volumio[3134]: info: Oct 30 16:02:13 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:02:13 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:02:13 volumio-rivo volumio[3134]: info: Oct 30 16:02:13 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:02:13 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:02:13 volumio-rivo volumio[3134]: info: Oct 30 16:02:13 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:02:13 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:02:13 volumio-rivo volumio[3134]: info: Oct 30 16:02:13 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:02:13 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:02:13 volumio-rivo volumio[3134]: info: FusionDsp - ---- read samplerate, raw: 48000,S32_LE,2,32 Oct 30 16:02:13 volumio-rivo volumio[3134]: info: FusionDsp - ---- read samplerate from file: 48000 Oct 30 16:02:13 volumio-rivo volumio[3134]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 30 16:02:13 volumio-rivo volumio[3134]: info: FusionDsp - Nulleq applied Oct 30 16:02:13 volumio-rivo volumio[3134]: info: Oct 30 16:02:13 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:02:13 volumio-rivo volumio[3134]: info: sendMpdCommand status took 53 milliseconds Oct 30 16:02:13 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:02:13 volumio-rivo volumio[3134]: info: sendMpdCommand status took 52 milliseconds Oct 30 16:02:13 volumio-rivo volumio[3134]: info: sendMpdCommand status took 51 milliseconds Oct 30 16:02:13 volumio-rivo volumio[3134]: info: sendMpdCommand status took 50 milliseconds Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:02:13 volumio-rivo volumio[3134]: info: Oct 30 16:02:13 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:02:13 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:02:13 volumio-rivo volumio[3134]: info: Oct 30 16:02:13 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:02:13 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:02:13 volumio-rivo volumio[3134]: info: Oct 30 16:02:13 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:02:13 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:02:13 volumio-rivo volumio[3134]: info: sendMpdCommand status took 41 milliseconds Oct 30 16:02:13 volumio-rivo volumio[3134]: info: sendMpdCommand playlistinfo took 36 milliseconds Oct 30 16:02:13 volumio-rivo volumio[3134]: info: sendMpdCommand playlistinfo took 37 milliseconds Oct 30 16:02:13 volumio-rivo volumio[3134]: info: sendMpdCommand playlistinfo took 36 milliseconds Oct 30 16:02:13 volumio-rivo volumio[3134]: info: sendMpdCommand status took 29 milliseconds Oct 30 16:02:13 volumio-rivo volumio[3134]: info: sendMpdCommand status took 21 milliseconds Oct 30 16:02:13 volumio-rivo volumio[3134]: info: sendMpdCommand status took 15 milliseconds Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseTrackInfo Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseTrackInfo Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseTrackInfo Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:02:13 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 1 Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":482,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"283027762","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/283027762","trackType":"qobuz"} Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: CURRENT POSITION 1 Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState stateService play Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState currentStatus stop Oct 30 16:02:13 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 1 Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":482,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"283027762","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/283027762","trackType":"qobuz"} Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: CURRENT POSITION 1 Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState stateService play Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState currentStatus play Oct 30 16:02:13 volumio-rivo volumio[3134]: info: Received an update from plugin. extracting info from payload Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 1 Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":482,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"283027762","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/283027762","trackType":"qobuz"} Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: CURRENT POSITION 1 Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState stateService play Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState currentStatus play Oct 30 16:02:13 volumio-rivo volumio[3134]: info: Received an update from plugin. extracting info from payload Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 1 Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":482,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"283027762","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/283027762","trackType":"qobuz"} Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: CURRENT POSITION 1 Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState stateService play Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState currentStatus play Oct 30 16:02:13 volumio-rivo volumio[3134]: info: Received an update from plugin. extracting info from payload Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: ------------------------------ 196ms Oct 30 16:02:13 volumio-rivo volumio[3134]: info: ------------------------------ 236ms Oct 30 16:02:13 volumio-rivo volumio[3134]: info: ------------------------------ 235ms Oct 30 16:02:13 volumio-rivo volumio[3134]: info: ------------------------------ 235ms Oct 30 16:02:13 volumio-rivo volumio[3134]: info: sendMpdCommand playlistinfo took 123 milliseconds Oct 30 16:02:13 volumio-rivo volumio[3134]: info: sendMpdCommand playlistinfo took 120 milliseconds Oct 30 16:02:13 volumio-rivo volumio[3134]: info: sendMpdCommand playlistinfo took 121 milliseconds Oct 30 16:02:13 volumio-rivo volumio[3134]: info: sendMpdCommand playlistinfo took 121 milliseconds Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseTrackInfo Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseTrackInfo Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseTrackInfo Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseTrackInfo Oct 30 16:02:13 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 1 Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1238,"duration":482,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1203 Kbps","isStreaming":false,"title":"283027762","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/283027762","trackType":"qobuz"} Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: CURRENT POSITION 1 Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState stateService play Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState currentStatus play Oct 30 16:02:13 volumio-rivo volumio[3134]: info: Received an update from plugin. extracting info from payload Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 1 Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1354,"duration":482,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1203 Kbps","isStreaming":false,"title":"283027762","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/283027762","trackType":"qobuz"} Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: CURRENT POSITION 1 Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState stateService play Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState currentStatus play Oct 30 16:02:13 volumio-rivo volumio[3134]: info: Received an update from plugin. extracting info from payload Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 1 Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1354,"duration":482,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1203 Kbps","isStreaming":false,"title":"283027762","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/283027762","trackType":"qobuz"} Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: CURRENT POSITION 1 Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState stateService play Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState currentStatus play Oct 30 16:02:13 volumio-rivo volumio[3134]: info: Received an update from plugin. extracting info from payload Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 1 Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1480,"duration":482,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1203 Kbps","isStreaming":false,"title":"283027762","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/283027762","trackType":"qobuz"} Oct 30 16:02:13 volumio-rivo volumio[3134]: verbose: CURRENT POSITION 1 Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState stateService play Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState currentStatus play Oct 30 16:02:13 volumio-rivo volumio[3134]: info: Received an update from plugin. extracting info from payload Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:13 volumio-rivo volumio[3134]: info: ------------------------------ 312ms Oct 30 16:02:13 volumio-rivo volumio[3134]: info: ------------------------------ 299ms Oct 30 16:02:13 volumio-rivo volumio[3134]: info: ------------------------------ 292ms Oct 30 16:02:13 volumio-rivo volumio[3134]: info: ------------------------------ 285ms Oct 30 16:02:13 volumio-rivo volumio[3134]: info: FusionDsp - {"Reload":{"result":"Ok"}} Oct 30 16:02:14 volumio-rivo volumio[3134]: STREAMING PROXY: Client dropped request, destroying Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioNext Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CoreStateMachine::next Oct 30 16:02:22 volumio-rivo volumio[3134]: info: [1730300542295] ControllerQobuz::next Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CoreStateMachine::next Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CoreStateMachine::stop Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CoreStateMachine::stPlaybackTimer Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CoreStateMachine::updateTrackBlock Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrackBlock Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 1 Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CoreStateMachine::serviceStop Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 1 Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CoreCommandRouter::serviceStop Oct 30 16:02:22 volumio-rivo volumio[3134]: info: [1730300542304] ControllerQobuz::stop Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 30 16:02:22 volumio-rivo volumio[3134]: info: ControllerMpd::stop Oct 30 16:02:22 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand stop Oct 30 16:02:22 volumio-rivo volumio[3134]: info: sendMpdCommand stop took 56 milliseconds Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CoreStateMachine::play index undefined Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 2 Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CoreStateMachine::startPlaybackTimer Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 2 Oct 30 16:02:22 volumio-rivo volumio[3134]: info: [1730300542364] ControllerQobuz::clearAddPlayTrack Oct 30 16:02:22 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand stop Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CoreStateMachine::updateTrackBlock Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrackBlock Oct 30 16:02:22 volumio-rivo volumio[3134]: info: Oct 30 16:02:22 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:02:22 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:02:22 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:02:22 volumio-rivo volumio[3134]: info: sendMpdCommand stop took 3 milliseconds Oct 30 16:02:22 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand clear Oct 30 16:02:22 volumio-rivo volumio[3134]: info: Oct 30 16:02:22 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:02:22 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:02:22 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:02:22 volumio-rivo volumio[3134]: info: Oct 30 16:02:22 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:02:22 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:02:22 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:02:22 volumio-rivo volumio[3134]: info: Oct 30 16:02:22 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:02:22 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:02:22 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:02:22 volumio-rivo volumio[3134]: info: Oct 30 16:02:22 volumio-rivo volumio[3134]: ---------------------------- MPD announces system playlist update Oct 30 16:02:22 volumio-rivo volumio[3134]: info: Ignoring MPD Status Update Oct 30 16:02:22 volumio-rivo volumio[3134]: info: sendMpdCommand status took 13 milliseconds Oct 30 16:02:22 volumio-rivo volumio[3134]: info: sendMpdCommand clear took 11 milliseconds Oct 30 16:02:22 volumio-rivo volumio[3134]: info: sendMpdCommand status took 9 milliseconds Oct 30 16:02:22 volumio-rivo volumio[3134]: info: sendMpdCommand status took 6 milliseconds Oct 30 16:02:22 volumio-rivo volumio[3134]: info: sendMpdCommand status took 5 milliseconds Oct 30 16:02:22 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:02:22 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:02:22 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/283027763" Oct 30 16:02:22 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:02:22 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:02:22 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:02:22 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:02:22 volumio-rivo volumio[3134]: STREAMING PROXY: Handling url /?data=qobuz://song/283027763 Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 2 Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 2 Oct 30 16:02:22 volumio-rivo volumio[3134]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Oct 30 16:02:22 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 2 Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 2 Oct 30 16:02:22 volumio-rivo volumio[3134]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Oct 30 16:02:22 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 2 Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 2 Oct 30 16:02:22 volumio-rivo volumio[3134]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Oct 30 16:02:22 volumio-rivo volumio[3134]: info: ------------------------------ 47ms Oct 30 16:02:22 volumio-rivo volumio[3134]: info: ------------------------------ 46ms Oct 30 16:02:22 volumio-rivo volumio[3134]: info: ------------------------------ 44ms Oct 30 16:02:22 volumio-rivo volumio[3134]: info: Oct 30 16:02:22 volumio-rivo volumio[3134]: ---------------------------- MPD announces system playlist update Oct 30 16:02:22 volumio-rivo volumio[3134]: info: Ignoring MPD Status Update Oct 30 16:02:22 volumio-rivo volumio[3134]: info: Oct 30 16:02:22 volumio-rivo volumio[3134]: ---------------------------- MPD announces system playlist update Oct 30 16:02:22 volumio-rivo volumio[3134]: info: Ignoring MPD Status Update Oct 30 16:02:22 volumio-rivo volumio[3134]: info: Oct 30 16:02:22 volumio-rivo volumio[3134]: ---------------------------- MPD announces system playlist update Oct 30 16:02:22 volumio-rivo volumio[3134]: info: Ignoring MPD Status Update Oct 30 16:02:22 volumio-rivo volumio[3134]: error: updateQueue error: null Oct 30 16:02:22 volumio-rivo volumio[3134]: info: ------------------------------ 52ms Oct 30 16:02:22 volumio-rivo volumio[3134]: info: sendMpdCommand playlistinfo took 48 milliseconds Oct 30 16:02:22 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseTrackInfo Oct 30 16:02:22 volumio-rivo volumio[3134]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Oct 30 16:02:22 volumio-rivo volumio[3134]: info: ------------------------------ 67ms Oct 30 16:02:22 volumio-rivo volumio[3134]: info: Executing endpoint getStreamUrlqobuz Oct 30 16:02:22 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 30 16:02:23 volumio-rivo volumio[3134]: info: getStreamUrl took 583 milliseconds Oct 30 16:02:23 volumio-rivo volumio[3134]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=2880200&eid=283027763&fmt=7&profile=raw&app_id=539451548&cid=2033386&etsp=1730304142&hmac=Q60u_4fNSdJLem_hqZDLvOMDBUg Oct 30 16:02:23 volumio-rivo volumio[3134]: STREAMING PROXY: Response: 200, length: 40757916 Oct 30 16:02:23 volumio-rivo volumio[3134]: STREAMING PROXY: Client dropped request, destroying Oct 30 16:02:23 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/283027763" Oct 30 16:02:23 volumio-rivo volumio[3134]: error: updateQueue error: null Oct 30 16:02:23 volumio-rivo volumio[3134]: error: updateQueue error: null Oct 30 16:02:23 volumio-rivo volumio[3134]: error: updateQueue error: null Oct 30 16:02:23 volumio-rivo volumio[3134]: info: ------------------------------ 671ms Oct 30 16:02:23 volumio-rivo volumio[3134]: info: ------------------------------ 670ms Oct 30 16:02:23 volumio-rivo volumio[3134]: info: ------------------------------ 669ms Oct 30 16:02:23 volumio-rivo volumio[3134]: info: Oct 30 16:02:23 volumio-rivo volumio[3134]: ---------------------------- MPD announces system playlist update Oct 30 16:02:23 volumio-rivo volumio[3134]: info: Ignoring MPD Status Update Oct 30 16:02:23 volumio-rivo volumio[3134]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/283027763" took 16 milliseconds Oct 30 16:02:23 volumio-rivo volumio[3134]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 30 16:02:23 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand play Oct 30 16:02:23 volumio-rivo volumio[3134]: info: Oct 30 16:02:23 volumio-rivo volumio[3134]: ---------------------------- MPD announces system playlist update Oct 30 16:02:23 volumio-rivo volumio[3134]: info: Ignoring MPD Status Update Oct 30 16:02:23 volumio-rivo volumio[3134]: info: Oct 30 16:02:23 volumio-rivo volumio[3134]: ---------------------------- MPD announces system playlist update Oct 30 16:02:23 volumio-rivo volumio[3134]: STREAMING PROXY: Handling url /?data=qobuz://song/283027763 Oct 30 16:02:23 volumio-rivo volumio[3134]: info: Ignoring MPD Status Update Oct 30 16:02:23 volumio-rivo volumio[3134]: info: Oct 30 16:02:23 volumio-rivo volumio[3134]: ---------------------------- MPD announces system playlist update Oct 30 16:02:23 volumio-rivo volumio[3134]: info: Ignoring MPD Status Update Oct 30 16:02:23 volumio-rivo volumio[3134]: info: ------------------------------ 16ms Oct 30 16:02:23 volumio-rivo volumio[3134]: info: sendMpdCommand play took 15 milliseconds Oct 30 16:02:23 volumio-rivo volumio[3134]: info: ------------------------------ 14ms Oct 30 16:02:23 volumio-rivo volumio[3134]: info: ------------------------------ 12ms Oct 30 16:02:23 volumio-rivo volumio[3134]: info: ------------------------------ 5ms Oct 30 16:02:23 volumio-rivo volumio[3134]: info: Executing endpoint getStreamUrlqobuz Oct 30 16:02:23 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 30 16:02:23 volumio-rivo volumio[3134]: info: camilladsp spawned new process with pid 4022, instance 1, run: true Oct 30 16:02:23 volumio-rivo volumio[3134]: info: getStreamUrl took 697 milliseconds Oct 30 16:02:23 volumio-rivo volumio[3134]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=2880200&eid=283027763&fmt=7&profile=raw&app_id=539451548&cid=2033386&etsp=1730304143&hmac=WIyl5RV2rffPlUKk68D1Xqe9zbg Oct 30 16:02:23 volumio-rivo volumio[3134]: STREAMING PROXY: Response: 200, length: 40757916 Oct 30 16:02:23 volumio-rivo volumio[3134]: info: Oct 30 16:02:23 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:02:23 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:02:23 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:02:23 volumio-rivo volumio[3134]: info: Oct 30 16:02:23 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:02:23 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:02:23 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:02:23 volumio-rivo volumio[3134]: info: Oct 30 16:02:23 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:02:23 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:02:23 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:02:23 volumio-rivo volumio[3134]: info: Oct 30 16:02:23 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:02:23 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:02:23 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:02:23 volumio-rivo volumio[3134]: info: FusionDsp - ---- read samplerate, raw: 48000,S32_LE,2,32 Oct 30 16:02:23 volumio-rivo volumio[3134]: info: FusionDsp - ---- read samplerate from file: 48000 Oct 30 16:02:23 volumio-rivo volumio[3134]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 30 16:02:23 volumio-rivo volumio[3134]: info: FusionDsp - Nulleq applied Oct 30 16:02:23 volumio-rivo volumio[3134]: info: Oct 30 16:02:23 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:02:23 volumio-rivo volumio[3134]: info: sendMpdCommand status took 58 milliseconds Oct 30 16:02:23 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:02:23 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:02:23 volumio-rivo volumio[3134]: info: sendMpdCommand status took 57 milliseconds Oct 30 16:02:23 volumio-rivo volumio[3134]: info: sendMpdCommand status took 54 milliseconds Oct 30 16:02:23 volumio-rivo volumio[3134]: info: sendMpdCommand status took 48 milliseconds Oct 30 16:02:23 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:02:23 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:02:23 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:02:23 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:02:23 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:02:23 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:02:23 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:02:23 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:02:23 volumio-rivo volumio[3134]: info: Oct 30 16:02:23 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:02:23 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:02:23 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:02:23 volumio-rivo volumio[3134]: info: Oct 30 16:02:23 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:02:23 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:02:23 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:02:23 volumio-rivo volumio[3134]: info: Oct 30 16:02:23 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:02:23 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:02:23 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:02:23 volumio-rivo volumio[3134]: info: sendMpdCommand status took 29 milliseconds Oct 30 16:02:23 volumio-rivo volumio[3134]: info: sendMpdCommand playlistinfo took 24 milliseconds Oct 30 16:02:23 volumio-rivo volumio[3134]: info: sendMpdCommand playlistinfo took 22 milliseconds Oct 30 16:02:23 volumio-rivo volumio[3134]: info: sendMpdCommand playlistinfo took 22 milliseconds Oct 30 16:02:23 volumio-rivo volumio[3134]: info: sendMpdCommand playlistinfo took 23 milliseconds Oct 30 16:02:23 volumio-rivo volumio[3134]: info: sendMpdCommand status took 18 milliseconds Oct 30 16:02:23 volumio-rivo volumio[3134]: info: sendMpdCommand status took 16 milliseconds Oct 30 16:02:23 volumio-rivo volumio[3134]: info: sendMpdCommand status took 11 milliseconds Oct 30 16:02:23 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:02:23 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:02:23 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseTrackInfo Oct 30 16:02:23 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseTrackInfo Oct 30 16:02:23 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseTrackInfo Oct 30 16:02:23 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseTrackInfo Oct 30 16:02:23 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:02:23 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:02:23 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:02:23 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:02:23 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:02:23 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:02:23 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:02:23 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:02:23 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 2 Oct 30 16:02:23 volumio-rivo volumio[3134]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":203,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"283027763","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/283027763","trackType":"qobuz"} Oct 30 16:02:23 volumio-rivo volumio[3134]: verbose: CURRENT POSITION 2 Oct 30 16:02:23 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState stateService play Oct 30 16:02:23 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState currentStatus stop Oct 30 16:02:23 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:02:23 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 2 Oct 30 16:02:24 volumio-rivo volumio[3134]: verbose: STATE SERVICE {"status":"play","position":0,"seek":10,"duration":203,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1477 Kbps","isStreaming":false,"title":"283027763","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/283027763","trackType":"qobuz"} Oct 30 16:02:24 volumio-rivo volumio[3134]: verbose: CURRENT POSITION 2 Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState stateService play Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState currentStatus play Oct 30 16:02:24 volumio-rivo volumio[3134]: info: Received an update from plugin. extracting info from payload Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 2 Oct 30 16:02:24 volumio-rivo volumio[3134]: verbose: STATE SERVICE {"status":"play","position":0,"seek":388,"duration":203,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1461 Kbps","isStreaming":false,"title":"283027763","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/283027763","trackType":"qobuz"} Oct 30 16:02:24 volumio-rivo volumio[3134]: verbose: CURRENT POSITION 2 Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState stateService play Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState currentStatus play Oct 30 16:02:24 volumio-rivo volumio[3134]: info: Received an update from plugin. extracting info from payload Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 2 Oct 30 16:02:24 volumio-rivo volumio[3134]: verbose: STATE SERVICE {"status":"play","position":0,"seek":483,"duration":203,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1455 Kbps","isStreaming":false,"title":"283027763","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/283027763","trackType":"qobuz"} Oct 30 16:02:24 volumio-rivo volumio[3134]: verbose: CURRENT POSITION 2 Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState stateService play Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState currentStatus play Oct 30 16:02:24 volumio-rivo volumio[3134]: info: Received an update from plugin. extracting info from payload Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: ------------------------------ 191ms Oct 30 16:02:24 volumio-rivo volumio[3134]: info: ------------------------------ 224ms Oct 30 16:02:24 volumio-rivo volumio[3134]: info: ------------------------------ 223ms Oct 30 16:02:24 volumio-rivo volumio[3134]: info: ------------------------------ 218ms Oct 30 16:02:24 volumio-rivo volumio[3134]: info: sendMpdCommand playlistinfo took 118 milliseconds Oct 30 16:02:24 volumio-rivo volumio[3134]: info: sendMpdCommand playlistinfo took 111 milliseconds Oct 30 16:02:24 volumio-rivo volumio[3134]: info: sendMpdCommand playlistinfo took 111 milliseconds Oct 30 16:02:24 volumio-rivo volumio[3134]: info: sendMpdCommand playlistinfo took 111 milliseconds Oct 30 16:02:24 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseTrackInfo Oct 30 16:02:24 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseTrackInfo Oct 30 16:02:24 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseTrackInfo Oct 30 16:02:24 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseTrackInfo Oct 30 16:02:24 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 2 Oct 30 16:02:24 volumio-rivo volumio[3134]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1238,"duration":203,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1628 Kbps","isStreaming":false,"title":"283027763","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/283027763","trackType":"qobuz"} Oct 30 16:02:24 volumio-rivo volumio[3134]: verbose: CURRENT POSITION 2 Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState stateService play Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState currentStatus play Oct 30 16:02:24 volumio-rivo volumio[3134]: info: Received an update from plugin. extracting info from payload Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 2 Oct 30 16:02:24 volumio-rivo volumio[3134]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1238,"duration":203,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1628 Kbps","isStreaming":false,"title":"283027763","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/283027763","trackType":"qobuz"} Oct 30 16:02:24 volumio-rivo volumio[3134]: verbose: CURRENT POSITION 2 Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState stateService play Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState currentStatus play Oct 30 16:02:24 volumio-rivo volumio[3134]: info: Received an update from plugin. extracting info from payload Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 2 Oct 30 16:02:24 volumio-rivo volumio[3134]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1238,"duration":203,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1628 Kbps","isStreaming":false,"title":"283027763","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/283027763","trackType":"qobuz"} Oct 30 16:02:24 volumio-rivo volumio[3134]: verbose: CURRENT POSITION 2 Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState stateService play Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState currentStatus play Oct 30 16:02:24 volumio-rivo volumio[3134]: info: Received an update from plugin. extracting info from payload Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 2 Oct 30 16:02:24 volumio-rivo volumio[3134]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1354,"duration":203,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1600 Kbps","isStreaming":false,"title":"283027763","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/283027763","trackType":"qobuz"} Oct 30 16:02:24 volumio-rivo volumio[3134]: verbose: CURRENT POSITION 2 Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState stateService play Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState currentStatus play Oct 30 16:02:24 volumio-rivo volumio[3134]: info: Received an update from plugin. extracting info from payload Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:24 volumio-rivo volumio[3134]: info: ------------------------------ 290ms Oct 30 16:02:24 volumio-rivo volumio[3134]: info: ------------------------------ 268ms Oct 30 16:02:24 volumio-rivo volumio[3134]: info: ------------------------------ 265ms Oct 30 16:02:24 volumio-rivo volumio[3134]: info: ------------------------------ 264ms Oct 30 16:02:24 volumio-rivo volumio[3134]: info: FusionDsp - {"Reload":{"result":"Ok"}} Oct 30 16:02:24 volumio-rivo volumio[3134]: STREAMING PROXY: Client dropped request, destroying Oct 30 16:02:29 volumio-rivo volumio[3134]: info: Executing endpoint metavolumio Oct 30 16:02:29 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 30 16:02:29 volumio-rivo volumio[3134]: info: Executing endpoint metavolumio Oct 30 16:02:29 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 30 16:02:32 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 30 16:02:32 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 30 16:02:32 volumio-rivo volumio[3134]: info: Discovery: Getting this device information Oct 30 16:02:32 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioGetState Oct 30 16:02:32 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 30 16:02:32 volumio-rivo volumio[3134]: verbose: New Socket.io Connection to 192.168.1.104:3000 from 192.168.1.102 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 Oct 30 16:02:32 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioGetState Oct 30 16:02:32 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 30 16:02:32 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 30 16:02:38 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPause Oct 30 16:02:38 volumio-rivo volumio[3134]: info: CoreStateMachine::pause Oct 30 16:02:38 volumio-rivo volumio[3134]: info: CoreStateMachine::stPlaybackTimer Oct 30 16:02:38 volumio-rivo volumio[3134]: info: CoreStateMachine::servicePause Oct 30 16:02:38 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 2 Oct 30 16:02:38 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePause Oct 30 16:02:38 volumio-rivo volumio[3134]: info: [1730300558120] ControllerQobuz::pause Oct 30 16:02:38 volumio-rivo volumio[3134]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 30 16:02:38 volumio-rivo volumio[3134]: info: ControllerMpd::pause Oct 30 16:02:38 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand pause Oct 30 16:02:38 volumio-rivo volumio[3134]: info: Oct 30 16:02:38 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:02:38 volumio-rivo volumio[3134]: info: sendMpdCommand pause took 4 milliseconds Oct 30 16:02:38 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:02:38 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:02:38 volumio-rivo volumio[3134]: info: Oct 30 16:02:38 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:02:38 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:02:38 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:02:38 volumio-rivo volumio[3134]: info: Oct 30 16:02:38 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:02:38 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:02:38 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:02:38 volumio-rivo volumio[3134]: info: Oct 30 16:02:38 volumio-rivo volumio[3134]: ---------------------------- MPD announces state update: player Oct 30 16:02:38 volumio-rivo volumio[3134]: info: ControllerMpd::getState Oct 30 16:02:38 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand status Oct 30 16:02:38 volumio-rivo volumio[3134]: info: sendMpdCommand status took 15 milliseconds Oct 30 16:02:38 volumio-rivo volumio[3134]: info: sendMpdCommand status took 13 milliseconds Oct 30 16:02:38 volumio-rivo volumio[3134]: info: sendMpdCommand status took 11 milliseconds Oct 30 16:02:38 volumio-rivo volumio[3134]: info: sendMpdCommand status took 7 milliseconds Oct 30 16:02:38 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:02:38 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:02:38 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:02:38 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:02:38 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:02:38 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:02:38 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseState Oct 30 16:02:38 volumio-rivo volumio[3134]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 16:02:38 volumio-rivo volumio[3134]: info: sendMpdCommand playlistinfo took 7 milliseconds Oct 30 16:02:38 volumio-rivo volumio[3134]: info: sendMpdCommand playlistinfo took 7 milliseconds Oct 30 16:02:38 volumio-rivo volumio[3134]: info: sendMpdCommand playlistinfo took 6 milliseconds Oct 30 16:02:38 volumio-rivo volumio[3134]: info: sendMpdCommand playlistinfo took 6 milliseconds Oct 30 16:02:38 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseTrackInfo Oct 30 16:02:38 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseTrackInfo Oct 30 16:02:38 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseTrackInfo Oct 30 16:02:38 volumio-rivo volumio[3134]: verbose: ControllerMpd::parseTrackInfo Oct 30 16:02:38 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:02:38 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:02:38 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 2 Oct 30 16:02:38 volumio-rivo volumio[3134]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":15855,"duration":203,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1461 Kbps","isStreaming":false,"title":"283027763","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/283027763","trackType":"qobuz"} Oct 30 16:02:38 volumio-rivo volumio[3134]: verbose: CURRENT POSITION 2 Oct 30 16:02:38 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState stateService pause Oct 30 16:02:38 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState currentStatus pause Oct 30 16:02:38 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:38 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 30 16:02:38 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:38 volumio-rivo volumio[3134]: info: CoreStateMachine::stPlaybackTimer Oct 30 16:02:38 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:02:38 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:02:38 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 2 Oct 30 16:02:38 volumio-rivo volumio[3134]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":15855,"duration":203,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1461 Kbps","isStreaming":false,"title":"283027763","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/283027763","trackType":"qobuz"} Oct 30 16:02:38 volumio-rivo volumio[3134]: verbose: CURRENT POSITION 2 Oct 30 16:02:38 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState stateService pause Oct 30 16:02:38 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState currentStatus pause Oct 30 16:02:38 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:38 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:38 volumio-rivo volumio[3134]: info: CoreStateMachine::stPlaybackTimer Oct 30 16:02:38 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:02:38 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:02:38 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 2 Oct 30 16:02:38 volumio-rivo volumio[3134]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":15855,"duration":203,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1461 Kbps","isStreaming":false,"title":"283027763","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/283027763","trackType":"qobuz"} Oct 30 16:02:38 volumio-rivo volumio[3134]: verbose: CURRENT POSITION 2 Oct 30 16:02:38 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState stateService pause Oct 30 16:02:38 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState currentStatus pause Oct 30 16:02:38 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:38 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:38 volumio-rivo volumio[3134]: info: CoreStateMachine::stPlaybackTimer Oct 30 16:02:38 volumio-rivo volumio[3134]: info: ControllerMpd::pushState Oct 30 16:02:38 volumio-rivo volumio[3134]: info: CoreCommandRouter::servicePushState Oct 30 16:02:38 volumio-rivo volumio[3134]: info: CorePlayQueue::getTrack 2 Oct 30 16:02:38 volumio-rivo volumio[3134]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":15855,"duration":203,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1461 Kbps","isStreaming":false,"title":"283027763","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/283027763","trackType":"qobuz"} Oct 30 16:02:38 volumio-rivo volumio[3134]: verbose: CURRENT POSITION 2 Oct 30 16:02:38 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState stateService pause Oct 30 16:02:38 volumio-rivo volumio[3134]: info: CoreStateMachine::syncState currentStatus pause Oct 30 16:02:38 volumio-rivo volumio[3134]: info: CoreStateMachine::pushState Oct 30 16:02:38 volumio-rivo volumio[3134]: info: CoreCommandRouter::volumioPushState Oct 30 16:02:38 volumio-rivo volumio[3134]: info: CoreStateMachine::stPlaybackTimer Oct 30 16:02:38 volumio-rivo volumio[3134]: info: ------------------------------ 71ms Oct 30 16:02:38 volumio-rivo volumio[3134]: info: ------------------------------ 68ms Oct 30 16:02:38 volumio-rivo volumio[3134]: info: ------------------------------ 66ms Oct 30 16:02:38 volumio-rivo volumio[3134]: info: ------------------------------ 64ms Oct 30 16:02:38 volumio-rivo volumio[3134]: info: camilladsp spawned new process with pid 4065, instance 1, run: true Oct 30 16:02:45 volumio-rivo volumio[3134]: Searching all installed plugins Oct 30 16:02:45 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 30 16:02:45 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: , search Oct 30 16:02:45 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: mpd , search Oct 30 16:02:45 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Oct 30 16:02:45 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Oct 30 16:02:45 volumio-rivo volumio[3134]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Oct 30 16:02:45 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: webradio , search Oct 30 16:02:45 volumio-rivo volumio[3134]: info: CoreCommandRouter::executeOnPlugin: calmradio , search Oct 30 16:02:45 volumio-rivo volumio[3134]: info: [1730300565474] ControllerCalmRadio::searchCategories Oct 30 16:02:45 volumio-rivo volumio[3134]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 30 16:02:45 volumio-rivo volumio[3134]: TypeError: Cannot read property 'cats' of undefined Oct 30 16:02:45 volumio-rivo volumio[3134]: at ControllerCalmRadio.searchCategories (/data/plugins/music_service/calmradio/index.js:615:42) Oct 30 16:02:45 volumio-rivo volumio[3134]: at ControllerCalmRadio.search (/data/plugins/music_service/calmradio/index.js:665:28) Oct 30 16:02:45 volumio-rivo volumio[3134]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1083:32) Oct 30 16:02:45 volumio-rivo volumio[3134]: at CoreMusicLibrary.searchOnPlugin (/volumio/app/musiclibrary.js:668:44) Oct 30 16:02:45 volumio-rivo volumio[3134]: at CoreMusicLibrary.search (/volumio/app/musiclibrary.js:455:27) Oct 30 16:02:45 volumio-rivo volumio[3134]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:485:44) Oct 30 16:02:45 volumio-rivo volumio[3134]: at Socket.emit (events.js:400:28) Oct 30 16:02:45 volumio-rivo volumio[3134]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Oct 30 16:02:45 volumio-rivo volumio[3134]: at processTicksAndRejections (internal/process/task_queues.js:77:11) Oct 30 16:02:45 volumio-rivo volumio[3134]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 30 16:02:46 volumio-rivo sudo[4082]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-30 16:01 Oct 30 16:02:46 volumio-rivo sudo[4082]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="bba9e3185e150dd0995f9a49355b34fc6218d5a2" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 05:47:06 PM CEST" VOLUMIO_VERSION="3.757" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="b3e08c3e210a64867536255c2503fb09"