Dec 10 19:49:00 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:00 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:00 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:00 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:00 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:00 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:01 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:01 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:01 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:01 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:02 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:02 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:02 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:02 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:02 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:02 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:03 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:03 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:03 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:03 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:03 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:03 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:04 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:04 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:04 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:04 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:04 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:04 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:05 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:05 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:05 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:05 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:05 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:05 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:06 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:06 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:06 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:06 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:06 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:06 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:07 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:07 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:07 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:07 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:07 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:07 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:08 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:08 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:08 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:08 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:08 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:08 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:09 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:09 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:09 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:09 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:10 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:10 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:10 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:10 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:10 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:10 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:11 volumio-4 volumio[4425]: info: Preload queue cleared Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioReplaceandPlayItems Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreStateMachine::ClearQueue Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreStateMachine::stop Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreStateMachine::stPlaybackTimer Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreStateMachine::updateTrackBlock Dec 10 19:49:11 volumio-4 volumio[4425]: info: CorePlayQueue::getTrackBlock Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreStateMachine::pushState Dec 10 19:49:11 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioPushState Dec 10 19:49:11 volumio-4 volumio[4425]: info: MRS: Pushing multiroomSync output update for this device Dec 10 19:49:11 volumio-4 volumio[4425]: info: MRS: Pushing multiroomSync output Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:11 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreStateMachine::serviceStop Dec 10 19:49:11 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreCommandRouter::serviceStop Dec 10 19:49:11 volumio-4 volumio[4425]: info: [1765392551570] ControllerUPNPBrowser::stop Dec 10 19:49:11 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand stop Dec 10 19:49:11 volumio-4 volumio[4425]: info: CorePlayQueue::clearPlayQueue Dec 10 19:49:11 volumio-4 volumio[4425]: info: CorePlayQueue::saveQueue Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioPushQueue Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreStateMachine::addQueueItems Dec 10 19:49:11 volumio-4 volumio[4425]: info: CorePlayQueue::addQueueItems Dec 10 19:49:11 volumio-4 volumio[4425]: info: Preload queue cleared Dec 10 19:49:11 volumio-4 volumio[4425]: info: Adding Item to queue: upnp/folder/http://192.168.0.216:50001/ContentDirectory/control@22$1113 Dec 10 19:49:11 volumio-4 volumio[4425]: info: Using cached record of: upnp/folder/http://192.168.0.216:50001/ContentDirectory/control@22$1113 Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioPushQueue Dec 10 19:49:11 volumio-4 volumio[4425]: info: CorePlayQueue::saveQueue Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreStateMachine::updateTrackBlock Dec 10 19:49:11 volumio-4 volumio[4425]: info: CorePlayQueue::getTrackBlock Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:11 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioPlay Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreStateMachine::play index 0 Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreStateMachine::stop Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreStateMachine::play index undefined Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 10 19:49:11 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreStateMachine::startPlaybackTimer Dec 10 19:49:11 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:11 volumio-4 volumio[4425]: info: [1765392551579] ControllerUPNPBrowser::clearAddPlayTrack Dec 10 19:49:11 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand stop Dec 10 19:49:11 volumio-4 volumio[4425]: info: Dec 10 19:49:11 volumio-4 volumio[4425]: ---------------------------- MPD announces state update: player Dec 10 19:49:11 volumio-4 volumio[4425]: info: sendMpdCommand stop took 16 milliseconds Dec 10 19:49:11 volumio-4 volumio[4425]: info: ControllerMpd::getState Dec 10 19:49:11 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand status Dec 10 19:49:11 volumio-4 volumio[4425]: info: sendMpdCommand stop took 8 milliseconds Dec 10 19:49:11 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand clear Dec 10 19:49:11 volumio-4 volumio[4425]: info: Dec 10 19:49:11 volumio-4 volumio[4425]: ---------------------------- MPD announces system playlist update Dec 10 19:49:11 volumio-4 volumio[4425]: info: Ignoring MPD Status Update Dec 10 19:49:11 volumio-4 volumio[4425]: info: sendMpdCommand status took 5 milliseconds Dec 10 19:49:11 volumio-4 volumio[4425]: info: sendMpdCommand clear took 4 milliseconds Dec 10 19:49:11 volumio-4 volumio[4425]: verbose: ControllerMpd::parseState Dec 10 19:49:11 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 10 19:49:11 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.0.216:50002/m/MP3/8431.mp3" Dec 10 19:49:11 volumio-4 volumio[4425]: error: updateQueue error: null Dec 10 19:49:11 volumio-4 volumio[4425]: info: ------------------------------ 2ms Dec 10 19:49:11 volumio-4 volumio[4425]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 10 19:49:11 volumio-4 volumio[4425]: verbose: ControllerMpd::parseTrackInfo Dec 10 19:49:11 volumio-4 volumio[4425]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Dec 10 19:49:11 volumio-4 volumio[4425]: info: ------------------------------ 7ms Dec 10 19:49:11 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.0.216:50002/m/MP3/8431.mp3" Dec 10 19:49:11 volumio-4 volumio[4425]: info: Dec 10 19:49:11 volumio-4 volumio[4425]: ---------------------------- MPD announces system playlist update Dec 10 19:49:11 volumio-4 volumio[4425]: info: Ignoring MPD Status Update Dec 10 19:49:11 volumio-4 volumio[4425]: info: sendMpdCommand add "http://192.168.0.216:50002/m/MP3/8431.mp3" took 1 milliseconds Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 10 19:49:11 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand play Dec 10 19:49:11 volumio-4 volumio[4425]: info: ------------------------------ 1ms Dec 10 19:49:11 volumio-4 volumio[4425]: info: sendMpdCommand play took 1 milliseconds Dec 10 19:49:11 volumio-4 volumio[4425]: info: Dec 10 19:49:11 volumio-4 volumio[4425]: ---------------------------- MPD announces state update: player Dec 10 19:49:11 volumio-4 volumio[4425]: info: ControllerMpd::getState Dec 10 19:49:11 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand status Dec 10 19:49:11 volumio-4 volumio[4425]: info: Dec 10 19:49:11 volumio-4 volumio[4425]: ---------------------------- MPD announces state update: player Dec 10 19:49:11 volumio-4 volumio[4425]: info: ControllerMpd::getState Dec 10 19:49:11 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand status Dec 10 19:49:11 volumio-4 volumio[4425]: info: sendMpdCommand status took 1 milliseconds Dec 10 19:49:11 volumio-4 volumio[4425]: verbose: ControllerMpd::parseState Dec 10 19:49:11 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 10 19:49:11 volumio-4 volumio[4425]: info: sendMpdCommand status took 1 milliseconds Dec 10 19:49:11 volumio-4 volumio[4425]: verbose: ControllerMpd::parseState Dec 10 19:49:11 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 10 19:49:11 volumio-4 volumio[4425]: info: sendMpdCommand playlistinfo took 2 milliseconds Dec 10 19:49:11 volumio-4 volumio[4425]: verbose: ControllerMpd::parseTrackInfo Dec 10 19:49:11 volumio-4 volumio[4425]: info: ControllerMpd::pushState Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreCommandRouter::servicePushState Dec 10 19:49:11 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:11 volumio-4 volumio[4425]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":240,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"8431.mp3","artist":null,"album":null,"uri":"http://192.168.0.216:50002/m/MP3/8431.mp3","trackType":"mp3"} Dec 10 19:49:11 volumio-4 volumio[4425]: verbose: CURRENT POSITION 0 Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreStateMachine::syncState stateService play Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreStateMachine::syncState currentStatus stop Dec 10 19:49:11 volumio-4 volumio[4425]: info: ------------------------------ 5ms Dec 10 19:49:11 volumio-4 volumio[4425]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 10 19:49:11 volumio-4 volumio[4425]: verbose: ControllerMpd::parseTrackInfo Dec 10 19:49:11 volumio-4 volumio[4425]: info: ControllerMpd::pushState Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreCommandRouter::servicePushState Dec 10 19:49:11 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:11 volumio-4 volumio[4425]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":240,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"8431.mp3","artist":null,"album":null,"uri":"http://192.168.0.216:50002/m/MP3/8431.mp3","trackType":"mp3"} Dec 10 19:49:11 volumio-4 volumio[4425]: verbose: CURRENT POSITION 0 Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreStateMachine::syncState stateService play Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreStateMachine::syncState currentStatus play Dec 10 19:49:11 volumio-4 volumio[4425]: info: Received an update from plugin. extracting info from payload Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreStateMachine::pushState Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioPushState Dec 10 19:49:11 volumio-4 volumio[4425]: info: MRS: Pushing multiroomSync output update for this device Dec 10 19:49:11 volumio-4 volumio[4425]: info: MRS: Pushing multiroomSync output Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreStateMachine::pushState Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioPushState Dec 10 19:49:11 volumio-4 volumio[4425]: info: MRS: Pushing multiroomSync output update for this device Dec 10 19:49:11 volumio-4 volumio[4425]: info: MRS: Pushing multiroomSync output Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:11 volumio-4 volumio[4425]: info: ------------------------------ 17ms Dec 10 19:49:11 volumio-4 volumio[4425]: info: Dec 10 19:49:11 volumio-4 volumio[4425]: ---------------------------- MPD announces system playlist update Dec 10 19:49:11 volumio-4 volumio[4425]: info: Ignoring MPD Status Update Dec 10 19:49:11 volumio-4 volumio[4425]: info: Dec 10 19:49:11 volumio-4 volumio[4425]: ---------------------------- MPD announces state update: player Dec 10 19:49:11 volumio-4 volumio[4425]: info: ControllerMpd::getState Dec 10 19:49:11 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand status Dec 10 19:49:11 volumio-4 volumio[4425]: info: ------------------------------ 2ms Dec 10 19:49:11 volumio-4 volumio[4425]: info: sendMpdCommand status took 2 milliseconds Dec 10 19:49:11 volumio-4 volumio[4425]: verbose: ControllerMpd::parseState Dec 10 19:49:11 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 10 19:49:11 volumio-4 volumio[4425]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 10 19:49:11 volumio-4 volumio[4425]: verbose: ControllerMpd::parseTrackInfo Dec 10 19:49:11 volumio-4 volumio[4425]: info: ControllerMpd::pushState Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreCommandRouter::servicePushState Dec 10 19:49:11 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:11 volumio-4 volumio[4425]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1202,"duration":240,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"I Try","artist":"Macy Gray","album":"The Very Best of Macy Gray","uri":"http://192.168.0.216:50002/m/MP3/8431.mp3","trackType":"mp3"} Dec 10 19:49:11 volumio-4 volumio[4425]: verbose: CURRENT POSITION 0 Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreStateMachine::syncState stateService play Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreStateMachine::syncState currentStatus play Dec 10 19:49:11 volumio-4 volumio[4425]: info: Received an update from plugin. extracting info from payload Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreStateMachine::pushState Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioPushState Dec 10 19:49:11 volumio-4 volumio[4425]: info: MRS: Pushing multiroomSync output update for this device Dec 10 19:49:11 volumio-4 volumio[4425]: info: MRS: Pushing multiroomSync output Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreStateMachine::pushState Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioPushState Dec 10 19:49:11 volumio-4 volumio[4425]: info: MRS: Pushing multiroomSync output update for this device Dec 10 19:49:11 volumio-4 volumio[4425]: info: MRS: Pushing multiroomSync output Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:11 volumio-4 volumio[4425]: info: ------------------------------ 15ms Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetQueue Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreStateMachine::getQueue Dec 10 19:49:11 volumio-4 volumio[4425]: info: CorePlayQueue::getQueue Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetQueue Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreStateMachine::getQueue Dec 10 19:49:11 volumio-4 volumio[4425]: info: CorePlayQueue::getQueue Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:11 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:12 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:12 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:12 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:12 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:12 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:12 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:13 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:13 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:13 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:13 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:13 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:13 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:14 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:14 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:14 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:14 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:14 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:14 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:15 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:15 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:15 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:15 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:16 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:16 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:16 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:16 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:16 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:16 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:17 volumio-4 volumio[4425]: info: Preload queue cleared Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioReplaceandPlayItems Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreStateMachine::ClearQueue Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreStateMachine::stop Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreStateMachine::stPlaybackTimer Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreStateMachine::updateTrackBlock Dec 10 19:49:17 volumio-4 volumio[4425]: info: CorePlayQueue::getTrackBlock Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreStateMachine::pushState Dec 10 19:49:17 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioPushState Dec 10 19:49:17 volumio-4 volumio[4425]: info: MRS: Pushing multiroomSync output update for this device Dec 10 19:49:17 volumio-4 volumio[4425]: info: MRS: Pushing multiroomSync output Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:17 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreStateMachine::serviceStop Dec 10 19:49:17 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreCommandRouter::serviceStop Dec 10 19:49:17 volumio-4 volumio[4425]: info: [1765392557332] ControllerUPNPBrowser::stop Dec 10 19:49:17 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand stop Dec 10 19:49:17 volumio-4 volumio[4425]: info: CorePlayQueue::clearPlayQueue Dec 10 19:49:17 volumio-4 volumio[4425]: info: CorePlayQueue::saveQueue Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioPushQueue Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreStateMachine::addQueueItems Dec 10 19:49:17 volumio-4 volumio[4425]: info: CorePlayQueue::addQueueItems Dec 10 19:49:17 volumio-4 volumio[4425]: info: Preload queue cleared Dec 10 19:49:17 volumio-4 volumio[4425]: info: Adding Item to queue: upnp/folder/http://192.168.0.216:50001/ContentDirectory/control@22$1113 Dec 10 19:49:17 volumio-4 volumio[4425]: info: Using cached record of: upnp/folder/http://192.168.0.216:50001/ContentDirectory/control@22$1113 Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioPushQueue Dec 10 19:49:17 volumio-4 volumio[4425]: info: CorePlayQueue::saveQueue Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreStateMachine::updateTrackBlock Dec 10 19:49:17 volumio-4 volumio[4425]: info: CorePlayQueue::getTrackBlock Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:17 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioPlay Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreStateMachine::play index 0 Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreStateMachine::stop Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreStateMachine::play index undefined Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 10 19:49:17 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreStateMachine::startPlaybackTimer Dec 10 19:49:17 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:17 volumio-4 volumio[4425]: info: [1765392557340] ControllerUPNPBrowser::clearAddPlayTrack Dec 10 19:49:17 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand stop Dec 10 19:49:17 volumio-4 volumio[4425]: info: Dec 10 19:49:17 volumio-4 volumio[4425]: ---------------------------- MPD announces state update: player Dec 10 19:49:17 volumio-4 volumio[4425]: info: sendMpdCommand stop took 14 milliseconds Dec 10 19:49:17 volumio-4 volumio[4425]: info: ControllerMpd::getState Dec 10 19:49:17 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand status Dec 10 19:49:17 volumio-4 volumio[4425]: info: sendMpdCommand stop took 6 milliseconds Dec 10 19:49:17 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand clear Dec 10 19:49:17 volumio-4 volumio[4425]: info: Dec 10 19:49:17 volumio-4 volumio[4425]: ---------------------------- MPD announces system playlist update Dec 10 19:49:17 volumio-4 volumio[4425]: info: Ignoring MPD Status Update Dec 10 19:49:17 volumio-4 volumio[4425]: info: sendMpdCommand status took 1 milliseconds Dec 10 19:49:17 volumio-4 volumio[4425]: info: sendMpdCommand clear took 0 milliseconds Dec 10 19:49:17 volumio-4 volumio[4425]: verbose: ControllerMpd::parseState Dec 10 19:49:17 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 10 19:49:17 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.0.216:50002/m/MP3/8431.mp3" Dec 10 19:49:17 volumio-4 volumio[4425]: error: updateQueue error: null Dec 10 19:49:17 volumio-4 volumio[4425]: info: ------------------------------ 2ms Dec 10 19:49:17 volumio-4 volumio[4425]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 10 19:49:17 volumio-4 volumio[4425]: verbose: ControllerMpd::parseTrackInfo Dec 10 19:49:17 volumio-4 volumio[4425]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Dec 10 19:49:17 volumio-4 volumio[4425]: info: ------------------------------ 3ms Dec 10 19:49:17 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.0.216:50002/m/MP3/8431.mp3" Dec 10 19:49:17 volumio-4 volumio[4425]: info: Dec 10 19:49:17 volumio-4 volumio[4425]: ---------------------------- MPD announces system playlist update Dec 10 19:49:17 volumio-4 volumio[4425]: info: Ignoring MPD Status Update Dec 10 19:49:17 volumio-4 volumio[4425]: info: sendMpdCommand add "http://192.168.0.216:50002/m/MP3/8431.mp3" took 2 milliseconds Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 10 19:49:17 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand play Dec 10 19:49:17 volumio-4 volumio[4425]: info: ------------------------------ 1ms Dec 10 19:49:17 volumio-4 volumio[4425]: info: sendMpdCommand play took 1 milliseconds Dec 10 19:49:17 volumio-4 volumio[4425]: info: Dec 10 19:49:17 volumio-4 volumio[4425]: ---------------------------- MPD announces state update: player Dec 10 19:49:17 volumio-4 volumio[4425]: info: ControllerMpd::getState Dec 10 19:49:17 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand status Dec 10 19:49:17 volumio-4 volumio[4425]: info: Dec 10 19:49:17 volumio-4 volumio[4425]: ---------------------------- MPD announces state update: player Dec 10 19:49:17 volumio-4 volumio[4425]: info: sendMpdCommand status took 3 milliseconds Dec 10 19:49:17 volumio-4 volumio[4425]: info: ControllerMpd::getState Dec 10 19:49:17 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand status Dec 10 19:49:17 volumio-4 volumio[4425]: verbose: ControllerMpd::parseState Dec 10 19:49:17 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 10 19:49:17 volumio-4 volumio[4425]: info: sendMpdCommand status took 1 milliseconds Dec 10 19:49:17 volumio-4 volumio[4425]: info: sendMpdCommand playlistinfo took 2 milliseconds Dec 10 19:49:17 volumio-4 volumio[4425]: verbose: ControllerMpd::parseState Dec 10 19:49:17 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 10 19:49:17 volumio-4 volumio[4425]: verbose: ControllerMpd::parseTrackInfo Dec 10 19:49:17 volumio-4 volumio[4425]: info: ControllerMpd::pushState Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreCommandRouter::servicePushState Dec 10 19:49:17 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:17 volumio-4 volumio[4425]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":240,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"8431.mp3","artist":null,"album":null,"uri":"http://192.168.0.216:50002/m/MP3/8431.mp3","trackType":"mp3"} Dec 10 19:49:17 volumio-4 volumio[4425]: verbose: CURRENT POSITION 0 Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreStateMachine::syncState stateService play Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreStateMachine::syncState currentStatus stop Dec 10 19:49:17 volumio-4 volumio[4425]: info: ------------------------------ 7ms Dec 10 19:49:17 volumio-4 volumio[4425]: info: sendMpdCommand playlistinfo took 3 milliseconds Dec 10 19:49:17 volumio-4 volumio[4425]: verbose: ControllerMpd::parseTrackInfo Dec 10 19:49:17 volumio-4 volumio[4425]: info: ControllerMpd::pushState Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreCommandRouter::servicePushState Dec 10 19:49:17 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:17 volumio-4 volumio[4425]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":240,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"8431.mp3","artist":null,"album":null,"uri":"http://192.168.0.216:50002/m/MP3/8431.mp3","trackType":"mp3"} Dec 10 19:49:17 volumio-4 volumio[4425]: verbose: CURRENT POSITION 0 Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreStateMachine::syncState stateService play Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreStateMachine::syncState currentStatus play Dec 10 19:49:17 volumio-4 volumio[4425]: info: Received an update from plugin. extracting info from payload Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreStateMachine::pushState Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioPushState Dec 10 19:49:17 volumio-4 volumio[4425]: info: MRS: Pushing multiroomSync output update for this device Dec 10 19:49:17 volumio-4 volumio[4425]: info: MRS: Pushing multiroomSync output Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreStateMachine::pushState Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioPushState Dec 10 19:49:17 volumio-4 volumio[4425]: info: MRS: Pushing multiroomSync output update for this device Dec 10 19:49:17 volumio-4 volumio[4425]: info: MRS: Pushing multiroomSync output Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:17 volumio-4 volumio[4425]: info: ------------------------------ 15ms Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:17 volumio-4 volumio[4425]: info: Dec 10 19:49:17 volumio-4 volumio[4425]: ---------------------------- MPD announces system playlist update Dec 10 19:49:17 volumio-4 volumio[4425]: info: Ignoring MPD Status Update Dec 10 19:49:17 volumio-4 volumio[4425]: info: Dec 10 19:49:17 volumio-4 volumio[4425]: ---------------------------- MPD announces state update: player Dec 10 19:49:17 volumio-4 volumio[4425]: info: ControllerMpd::getState Dec 10 19:49:17 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand status Dec 10 19:49:17 volumio-4 volumio[4425]: info: ------------------------------ 1ms Dec 10 19:49:17 volumio-4 volumio[4425]: info: sendMpdCommand status took 2 milliseconds Dec 10 19:49:17 volumio-4 volumio[4425]: verbose: ControllerMpd::parseState Dec 10 19:49:17 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 10 19:49:17 volumio-4 volumio[4425]: info: sendMpdCommand playlistinfo took 0 milliseconds Dec 10 19:49:17 volumio-4 volumio[4425]: verbose: ControllerMpd::parseTrackInfo Dec 10 19:49:17 volumio-4 volumio[4425]: info: ControllerMpd::pushState Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreCommandRouter::servicePushState Dec 10 19:49:17 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:17 volumio-4 volumio[4425]: verbose: STATE SERVICE {"status":"play","position":0,"seek":297,"duration":240,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"I Try","artist":"Macy Gray","album":"The Very Best of Macy Gray","uri":"http://192.168.0.216:50002/m/MP3/8431.mp3","trackType":"mp3"} Dec 10 19:49:17 volumio-4 volumio[4425]: verbose: CURRENT POSITION 0 Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreStateMachine::syncState stateService play Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreStateMachine::syncState currentStatus play Dec 10 19:49:17 volumio-4 volumio[4425]: info: Received an update from plugin. extracting info from payload Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreStateMachine::pushState Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioPushState Dec 10 19:49:17 volumio-4 volumio[4425]: info: MRS: Pushing multiroomSync output update for this device Dec 10 19:49:17 volumio-4 volumio[4425]: info: MRS: Pushing multiroomSync output Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreStateMachine::pushState Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioPushState Dec 10 19:49:17 volumio-4 volumio[4425]: info: MRS: Pushing multiroomSync output update for this device Dec 10 19:49:17 volumio-4 volumio[4425]: info: MRS: Pushing multiroomSync output Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:17 volumio-4 volumio[4425]: info: ------------------------------ 17ms Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetQueue Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreStateMachine::getQueue Dec 10 19:49:17 volumio-4 volumio[4425]: info: CorePlayQueue::getQueue Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetQueue Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreStateMachine::getQueue Dec 10 19:49:17 volumio-4 volumio[4425]: info: CorePlayQueue::getQueue Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:17 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:18 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:18 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:18 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:18 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:18 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:18 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:19 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:19 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:19 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:19 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:19 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:19 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:20 volumio-4 volumio[4425]: info: Preload queue cleared Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioReplaceandPlayItems Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreStateMachine::ClearQueue Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreStateMachine::stop Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreStateMachine::stPlaybackTimer Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreStateMachine::updateTrackBlock Dec 10 19:49:20 volumio-4 volumio[4425]: info: CorePlayQueue::getTrackBlock Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreStateMachine::pushState Dec 10 19:49:20 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioPushState Dec 10 19:49:20 volumio-4 volumio[4425]: info: MRS: Pushing multiroomSync output update for this device Dec 10 19:49:20 volumio-4 volumio[4425]: info: MRS: Pushing multiroomSync output Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:20 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreStateMachine::serviceStop Dec 10 19:49:20 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreCommandRouter::serviceStop Dec 10 19:49:20 volumio-4 volumio[4425]: info: [1765392560457] ControllerUPNPBrowser::stop Dec 10 19:49:20 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand stop Dec 10 19:49:20 volumio-4 volumio[4425]: info: CorePlayQueue::clearPlayQueue Dec 10 19:49:20 volumio-4 volumio[4425]: info: CorePlayQueue::saveQueue Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioPushQueue Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreStateMachine::addQueueItems Dec 10 19:49:20 volumio-4 volumio[4425]: info: CorePlayQueue::addQueueItems Dec 10 19:49:20 volumio-4 volumio[4425]: info: Preload queue cleared Dec 10 19:49:20 volumio-4 volumio[4425]: info: Adding Item to queue: upnp/http://192.168.0.216:50001/ContentDirectory/control@22$@8431 Dec 10 19:49:20 volumio-4 volumio[4425]: info: Using cached record of: upnp/http://192.168.0.216:50001/ContentDirectory/control@22$@8431 Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioPushQueue Dec 10 19:49:20 volumio-4 volumio[4425]: info: CorePlayQueue::saveQueue Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreStateMachine::updateTrackBlock Dec 10 19:49:20 volumio-4 volumio[4425]: info: CorePlayQueue::getTrackBlock Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:20 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioPlay Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreStateMachine::play index 0 Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreStateMachine::addQueueItems Dec 10 19:49:20 volumio-4 volumio[4425]: info: CorePlayQueue::addQueueItems Dec 10 19:49:20 volumio-4 volumio[4425]: info: Preload queue cleared Dec 10 19:49:20 volumio-4 volumio[4425]: info: Adding Item to queue: upnp/http://192.168.0.216:50001/ContentDirectory/control@22$@8433 Dec 10 19:49:20 volumio-4 volumio[4425]: info: Using cached record of: upnp/http://192.168.0.216:50001/ContentDirectory/control@22$@8433 Dec 10 19:49:20 volumio-4 volumio[4425]: info: Adding Item to queue: upnp/http://192.168.0.216:50001/ContentDirectory/control@22$@8435 Dec 10 19:49:20 volumio-4 volumio[4425]: info: Using cached record of: upnp/http://192.168.0.216:50001/ContentDirectory/control@22$@8435 Dec 10 19:49:20 volumio-4 volumio[4425]: info: Adding Item to queue: upnp/http://192.168.0.216:50001/ContentDirectory/control@22$@8437 Dec 10 19:49:20 volumio-4 volumio[4425]: info: Using cached record of: upnp/http://192.168.0.216:50001/ContentDirectory/control@22$@8437 Dec 10 19:49:20 volumio-4 volumio[4425]: info: Adding Item to queue: upnp/http://192.168.0.216:50001/ContentDirectory/control@22$@8439 Dec 10 19:49:20 volumio-4 volumio[4425]: info: Using cached record of: upnp/http://192.168.0.216:50001/ContentDirectory/control@22$@8439 Dec 10 19:49:20 volumio-4 volumio[4425]: info: Adding Item to queue: upnp/http://192.168.0.216:50001/ContentDirectory/control@22$@8441 Dec 10 19:49:20 volumio-4 volumio[4425]: info: Using cached record of: upnp/http://192.168.0.216:50001/ContentDirectory/control@22$@8441 Dec 10 19:49:20 volumio-4 volumio[4425]: info: Adding Item to queue: upnp/http://192.168.0.216:50001/ContentDirectory/control@22$@8442 Dec 10 19:49:20 volumio-4 volumio[4425]: info: Using cached record of: upnp/http://192.168.0.216:50001/ContentDirectory/control@22$@8442 Dec 10 19:49:20 volumio-4 volumio[4425]: info: Adding Item to queue: upnp/http://192.168.0.216:50001/ContentDirectory/control@22$@8444 Dec 10 19:49:20 volumio-4 volumio[4425]: info: Using cached record of: upnp/http://192.168.0.216:50001/ContentDirectory/control@22$@8444 Dec 10 19:49:20 volumio-4 volumio[4425]: info: Adding Item to queue: upnp/http://192.168.0.216:50001/ContentDirectory/control@22$@8448 Dec 10 19:49:20 volumio-4 volumio[4425]: info: Using cached record of: upnp/http://192.168.0.216:50001/ContentDirectory/control@22$@8448 Dec 10 19:49:20 volumio-4 volumio[4425]: info: Adding Item to queue: upnp/http://192.168.0.216:50001/ContentDirectory/control@22$@8451 Dec 10 19:49:20 volumio-4 volumio[4425]: info: Using cached record of: upnp/http://192.168.0.216:50001/ContentDirectory/control@22$@8451 Dec 10 19:49:20 volumio-4 volumio[4425]: info: Adding Item to queue: upnp/http://192.168.0.216:50001/ContentDirectory/control@22$@8454 Dec 10 19:49:20 volumio-4 volumio[4425]: info: Using cached record of: upnp/http://192.168.0.216:50001/ContentDirectory/control@22$@8454 Dec 10 19:49:20 volumio-4 volumio[4425]: info: Adding Item to queue: upnp/http://192.168.0.216:50001/ContentDirectory/control@22$@8457 Dec 10 19:49:20 volumio-4 volumio[4425]: info: Using cached record of: upnp/http://192.168.0.216:50001/ContentDirectory/control@22$@8457 Dec 10 19:49:20 volumio-4 volumio[4425]: info: Adding Item to queue: upnp/http://192.168.0.216:50001/ContentDirectory/control@22$@8461 Dec 10 19:49:20 volumio-4 volumio[4425]: info: Using cached record of: upnp/http://192.168.0.216:50001/ContentDirectory/control@22$@8461 Dec 10 19:49:20 volumio-4 volumio[4425]: info: Adding Item to queue: upnp/http://192.168.0.216:50001/ContentDirectory/control@22$@8464 Dec 10 19:49:20 volumio-4 volumio[4425]: info: Using cached record of: upnp/http://192.168.0.216:50001/ContentDirectory/control@22$@8464 Dec 10 19:49:20 volumio-4 volumio[4425]: info: Adding Item to queue: upnp/http://192.168.0.216:50001/ContentDirectory/control@22$@8466 Dec 10 19:49:20 volumio-4 volumio[4425]: info: Using cached record of: upnp/http://192.168.0.216:50001/ContentDirectory/control@22$@8466 Dec 10 19:49:20 volumio-4 volumio[4425]: info: Adding Item to queue: upnp/http://192.168.0.216:50001/ContentDirectory/control@22$@8469 Dec 10 19:49:20 volumio-4 volumio[4425]: info: Using cached record of: upnp/http://192.168.0.216:50001/ContentDirectory/control@22$@8469 Dec 10 19:49:20 volumio-4 volumio[4425]: info: Adding Item to queue: upnp/http://192.168.0.216:50001/ContentDirectory/control@22$@8471 Dec 10 19:49:20 volumio-4 volumio[4425]: info: Using cached record of: upnp/http://192.168.0.216:50001/ContentDirectory/control@22$@8471 Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreStateMachine::stop Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioPushQueue Dec 10 19:49:20 volumio-4 volumio[4425]: info: CorePlayQueue::saveQueue Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreStateMachine::play index undefined Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreStateMachine::updateTrackBlock Dec 10 19:49:20 volumio-4 volumio[4425]: info: CorePlayQueue::getTrackBlock Dec 10 19:49:20 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:20 volumio-4 volumio[4425]: info: Dec 10 19:49:20 volumio-4 volumio[4425]: ---------------------------- MPD announces state update: player Dec 10 19:49:20 volumio-4 volumio[4425]: info: sendMpdCommand stop took 15 milliseconds Dec 10 19:49:20 volumio-4 volumio[4425]: info: ControllerMpd::getState Dec 10 19:49:20 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand status Dec 10 19:49:20 volumio-4 volumio[4425]: info: sendMpdCommand status took 1 milliseconds Dec 10 19:49:20 volumio-4 volumio[4425]: verbose: ControllerMpd::parseState Dec 10 19:49:20 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 10 19:49:20 volumio-4 volumio[4425]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 10 19:49:20 volumio-4 volumio[4425]: verbose: ControllerMpd::parseTrackInfo Dec 10 19:49:20 volumio-4 volumio[4425]: info: ControllerMpd::pushState Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreCommandRouter::servicePushState Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreStateMachine::pushState Dec 10 19:49:20 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioPushState Dec 10 19:49:20 volumio-4 volumio[4425]: info: MRS: Pushing multiroomSync output update for this device Dec 10 19:49:20 volumio-4 volumio[4425]: info: MRS: Pushing multiroomSync output Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:20 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:20 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:20 volumio-4 volumio[4425]: 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":"I Try","artist":"Macy Gray","album":"The Very Best of Macy Gray","uri":"http://192.168.0.216:50002/m/MP3/8431.mp3","trackType":"mp3"} Dec 10 19:49:20 volumio-4 volumio[4425]: verbose: CURRENT POSITION 0 Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreStateMachine::syncState stateService stop Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreStateMachine::syncState currentStatus stop Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreStateMachine::pushState Dec 10 19:49:20 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioPushState Dec 10 19:49:20 volumio-4 volumio[4425]: info: MRS: Pushing multiroomSync output update for this device Dec 10 19:49:20 volumio-4 volumio[4425]: info: MRS: Pushing multiroomSync output Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:20 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:20 volumio-4 volumio[4425]: info: No code Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreStateMachine::pushState Dec 10 19:49:20 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioPushState Dec 10 19:49:20 volumio-4 volumio[4425]: info: MRS: Pushing multiroomSync output update for this device Dec 10 19:49:20 volumio-4 volumio[4425]: info: MRS: Pushing multiroomSync output Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:20 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:20 volumio-4 volumio[4425]: info: ------------------------------ 12ms Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:20 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:20 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:20 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:20 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:20 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:21 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:21 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:21 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:21 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:21 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:21 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:21 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:21 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:21 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:21 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:21 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:21 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:22 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:22 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:22 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:22 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:22 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:22 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:22 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:22 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:23 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:23 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:23 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:23 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:23 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:23 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:23 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:23 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:23 volumio-4 volumio[4425]: info: MRS: STARTING volumioStreaming Dec 10 19:49:23 volumio-4 sudo[16401]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/stream.m3u8 /tmp/hls/stream225.ts /tmp/hls/stream226.ts /tmp/hls/stream227.ts /tmp/hls/stream228.ts Dec 10 19:49:23 volumio-4 sudo[16401]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 19:49:23 volumio-4 sudo[16401]: pam_unix(sudo:session): session closed for user root Dec 10 19:49:23 volumio-4 sudo[16403]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumioStreaming Dec 10 19:49:23 volumio-4 sudo[16403]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 19:49:23 volumio-4 systemd[1]: Stopping volumioStreaming.service - VolumioStreamingService... Dec 10 19:49:23 volumio-4 systemd[1]: volumioStreaming.service: Killing process 11822 (ffmpeg) with signal SIGKILL. Dec 10 19:49:23 volumio-4 systemd[1]: volumioStreaming.service: Deactivated successfully. Dec 10 19:49:23 volumio-4 systemd[1]: Stopped volumioStreaming.service - VolumioStreamingService. Dec 10 19:49:23 volumio-4 systemd[1]: volumioStreaming.service: Consumed 22.449s CPU time. Dec 10 19:49:23 volumio-4 systemd[1]: Started volumioStreaming.service - VolumioStreamingService. Dec 10 19:49:23 volumio-4 sudo[16403]: pam_unix(sudo:session): session closed for user root Dec 10 19:49:23 volumio-4 volumio[4425]: info: MRS: volumioStreaming STARTED Dec 10 19:49:23 volumio-4 sudo[16407]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Dec 10 19:49:23 volumio-4 sudo[16407]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 19:49:23 volumio-4 sudo[16407]: pam_unix(sudo:session): session closed for user root Dec 10 19:49:23 volumio-4 volumio[4425]: info: MRS: Cast player state: IDLE Dec 10 19:49:23 volumio-4 volumio[4425]: info: MRS: Cast player state: IDLE Dec 10 19:49:23 volumio-4 volumio[4425]: info: MRS: Cast player state: IDLE Dec 10 19:49:23 volumio-4 volumio[4425]: info: MRS: Cast player state: IDLE Dec 10 19:49:23 volumio-4 volumio[4425]: info: MRS: Cast player state: IDLE Dec 10 19:49:23 volumio-4 volumio[4425]: info: MRS: Cast player state: IDLE Dec 10 19:49:23 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:23 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:23 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:23 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:23 volumio-4 go-librespot[4943]: time="2025-12-10T19:49:23+01:00" level=trace msg="sent dealer ping" Dec 10 19:49:23 volumio-4 go-librespot[4943]: time="2025-12-10T19:49:23+01:00" level=trace msg="received dealer pong" Dec 10 19:49:24 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:24 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:24 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:24 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:24 volumio-4 go-librespot[4943]: time="2025-12-10T19:49:24+01:00" level=trace msg="received accesspoint ping" Dec 10 19:49:24 volumio-4 go-librespot[4943]: time="2025-12-10T19:49:24+01:00" level=trace msg="received accesspoint pong ack" Dec 10 19:49:24 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:24 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:24 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:24 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:24 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:24 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:24 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:24 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:24 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:24 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:25 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:25 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:25 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:25 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:25 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:25 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:25 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:25 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:25 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:25 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:25 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:25 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:26 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:26 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:26 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:26 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:26 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:26 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:26 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:26 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:26 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:26 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:26 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:26 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:27 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:27 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:27 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:27 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:27 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:27 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:27 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:27 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:27 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:27 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:27 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:27 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:28 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:28 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:28 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:28 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:28 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:28 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:28 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:28 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:28 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:28 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:28 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:28 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:29 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:29 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:29 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:29 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:29 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:29 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:29 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:29 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:29 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:29 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:29 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:29 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:30 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:30 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:30 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:30 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:30 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:30 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:30 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:30 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:30 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:30 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:30 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:30 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:31 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:31 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:31 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:31 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:31 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:31 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:31 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:31 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:31 volumio-4 volumio[4425]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Dec 10 19:49:31 volumio-4 volumio[4425]: info: Preload queue cleared Dec 10 19:49:32 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:32 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:32 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:32 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:32 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:32 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:32 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:32 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:32 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:32 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:32 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:32 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:33 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:33 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:33 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:33 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:33 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:33 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:33 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:33 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:33 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:33 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:33 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:33 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:34 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:34 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:34 volumio-4 volumio[4425]: info: Preload queue cleared Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioReplaceandPlayItems Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreStateMachine::ClearQueue Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreStateMachine::stop Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 10 19:49:34 volumio-4 volumio[4425]: info: CorePlayQueue::clearPlayQueue Dec 10 19:49:34 volumio-4 volumio[4425]: info: CorePlayQueue::saveQueue Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioPushQueue Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreStateMachine::addQueueItems Dec 10 19:49:34 volumio-4 volumio[4425]: info: CorePlayQueue::addQueueItems Dec 10 19:49:34 volumio-4 volumio[4425]: info: Preload queue cleared Dec 10 19:49:34 volumio-4 volumio[4425]: info: Adding Item to queue: upnp/folder/http://192.168.0.216:50001/ContentDirectory/control@22$1113 Dec 10 19:49:34 volumio-4 volumio[4425]: info: Using cached record of: upnp/folder/http://192.168.0.216:50001/ContentDirectory/control@22$1113 Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioPushQueue Dec 10 19:49:34 volumio-4 volumio[4425]: info: CorePlayQueue::saveQueue Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreStateMachine::updateTrackBlock Dec 10 19:49:34 volumio-4 volumio[4425]: info: CorePlayQueue::getTrackBlock Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:34 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioPlay Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreStateMachine::play index 0 Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreStateMachine::stop Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreStateMachine::play index undefined Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 10 19:49:34 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreStateMachine::startPlaybackTimer Dec 10 19:49:34 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:34 volumio-4 volumio[4425]: info: [1765392574121] ControllerUPNPBrowser::clearAddPlayTrack Dec 10 19:49:34 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand stop Dec 10 19:49:34 volumio-4 volumio[4425]: info: sendMpdCommand stop took 3 milliseconds Dec 10 19:49:34 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand clear Dec 10 19:49:34 volumio-4 volumio[4425]: info: Dec 10 19:49:34 volumio-4 volumio[4425]: ---------------------------- MPD announces system playlist update Dec 10 19:49:34 volumio-4 volumio[4425]: info: Ignoring MPD Status Update Dec 10 19:49:34 volumio-4 volumio[4425]: info: sendMpdCommand clear took 1 milliseconds Dec 10 19:49:34 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.0.216:50002/m/MP3/8431.mp3" Dec 10 19:49:34 volumio-4 volumio[4425]: error: updateQueue error: null Dec 10 19:49:34 volumio-4 volumio[4425]: info: ------------------------------ 4ms Dec 10 19:49:34 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.0.216:50002/m/MP3/8431.mp3" Dec 10 19:49:34 volumio-4 volumio[4425]: info: Dec 10 19:49:34 volumio-4 volumio[4425]: ---------------------------- MPD announces system playlist update Dec 10 19:49:34 volumio-4 volumio[4425]: info: Ignoring MPD Status Update Dec 10 19:49:34 volumio-4 volumio[4425]: info: sendMpdCommand add "http://192.168.0.216:50002/m/MP3/8431.mp3" took 2 milliseconds Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 10 19:49:34 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand play Dec 10 19:49:34 volumio-4 volumio[4425]: info: ------------------------------ 3ms Dec 10 19:49:34 volumio-4 volumio[4425]: info: sendMpdCommand play took 1 milliseconds Dec 10 19:49:34 volumio-4 volumio[4425]: info: Dec 10 19:49:34 volumio-4 volumio[4425]: ---------------------------- MPD announces state update: player Dec 10 19:49:34 volumio-4 volumio[4425]: info: ControllerMpd::getState Dec 10 19:49:34 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand status Dec 10 19:49:34 volumio-4 volumio[4425]: info: Dec 10 19:49:34 volumio-4 volumio[4425]: ---------------------------- MPD announces state update: player Dec 10 19:49:34 volumio-4 volumio[4425]: info: sendMpdCommand status took 2 milliseconds Dec 10 19:49:34 volumio-4 volumio[4425]: info: ControllerMpd::getState Dec 10 19:49:34 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand status Dec 10 19:49:34 volumio-4 volumio[4425]: verbose: ControllerMpd::parseState Dec 10 19:49:34 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 10 19:49:34 volumio-4 volumio[4425]: info: sendMpdCommand status took 1 milliseconds Dec 10 19:49:34 volumio-4 volumio[4425]: verbose: ControllerMpd::parseState Dec 10 19:49:34 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 10 19:49:34 volumio-4 volumio[4425]: info: sendMpdCommand playlistinfo took 2 milliseconds Dec 10 19:49:34 volumio-4 volumio[4425]: verbose: ControllerMpd::parseTrackInfo Dec 10 19:49:34 volumio-4 volumio[4425]: info: ControllerMpd::pushState Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreCommandRouter::servicePushState Dec 10 19:49:34 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:34 volumio-4 volumio[4425]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":240,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"8431.mp3","artist":null,"album":null,"uri":"http://192.168.0.216:50002/m/MP3/8431.mp3","trackType":"mp3"} Dec 10 19:49:34 volumio-4 volumio[4425]: verbose: CURRENT POSITION 0 Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreStateMachine::syncState stateService play Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreStateMachine::syncState currentStatus stop Dec 10 19:49:34 volumio-4 volumio[4425]: info: ------------------------------ 6ms Dec 10 19:49:34 volumio-4 volumio[4425]: info: sendMpdCommand playlistinfo took 3 milliseconds Dec 10 19:49:34 volumio-4 volumio[4425]: verbose: ControllerMpd::parseTrackInfo Dec 10 19:49:34 volumio-4 volumio[4425]: info: ControllerMpd::pushState Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreCommandRouter::servicePushState Dec 10 19:49:34 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:34 volumio-4 volumio[4425]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":240,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"8431.mp3","artist":null,"album":null,"uri":"http://192.168.0.216:50002/m/MP3/8431.mp3","trackType":"mp3"} Dec 10 19:49:34 volumio-4 volumio[4425]: verbose: CURRENT POSITION 0 Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreStateMachine::syncState stateService play Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreStateMachine::syncState currentStatus play Dec 10 19:49:34 volumio-4 volumio[4425]: info: Received an update from plugin. extracting info from payload Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreStateMachine::pushState Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioPushState Dec 10 19:49:34 volumio-4 volumio[4425]: info: MRS: Pushing multiroomSync output update for this device Dec 10 19:49:34 volumio-4 volumio[4425]: info: MRS: Pushing multiroomSync output Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreStateMachine::pushState Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioPushState Dec 10 19:49:34 volumio-4 volumio[4425]: info: MRS: Pushing multiroomSync output update for this device Dec 10 19:49:34 volumio-4 volumio[4425]: info: MRS: Pushing multiroomSync output Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:34 volumio-4 volumio[4425]: info: ------------------------------ 34ms Dec 10 19:49:34 volumio-4 volumio[4425]: info: Dec 10 19:49:34 volumio-4 volumio[4425]: ---------------------------- MPD announces system playlist update Dec 10 19:49:34 volumio-4 volumio[4425]: info: Ignoring MPD Status Update Dec 10 19:49:34 volumio-4 volumio[4425]: info: Dec 10 19:49:34 volumio-4 volumio[4425]: ---------------------------- MPD announces state update: player Dec 10 19:49:34 volumio-4 volumio[4425]: info: ControllerMpd::getState Dec 10 19:49:34 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand status Dec 10 19:49:34 volumio-4 volumio[4425]: info: ------------------------------ 15ms Dec 10 19:49:34 volumio-4 volumio[4425]: info: sendMpdCommand status took 13 milliseconds Dec 10 19:49:34 volumio-4 volumio[4425]: verbose: ControllerMpd::parseState Dec 10 19:49:34 volumio-4 volumio[4425]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 10 19:49:34 volumio-4 volumio[4425]: info: sendMpdCommand playlistinfo took 2 milliseconds Dec 10 19:49:34 volumio-4 volumio[4425]: verbose: ControllerMpd::parseTrackInfo Dec 10 19:49:34 volumio-4 volumio[4425]: info: ControllerMpd::pushState Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreCommandRouter::servicePushState Dec 10 19:49:34 volumio-4 volumio[4425]: info: CorePlayQueue::getTrack 0 Dec 10 19:49:34 volumio-4 volumio[4425]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1236,"duration":240,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"I Try","artist":"Macy Gray","album":"The Very Best of Macy Gray","uri":"http://192.168.0.216:50002/m/MP3/8431.mp3","trackType":"mp3"} Dec 10 19:49:34 volumio-4 volumio[4425]: verbose: CURRENT POSITION 0 Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreStateMachine::syncState stateService play Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreStateMachine::syncState currentStatus play Dec 10 19:49:34 volumio-4 volumio[4425]: info: Received an update from plugin. extracting info from payload Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreStateMachine::pushState Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioPushState Dec 10 19:49:34 volumio-4 volumio[4425]: info: MRS: Pushing multiroomSync output update for this device Dec 10 19:49:34 volumio-4 volumio[4425]: info: MRS: Pushing multiroomSync output Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreStateMachine::pushState Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioPushState Dec 10 19:49:34 volumio-4 volumio[4425]: info: MRS: Pushing multiroomSync output update for this device Dec 10 19:49:34 volumio-4 volumio[4425]: info: MRS: Pushing multiroomSync output Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:34 volumio-4 volumio[4425]: info: ------------------------------ 30ms Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetQueue Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreStateMachine::getQueue Dec 10 19:49:34 volumio-4 volumio[4425]: info: CorePlayQueue::getQueue Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetQueue Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreStateMachine::getQueue Dec 10 19:49:34 volumio-4 volumio[4425]: info: CorePlayQueue::getQueue Dec 10 19:49:34 volumio-4 volumio[4425]: info: MRS: Connected to cast device: Chromecast-827f0cbe7de9a46b70f5ef607fffd3a0 Dec 10 19:49:34 volumio-4 volumio[4425]: info: Refreshing Cached IP Addresses Dec 10 19:49:34 volumio-4 sudo[16617]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 10 19:49:34 volumio-4 sudo[16617]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 19:49:34 volumio-4 sudo[16617]: pam_unix(sudo:session): session closed for user root Dec 10 19:49:34 volumio-4 sudo[16619]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 10 19:49:34 volumio-4 sudo[16619]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 19:49:34 volumio-4 sudo[16619]: pam_unix(sudo:session): session closed for user root Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:34 volumio-4 volumio[4425]: info: MRS: Cast player state: IDLE Dec 10 19:49:34 volumio-4 volumio[4425]: info: MRS: Cast player state: IDLE Dec 10 19:49:34 volumio-4 volumio[4425]: info: MRS: Cast player state: IDLE Dec 10 19:49:34 volumio-4 volumio[4425]: info: MRS: Cast player state: IDLE Dec 10 19:49:34 volumio-4 volumio[4425]: info: MRS: cast media loaded Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:34 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:35 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:35 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:35 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:35 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:35 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:35 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:36 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:36 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:36 volumio-4 volumio[4425]: info: MRS: Cast player state: BUFFERING Dec 10 19:49:36 volumio-4 volumio[4425]: info: MRS: Cast player state: BUFFERING Dec 10 19:49:36 volumio-4 volumio[4425]: info: MRS: Cast player state: BUFFERING Dec 10 19:49:36 volumio-4 volumio[4425]: info: MRS: Cast player state: BUFFERING Dec 10 19:49:36 volumio-4 volumio[4425]: info: MRS: Cast player state: PLAYING Dec 10 19:49:36 volumio-4 volumio[4425]: info: MRS: Cast player state: PLAYING Dec 10 19:49:36 volumio-4 volumio[4425]: info: MRS: Cast player state: PLAYING Dec 10 19:49:36 volumio-4 volumio[4425]: info: MRS: Cast player state: PLAYING Dec 10 19:49:36 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:36 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:36 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:36 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:36 volumio-4 volumio[4425]: info: MRS: Cast player state: BUFFERING Dec 10 19:49:36 volumio-4 volumio[4425]: info: MRS: Cast player state: BUFFERING Dec 10 19:49:36 volumio-4 volumio[4425]: info: MRS: Cast player state: BUFFERING Dec 10 19:49:36 volumio-4 volumio[4425]: info: MRS: Cast player state: BUFFERING Dec 10 19:49:37 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:37 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:37 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:37 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:37 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:37 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:38 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:38 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:38 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:38 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:38 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:38 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:39 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:39 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:39 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:39 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:39 volumio-4 volumio[4425]: info: MRS: Cast player state: BUFFERING Dec 10 19:49:39 volumio-4 volumio[4425]: info: MRS: Cast player state: BUFFERING Dec 10 19:49:39 volumio-4 volumio[4425]: info: MRS: Cast player state: BUFFERING Dec 10 19:49:39 volumio-4 volumio[4425]: info: MRS: Cast player state: BUFFERING Dec 10 19:49:40 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:40 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:40 volumio-4 volumio[4425]: info: MRS: Cast player state: BUFFERING Dec 10 19:49:40 volumio-4 volumio[4425]: info: MRS: Cast player state: BUFFERING Dec 10 19:49:40 volumio-4 volumio[4425]: info: MRS: Cast player state: BUFFERING Dec 10 19:49:40 volumio-4 volumio[4425]: info: MRS: Cast player state: BUFFERING Dec 10 19:49:40 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:40 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:40 volumio-4 volumio[4425]: info: MRS: Cast player state: PLAYING Dec 10 19:49:40 volumio-4 volumio[4425]: info: MRS: Cast player state: PLAYING Dec 10 19:49:40 volumio-4 volumio[4425]: info: MRS: Cast player state: PLAYING Dec 10 19:49:40 volumio-4 volumio[4425]: info: MRS: Cast player state: PLAYING Dec 10 19:49:40 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:40 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:41 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:41 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:41 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:41 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:41 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:41 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:42 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:42 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:42 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:42 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:42 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:42 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:43 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:43 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:43 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:43 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:43 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:43 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:44 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:44 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:44 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:44 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:44 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:44 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:45 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:45 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:45 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:45 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:45 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:45 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:46 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:46 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:46 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:46 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:46 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:46 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:47 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:47 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:47 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:47 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:48 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:48 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:48 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:48 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:48 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:48 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:49 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:49 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:49 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:49 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:49 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:49 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:50 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:50 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:50 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:50 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:50 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:50 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:51 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:51 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:51 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:51 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:51 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:51 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:52 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:52 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:52 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:52 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:52 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:52 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:53 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:53 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:53 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:53 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:53 volumio-4 go-librespot[4943]: time="2025-12-10T19:49:53+01:00" level=trace msg="sent dealer ping" Dec 10 19:49:53 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:53 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:53 volumio-4 go-librespot[4943]: time="2025-12-10T19:49:53+01:00" level=trace msg="received dealer pong" Dec 10 19:49:54 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:54 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:54 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:54 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:55 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:55 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:55 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:55 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:55 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:55 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:56 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:56 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:56 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:56 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:56 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:56 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:57 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:57 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:57 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:57 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:57 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:57 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:58 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:58 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:58 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:58 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:58 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:58 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:59 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:59 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:59 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:59 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:59 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:49:59 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:00 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:00 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:00 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:00 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:00 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:00 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:01 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:01 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:01 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:01 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:01 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:01 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:02 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:02 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:02 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:02 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:02 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:02 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:03 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:03 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:03 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:03 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:04 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:04 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:04 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:04 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:04 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:04 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:05 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:05 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:05 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:05 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:05 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:05 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:06 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:06 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:06 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:06 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:06 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:06 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:07 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:07 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:07 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:07 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:07 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:07 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:08 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:08 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:08 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:08 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:08 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:08 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:09 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:09 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:09 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:09 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:09 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:09 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:10 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:10 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:10 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:10 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:10 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:10 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:11 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:11 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:11 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:11 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:11 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:11 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:12 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:12 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:12 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:12 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:13 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:13 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:13 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:13 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:13 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:13 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:14 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:14 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:14 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:14 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:14 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:14 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:15 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:15 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:15 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:15 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:15 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:15 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:16 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:16 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:16 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:16 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:16 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:16 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:17 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:17 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:17 volumio-4 volumio[4425]: info: CoreCommandRouter::executeOnPlugin: multiroom , disableAudioOutput Dec 10 19:50:17 volumio-4 volumio[4425]: info: MRS: Setting this device as single Dec 10 19:50:17 volumio-4 volumio[4425]: info: Dec 10 19:50:17 volumio-4 volumio[4425]: [1765392617463] ---------------------------- Setting Multiroom Single Dec 10 19:50:17 volumio-4 volumio[4425]: info: MRS: disable multiroom output Dec 10 19:50:17 volumio-4 volumio[4425]: info: MRS: Set multiroom target PCM to volumioDiscard Dec 10 19:50:17 volumio-4 volumio[4425]: info: Changed audio target for /tmp/multiroom/client/switch.target to volumioDiscard Dec 10 19:50:17 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:17 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:17 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:17 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:18 volumio-4 volumio[4425]: info: MRS: Set multiroom target PCM to volumioLocalPlayback Dec 10 19:50:18 volumio-4 volumio[4425]: info: Changed audio target for /tmp/multiroom/server/switch.target to volumioLocalPlayback Dec 10 19:50:18 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:18 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:18 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:18 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:18 volumio-4 volumio[4425]: info: MRS: STOPPING volumioStreaming Dec 10 19:50:18 volumio-4 volumio[4425]: info: MRS: Stopping cast device: Chromecast-827f0cbe7de9a46b70f5ef607fffd3a0 Dec 10 19:50:18 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:18 volumio-4 sudo[17461]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Dec 10 19:50:18 volumio-4 sudo[17461]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 19:50:18 volumio-4 sudo[17463]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/stream.m3u8 /tmp/hls/stream40.ts /tmp/hls/stream41.ts /tmp/hls/stream42.ts /tmp/hls/stream43.ts Dec 10 19:50:18 volumio-4 sudo[17463]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 19:50:18 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:18 volumio-4 sudo[17463]: pam_unix(sudo:session): session closed for user root Dec 10 19:50:18 volumio-4 volumio[4425]: info: MRS: Removed streaming files Dec 10 19:50:18 volumio-4 systemd[1]: Stopping volumioStreaming.service - VolumioStreamingService... Dec 10 19:50:18 volumio-4 systemd[1]: volumioStreaming.service: Killing process 16409 (ffmpeg) with signal SIGKILL. Dec 10 19:50:18 volumio-4 systemd[1]: volumioStreaming.service: Killing process 16628 (ffmpeg) with signal SIGKILL. Dec 10 19:50:18 volumio-4 systemd[1]: volumioStreaming.service: Killing process 16630 (ffmpeg) with signal SIGKILL. Dec 10 19:50:18 volumio-4 systemd[1]: volumioStreaming.service: Deactivated successfully. Dec 10 19:50:18 volumio-4 systemd[1]: Stopped volumioStreaming.service - VolumioStreamingService. Dec 10 19:50:18 volumio-4 systemd[1]: volumioStreaming.service: Consumed 4.883s CPU time. Dec 10 19:50:18 volumio-4 sudo[17461]: pam_unix(sudo:session): session closed for user root Dec 10 19:50:18 volumio-4 volumio[4425]: info: MRS: volumioStreaming STOPPED Dec 10 19:50:19 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:19 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:19 volumio-4 volumio[4425]: info: CoreCommandRouter::executeOnPlugin: multiroom , enableAudioOutput Dec 10 19:50:19 volumio-4 volumio[4425]: info: MRS: Starting cast device: Chromecast-827f0cbe7de9a46b70f5ef607fffd3a0 Dec 10 19:50:19 volumio-4 volumio[4425]: info: Enabled audio output: Chromecast-827f0cbe7de9a46b70f5ef607fffd3a0 Dec 10 19:50:19 volumio-4 volumio[4425]: info: MRS: Setting this device as Streaming Server Dec 10 19:50:19 volumio-4 volumio[4425]: info: Dec 10 19:50:19 volumio-4 volumio[4425]: [1765392619498] ---------------------------- MRS: Setting Streaming Server Dec 10 19:50:19 volumio-4 volumio[4425]: info: MRS: enable multiroom server output Dec 10 19:50:19 volumio-4 volumio[4425]: info: MRS: Set multiroom target PCM to volumioMultiRoom Dec 10 19:50:19 volumio-4 volumio[4425]: info: Changed audio target for /tmp/multiroom/server/switch.target to volumioMultiRoom Dec 10 19:50:19 volumio-4 volumio[4425]: info: MRS: Set multiroom target PCM to volumioLocalPlayback Dec 10 19:50:19 volumio-4 volumio[4425]: info: Changed audio target for /tmp/multiroom/client/switch.target to volumioLocalPlayback Dec 10 19:50:19 volumio-4 volumio[4425]: info: MRS: STARTING volumioStreaming Dec 10 19:50:19 volumio-4 sudo[17481]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Dec 10 19:50:19 volumio-4 sudo[17481]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 19:50:19 volumio-4 sudo[17483]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumioStreaming Dec 10 19:50:19 volumio-4 sudo[17483]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 19:50:19 volumio-4 sudo[17481]: pam_unix(sudo:session): session closed for user root Dec 10 19:50:19 volumio-4 volumio[4425]: info: MRS: Connected to cast device: Chromecast-827f0cbe7de9a46b70f5ef607fffd3a0 Dec 10 19:50:19 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:19 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:19 volumio-4 systemd[1]: Started volumioStreaming.service - VolumioStreamingService. Dec 10 19:50:19 volumio-4 sudo[17483]: pam_unix(sudo:session): session closed for user root Dec 10 19:50:19 volumio-4 volumio[4425]: info: MRS: volumioStreaming STARTED Dec 10 19:50:19 volumio-4 sudo[17493]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Dec 10 19:50:19 volumio-4 sudo[17493]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 19:50:19 volumio-4 sudo[17493]: pam_unix(sudo:session): session closed for user root Dec 10 19:50:19 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:19 volumio-4 volumio[4425]: info: CoreCommandRouter::volumioGetState Dec 10 19:50:20 volumio-4 volumio[4425]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 10 19:50:20 volumio-4 volumio[4425]: TypeError: Cannot read properties of undefined (reading 'on') Dec 10 19:50:20 volumio-4 volumio[4425]: at /myvolumio/plugins/audio_interface/multiroom/multiroom_real:1:29945 Dec 10 19:50:20 volumio-4 volumio[4425]: at /myvolumio/plugins/audio_interface/multiroom/node_modules/castv2-client/lib/senders/platform.js:95:20 Dec 10 19:50:20 volumio-4 volumio[4425]: at /myvolumio/plugins/audio_interface/multiroom/node_modules/castv2-client/lib/controllers/receiver.js:51:14 Dec 10 19:50:20 volumio-4 volumio[4425]: at fn.onmessage (/myvolumio/plugins/audio_interface/multiroom/node_modules/castv2-client/lib/controllers/request-response.js:27:7) Dec 10 19:50:20 volumio-4 volumio[4425]: at fn.emit (node:events:526:35) Dec 10 19:50:20 volumio-4 volumio[4425]: at Channel.onmessage (/myvolumio/plugins/audio_interface/multiroom/node_modules/castv2-client/lib/controllers/controller.js:16:10) Dec 10 19:50:20 volumio-4 volumio[4425]: at Channel.emit (node:events:514:28) Dec 10 19:50:20 volumio-4 volumio[4425]: at Client.onmessage (/myvolumio/plugins/audio_interface/multiroom/node_modules/castv2/lib/channel.js:23:10) Dec 10 19:50:20 volumio-4 volumio[4425]: at Client.emit (node:events:526:35) Dec 10 19:50:20 volumio-4 volumio[4425]: at PacketStreamWrapper.onpacket (/myvolumio/plugins/audio_interface/multiroom/node_modules/castv2/lib/client.js:81:10) Dec 10 19:50:20 volumio-4 volumio[4425]: at PacketStreamWrapper.emit (node:events:514:28) Dec 10 19:50:20 volumio-4 volumio[4425]: at TLSSocket. (/myvolumio/plugins/audio_interface/multiroom/node_modules/castv2/lib/packet-stream-wrapper.js:28:16) Dec 10 19:50:20 volumio-4 volumio[4425]: at TLSSocket.emit (node:events:514:28) Dec 10 19:50:20 volumio-4 volumio[4425]: at emitReadable_ (node:internal/streams/readable:609:12) Dec 10 19:50:20 volumio-4 volumio[4425]: at process.processTicksAndRejections (node:internal/process/task_queues:81:21) Dec 10 19:50:20 volumio-4 volumio[4425]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 10 19:50:20 volumio-4 sudo[17520]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-10 19:49' Dec 10 19:50:20 volumio-4 sudo[17520]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"