-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Sun 2025-09-14 16:06:47 CEST. -- Sep 14 16:05:00 volumio volumio[841]: info: Sep 14 16:05:00 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:00 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:00 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:00 volumio volumio[841]: info: Sep 14 16:05:00 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:00 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:00 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:00 volumio volumio[841]: info: Sep 14 16:05:00 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:00 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:00 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:00 volumio volumio[841]: info: Sep 14 16:05:00 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:00 volumio volumio[841]: info: sendMpdCommand status took 36 milliseconds Sep 14 16:05:00 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:00 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:00 volumio volumio[841]: info: sendMpdCommand status took 21 milliseconds Sep 14 16:05:00 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:00 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:00 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:00 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:00 volumio volumio[841]: info: Sep 14 16:05:00 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:00 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:00 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:00 volumio volumio[841]: info: Sep 14 16:05:00 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:00 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:00 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:00 volumio volumio[841]: info: sendMpdCommand status took 37 milliseconds Sep 14 16:05:00 volumio volumio[841]: info: sendMpdCommand status took 22 milliseconds Sep 14 16:05:00 volumio volumio[841]: info: sendMpdCommand playlistinfo took 20 milliseconds Sep 14 16:05:00 volumio volumio[841]: info: sendMpdCommand playlistinfo took 19 milliseconds Sep 14 16:05:00 volumio volumio[841]: info: sendMpdCommand status took 17 milliseconds Sep 14 16:05:00 volumio volumio[841]: info: sendMpdCommand status took 14 milliseconds Sep 14 16:05:00 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:00 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:00 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:00 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:00 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:05:00 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:05:00 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:00 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:00 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:00 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:00 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:00 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:00 volumio volumio[841]: info: CorePlayQueue::getTrack 2 Sep 14 16:05:00 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":275,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"227945.m4a","artist":null,"album":null,"uri":"http://192.168.1.10:50002/m/NDLNA/227945.m4a","trackType":"m4a"} Sep 14 16:05:00 volumio volumio[841]: verbose: CURRENT POSITION 2 Sep 14 16:05:00 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:05:00 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus stop Sep 14 16:05:00 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:00 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:00 volumio volumio[841]: info: CorePlayQueue::getTrack 2 Sep 14 16:05:00 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":275,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"227945.m4a","artist":null,"album":null,"uri":"http://192.168.1.10:50002/m/NDLNA/227945.m4a","trackType":"m4a"} Sep 14 16:05:00 volumio volumio[841]: verbose: CURRENT POSITION 2 Sep 14 16:05:00 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:05:00 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:05:00 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:05:00 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:00 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:05:00 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:00 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:00 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:00 volumio volumio[841]: info: ------------------------------ 100ms Sep 14 16:05:00 volumio volumio[841]: info: ------------------------------ 120ms Sep 14 16:05:00 volumio volumio[841]: info: sendMpdCommand playlistinfo took 58 milliseconds Sep 14 16:05:00 volumio volumio[841]: info: sendMpdCommand playlistinfo took 58 milliseconds Sep 14 16:05:00 volumio volumio[841]: info: sendMpdCommand playlistinfo took 55 milliseconds Sep 14 16:05:00 volumio volumio[841]: info: sendMpdCommand playlistinfo took 54 milliseconds Sep 14 16:05:00 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:05:00 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:05:00 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:05:00 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:05:00 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:00 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:00 volumio volumio[841]: info: CorePlayQueue::getTrack 2 Sep 14 16:05:00 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":114,"duration":275,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"249 Kbps","isStreaming":false,"title":"227945.m4a","artist":null,"album":null,"uri":"http://192.168.1.10:50002/m/NDLNA/227945.m4a","trackType":"m4a"} Sep 14 16:05:00 volumio volumio[841]: verbose: CURRENT POSITION 2 Sep 14 16:05:00 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:05:00 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:05:00 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:05:00 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:00 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:05:00 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:00 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:00 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:00 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:00 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:00 volumio volumio[841]: info: CorePlayQueue::getTrack 2 Sep 14 16:05:00 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":982,"duration":275,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"249 Kbps","isStreaming":false,"title":"227945.m4a","artist":null,"album":null,"uri":"http://192.168.1.10:50002/m/NDLNA/227945.m4a","trackType":"m4a"} Sep 14 16:05:00 volumio volumio[841]: verbose: CURRENT POSITION 2 Sep 14 16:05:00 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:05:00 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:05:00 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:05:00 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:00 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:00 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:00 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:00 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:00 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:00 volumio volumio[841]: info: CorePlayQueue::getTrack 2 Sep 14 16:05:00 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":982,"duration":275,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"249 Kbps","isStreaming":false,"title":"227945.m4a","artist":null,"album":null,"uri":"http://192.168.1.10:50002/m/NDLNA/227945.m4a","trackType":"m4a"} Sep 14 16:05:00 volumio volumio[841]: verbose: CURRENT POSITION 2 Sep 14 16:05:00 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:05:00 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:05:00 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:05:00 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:00 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:00 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:00 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:00 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:00 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:00 volumio volumio[841]: info: CorePlayQueue::getTrack 2 Sep 14 16:05:00 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":982,"duration":275,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"249 Kbps","isStreaming":false,"title":"227945.m4a","artist":null,"album":null,"uri":"http://192.168.1.10:50002/m/NDLNA/227945.m4a","trackType":"m4a"} Sep 14 16:05:00 volumio volumio[841]: verbose: CURRENT POSITION 2 Sep 14 16:05:00 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:05:00 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:05:00 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:05:00 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:00 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:00 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:00 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:00 volumio volumio[841]: info: ------------------------------ 235ms Sep 14 16:05:00 volumio volumio[841]: info: ------------------------------ 232ms Sep 14 16:05:00 volumio volumio[841]: info: ------------------------------ 212ms Sep 14 16:05:00 volumio volumio[841]: info: ------------------------------ 210ms Sep 14 16:05:02 volumio volumio[841]: info: CoreCommandRouter::volumioNext Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::next Sep 14 16:05:02 volumio volumio[841]: info: ControllerMpd::next Sep 14 16:05:02 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand next Sep 14 16:05:02 volumio volumio[841]: info: sendMpdCommand next took 8 milliseconds Sep 14 16:05:02 volumio volumio[841]: info: Sep 14 16:05:02 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:02 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:02 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:02 volumio volumio[841]: info: Sep 14 16:05:02 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:02 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:02 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:02 volumio volumio[841]: info: Sep 14 16:05:02 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:02 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:02 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:02 volumio volumio[841]: info: sendMpdCommand status took 7 milliseconds Sep 14 16:05:02 volumio volumio[841]: info: sendMpdCommand status took 5 milliseconds Sep 14 16:05:02 volumio volumio[841]: info: sendMpdCommand status took 3 milliseconds Sep 14 16:05:02 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:02 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:02 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:02 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:02 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:02 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:05:02 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:02 volumio volumio[841]: info: CorePlayQueue::getTrack 2 Sep 14 16:05:02 volumio volumio[841]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Sep 14 16:05:02 volumio volumio[841]: verbose: CURRENT POSITION 2 Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::syncState stateService stop Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::play index undefined Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:02 volumio volumio[841]: info: CorePlayQueue::getTrack 3 Sep 14 16:05:02 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:05:02 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:02 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:02 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:02 volumio volumio[841]: info: CorePlayQueue::getTrack 3 Sep 14 16:05:02 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:02 volumio volumio[841]: info: CorePlayQueue::getTrack 3 Sep 14 16:05:02 volumio volumio[841]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Sep 14 16:05:02 volumio volumio[841]: verbose: CURRENT POSITION 3 Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::syncState stateService stop Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus stop Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:02 volumio volumio[841]: info: CorePlayQueue::getTrack 3 Sep 14 16:05:02 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:02 volumio volumio[841]: info: No code Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:02 volumio volumio[841]: info: CorePlayQueue::getTrack 3 Sep 14 16:05:02 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:02 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:02 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:02 volumio volumio[841]: info: CorePlayQueue::getTrack 3 Sep 14 16:05:02 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:02 volumio volumio[841]: info: CorePlayQueue::getTrack 3 Sep 14 16:05:02 volumio volumio[841]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Sep 14 16:05:02 volumio volumio[841]: verbose: CURRENT POSITION 3 Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::syncState stateService stop Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus stop Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:02 volumio volumio[841]: info: CorePlayQueue::getTrack 3 Sep 14 16:05:02 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:02 volumio volumio[841]: info: No code Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:02 volumio volumio[841]: info: CorePlayQueue::getTrack 3 Sep 14 16:05:02 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:02 volumio volumio[841]: info: CorePlayQueue::getTrack 3 Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::startPlaybackTimer Sep 14 16:05:02 volumio volumio[841]: info: CorePlayQueue::getTrack 3 Sep 14 16:05:02 volumio volumio[841]: info: [1757858702367] ControllerUPNPBrowser::clearAddPlayTrack Sep 14 16:05:02 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand stop Sep 14 16:05:02 volumio volumio[841]: info: ------------------------------ 130ms Sep 14 16:05:02 volumio volumio[841]: info: ------------------------------ 130ms Sep 14 16:05:02 volumio volumio[841]: info: ------------------------------ 128ms Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:02 volumio volumio[841]: info: CorePlayQueue::getTrack 3 Sep 14 16:05:02 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:05:02 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:02 volumio volumio[841]: info: sendMpdCommand stop took 25 milliseconds Sep 14 16:05:02 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand clear Sep 14 16:05:02 volumio volumio[841]: info: Sep 14 16:05:02 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:05:02 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:05:02 volumio volumio[841]: info: sendMpdCommand clear took 19 milliseconds Sep 14 16:05:02 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.10:50002/m/NDLNA/227946.m4a" Sep 14 16:05:02 volumio volumio[841]: info: Sep 14 16:05:02 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:05:02 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:05:02 volumio volumio[841]: info: Sep 14 16:05:02 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:05:02 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:05:02 volumio volumio[841]: error: updateQueue error: null Sep 14 16:05:02 volumio volumio[841]: info: ------------------------------ 10ms Sep 14 16:05:02 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.10:50002/m/NDLNA/227946.m4a" Sep 14 16:05:02 volumio volumio[841]: error: updateQueue error: null Sep 14 16:05:02 volumio volumio[841]: info: Sep 14 16:05:02 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:05:02 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:05:02 volumio volumio[841]: info: ------------------------------ 19ms Sep 14 16:05:02 volumio volumio[841]: info: ------------------------------ 17ms Sep 14 16:05:02 volumio volumio[841]: info: sendMpdCommand add "http://192.168.1.10:50002/m/NDLNA/227946.m4a" took 5 milliseconds Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::setConsumeUpdateService mpd Sep 14 16:05:02 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand play Sep 14 16:05:02 volumio volumio[841]: info: Sep 14 16:05:02 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:05:02 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:05:02 volumio volumio[841]: info: Sep 14 16:05:02 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:05:02 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:05:02 volumio volumio[841]: info: ------------------------------ 10ms Sep 14 16:05:02 volumio volumio[841]: info: sendMpdCommand play took 7 milliseconds Sep 14 16:05:02 volumio volumio[841]: info: ------------------------------ 7ms Sep 14 16:05:02 volumio volumio[841]: info: ------------------------------ 4ms Sep 14 16:05:02 volumio volumio[841]: info: Sep 14 16:05:02 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:02 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:02 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:02 volumio volumio[841]: info: Sep 14 16:05:02 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:02 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:02 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:02 volumio volumio[841]: info: Sep 14 16:05:02 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:02 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:02 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:02 volumio volumio[841]: info: Sep 14 16:05:02 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:02 volumio volumio[841]: info: sendMpdCommand status took 11 milliseconds Sep 14 16:05:02 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:02 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:02 volumio volumio[841]: info: sendMpdCommand status took 10 milliseconds Sep 14 16:05:02 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:02 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:02 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:02 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:02 volumio volumio[841]: info: Sep 14 16:05:02 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:02 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:02 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:02 volumio volumio[841]: info: Sep 14 16:05:02 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:02 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:02 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:02 volumio volumio[841]: info: sendMpdCommand status took 22 milliseconds Sep 14 16:05:02 volumio volumio[841]: info: sendMpdCommand status took 19 milliseconds Sep 14 16:05:02 volumio volumio[841]: info: sendMpdCommand playlistinfo took 17 milliseconds Sep 14 16:05:02 volumio volumio[841]: info: sendMpdCommand playlistinfo took 16 milliseconds Sep 14 16:05:02 volumio volumio[841]: info: sendMpdCommand status took 12 milliseconds Sep 14 16:05:02 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:02 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:02 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:02 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:02 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:05:02 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:02 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:02 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:02 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:02 volumio volumio[841]: info: CorePlayQueue::getTrack 3 Sep 14 16:05:02 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":222,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"227946.m4a","artist":null,"album":null,"uri":"http://192.168.1.10:50002/m/NDLNA/227946.m4a","trackType":"m4a"} Sep 14 16:05:02 volumio volumio[841]: verbose: CURRENT POSITION 3 Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus stop Sep 14 16:05:02 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:02 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:02 volumio volumio[841]: info: CorePlayQueue::getTrack 3 Sep 14 16:05:02 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":222,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"227946.m4a","artist":null,"album":null,"uri":"http://192.168.1.10:50002/m/NDLNA/227946.m4a","trackType":"m4a"} Sep 14 16:05:02 volumio volumio[841]: verbose: CURRENT POSITION 3 Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:05:02 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:02 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:05:02 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:02 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:02 volumio volumio[841]: info: ------------------------------ 93ms Sep 14 16:05:02 volumio volumio[841]: info: ------------------------------ 122ms Sep 14 16:05:02 volumio volumio[841]: info: sendMpdCommand status took 114 milliseconds Sep 14 16:05:02 volumio volumio[841]: info: sendMpdCommand playlistinfo took 105 milliseconds Sep 14 16:05:02 volumio volumio[841]: info: sendMpdCommand playlistinfo took 104 milliseconds Sep 14 16:05:02 volumio volumio[841]: info: sendMpdCommand playlistinfo took 102 milliseconds Sep 14 16:05:02 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:02 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:02 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:05:02 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:05:02 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:05:02 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:02 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:02 volumio volumio[841]: info: CorePlayQueue::getTrack 3 Sep 14 16:05:02 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":222,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"227946.m4a","artist":null,"album":null,"uri":"http://192.168.1.10:50002/m/NDLNA/227946.m4a","trackType":"m4a"} Sep 14 16:05:02 volumio volumio[841]: verbose: CURRENT POSITION 3 Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:05:02 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:02 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:05:02 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:02 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:02 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:02 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:02 volumio volumio[841]: info: CorePlayQueue::getTrack 3 Sep 14 16:05:02 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":222,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"227946.m4a","artist":null,"album":null,"uri":"http://192.168.1.10:50002/m/NDLNA/227946.m4a","trackType":"m4a"} Sep 14 16:05:02 volumio volumio[841]: verbose: CURRENT POSITION 3 Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:05:02 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:02 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:02 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:02 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:02 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:02 volumio volumio[841]: info: CorePlayQueue::getTrack 3 Sep 14 16:05:02 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":222,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"227946.m4a","artist":null,"album":null,"uri":"http://192.168.1.10:50002/m/NDLNA/227946.m4a","trackType":"m4a"} Sep 14 16:05:02 volumio volumio[841]: verbose: CURRENT POSITION 3 Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:05:02 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:02 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:02 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:02 volumio volumio[841]: info: ------------------------------ 251ms Sep 14 16:05:02 volumio volumio[841]: info: ------------------------------ 247ms Sep 14 16:05:02 volumio volumio[841]: info: ------------------------------ 237ms Sep 14 16:05:02 volumio volumio[841]: info: sendMpdCommand playlistinfo took 129 milliseconds Sep 14 16:05:02 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:05:02 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:02 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:02 volumio volumio[841]: info: CorePlayQueue::getTrack 3 Sep 14 16:05:02 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":222,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"227946.m4a","artist":null,"album":null,"uri":"http://192.168.1.10:50002/m/NDLNA/227946.m4a","trackType":"m4a"} Sep 14 16:05:02 volumio volumio[841]: verbose: CURRENT POSITION 3 Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:05:02 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:02 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:02 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:02 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:02 volumio volumio[841]: info: ------------------------------ 282ms Sep 14 16:05:04 volumio systemd[1]: Starting Cleanup of Temporary Directories... Sep 14 16:05:04 volumio systemd[1]: systemd-tmpfiles-clean.service: Succeeded. Sep 14 16:05:04 volumio systemd[1]: Started Cleanup of Temporary Directories. Sep 14 16:05:10 volumio volumio[841]: info: CoreCommandRouter::volumioNext Sep 14 16:05:10 volumio volumio[841]: info: CoreStateMachine::next Sep 14 16:05:10 volumio volumio[841]: info: ControllerMpd::next Sep 14 16:05:10 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand next Sep 14 16:05:10 volumio volumio[841]: info: Sep 14 16:05:10 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:10 volumio volumio[841]: info: sendMpdCommand next took 10 milliseconds Sep 14 16:05:10 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:10 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:10 volumio volumio[841]: info: Sep 14 16:05:10 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:10 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:10 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:10 volumio volumio[841]: info: Sep 14 16:05:10 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:10 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:10 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:10 volumio volumio[841]: info: sendMpdCommand status took 7 milliseconds Sep 14 16:05:10 volumio volumio[841]: info: sendMpdCommand status took 5 milliseconds Sep 14 16:05:10 volumio volumio[841]: info: sendMpdCommand status took 3 milliseconds Sep 14 16:05:10 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:10 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:10 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:10 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:10 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:10 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:10 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:05:10 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:10 volumio volumio[841]: info: CorePlayQueue::getTrack 3 Sep 14 16:05:10 volumio volumio[841]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Sep 14 16:05:10 volumio volumio[841]: verbose: CURRENT POSITION 3 Sep 14 16:05:10 volumio volumio[841]: info: CoreStateMachine::syncState stateService stop Sep 14 16:05:10 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:05:10 volumio volumio[841]: info: CoreStateMachine::play index undefined Sep 14 16:05:10 volumio volumio[841]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 14 16:05:10 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:10 volumio volumio[841]: info: CorePlayQueue::getTrack 4 Sep 14 16:05:10 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:05:10 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:10 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:10 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:10 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:10 volumio volumio[841]: info: CorePlayQueue::getTrack 4 Sep 14 16:05:10 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:11 volumio volumio[841]: info: CorePlayQueue::getTrack 4 Sep 14 16:05:11 volumio volumio[841]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Sep 14 16:05:11 volumio volumio[841]: verbose: CURRENT POSITION 4 Sep 14 16:05:11 volumio volumio[841]: info: CoreStateMachine::syncState stateService stop Sep 14 16:05:11 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus stop Sep 14 16:05:11 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:11 volumio volumio[841]: info: CorePlayQueue::getTrack 4 Sep 14 16:05:11 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:11 volumio volumio[841]: info: No code Sep 14 16:05:11 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:11 volumio volumio[841]: info: CorePlayQueue::getTrack 4 Sep 14 16:05:11 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:11 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:11 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:11 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:11 volumio volumio[841]: info: CorePlayQueue::getTrack 4 Sep 14 16:05:11 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:11 volumio volumio[841]: info: CorePlayQueue::getTrack 4 Sep 14 16:05:11 volumio volumio[841]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Sep 14 16:05:11 volumio volumio[841]: verbose: CURRENT POSITION 4 Sep 14 16:05:11 volumio volumio[841]: info: CoreStateMachine::syncState stateService stop Sep 14 16:05:11 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus stop Sep 14 16:05:11 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:11 volumio volumio[841]: info: CorePlayQueue::getTrack 4 Sep 14 16:05:11 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:11 volumio volumio[841]: info: No code Sep 14 16:05:11 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:11 volumio volumio[841]: info: CorePlayQueue::getTrack 4 Sep 14 16:05:11 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:11 volumio volumio[841]: info: CorePlayQueue::getTrack 4 Sep 14 16:05:11 volumio volumio[841]: info: CoreStateMachine::startPlaybackTimer Sep 14 16:05:11 volumio volumio[841]: info: CorePlayQueue::getTrack 4 Sep 14 16:05:11 volumio volumio[841]: info: [1757858711099] ControllerUPNPBrowser::clearAddPlayTrack Sep 14 16:05:11 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand stop Sep 14 16:05:11 volumio volumio[841]: info: ------------------------------ 131ms Sep 14 16:05:11 volumio volumio[841]: info: ------------------------------ 130ms Sep 14 16:05:11 volumio volumio[841]: info: ------------------------------ 129ms Sep 14 16:05:11 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:11 volumio volumio[841]: info: CorePlayQueue::getTrack 4 Sep 14 16:05:11 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:05:11 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:11 volumio volumio[841]: info: sendMpdCommand stop took 32 milliseconds Sep 14 16:05:11 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand clear Sep 14 16:05:11 volumio volumio[841]: info: Sep 14 16:05:11 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:05:11 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:05:11 volumio volumio[841]: info: sendMpdCommand clear took 25 milliseconds Sep 14 16:05:11 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.10:50002/m/NDLNA/227947.m4a" Sep 14 16:05:11 volumio volumio[841]: info: Sep 14 16:05:11 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:05:11 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:05:11 volumio volumio[841]: info: Sep 14 16:05:11 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:05:11 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:05:11 volumio volumio[841]: error: updateQueue error: null Sep 14 16:05:11 volumio volumio[841]: info: ------------------------------ 13ms Sep 14 16:05:11 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.10:50002/m/NDLNA/227947.m4a" Sep 14 16:05:11 volumio volumio[841]: error: updateQueue error: null Sep 14 16:05:11 volumio volumio[841]: error: updateQueue error: null Sep 14 16:05:11 volumio volumio[841]: info: Sep 14 16:05:11 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:05:11 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:05:11 volumio volumio[841]: info: ------------------------------ 19ms Sep 14 16:05:11 volumio volumio[841]: info: ------------------------------ 17ms Sep 14 16:05:11 volumio volumio[841]: info: sendMpdCommand add "http://192.168.1.10:50002/m/NDLNA/227947.m4a" took 5 milliseconds Sep 14 16:05:11 volumio volumio[841]: info: CoreStateMachine::setConsumeUpdateService mpd Sep 14 16:05:11 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand play Sep 14 16:05:11 volumio volumio[841]: info: Sep 14 16:05:11 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:05:11 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:05:11 volumio volumio[841]: info: Sep 14 16:05:11 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:05:11 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:05:11 volumio volumio[841]: info: ------------------------------ 10ms Sep 14 16:05:11 volumio volumio[841]: info: sendMpdCommand play took 8 milliseconds Sep 14 16:05:11 volumio volumio[841]: info: ------------------------------ 7ms Sep 14 16:05:11 volumio volumio[841]: info: ------------------------------ 4ms Sep 14 16:05:11 volumio volumio[841]: info: Sep 14 16:05:11 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:11 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:11 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:11 volumio volumio[841]: info: Sep 14 16:05:11 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:11 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:11 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:11 volumio volumio[841]: info: Sep 14 16:05:11 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:11 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:11 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:11 volumio volumio[841]: info: Sep 14 16:05:11 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:11 volumio volumio[841]: info: sendMpdCommand status took 11 milliseconds Sep 14 16:05:11 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:11 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:11 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:11 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:11 volumio volumio[841]: info: sendMpdCommand status took 12 milliseconds Sep 14 16:05:11 volumio volumio[841]: info: sendMpdCommand status took 11 milliseconds Sep 14 16:05:11 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:11 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:11 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:11 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:11 volumio volumio[841]: info: Sep 14 16:05:11 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:11 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:11 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:11 volumio volumio[841]: info: Sep 14 16:05:11 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:11 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:11 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:11 volumio volumio[841]: info: sendMpdCommand status took 21 milliseconds Sep 14 16:05:11 volumio volumio[841]: info: sendMpdCommand playlistinfo took 21 milliseconds Sep 14 16:05:11 volumio volumio[841]: info: sendMpdCommand playlistinfo took 15 milliseconds Sep 14 16:05:11 volumio volumio[841]: info: sendMpdCommand status took 11 milliseconds Sep 14 16:05:11 volumio volumio[841]: info: sendMpdCommand status took 8 milliseconds Sep 14 16:05:11 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:11 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:11 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:05:11 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:05:11 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:05:11 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:11 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:11 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:11 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:11 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:11 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:11 volumio volumio[841]: info: CorePlayQueue::getTrack 4 Sep 14 16:05:11 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":254,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"227947.m4a","artist":null,"album":null,"uri":"http://192.168.1.10:50002/m/NDLNA/227947.m4a","trackType":"m4a"} Sep 14 16:05:11 volumio volumio[841]: verbose: CURRENT POSITION 4 Sep 14 16:05:11 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:05:11 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus stop Sep 14 16:05:11 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:11 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:11 volumio volumio[841]: info: CorePlayQueue::getTrack 4 Sep 14 16:05:11 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":254,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"227947.m4a","artist":null,"album":null,"uri":"http://192.168.1.10:50002/m/NDLNA/227947.m4a","trackType":"m4a"} Sep 14 16:05:11 volumio volumio[841]: verbose: CURRENT POSITION 4 Sep 14 16:05:11 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:05:11 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:05:11 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:05:11 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:11 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:05:11 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:11 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:11 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:11 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:11 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:11 volumio volumio[841]: info: CorePlayQueue::getTrack 4 Sep 14 16:05:11 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":254,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"227947.m4a","artist":null,"album":null,"uri":"http://192.168.1.10:50002/m/NDLNA/227947.m4a","trackType":"m4a"} Sep 14 16:05:11 volumio volumio[841]: verbose: CURRENT POSITION 4 Sep 14 16:05:11 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:05:11 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:05:11 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:05:11 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:11 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:11 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:11 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:11 volumio volumio[841]: info: ------------------------------ 94ms Sep 14 16:05:11 volumio volumio[841]: info: ------------------------------ 153ms Sep 14 16:05:11 volumio volumio[841]: info: ------------------------------ 153ms Sep 14 16:05:11 volumio volumio[841]: info: sendMpdCommand playlistinfo took 129 milliseconds Sep 14 16:05:11 volumio volumio[841]: info: sendMpdCommand playlistinfo took 126 milliseconds Sep 14 16:05:11 volumio volumio[841]: info: sendMpdCommand playlistinfo took 125 milliseconds Sep 14 16:05:11 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:05:11 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:05:11 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:05:11 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:11 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:11 volumio volumio[841]: info: CorePlayQueue::getTrack 4 Sep 14 16:05:11 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":254,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"227947.m4a","artist":null,"album":null,"uri":"http://192.168.1.10:50002/m/NDLNA/227947.m4a","trackType":"m4a"} Sep 14 16:05:11 volumio volumio[841]: verbose: CURRENT POSITION 4 Sep 14 16:05:11 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:05:11 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:05:11 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:05:11 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:11 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:05:11 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:11 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:11 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:11 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:11 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:11 volumio volumio[841]: info: CorePlayQueue::getTrack 4 Sep 14 16:05:11 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":254,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"227947.m4a","artist":null,"album":null,"uri":"http://192.168.1.10:50002/m/NDLNA/227947.m4a","trackType":"m4a"} Sep 14 16:05:11 volumio volumio[841]: verbose: CURRENT POSITION 4 Sep 14 16:05:11 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:05:11 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:05:11 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:05:11 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:11 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:11 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:11 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:11 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:11 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:11 volumio volumio[841]: info: CorePlayQueue::getTrack 4 Sep 14 16:05:11 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":254,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"227947.m4a","artist":null,"album":null,"uri":"http://192.168.1.10:50002/m/NDLNA/227947.m4a","trackType":"m4a"} Sep 14 16:05:11 volumio volumio[841]: verbose: CURRENT POSITION 4 Sep 14 16:05:11 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:05:11 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:05:11 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:05:11 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:11 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:11 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:11 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:11 volumio volumio[841]: info: ------------------------------ 266ms Sep 14 16:05:11 volumio volumio[841]: info: ------------------------------ 254ms Sep 14 16:05:11 volumio volumio[841]: info: ------------------------------ 251ms Sep 14 16:05:27 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 14 16:05:28 volumio volumio[841]: info: Preload queue cleared Sep 14 16:05:28 volumio volumio[841]: info: Preloading song: upnp/http://192.168.1.10:50001/ContentDirectory/control@27$186705$@229277 Sep 14 16:05:28 volumio volumio[841]: info: Preloading song: upnp/http://192.168.1.10:50001/ContentDirectory/control@27$186705$@186788 Sep 14 16:05:28 volumio volumio[841]: info: Preloading song: upnp/http://192.168.1.10:50001/ContentDirectory/control@27$186705$@186854 Sep 14 16:05:28 volumio volumio[841]: info: Preloading song: upnp/http://192.168.1.10:50001/ContentDirectory/control@27$186705$@186705 Sep 14 16:05:28 volumio volumio[841]: info: Preloading song: upnp/http://192.168.1.10:50001/ContentDirectory/control@27$186705$@197870 Sep 14 16:05:28 volumio volumio[841]: info: Preloading song: upnp/http://192.168.1.10:50001/ContentDirectory/control@27$186705$@206043 Sep 14 16:05:28 volumio volumio[841]: info: Preloading song: upnp/http://192.168.1.10:50001/ContentDirectory/control@27$186705$@203734 Sep 14 16:05:28 volumio volumio[841]: info: Preloading song: upnp/http://192.168.1.10:50001/ContentDirectory/control@27$186705$@214469 Sep 14 16:05:28 volumio volumio[841]: info: Preloading song: upnp/http://192.168.1.10:50001/ContentDirectory/control@27$186705$@215718 Sep 14 16:05:28 volumio volumio[841]: info: Preloading song: upnp/http://192.168.1.10:50001/ContentDirectory/control@27$186705$@226080 Sep 14 16:05:28 volumio volumio[841]: info: Preloading song: upnp/http://192.168.1.10:50001/ContentDirectory/control@27$186705$@226081 Sep 14 16:05:28 volumio volumio[841]: info: Preloading song: upnp/http://192.168.1.10:50001/ContentDirectory/control@27$186705$@226082 Sep 14 16:05:28 volumio volumio[841]: info: Preloading song: upnp/http://192.168.1.10:50001/ContentDirectory/control@27$186705$@226083 Sep 14 16:05:28 volumio volumio[841]: info: Preloading song: upnp/http://192.168.1.10:50001/ContentDirectory/control@27$186705$@203847 Sep 14 16:05:28 volumio volumio[841]: info: Exploding uri upnp/http://192.168.1.10:50001/ContentDirectory/control@27$186705$@229277 in service upnp_browser Sep 14 16:05:28 volumio volumio[841]: info: Exploding uri upnp/http://192.168.1.10:50001/ContentDirectory/control@27$186705$@186788 in service upnp_browser Sep 14 16:05:28 volumio volumio[841]: info: Exploding uri upnp/http://192.168.1.10:50001/ContentDirectory/control@27$186705$@186854 in service upnp_browser Sep 14 16:05:28 volumio volumio[841]: info: Exploding uri upnp/http://192.168.1.10:50001/ContentDirectory/control@27$186705$@186705 in service upnp_browser Sep 14 16:05:28 volumio volumio[841]: info: Exploding uri upnp/http://192.168.1.10:50001/ContentDirectory/control@27$186705$@197870 in service upnp_browser Sep 14 16:05:28 volumio volumio[841]: info: Exploding uri upnp/http://192.168.1.10:50001/ContentDirectory/control@27$186705$@206043 in service upnp_browser Sep 14 16:05:28 volumio volumio[841]: info: Exploding uri upnp/http://192.168.1.10:50001/ContentDirectory/control@27$186705$@203734 in service upnp_browser Sep 14 16:05:28 volumio volumio[841]: info: Exploding uri upnp/http://192.168.1.10:50001/ContentDirectory/control@27$186705$@214469 in service upnp_browser Sep 14 16:05:28 volumio volumio[841]: info: Exploding uri upnp/http://192.168.1.10:50001/ContentDirectory/control@27$186705$@215718 in service upnp_browser Sep 14 16:05:28 volumio volumio[841]: info: Exploding uri upnp/http://192.168.1.10:50001/ContentDirectory/control@27$186705$@226080 in service upnp_browser Sep 14 16:05:28 volumio volumio[841]: info: Exploding uri upnp/http://192.168.1.10:50001/ContentDirectory/control@27$186705$@226081 in service upnp_browser Sep 14 16:05:28 volumio volumio[841]: info: Exploding uri upnp/http://192.168.1.10:50001/ContentDirectory/control@27$186705$@226082 in service upnp_browser Sep 14 16:05:28 volumio volumio[841]: info: Exploding uri upnp/http://192.168.1.10:50001/ContentDirectory/control@27$186705$@226083 in service upnp_browser Sep 14 16:05:28 volumio volumio[841]: info: Exploding uri upnp/http://192.168.1.10:50001/ContentDirectory/control@27$186705$@203847 in service upnp_browser Sep 14 16:05:29 volumio volumio[841]: info: Preload queue cleared Sep 14 16:05:29 volumio volumio[841]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 14 16:05:29 volumio volumio[841]: info: CoreStateMachine::ClearQueue Sep 14 16:05:29 volumio volumio[841]: info: CoreStateMachine::stop Sep 14 16:05:29 volumio volumio[841]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 14 16:05:29 volumio volumio[841]: info: CoreStateMachine::stPlaybackTimer Sep 14 16:05:29 volumio volumio[841]: info: CoreStateMachine::updateTrackBlock Sep 14 16:05:29 volumio volumio[841]: info: CorePlayQueue::getTrackBlock Sep 14 16:05:29 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:29 volumio volumio[841]: info: CorePlayQueue::getTrack 4 Sep 14 16:05:29 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:05:29 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:29 volumio volumio[841]: info: CoreStateMachine::serviceStop Sep 14 16:05:29 volumio volumio[841]: info: CorePlayQueue::getTrack 4 Sep 14 16:05:29 volumio volumio[841]: info: CoreCommandRouter::serviceStop Sep 14 16:05:29 volumio volumio[841]: info: [1757858729940] ControllerUPNPBrowser::stop Sep 14 16:05:29 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand stop Sep 14 16:05:29 volumio volumio[841]: info: CorePlayQueue::clearPlayQueue Sep 14 16:05:29 volumio volumio[841]: info: CorePlayQueue::saveQueue Sep 14 16:05:29 volumio volumio[841]: info: CoreCommandRouter::volumioPushQueue Sep 14 16:05:29 volumio volumio[841]: info: CoreStateMachine::addQueueItems Sep 14 16:05:29 volumio volumio[841]: info: CorePlayQueue::addQueueItems Sep 14 16:05:29 volumio volumio[841]: info: Preload queue cleared Sep 14 16:05:29 volumio volumio[841]: info: Adding Item to queue: upnp/folder/http://192.168.1.10:50001/ContentDirectory/control@27$186705 Sep 14 16:05:29 volumio volumio[841]: info: Exploding uri upnp/folder/http://192.168.1.10:50001/ContentDirectory/control@27$186705 in service upnp_browser Sep 14 16:05:29 volumio volumio[841]: info: sendMpdCommand stop took 45 milliseconds Sep 14 16:05:29 volumio volumio[841]: info: Sep 14 16:05:29 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:29 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:29 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:29 volumio volumio[841]: info: Sep 14 16:05:29 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:29 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:29 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:29 volumio volumio[841]: info: Sep 14 16:05:29 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:29 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:29 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:29 volumio volumio[841]: info: sendMpdCommand status took 9 milliseconds Sep 14 16:05:29 volumio volumio[841]: info: sendMpdCommand status took 7 milliseconds Sep 14 16:05:29 volumio volumio[841]: info: sendMpdCommand status took 4 milliseconds Sep 14 16:05:29 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:29 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:29 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:29 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushQueue Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::saveQueue Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::updateTrackBlock Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getTrackBlock Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioPlay Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::play index 0 Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::stop Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::play index undefined Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::startPlaybackTimer Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:05:30 volumio volumio[841]: info: [1757858730061] ControllerUPNPBrowser::clearAddPlayTrack Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand stop Sep 14 16:05:30 volumio volumio[841]: info: sendMpdCommand playlistinfo took 66 milliseconds Sep 14 16:05:30 volumio volumio[841]: info: sendMpdCommand playlistinfo took 66 milliseconds Sep 14 16:05:30 volumio volumio[841]: info: sendMpdCommand playlistinfo took 66 milliseconds Sep 14 16:05:30 volumio volumio[841]: info: sendMpdCommand stop took 5 milliseconds Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand clear Sep 14 16:05:30 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:05:30 volumio volumio[841]: 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":"227947.m4a","artist":null,"album":null,"uri":"http://192.168.1.10:50002/m/NDLNA/227947.m4a","trackType":"m4a"} Sep 14 16:05:30 volumio volumio[841]: verbose: CURRENT POSITION 0 Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::syncState stateService stop Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus stop Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:30 volumio volumio[841]: info: No code Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:30 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:05:30 volumio volumio[841]: 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":"227947.m4a","artist":null,"album":null,"uri":"http://192.168.1.10:50002/m/NDLNA/227947.m4a","trackType":"m4a"} Sep 14 16:05:30 volumio volumio[841]: verbose: CURRENT POSITION 0 Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::syncState stateService stop Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus stop Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:30 volumio volumio[841]: info: No code Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:30 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:05:30 volumio volumio[841]: 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":"227947.m4a","artist":null,"album":null,"uri":"http://192.168.1.10:50002/m/NDLNA/227947.m4a","trackType":"m4a"} Sep 14 16:05:30 volumio volumio[841]: verbose: CURRENT POSITION 0 Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::syncState stateService stop Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus stop Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:30 volumio volumio[841]: info: No code Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:30 volumio volumio[841]: info: ------------------------------ 204ms Sep 14 16:05:30 volumio volumio[841]: info: ------------------------------ 202ms Sep 14 16:05:30 volumio volumio[841]: info: ------------------------------ 201ms Sep 14 16:05:30 volumio volumio[841]: info: Sep 14 16:05:30 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:05:30 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:05:30 volumio volumio[841]: info: sendMpdCommand clear took 157 milliseconds Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.10:50002/m/NDLNA/229277.flac" Sep 14 16:05:30 volumio volumio[841]: info: Sep 14 16:05:30 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:05:30 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:05:30 volumio volumio[841]: info: Sep 14 16:05:30 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:05:30 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:05:30 volumio volumio[841]: error: updateQueue error: null Sep 14 16:05:30 volumio volumio[841]: info: ------------------------------ 13ms Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.10:50002/m/NDLNA/229277.flac" Sep 14 16:05:30 volumio volumio[841]: error: updateQueue error: null Sep 14 16:05:30 volumio volumio[841]: error: updateQueue error: null Sep 14 16:05:30 volumio volumio[841]: info: Sep 14 16:05:30 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:05:30 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:05:30 volumio volumio[841]: info: ------------------------------ 86ms Sep 14 16:05:30 volumio volumio[841]: info: ------------------------------ 84ms Sep 14 16:05:30 volumio volumio[841]: info: sendMpdCommand add "http://192.168.1.10:50002/m/NDLNA/229277.flac" took 4 milliseconds Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::setConsumeUpdateService mpd Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand play Sep 14 16:05:30 volumio volumio[841]: info: Sep 14 16:05:30 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:05:30 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:05:30 volumio volumio[841]: info: Sep 14 16:05:30 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:05:30 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:05:30 volumio volumio[841]: info: ------------------------------ 9ms Sep 14 16:05:30 volumio volumio[841]: info: sendMpdCommand play took 7 milliseconds Sep 14 16:05:30 volumio volumio[841]: info: ------------------------------ 6ms Sep 14 16:05:30 volumio volumio[841]: info: ------------------------------ 4ms Sep 14 16:05:30 volumio volumio[841]: info: Sep 14 16:05:30 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:30 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:30 volumio volumio[841]: info: Sep 14 16:05:30 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:30 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:30 volumio volumio[841]: info: Sep 14 16:05:30 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:30 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:30 volumio volumio[841]: info: Sep 14 16:05:30 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:30 volumio volumio[841]: info: sendMpdCommand status took 10 milliseconds Sep 14 16:05:30 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:30 volumio volumio[841]: info: Sep 14 16:05:30 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:30 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:30 volumio volumio[841]: info: sendMpdCommand status took 17 milliseconds Sep 14 16:05:30 volumio volumio[841]: info: sendMpdCommand status took 15 milliseconds Sep 14 16:05:30 volumio volumio[841]: info: sendMpdCommand status took 11 milliseconds Sep 14 16:05:30 volumio volumio[841]: info: sendMpdCommand playlistinfo took 10 milliseconds Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:05:30 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:05:30 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":210,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"229277.flac","artist":null,"album":null,"uri":"http://192.168.1.10:50002/m/NDLNA/229277.flac","trackType":"flac"} Sep 14 16:05:30 volumio volumio[841]: verbose: CURRENT POSITION 0 Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus stop Sep 14 16:05:30 volumio volumio[841]: info: ------------------------------ 36ms Sep 14 16:05:30 volumio volumio[841]: info: Sep 14 16:05:30 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:30 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:30 volumio volumio[841]: info: Sep 14 16:05:30 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:05:30 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:05:30 volumio volumio[841]: info: Sep 14 16:05:30 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:30 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:30 volumio volumio[841]: info: sendMpdCommand status took 25 milliseconds Sep 14 16:05:30 volumio volumio[841]: info: sendMpdCommand playlistinfo took 18 milliseconds Sep 14 16:05:30 volumio volumio[841]: info: sendMpdCommand playlistinfo took 18 milliseconds Sep 14 16:05:30 volumio volumio[841]: info: sendMpdCommand playlistinfo took 18 milliseconds Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:05:30 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:05:30 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":210,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Faded","artist":"Alan Walker","album":"Best Of 2016 Sommerhits","uri":"http://192.168.1.10:50002/m/NDLNA/229277.flac","trackType":"flac"} Sep 14 16:05:30 volumio volumio[841]: verbose: CURRENT POSITION 0 Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:05:30 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:30 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:05:30 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":210,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Faded","artist":"Alan Walker","album":"Best Of 2016 Sommerhits","uri":"http://192.168.1.10:50002/m/NDLNA/229277.flac","trackType":"flac"} Sep 14 16:05:30 volumio volumio[841]: verbose: CURRENT POSITION 0 Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:05:30 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:30 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:05:30 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":210,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Faded","artist":"Alan Walker","album":"Best Of 2016 Sommerhits","uri":"http://192.168.1.10:50002/m/NDLNA/229277.flac","trackType":"flac"} Sep 14 16:05:30 volumio volumio[841]: verbose: CURRENT POSITION 0 Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:05:30 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:30 volumio volumio[841]: info: ------------------------------ 210ms Sep 14 16:05:30 volumio volumio[841]: info: ------------------------------ 208ms Sep 14 16:05:30 volumio volumio[841]: info: ------------------------------ 206ms Sep 14 16:05:30 volumio volumio[841]: info: Sep 14 16:05:30 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:05:30 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:05:30 volumio volumio[841]: info: Sep 14 16:05:30 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:30 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:30 volumio volumio[841]: info: Sep 14 16:05:30 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:05:30 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:05:30 volumio volumio[841]: info: Sep 14 16:05:30 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:30 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:30 volumio volumio[841]: info: sendMpdCommand status took 190 milliseconds Sep 14 16:05:30 volumio volumio[841]: info: ------------------------------ 189ms Sep 14 16:05:30 volumio volumio[841]: info: sendMpdCommand status took 185 milliseconds Sep 14 16:05:30 volumio volumio[841]: info: sendMpdCommand playlistinfo took 180 milliseconds Sep 14 16:05:30 volumio volumio[841]: info: ------------------------------ 12ms Sep 14 16:05:30 volumio volumio[841]: info: sendMpdCommand status took 11 milliseconds Sep 14 16:05:30 volumio volumio[841]: info: ------------------------------ 10ms Sep 14 16:05:30 volumio volumio[841]: info: sendMpdCommand status took 9 milliseconds Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:30 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:05:30 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":846,"duration":210,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"625 Kbps","isStreaming":false,"title":"Faded","artist":"Alan Walker","album":"Best Of 2016 Sommerhits","uri":"http://192.168.1.10:50002/m/NDLNA/229277.flac","trackType":"flac"} Sep 14 16:05:30 volumio volumio[841]: verbose: CURRENT POSITION 0 Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:05:30 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:30 volumio volumio[841]: info: ------------------------------ 274ms Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:05:30 volumio volumio[841]: info: sendMpdCommand playlistinfo took 117 milliseconds Sep 14 16:05:30 volumio volumio[841]: info: sendMpdCommand playlistinfo took 117 milliseconds Sep 14 16:05:30 volumio volumio[841]: info: sendMpdCommand playlistinfo took 117 milliseconds Sep 14 16:05:30 volumio volumio[841]: info: sendMpdCommand playlistinfo took 117 milliseconds Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:05:30 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:05:30 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:05:30 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":960,"duration":210,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"631 Kbps","isStreaming":false,"title":"Faded","artist":"Alan Walker","album":"Best Of 2016 Sommerhits","uri":"http://192.168.1.10:50002/m/NDLNA/229277.flac","trackType":"flac"} Sep 14 16:05:30 volumio volumio[841]: verbose: CURRENT POSITION 0 Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:05:30 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:30 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:05:30 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":960,"duration":210,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"621 Kbps","isStreaming":false,"title":"Faded","artist":"Alan Walker","album":"Best Of 2016 Sommerhits","uri":"http://192.168.1.10:50002/m/NDLNA/229277.flac","trackType":"flac"} Sep 14 16:05:30 volumio volumio[841]: verbose: CURRENT POSITION 0 Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:05:30 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:30 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:05:30 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1098,"duration":210,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"627 Kbps","isStreaming":false,"title":"Faded","artist":"Alan Walker","album":"Best Of 2016 Sommerhits","uri":"http://192.168.1.10:50002/m/NDLNA/229277.flac","trackType":"flac"} Sep 14 16:05:30 volumio volumio[841]: verbose: CURRENT POSITION 0 Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:05:30 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:30 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:05:30 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1098,"duration":210,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"627 Kbps","isStreaming":false,"title":"Faded","artist":"Alan Walker","album":"Best Of 2016 Sommerhits","uri":"http://192.168.1.10:50002/m/NDLNA/229277.flac","trackType":"flac"} Sep 14 16:05:30 volumio volumio[841]: verbose: CURRENT POSITION 0 Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:05:30 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:30 volumio volumio[841]: info: ------------------------------ 540ms Sep 14 16:05:30 volumio volumio[841]: info: ------------------------------ 536ms Sep 14 16:05:30 volumio volumio[841]: info: ------------------------------ 361ms Sep 14 16:05:30 volumio volumio[841]: info: ------------------------------ 360ms Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:05:30 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:05:30 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:05:30 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:05:35 volumio volumio[841]: info: CoreCommandRouter::volumioNext Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::next Sep 14 16:05:35 volumio volumio[841]: info: ControllerMpd::next Sep 14 16:05:35 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand next Sep 14 16:05:35 volumio volumio[841]: info: Sep 14 16:05:35 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:35 volumio volumio[841]: info: sendMpdCommand next took 17 milliseconds Sep 14 16:05:35 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:35 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:35 volumio volumio[841]: info: Sep 14 16:05:35 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:35 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:35 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:35 volumio volumio[841]: info: Sep 14 16:05:35 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:35 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:35 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:35 volumio volumio[841]: info: sendMpdCommand status took 6 milliseconds Sep 14 16:05:35 volumio volumio[841]: info: sendMpdCommand status took 5 milliseconds Sep 14 16:05:35 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:35 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:35 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:35 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:35 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:05:35 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:35 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:05:35 volumio volumio[841]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Sep 14 16:05:35 volumio volumio[841]: verbose: CURRENT POSITION 0 Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::syncState stateService stop Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::play index undefined Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:35 volumio volumio[841]: info: CorePlayQueue::getTrack 1 Sep 14 16:05:35 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:05:35 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:35 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:35 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:35 volumio volumio[841]: info: CorePlayQueue::getTrack 1 Sep 14 16:05:35 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:35 volumio volumio[841]: info: CorePlayQueue::getTrack 1 Sep 14 16:05:35 volumio volumio[841]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Sep 14 16:05:35 volumio volumio[841]: verbose: CURRENT POSITION 1 Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::syncState stateService stop Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus stop Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:35 volumio volumio[841]: info: CorePlayQueue::getTrack 1 Sep 14 16:05:35 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:35 volumio volumio[841]: info: No code Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:35 volumio volumio[841]: info: CorePlayQueue::getTrack 1 Sep 14 16:05:35 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:35 volumio volumio[841]: info: CorePlayQueue::getTrack 1 Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::startPlaybackTimer Sep 14 16:05:35 volumio volumio[841]: info: CorePlayQueue::getTrack 1 Sep 14 16:05:35 volumio volumio[841]: info: [1757858735521] ControllerUPNPBrowser::clearAddPlayTrack Sep 14 16:05:35 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand stop Sep 14 16:05:35 volumio volumio[841]: info: ------------------------------ 93ms Sep 14 16:05:35 volumio volumio[841]: info: ------------------------------ 106ms Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:35 volumio volumio[841]: info: CorePlayQueue::getTrack 1 Sep 14 16:05:35 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:05:35 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:35 volumio volumio[841]: info: sendMpdCommand status took 125 milliseconds Sep 14 16:05:35 volumio volumio[841]: info: sendMpdCommand stop took 39 milliseconds Sep 14 16:05:35 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:35 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand clear Sep 14 16:05:35 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:35 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:35 volumio volumio[841]: info: CorePlayQueue::getTrack 1 Sep 14 16:05:35 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:05:35 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:35 volumio volumio[841]: info: CorePlayQueue::getTrack 1 Sep 14 16:05:35 volumio volumio[841]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Sep 14 16:05:35 volumio volumio[841]: verbose: CURRENT POSITION 1 Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::syncState stateService stop Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus stop Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:35 volumio volumio[841]: info: CorePlayQueue::getTrack 1 Sep 14 16:05:35 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:35 volumio volumio[841]: info: No code Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:35 volumio volumio[841]: info: CorePlayQueue::getTrack 1 Sep 14 16:05:35 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:35 volumio volumio[841]: info: ------------------------------ 176ms Sep 14 16:05:35 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:05:35 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:05:35 volumio volumio[841]: info: Sep 14 16:05:35 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:05:35 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:05:35 volumio volumio[841]: info: sendMpdCommand clear took 86 milliseconds Sep 14 16:05:35 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.10:50002/m/MP3/186788.mp3" Sep 14 16:05:35 volumio volumio[841]: info: Sep 14 16:05:35 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:05:35 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:05:35 volumio volumio[841]: info: Sep 14 16:05:35 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:05:35 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:05:35 volumio volumio[841]: error: updateQueue error: null Sep 14 16:05:35 volumio volumio[841]: info: ------------------------------ 96ms Sep 14 16:05:35 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.10:50002/m/MP3/186788.mp3" Sep 14 16:05:35 volumio volumio[841]: error: updateQueue error: null Sep 14 16:05:35 volumio volumio[841]: error: updateQueue error: null Sep 14 16:05:35 volumio volumio[841]: info: ------------------------------ 94ms Sep 14 16:05:35 volumio volumio[841]: info: ------------------------------ 93ms Sep 14 16:05:35 volumio volumio[841]: info: sendMpdCommand add "http://192.168.1.10:50002/m/MP3/186788.mp3" took 3 milliseconds Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::setConsumeUpdateService mpd Sep 14 16:05:35 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand play Sep 14 16:05:35 volumio volumio[841]: info: Sep 14 16:05:35 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:05:35 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:05:35 volumio volumio[841]: info: sendMpdCommand play took 3 milliseconds Sep 14 16:05:35 volumio volumio[841]: info: Sep 14 16:05:35 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:05:35 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:05:35 volumio volumio[841]: info: Sep 14 16:05:35 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:05:35 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:05:35 volumio volumio[841]: info: ------------------------------ 9ms Sep 14 16:05:35 volumio volumio[841]: info: ------------------------------ 6ms Sep 14 16:05:35 volumio volumio[841]: info: ------------------------------ 4ms Sep 14 16:05:35 volumio volumio[841]: info: Sep 14 16:05:35 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:35 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:35 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:35 volumio volumio[841]: info: Sep 14 16:05:35 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:35 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:35 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:35 volumio volumio[841]: info: Sep 14 16:05:35 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:35 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:35 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:35 volumio volumio[841]: info: Sep 14 16:05:35 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:35 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:35 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:35 volumio volumio[841]: info: Sep 14 16:05:35 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:35 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:35 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:35 volumio volumio[841]: info: Sep 14 16:05:35 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:35 volumio volumio[841]: info: sendMpdCommand status took 27 milliseconds Sep 14 16:05:35 volumio volumio[841]: info: sendMpdCommand status took 25 milliseconds Sep 14 16:05:35 volumio volumio[841]: info: sendMpdCommand status took 23 milliseconds Sep 14 16:05:35 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:35 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:35 volumio volumio[841]: info: sendMpdCommand status took 11 milliseconds Sep 14 16:05:35 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:35 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:35 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:35 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:35 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:35 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:35 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:35 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:35 volumio volumio[841]: info: sendMpdCommand status took 18 milliseconds Sep 14 16:05:35 volumio volumio[841]: info: sendMpdCommand status took 12 milliseconds Sep 14 16:05:35 volumio volumio[841]: info: sendMpdCommand playlistinfo took 9 milliseconds Sep 14 16:05:35 volumio volumio[841]: info: sendMpdCommand playlistinfo took 9 milliseconds Sep 14 16:05:35 volumio volumio[841]: info: sendMpdCommand playlistinfo took 9 milliseconds Sep 14 16:05:35 volumio volumio[841]: info: sendMpdCommand playlistinfo took 8 milliseconds Sep 14 16:05:35 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:35 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:35 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:35 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:35 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:05:35 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:05:35 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:05:35 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:05:35 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:35 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:35 volumio volumio[841]: info: CorePlayQueue::getTrack 1 Sep 14 16:05:35 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":189,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"186788.mp3","artist":null,"album":null,"uri":"http://192.168.1.10:50002/m/MP3/186788.mp3","trackType":"mp3"} Sep 14 16:05:35 volumio volumio[841]: verbose: CURRENT POSITION 1 Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus stop Sep 14 16:05:35 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:35 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:35 volumio volumio[841]: info: CorePlayQueue::getTrack 1 Sep 14 16:05:35 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":189,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"186788.mp3","artist":null,"album":null,"uri":"http://192.168.1.10:50002/m/MP3/186788.mp3","trackType":"mp3"} Sep 14 16:05:35 volumio volumio[841]: verbose: CURRENT POSITION 1 Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:05:35 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:35 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:05:35 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:35 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:35 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:35 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:35 volumio volumio[841]: info: CorePlayQueue::getTrack 1 Sep 14 16:05:35 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":189,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"186788.mp3","artist":null,"album":null,"uri":"http://192.168.1.10:50002/m/MP3/186788.mp3","trackType":"mp3"} Sep 14 16:05:35 volumio volumio[841]: verbose: CURRENT POSITION 1 Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:05:35 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:35 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:35 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:35 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:35 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:35 volumio volumio[841]: info: CorePlayQueue::getTrack 1 Sep 14 16:05:35 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":189,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"186788.mp3","artist":null,"album":null,"uri":"http://192.168.1.10:50002/m/MP3/186788.mp3","trackType":"mp3"} Sep 14 16:05:35 volumio volumio[841]: verbose: CURRENT POSITION 1 Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:05:35 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:35 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:35 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:35 volumio volumio[841]: info: ------------------------------ 96ms Sep 14 16:05:35 volumio volumio[841]: info: ------------------------------ 190ms Sep 14 16:05:35 volumio volumio[841]: info: ------------------------------ 189ms Sep 14 16:05:35 volumio volumio[841]: info: ------------------------------ 177ms Sep 14 16:05:35 volumio volumio[841]: info: Sep 14 16:05:35 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:05:35 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:05:35 volumio volumio[841]: info: Sep 14 16:05:35 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:35 volumio volumio[841]: info: sendMpdCommand playlistinfo took 155 milliseconds Sep 14 16:05:35 volumio volumio[841]: info: sendMpdCommand playlistinfo took 153 milliseconds Sep 14 16:05:35 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:35 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:35 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:05:35 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:05:35 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:35 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:35 volumio volumio[841]: info: CorePlayQueue::getTrack 1 Sep 14 16:05:35 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":189,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"186788.mp3","artist":null,"album":null,"uri":"http://192.168.1.10:50002/m/MP3/186788.mp3","trackType":"mp3"} Sep 14 16:05:35 volumio volumio[841]: verbose: CURRENT POSITION 1 Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:05:35 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:35 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:05:35 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:35 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:35 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:35 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:35 volumio volumio[841]: info: CorePlayQueue::getTrack 1 Sep 14 16:05:35 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":189,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"186788.mp3","artist":null,"album":null,"uri":"http://192.168.1.10:50002/m/MP3/186788.mp3","trackType":"mp3"} Sep 14 16:05:35 volumio volumio[841]: verbose: CURRENT POSITION 1 Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:05:35 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:05:36 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:05:36 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:36 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:36 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:36 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:36 volumio volumio[841]: info: ------------------------------ 270ms Sep 14 16:05:36 volumio volumio[841]: info: ------------------------------ 266ms Sep 14 16:05:36 volumio volumio[841]: info: Sep 14 16:05:36 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:05:36 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:05:36 volumio volumio[841]: info: Sep 14 16:05:36 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:36 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:36 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:36 volumio volumio[841]: info: Sep 14 16:05:36 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:05:36 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:05:36 volumio volumio[841]: info: Sep 14 16:05:36 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:05:36 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:05:36 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:05:36 volumio volumio[841]: info: ------------------------------ 127ms Sep 14 16:05:36 volumio volumio[841]: info: sendMpdCommand status took 124 milliseconds Sep 14 16:05:36 volumio volumio[841]: info: ------------------------------ 11ms Sep 14 16:05:36 volumio volumio[841]: info: sendMpdCommand status took 10 milliseconds Sep 14 16:05:36 volumio volumio[841]: info: ------------------------------ 9ms Sep 14 16:05:36 volumio volumio[841]: info: sendMpdCommand status took 7 milliseconds Sep 14 16:05:36 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:36 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:36 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:36 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:36 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:05:36 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:05:36 volumio volumio[841]: info: sendMpdCommand playlistinfo took 4 milliseconds Sep 14 16:05:36 volumio volumio[841]: info: sendMpdCommand playlistinfo took 4 milliseconds Sep 14 16:05:36 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:05:36 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:36 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:36 volumio volumio[841]: info: CorePlayQueue::getTrack 1 Sep 14 16:05:36 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":982,"duration":189,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Sing Me To Sleep","artist":"Alan Walker","album":"Bravo Hits Vol. 94","uri":"http://192.168.1.10:50002/m/MP3/186788.mp3","trackType":"mp3"} Sep 14 16:05:36 volumio volumio[841]: verbose: CURRENT POSITION 1 Sep 14 16:05:36 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:05:36 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:05:36 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:05:36 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:36 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:05:36 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:36 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:36 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:36 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:36 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:36 volumio volumio[841]: info: CorePlayQueue::getTrack 1 Sep 14 16:05:36 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1108,"duration":189,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Sing Me To Sleep","artist":"Alan Walker","album":"Bravo Hits Vol. 94","uri":"http://192.168.1.10:50002/m/MP3/186788.mp3","trackType":"mp3"} Sep 14 16:05:36 volumio volumio[841]: verbose: CURRENT POSITION 1 Sep 14 16:05:36 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:05:36 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:05:36 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:05:36 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:36 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:36 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:36 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:36 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:05:36 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:05:36 volumio volumio[841]: info: CorePlayQueue::getTrack 1 Sep 14 16:05:36 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1108,"duration":189,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Sing Me To Sleep","artist":"Alan Walker","album":"Bravo Hits Vol. 94","uri":"http://192.168.1.10:50002/m/MP3/186788.mp3","trackType":"mp3"} Sep 14 16:05:36 volumio volumio[841]: verbose: CURRENT POSITION 1 Sep 14 16:05:36 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:05:36 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:05:36 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:05:36 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:36 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:36 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:05:36 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:05:36 volumio volumio[841]: info: ------------------------------ 248ms Sep 14 16:05:36 volumio volumio[841]: info: ------------------------------ 132ms Sep 14 16:05:36 volumio volumio[841]: info: ------------------------------ 131ms Sep 14 16:05:36 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:05:36 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:05:36 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:05:36 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:05:36 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:05:36 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:05:36 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:05:36 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:05:36 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:05:36 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:05:36 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:05:36 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:05:36 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:05:36 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:05:36 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:05:36 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:05:36 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:05:36 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:06:01 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 14 16:06:01 volumio volumio[841]: info: Preload queue cleared Sep 14 16:06:01 volumio volumio[841]: info: Preloading song: upnp/http://192.168.1.10:50001/ContentDirectory/control@27$187594$@187594 Sep 14 16:06:01 volumio volumio[841]: info: Preloading song: upnp/http://192.168.1.10:50001/ContentDirectory/control@27$187594$@188172 Sep 14 16:06:01 volumio volumio[841]: info: Preloading song: upnp/http://192.168.1.10:50001/ContentDirectory/control@27$187594$@192299 Sep 14 16:06:01 volumio volumio[841]: info: Preloading song: upnp/http://192.168.1.10:50001/ContentDirectory/control@27$187594$@193813 Sep 14 16:06:01 volumio volumio[841]: info: Exploding uri upnp/http://192.168.1.10:50001/ContentDirectory/control@27$187594$@187594 in service upnp_browser Sep 14 16:06:01 volumio volumio[841]: info: Exploding uri upnp/http://192.168.1.10:50001/ContentDirectory/control@27$187594$@188172 in service upnp_browser Sep 14 16:06:01 volumio volumio[841]: info: Exploding uri upnp/http://192.168.1.10:50001/ContentDirectory/control@27$187594$@192299 in service upnp_browser Sep 14 16:06:01 volumio volumio[841]: info: Exploding uri upnp/http://192.168.1.10:50001/ContentDirectory/control@27$187594$@193813 in service upnp_browser Sep 14 16:06:02 volumio volumio[841]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Aerosmith/The%20Best%20Of/3f138342-5044-49ac-9d58-86eef5b2e5c6.png' Sep 14 16:06:08 volumio volumio[841]: info: Preload queue cleared Sep 14 16:06:08 volumio volumio[841]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 14 16:06:08 volumio volumio[841]: info: CoreStateMachine::ClearQueue Sep 14 16:06:08 volumio volumio[841]: info: CoreStateMachine::stop Sep 14 16:06:08 volumio volumio[841]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 14 16:06:08 volumio volumio[841]: info: CoreStateMachine::stPlaybackTimer Sep 14 16:06:08 volumio volumio[841]: info: CoreStateMachine::updateTrackBlock Sep 14 16:06:08 volumio volumio[841]: info: CorePlayQueue::getTrackBlock Sep 14 16:06:08 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:08 volumio volumio[841]: info: CorePlayQueue::getTrack 1 Sep 14 16:06:08 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:06:08 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:08 volumio volumio[841]: info: CoreStateMachine::serviceStop Sep 14 16:06:08 volumio volumio[841]: info: CorePlayQueue::getTrack 1 Sep 14 16:06:08 volumio volumio[841]: info: CoreCommandRouter::serviceStop Sep 14 16:06:08 volumio volumio[841]: info: [1757858768861] ControllerUPNPBrowser::stop Sep 14 16:06:08 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand stop Sep 14 16:06:08 volumio volumio[841]: info: CorePlayQueue::clearPlayQueue Sep 14 16:06:08 volumio volumio[841]: info: CorePlayQueue::saveQueue Sep 14 16:06:08 volumio volumio[841]: info: CoreCommandRouter::volumioPushQueue Sep 14 16:06:08 volumio volumio[841]: info: CoreStateMachine::addQueueItems Sep 14 16:06:08 volumio volumio[841]: info: CorePlayQueue::addQueueItems Sep 14 16:06:08 volumio volumio[841]: info: Preload queue cleared Sep 14 16:06:08 volumio volumio[841]: info: Adding Item to queue: upnp/folder/http://192.168.1.10:50001/ContentDirectory/control@27$187594 Sep 14 16:06:08 volumio volumio[841]: info: Exploding uri upnp/folder/http://192.168.1.10:50001/ContentDirectory/control@27$187594 in service upnp_browser Sep 14 16:06:08 volumio volumio[841]: info: CoreCommandRouter::volumioPushQueue Sep 14 16:06:08 volumio volumio[841]: info: CorePlayQueue::saveQueue Sep 14 16:06:08 volumio volumio[841]: info: CoreStateMachine::updateTrackBlock Sep 14 16:06:08 volumio volumio[841]: info: CorePlayQueue::getTrackBlock Sep 14 16:06:08 volumio volumio[841]: info: CoreCommandRouter::volumioPlay Sep 14 16:06:08 volumio volumio[841]: info: CoreStateMachine::play index 0 Sep 14 16:06:08 volumio volumio[841]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 14 16:06:08 volumio volumio[841]: info: CoreStateMachine::stop Sep 14 16:06:08 volumio volumio[841]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 14 16:06:08 volumio volumio[841]: info: CoreStateMachine::play index undefined Sep 14 16:06:08 volumio volumio[841]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 14 16:06:08 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:08 volumio volumio[841]: info: CoreStateMachine::startPlaybackTimer Sep 14 16:06:08 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:08 volumio volumio[841]: info: [1757858768919] ControllerUPNPBrowser::clearAddPlayTrack Sep 14 16:06:08 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand stop Sep 14 16:06:08 volumio volumio[841]: info: Sep 14 16:06:08 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:06:08 volumio volumio[841]: info: sendMpdCommand stop took 62 milliseconds Sep 14 16:06:08 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:06:08 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:06:08 volumio volumio[841]: info: sendMpdCommand stop took 5 milliseconds Sep 14 16:06:08 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand clear Sep 14 16:06:08 volumio volumio[841]: info: Sep 14 16:06:08 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:06:08 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:06:08 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:06:08 volumio volumio[841]: info: Sep 14 16:06:08 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:06:08 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:06:08 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:06:08 volumio volumio[841]: info: Sep 14 16:06:08 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:06:08 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:06:08 volumio volumio[841]: info: sendMpdCommand status took 15 milliseconds Sep 14 16:06:08 volumio volumio[841]: info: sendMpdCommand clear took 15 milliseconds Sep 14 16:06:08 volumio volumio[841]: info: sendMpdCommand status took 13 milliseconds Sep 14 16:06:08 volumio volumio[841]: info: sendMpdCommand status took 12 milliseconds Sep 14 16:06:08 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:06:08 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:06:08 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.10:50002/m/MP3/187594.mp3" Sep 14 16:06:08 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:06:08 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:06:08 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:06:08 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:06:08 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:08 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:08 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:06:08 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:08 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:08 volumio volumio[841]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Sep 14 16:06:08 volumio volumio[841]: verbose: CURRENT POSITION 0 Sep 14 16:06:08 volumio volumio[841]: info: CoreStateMachine::syncState stateService stop Sep 14 16:06:08 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus stop Sep 14 16:06:08 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:08 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:08 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:08 volumio volumio[841]: info: No code Sep 14 16:06:08 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:08 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:08 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:08 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:06:08 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:06:08 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:08 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:08 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:08 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:08 volumio volumio[841]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Sep 14 16:06:08 volumio volumio[841]: verbose: CURRENT POSITION 0 Sep 14 16:06:08 volumio volumio[841]: info: CoreStateMachine::syncState stateService stop Sep 14 16:06:08 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus stop Sep 14 16:06:08 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:08 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:08 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:08 volumio volumio[841]: info: No code Sep 14 16:06:08 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:08 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:08 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:09 volumio volumio[841]: info: ------------------------------ 109ms Sep 14 16:06:09 volumio volumio[841]: info: ------------------------------ 109ms Sep 14 16:06:09 volumio volumio[841]: info: Sep 14 16:06:09 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:06:09 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:06:09 volumio volumio[841]: info: Sep 14 16:06:09 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:06:09 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:06:09 volumio volumio[841]: error: updateQueue error: null Sep 14 16:06:09 volumio volumio[841]: error: updateQueue error: null Sep 14 16:06:09 volumio volumio[841]: error: updateQueue error: null Sep 14 16:06:09 volumio volumio[841]: info: ------------------------------ 107ms Sep 14 16:06:09 volumio volumio[841]: info: sendMpdCommand playlistinfo took 104 milliseconds Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.10:50002/m/MP3/187594.mp3" Sep 14 16:06:09 volumio volumio[841]: info: ------------------------------ 7ms Sep 14 16:06:09 volumio volumio[841]: info: ------------------------------ 6ms Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:06:09 volumio volumio[841]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Sep 14 16:06:09 volumio volumio[841]: info: ------------------------------ 127ms Sep 14 16:06:09 volumio volumio[841]: info: Sep 14 16:06:09 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:06:09 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:06:09 volumio volumio[841]: info: sendMpdCommand add "http://192.168.1.10:50002/m/MP3/187594.mp3" took 17 milliseconds Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::setConsumeUpdateService mpd Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand play Sep 14 16:06:09 volumio volumio[841]: info: Sep 14 16:06:09 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:06:09 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:06:09 volumio volumio[841]: info: Sep 14 16:06:09 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:06:09 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:06:09 volumio volumio[841]: info: ------------------------------ 10ms Sep 14 16:06:09 volumio volumio[841]: info: sendMpdCommand play took 9 milliseconds Sep 14 16:06:09 volumio volumio[841]: info: ------------------------------ 8ms Sep 14 16:06:09 volumio volumio[841]: info: ------------------------------ 7ms Sep 14 16:06:09 volumio volumio[841]: info: Sep 14 16:06:09 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:06:09 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:06:09 volumio volumio[841]: info: Sep 14 16:06:09 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:06:09 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:06:09 volumio volumio[841]: info: Sep 14 16:06:09 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:06:09 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:06:09 volumio volumio[841]: info: Sep 14 16:06:09 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:06:09 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:06:09 volumio volumio[841]: info: sendMpdCommand status took 11 milliseconds Sep 14 16:06:09 volumio volumio[841]: info: sendMpdCommand status took 9 milliseconds Sep 14 16:06:09 volumio volumio[841]: info: sendMpdCommand status took 6 milliseconds Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:06:09 volumio volumio[841]: info: Sep 14 16:06:09 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:06:09 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:06:09 volumio volumio[841]: info: Sep 14 16:06:09 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:06:09 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:06:09 volumio volumio[841]: info: sendMpdCommand status took 14 milliseconds Sep 14 16:06:09 volumio volumio[841]: info: sendMpdCommand playlistinfo took 11 milliseconds Sep 14 16:06:09 volumio volumio[841]: info: sendMpdCommand playlistinfo took 10 milliseconds Sep 14 16:06:09 volumio volumio[841]: info: sendMpdCommand status took 8 milliseconds Sep 14 16:06:09 volumio volumio[841]: info: sendMpdCommand status took 6 milliseconds Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:06:09 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:06:09 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:09 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":212,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"187594.mp3","artist":null,"album":null,"uri":"http://192.168.1.10:50002/m/MP3/187594.mp3","trackType":"mp3"} Sep 14 16:06:09 volumio volumio[841]: verbose: CURRENT POSITION 0 Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus stop Sep 14 16:06:09 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:06:09 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:09 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":212,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"187594.mp3","artist":null,"album":null,"uri":"http://192.168.1.10:50002/m/MP3/187594.mp3","trackType":"mp3"} Sep 14 16:06:09 volumio volumio[841]: verbose: CURRENT POSITION 0 Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:06:09 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:09 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:06:09 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:09 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":212,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"187594.mp3","artist":null,"album":null,"uri":"http://192.168.1.10:50002/m/MP3/187594.mp3","trackType":"mp3"} Sep 14 16:06:09 volumio volumio[841]: verbose: CURRENT POSITION 0 Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:06:09 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:09 volumio volumio[841]: info: ------------------------------ 66ms Sep 14 16:06:09 volumio volumio[841]: info: ------------------------------ 121ms Sep 14 16:06:09 volumio volumio[841]: info: ------------------------------ 120ms Sep 14 16:06:09 volumio volumio[841]: info: Sep 14 16:06:09 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:06:09 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:06:09 volumio volumio[841]: info: Sep 14 16:06:09 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:06:09 volumio volumio[841]: info: sendMpdCommand playlistinfo took 105 milliseconds Sep 14 16:06:09 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:06:09 volumio volumio[841]: info: sendMpdCommand playlistinfo took 104 milliseconds Sep 14 16:06:09 volumio volumio[841]: info: sendMpdCommand playlistinfo took 105 milliseconds Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:06:09 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:06:09 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:09 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":212,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"187594.mp3","artist":null,"album":null,"uri":"http://192.168.1.10:50002/m/MP3/187594.mp3","trackType":"mp3"} Sep 14 16:06:09 volumio volumio[841]: verbose: CURRENT POSITION 0 Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:06:09 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:09 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:06:09 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:09 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":212,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Walk This Way","artist":"Aerosmith","album":"70s Greatest Hits [Disc 2]","uri":"http://192.168.1.10:50002/m/MP3/187594.mp3","trackType":"mp3"} Sep 14 16:06:09 volumio volumio[841]: verbose: CURRENT POSITION 0 Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:06:09 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:09 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:06:09 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:09 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":212,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Walk This Way","artist":"Aerosmith","album":"70s Greatest Hits [Disc 2]","uri":"http://192.168.1.10:50002/m/MP3/187594.mp3","trackType":"mp3"} Sep 14 16:06:09 volumio volumio[841]: verbose: CURRENT POSITION 0 Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:06:09 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:09 volumio volumio[841]: info: ------------------------------ 239ms Sep 14 16:06:09 volumio volumio[841]: info: ------------------------------ 232ms Sep 14 16:06:09 volumio volumio[841]: info: ------------------------------ 231ms Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:06:09 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:06:09 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:06:09 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:06:09 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:06:09 volumio volumio[841]: info: Sep 14 16:06:09 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:06:09 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:06:09 volumio volumio[841]: info: Sep 14 16:06:09 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:06:09 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:06:09 volumio volumio[841]: info: Sep 14 16:06:09 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:06:09 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:06:09 volumio volumio[841]: info: Sep 14 16:06:09 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:06:09 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:06:09 volumio volumio[841]: info: ------------------------------ 176ms Sep 14 16:06:09 volumio volumio[841]: info: sendMpdCommand status took 174 milliseconds Sep 14 16:06:09 volumio volumio[841]: info: ------------------------------ 21ms Sep 14 16:06:09 volumio volumio[841]: info: sendMpdCommand status took 20 milliseconds Sep 14 16:06:09 volumio volumio[841]: info: ------------------------------ 19ms Sep 14 16:06:09 volumio volumio[841]: info: sendMpdCommand status took 18 milliseconds Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:06:09 volumio volumio[841]: info: sendMpdCommand playlistinfo took 4 milliseconds Sep 14 16:06:09 volumio volumio[841]: info: sendMpdCommand playlistinfo took 3 milliseconds Sep 14 16:06:09 volumio volumio[841]: info: sendMpdCommand playlistinfo took 4 milliseconds Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:06:09 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:06:09 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:06:09 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:09 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":982,"duration":212,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Walk This Way","artist":"Aerosmith","album":"70s Greatest Hits [Disc 2]","uri":"http://192.168.1.10:50002/m/MP3/187594.mp3","trackType":"mp3"} Sep 14 16:06:09 volumio volumio[841]: verbose: CURRENT POSITION 0 Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:06:09 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:09 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:06:09 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:09 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1108,"duration":212,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Walk This Way","artist":"Aerosmith","album":"70s Greatest Hits [Disc 2]","uri":"http://192.168.1.10:50002/m/MP3/187594.mp3","trackType":"mp3"} Sep 14 16:06:09 volumio volumio[841]: verbose: CURRENT POSITION 0 Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:06:09 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:09 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:06:09 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:09 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1108,"duration":212,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Walk This Way","artist":"Aerosmith","album":"70s Greatest Hits [Disc 2]","uri":"http://192.168.1.10:50002/m/MP3/187594.mp3","trackType":"mp3"} Sep 14 16:06:09 volumio volumio[841]: verbose: CURRENT POSITION 0 Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:06:09 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:09 volumio volumio[841]: info: ------------------------------ 281ms Sep 14 16:06:09 volumio volumio[841]: info: ------------------------------ 127ms Sep 14 16:06:09 volumio volumio[841]: info: ------------------------------ 125ms Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:06:09 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:06:09 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:06:09 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:06:09 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:06:09 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:06:09 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:06:09 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:06:09 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:06:12 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 14 16:06:12 volumio volumio[841]: info: Preload queue cleared Sep 14 16:06:13 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 14 16:06:13 volumio volumio[841]: info: Preload queue cleared Sep 14 16:06:16 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 14 16:06:17 volumio volumio[841]: info: Preload queue cleared Sep 14 16:06:18 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 14 16:06:19 volumio volumio[841]: Cannot compose Albumart path Sep 14 16:06:19 volumio volumio[841]: info: Preload queue cleared Sep 14 16:06:28 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 14 16:06:28 volumio volumio[841]: info: Preload queue cleared Sep 14 16:06:28 volumio volumio[841]: info: Preloading song: upnp/http://192.168.1.10:50001/ContentDirectory/control@27$190808$@190808 Sep 14 16:06:28 volumio volumio[841]: info: Exploding uri upnp/http://192.168.1.10:50001/ContentDirectory/control@27$190808$@190808 in service upnp_browser Sep 14 16:06:30 volumio volumio[841]: info: Preload queue cleared Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::ClearQueue Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::stop Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::stPlaybackTimer Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::updateTrackBlock Sep 14 16:06:30 volumio volumio[841]: info: CorePlayQueue::getTrackBlock Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::serviceStop Sep 14 16:06:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::serviceStop Sep 14 16:06:30 volumio volumio[841]: info: [1757858790442] ControllerUPNPBrowser::stop Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand stop Sep 14 16:06:30 volumio volumio[841]: info: CorePlayQueue::clearPlayQueue Sep 14 16:06:30 volumio volumio[841]: info: CorePlayQueue::saveQueue Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushQueue Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::addQueueItems Sep 14 16:06:30 volumio volumio[841]: info: CorePlayQueue::addQueueItems Sep 14 16:06:30 volumio volumio[841]: info: Preload queue cleared Sep 14 16:06:30 volumio volumio[841]: info: Adding Item to queue: upnp/folder/http://192.168.1.10:50001/ContentDirectory/control@27$190808 Sep 14 16:06:30 volumio volumio[841]: info: Exploding uri upnp/folder/http://192.168.1.10:50001/ContentDirectory/control@27$190808 in service upnp_browser Sep 14 16:06:30 volumio volumio[841]: info: Sep 14 16:06:30 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:06:30 volumio volumio[841]: info: sendMpdCommand stop took 25 milliseconds Sep 14 16:06:30 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:06:30 volumio volumio[841]: info: sendMpdCommand status took 3 milliseconds Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:06:30 volumio volumio[841]: info: Sep 14 16:06:30 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:06:30 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:06:30 volumio volumio[841]: info: Sep 14 16:06:30 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:06:30 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:06:30 volumio volumio[841]: info: sendMpdCommand playlistinfo took 6 milliseconds Sep 14 16:06:30 volumio volumio[841]: info: sendMpdCommand status took 5 milliseconds Sep 14 16:06:30 volumio volumio[841]: info: sendMpdCommand status took 3 milliseconds Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:06:30 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:30 volumio volumio[841]: 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":"Walk This Way","artist":"Aerosmith","album":"70s Greatest Hits [Disc 2]","uri":"http://192.168.1.10:50002/m/MP3/187594.mp3","trackType":"mp3"} Sep 14 16:06:30 volumio volumio[841]: verbose: CURRENT POSITION 0 Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::syncState stateService stop Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus stop Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:30 volumio volumio[841]: info: No code Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:30 volumio volumio[841]: info: ------------------------------ 68ms Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushQueue Sep 14 16:06:30 volumio volumio[841]: info: CorePlayQueue::saveQueue Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::updateTrackBlock Sep 14 16:06:30 volumio volumio[841]: info: CorePlayQueue::getTrackBlock Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::volumioPlay Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::play index 0 Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::stop Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::play index undefined Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 14 16:06:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::startPlaybackTimer Sep 14 16:06:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:30 volumio volumio[841]: info: [1757858790555] ControllerUPNPBrowser::clearAddPlayTrack Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand stop Sep 14 16:06:30 volumio volumio[841]: info: sendMpdCommand playlistinfo took 76 milliseconds Sep 14 16:06:30 volumio volumio[841]: info: sendMpdCommand playlistinfo took 77 milliseconds Sep 14 16:06:30 volumio volumio[841]: info: sendMpdCommand stop took 4 milliseconds Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand clear Sep 14 16:06:30 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:30 volumio volumio[841]: 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":"Walk This Way","artist":"Aerosmith","album":"70s Greatest Hits [Disc 2]","uri":"http://192.168.1.10:50002/m/MP3/187594.mp3","trackType":"mp3"} Sep 14 16:06:30 volumio volumio[841]: verbose: CURRENT POSITION 0 Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::syncState stateService stop Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus stop Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:30 volumio volumio[841]: info: No code Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:30 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:30 volumio volumio[841]: 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":"Walk This Way","artist":"Aerosmith","album":"70s Greatest Hits [Disc 2]","uri":"http://192.168.1.10:50002/m/MP3/187594.mp3","trackType":"mp3"} Sep 14 16:06:30 volumio volumio[841]: verbose: CURRENT POSITION 0 Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::syncState stateService stop Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus stop Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:30 volumio volumio[841]: info: No code Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:30 volumio volumio[841]: info: ------------------------------ 170ms Sep 14 16:06:30 volumio volumio[841]: info: ------------------------------ 170ms Sep 14 16:06:30 volumio volumio[841]: info: Sep 14 16:06:30 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:06:30 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:06:30 volumio volumio[841]: info: sendMpdCommand clear took 105 milliseconds Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.10:50002/m/MP3/190808.mp3" Sep 14 16:06:30 volumio volumio[841]: info: Sep 14 16:06:30 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:06:30 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:06:30 volumio volumio[841]: info: Sep 14 16:06:30 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:06:30 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:06:30 volumio volumio[841]: error: updateQueue error: null Sep 14 16:06:30 volumio volumio[841]: info: ------------------------------ 118ms Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.10:50002/m/MP3/190808.mp3" Sep 14 16:06:30 volumio volumio[841]: error: updateQueue error: null Sep 14 16:06:30 volumio volumio[841]: error: updateQueue error: null Sep 14 16:06:30 volumio volumio[841]: info: Sep 14 16:06:30 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:06:30 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:06:30 volumio volumio[841]: info: ------------------------------ 116ms Sep 14 16:06:30 volumio volumio[841]: info: ------------------------------ 114ms Sep 14 16:06:30 volumio volumio[841]: info: sendMpdCommand add "http://192.168.1.10:50002/m/MP3/190808.mp3" took 3 milliseconds Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::setConsumeUpdateService mpd Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand play Sep 14 16:06:30 volumio volumio[841]: info: Sep 14 16:06:30 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:06:30 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:06:30 volumio volumio[841]: info: Sep 14 16:06:30 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:06:30 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:06:30 volumio volumio[841]: info: ------------------------------ 8ms Sep 14 16:06:30 volumio volumio[841]: info: sendMpdCommand play took 7 milliseconds Sep 14 16:06:30 volumio volumio[841]: info: ------------------------------ 6ms Sep 14 16:06:30 volumio volumio[841]: info: ------------------------------ 4ms Sep 14 16:06:30 volumio volumio[841]: info: Sep 14 16:06:30 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:06:30 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:06:30 volumio volumio[841]: info: Sep 14 16:06:30 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:06:30 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:06:30 volumio volumio[841]: info: Sep 14 16:06:30 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:06:30 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:06:30 volumio volumio[841]: info: Sep 14 16:06:30 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:06:30 volumio volumio[841]: info: sendMpdCommand status took 14 milliseconds Sep 14 16:06:30 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:06:30 volumio volumio[841]: info: sendMpdCommand status took 13 milliseconds Sep 14 16:06:30 volumio volumio[841]: info: sendMpdCommand status took 11 milliseconds Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:06:30 volumio volumio[841]: info: Sep 14 16:06:30 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:06:30 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:06:30 volumio volumio[841]: info: Sep 14 16:06:30 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:06:30 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:06:30 volumio volumio[841]: info: sendMpdCommand status took 11 milliseconds Sep 14 16:06:30 volumio volumio[841]: info: sendMpdCommand playlistinfo took 10 milliseconds Sep 14 16:06:30 volumio volumio[841]: info: sendMpdCommand playlistinfo took 9 milliseconds Sep 14 16:06:30 volumio volumio[841]: info: sendMpdCommand playlistinfo took 8 milliseconds Sep 14 16:06:30 volumio volumio[841]: info: sendMpdCommand status took 6 milliseconds Sep 14 16:06:30 volumio volumio[841]: info: sendMpdCommand status took 5 milliseconds Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:06:30 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:06:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:30 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":369,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"190808.mp3","artist":null,"album":null,"uri":"http://192.168.1.10:50002/m/MP3/190808.mp3","trackType":"mp3"} Sep 14 16:06:30 volumio volumio[841]: verbose: CURRENT POSITION 0 Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus stop Sep 14 16:06:30 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:06:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:30 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":369,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"190808.mp3","artist":null,"album":null,"uri":"http://192.168.1.10:50002/m/MP3/190808.mp3","trackType":"mp3"} Sep 14 16:06:30 volumio volumio[841]: verbose: CURRENT POSITION 0 Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:06:30 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:30 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:06:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:30 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":369,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"190808.mp3","artist":null,"album":null,"uri":"http://192.168.1.10:50002/m/MP3/190808.mp3","trackType":"mp3"} Sep 14 16:06:30 volumio volumio[841]: verbose: CURRENT POSITION 0 Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:06:30 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:30 volumio volumio[841]: info: ------------------------------ 80ms Sep 14 16:06:30 volumio volumio[841]: info: ------------------------------ 134ms Sep 14 16:06:30 volumio volumio[841]: info: ------------------------------ 134ms Sep 14 16:06:30 volumio volumio[841]: info: Sep 14 16:06:30 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:06:30 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:06:30 volumio volumio[841]: info: Sep 14 16:06:30 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:06:30 volumio volumio[841]: info: sendMpdCommand playlistinfo took 111 milliseconds Sep 14 16:06:30 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:06:30 volumio volumio[841]: info: sendMpdCommand playlistinfo took 102 milliseconds Sep 14 16:06:30 volumio volumio[841]: info: sendMpdCommand playlistinfo took 103 milliseconds Sep 14 16:06:30 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:06:30 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:06:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:30 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":369,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"190808.mp3","artist":null,"album":null,"uri":"http://192.168.1.10:50002/m/MP3/190808.mp3","trackType":"mp3"} Sep 14 16:06:30 volumio volumio[841]: verbose: CURRENT POSITION 0 Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:06:30 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:30 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:06:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:30 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":369,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"we gonna take u","artist":"Alchemist Project","album":"Alchemist Project In The Mix 2","uri":"http://192.168.1.10:50002/m/MP3/190808.mp3","trackType":"mp3"} Sep 14 16:06:30 volumio volumio[841]: verbose: CURRENT POSITION 0 Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:06:30 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:30 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:06:30 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:30 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":369,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"we gonna take u","artist":"Alchemist Project","album":"Alchemist Project In The Mix 2","uri":"http://192.168.1.10:50002/m/MP3/190808.mp3","trackType":"mp3"} Sep 14 16:06:30 volumio volumio[841]: verbose: CURRENT POSITION 0 Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:06:30 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:06:30 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:30 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:31 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:31 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:31 volumio volumio[841]: info: ------------------------------ 254ms Sep 14 16:06:31 volumio volumio[841]: info: ------------------------------ 247ms Sep 14 16:06:31 volumio volumio[841]: info: ------------------------------ 247ms Sep 14 16:06:31 volumio volumio[841]: info: Sep 14 16:06:31 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:06:31 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:06:31 volumio volumio[841]: info: Sep 14 16:06:31 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:06:31 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:06:31 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:06:31 volumio volumio[841]: info: Sep 14 16:06:31 volumio volumio[841]: ---------------------------- MPD announces system playlist update Sep 14 16:06:31 volumio volumio[841]: info: Ignoring MPD Status Update Sep 14 16:06:31 volumio volumio[841]: info: Sep 14 16:06:31 volumio volumio[841]: ---------------------------- MPD announces state update: player Sep 14 16:06:31 volumio volumio[841]: info: ControllerMpd::getState Sep 14 16:06:31 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand status Sep 14 16:06:31 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:06:31 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:06:31 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:06:31 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:06:31 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:06:31 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:06:31 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:06:31 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:06:31 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:06:31 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:06:31 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:06:31 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:06:31 volumio volumio[841]: info: ------------------------------ 171ms Sep 14 16:06:31 volumio volumio[841]: info: sendMpdCommand status took 169 milliseconds Sep 14 16:06:31 volumio volumio[841]: info: ------------------------------ 40ms Sep 14 16:06:31 volumio volumio[841]: info: sendMpdCommand status took 39 milliseconds Sep 14 16:06:31 volumio volumio[841]: info: ------------------------------ 38ms Sep 14 16:06:31 volumio volumio[841]: info: sendMpdCommand status took 36 milliseconds Sep 14 16:06:31 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:06:31 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:06:31 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:06:31 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:06:31 volumio volumio[841]: verbose: ControllerMpd::parseState Sep 14 16:06:31 volumio volumio[841]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 14 16:06:31 volumio volumio[841]: info: sendMpdCommand playlistinfo took 12 milliseconds Sep 14 16:06:31 volumio volumio[841]: info: sendMpdCommand playlistinfo took 11 milliseconds Sep 14 16:06:31 volumio volumio[841]: info: sendMpdCommand playlistinfo took 12 milliseconds Sep 14 16:06:31 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:06:31 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:06:31 volumio volumio[841]: verbose: ControllerMpd::parseTrackInfo Sep 14 16:06:31 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:06:31 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:06:31 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:31 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":982,"duration":369,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"112 Kbps","isStreaming":false,"title":"we gonna take u","artist":"Alchemist Project","album":"Alchemist Project In The Mix 2","uri":"http://192.168.1.10:50002/m/MP3/190808.mp3","trackType":"mp3"} Sep 14 16:06:31 volumio volumio[841]: verbose: CURRENT POSITION 0 Sep 14 16:06:31 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:06:31 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:06:31 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:06:31 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:31 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 14 16:06:31 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:31 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:31 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:31 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:06:31 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:06:31 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:31 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1108,"duration":369,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"112 Kbps","isStreaming":false,"title":"we gonna take u","artist":"Alchemist Project","album":"Alchemist Project In The Mix 2","uri":"http://192.168.1.10:50002/m/MP3/190808.mp3","trackType":"mp3"} Sep 14 16:06:31 volumio volumio[841]: verbose: CURRENT POSITION 0 Sep 14 16:06:31 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:06:31 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:06:31 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:06:31 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:31 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:31 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:31 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:31 volumio volumio[841]: info: ControllerMpd::pushState Sep 14 16:06:31 volumio volumio[841]: info: CoreCommandRouter::servicePushState Sep 14 16:06:31 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Sep 14 16:06:31 volumio volumio[841]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1108,"duration":369,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"112 Kbps","isStreaming":false,"title":"we gonna take u","artist":"Alchemist Project","album":"Alchemist Project In The Mix 2","uri":"http://192.168.1.10:50002/m/MP3/190808.mp3","trackType":"mp3"} Sep 14 16:06:31 volumio volumio[841]: verbose: CURRENT POSITION 0 Sep 14 16:06:31 volumio volumio[841]: info: CoreStateMachine::syncState stateService play Sep 14 16:06:31 volumio volumio[841]: info: CoreStateMachine::syncState currentStatus play Sep 14 16:06:31 volumio volumio[841]: info: Received an update from plugin. extracting info from payload Sep 14 16:06:31 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:31 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:31 volumio volumio[841]: info: CoreStateMachine::pushState Sep 14 16:06:31 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Sep 14 16:06:31 volumio volumio[841]: info: ------------------------------ 294ms Sep 14 16:06:31 volumio volumio[841]: info: ------------------------------ 163ms Sep 14 16:06:31 volumio volumio[841]: info: ------------------------------ 161ms Sep 14 16:06:31 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:06:31 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:06:31 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:06:31 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:06:31 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:06:31 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:06:31 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:06:31 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:06:31 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:06:31 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:06:31 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:06:31 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:06:31 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:06:31 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:06:31 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:06:31 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Sep 14 16:06:31 volumio volumio[841]: info: CoreStateMachine::getQueue Sep 14 16:06:31 volumio volumio[841]: info: CorePlayQueue::getQueue Sep 14 16:06:37 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 14 16:06:38 volumio volumio[841]: info: Preload queue cleared Sep 14 16:06:41 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 14 16:06:41 volumio volumio[841]: info: Preload queue cleared Sep 14 16:06:46 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 14 16:06:46 volumio volumio[841]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 14 16:06:46 volumio volumio[841]: TypeError: Cannot read property 'length' of undefined Sep 14 16:06:46 volumio volumio[841]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Sep 14 16:06:46 volumio volumio[841]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Sep 14 16:06:46 volumio volumio[841]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Sep 14 16:06:46 volumio volumio[841]: at Parser.emit (events.js:315:20) Sep 14 16:06:46 volumio volumio[841]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Sep 14 16:06:46 volumio volumio[841]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Sep 14 16:06:46 volumio volumio[841]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Sep 14 16:06:46 volumio volumio[841]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Sep 14 16:06:46 volumio volumio[841]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Sep 14 16:06:46 volumio volumio[841]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Sep 14 16:06:46 volumio volumio[841]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Sep 14 16:06:46 volumio volumio[841]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Sep 14 16:06:46 volumio volumio[841]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Sep 14 16:06:46 volumio volumio[841]: at IncomingMessage.emit (events.js:327:22) Sep 14 16:06:46 volumio volumio[841]: at endReadableNT (internal/streams/readable.js:1327:12) Sep 14 16:06:46 volumio volumio[841]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Sep 14 16:06:46 volumio volumio[841]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 14 16:06:47 volumio sudo[5309]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-09-14 16:05 Sep 14 16:06:47 volumio sudo[5309]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="29866754e5f1d7e4d0f581c10d9f22852f6f21db" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 10:25:36 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="cf6e14681b2ecbbdc9a62186b0f3114c"