-- Logs begin at Tue 2025-09-02 13:54:10 UTC, end at Tue 2025-09-02 14:56:23 UTC. -- Sep 02 14:55:00 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 02 14:55:00 volumio volumio[1149]: info: Preload queue cleared Sep 02 14:55:00 volumio volumio[1149]: info: Preloading song: upnp/http://192.168.0.62:8096/dlna/f17fff4b-1aa2-4109-b3ef-e9df1aa71792/contentdirectory/control@371482 Sep 02 14:55:00 volumio volumio[1149]: info: Preloading song: upnp/http://192.168.0.62:8096/dlna/f17fff4b-1aa2-4109-b3ef-e9df1aa71792/contentdirectory/control@371481 Sep 02 14:55:00 volumio volumio[1149]: info: Preloading song: upnp/http://192.168.0.62:8096/dlna/f17fff4b-1aa2-4109-b3ef-e9df1aa71792/contentdirectory/control@371483 Sep 02 14:55:00 volumio volumio[1149]: info: Preloading song: upnp/http://192.168.0.62:8096/dlna/f17fff4b-1aa2-4109-b3ef-e9df1aa71792/contentdirectory/control@371479 Sep 02 14:55:00 volumio volumio[1149]: info: Preloading song: upnp/http://192.168.0.62:8096/dlna/f17fff4b-1aa2-4109-b3ef-e9df1aa71792/contentdirectory/control@371478 Sep 02 14:55:00 volumio volumio[1149]: info: Preloading song: upnp/http://192.168.0.62:8096/dlna/f17fff4b-1aa2-4109-b3ef-e9df1aa71792/contentdirectory/control@371480 Sep 02 14:55:00 volumio volumio[1149]: info: Preloading song: upnp/http://192.168.0.62:8096/dlna/f17fff4b-1aa2-4109-b3ef-e9df1aa71792/contentdirectory/control@371477 Sep 02 14:55:00 volumio volumio[1149]: info: Exploding uri upnp/http://192.168.0.62:8096/dlna/f17fff4b-1aa2-4109-b3ef-e9df1aa71792/contentdirectory/control@371482 in service upnp_browser Sep 02 14:55:00 volumio volumio[1149]: info: Exploding uri upnp/http://192.168.0.62:8096/dlna/f17fff4b-1aa2-4109-b3ef-e9df1aa71792/contentdirectory/control@371481 in service upnp_browser Sep 02 14:55:00 volumio volumio[1149]: info: Exploding uri upnp/http://192.168.0.62:8096/dlna/f17fff4b-1aa2-4109-b3ef-e9df1aa71792/contentdirectory/control@371483 in service upnp_browser Sep 02 14:55:00 volumio volumio[1149]: info: Exploding uri upnp/http://192.168.0.62:8096/dlna/f17fff4b-1aa2-4109-b3ef-e9df1aa71792/contentdirectory/control@371479 in service upnp_browser Sep 02 14:55:01 volumio volumio[1149]: info: Exploding uri upnp/http://192.168.0.62:8096/dlna/f17fff4b-1aa2-4109-b3ef-e9df1aa71792/contentdirectory/control@371478 in service upnp_browser Sep 02 14:55:01 volumio volumio[1149]: info: Exploding uri upnp/http://192.168.0.62:8096/dlna/f17fff4b-1aa2-4109-b3ef-e9df1aa71792/contentdirectory/control@371480 in service upnp_browser Sep 02 14:55:01 volumio volumio[1149]: info: Exploding uri upnp/http://192.168.0.62:8096/dlna/f17fff4b-1aa2-4109-b3ef-e9df1aa71792/contentdirectory/control@371477 in service upnp_browser Sep 02 14:55:06 volumio volumio[1149]: info: Preload queue cleared Sep 02 14:55:06 volumio volumio[1149]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 02 14:55:06 volumio volumio[1149]: info: CoreStateMachine::ClearQueue Sep 02 14:55:06 volumio volumio[1149]: info: CoreStateMachine::stop Sep 02 14:55:06 volumio volumio[1149]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 02 14:55:06 volumio volumio[1149]: info: CoreStateMachine::updateTrackBlock Sep 02 14:55:06 volumio volumio[1149]: info: CorePlayQueue::getTrackBlock Sep 02 14:55:06 volumio volumio[1149]: info: CoreStateMachine::stPlaybackTimer Sep 02 14:55:06 volumio volumio[1149]: info: CoreStateMachine::pushState Sep 02 14:55:06 volumio volumio[1149]: info: CorePlayQueue::getTrack 1 Sep 02 14:55:06 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 02 14:55:06 volumio volumio[1149]: info: CoreCommandRouter::volumioPushState Sep 02 14:55:06 volumio volumio[1149]: info: MRS: Pushing multiroomSync output update for this device Sep 02 14:55:06 volumio volumio[1149]: info: MRS: Pushing multiroomSync output Sep 02 14:55:06 volumio volumio[1149]: info: CoreCommandRouter::volumioGetState Sep 02 14:55:06 volumio volumio[1149]: info: CorePlayQueue::getTrack 1 Sep 02 14:55:06 volumio volumio[1149]: info: CoreStateMachine::serviceStop Sep 02 14:55:06 volumio volumio[1149]: info: CorePlayQueue::getTrack 1 Sep 02 14:55:06 volumio volumio[1149]: info: CoreCommandRouter::serviceStop Sep 02 14:55:06 volumio volumio[1149]: info: ControllerMpd::stop Sep 02 14:55:06 volumio volumio[1149]: verbose: ControllerMpd::sendMpdCommand stop Sep 02 14:55:06 volumio volumio[1149]: info: CorePlayQueue::clearPlayQueue Sep 02 14:55:06 volumio volumio[1149]: info: CorePlayQueue::saveQueue Sep 02 14:55:06 volumio volumio[1149]: info: CoreCommandRouter::volumioPushQueue Sep 02 14:55:06 volumio volumio[1149]: info: CoreStateMachine::addQueueItems Sep 02 14:55:06 volumio volumio[1149]: info: CorePlayQueue::addQueueItems Sep 02 14:55:06 volumio volumio[1149]: info: Preload queue cleared Sep 02 14:55:06 volumio volumio[1149]: info: Adding Item to queue: upnp/http://192.168.0.62:8096/dlna/f17fff4b-1aa2-4109-b3ef-e9df1aa71792/contentdirectory/control@371482 Sep 02 14:55:06 volumio volumio[1149]: info: Using cached record of: upnp/http://192.168.0.62:8096/dlna/f17fff4b-1aa2-4109-b3ef-e9df1aa71792/contentdirectory/control@371482 Sep 02 14:55:06 volumio volumio[1149]: info: Adding Item to queue: upnp/http://192.168.0.62:8096/dlna/f17fff4b-1aa2-4109-b3ef-e9df1aa71792/contentdirectory/control@371481 Sep 02 14:55:06 volumio volumio[1149]: info: Using cached record of: upnp/http://192.168.0.62:8096/dlna/f17fff4b-1aa2-4109-b3ef-e9df1aa71792/contentdirectory/control@371481 Sep 02 14:55:06 volumio volumio[1149]: info: CoreCommandRouter::volumioPushQueue Sep 02 14:55:06 volumio volumio[1149]: info: CorePlayQueue::saveQueue Sep 02 14:55:06 volumio volumio[1149]: info: CoreStateMachine::updateTrackBlock Sep 02 14:55:06 volumio volumio[1149]: info: CorePlayQueue::getTrackBlock Sep 02 14:55:06 volumio volumio[1149]: info: CoreCommandRouter::volumioPlay Sep 02 14:55:06 volumio volumio[1149]: info: CoreStateMachine::play index 1 Sep 02 14:55:06 volumio volumio[1149]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 02 14:55:06 volumio volumio[1149]: info: CoreStateMachine::addQueueItems Sep 02 14:55:06 volumio volumio[1149]: info: CorePlayQueue::addQueueItems Sep 02 14:55:06 volumio volumio[1149]: info: Preload queue cleared Sep 02 14:55:06 volumio volumio[1149]: info: Adding Item to queue: upnp/http://192.168.0.62:8096/dlna/f17fff4b-1aa2-4109-b3ef-e9df1aa71792/contentdirectory/control@371483 Sep 02 14:55:06 volumio volumio[1149]: info: Using cached record of: upnp/http://192.168.0.62:8096/dlna/f17fff4b-1aa2-4109-b3ef-e9df1aa71792/contentdirectory/control@371483 Sep 02 14:55:06 volumio volumio[1149]: info: Adding Item to queue: upnp/http://192.168.0.62:8096/dlna/f17fff4b-1aa2-4109-b3ef-e9df1aa71792/contentdirectory/control@371479 Sep 02 14:55:06 volumio volumio[1149]: info: Using cached record of: upnp/http://192.168.0.62:8096/dlna/f17fff4b-1aa2-4109-b3ef-e9df1aa71792/contentdirectory/control@371479 Sep 02 14:55:06 volumio volumio[1149]: info: Adding Item to queue: upnp/http://192.168.0.62:8096/dlna/f17fff4b-1aa2-4109-b3ef-e9df1aa71792/contentdirectory/control@371478 Sep 02 14:55:06 volumio volumio[1149]: info: Using cached record of: upnp/http://192.168.0.62:8096/dlna/f17fff4b-1aa2-4109-b3ef-e9df1aa71792/contentdirectory/control@371478 Sep 02 14:55:06 volumio volumio[1149]: info: Adding Item to queue: upnp/http://192.168.0.62:8096/dlna/f17fff4b-1aa2-4109-b3ef-e9df1aa71792/contentdirectory/control@371480 Sep 02 14:55:06 volumio volumio[1149]: info: Using cached record of: upnp/http://192.168.0.62:8096/dlna/f17fff4b-1aa2-4109-b3ef-e9df1aa71792/contentdirectory/control@371480 Sep 02 14:55:06 volumio volumio[1149]: info: Adding Item to queue: upnp/http://192.168.0.62:8096/dlna/f17fff4b-1aa2-4109-b3ef-e9df1aa71792/contentdirectory/control@371477 Sep 02 14:55:06 volumio volumio[1149]: info: Using cached record of: upnp/http://192.168.0.62:8096/dlna/f17fff4b-1aa2-4109-b3ef-e9df1aa71792/contentdirectory/control@371477 Sep 02 14:55:06 volumio volumio[1149]: info: CoreStateMachine::stop Sep 02 14:55:06 volumio volumio[1149]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 02 14:55:06 volumio volumio[1149]: info: CoreCommandRouter::volumioPushQueue Sep 02 14:55:06 volumio volumio[1149]: info: CorePlayQueue::saveQueue Sep 02 14:55:06 volumio volumio[1149]: info: CoreStateMachine::play index undefined Sep 02 14:55:06 volumio volumio[1149]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 02 14:55:06 volumio volumio[1149]: info: CoreStateMachine::updateTrackBlock Sep 02 14:55:06 volumio volumio[1149]: info: CorePlayQueue::getTrackBlock Sep 02 14:55:06 volumio volumio[1149]: info: CorePlayQueue::getTrack 1 Sep 02 14:55:06 volumio volumio[1149]: info: CoreStateMachine::startPlaybackTimer Sep 02 14:55:06 volumio volumio[1149]: info: CorePlayQueue::getTrack 1 Sep 02 14:55:06 volumio volumio[1149]: info: [1756824906575] ControllerUPNPBrowser::clearAddPlayTrack Sep 02 14:55:06 volumio volumio[1149]: verbose: ControllerMpd::sendMpdCommand stop Sep 02 14:55:06 volumio volumio[1149]: info: Sep 02 14:55:06 volumio volumio[1149]: ---------------------------- MPD announces state update: player Sep 02 14:55:06 volumio volumio[1149]: info: sendMpdCommand stop took 77 milliseconds Sep 02 14:55:06 volumio volumio[1149]: info: ControllerMpd::getState Sep 02 14:55:06 volumio volumio[1149]: verbose: ControllerMpd::sendMpdCommand status Sep 02 14:55:06 volumio volumio[1149]: info: sendMpdCommand stop took 17 milliseconds Sep 02 14:55:06 volumio volumio[1149]: verbose: ControllerMpd::sendMpdCommand clear Sep 02 14:55:06 volumio volumio[1149]: info: Sep 02 14:55:06 volumio volumio[1149]: ---------------------------- MPD announces system playlist update Sep 02 14:55:06 volumio volumio[1149]: info: Ignoring MPD Status Update Sep 02 14:55:06 volumio volumio[1149]: info: sendMpdCommand status took 4 milliseconds Sep 02 14:55:06 volumio volumio[1149]: info: sendMpdCommand clear took 3 milliseconds Sep 02 14:55:06 volumio volumio[1149]: verbose: ControllerMpd::parseState Sep 02 14:55:06 volumio volumio[1149]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 02 14:55:06 volumio volumio[1149]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.0.62:8096/audio/371481/original.flac?DeviceProfileId=c3dded503748480b95855c76e31cf2f7&DeviceId=08a3735b38a8c3334f24ad9cdc93c804&MediaSourceId=6ebbbcc1458ebaa04ae149f2a6cf5113&PlaySessionId=2b488fcb5f5ddd5c8d66c4070a44e286&api_key=47bb1d2f1a7b45479037b494c036a36a" Sep 02 14:55:06 volumio volumio[1149]: error: updateQueue error: null Sep 02 14:55:06 volumio volumio[1149]: info: ------------------------------ 9ms Sep 02 14:55:06 volumio volumio[1149]: info: sendMpdCommand playlistinfo took 6 milliseconds Sep 02 14:55:06 volumio volumio[1149]: verbose: ControllerMpd::parseTrackInfo Sep 02 14:55:06 volumio volumio[1149]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Sep 02 14:55:06 volumio volumio[1149]: info: ------------------------------ 19ms Sep 02 14:55:07 volumio volumio[1149]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.0.62:8096/audio/371481/original.flac?DeviceProfileId=c3dded503748480b95855c76e31cf2f7&DeviceId=08a3735b38a8c3334f24ad9cdc93c804&MediaSourceId=6ebbbcc1458ebaa04ae149f2a6cf5113&PlaySessionId=2b488fcb5f5ddd5c8d66c4070a44e286&api_key=47bb1d2f1a7b45479037b494c036a36a" Sep 02 14:55:07 volumio volumio[1149]: info: Sep 02 14:55:07 volumio volumio[1149]: ---------------------------- MPD announces system playlist update Sep 02 14:55:07 volumio volumio[1149]: info: Ignoring MPD Status Update Sep 02 14:55:07 volumio volumio[1149]: info: sendMpdCommand add "http://192.168.0.62:8096/audio/371481/original.flac?DeviceProfileId=c3dded503748480b95855c76e31cf2f7&DeviceId=08a3735b38a8c3334f24ad9cdc93c804&MediaSourceId=6ebbbcc1458ebaa04ae149f2a6cf5113&PlaySessionId=2b488fcb5f5ddd5c8d66c4070a44e286&api_key=47bb1d2f1a7b45479037b494c036a36a" took 1 milliseconds Sep 02 14:55:07 volumio volumio[1149]: info: CoreStateMachine::setConsumeUpdateService mpd Sep 02 14:55:07 volumio volumio[1149]: verbose: ControllerMpd::sendMpdCommand play Sep 02 14:55:07 volumio volumio[1149]: info: ------------------------------ 3ms Sep 02 14:55:07 volumio volumio[1149]: info: sendMpdCommand play took 2 milliseconds Sep 02 14:55:07 volumio volumio[1149]: info: Sep 02 14:55:07 volumio volumio[1149]: ---------------------------- MPD announces state update: player Sep 02 14:55:07 volumio volumio[1149]: info: ControllerMpd::getState Sep 02 14:55:07 volumio volumio[1149]: verbose: ControllerMpd::sendMpdCommand status Sep 02 14:55:07 volumio volumio[1149]: info: Sep 02 14:55:07 volumio volumio[1149]: ---------------------------- MPD announces state update: player Sep 02 14:55:07 volumio volumio[1149]: info: sendMpdCommand status took 3 milliseconds Sep 02 14:55:07 volumio volumio[1149]: info: ControllerMpd::getState Sep 02 14:55:07 volumio volumio[1149]: verbose: ControllerMpd::sendMpdCommand status Sep 02 14:55:07 volumio volumio[1149]: verbose: ControllerMpd::parseState Sep 02 14:55:07 volumio volumio[1149]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 02 14:55:07 volumio volumio[1149]: info: sendMpdCommand status took 3 milliseconds Sep 02 14:55:07 volumio volumio[1149]: verbose: ControllerMpd::parseState Sep 02 14:55:07 volumio volumio[1149]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 02 14:55:07 volumio volumio[1149]: info: sendMpdCommand playlistinfo took 3 milliseconds Sep 02 14:55:07 volumio volumio[1149]: info: sendMpdCommand playlistinfo took 1 milliseconds Sep 02 14:55:07 volumio volumio[1149]: verbose: ControllerMpd::parseTrackInfo Sep 02 14:55:07 volumio volumio[1149]: verbose: ControllerMpd::parseTrackInfo Sep 02 14:55:07 volumio volumio[1149]: info: ControllerMpd::pushState Sep 02 14:55:07 volumio volumio[1149]: info: CoreCommandRouter::servicePushState Sep 02 14:55:07 volumio volumio[1149]: info: CorePlayQueue::getTrack 1 Sep 02 14:55:07 volumio volumio[1149]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":390,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":"original.flac?DeviceProfileId=c3dded503748480b95855c76e31cf2f7&DeviceId=08a3735b38a8c3334f24ad9cdc93c804&MediaSourceId=6ebbbcc1458ebaa04ae149f2a6cf5113&PlaySessionId=2b488fcb5f5ddd5c8d66c4070a44e286&api_key=47bb1d2f1a7b45479037b494c036a36a","artist":null,"album":null,"uri":"http://192.168.0.62:8096/audio/371481/original.flac?DeviceProfileId=c3dded503748480b95855c76e31cf2f7&DeviceId=08a3735b38a8c3334f24ad9cdc93c804&MediaSourceId=6ebbbcc1458ebaa04ae149f2a6cf5113&PlaySessionId=2b488fcb5f5ddd5c8d66c4070a44e286&api_key=47bb1d2f1a7b45479037b494c036a36a","trackType":""} Sep 02 14:55:07 volumio volumio[1149]: verbose: CURRENT POSITION 1 Sep 02 14:55:07 volumio volumio[1149]: info: CoreStateMachine::syncState stateService play Sep 02 14:55:07 volumio volumio[1149]: info: CoreStateMachine::syncState currentStatus stop Sep 02 14:55:07 volumio volumio[1149]: info: ControllerMpd::pushState Sep 02 14:55:07 volumio volumio[1149]: info: CoreCommandRouter::servicePushState Sep 02 14:55:07 volumio volumio[1149]: info: CorePlayQueue::getTrack 1 Sep 02 14:55:07 volumio volumio[1149]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":390,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":"original.flac?DeviceProfileId=c3dded503748480b95855c76e31cf2f7&DeviceId=08a3735b38a8c3334f24ad9cdc93c804&MediaSourceId=6ebbbcc1458ebaa04ae149f2a6cf5113&PlaySessionId=2b488fcb5f5ddd5c8d66c4070a44e286&api_key=47bb1d2f1a7b45479037b494c036a36a","artist":null,"album":null,"uri":"http://192.168.0.62:8096/audio/371481/original.flac?DeviceProfileId=c3dded503748480b95855c76e31cf2f7&DeviceId=08a3735b38a8c3334f24ad9cdc93c804&MediaSourceId=6ebbbcc1458ebaa04ae149f2a6cf5113&PlaySessionId=2b488fcb5f5ddd5c8d66c4070a44e286&api_key=47bb1d2f1a7b45479037b494c036a36a","trackType":""} Sep 02 14:55:07 volumio volumio[1149]: verbose: CURRENT POSITION 1 Sep 02 14:55:07 volumio volumio[1149]: info: CoreStateMachine::syncState stateService play Sep 02 14:55:07 volumio volumio[1149]: info: CoreStateMachine::syncState currentStatus play Sep 02 14:55:07 volumio volumio[1149]: info: Received an update from plugin. extracting info from payload Sep 02 14:55:07 volumio volumio[1149]: info: CoreStateMachine::pushState Sep 02 14:55:07 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 02 14:55:07 volumio volumio[1149]: info: CoreCommandRouter::volumioPushState Sep 02 14:55:07 volumio volumio[1149]: info: MRS: Pushing multiroomSync output update for this device Sep 02 14:55:07 volumio volumio[1149]: info: MRS: Pushing multiroomSync output Sep 02 14:55:07 volumio volumio[1149]: info: CoreCommandRouter::volumioGetState Sep 02 14:55:07 volumio volumio[1149]: info: CoreStateMachine::pushState Sep 02 14:55:07 volumio volumio[1149]: info: CoreCommandRouter::volumioPushState Sep 02 14:55:07 volumio volumio[1149]: info: MRS: Pushing multiroomSync output update for this device Sep 02 14:55:07 volumio volumio[1149]: info: MRS: Pushing multiroomSync output Sep 02 14:55:07 volumio volumio[1149]: info: CoreCommandRouter::volumioGetState Sep 02 14:55:07 volumio volumio[1149]: info: ------------------------------ 37ms Sep 02 14:55:07 volumio volumio[1149]: info: ------------------------------ 84ms Sep 02 14:55:07 volumio volumio[1149]: info: Sep 02 14:55:07 volumio volumio[1149]: ---------------------------- MPD announces system playlist update Sep 02 14:55:07 volumio volumio[1149]: info: Ignoring MPD Status Update Sep 02 14:55:07 volumio volumio[1149]: info: Sep 02 14:55:07 volumio volumio[1149]: ---------------------------- MPD announces state update: player Sep 02 14:55:07 volumio volumio[1149]: info: ControllerMpd::getState Sep 02 14:55:07 volumio volumio[1149]: verbose: ControllerMpd::sendMpdCommand status Sep 02 14:55:07 volumio volumio[1149]: info: ------------------------------ 22ms Sep 02 14:55:07 volumio volumio[1149]: info: sendMpdCommand status took 21 milliseconds Sep 02 14:55:07 volumio volumio[1149]: verbose: ControllerMpd::parseState Sep 02 14:55:07 volumio volumio[1149]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 02 14:55:07 volumio volumio[1149]: info: sendMpdCommand playlistinfo took 1 milliseconds Sep 02 14:55:07 volumio volumio[1149]: verbose: ControllerMpd::parseTrackInfo Sep 02 14:55:07 volumio volumio[1149]: info: ControllerMpd::pushState Sep 02 14:55:07 volumio volumio[1149]: info: CoreCommandRouter::servicePushState Sep 02 14:55:07 volumio volumio[1149]: info: CorePlayQueue::getTrack 1 Sep 02 14:55:07 volumio volumio[1149]: verbose: STATE SERVICE {"status":"play","position":0,"seek":763,"duration":390,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"5136 Kbps","isStreaming":false,"title":"Leave In Silence (Longer)","artist":"Depeche Mode","album":"A Broken Frame | The 12\" Singles","uri":"http://192.168.0.62:8096/audio/371481/original.flac?DeviceProfileId=c3dded503748480b95855c76e31cf2f7&DeviceId=08a3735b38a8c3334f24ad9cdc93c804&MediaSourceId=6ebbbcc1458ebaa04ae149f2a6cf5113&PlaySessionId=2b488fcb5f5ddd5c8d66c4070a44e286&api_key=47bb1d2f1a7b45479037b494c036a36a","trackType":""} Sep 02 14:55:07 volumio volumio[1149]: verbose: CURRENT POSITION 1 Sep 02 14:55:07 volumio volumio[1149]: info: CoreStateMachine::syncState stateService play Sep 02 14:55:07 volumio volumio[1149]: info: CoreStateMachine::syncState currentStatus play Sep 02 14:55:07 volumio volumio[1149]: info: Received an update from plugin. extracting info from payload Sep 02 14:55:07 volumio volumio[1149]: info: CoreStateMachine::pushState Sep 02 14:55:07 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 02 14:55:07 volumio volumio[1149]: info: CoreCommandRouter::volumioPushState Sep 02 14:55:07 volumio volumio[1149]: info: MRS: Pushing multiroomSync output update for this device Sep 02 14:55:07 volumio volumio[1149]: info: MRS: Pushing multiroomSync output Sep 02 14:55:07 volumio volumio[1149]: info: CoreCommandRouter::volumioGetState Sep 02 14:55:07 volumio volumio[1149]: info: CoreStateMachine::pushState Sep 02 14:55:07 volumio volumio[1149]: info: CoreCommandRouter::volumioPushState Sep 02 14:55:07 volumio volumio[1149]: info: MRS: Pushing multiroomSync output update for this device Sep 02 14:55:07 volumio volumio[1149]: info: MRS: Pushing multiroomSync output Sep 02 14:55:07 volumio volumio[1149]: info: CoreCommandRouter::volumioGetState Sep 02 14:55:07 volumio volumio[1149]: info: ------------------------------ 103ms Sep 02 14:55:07 volumio volumio[1149]: info: CoreCommandRouter::volumioGetQueue Sep 02 14:55:07 volumio volumio[1149]: info: CoreStateMachine::getQueue Sep 02 14:55:07 volumio volumio[1149]: info: CorePlayQueue::getQueue Sep 02 14:55:07 volumio volumio[1149]: info: CoreCommandRouter::volumioGetQueue Sep 02 14:55:07 volumio volumio[1149]: info: CoreStateMachine::getQueue Sep 02 14:55:07 volumio volumio[1149]: info: CorePlayQueue::getQueue Sep 02 14:55:08 volumio volumio[1149]: error: error Sep 02 14:55:08 volumio volumio[1149]: error: error Sep 02 14:55:08 volumio volumio[1149]: error: error Sep 02 14:55:08 volumio volumio[1149]: error: error Sep 02 14:55:08 volumio volumio[1149]: error: error Sep 02 14:55:08 volumio volumio[1149]: error: error Sep 02 14:55:09 volumio volumio[1149]: error: error Sep 02 14:55:09 volumio volumio[1149]: error: error Sep 02 14:55:09 volumio volumio[1149]: error: error Sep 02 14:55:09 volumio volumio[1149]: error: error Sep 02 14:55:09 volumio volumio[1149]: error: error Sep 02 14:55:09 volumio volumio[1149]: error: error Sep 02 14:55:09 volumio volumio[1149]: error: error Sep 02 14:55:09 volumio volumio[1149]: error: error Sep 02 14:55:09 volumio volumio[1149]: error: error Sep 02 14:55:09 volumio volumio[1149]: error: error Sep 02 14:55:09 volumio volumio[1149]: error: error Sep 02 14:55:09 volumio volumio[1149]: error: error Sep 02 14:55:09 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 02 14:55:09 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 02 14:55:09 volumio volumio[1149]: info: Discovery: Getting this device information Sep 02 14:55:09 volumio volumio[1149]: info: CoreCommandRouter::volumioGetState Sep 02 14:55:09 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 02 14:55:22 volumio volumio[1149]: info: VolumeController::SetAlsaVolume+ Sep 02 14:55:22 volumio volumio[1149]: info: CoreStateMachine::pushState Sep 02 14:55:22 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 02 14:55:22 volumio volumio[1149]: info: CoreCommandRouter::volumioPushState Sep 02 14:55:22 volumio volumio[1149]: info: MRS: Pushing multiroomSync output update for this device Sep 02 14:55:22 volumio volumio[1149]: info: MRS: Pushing multiroomSync output Sep 02 14:55:22 volumio volumio[1149]: info: CoreCommandRouter::volumioGetState Sep 02 14:55:22 volumio volumio[1149]: info: CoreCommandRouter::volumioGetQueue Sep 02 14:55:22 volumio volumio[1149]: info: CoreStateMachine::getQueue Sep 02 14:55:22 volumio volumio[1149]: info: CorePlayQueue::getQueue Sep 02 14:55:22 volumio volumio[1149]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified Sep 02 14:55:22 volumio volumio[1149]: xcb_connection_has_error() returned true Sep 02 14:55:23 volumio volumio[1149]: info: VolumeController::SetAlsaVolume+ Sep 02 14:55:23 volumio volumio[1149]: info: CoreStateMachine::pushState Sep 02 14:55:23 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 02 14:55:23 volumio volumio[1149]: info: CoreCommandRouter::volumioPushState Sep 02 14:55:23 volumio volumio[1149]: info: MRS: Pushing multiroomSync output update for this device Sep 02 14:55:23 volumio volumio[1149]: info: MRS: Pushing multiroomSync output Sep 02 14:55:23 volumio volumio[1149]: info: CoreCommandRouter::volumioGetState Sep 02 14:55:23 volumio volumio[1149]: info: CoreCommandRouter::volumioGetQueue Sep 02 14:55:23 volumio volumio[1149]: info: CoreStateMachine::getQueue Sep 02 14:55:23 volumio volumio[1149]: info: CorePlayQueue::getQueue Sep 02 14:55:23 volumio volumio[1149]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified Sep 02 14:55:23 volumio volumio[1149]: xcb_connection_has_error() returned true Sep 02 14:55:24 volumio volumio[1149]: info: VolumeController::SetAlsaVolume+ Sep 02 14:55:24 volumio volumio[1149]: info: CoreStateMachine::pushState Sep 02 14:55:24 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 02 14:55:24 volumio volumio[1149]: info: CoreCommandRouter::volumioPushState Sep 02 14:55:24 volumio volumio[1149]: info: MRS: Pushing multiroomSync output update for this device Sep 02 14:55:24 volumio volumio[1149]: info: MRS: Pushing multiroomSync output Sep 02 14:55:24 volumio volumio[1149]: info: CoreCommandRouter::volumioGetState Sep 02 14:55:24 volumio volumio[1149]: info: CoreCommandRouter::volumioGetQueue Sep 02 14:55:24 volumio volumio[1149]: info: CoreStateMachine::getQueue Sep 02 14:55:24 volumio volumio[1149]: info: CorePlayQueue::getQueue Sep 02 14:55:24 volumio volumio[1149]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified Sep 02 14:55:24 volumio volumio[1149]: xcb_connection_has_error() returned true Sep 02 14:55:25 volumio volumio[1149]: info: VolumeController::SetAlsaVolume20 Sep 02 14:55:25 volumio volumio[1149]: info: CoreStateMachine::pushState Sep 02 14:55:25 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 02 14:55:25 volumio volumio[1149]: info: CoreCommandRouter::volumioPushState Sep 02 14:55:25 volumio volumio[1149]: info: MRS: Pushing multiroomSync output update for this device Sep 02 14:55:25 volumio volumio[1149]: info: MRS: Pushing multiroomSync output Sep 02 14:55:25 volumio volumio[1149]: info: CoreCommandRouter::volumioGetState Sep 02 14:55:25 volumio volumio[1149]: info: CoreCommandRouter::volumioGetQueue Sep 02 14:55:25 volumio volumio[1149]: info: CoreStateMachine::getQueue Sep 02 14:55:25 volumio volumio[1149]: info: CorePlayQueue::getQueue Sep 02 14:55:25 volumio volumio[1149]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified Sep 02 14:55:25 volumio volumio[1149]: xcb_connection_has_error() returned true Sep 02 14:55:28 volumio volumio[1149]: info: VolumeController::SetAlsaVolume45 Sep 02 14:55:28 volumio volumio[1149]: info: CoreStateMachine::pushState Sep 02 14:55:28 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 02 14:55:28 volumio volumio[1149]: info: CoreCommandRouter::volumioPushState Sep 02 14:55:28 volumio volumio[1149]: info: MRS: Pushing multiroomSync output update for this device Sep 02 14:55:28 volumio volumio[1149]: info: MRS: Pushing multiroomSync output Sep 02 14:55:28 volumio volumio[1149]: info: CoreCommandRouter::volumioGetState Sep 02 14:55:28 volumio volumio[1149]: info: CoreCommandRouter::volumioGetQueue Sep 02 14:55:28 volumio volumio[1149]: info: CoreStateMachine::getQueue Sep 02 14:55:28 volumio volumio[1149]: info: CorePlayQueue::getQueue Sep 02 14:55:28 volumio volumio[1149]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified Sep 02 14:55:28 volumio volumio[1149]: xcb_connection_has_error() returned true Sep 02 14:55:33 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Sep 02 14:55:33 volumio volumio[1149]: info: CURURI: music-library Sep 02 14:55:33 volumio volumio[1149]: info: Preload queue cleared Sep 02 14:55:34 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Sep 02 14:55:34 volumio volumio[1149]: info: CURURI: music-library/USB Sep 02 14:55:34 volumio volumio[1149]: info: Preload queue cleared Sep 02 14:55:35 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Sep 02 14:55:35 volumio volumio[1149]: info: CURURI: music-library/USB/Music_BACK_UP Sep 02 14:55:35 volumio volumio[1149]: info: Preload queue cleared Sep 02 14:55:37 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Sep 02 14:55:37 volumio volumio[1149]: info: CURURI: music-library/USB/Music_BACK_UP/Music Bibliothek Sep 02 14:55:37 volumio volumio[1149]: info: Preload queue cleared Sep 02 14:55:39 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Sep 02 14:55:39 volumio volumio[1149]: info: CURURI: music-library/USB/Music_BACK_UP/Music Bibliothek/Adh​é​mar Sep 02 14:55:39 volumio volumio[1149]: info: Preload queue cleared Sep 02 14:55:39 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 02 14:55:39 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 02 14:55:39 volumio volumio[1149]: info: Discovery: Getting this device information Sep 02 14:55:39 volumio volumio[1149]: info: CoreCommandRouter::volumioGetState Sep 02 14:55:39 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 02 14:55:41 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Sep 02 14:55:41 volumio volumio[1149]: info: CURURI: music-library/USB/Music_BACK_UP/Music Bibliothek/Adh​é​mar/Night Bloom Sep 02 14:55:41 volumio volumio[1149]: info: Preload queue cleared Sep 02 14:55:41 volumio volumio[1149]: info: Preloading song: music-library/USB/Music_BACK_UP/Music Bibliothek/Adh​é​mar/Night Bloom/01-Freshness of the Sunset.flac Sep 02 14:55:41 volumio volumio[1149]: info: Preloading song: music-library/USB/Music_BACK_UP/Music Bibliothek/Adh​é​mar/Night Bloom/02-Around the Pond.flac Sep 02 14:55:41 volumio volumio[1149]: info: Preloading song: music-library/USB/Music_BACK_UP/Music Bibliothek/Adh​é​mar/Night Bloom/03-Smell of Jasmines.flac Sep 02 14:55:41 volumio volumio[1149]: info: Preloading song: music-library/USB/Music_BACK_UP/Music Bibliothek/Adh​é​mar/Night Bloom/04-Blue Moonlight.flac Sep 02 14:55:41 volumio volumio[1149]: info: Preloading song: music-library/USB/Music_BACK_UP/Music Bibliothek/Adh​é​mar/Night Bloom/05-Around the pond (Laima Adelaide Remix).flac Sep 02 14:55:41 volumio volumio[1149]: info: Preloading song: music-library/USB/Music_BACK_UP/Music Bibliothek/Adh​é​mar/Night Bloom/06-Freshness of the Sunset (Atoloi Remix).flac Sep 02 14:55:41 volumio volumio[1149]: info: Exploding uri music-library/USB/Music_BACK_UP/Music Bibliothek/Adh​é​mar/Night Bloom/01-Freshness of the Sunset.flac in service mpd Sep 02 14:55:41 volumio volumio[1149]: info: ALBUMART /albumart?cacheid=112&web=Adh%C3%A9mar/Night%20Bloom/small&path=%2Fmnt%2FUSB%2FMusic_BACK_UP%2FMusic%20Bibliothek%2FAdh%E2%80%8B%C3%A9%E2%80%8Bmar%2FNight%20Bloom%2F01-Freshness%20of%20the%20Sunset.flac&metadata=false Sep 02 14:55:41 volumio volumio[1149]: info: URI /mnt/USB/Music_BACK_UP/Music Bibliothek/Adh​é​mar/Night Bloom/01-Freshness of the Sunset.flac Sep 02 14:55:41 volumio volumio[1149]: info: Exploding uri music-library/USB/Music_BACK_UP/Music Bibliothek/Adh​é​mar/Night Bloom/02-Around the Pond.flac in service mpd Sep 02 14:55:41 volumio volumio[1149]: info: ALBUMART /albumart?cacheid=112&web=Adh%C3%A9mar/Night%20Bloom/small&path=%2Fmnt%2FUSB%2FMusic_BACK_UP%2FMusic%20Bibliothek%2FAdh%E2%80%8B%C3%A9%E2%80%8Bmar%2FNight%20Bloom%2F02-Around%20the%20Pond.flac&metadata=false Sep 02 14:55:41 volumio volumio[1149]: info: URI /mnt/USB/Music_BACK_UP/Music Bibliothek/Adh​é​mar/Night Bloom/02-Around the Pond.flac Sep 02 14:55:41 volumio volumio[1149]: info: Exploding uri music-library/USB/Music_BACK_UP/Music Bibliothek/Adh​é​mar/Night Bloom/03-Smell of Jasmines.flac in service mpd Sep 02 14:55:41 volumio volumio[1149]: info: ALBUMART /albumart?cacheid=112&web=Adh%C3%A9mar/Night%20Bloom/small&path=%2Fmnt%2FUSB%2FMusic_BACK_UP%2FMusic%20Bibliothek%2FAdh%E2%80%8B%C3%A9%E2%80%8Bmar%2FNight%20Bloom%2F03-Smell%20of%20Jasmines.flac&metadata=false Sep 02 14:55:41 volumio volumio[1149]: info: URI /mnt/USB/Music_BACK_UP/Music Bibliothek/Adh​é​mar/Night Bloom/03-Smell of Jasmines.flac Sep 02 14:55:41 volumio volumio[1149]: info: Exploding uri music-library/USB/Music_BACK_UP/Music Bibliothek/Adh​é​mar/Night Bloom/04-Blue Moonlight.flac in service mpd Sep 02 14:55:41 volumio volumio[1149]: info: ALBUMART /albumart?cacheid=112&web=Adh%C3%A9mar/Night%20Bloom/small&path=%2Fmnt%2FUSB%2FMusic_BACK_UP%2FMusic%20Bibliothek%2FAdh%E2%80%8B%C3%A9%E2%80%8Bmar%2FNight%20Bloom%2F04-Blue%20Moonlight.flac&metadata=false Sep 02 14:55:41 volumio volumio[1149]: info: URI /mnt/USB/Music_BACK_UP/Music Bibliothek/Adh​é​mar/Night Bloom/04-Blue Moonlight.flac Sep 02 14:55:41 volumio volumio[1149]: info: Exploding uri music-library/USB/Music_BACK_UP/Music Bibliothek/Adh​é​mar/Night Bloom/05-Around the pond (Laima Adelaide Remix).flac in service mpd Sep 02 14:55:41 volumio volumio[1149]: info: ALBUMART /albumart?cacheid=112&web=Adh%C3%A9mar/Night%20Bloom/small&path=%2Fmnt%2FUSB%2FMusic_BACK_UP%2FMusic%20Bibliothek%2FAdh%E2%80%8B%C3%A9%E2%80%8Bmar%2FNight%20Bloom%2F05-Around%20the%20pond%20(Laima%20Adelaide%20Remix).flac&metadata=false Sep 02 14:55:41 volumio volumio[1149]: info: URI /mnt/USB/Music_BACK_UP/Music Bibliothek/Adh​é​mar/Night Bloom/05-Around the pond (Laima Adelaide Remix).flac Sep 02 14:55:41 volumio volumio[1149]: info: Exploding uri music-library/USB/Music_BACK_UP/Music Bibliothek/Adh​é​mar/Night Bloom/06-Freshness of the Sunset (Atoloi Remix).flac in service mpd Sep 02 14:55:41 volumio volumio[1149]: info: ALBUMART /albumart?cacheid=112&web=Adh%C3%A9mar/Night%20Bloom/small&path=%2Fmnt%2FUSB%2FMusic_BACK_UP%2FMusic%20Bibliothek%2FAdh%E2%80%8B%C3%A9%E2%80%8Bmar%2FNight%20Bloom%2F06-Freshness%20of%20the%20Sunset%20(Atoloi%20Remix).flac&metadata=false Sep 02 14:55:41 volumio volumio[1149]: info: URI /mnt/USB/Music_BACK_UP/Music Bibliothek/Adh​é​mar/Night Bloom/06-Freshness of the Sunset (Atoloi Remix).flac Sep 02 14:55:42 volumio volumio[1149]: info: Preload queue cleared Sep 02 14:55:42 volumio volumio[1149]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 02 14:55:42 volumio volumio[1149]: info: CoreStateMachine::ClearQueue Sep 02 14:55:42 volumio volumio[1149]: info: CoreStateMachine::stop Sep 02 14:55:42 volumio volumio[1149]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 02 14:55:42 volumio volumio[1149]: info: CoreStateMachine::stPlaybackTimer Sep 02 14:55:42 volumio volumio[1149]: info: CoreStateMachine::updateTrackBlock Sep 02 14:55:42 volumio volumio[1149]: info: CorePlayQueue::getTrackBlock Sep 02 14:55:42 volumio volumio[1149]: info: CoreStateMachine::pushState Sep 02 14:55:42 volumio volumio[1149]: info: CorePlayQueue::getTrack 1 Sep 02 14:55:42 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 02 14:55:42 volumio volumio[1149]: info: CoreCommandRouter::volumioPushState Sep 02 14:55:42 volumio volumio[1149]: info: MRS: Pushing multiroomSync output update for this device Sep 02 14:55:42 volumio volumio[1149]: info: MRS: Pushing multiroomSync output Sep 02 14:55:42 volumio volumio[1149]: info: CoreCommandRouter::volumioGetState Sep 02 14:55:42 volumio volumio[1149]: info: CorePlayQueue::getTrack 1 Sep 02 14:55:42 volumio volumio[1149]: info: CoreStateMachine::serviceStop Sep 02 14:55:42 volumio volumio[1149]: info: CorePlayQueue::getTrack 1 Sep 02 14:55:42 volumio volumio[1149]: info: CoreCommandRouter::serviceStop Sep 02 14:55:42 volumio volumio[1149]: info: [1756824942928] ControllerUPNPBrowser::stop Sep 02 14:55:42 volumio volumio[1149]: verbose: ControllerMpd::sendMpdCommand stop Sep 02 14:55:42 volumio volumio[1149]: info: CorePlayQueue::clearPlayQueue Sep 02 14:55:42 volumio volumio[1149]: info: CorePlayQueue::saveQueue Sep 02 14:55:42 volumio volumio[1149]: info: CoreCommandRouter::volumioPushQueue Sep 02 14:55:42 volumio volumio[1149]: info: CoreStateMachine::addQueueItems Sep 02 14:55:42 volumio volumio[1149]: info: CorePlayQueue::addQueueItems Sep 02 14:55:42 volumio volumio[1149]: info: Preload queue cleared Sep 02 14:55:42 volumio volumio[1149]: info: Adding Item to queue: music-library/USB/Music_BACK_UP/Music Bibliothek/Adh​é​mar/Night Bloom/01-Freshness of the Sunset.flac Sep 02 14:55:42 volumio volumio[1149]: info: Using cached record of: music-library/USB/Music_BACK_UP/Music Bibliothek/Adh​é​mar/Night Bloom/01-Freshness of the Sunset.flac Sep 02 14:55:42 volumio volumio[1149]: info: CoreCommandRouter::volumioPushQueue Sep 02 14:55:42 volumio volumio[1149]: info: CorePlayQueue::saveQueue Sep 02 14:55:42 volumio volumio[1149]: info: CoreStateMachine::updateTrackBlock Sep 02 14:55:42 volumio volumio[1149]: info: CorePlayQueue::getTrackBlock Sep 02 14:55:42 volumio volumio[1149]: info: CoreCommandRouter::volumioPlay Sep 02 14:55:42 volumio volumio[1149]: info: CoreStateMachine::play index 0 Sep 02 14:55:42 volumio volumio[1149]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 02 14:55:42 volumio volumio[1149]: info: CoreStateMachine::addQueueItems Sep 02 14:55:42 volumio volumio[1149]: info: CorePlayQueue::addQueueItems Sep 02 14:55:42 volumio volumio[1149]: info: Preload queue cleared Sep 02 14:55:42 volumio volumio[1149]: info: Adding Item to queue: music-library/USB/Music_BACK_UP/Music Bibliothek/Adh​é​mar/Night Bloom/02-Around the Pond.flac Sep 02 14:55:42 volumio volumio[1149]: info: Using cached record of: music-library/USB/Music_BACK_UP/Music Bibliothek/Adh​é​mar/Night Bloom/02-Around the Pond.flac Sep 02 14:55:42 volumio volumio[1149]: info: Adding Item to queue: music-library/USB/Music_BACK_UP/Music Bibliothek/Adh​é​mar/Night Bloom/03-Smell of Jasmines.flac Sep 02 14:55:42 volumio volumio[1149]: info: Using cached record of: music-library/USB/Music_BACK_UP/Music Bibliothek/Adh​é​mar/Night Bloom/03-Smell of Jasmines.flac Sep 02 14:55:42 volumio volumio[1149]: info: Adding Item to queue: music-library/USB/Music_BACK_UP/Music Bibliothek/Adh​é​mar/Night Bloom/04-Blue Moonlight.flac Sep 02 14:55:42 volumio volumio[1149]: info: Using cached record of: music-library/USB/Music_BACK_UP/Music Bibliothek/Adh​é​mar/Night Bloom/04-Blue Moonlight.flac Sep 02 14:55:42 volumio volumio[1149]: info: Adding Item to queue: music-library/USB/Music_BACK_UP/Music Bibliothek/Adh​é​mar/Night Bloom/05-Around the pond (Laima Adelaide Remix).flac Sep 02 14:55:42 volumio volumio[1149]: info: Using cached record of: music-library/USB/Music_BACK_UP/Music Bibliothek/Adh​é​mar/Night Bloom/05-Around the pond (Laima Adelaide Remix).flac Sep 02 14:55:42 volumio volumio[1149]: info: Adding Item to queue: music-library/USB/Music_BACK_UP/Music Bibliothek/Adh​é​mar/Night Bloom/06-Freshness of the Sunset (Atoloi Remix).flac Sep 02 14:55:42 volumio volumio[1149]: info: Using cached record of: music-library/USB/Music_BACK_UP/Music Bibliothek/Adh​é​mar/Night Bloom/06-Freshness of the Sunset (Atoloi Remix).flac Sep 02 14:55:42 volumio volumio[1149]: info: CoreStateMachine::stop Sep 02 14:55:42 volumio volumio[1149]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 02 14:55:42 volumio volumio[1149]: info: CoreCommandRouter::volumioPushQueue Sep 02 14:55:42 volumio volumio[1149]: info: CorePlayQueue::saveQueue Sep 02 14:55:42 volumio volumio[1149]: info: CoreStateMachine::play index undefined Sep 02 14:55:42 volumio volumio[1149]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 02 14:55:42 volumio volumio[1149]: info: CoreStateMachine::updateTrackBlock Sep 02 14:55:42 volumio volumio[1149]: info: CorePlayQueue::getTrackBlock Sep 02 14:55:42 volumio volumio[1149]: info: CorePlayQueue::getTrack 0 Sep 02 14:55:42 volumio volumio[1149]: info: CoreStateMachine::startPlaybackTimer Sep 02 14:55:42 volumio volumio[1149]: info: CorePlayQueue::getTrack 0 Sep 02 14:55:42 volumio volumio[1149]: verbose: ControllerMpd::clearAddPlayTracks USB/Music_BACK_UP/Music Bibliothek/Adh​é​mar/Night Bloom/01-Freshness of the Sunset.flac Sep 02 14:55:42 volumio volumio[1149]: verbose: ControllerMpd::sendMpdCommand stop Sep 02 14:55:43 volumio volumio[1149]: info: Sep 02 14:55:43 volumio volumio[1149]: ---------------------------- MPD announces state update: player Sep 02 14:55:43 volumio volumio[1149]: info: sendMpdCommand stop took 100 milliseconds Sep 02 14:55:43 volumio volumio[1149]: info: ControllerMpd::getState Sep 02 14:55:43 volumio volumio[1149]: verbose: ControllerMpd::sendMpdCommand status Sep 02 14:55:43 volumio volumio[1149]: info: sendMpdCommand stop took 41 milliseconds Sep 02 14:55:43 volumio volumio[1149]: verbose: ControllerMpd::sendMpdCommand clear Sep 02 14:55:43 volumio volumio[1149]: info: Sep 02 14:55:43 volumio volumio[1149]: ---------------------------- MPD announces system playlist update Sep 02 14:55:43 volumio volumio[1149]: info: Ignoring MPD Status Update Sep 02 14:55:43 volumio volumio[1149]: info: sendMpdCommand status took 18 milliseconds Sep 02 14:55:43 volumio volumio[1149]: info: sendMpdCommand clear took 17 milliseconds Sep 02 14:55:43 volumio volumio[1149]: verbose: ControllerMpd::parseState Sep 02 14:55:43 volumio volumio[1149]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 02 14:55:43 volumio volumio[1149]: verbose: ControllerMpd::sendMpdCommand add "USB/Music_BACK_UP/Music Bibliothek/Adh​é​mar/Night Bloom/01-Freshness of the Sunset.flac" Sep 02 14:55:43 volumio volumio[1149]: error: updateQueue error: null Sep 02 14:55:43 volumio volumio[1149]: info: Sep 02 14:55:43 volumio volumio[1149]: ---------------------------- MPD announces system playlist update Sep 02 14:55:43 volumio volumio[1149]: info: Ignoring MPD Status Update Sep 02 14:55:43 volumio volumio[1149]: info: ------------------------------ 11ms Sep 02 14:55:43 volumio volumio[1149]: info: sendMpdCommand playlistinfo took 10 milliseconds Sep 02 14:55:43 volumio volumio[1149]: info: sendMpdCommand add "USB/Music_BACK_UP/Music Bibliothek/Adh​é​mar/Night Bloom/01-Freshness of the Sunset.flac" took 10 milliseconds Sep 02 14:55:43 volumio volumio[1149]: verbose: ControllerMpd::parseTrackInfo Sep 02 14:55:43 volumio volumio[1149]: verbose: ControllerMpd::sendMpdCommand play Sep 02 14:55:43 volumio volumio[1149]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Sep 02 14:55:43 volumio volumio[1149]: info: ------------------------------ 32ms Sep 02 14:55:43 volumio volumio[1149]: info: Sep 02 14:55:43 volumio volumio[1149]: ---------------------------- MPD announces state update: player Sep 02 14:55:43 volumio volumio[1149]: info: ------------------------------ 94ms Sep 02 14:55:43 volumio volumio[1149]: info: sendMpdCommand play took 93 milliseconds Sep 02 14:55:43 volumio volumio[1149]: info: ControllerMpd::getState Sep 02 14:55:43 volumio volumio[1149]: verbose: ControllerMpd::sendMpdCommand status Sep 02 14:55:43 volumio volumio[1149]: info: Sep 02 14:55:43 volumio volumio[1149]: ---------------------------- MPD announces state update: player Sep 02 14:55:43 volumio volumio[1149]: info: ControllerMpd::getState Sep 02 14:55:43 volumio volumio[1149]: verbose: ControllerMpd::sendMpdCommand status Sep 02 14:55:43 volumio volumio[1149]: info: sendMpdCommand status took 107 milliseconds Sep 02 14:55:43 volumio volumio[1149]: verbose: ControllerMpd::parseState Sep 02 14:55:43 volumio volumio[1149]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 02 14:55:43 volumio volumio[1149]: info: sendMpdCommand status took 202 milliseconds Sep 02 14:55:43 volumio volumio[1149]: info: sendMpdCommand playlistinfo took 201 milliseconds Sep 02 14:55:43 volumio volumio[1149]: verbose: ControllerMpd::parseState Sep 02 14:55:43 volumio volumio[1149]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 02 14:55:43 volumio volumio[1149]: verbose: ControllerMpd::parseTrackInfo Sep 02 14:55:43 volumio volumio[1149]: info: ControllerMpd::pushState Sep 02 14:55:43 volumio volumio[1149]: info: CoreCommandRouter::servicePushState Sep 02 14:55:43 volumio volumio[1149]: info: CorePlayQueue::getTrack 0 Sep 02 14:55:43 volumio volumio[1149]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1212,"duration":455,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"424 Kbps","isStreaming":false,"title":"Freshness Of The Sunset","artist":"Adhémar","album":"Night Bloom","uri":"USB/Music_BACK_UP/Music Bibliothek/Adh​é​mar/Night Bloom/01-Freshness of the Sunset.flac","trackType":"flac"} Sep 02 14:55:43 volumio volumio[1149]: verbose: CURRENT POSITION 0 Sep 02 14:55:43 volumio volumio[1149]: info: CoreStateMachine::syncState stateService play Sep 02 14:55:43 volumio volumio[1149]: info: CoreStateMachine::syncState currentStatus stop Sep 02 14:55:43 volumio volumio[1149]: info: ------------------------------ 313ms Sep 02 14:55:43 volumio volumio[1149]: info: sendMpdCommand playlistinfo took 8 milliseconds Sep 02 14:55:43 volumio volumio[1149]: verbose: ControllerMpd::parseTrackInfo Sep 02 14:55:43 volumio volumio[1149]: info: ControllerMpd::pushState Sep 02 14:55:43 volumio volumio[1149]: info: CoreCommandRouter::servicePushState Sep 02 14:55:43 volumio volumio[1149]: info: CorePlayQueue::getTrack 0 Sep 02 14:55:43 volumio volumio[1149]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1464,"duration":455,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"434 Kbps","isStreaming":false,"title":"Freshness Of The Sunset","artist":"Adhémar","album":"Night Bloom","uri":"USB/Music_BACK_UP/Music Bibliothek/Adh​é​mar/Night Bloom/01-Freshness of the Sunset.flac","trackType":"flac"} Sep 02 14:55:43 volumio volumio[1149]: verbose: CURRENT POSITION 0 Sep 02 14:55:43 volumio volumio[1149]: info: CoreStateMachine::syncState stateService play Sep 02 14:55:43 volumio volumio[1149]: info: CoreStateMachine::syncState currentStatus play Sep 02 14:55:43 volumio volumio[1149]: info: Received an update from plugin. extracting info from payload Sep 02 14:55:43 volumio volumio[1149]: info: CoreStateMachine::pushState Sep 02 14:55:43 volumio volumio[1149]: info: CorePlayQueue::getTrack 0 Sep 02 14:55:43 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 02 14:55:43 volumio volumio[1149]: info: CoreCommandRouter::volumioPushState Sep 02 14:55:43 volumio volumio[1149]: info: MRS: Pushing multiroomSync output update for this device Sep 02 14:55:43 volumio volumio[1149]: info: MRS: Pushing multiroomSync output Sep 02 14:55:43 volumio volumio[1149]: info: CoreCommandRouter::volumioGetState Sep 02 14:55:43 volumio volumio[1149]: info: CorePlayQueue::getTrack 0 Sep 02 14:55:43 volumio volumio[1149]: info: CoreStateMachine::pushState Sep 02 14:55:43 volumio volumio[1149]: info: CorePlayQueue::getTrack 0 Sep 02 14:55:43 volumio volumio[1149]: info: CoreCommandRouter::volumioPushState Sep 02 14:55:43 volumio volumio[1149]: info: MRS: Pushing multiroomSync output update for this device Sep 02 14:55:43 volumio volumio[1149]: info: MRS: Pushing multiroomSync output Sep 02 14:55:43 volumio volumio[1149]: info: CoreCommandRouter::volumioGetState Sep 02 14:55:43 volumio volumio[1149]: info: CorePlayQueue::getTrack 0 Sep 02 14:55:43 volumio volumio[1149]: info: ------------------------------ 264ms Sep 02 14:55:43 volumio ntpd[1113]: Soliciting pool server 2001:43f8:691:100::58 Sep 02 14:55:55 volumio volumio[1149]: info: VolumeController::SetAlsaVolume+ Sep 02 14:55:55 volumio volumio[1149]: info: CoreStateMachine::pushState Sep 02 14:55:55 volumio volumio[1149]: info: CorePlayQueue::getTrack 0 Sep 02 14:55:55 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 02 14:55:55 volumio volumio[1149]: info: CoreCommandRouter::volumioPushState Sep 02 14:55:55 volumio volumio[1149]: info: MRS: Pushing multiroomSync output update for this device Sep 02 14:55:55 volumio volumio[1149]: info: MRS: Pushing multiroomSync output Sep 02 14:55:55 volumio volumio[1149]: info: CoreCommandRouter::volumioGetState Sep 02 14:55:55 volumio volumio[1149]: info: CorePlayQueue::getTrack 0 Sep 02 14:55:56 volumio volumio[1149]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified Sep 02 14:55:56 volumio volumio[1149]: xcb_connection_has_error() returned true Sep 02 14:55:57 volumio volumio[1149]: info: VolumeController::SetAlsaVolume+ Sep 02 14:55:57 volumio volumio[1149]: info: CoreStateMachine::pushState Sep 02 14:55:57 volumio volumio[1149]: info: CorePlayQueue::getTrack 0 Sep 02 14:55:57 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 02 14:55:57 volumio volumio[1149]: info: CoreCommandRouter::volumioPushState Sep 02 14:55:57 volumio volumio[1149]: info: MRS: Pushing multiroomSync output update for this device Sep 02 14:55:57 volumio volumio[1149]: info: MRS: Pushing multiroomSync output Sep 02 14:55:57 volumio volumio[1149]: info: CoreCommandRouter::volumioGetState Sep 02 14:55:57 volumio volumio[1149]: info: CorePlayQueue::getTrack 0 Sep 02 14:55:57 volumio volumio[1149]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified Sep 02 14:55:57 volumio volumio[1149]: xcb_connection_has_error() returned true Sep 02 14:55:59 volumio volumio[1149]: error: error Sep 02 14:55:59 volumio volumio[1149]: error: error Sep 02 14:55:59 volumio volumio[1149]: error: error Sep 02 14:55:59 volumio volumio[1149]: error: error Sep 02 14:55:59 volumio volumio[1149]: error: error Sep 02 14:55:59 volumio volumio[1149]: error: error Sep 02 14:55:59 volumio volumio[1149]: error: error Sep 02 14:55:59 volumio volumio[1149]: error: error Sep 02 14:55:59 volumio volumio[1149]: error: error Sep 02 14:55:59 volumio volumio[1149]: error: error Sep 02 14:55:59 volumio volumio[1149]: error: error Sep 02 14:55:59 volumio volumio[1149]: error: error Sep 02 14:55:59 volumio volumio[1149]: error: error Sep 02 14:55:59 volumio volumio[1149]: error: error Sep 02 14:55:59 volumio volumio[1149]: error: error Sep 02 14:55:59 volumio volumio[1149]: error: error Sep 02 14:56:00 volumio volumio[1149]: error: error Sep 02 14:56:00 volumio volumio[1149]: error: error Sep 02 14:56:00 volumio volumio[1149]: info: VolumeController::SetAlsaVolume30 Sep 02 14:56:00 volumio volumio[1149]: info: CoreStateMachine::pushState Sep 02 14:56:00 volumio volumio[1149]: info: CorePlayQueue::getTrack 0 Sep 02 14:56:00 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 02 14:56:00 volumio volumio[1149]: info: CoreCommandRouter::volumioPushState Sep 02 14:56:00 volumio volumio[1149]: info: MRS: Pushing multiroomSync output update for this device Sep 02 14:56:00 volumio volumio[1149]: info: MRS: Pushing multiroomSync output Sep 02 14:56:00 volumio volumio[1149]: info: CoreCommandRouter::volumioGetState Sep 02 14:56:00 volumio volumio[1149]: info: CorePlayQueue::getTrack 0 Sep 02 14:56:00 volumio volumio[1149]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified Sep 02 14:56:00 volumio volumio[1149]: xcb_connection_has_error() returned true Sep 02 14:56:09 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 02 14:56:09 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 02 14:56:09 volumio volumio[1149]: info: Discovery: Getting this device information Sep 02 14:56:09 volumio volumio[1149]: info: CoreCommandRouter::volumioGetState Sep 02 14:56:09 volumio volumio[1149]: info: CorePlayQueue::getTrack 0 Sep 02 14:56:09 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 02 14:56:23 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: multiroom , audioOutputPlay Sep 02 14:56:23 volumio volumio[1149]: info: Error : CoreCommandRouter::executeOnPlugin: No method [audioOutputPlay] in plugin multiroom Sep 02 14:56:23 volumio volumio[1149]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 02 14:56:23 volumio volumio[1149]: TypeError: Cannot read property 'then' of undefined Sep 02 14:56:23 volumio volumio[1149]: at outputs.audioOutputPlay (/volumio/app/plugins/audio_interface/outputs/index.js:367:9) Sep 02 14:56:23 volumio volumio[1149]: at CoreCommandRouter.audioOutputPlay (/volumio/app/index.js:2279:30) Sep 02 14:56:23 volumio volumio[1149]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1456:26) Sep 02 14:56:23 volumio volumio[1149]: at Socket.emit (events.js:400:28) Sep 02 14:56:23 volumio volumio[1149]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Sep 02 14:56:23 volumio volumio[1149]: at processTicksAndRejections (internal/process/task_queues.js:77:11) Sep 02 14:56:23 volumio volumio[1149]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 02 14:56:23 volumio sudo[5326]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-09-02 14:55 Sep 02 14:56:23 volumio sudo[5326]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="669bb6cc406bb77b11c5184fedb8a4dfd19ba4ec" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 10:55:15 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="tinkerboard" VOLUMIO_DEVICENAME="Asus Tinkerboard" VOLUMIO_HASH="2f3686ade78abf3b92c180a0c5b20c6b"