-- Logs begin at Sat 2024-10-26 20:18:20 +04, end at Sun 2024-10-27 00:10:35 +04. -- Oct 27 00:09:03 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioNext Oct 27 00:09:03 minidsp-shd volumio[22135]: info: CoreStateMachine::next Oct 27 00:09:03 minidsp-shd volumio[22135]: info: [1729973343990] ControllerQobuz::next Oct 27 00:09:03 minidsp-shd volumio[22135]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 27 00:09:03 minidsp-shd volumio[22135]: info: CoreStateMachine::next Oct 27 00:09:03 minidsp-shd volumio[22135]: info: CoreStateMachine::stop Oct 27 00:09:03 minidsp-shd volumio[22135]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 27 00:09:03 minidsp-shd volumio[22135]: info: CoreStateMachine::stPlaybackTimer Oct 27 00:09:03 minidsp-shd volumio[22135]: info: CoreStateMachine::updateTrackBlock Oct 27 00:09:03 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrackBlock Oct 27 00:09:04 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:04 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 958 Oct 27 00:09:04 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 27 00:09:04 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:04 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:04 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:04 minidsp-shd volumio[22135]: info: CoreStateMachine::serviceStop Oct 27 00:09:04 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 958 Oct 27 00:09:04 minidsp-shd volumio[22135]: info: CoreCommandRouter::serviceStop Oct 27 00:09:04 minidsp-shd volumio[22135]: info: [1729973344039] ControllerQobuz::stop Oct 27 00:09:04 minidsp-shd volumio[22135]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 27 00:09:04 minidsp-shd volumio[22135]: info: ControllerMpd::stop Oct 27 00:09:04 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand stop Oct 27 00:09:04 minidsp-shd volumio[22135]: STREAMING PROXY: Client dropped request, destroying Oct 27 00:09:04 minidsp-shd volumio[22135]: info: Oct 27 00:09:04 minidsp-shd volumio[22135]: ---------------------------- MPD announces state update: player Oct 27 00:09:04 minidsp-shd volumio[22135]: info: sendMpdCommand stop took 63 milliseconds Oct 27 00:09:04 minidsp-shd volumio[22135]: info: ControllerMpd::getState Oct 27 00:09:04 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand status Oct 27 00:09:04 minidsp-shd volumio[22135]: info: CoreStateMachine::play index undefined Oct 27 00:09:04 minidsp-shd volumio[22135]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 27 00:09:04 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 959 Oct 27 00:09:04 minidsp-shd volumio[22135]: info: CoreStateMachine::startPlaybackTimer Oct 27 00:09:04 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 959 Oct 27 00:09:04 minidsp-shd volumio[22135]: info: [1729973344112] ControllerQobuz::clearAddPlayTrack Oct 27 00:09:04 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand stop Oct 27 00:09:04 minidsp-shd volumio[22135]: info: CoreStateMachine::updateTrackBlock Oct 27 00:09:04 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrackBlock Oct 27 00:09:04 minidsp-shd volumio[22135]: info: Oct 27 00:09:04 minidsp-shd volumio[22135]: ---------------------------- MPD announces state update: player Oct 27 00:09:04 minidsp-shd volumio[22135]: info: ControllerMpd::getState Oct 27 00:09:04 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand status Oct 27 00:09:04 minidsp-shd volumio[22135]: info: Oct 27 00:09:04 minidsp-shd volumio[22135]: ---------------------------- MPD announces state update: player Oct 27 00:09:04 minidsp-shd volumio[22135]: info: ControllerMpd::getState Oct 27 00:09:04 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand status Oct 27 00:09:04 minidsp-shd volumio[22135]: info: sendMpdCommand status took 19 milliseconds Oct 27 00:09:04 minidsp-shd volumio[22135]: info: sendMpdCommand stop took 14 milliseconds Oct 27 00:09:04 minidsp-shd volumio[22135]: info: sendMpdCommand status took 10 milliseconds Oct 27 00:09:04 minidsp-shd volumio[22135]: info: sendMpdCommand status took 7 milliseconds Oct 27 00:09:04 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseState Oct 27 00:09:04 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 00:09:04 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand clear Oct 27 00:09:04 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseState Oct 27 00:09:04 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 00:09:04 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseState Oct 27 00:09:04 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 00:09:04 minidsp-shd volumio[22135]: info: Oct 27 00:09:04 minidsp-shd volumio[22135]: ---------------------------- MPD announces system playlist update Oct 27 00:09:04 minidsp-shd volumio[22135]: info: Ignoring MPD Status Update Oct 27 00:09:04 minidsp-shd volumio[22135]: info: sendMpdCommand playlistinfo took 13 milliseconds Oct 27 00:09:04 minidsp-shd volumio[22135]: info: sendMpdCommand clear took 14 milliseconds Oct 27 00:09:04 minidsp-shd volumio[22135]: info: sendMpdCommand playlistinfo took 14 milliseconds Oct 27 00:09:04 minidsp-shd volumio[22135]: info: sendMpdCommand playlistinfo took 14 milliseconds Oct 27 00:09:04 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseTrackInfo Oct 27 00:09:04 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/130290818" Oct 27 00:09:04 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseTrackInfo Oct 27 00:09:04 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseTrackInfo Oct 27 00:09:04 minidsp-shd volumio[22135]: info: ControllerMpd::pushState Oct 27 00:09:04 minidsp-shd volumio[22135]: info: CoreCommandRouter::servicePushState Oct 27 00:09:04 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:04 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 959 Oct 27 00:09:04 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 27 00:09:04 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:04 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:04 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:04 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 959 Oct 27 00:09:04 minidsp-shd volumio[22135]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Oct 27 00:09:04 minidsp-shd volumio[22135]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Oct 27 00:09:04 minidsp-shd volumio[22135]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Oct 27 00:09:04 minidsp-shd volumio[22135]: STREAMING PROXY: Handling url /?data=qobuz://song/130290818 Oct 27 00:09:04 minidsp-shd volumio[22135]: info: ------------------------------ 82ms Oct 27 00:09:04 minidsp-shd volumio[22135]: info: ------------------------------ 71ms Oct 27 00:09:04 minidsp-shd volumio[22135]: info: ------------------------------ 68ms Oct 27 00:09:04 minidsp-shd volumio[22135]: info: Oct 27 00:09:04 minidsp-shd volumio[22135]: ---------------------------- MPD announces system playlist update Oct 27 00:09:04 minidsp-shd volumio[22135]: info: Ignoring MPD Status Update Oct 27 00:09:04 minidsp-shd volumio[22135]: info: Oct 27 00:09:04 minidsp-shd volumio[22135]: ---------------------------- MPD announces system playlist update Oct 27 00:09:04 minidsp-shd volumio[22135]: info: Ignoring MPD Status Update Oct 27 00:09:04 minidsp-shd volumio[22135]: error: updateQueue error: null Oct 27 00:09:04 minidsp-shd volumio[22135]: info: ------------------------------ 56ms Oct 27 00:09:04 minidsp-shd volumio[22135]: info: Executing endpoint getStreamUrlqobuz Oct 27 00:09:04 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 27 00:09:05 minidsp-shd volumio[22135]: info: getStreamUrl took 1481 milliseconds Oct 27 00:09:05 minidsp-shd volumio[22135]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=640488&eid=130290818&fmt=7&profile=raw&app_id=539451548&cid=1486318&etsp=1729976945&hmac=ON2CUeEos3JCz-svL2Qp_9hIPDk Oct 27 00:09:06 minidsp-shd volumio[22135]: STREAMING PROXY: Response: 200, length: 32499605 Oct 27 00:09:06 minidsp-shd volumio[22135]: STREAMING PROXY: Client dropped request, destroying Oct 27 00:09:06 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/130290818" Oct 27 00:09:06 minidsp-shd volumio[22135]: error: updateQueue error: null Oct 27 00:09:06 minidsp-shd volumio[22135]: error: updateQueue error: null Oct 27 00:09:06 minidsp-shd volumio[22135]: info: Oct 27 00:09:06 minidsp-shd volumio[22135]: ---------------------------- MPD announces system playlist update Oct 27 00:09:06 minidsp-shd volumio[22135]: info: Ignoring MPD Status Update Oct 27 00:09:06 minidsp-shd volumio[22135]: info: ------------------------------ 2517ms Oct 27 00:09:06 minidsp-shd volumio[22135]: info: ------------------------------ 2515ms Oct 27 00:09:06 minidsp-shd volumio[22135]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/130290818" took 7 milliseconds Oct 27 00:09:06 minidsp-shd volumio[22135]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 27 00:09:06 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand play Oct 27 00:09:06 minidsp-shd volumio[22135]: info: Oct 27 00:09:06 minidsp-shd volumio[22135]: ---------------------------- MPD announces system playlist update Oct 27 00:09:06 minidsp-shd volumio[22135]: info: Ignoring MPD Status Update Oct 27 00:09:06 minidsp-shd volumio[22135]: info: Oct 27 00:09:06 minidsp-shd volumio[22135]: ---------------------------- MPD announces system playlist update Oct 27 00:09:06 minidsp-shd volumio[22135]: STREAMING PROXY: Handling url /?data=qobuz://song/130290818 Oct 27 00:09:06 minidsp-shd volumio[22135]: info: Ignoring MPD Status Update Oct 27 00:09:06 minidsp-shd volumio[22135]: info: ------------------------------ 15ms Oct 27 00:09:06 minidsp-shd volumio[22135]: info: sendMpdCommand play took 11 milliseconds Oct 27 00:09:06 minidsp-shd volumio[22135]: info: ------------------------------ 10ms Oct 27 00:09:06 minidsp-shd volumio[22135]: info: ------------------------------ 7ms Oct 27 00:09:06 minidsp-shd volumio[22135]: info: Executing endpoint getStreamUrlqobuz Oct 27 00:09:06 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 27 00:09:08 minidsp-shd volumio[22135]: info: getStreamUrl took 1282 milliseconds Oct 27 00:09:08 minidsp-shd volumio[22135]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=640488&eid=130290818&fmt=7&profile=raw&app_id=539451548&cid=1486318&etsp=1729976947&hmac=5oD7qZCj9p20TO5bOkvQXeLTOao Oct 27 00:09:08 minidsp-shd volumio[22135]: STREAMING PROXY: Response: 200, length: 32499605 Oct 27 00:09:08 minidsp-shd volumio[22135]: info: Oct 27 00:09:08 minidsp-shd volumio[22135]: ---------------------------- MPD announces state update: player Oct 27 00:09:08 minidsp-shd volumio[22135]: info: ControllerMpd::getState Oct 27 00:09:08 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand status Oct 27 00:09:08 minidsp-shd volumio[22135]: info: Oct 27 00:09:08 minidsp-shd volumio[22135]: ---------------------------- MPD announces state update: player Oct 27 00:09:08 minidsp-shd volumio[22135]: info: ControllerMpd::getState Oct 27 00:09:08 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand status Oct 27 00:09:08 minidsp-shd volumio[22135]: info: Oct 27 00:09:08 minidsp-shd volumio[22135]: ---------------------------- MPD announces state update: player Oct 27 00:09:08 minidsp-shd volumio[22135]: info: ControllerMpd::getState Oct 27 00:09:08 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand status Oct 27 00:09:08 minidsp-shd volumio[22135]: info: Oct 27 00:09:08 minidsp-shd volumio[22135]: ---------------------------- MPD announces state update: player Oct 27 00:09:08 minidsp-shd volumio[22135]: info: sendMpdCommand status took 31 milliseconds Oct 27 00:09:08 minidsp-shd volumio[22135]: info: ControllerMpd::getState Oct 27 00:09:08 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand status Oct 27 00:09:08 minidsp-shd volumio[22135]: info: sendMpdCommand status took 29 milliseconds Oct 27 00:09:08 minidsp-shd volumio[22135]: info: sendMpdCommand status took 20 milliseconds Oct 27 00:09:08 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseState Oct 27 00:09:08 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 00:09:08 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseState Oct 27 00:09:08 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 00:09:08 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseState Oct 27 00:09:08 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 00:09:08 minidsp-shd volumio[22135]: info: Oct 27 00:09:08 minidsp-shd volumio[22135]: ---------------------------- MPD announces state update: player Oct 27 00:09:08 minidsp-shd volumio[22135]: info: ControllerMpd::getState Oct 27 00:09:08 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand status Oct 27 00:09:08 minidsp-shd volumio[22135]: info: Oct 27 00:09:08 minidsp-shd volumio[22135]: ---------------------------- MPD announces state update: player Oct 27 00:09:08 minidsp-shd volumio[22135]: info: ControllerMpd::getState Oct 27 00:09:08 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand status Oct 27 00:09:08 minidsp-shd volumio[22135]: info: sendMpdCommand status took 51 milliseconds Oct 27 00:09:08 minidsp-shd volumio[22135]: info: sendMpdCommand playlistinfo took 39 milliseconds Oct 27 00:09:08 minidsp-shd volumio[22135]: info: sendMpdCommand playlistinfo took 35 milliseconds Oct 27 00:09:08 minidsp-shd volumio[22135]: info: sendMpdCommand playlistinfo took 34 milliseconds Oct 27 00:09:08 minidsp-shd volumio[22135]: info: sendMpdCommand status took 24 milliseconds Oct 27 00:09:08 minidsp-shd volumio[22135]: info: sendMpdCommand status took 11 milliseconds Oct 27 00:09:08 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseState Oct 27 00:09:08 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 00:09:08 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseTrackInfo Oct 27 00:09:08 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseTrackInfo Oct 27 00:09:08 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseTrackInfo Oct 27 00:09:08 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseState Oct 27 00:09:08 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 00:09:08 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseState Oct 27 00:09:08 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 00:09:08 minidsp-shd volumio[22135]: info: ControllerMpd::pushState Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreCommandRouter::servicePushState Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 959 Oct 27 00:09:08 minidsp-shd volumio[22135]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":147,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"130290818","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/130290818","trackType":"qobuz"} Oct 27 00:09:08 minidsp-shd volumio[22135]: verbose: CURRENT POSITION 959 Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState stateService play Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState currentStatus stop Oct 27 00:09:08 minidsp-shd volumio[22135]: info: ControllerMpd::pushState Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreCommandRouter::servicePushState Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 959 Oct 27 00:09:08 minidsp-shd volumio[22135]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":147,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"130290818","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/130290818","trackType":"qobuz"} Oct 27 00:09:08 minidsp-shd volumio[22135]: verbose: CURRENT POSITION 959 Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState stateService play Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState currentStatus play Oct 27 00:09:08 minidsp-shd volumio[22135]: info: Received an update from plugin. extracting info from payload Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:08 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:08 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:08 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:08 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:08 minidsp-shd volumio[22135]: info: ControllerMpd::pushState Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreCommandRouter::servicePushState Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 959 Oct 27 00:09:08 minidsp-shd volumio[22135]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":147,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"130290818","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/130290818","trackType":"qobuz"} Oct 27 00:09:08 minidsp-shd volumio[22135]: verbose: CURRENT POSITION 959 Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState stateService play Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState currentStatus play Oct 27 00:09:08 minidsp-shd volumio[22135]: info: Received an update from plugin. extracting info from payload Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:08 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:08 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:08 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:08 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:08 minidsp-shd volumio[22135]: info: ------------------------------ 206ms Oct 27 00:09:08 minidsp-shd volumio[22135]: info: ------------------------------ 233ms Oct 27 00:09:08 minidsp-shd volumio[22135]: info: ------------------------------ 228ms Oct 27 00:09:08 minidsp-shd volumio[22135]: info: sendMpdCommand playlistinfo took 150 milliseconds Oct 27 00:09:08 minidsp-shd volumio[22135]: info: sendMpdCommand playlistinfo took 146 milliseconds Oct 27 00:09:08 minidsp-shd volumio[22135]: info: sendMpdCommand playlistinfo took 146 milliseconds Oct 27 00:09:08 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseTrackInfo Oct 27 00:09:08 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseTrackInfo Oct 27 00:09:08 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseTrackInfo Oct 27 00:09:08 minidsp-shd volumio[22135]: info: ControllerMpd::pushState Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreCommandRouter::servicePushState Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 959 Oct 27 00:09:08 minidsp-shd volumio[22135]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":147,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"130290818","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/130290818","trackType":"qobuz"} Oct 27 00:09:08 minidsp-shd volumio[22135]: verbose: CURRENT POSITION 959 Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState stateService play Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState currentStatus play Oct 27 00:09:08 minidsp-shd volumio[22135]: info: Received an update from plugin. extracting info from payload Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:08 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:08 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:08 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:08 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:08 minidsp-shd volumio[22135]: info: ControllerMpd::pushState Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreCommandRouter::servicePushState Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 959 Oct 27 00:09:08 minidsp-shd volumio[22135]: verbose: STATE SERVICE {"status":"play","position":0,"seek":965,"duration":147,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1281 Kbps","isStreaming":false,"title":"130290818","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/130290818","trackType":"qobuz"} Oct 27 00:09:08 minidsp-shd volumio[22135]: verbose: CURRENT POSITION 959 Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState stateService play Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState currentStatus play Oct 27 00:09:08 minidsp-shd volumio[22135]: info: Received an update from plugin. extracting info from payload Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:08 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:08 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:08 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:08 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:08 minidsp-shd volumio[22135]: info: ControllerMpd::pushState Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreCommandRouter::servicePushState Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 959 Oct 27 00:09:08 minidsp-shd volumio[22135]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1112,"duration":147,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1310 Kbps","isStreaming":false,"title":"130290818","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/130290818","trackType":"qobuz"} Oct 27 00:09:08 minidsp-shd volumio[22135]: verbose: CURRENT POSITION 959 Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState stateService play Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState currentStatus play Oct 27 00:09:08 minidsp-shd volumio[22135]: info: Received an update from plugin. extracting info from payload Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:08 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:08 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:08 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:08 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:08 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:08 minidsp-shd volumio[22135]: info: ------------------------------ 379ms Oct 27 00:09:08 minidsp-shd volumio[22135]: info: ------------------------------ 351ms Oct 27 00:09:08 minidsp-shd volumio[22135]: info: ------------------------------ 339ms Oct 27 00:09:10 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioSeek Oct 27 00:09:10 minidsp-shd volumio[22135]: info: CoreStateMachine::seek Oct 27 00:09:10 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 959 Oct 27 00:09:10 minidsp-shd volumio[22135]: info: TRACKBLOCK {"uri":"qobuz://song/130290818","service":"qobuz","name":"SPACED OUT, PHASED OUT","title":"SPACED OUT, PHASED OUT","album":"AFTER DINNER WE TALK DREAMS","type":"track","tracknumber":13,"volumeNumber":1,"albumart":"https://static.qobuz.com/images/covers/4b/xb/xvwaje0v2xb4b_600.jpg","duration":146,"explicit":false,"artist":"Michelle","artistUri":"qobuz://artist/139705","albumUri":"qobuz://album/xvwaje0v2xb4b","audioQuality":"","tagImage":""} Oct 27 00:09:10 minidsp-shd volumio[22135]: info: CoreStateMachine::startPlaybackTimer Oct 27 00:09:10 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 959 Oct 27 00:09:10 minidsp-shd volumio[22135]: info: [1729973350674] ControllerQobuz::seek Oct 27 00:09:10 minidsp-shd volumio[22135]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 27 00:09:10 minidsp-shd volumio[22135]: info: ControllerMpd::seek Oct 27 00:09:10 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:10 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 27 00:09:10 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:10 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:10 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:10 minidsp-shd volumio[22135]: STREAMING PROXY: Client dropped request, destroying Oct 27 00:09:10 minidsp-shd volumio[22135]: STREAMING PROXY: Handling url /?data=qobuz://song/130290818 Oct 27 00:09:10 minidsp-shd volumio[22135]: info: Executing endpoint getStreamUrlqobuz Oct 27 00:09:10 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 27 00:09:11 minidsp-shd volumio[22135]: info: getStreamUrl took 1167 milliseconds Oct 27 00:09:11 minidsp-shd volumio[22135]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=640488&eid=130290818&fmt=7&profile=raw&app_id=539451548&cid=1486318&etsp=1729976951&hmac=gOpJa-EP3Tcl5RGPGNPWcxdy5Zo Oct 27 00:09:11 minidsp-shd volumio[22135]: STREAMING PROXY: Got range request: bytes=5945637- Oct 27 00:09:11 minidsp-shd volumio[22135]: STREAMING PROXY: Response: 206, length: 26553968 Oct 27 00:09:11 minidsp-shd volumio[22135]: error: null Oct 27 00:09:11 minidsp-shd volumio[22135]: info: Oct 27 00:09:11 minidsp-shd volumio[22135]: ---------------------------- MPD announces state update: player Oct 27 00:09:11 minidsp-shd volumio[22135]: info: ControllerMpd::getState Oct 27 00:09:11 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand status Oct 27 00:09:11 minidsp-shd volumio[22135]: info: Oct 27 00:09:11 minidsp-shd volumio[22135]: ---------------------------- MPD announces state update: player Oct 27 00:09:11 minidsp-shd volumio[22135]: info: ControllerMpd::getState Oct 27 00:09:11 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand status Oct 27 00:09:11 minidsp-shd volumio[22135]: info: Oct 27 00:09:11 minidsp-shd volumio[22135]: ---------------------------- MPD announces state update: player Oct 27 00:09:11 minidsp-shd volumio[22135]: info: ControllerMpd::getState Oct 27 00:09:11 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand status Oct 27 00:09:11 minidsp-shd volumio[22135]: info: sendMpdCommand status took 13 milliseconds Oct 27 00:09:11 minidsp-shd volumio[22135]: info: sendMpdCommand status took 10 milliseconds Oct 27 00:09:11 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseState Oct 27 00:09:11 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 00:09:11 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseState Oct 27 00:09:11 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 00:09:12 minidsp-shd volumio[22135]: info: sendMpdCommand status took 15 milliseconds Oct 27 00:09:12 minidsp-shd volumio[22135]: info: sendMpdCommand playlistinfo took 8 milliseconds Oct 27 00:09:12 minidsp-shd volumio[22135]: info: sendMpdCommand playlistinfo took 7 milliseconds Oct 27 00:09:12 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseState Oct 27 00:09:12 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 00:09:12 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseTrackInfo Oct 27 00:09:12 minidsp-shd volumio[22135]: info: ControllerMpd::pushState Oct 27 00:09:12 minidsp-shd volumio[22135]: info: CoreCommandRouter::servicePushState Oct 27 00:09:12 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 959 Oct 27 00:09:12 minidsp-shd volumio[22135]: verbose: STATE SERVICE {"status":"play","position":0,"seek":28000,"duration":147,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1418 Kbps","isStreaming":false,"title":"130290818","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/130290818","trackType":"qobuz"} Oct 27 00:09:12 minidsp-shd volumio[22135]: verbose: CURRENT POSITION 959 Oct 27 00:09:12 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState stateService play Oct 27 00:09:12 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState currentStatus play Oct 27 00:09:12 minidsp-shd volumio[22135]: info: Received an update from plugin. extracting info from payload Oct 27 00:09:12 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:12 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 27 00:09:12 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:12 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:12 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:12 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:12 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:12 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:12 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:12 minidsp-shd volumio[22135]: info: ControllerMpd::pushState Oct 27 00:09:12 minidsp-shd volumio[22135]: info: CoreCommandRouter::servicePushState Oct 27 00:09:12 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 959 Oct 27 00:09:12 minidsp-shd volumio[22135]: verbose: STATE SERVICE {"status":"play","position":0,"seek":28000,"duration":147,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1418 Kbps","isStreaming":false,"title":"130290818","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/130290818","trackType":"qobuz"} Oct 27 00:09:12 minidsp-shd volumio[22135]: verbose: CURRENT POSITION 959 Oct 27 00:09:12 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState stateService play Oct 27 00:09:12 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState currentStatus play Oct 27 00:09:12 minidsp-shd volumio[22135]: info: Received an update from plugin. extracting info from payload Oct 27 00:09:12 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:12 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:12 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:12 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:12 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:12 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:12 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:12 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:12 minidsp-shd volumio[22135]: info: ------------------------------ 145ms Oct 27 00:09:12 minidsp-shd volumio[22135]: info: ------------------------------ 144ms Oct 27 00:09:12 minidsp-shd volumio[22135]: info: sendMpdCommand playlistinfo took 120 milliseconds Oct 27 00:09:12 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseTrackInfo Oct 27 00:09:12 minidsp-shd volumio[22135]: info: ControllerMpd::pushState Oct 27 00:09:12 minidsp-shd volumio[22135]: info: CoreCommandRouter::servicePushState Oct 27 00:09:12 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 959 Oct 27 00:09:12 minidsp-shd volumio[22135]: verbose: STATE SERVICE {"status":"play","position":0,"seek":28000,"duration":147,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1418 Kbps","isStreaming":false,"title":"130290818","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/130290818","trackType":"qobuz"} Oct 27 00:09:12 minidsp-shd volumio[22135]: verbose: CURRENT POSITION 959 Oct 27 00:09:12 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState stateService play Oct 27 00:09:12 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState currentStatus play Oct 27 00:09:12 minidsp-shd volumio[22135]: info: Received an update from plugin. extracting info from payload Oct 27 00:09:12 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:12 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 27 00:09:12 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:12 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:12 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:12 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:12 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:12 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:12 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:12 minidsp-shd volumio[22135]: info: ------------------------------ 203ms Oct 27 00:09:12 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 27 00:09:12 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 27 00:09:12 minidsp-shd volumio[22135]: info: Discovery: Getting this device information Oct 27 00:09:12 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioGetState Oct 27 00:09:12 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 27 00:09:15 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioNext Oct 27 00:09:15 minidsp-shd volumio[22135]: info: CoreStateMachine::next Oct 27 00:09:15 minidsp-shd volumio[22135]: info: [1729973355795] ControllerQobuz::next Oct 27 00:09:15 minidsp-shd volumio[22135]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 27 00:09:15 minidsp-shd volumio[22135]: info: CoreStateMachine::next Oct 27 00:09:15 minidsp-shd volumio[22135]: info: CoreStateMachine::stop Oct 27 00:09:15 minidsp-shd volumio[22135]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 27 00:09:15 minidsp-shd volumio[22135]: info: CoreStateMachine::stPlaybackTimer Oct 27 00:09:15 minidsp-shd volumio[22135]: info: CoreStateMachine::updateTrackBlock Oct 27 00:09:15 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrackBlock Oct 27 00:09:15 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:15 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 959 Oct 27 00:09:15 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 27 00:09:15 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:15 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:15 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:15 minidsp-shd volumio[22135]: info: CoreStateMachine::serviceStop Oct 27 00:09:15 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 959 Oct 27 00:09:15 minidsp-shd volumio[22135]: info: CoreCommandRouter::serviceStop Oct 27 00:09:15 minidsp-shd volumio[22135]: info: [1729973355827] ControllerQobuz::stop Oct 27 00:09:15 minidsp-shd volumio[22135]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 27 00:09:15 minidsp-shd volumio[22135]: info: ControllerMpd::stop Oct 27 00:09:15 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand stop Oct 27 00:09:15 minidsp-shd volumio[22135]: STREAMING PROXY: Client dropped request, destroying Oct 27 00:09:15 minidsp-shd volumio[22135]: info: Oct 27 00:09:15 minidsp-shd volumio[22135]: ---------------------------- MPD announces state update: player Oct 27 00:09:15 minidsp-shd volumio[22135]: info: sendMpdCommand stop took 44 milliseconds Oct 27 00:09:15 minidsp-shd volumio[22135]: info: ControllerMpd::getState Oct 27 00:09:15 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand status Oct 27 00:09:15 minidsp-shd volumio[22135]: info: CoreStateMachine::play index undefined Oct 27 00:09:15 minidsp-shd volumio[22135]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 27 00:09:15 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 960 Oct 27 00:09:15 minidsp-shd volumio[22135]: info: CoreStateMachine::startPlaybackTimer Oct 27 00:09:15 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 960 Oct 27 00:09:15 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioGetVisibleSources Oct 27 00:09:15 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 27 00:09:15 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 27 00:09:15 minidsp-shd volumio[22135]: info: [1729973355886] ControllerQobuz::clearAddPlayTrack Oct 27 00:09:15 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand stop Oct 27 00:09:15 minidsp-shd volumio[22135]: info: CoreStateMachine::updateTrackBlock Oct 27 00:09:15 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrackBlock Oct 27 00:09:15 minidsp-shd volumio[22135]: info: Oct 27 00:09:15 minidsp-shd volumio[22135]: ---------------------------- MPD announces state update: player Oct 27 00:09:15 minidsp-shd volumio[22135]: info: ControllerMpd::getState Oct 27 00:09:15 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand status Oct 27 00:09:15 minidsp-shd volumio[22135]: info: Oct 27 00:09:15 minidsp-shd volumio[22135]: ---------------------------- MPD announces state update: player Oct 27 00:09:15 minidsp-shd volumio[22135]: info: ControllerMpd::getState Oct 27 00:09:15 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand status Oct 27 00:09:15 minidsp-shd volumio[22135]: info: sendMpdCommand status took 22 milliseconds Oct 27 00:09:15 minidsp-shd volumio[22135]: info: sendMpdCommand stop took 11 milliseconds Oct 27 00:09:15 minidsp-shd volumio[22135]: info: sendMpdCommand status took 8 milliseconds Oct 27 00:09:15 minidsp-shd volumio[22135]: info: sendMpdCommand status took 5 milliseconds Oct 27 00:09:15 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseState Oct 27 00:09:15 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 00:09:15 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand clear Oct 27 00:09:15 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseState Oct 27 00:09:15 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 00:09:15 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseState Oct 27 00:09:15 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 00:09:15 minidsp-shd volumio[22135]: info: Oct 27 00:09:15 minidsp-shd volumio[22135]: ---------------------------- MPD announces system playlist update Oct 27 00:09:15 minidsp-shd volumio[22135]: info: Ignoring MPD Status Update Oct 27 00:09:15 minidsp-shd volumio[22135]: info: sendMpdCommand playlistinfo took 12 milliseconds Oct 27 00:09:15 minidsp-shd volumio[22135]: info: sendMpdCommand clear took 11 milliseconds Oct 27 00:09:15 minidsp-shd volumio[22135]: info: sendMpdCommand playlistinfo took 11 milliseconds Oct 27 00:09:15 minidsp-shd volumio[22135]: info: sendMpdCommand playlistinfo took 11 milliseconds Oct 27 00:09:15 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseTrackInfo Oct 27 00:09:15 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/130290819" Oct 27 00:09:15 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseTrackInfo Oct 27 00:09:15 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseTrackInfo Oct 27 00:09:15 minidsp-shd volumio[22135]: info: ControllerMpd::pushState Oct 27 00:09:15 minidsp-shd volumio[22135]: info: CoreCommandRouter::servicePushState Oct 27 00:09:15 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:15 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 960 Oct 27 00:09:15 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 27 00:09:15 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:15 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:15 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:15 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 960 Oct 27 00:09:15 minidsp-shd volumio[22135]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Oct 27 00:09:15 minidsp-shd volumio[22135]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Oct 27 00:09:15 minidsp-shd volumio[22135]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Oct 27 00:09:15 minidsp-shd volumio[22135]: STREAMING PROXY: Handling url /?data=qobuz://song/130290819 Oct 27 00:09:15 minidsp-shd volumio[22135]: info: ------------------------------ 84ms Oct 27 00:09:15 minidsp-shd volumio[22135]: info: ------------------------------ 68ms Oct 27 00:09:15 minidsp-shd volumio[22135]: info: ------------------------------ 64ms Oct 27 00:09:15 minidsp-shd volumio[22135]: info: Oct 27 00:09:15 minidsp-shd volumio[22135]: ---------------------------- MPD announces system playlist update Oct 27 00:09:15 minidsp-shd volumio[22135]: info: Ignoring MPD Status Update Oct 27 00:09:15 minidsp-shd volumio[22135]: info: Oct 27 00:09:15 minidsp-shd volumio[22135]: ---------------------------- MPD announces system playlist update Oct 27 00:09:15 minidsp-shd volumio[22135]: info: Ignoring MPD Status Update Oct 27 00:09:15 minidsp-shd volumio[22135]: error: updateQueue error: null Oct 27 00:09:15 minidsp-shd volumio[22135]: info: ------------------------------ 55ms Oct 27 00:09:15 minidsp-shd volumio[22135]: info: Executing endpoint getStreamUrlqobuz Oct 27 00:09:15 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 27 00:09:17 minidsp-shd volumio[22135]: info: getStreamUrl took 1270 milliseconds Oct 27 00:09:17 minidsp-shd volumio[22135]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=640488&eid=130290819&fmt=7&profile=raw&app_id=539451548&cid=1486318&etsp=1729976957&hmac=DJLHvNyK0yJ7LgpBvQ5AaaIP7HM Oct 27 00:09:17 minidsp-shd volumio[22135]: STREAMING PROXY: Response: 200, length: 45630613 Oct 27 00:09:17 minidsp-shd volumio[22135]: STREAMING PROXY: Client dropped request, destroying Oct 27 00:09:17 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/130290819" Oct 27 00:09:17 minidsp-shd volumio[22135]: error: updateQueue error: null Oct 27 00:09:17 minidsp-shd volumio[22135]: error: updateQueue error: null Oct 27 00:09:17 minidsp-shd volumio[22135]: info: Oct 27 00:09:17 minidsp-shd volumio[22135]: ---------------------------- MPD announces system playlist update Oct 27 00:09:17 minidsp-shd volumio[22135]: info: Ignoring MPD Status Update Oct 27 00:09:17 minidsp-shd volumio[22135]: info: ------------------------------ 1832ms Oct 27 00:09:17 minidsp-shd volumio[22135]: info: ------------------------------ 1830ms Oct 27 00:09:17 minidsp-shd volumio[22135]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/130290819" took 7 milliseconds Oct 27 00:09:17 minidsp-shd volumio[22135]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 27 00:09:17 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand play Oct 27 00:09:17 minidsp-shd volumio[22135]: info: Oct 27 00:09:17 minidsp-shd volumio[22135]: ---------------------------- MPD announces system playlist update Oct 27 00:09:17 minidsp-shd volumio[22135]: info: Ignoring MPD Status Update Oct 27 00:09:17 minidsp-shd volumio[22135]: info: Oct 27 00:09:17 minidsp-shd volumio[22135]: ---------------------------- MPD announces system playlist update Oct 27 00:09:17 minidsp-shd volumio[22135]: info: Ignoring MPD Status Update Oct 27 00:09:17 minidsp-shd volumio[22135]: STREAMING PROXY: Handling url /?data=qobuz://song/130290819 Oct 27 00:09:17 minidsp-shd volumio[22135]: info: ------------------------------ 14ms Oct 27 00:09:17 minidsp-shd volumio[22135]: info: sendMpdCommand play took 11 milliseconds Oct 27 00:09:17 minidsp-shd volumio[22135]: info: ------------------------------ 10ms Oct 27 00:09:17 minidsp-shd volumio[22135]: info: ------------------------------ 7ms Oct 27 00:09:17 minidsp-shd volumio[22135]: info: Executing endpoint getStreamUrlqobuz Oct 27 00:09:17 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 27 00:09:19 minidsp-shd volumio[22135]: info: getStreamUrl took 1343 milliseconds Oct 27 00:09:19 minidsp-shd volumio[22135]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=640488&eid=130290819&fmt=7&profile=raw&app_id=539451548&cid=1486318&etsp=1729976958&hmac=ciHk4kOTe_mBwj8kCpnnkcDtPqA Oct 27 00:09:19 minidsp-shd volumio[22135]: STREAMING PROXY: Response: 200, length: 45630613 Oct 27 00:09:19 minidsp-shd volumio[22135]: info: Oct 27 00:09:19 minidsp-shd volumio[22135]: ---------------------------- MPD announces state update: player Oct 27 00:09:19 minidsp-shd volumio[22135]: info: ControllerMpd::getState Oct 27 00:09:19 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand status Oct 27 00:09:19 minidsp-shd volumio[22135]: info: Oct 27 00:09:19 minidsp-shd volumio[22135]: ---------------------------- MPD announces state update: player Oct 27 00:09:19 minidsp-shd volumio[22135]: info: ControllerMpd::getState Oct 27 00:09:19 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand status Oct 27 00:09:19 minidsp-shd volumio[22135]: info: Oct 27 00:09:19 minidsp-shd volumio[22135]: ---------------------------- MPD announces state update: player Oct 27 00:09:19 minidsp-shd volumio[22135]: info: ControllerMpd::getState Oct 27 00:09:19 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand status Oct 27 00:09:19 minidsp-shd volumio[22135]: info: Oct 27 00:09:19 minidsp-shd volumio[22135]: ---------------------------- MPD announces state update: player Oct 27 00:09:19 minidsp-shd volumio[22135]: info: ControllerMpd::getState Oct 27 00:09:19 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand status Oct 27 00:09:19 minidsp-shd volumio[22135]: info: Oct 27 00:09:19 minidsp-shd volumio[22135]: ---------------------------- MPD announces state update: player Oct 27 00:09:19 minidsp-shd volumio[22135]: info: sendMpdCommand status took 28 milliseconds Oct 27 00:09:19 minidsp-shd volumio[22135]: info: sendMpdCommand status took 23 milliseconds Oct 27 00:09:19 minidsp-shd volumio[22135]: info: ControllerMpd::getState Oct 27 00:09:19 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand status Oct 27 00:09:19 minidsp-shd volumio[22135]: info: sendMpdCommand status took 20 milliseconds Oct 27 00:09:19 minidsp-shd volumio[22135]: info: sendMpdCommand status took 13 milliseconds Oct 27 00:09:19 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseState Oct 27 00:09:19 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 00:09:19 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseState Oct 27 00:09:19 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 00:09:19 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseState Oct 27 00:09:19 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 00:09:19 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseState Oct 27 00:09:19 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 00:09:19 minidsp-shd volumio[22135]: info: Oct 27 00:09:19 minidsp-shd volumio[22135]: ---------------------------- MPD announces state update: player Oct 27 00:09:19 minidsp-shd volumio[22135]: info: ControllerMpd::getState Oct 27 00:09:19 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand status Oct 27 00:09:19 minidsp-shd volumio[22135]: info: sendMpdCommand status took 30 milliseconds Oct 27 00:09:19 minidsp-shd volumio[22135]: info: sendMpdCommand playlistinfo took 28 milliseconds Oct 27 00:09:19 minidsp-shd volumio[22135]: info: sendMpdCommand playlistinfo took 26 milliseconds Oct 27 00:09:19 minidsp-shd volumio[22135]: info: sendMpdCommand playlistinfo took 22 milliseconds Oct 27 00:09:19 minidsp-shd volumio[22135]: info: sendMpdCommand playlistinfo took 21 milliseconds Oct 27 00:09:19 minidsp-shd volumio[22135]: info: sendMpdCommand status took 10 milliseconds Oct 27 00:09:19 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseState Oct 27 00:09:19 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 00:09:19 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseTrackInfo Oct 27 00:09:19 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseTrackInfo Oct 27 00:09:19 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseTrackInfo Oct 27 00:09:19 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseState Oct 27 00:09:19 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 00:09:19 minidsp-shd volumio[22135]: info: ControllerMpd::pushState Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreCommandRouter::servicePushState Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 960 Oct 27 00:09:19 minidsp-shd volumio[22135]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":229,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"130290819","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/130290819","trackType":"qobuz"} Oct 27 00:09:19 minidsp-shd volumio[22135]: verbose: CURRENT POSITION 960 Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState stateService play Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState currentStatus stop Oct 27 00:09:19 minidsp-shd volumio[22135]: info: ControllerMpd::pushState Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreCommandRouter::servicePushState Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 960 Oct 27 00:09:19 minidsp-shd volumio[22135]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":229,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"130290819","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/130290819","trackType":"qobuz"} Oct 27 00:09:19 minidsp-shd volumio[22135]: verbose: CURRENT POSITION 960 Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState stateService play Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState currentStatus play Oct 27 00:09:19 minidsp-shd volumio[22135]: info: Received an update from plugin. extracting info from payload Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:19 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:19 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:19 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:19 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:19 minidsp-shd volumio[22135]: info: ControllerMpd::pushState Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreCommandRouter::servicePushState Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 960 Oct 27 00:09:19 minidsp-shd volumio[22135]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":229,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"130290819","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/130290819","trackType":"qobuz"} Oct 27 00:09:19 minidsp-shd volumio[22135]: verbose: CURRENT POSITION 960 Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState stateService play Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState currentStatus play Oct 27 00:09:19 minidsp-shd volumio[22135]: info: Received an update from plugin. extracting info from payload Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:19 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:19 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:19 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:19 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:19 minidsp-shd volumio[22135]: info: ControllerMpd::pushState Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreCommandRouter::servicePushState Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 960 Oct 27 00:09:19 minidsp-shd volumio[22135]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":229,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"130290819","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/130290819","trackType":"qobuz"} Oct 27 00:09:19 minidsp-shd volumio[22135]: verbose: CURRENT POSITION 960 Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState stateService play Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState currentStatus play Oct 27 00:09:19 minidsp-shd volumio[22135]: info: Received an update from plugin. extracting info from payload Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:19 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:19 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:19 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:19 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:19 minidsp-shd volumio[22135]: info: ------------------------------ 199ms Oct 27 00:09:19 minidsp-shd volumio[22135]: info: ------------------------------ 245ms Oct 27 00:09:19 minidsp-shd volumio[22135]: info: ------------------------------ 243ms Oct 27 00:09:19 minidsp-shd volumio[22135]: info: ------------------------------ 238ms Oct 27 00:09:19 minidsp-shd volumio[22135]: info: sendMpdCommand playlistinfo took 188 milliseconds Oct 27 00:09:19 minidsp-shd volumio[22135]: info: sendMpdCommand playlistinfo took 183 milliseconds Oct 27 00:09:19 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseTrackInfo Oct 27 00:09:19 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseTrackInfo Oct 27 00:09:19 minidsp-shd volumio[22135]: info: ControllerMpd::pushState Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreCommandRouter::servicePushState Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 960 Oct 27 00:09:19 minidsp-shd volumio[22135]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":229,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"130290819","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/130290819","trackType":"qobuz"} Oct 27 00:09:19 minidsp-shd volumio[22135]: verbose: CURRENT POSITION 960 Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState stateService play Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState currentStatus play Oct 27 00:09:19 minidsp-shd volumio[22135]: info: Received an update from plugin. extracting info from payload Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:19 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:19 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:19 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:19 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:19 minidsp-shd volumio[22135]: info: ControllerMpd::pushState Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreCommandRouter::servicePushState Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 960 Oct 27 00:09:19 minidsp-shd volumio[22135]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1112,"duration":229,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1751 Kbps","isStreaming":false,"title":"130290819","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/130290819","trackType":"qobuz"} Oct 27 00:09:19 minidsp-shd volumio[22135]: verbose: CURRENT POSITION 960 Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState stateService play Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState currentStatus play Oct 27 00:09:19 minidsp-shd volumio[22135]: info: Received an update from plugin. extracting info from payload Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:19 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:19 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:19 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:19 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:19 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:19 minidsp-shd volumio[22135]: info: ------------------------------ 336ms Oct 27 00:09:19 minidsp-shd volumio[22135]: info: ------------------------------ 311ms Oct 27 00:09:25 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioSeek Oct 27 00:09:25 minidsp-shd volumio[22135]: info: CoreStateMachine::seek Oct 27 00:09:25 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 960 Oct 27 00:09:25 minidsp-shd volumio[22135]: info: TRACKBLOCK {"uri":"qobuz://song/130290819","service":"qobuz","name":"MY FRIENDS","title":"MY FRIENDS","album":"AFTER DINNER WE TALK DREAMS","type":"track","tracknumber":14,"volumeNumber":1,"albumart":"https://static.qobuz.com/images/covers/4b/xb/xvwaje0v2xb4b_600.jpg","duration":229,"explicit":false,"artist":"Michelle","artistUri":"qobuz://artist/139705","albumUri":"qobuz://album/xvwaje0v2xb4b","audioQuality":"","tagImage":""} Oct 27 00:09:25 minidsp-shd volumio[22135]: info: CoreStateMachine::startPlaybackTimer Oct 27 00:09:25 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 960 Oct 27 00:09:25 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioGetVisibleSources Oct 27 00:09:25 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 27 00:09:25 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 27 00:09:25 minidsp-shd volumio[22135]: info: [1729973365054] ControllerQobuz::seek Oct 27 00:09:25 minidsp-shd volumio[22135]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 27 00:09:25 minidsp-shd volumio[22135]: info: ControllerMpd::seek Oct 27 00:09:25 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:25 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 27 00:09:25 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:25 minidsp-shd volumio[22135]: STREAMING PROXY: Client dropped request, destroying Oct 27 00:09:25 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:25 minidsp-shd volumio[22135]: STREAMING PROXY: Handling url /?data=qobuz://song/130290819 Oct 27 00:09:25 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:25 minidsp-shd volumio[22135]: info: Executing endpoint getStreamUrlqobuz Oct 27 00:09:25 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 27 00:09:26 minidsp-shd volumio[22135]: info: getStreamUrl took 1696 milliseconds Oct 27 00:09:26 minidsp-shd volumio[22135]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=640488&eid=130290819&fmt=7&profile=raw&app_id=539451548&cid=1486318&etsp=1729976966&hmac=L0jGXFBKrg7eNfJPOBvwUVuyy3I Oct 27 00:09:26 minidsp-shd volumio[22135]: STREAMING PROXY: Got range request: bytes=13389840- Oct 27 00:09:26 minidsp-shd volumio[22135]: STREAMING PROXY: Response: 206, length: 32240773 Oct 27 00:09:26 minidsp-shd volumio[22135]: error: null Oct 27 00:09:26 minidsp-shd volumio[22135]: info: Oct 27 00:09:26 minidsp-shd volumio[22135]: ---------------------------- MPD announces state update: player Oct 27 00:09:26 minidsp-shd volumio[22135]: info: ControllerMpd::getState Oct 27 00:09:26 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand status Oct 27 00:09:27 minidsp-shd volumio[22135]: info: Oct 27 00:09:27 minidsp-shd volumio[22135]: ---------------------------- MPD announces state update: player Oct 27 00:09:27 minidsp-shd volumio[22135]: info: ControllerMpd::getState Oct 27 00:09:27 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand status Oct 27 00:09:27 minidsp-shd volumio[22135]: info: Oct 27 00:09:27 minidsp-shd volumio[22135]: ---------------------------- MPD announces state update: player Oct 27 00:09:27 minidsp-shd volumio[22135]: info: ControllerMpd::getState Oct 27 00:09:27 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand status Oct 27 00:09:27 minidsp-shd volumio[22135]: info: sendMpdCommand status took 21 milliseconds Oct 27 00:09:27 minidsp-shd volumio[22135]: info: sendMpdCommand status took 14 milliseconds Oct 27 00:09:27 minidsp-shd volumio[22135]: info: sendMpdCommand status took 8 milliseconds Oct 27 00:09:27 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseState Oct 27 00:09:27 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 00:09:27 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseState Oct 27 00:09:27 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 00:09:27 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseState Oct 27 00:09:27 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 00:09:27 minidsp-shd volumio[22135]: info: sendMpdCommand playlistinfo took 9 milliseconds Oct 27 00:09:27 minidsp-shd volumio[22135]: info: sendMpdCommand playlistinfo took 8 milliseconds Oct 27 00:09:27 minidsp-shd volumio[22135]: info: sendMpdCommand playlistinfo took 7 milliseconds Oct 27 00:09:27 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseTrackInfo Oct 27 00:09:27 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseTrackInfo Oct 27 00:09:27 minidsp-shd volumio[22135]: info: ControllerMpd::pushState Oct 27 00:09:27 minidsp-shd volumio[22135]: info: CoreCommandRouter::servicePushState Oct 27 00:09:27 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 960 Oct 27 00:09:27 minidsp-shd volumio[22135]: verbose: STATE SERVICE {"status":"play","position":0,"seek":61000,"duration":229,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1708 Kbps","isStreaming":false,"title":"130290819","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/130290819","trackType":"qobuz"} Oct 27 00:09:27 minidsp-shd volumio[22135]: verbose: CURRENT POSITION 960 Oct 27 00:09:27 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState stateService play Oct 27 00:09:27 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState currentStatus play Oct 27 00:09:27 minidsp-shd volumio[22135]: info: Received an update from plugin. extracting info from payload Oct 27 00:09:27 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:27 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 27 00:09:27 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:27 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:27 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:27 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:27 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:27 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:27 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:27 minidsp-shd volumio[22135]: info: ControllerMpd::pushState Oct 27 00:09:27 minidsp-shd volumio[22135]: info: CoreCommandRouter::servicePushState Oct 27 00:09:27 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 960 Oct 27 00:09:27 minidsp-shd volumio[22135]: verbose: STATE SERVICE {"status":"play","position":0,"seek":61000,"duration":229,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1708 Kbps","isStreaming":false,"title":"130290819","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/130290819","trackType":"qobuz"} Oct 27 00:09:27 minidsp-shd volumio[22135]: verbose: CURRENT POSITION 960 Oct 27 00:09:27 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState stateService play Oct 27 00:09:27 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState currentStatus play Oct 27 00:09:27 minidsp-shd volumio[22135]: info: Received an update from plugin. extracting info from payload Oct 27 00:09:27 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:27 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:27 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:27 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:27 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:27 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:27 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:27 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:27 minidsp-shd volumio[22135]: info: ControllerMpd::pushState Oct 27 00:09:27 minidsp-shd volumio[22135]: info: CoreCommandRouter::servicePushState Oct 27 00:09:27 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 960 Oct 27 00:09:27 minidsp-shd volumio[22135]: verbose: STATE SERVICE {"status":"play","position":0,"seek":61000,"duration":229,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1708 Kbps","isStreaming":false,"title":"130290819","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/130290819","trackType":"qobuz"} Oct 27 00:09:27 minidsp-shd volumio[22135]: verbose: CURRENT POSITION 960 Oct 27 00:09:27 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState stateService play Oct 27 00:09:27 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState currentStatus play Oct 27 00:09:27 minidsp-shd volumio[22135]: info: Received an update from plugin. extracting info from payload Oct 27 00:09:27 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:27 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:27 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:27 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:27 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:27 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:27 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:27 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:27 minidsp-shd volumio[22135]: info: ------------------------------ 196ms Oct 27 00:09:27 minidsp-shd volumio[22135]: info: ------------------------------ 189ms Oct 27 00:09:27 minidsp-shd volumio[22135]: info: ------------------------------ 187ms Oct 27 00:09:33 minidsp-shd ntpd[798]: Soliciting pool server 2001:ac8:81:65:0:2:0:2 Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioNext Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreStateMachine::next Oct 27 00:09:34 minidsp-shd volumio[22135]: info: [1729973374633] ControllerQobuz::next Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreStateMachine::next Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreStateMachine::stop Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreStateMachine::stPlaybackTimer Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreStateMachine::updateTrackBlock Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrackBlock Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 960 Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:34 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:34 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreStateMachine::serviceStop Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 960 Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreCommandRouter::serviceStop Oct 27 00:09:34 minidsp-shd volumio[22135]: info: [1729973374662] ControllerQobuz::stop Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 27 00:09:34 minidsp-shd volumio[22135]: info: ControllerMpd::stop Oct 27 00:09:34 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand stop Oct 27 00:09:34 minidsp-shd volumio[22135]: STREAMING PROXY: Client dropped request, destroying Oct 27 00:09:34 minidsp-shd volumio[22135]: info: Oct 27 00:09:34 minidsp-shd volumio[22135]: ---------------------------- MPD announces state update: player Oct 27 00:09:34 minidsp-shd volumio[22135]: info: sendMpdCommand stop took 47 milliseconds Oct 27 00:09:34 minidsp-shd volumio[22135]: info: ControllerMpd::getState Oct 27 00:09:34 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand status Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreStateMachine::play index undefined Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 961 Oct 27 00:09:34 minidsp-shd volumio[22135]: info: Oct 27 00:09:34 minidsp-shd volumio[22135]: ---------------------------- MPD announces state update: player Oct 27 00:09:34 minidsp-shd volumio[22135]: info: ControllerMpd::getState Oct 27 00:09:34 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand status Oct 27 00:09:34 minidsp-shd volumio[22135]: info: Oct 27 00:09:34 minidsp-shd volumio[22135]: ---------------------------- MPD announces state update: player Oct 27 00:09:34 minidsp-shd volumio[22135]: info: ControllerMpd::getState Oct 27 00:09:34 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand status Oct 27 00:09:34 minidsp-shd volumio[22135]: info: sendMpdCommand status took 14 milliseconds Oct 27 00:09:34 minidsp-shd volumio[22135]: info: sendMpdCommand status took 8 milliseconds Oct 27 00:09:34 minidsp-shd volumio[22135]: info: sendMpdCommand status took 6 milliseconds Oct 27 00:09:34 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseState Oct 27 00:09:34 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 00:09:34 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseState Oct 27 00:09:34 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 00:09:34 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseState Oct 27 00:09:34 minidsp-shd volumio[22135]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 00:09:34 minidsp-shd volumio[22135]: info: sendMpdCommand playlistinfo took 6 milliseconds Oct 27 00:09:34 minidsp-shd volumio[22135]: info: sendMpdCommand playlistinfo took 5 milliseconds Oct 27 00:09:34 minidsp-shd volumio[22135]: info: sendMpdCommand playlistinfo took 5 milliseconds Oct 27 00:09:34 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseTrackInfo Oct 27 00:09:34 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseTrackInfo Oct 27 00:09:34 minidsp-shd volumio[22135]: verbose: ControllerMpd::parseTrackInfo Oct 27 00:09:34 minidsp-shd volumio[22135]: info: ControllerMpd::pushState Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreCommandRouter::servicePushState Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 0 Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:34 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:34 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 0 Oct 27 00:09:34 minidsp-shd volumio[22135]: 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":"130290819","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/130290819","trackType":"qobuz"} Oct 27 00:09:34 minidsp-shd volumio[22135]: verbose: CURRENT POSITION 0 Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState stateService stop Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState currentStatus stop Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 0 Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:34 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:34 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:34 minidsp-shd volumio[22135]: info: No code Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 0 Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:34 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:34 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:34 minidsp-shd volumio[22135]: info: ControllerMpd::pushState Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreCommandRouter::servicePushState Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 0 Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:34 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:34 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 0 Oct 27 00:09:34 minidsp-shd volumio[22135]: 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":"130290819","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/130290819","trackType":"qobuz"} Oct 27 00:09:34 minidsp-shd volumio[22135]: verbose: CURRENT POSITION 0 Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState stateService stop Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState currentStatus stop Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 0 Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:34 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:34 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:34 minidsp-shd volumio[22135]: info: No code Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 0 Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:34 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:34 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:34 minidsp-shd volumio[22135]: info: ControllerMpd::pushState Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreCommandRouter::servicePushState Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 0 Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:34 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:34 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 0 Oct 27 00:09:34 minidsp-shd volumio[22135]: 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":"130290819","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/130290819","trackType":"qobuz"} Oct 27 00:09:34 minidsp-shd volumio[22135]: verbose: CURRENT POSITION 0 Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState stateService stop Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreStateMachine::syncState currentStatus stop Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 0 Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:34 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:34 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:34 minidsp-shd volumio[22135]: info: No code Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreStateMachine::pushState Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 0 Oct 27 00:09:34 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioPushState Oct 27 00:09:34 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output update for this device Oct 27 00:09:34 minidsp-shd volumio[22135]: info: MRS: Pushing multiroomSync output Oct 27 00:09:34 minidsp-shd volumio[22135]: info: ------------------------------ 168ms Oct 27 00:09:34 minidsp-shd volumio[22135]: info: ------------------------------ 163ms Oct 27 00:09:34 minidsp-shd volumio[22135]: info: ------------------------------ 163ms Oct 27 00:09:37 minidsp-shd volumio[22135]: info: Executing endpoint metavolumio Oct 27 00:09:37 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 27 00:09:37 minidsp-shd volumio[22135]: info: Executing endpoint metavolumio Oct 27 00:09:37 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 27 00:09:42 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 27 00:09:42 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 27 00:09:42 minidsp-shd volumio[22135]: info: Discovery: Getting this device information Oct 27 00:09:42 minidsp-shd volumio[22135]: info: CoreCommandRouter::volumioGetState Oct 27 00:09:42 minidsp-shd volumio[22135]: info: CorePlayQueue::getTrack 0 Oct 27 00:09:42 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 27 00:09:44 minidsp-shd volumio[22135]: info: Executing endpoint metavolumio Oct 27 00:09:44 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 27 00:10:00 minidsp-shd volumio[22135]: Searching all installed plugins Oct 27 00:10:00 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 27 00:10:00 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: , search Oct 27 00:10:00 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: mpd , search Oct 27 00:10:00 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Oct 27 00:10:00 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Oct 27 00:10:00 minidsp-shd volumio[22135]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Oct 27 00:10:00 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: webradio , search Oct 27 00:10:00 minidsp-shd volumio[22135]: info: CoreCommandRouter::executeOnPlugin: calmradio , search Oct 27 00:10:00 minidsp-shd volumio[22135]: info: [1729973400503] ControllerCalmRadio::searchCategories Oct 27 00:10:00 minidsp-shd volumio[22135]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 27 00:10:00 minidsp-shd volumio[22135]: TypeError: Cannot read property 'cats' of undefined Oct 27 00:10:00 minidsp-shd volumio[22135]: at ControllerCalmRadio.searchCategories (/data/plugins/music_service/calmradio/index.js:615:42) Oct 27 00:10:00 minidsp-shd volumio[22135]: at ControllerCalmRadio.search (/data/plugins/music_service/calmradio/index.js:665:28) Oct 27 00:10:00 minidsp-shd volumio[22135]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1077:32) Oct 27 00:10:00 minidsp-shd volumio[22135]: at CoreMusicLibrary.searchOnPlugin (/volumio/app/musiclibrary.js:668:44) Oct 27 00:10:00 minidsp-shd volumio[22135]: at CoreMusicLibrary.search (/volumio/app/musiclibrary.js:455:27) Oct 27 00:10:00 minidsp-shd volumio[22135]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:457:44) Oct 27 00:10:00 minidsp-shd volumio[22135]: at Socket.emit (events.js:400:28) Oct 27 00:10:00 minidsp-shd volumio[22135]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Oct 27 00:10:00 minidsp-shd volumio[22135]: at processTicksAndRejections (internal/process/task_queues.js:77:11) Oct 27 00:10:00 minidsp-shd volumio[22135]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 27 00:10:01 minidsp-shd sudo[24669]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-27 00:09 Oct 27 00:10:01 minidsp-shd sudo[24669]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 00:10:01 minidsp-shd sudo[24669]: pam_unix(sudo:session): session closed for user root Oct 27 00:10:01 minidsp-shd vtcs[22455]: [2024-10-27 00:10:01.772] [tisoc] [error] [SpkconServer.cpp:377] recv error. socket disconnected Oct 27 00:10:01 minidsp-shd volumio-remote-updater[451]: [2024-10-27 00:10:01] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Oct 27 00:10:01 minidsp-shd volumio-remote-updater[451]: [2024-10-27 00:10:01] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Oct 27 00:10:01 minidsp-shd systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Oct 27 00:10:01 minidsp-shd systemd[1]: volumio.service: Failed with result 'exit-code'. Oct 27 00:10:01 minidsp-shd systemd[1]: Started dynamicswap service. Oct 27 00:10:01 minidsp-shd systemd[1]: dynamicswap.service: Succeeded. Oct 27 00:10:02 minidsp-shd systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Oct 27 00:10:02 minidsp-shd systemd[1]: volumio.service: Scheduled restart job, restart counter is at 9. Oct 27 00:10:02 minidsp-shd systemd[1]: Started dynamicswap service. Oct 27 00:10:02 minidsp-shd systemd[1]: Stopped Volumio Backend Module. Oct 27 00:10:02 minidsp-shd systemd[1]: Started Volumio Backend Module. Oct 27 00:10:02 minidsp-shd systemd[1]: dynamicswap.service: Succeeded. Oct 27 00:10:05 minidsp-shd volumio[24682]: info: ------------------------------------------- Oct 27 00:10:05 minidsp-shd volumio[24682]: info: ----- Volumio3 ---- Oct 27 00:10:05 minidsp-shd volumio[24682]: info: ------------------------------------------- Oct 27 00:10:05 minidsp-shd volumio[24682]: info: ----- System startup ---- Oct 27 00:10:05 minidsp-shd volumio[24682]: info: ------------------------------------------- Oct 27 00:10:06 minidsp-shd volumio[24682]: info: MYVOLUMIO Environment detected Oct 27 00:10:06 minidsp-shd volumio[24682]: info: Plugin folders cleanup Oct 27 00:10:06 minidsp-shd volumio[24682]: info: Scanning into folder /volumio/app/plugins/ Oct 27 00:10:06 minidsp-shd volumio[24682]: info: Scanning category audio_interface Oct 27 00:10:06 minidsp-shd volumio[24682]: info: Scanning category miscellanea Oct 27 00:10:06 minidsp-shd volumio[24682]: info: Scanning category music_service Oct 27 00:10:06 minidsp-shd volumio[24682]: info: Scanning category plugins.json Oct 27 00:10:06 minidsp-shd volumio[24682]: info: Scanning category system_controller Oct 27 00:10:06 minidsp-shd volumio[24682]: info: Scanning category user_interface Oct 27 00:10:06 minidsp-shd volumio[24682]: info: Scanning into folder /data/plugins/ Oct 27 00:10:06 minidsp-shd volumio[24682]: info: Scanning category music_service Oct 27 00:10:06 minidsp-shd volumio[24682]: info: Plugin folders cleanup completed Oct 27 00:10:06 minidsp-shd volumio[24682]: info: ------------------------------------------- Oct 27 00:10:06 minidsp-shd volumio[24682]: info: ----- Core plugins startup ---- Oct 27 00:10:06 minidsp-shd volumio[24682]: info: ------------------------------------------- Oct 27 00:10:06 minidsp-shd volumio[24682]: info: Loading plugins from folder /volumio/app/plugins/ Oct 27 00:10:06 minidsp-shd volumio[24682]: info: Adding plugin bluetooth to MyMusic Plugins Oct 27 00:10:06 minidsp-shd volumio[24682]: info: Adding plugin multiroom to MyMusic Plugins Oct 27 00:10:06 minidsp-shd volumio[24682]: info: Adding plugin upnp to MyMusic Plugins Oct 27 00:10:06 minidsp-shd volumio[24682]: info: Adding plugin metavolumio to MyMusic Plugins Oct 27 00:10:06 minidsp-shd volumio[24682]: info: Adding plugin ms_surface_dial to MyMusic Plugins Oct 27 00:10:06 minidsp-shd volumio[24682]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 27 00:10:06 minidsp-shd volumio[24682]: info: Adding plugin cd_controller to MyMusic Plugins Oct 27 00:10:06 minidsp-shd volumio[24682]: info: Adding plugin raat to MyMusic Plugins Oct 27 00:10:06 minidsp-shd volumio[24682]: info: Adding plugin tidalconnect to MyMusic Plugins Oct 27 00:10:06 minidsp-shd volumio[24682]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 27 00:10:06 minidsp-shd volumio-remote-updater[451]: [2024-10-27 00:10:06] [connect] Successful connection Oct 27 00:10:06 minidsp-shd volumio[24682]: info: Loading plugins from folder /data/plugins/ Oct 27 00:10:06 minidsp-shd volumio[24682]: info: Loading plugin "system"... Oct 27 00:10:06 minidsp-shd volumio[24682]: info: Loading plugin "appearance"... Oct 27 00:10:08 minidsp-shd volumio[24682]: info: Loading plugin "network"... Oct 27 00:10:08 minidsp-shd volumio[24682]: info: Refreshing Cached IP Addresses Oct 27 00:10:08 minidsp-shd sudo[24709]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 27 00:10:08 minidsp-shd sudo[24709]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 00:10:08 minidsp-shd sudo[24709]: pam_unix(sudo:session): session closed for user root Oct 27 00:10:08 minidsp-shd volumio[24682]: info: Loading plugin "services"... Oct 27 00:10:08 minidsp-shd sudo[24711]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 27 00:10:08 minidsp-shd sudo[24711]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 00:10:08 minidsp-shd volumio[24682]: info: Loading plugin "alsa_controller"... Oct 27 00:10:08 minidsp-shd sudo[24711]: pam_unix(sudo:session): session closed for user root Oct 27 00:10:08 minidsp-shd sudo[24714]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Oct 27 00:10:08 minidsp-shd sudo[24714]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 00:10:08 minidsp-shd volumio[24682]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 27 00:10:08 minidsp-shd volumio[24682]: info: Loading plugin "wizard"... Oct 27 00:10:08 minidsp-shd volumio[24682]: info: Loading plugin "networkfs"... Oct 27 00:10:09 minidsp-shd volumio[24682]: info: Starting Udev Watcher for removable devices Oct 27 00:10:09 minidsp-shd volumio[24682]: info: Ignoring mount for partition: BOOT Oct 27 00:10:09 minidsp-shd volumio[24682]: info: Ignoring mount for partition: volumio Oct 27 00:10:09 minidsp-shd volumio[24682]: info: Ignoring mount for partition: volumio_data Oct 27 00:10:09 minidsp-shd volumio[24682]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 27 00:10:09 minidsp-shd volumio[24682]: info: Loading plugin "volumio_command_line_client"... Oct 27 00:10:09 minidsp-shd volumio[24682]: info: Loading plugin "upnp"... Oct 27 00:10:09 minidsp-shd volumio[24682]: info: [1729973409109] Starting Upmpd Daemon Oct 27 00:10:09 minidsp-shd volumio[24682]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 27 00:10:09 minidsp-shd volumio[24682]: info: Loading plugin "my_music"... Oct 27 00:10:09 minidsp-shd volumio[24682]: info: Loading plugin "mpd"... Oct 27 00:10:09 minidsp-shd volumio[24682]: info: Loading plugin "upnp_browser"... Oct 27 00:10:10 minidsp-shd volumio[24682]: info: Loading plugin "bluetooth"... Oct 27 00:10:10 minidsp-shd volumio[24682]: info: [1729973410623] Starting BluetoothController Oct 27 00:10:10 minidsp-shd volumio[24682]: info: Loading plugin "alarm-clock"... Oct 27 00:10:11 minidsp-shd volumio[24682]: info: Loading plugin "manifestui"... Oct 27 00:10:11 minidsp-shd volumio[24682]: info: Loading plugin "metavolumio"... Oct 27 00:10:13 minidsp-shd sudo[24714]: pam_unix(sudo:session): session closed for user root Oct 27 00:10:13 minidsp-shd volumio[24682]: info: Loading plugin "airplay_emulation"... Oct 27 00:10:13 minidsp-shd volumio[24682]: info: Starting Shairport Sync Oct 27 00:10:13 minidsp-shd volumio[24682]: info: Loading plugin "cd_controller"... Oct 27 00:10:13 minidsp-shd volumio[24682]: info: Loading plugin "last_100"... Oct 27 00:10:13 minidsp-shd volumio[24682]: info: Loading plugin "raat"... Oct 27 00:10:13 minidsp-shd volumio[24682]: info: RAAT Plugin loaded Oct 27 00:10:13 minidsp-shd volumio[24682]: info: Adding restartRAATSocket REST API Endpoint Oct 27 00:10:13 minidsp-shd volumio[24682]: info: Adding restartRAATSocket REST Endpoint for plugin: music_service/raat Oct 27 00:10:13 minidsp-shd volumio[24682]: info: Loading plugin "streaming_services"... Oct 27 00:10:15 minidsp-shd volumio[24682]: info: Starting Streaming Service Transparent Proxy Oct 27 00:10:15 minidsp-shd volumio[24682]: info: Loading plugin "tidalconnect"... Oct 27 00:10:15 minidsp-shd volumio[24682]: info: Loading plugin "webradio"... Oct 27 00:10:16 minidsp-shd volumio[24682]: info: Loading plugin "i2s_dacs"... Oct 27 00:10:16 minidsp-shd volumio[24682]: info: I2S DAC not set, start Auto-detection Oct 27 00:10:16 minidsp-shd volumio[24682]: info: Loading plugin "volumiodiscovery"... Oct 27 00:10:16 minidsp-shd volumio[24682]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 27 00:10:16 minidsp-shd volumio[24682]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 27 00:10:16 minidsp-shd volumio[24682]: *** WARNING *** For more information see Oct 27 00:10:16 minidsp-shd node[24682]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 27 00:10:16 minidsp-shd volumio[24682]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 27 00:10:16 minidsp-shd volumio[24682]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 27 00:10:16 minidsp-shd volumio[24682]: *** WARNING *** For more information see Oct 27 00:10:16 minidsp-shd node[24682]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 27 00:10:16 minidsp-shd node[24682]: *** WARNING *** For more information see Oct 27 00:10:16 minidsp-shd node[24682]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 27 00:10:16 minidsp-shd node[24682]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 27 00:10:16 minidsp-shd node[24682]: *** WARNING *** For more information see Oct 27 00:10:16 minidsp-shd volumio[24682]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 27 00:10:16 minidsp-shd volumio[24682]: info: Discovery: Started advertising with name: miniDSP SHD Oct 27 00:10:16 minidsp-shd volumio[24682]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 27 00:10:16 minidsp-shd volumio[24682]: info: Loading plugin "calmradio"... Oct 27 00:10:17 minidsp-shd volumio[24682]: info: Loading plugin "ytmusic"... Oct 27 00:10:18 minidsp-shd volumio[24682]: STREAMING PROXY: Starting server on port 3245 Oct 27 00:10:18 minidsp-shd volumio[24682]: Node JS runtime: 14 Oct 27 00:10:19 minidsp-shd volumio-remote-updater[451]: [2024-10-27 00:10:19] [connect] Successful connection Oct 27 00:10:19 minidsp-shd volumio[24682]: info: Loading plugin "multiroom"... Oct 27 00:10:22 minidsp-shd volumio[24682]: info: Applying required configuration parameters for plugin multiroom Oct 27 00:10:22 minidsp-shd sudo[24733]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Oct 27 00:10:22 minidsp-shd sudo[24733]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 00:10:22 minidsp-shd sudo[24733]: pam_unix(sudo:session): session closed for user root Oct 27 00:10:22 minidsp-shd volumio[24682]: /bin/mkdir: cannot create directory ‘/tmp/hls’: File exists Oct 27 00:10:22 minidsp-shd volumio[24682]: info: MRS: MultiRoom plugin initialized Oct 27 00:10:22 minidsp-shd volumio[24682]: info: MRS: STOPPING SNAPCLIENT Oct 27 00:10:22 minidsp-shd volumio[24682]: info: MRS: Snap server stop Oct 27 00:10:22 minidsp-shd sudo[24749]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Oct 27 00:10:22 minidsp-shd sudo[24749]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 00:10:22 minidsp-shd volumio[24682]: info: MRS: STOPPING volumioStreaming Oct 27 00:10:22 minidsp-shd sudo[24752]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Oct 27 00:10:22 minidsp-shd sudo[24752]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 00:10:22 minidsp-shd sudo[24749]: pam_unix(sudo:session): session closed for user root Oct 27 00:10:22 minidsp-shd sudo[24752]: pam_unix(sudo:session): session closed for user root Oct 27 00:10:22 minidsp-shd volumio[24682]: info: Loading plugin "outputs"... Oct 27 00:10:22 minidsp-shd sudo[24755]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Oct 27 00:10:22 minidsp-shd sudo[24755]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 00:10:22 minidsp-shd volumio[24682]: info: Loading plugin "albumart"... Oct 27 00:10:22 minidsp-shd sudo[24757]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Oct 27 00:10:22 minidsp-shd sudo[24757]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 00:10:22 minidsp-shd sudo[24757]: pam_unix(sudo:session): session closed for user root Oct 27 00:10:22 minidsp-shd volumio[24682]: info: Loading plugin "ms_surface_dial"... Oct 27 00:10:22 minidsp-shd sudo[24755]: pam_unix(sudo:session): session closed for user root Oct 27 00:10:23 minidsp-shd volumio[24682]: Forking 3 albumart workers Oct 27 00:10:23 minidsp-shd volumio[24682]: info: Applying required configuration parameters for plugin ms_surface_dial Oct 27 00:10:23 minidsp-shd volumio[24682]: info: Plugin example_plugin is not enabled Oct 27 00:10:23 minidsp-shd volumio[24682]: info: Loading plugin "hi_res_audio"... Oct 27 00:10:25 minidsp-shd volumio[24682]: Starting albumart workers Oct 27 00:10:25 minidsp-shd volumio[24682]: Starting albumart workers Oct 27 00:10:25 minidsp-shd volumio[24682]: Starting albumart workers Oct 27 00:10:25 minidsp-shd volumio[24682]: info: Applying required configuration parameters for plugin hi_res_audio Oct 27 00:10:26 minidsp-shd volumio[24682]: info: Loading plugin "inputs"... Oct 27 00:10:27 minidsp-shd volumio[24682]: info: Loading plugin "qobuz"... Oct 27 00:10:29 minidsp-shd volumio[24682]: info: Loading plugin "tidal"... Oct 27 00:10:31 minidsp-shd volumio[24682]: info: Loading plugin "oem_helper"... Oct 27 00:10:32 minidsp-shd volumio[24682]: info: Applying required configuration parameters for plugin oem_helper Oct 27 00:10:32 minidsp-shd volumio[24682]: info: Loading plugin "updater_comm"... Oct 27 00:10:32 minidsp-shd volumio[24682]: info: Plugin mpdemulation is not enabled Oct 27 00:10:32 minidsp-shd volumio[24682]: info: Loading plugin "rest_api"... Oct 27 00:10:32 minidsp-shd volumio[24682]: info: Loading plugin "websocket"... Oct 27 00:10:32 minidsp-shd volumio[24682]: info: Loading i18n strings for locale en Oct 27 00:10:32 minidsp-shd volumio[24682]: Updating browse sources language Oct 27 00:10:32 minidsp-shd volumio[24682]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 27 00:10:33 minidsp-shd volumio[24682]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 27 00:10:33 minidsp-shd volumio[24682]: info: CoreCommandRouter::initPlayerControls Oct 27 00:10:33 minidsp-shd volumio[24682]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 00:10:33 minidsp-shd volumio[24682]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 00:10:33 minidsp-shd volumio[24682]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 00:10:33 minidsp-shd volumio[24682]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 00:10:33 minidsp-shd volumio[24682]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 00:10:33 minidsp-shd volumio[24682]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 00:10:33 minidsp-shd volumio[24682]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 00:10:33 minidsp-shd volumio[24682]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 00:10:33 minidsp-shd volumio[24682]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 27 00:10:33 minidsp-shd volumio[24682]: Express server listening on port 3000 Oct 27 00:10:33 minidsp-shd volumio[24682]: [Metrics] WebUI: 28s 879.29ms Oct 27 00:10:33 minidsp-shd volumio[24682]: info: CoreStateMachine::resetVolumioState Oct 27 00:10:33 minidsp-shd volumio[24682]: info: CoreStateMachine::getcurrentVolume Oct 27 00:10:33 minidsp-shd volumio[24682]: info: CoreCommandRouter::volumioRetrievevolume Oct 27 00:10:33 minidsp-shd volumio[24682]: info: CoreStateMachine::pushState Oct 27 00:10:33 minidsp-shd volumio[24682]: info: CorePlayQueue::getTrack 0 Oct 27 00:10:33 minidsp-shd volumio[24682]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 27 00:10:33 minidsp-shd volumio[24682]: info: CoreCommandRouter::volumioPushState Oct 27 00:10:33 minidsp-shd volumio[24682]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 27 00:10:33 minidsp-shd sudo[24860]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 27 00:10:33 minidsp-shd sudo[24860]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 00:10:33 minidsp-shd sudo[24860]: pam_unix(sudo:session): session closed for user root Oct 27 00:10:33 minidsp-shd volumio[24682]: info: CoreCommandRouter::executeOnPlugin: inputs , getVolume Oct 27 00:10:33 minidsp-shd volumio[24682]: info: CoreCommandRouter::executeOnPlugin: inputs , getDSP Oct 27 00:10:33 minidsp-shd sudo[24863]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 27 00:10:33 minidsp-shd sudo[24863]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 00:10:33 minidsp-shd volumio[24682]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Oct 27 00:10:33 minidsp-shd volumio[24682]: info: Completed loading Core Plugins Oct 27 00:10:33 minidsp-shd sudo[24863]: pam_unix(sudo:session): session closed for user root Oct 27 00:10:33 minidsp-shd volumio[24682]: info: Preparing to generate the ALSA configuration file Oct 27 00:10:33 minidsp-shd volumio[24682]: info: MRS: Removed streaming files Oct 27 00:10:33 minidsp-shd volumio[24682]: info: MRS: volumioStreaming STOPPED Oct 27 00:10:33 minidsp-shd volumio[24682]: info: MRS: SNAPSERVER STOPPED Oct 27 00:10:33 minidsp-shd volumio[24682]: info: MRS: SNAPCLIENT STOPPED Oct 27 00:10:33 minidsp-shd volumio[24682]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Oct 27 00:10:33 minidsp-shd volumio[24682]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Oct 27 00:10:33 minidsp-shd volumio[24682]: info: Reading ALSA contributions from plugins. Oct 27 00:10:33 minidsp-shd volumio[24682]: verbose: New Socket.io Connection to 192.168.0.175 from 192.168.0.147 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_0 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Total Clients: 1 Oct 27 00:10:33 minidsp-shd volumio[24682]: verbose: New Socket.io Connection to 192.168.0.175 from 192.168.0.147 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_0 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Total Clients: 2 Oct 27 00:10:33 minidsp-shd volumio[24682]: verbose: New Socket.io Connection to 192.168.0.175 from 192.168.0.147 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_0 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Total Clients: 3 Oct 27 00:10:33 minidsp-shd volumio[24682]: verbose: New Socket.io Connection to 192.168.0.175 from 192.168.0.147 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_0 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Total Clients: 4 Oct 27 00:10:33 minidsp-shd volumio[24682]: verbose: New Socket.io Connection to 192.168.0.175 from 192.168.0.147 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_0 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Total Clients: 5 Oct 27 00:10:34 minidsp-shd volumio[24682]: info: Reloading queue from file Oct 27 00:10:34 minidsp-shd volumio[24682]: info: CoreStateMachine::setRepeat null single undefined Oct 27 00:10:34 minidsp-shd volumio[24682]: info: CoreStateMachine::pushState Oct 27 00:10:34 minidsp-shd volumio[24682]: info: CorePlayQueue::getTrack 0 Oct 27 00:10:34 minidsp-shd volumio[24682]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 27 00:10:34 minidsp-shd volumio[24682]: info: CoreCommandRouter::volumioPushState Oct 27 00:10:34 minidsp-shd volumio[24682]: info: CoreStateMachine::setRandom null Oct 27 00:10:34 minidsp-shd volumio[24682]: info: CoreStateMachine::pushState Oct 27 00:10:34 minidsp-shd volumio[24682]: info: CorePlayQueue::getTrack 0 Oct 27 00:10:34 minidsp-shd volumio[24682]: info: CoreCommandRouter::volumioPushState Oct 27 00:10:34 minidsp-shd volumio[24682]: info: Setting Device type: NanoPi NEO 3 Oct 27 00:10:34 minidsp-shd volumio[24682]: verbose: New Socket.io Connection to 192.168.0.175 from 192.168.0.147 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_0 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Total Clients: 6 Oct 27 00:10:34 minidsp-shd volumio-remote-updater[451]: [2024-10-27 00:10:34] [connect] Successful connection Oct 27 00:10:34 minidsp-shd sudo[24871]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Oct 27 00:10:34 minidsp-shd sudo[24871]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 00:10:34 minidsp-shd volumio[24682]: Searching all installed plugins Oct 27 00:10:34 minidsp-shd volumio[24682]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 27 00:10:34 minidsp-shd volumio[24682]: info: CoreCommandRouter::executeOnPlugin: , search Oct 27 00:10:34 minidsp-shd volumio[24682]: info: CoreCommandRouter::executeOnPlugin: mpd , search Oct 27 00:10:34 minidsp-shd volumio[24682]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 27 00:10:34 minidsp-shd sudo[24871]: pam_unix(sudo:session): session closed for user root Oct 27 00:10:34 minidsp-shd volumio[24682]: TypeError: Cannot read property 'then' of undefined Oct 27 00:10:34 minidsp-shd volumio[24682]: at ControllerMpd.search (/volumio/app/plugins/music_service/mpd/index.js:1582:17) Oct 27 00:10:34 minidsp-shd volumio[24682]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1077:32) Oct 27 00:10:34 minidsp-shd volumio[24682]: at CoreMusicLibrary.searchOnPlugin (/volumio/app/musiclibrary.js:668:44) Oct 27 00:10:34 minidsp-shd volumio[24682]: at CoreMusicLibrary.search (/volumio/app/musiclibrary.js:455:27) Oct 27 00:10:34 minidsp-shd volumio[24682]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:457:44) Oct 27 00:10:34 minidsp-shd volumio[24682]: at Socket.emit (events.js:400:28) Oct 27 00:10:34 minidsp-shd volumio[24682]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Oct 27 00:10:34 minidsp-shd volumio[24682]: at processTicksAndRejections (internal/process/task_queues.js:77:11) Oct 27 00:10:34 minidsp-shd volumio[24682]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 27 00:10:35 minidsp-shd ntpd[798]: Soliciting pool server 2001:ac8:81:65:0:2:0:3 Oct 27 00:10:35 minidsp-shd sudo[24882]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-27 00:09 Oct 27 00:10:35 minidsp-shd sudo[24882]: 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="17fcb754ddd6bd152b01008c46cc4ba1ca48bf35" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="281cefcd7a302aa7cfba569185cf7aae19b8c376" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="minidspshd" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 22 Mar 2024 03:13:25 PM CET" VOLUMIO_VERSION="3.608" VOLUMIO_HARDWARE="nanopineo3" VOLUMIO_DEVICENAME="Nanopi Neo3" VOLUMIO_VENDOR="miniDSP" VOLUMIO_MODEL="SHD" VOLUMIO_VENDOR_MODEL="miniDSP SHD" VOLUMIO_HASH="18533ba33f8f92d7e7e459bb30f70beb"