-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Sat 2025-04-19 20:50:13 CEST. -- Apr 19 20:49:07 volumio volumio[979]: info: CoreCommandRouter::volumioNext Apr 19 20:49:07 volumio volumio[979]: info: CoreStateMachine::next Apr 19 20:49:07 volumio volumio[979]: info: ControllerMpd::next Apr 19 20:49:07 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand next Apr 19 20:49:07 volumio volumio[979]: info: Apr 19 20:49:07 volumio volumio[979]: ---------------------------- MPD announces state update: player Apr 19 20:49:07 volumio volumio[979]: info: sendMpdCommand next took 21 milliseconds Apr 19 20:49:07 volumio volumio[979]: info: ControllerMpd::getState Apr 19 20:49:07 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 19 20:49:07 volumio volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 19 20:49:07 volumio volumio[979]: verbose: ControllerMpd::parseState Apr 19 20:49:07 volumio volumio[979]: info: ControllerMpd::pushState Apr 19 20:49:07 volumio volumio[979]: info: CoreCommandRouter::servicePushState Apr 19 20:49:07 volumio volumio[979]: info: CoreStateMachine::pushState Apr 19 20:49:07 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 19 20:49:07 volumio volumio[979]: info: CoreCommandRouter::volumioPushState Apr 19 20:49:07 volumio volumio[979]: info: CorePlayQueue::getTrack 2 Apr 19 20:49:07 volumio volumio[979]: 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} Apr 19 20:49:07 volumio volumio[979]: verbose: CURRENT POSITION 2 Apr 19 20:49:07 volumio volumio[979]: info: CoreStateMachine::syncState stateService stop Apr 19 20:49:07 volumio volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 19 20:49:07 volumio volumio[979]: info: CoreStateMachine::play index undefined Apr 19 20:49:07 volumio volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 19 20:49:07 volumio volumio[979]: info: CoreStateMachine::pushState Apr 19 20:49:07 volumio volumio[979]: info: CorePlayQueue::getTrack 3 Apr 19 20:49:07 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 19 20:49:07 volumio volumio[979]: info: CoreCommandRouter::volumioPushState Apr 19 20:49:07 volumio volumio[979]: info: CorePlayQueue::getTrack 3 Apr 19 20:49:07 volumio volumio[979]: info: CoreStateMachine::startPlaybackTimer Apr 19 20:49:07 volumio volumio[979]: info: CorePlayQueue::getTrack 3 Apr 19 20:49:07 volumio volumio[979]: info: [1745088547621] ControllerUPNPBrowser::clearAddPlayTrack Apr 19 20:49:07 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand stop Apr 19 20:49:07 volumio volumio[979]: info: ------------------------------ 13ms Apr 19 20:49:07 volumio volumio[979]: info: CoreStateMachine::pushState Apr 19 20:49:07 volumio volumio[979]: info: CorePlayQueue::getTrack 3 Apr 19 20:49:07 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 19 20:49:07 volumio volumio[979]: info: CoreCommandRouter::volumioPushState Apr 19 20:49:07 volumio volumio[979]: info: sendMpdCommand stop took 7 milliseconds Apr 19 20:49:07 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand clear Apr 19 20:49:07 volumio volumio[979]: info: CoreCommandRouter::volumioGetQueue Apr 19 20:49:07 volumio volumio[979]: info: CoreStateMachine::getQueue Apr 19 20:49:07 volumio volumio[979]: info: CorePlayQueue::getQueue Apr 19 20:49:07 volumio volumio[979]: info: Apr 19 20:49:07 volumio volumio[979]: ---------------------------- MPD announces system playlist update Apr 19 20:49:07 volumio volumio[979]: info: Ignoring MPD Status Update Apr 19 20:49:07 volumio volumio[979]: info: sendMpdCommand clear took 4 milliseconds Apr 19 20:49:07 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.0.6:50002/m/NDLNA/132209.flac" Apr 19 20:49:07 volumio volumio[979]: error: updateQueue error: null Apr 19 20:49:07 volumio volumio[979]: info: ------------------------------ 2ms Apr 19 20:49:07 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.0.6:50002/m/NDLNA/132209.flac" Apr 19 20:49:07 volumio volumio[979]: info: Apr 19 20:49:07 volumio volumio[979]: ---------------------------- MPD announces system playlist update Apr 19 20:49:07 volumio volumio[979]: info: Ignoring MPD Status Update Apr 19 20:49:07 volumio volumio[979]: info: sendMpdCommand add "http://192.168.0.6:50002/m/NDLNA/132209.flac" took 1 milliseconds Apr 19 20:49:07 volumio volumio[979]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 19 20:49:07 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand play Apr 19 20:49:07 volumio volumio[979]: info: ------------------------------ 2ms Apr 19 20:49:07 volumio volumio[979]: info: sendMpdCommand play took 1 milliseconds Apr 19 20:49:07 volumio volumio[979]: info: Apr 19 20:49:07 volumio volumio[979]: ---------------------------- MPD announces state update: player Apr 19 20:49:07 volumio volumio[979]: info: ControllerMpd::getState Apr 19 20:49:07 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 19 20:49:07 volumio volumio[979]: info: Apr 19 20:49:07 volumio volumio[979]: ---------------------------- MPD announces state update: player Apr 19 20:49:07 volumio volumio[979]: info: sendMpdCommand status took 2 milliseconds Apr 19 20:49:07 volumio volumio[979]: info: ControllerMpd::getState Apr 19 20:49:07 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 19 20:49:07 volumio volumio[979]: verbose: ControllerMpd::parseState Apr 19 20:49:07 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 19 20:49:07 volumio volumio[979]: info: sendMpdCommand status took 2 milliseconds Apr 19 20:49:07 volumio volumio[979]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 19 20:49:07 volumio volumio[979]: verbose: ControllerMpd::parseState Apr 19 20:49:07 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 19 20:49:07 volumio volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 19 20:49:07 volumio volumio[979]: info: ControllerMpd::pushState Apr 19 20:49:07 volumio volumio[979]: info: CoreCommandRouter::servicePushState Apr 19 20:49:07 volumio volumio[979]: info: CorePlayQueue::getTrack 3 Apr 19 20:49:07 volumio volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":298,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"132209.flac","artist":null,"album":null,"uri":"http://192.168.0.6:50002/m/NDLNA/132209.flac","trackType":"flac"} Apr 19 20:49:07 volumio volumio[979]: verbose: CURRENT POSITION 3 Apr 19 20:49:07 volumio volumio[979]: info: CoreStateMachine::syncState stateService play Apr 19 20:49:07 volumio volumio[979]: info: CoreStateMachine::syncState currentStatus stop Apr 19 20:49:07 volumio volumio[979]: info: ------------------------------ 7ms Apr 19 20:49:07 volumio volumio[979]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 19 20:49:07 volumio volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 19 20:49:07 volumio volumio[979]: info: ControllerMpd::pushState Apr 19 20:49:07 volumio volumio[979]: info: CoreCommandRouter::servicePushState Apr 19 20:49:07 volumio volumio[979]: info: CorePlayQueue::getTrack 3 Apr 19 20:49:07 volumio volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":298,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"132209.flac","artist":null,"album":null,"uri":"http://192.168.0.6:50002/m/NDLNA/132209.flac","trackType":"flac"} Apr 19 20:49:07 volumio volumio[979]: verbose: CURRENT POSITION 3 Apr 19 20:49:07 volumio volumio[979]: info: CoreStateMachine::syncState stateService play Apr 19 20:49:07 volumio volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 19 20:49:07 volumio volumio[979]: info: Received an update from plugin. extracting info from payload Apr 19 20:49:07 volumio volumio[979]: info: CoreStateMachine::pushState Apr 19 20:49:07 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 19 20:49:07 volumio volumio[979]: info: CoreCommandRouter::volumioPushState Apr 19 20:49:07 volumio volumio[979]: info: CoreStateMachine::pushState Apr 19 20:49:07 volumio volumio[979]: info: CoreCommandRouter::volumioPushState Apr 19 20:49:07 volumio volumio[979]: info: ------------------------------ 16ms Apr 19 20:49:07 volumio volumio[979]: info: Apr 19 20:49:07 volumio volumio[979]: ---------------------------- MPD announces system playlist update Apr 19 20:49:07 volumio volumio[979]: info: Ignoring MPD Status Update Apr 19 20:49:07 volumio volumio[979]: info: Apr 19 20:49:07 volumio volumio[979]: ---------------------------- MPD announces state update: player Apr 19 20:49:07 volumio volumio[979]: info: ControllerMpd::getState Apr 19 20:49:07 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 19 20:49:07 volumio volumio[979]: info: ------------------------------ 2ms Apr 19 20:49:07 volumio volumio[979]: info: sendMpdCommand status took 2 milliseconds Apr 19 20:49:07 volumio volumio[979]: verbose: ControllerMpd::parseState Apr 19 20:49:07 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 19 20:49:07 volumio volumio[979]: info: sendMpdCommand playlistinfo took 0 milliseconds Apr 19 20:49:07 volumio volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 19 20:49:07 volumio volumio[979]: info: ControllerMpd::pushState Apr 19 20:49:07 volumio volumio[979]: info: CoreCommandRouter::servicePushState Apr 19 20:49:07 volumio volumio[979]: info: CorePlayQueue::getTrack 3 Apr 19 20:49:07 volumio volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":178,"duration":298,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"196 Kbps","isStreaming":false,"title":"Praying For Time","artist":"George Michael","album":"Symphonica","uri":"http://192.168.0.6:50002/m/NDLNA/132209.flac","trackType":"flac"} Apr 19 20:49:07 volumio volumio[979]: verbose: CURRENT POSITION 3 Apr 19 20:49:07 volumio volumio[979]: info: CoreStateMachine::syncState stateService play Apr 19 20:49:07 volumio volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 19 20:49:07 volumio volumio[979]: info: Received an update from plugin. extracting info from payload Apr 19 20:49:07 volumio volumio[979]: info: CoreStateMachine::pushState Apr 19 20:49:07 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 19 20:49:07 volumio volumio[979]: info: CoreCommandRouter::volumioPushState Apr 19 20:49:07 volumio volumio[979]: info: CoreStateMachine::pushState Apr 19 20:49:07 volumio volumio[979]: info: CoreCommandRouter::volumioPushState Apr 19 20:49:07 volumio volumio[979]: info: ------------------------------ 18ms Apr 19 20:49:07 volumio volumio[979]: info: CoreCommandRouter::volumioGetQueue Apr 19 20:49:07 volumio volumio[979]: info: CoreStateMachine::getQueue Apr 19 20:49:07 volumio volumio[979]: info: CorePlayQueue::getQueue Apr 19 20:49:07 volumio volumio[979]: info: CoreCommandRouter::volumioGetQueue Apr 19 20:49:07 volumio volumio[979]: info: CoreStateMachine::getQueue Apr 19 20:49:07 volumio volumio[979]: info: CorePlayQueue::getQueue Apr 19 20:49:11 volumio volumio[979]: info: CoreCommandRouter::volumioNext Apr 19 20:49:11 volumio volumio[979]: info: CoreStateMachine::next Apr 19 20:49:11 volumio volumio[979]: info: ControllerMpd::next Apr 19 20:49:11 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand next Apr 19 20:49:11 volumio volumio[979]: info: sendMpdCommand next took 32 milliseconds Apr 19 20:49:11 volumio volumio[979]: info: Apr 19 20:49:11 volumio volumio[979]: ---------------------------- MPD announces state update: player Apr 19 20:49:11 volumio volumio[979]: info: ControllerMpd::getState Apr 19 20:49:11 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 19 20:49:11 volumio volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 19 20:49:11 volumio volumio[979]: verbose: ControllerMpd::parseState Apr 19 20:49:11 volumio volumio[979]: info: ControllerMpd::pushState Apr 19 20:49:11 volumio volumio[979]: info: CoreCommandRouter::servicePushState Apr 19 20:49:11 volumio volumio[979]: info: CoreStateMachine::pushState Apr 19 20:49:11 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 19 20:49:11 volumio volumio[979]: info: CoreCommandRouter::volumioPushState Apr 19 20:49:11 volumio volumio[979]: info: CorePlayQueue::getTrack 3 Apr 19 20:49:11 volumio volumio[979]: 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} Apr 19 20:49:11 volumio volumio[979]: verbose: CURRENT POSITION 3 Apr 19 20:49:11 volumio volumio[979]: info: CoreStateMachine::syncState stateService stop Apr 19 20:49:11 volumio volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 19 20:49:11 volumio volumio[979]: info: CoreStateMachine::play index undefined Apr 19 20:49:11 volumio volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 19 20:49:11 volumio volumio[979]: info: CoreStateMachine::pushState Apr 19 20:49:11 volumio volumio[979]: info: CorePlayQueue::getTrack 4 Apr 19 20:49:11 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 19 20:49:11 volumio volumio[979]: info: CoreCommandRouter::volumioPushState Apr 19 20:49:11 volumio volumio[979]: info: CorePlayQueue::getTrack 4 Apr 19 20:49:11 volumio volumio[979]: info: CoreStateMachine::startPlaybackTimer Apr 19 20:49:11 volumio volumio[979]: info: CorePlayQueue::getTrack 4 Apr 19 20:49:11 volumio volumio[979]: info: [1745088551882] ControllerUPNPBrowser::clearAddPlayTrack Apr 19 20:49:11 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand stop Apr 19 20:49:11 volumio volumio[979]: info: ------------------------------ 14ms Apr 19 20:49:11 volumio volumio[979]: info: CoreStateMachine::pushState Apr 19 20:49:11 volumio volumio[979]: info: CorePlayQueue::getTrack 4 Apr 19 20:49:11 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 19 20:49:11 volumio volumio[979]: info: CoreCommandRouter::volumioPushState Apr 19 20:49:11 volumio volumio[979]: info: sendMpdCommand stop took 6 milliseconds Apr 19 20:49:11 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand clear Apr 19 20:49:11 volumio volumio[979]: info: CoreCommandRouter::volumioGetQueue Apr 19 20:49:11 volumio volumio[979]: info: CoreStateMachine::getQueue Apr 19 20:49:11 volumio volumio[979]: info: CorePlayQueue::getQueue Apr 19 20:49:11 volumio volumio[979]: info: Apr 19 20:49:11 volumio volumio[979]: ---------------------------- MPD announces system playlist update Apr 19 20:49:11 volumio volumio[979]: info: Ignoring MPD Status Update Apr 19 20:49:11 volumio volumio[979]: info: sendMpdCommand clear took 6 milliseconds Apr 19 20:49:11 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.0.6:50002/m/NDLNA/132201.flac" Apr 19 20:49:11 volumio volumio[979]: error: updateQueue error: null Apr 19 20:49:11 volumio volumio[979]: info: ------------------------------ 86ms Apr 19 20:49:11 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.0.6:50002/m/NDLNA/132201.flac" Apr 19 20:49:11 volumio volumio[979]: info: Apr 19 20:49:11 volumio volumio[979]: ---------------------------- MPD announces system playlist update Apr 19 20:49:11 volumio volumio[979]: info: Ignoring MPD Status Update Apr 19 20:49:11 volumio volumio[979]: info: sendMpdCommand add "http://192.168.0.6:50002/m/NDLNA/132201.flac" took 2 milliseconds Apr 19 20:49:11 volumio volumio[979]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 19 20:49:11 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand play Apr 19 20:49:11 volumio volumio[979]: info: ------------------------------ 3ms Apr 19 20:49:11 volumio volumio[979]: info: sendMpdCommand play took 2 milliseconds Apr 19 20:49:12 volumio volumio[979]: info: Apr 19 20:49:12 volumio volumio[979]: ---------------------------- MPD announces state update: player Apr 19 20:49:12 volumio volumio[979]: info: ControllerMpd::getState Apr 19 20:49:12 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 19 20:49:12 volumio volumio[979]: info: Apr 19 20:49:12 volumio volumio[979]: ---------------------------- MPD announces state update: player Apr 19 20:49:12 volumio volumio[979]: info: sendMpdCommand status took 3 milliseconds Apr 19 20:49:12 volumio volumio[979]: info: ControllerMpd::getState Apr 19 20:49:12 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 19 20:49:12 volumio volumio[979]: verbose: ControllerMpd::parseState Apr 19 20:49:12 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 19 20:49:12 volumio volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 19 20:49:12 volumio volumio[979]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 19 20:49:12 volumio volumio[979]: verbose: ControllerMpd::parseState Apr 19 20:49:12 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 19 20:49:12 volumio volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 19 20:49:12 volumio volumio[979]: info: ControllerMpd::pushState Apr 19 20:49:12 volumio volumio[979]: info: CoreCommandRouter::servicePushState Apr 19 20:49:12 volumio volumio[979]: info: CorePlayQueue::getTrack 4 Apr 19 20:49:12 volumio volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":230,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"132201.flac","artist":null,"album":null,"uri":"http://192.168.0.6:50002/m/NDLNA/132201.flac","trackType":"flac"} Apr 19 20:49:12 volumio volumio[979]: verbose: CURRENT POSITION 4 Apr 19 20:49:12 volumio volumio[979]: info: CoreStateMachine::syncState stateService play Apr 19 20:49:12 volumio volumio[979]: info: CoreStateMachine::syncState currentStatus stop Apr 19 20:49:12 volumio volumio[979]: info: ------------------------------ 8ms Apr 19 20:49:12 volumio volumio[979]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 19 20:49:12 volumio volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 19 20:49:12 volumio volumio[979]: info: ControllerMpd::pushState Apr 19 20:49:12 volumio volumio[979]: info: CoreCommandRouter::servicePushState Apr 19 20:49:12 volumio volumio[979]: info: CorePlayQueue::getTrack 4 Apr 19 20:49:12 volumio volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":230,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"132201.flac","artist":null,"album":null,"uri":"http://192.168.0.6:50002/m/NDLNA/132201.flac","trackType":"flac"} Apr 19 20:49:12 volumio volumio[979]: verbose: CURRENT POSITION 4 Apr 19 20:49:12 volumio volumio[979]: info: CoreStateMachine::syncState stateService play Apr 19 20:49:12 volumio volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 19 20:49:12 volumio volumio[979]: info: Received an update from plugin. extracting info from payload Apr 19 20:49:12 volumio volumio[979]: info: CoreStateMachine::pushState Apr 19 20:49:12 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 19 20:49:12 volumio volumio[979]: info: CoreCommandRouter::volumioPushState Apr 19 20:49:12 volumio volumio[979]: info: CoreStateMachine::pushState Apr 19 20:49:12 volumio volumio[979]: info: CoreCommandRouter::volumioPushState Apr 19 20:49:12 volumio volumio[979]: info: ------------------------------ 19ms Apr 19 20:49:12 volumio volumio[979]: info: Apr 19 20:49:12 volumio volumio[979]: ---------------------------- MPD announces system playlist update Apr 19 20:49:12 volumio volumio[979]: info: Ignoring MPD Status Update Apr 19 20:49:12 volumio volumio[979]: info: Apr 19 20:49:12 volumio volumio[979]: ---------------------------- MPD announces state update: player Apr 19 20:49:12 volumio volumio[979]: info: ControllerMpd::getState Apr 19 20:49:12 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 19 20:49:12 volumio volumio[979]: info: ------------------------------ 3ms Apr 19 20:49:12 volumio volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 19 20:49:12 volumio volumio[979]: verbose: ControllerMpd::parseState Apr 19 20:49:12 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 19 20:49:12 volumio volumio[979]: info: sendMpdCommand playlistinfo took 0 milliseconds Apr 19 20:49:12 volumio volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 19 20:49:12 volumio volumio[979]: info: ControllerMpd::pushState Apr 19 20:49:12 volumio volumio[979]: info: CoreCommandRouter::servicePushState Apr 19 20:49:12 volumio volumio[979]: info: CorePlayQueue::getTrack 4 Apr 19 20:49:12 volumio volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":850,"duration":230,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"874 Kbps","isStreaming":false,"title":"Let Her Down Easy","artist":"George Michael","album":"Symphonica","uri":"http://192.168.0.6:50002/m/NDLNA/132201.flac","trackType":"flac"} Apr 19 20:49:12 volumio volumio[979]: verbose: CURRENT POSITION 4 Apr 19 20:49:12 volumio volumio[979]: info: CoreStateMachine::syncState stateService play Apr 19 20:49:12 volumio volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 19 20:49:12 volumio volumio[979]: info: Received an update from plugin. extracting info from payload Apr 19 20:49:12 volumio volumio[979]: info: CoreStateMachine::pushState Apr 19 20:49:12 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 19 20:49:12 volumio volumio[979]: info: CoreCommandRouter::volumioPushState Apr 19 20:49:12 volumio volumio[979]: info: CoreStateMachine::pushState Apr 19 20:49:12 volumio volumio[979]: info: CoreCommandRouter::volumioPushState Apr 19 20:49:12 volumio volumio[979]: info: ------------------------------ 17ms Apr 19 20:49:12 volumio volumio[979]: info: CoreCommandRouter::volumioGetQueue Apr 19 20:49:12 volumio volumio[979]: info: CoreStateMachine::getQueue Apr 19 20:49:12 volumio volumio[979]: info: CorePlayQueue::getQueue Apr 19 20:49:12 volumio volumio[979]: info: CoreCommandRouter::volumioGetQueue Apr 19 20:49:12 volumio volumio[979]: info: CoreStateMachine::getQueue Apr 19 20:49:12 volumio volumio[979]: info: CorePlayQueue::getQueue Apr 19 20:49:20 volumio volumio[979]: info: CoreCommandRouter::volumioGetQueue Apr 19 20:49:20 volumio volumio[979]: info: CoreStateMachine::getQueue Apr 19 20:49:20 volumio volumio[979]: info: CorePlayQueue::getQueue Apr 19 20:49:33 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Apr 19 20:49:33 volumio volumio[979]: info: Preload queue cleared Apr 19 20:49:33 volumio volumio[979]: info: Preloading song: upnp/http://192.168.0.6:50001/ContentDirectory/control@22$@138482 Apr 19 20:49:33 volumio volumio[979]: info: Preloading song: upnp/http://192.168.0.6:50001/ContentDirectory/control@22$@138441 Apr 19 20:49:33 volumio volumio[979]: info: Preloading song: upnp/http://192.168.0.6:50001/ContentDirectory/control@22$@138782 Apr 19 20:49:33 volumio volumio[979]: info: Exploding uri upnp/http://192.168.0.6:50001/ContentDirectory/control@22$@138482 in service upnp_browser Apr 19 20:49:33 volumio volumio[979]: info: Exploding uri upnp/http://192.168.0.6:50001/ContentDirectory/control@22$@138441 in service upnp_browser Apr 19 20:49:33 volumio volumio[979]: info: Exploding uri upnp/http://192.168.0.6:50001/ContentDirectory/control@22$@138782 in service upnp_browser Apr 19 20:49:41 volumio volumio[979]: info: Preload queue cleared Apr 19 20:49:41 volumio volumio[979]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 19 20:49:41 volumio volumio[979]: info: CoreStateMachine::ClearQueue Apr 19 20:49:41 volumio volumio[979]: info: CoreStateMachine::stop Apr 19 20:49:41 volumio volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 19 20:49:41 volumio volumio[979]: info: CoreStateMachine::stPlaybackTimer Apr 19 20:49:41 volumio volumio[979]: info: CoreStateMachine::updateTrackBlock Apr 19 20:49:41 volumio volumio[979]: info: CorePlayQueue::getTrackBlock Apr 19 20:49:41 volumio volumio[979]: info: CoreStateMachine::pushState Apr 19 20:49:41 volumio volumio[979]: info: CorePlayQueue::getTrack 4 Apr 19 20:49:41 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 19 20:49:41 volumio volumio[979]: info: CoreCommandRouter::volumioPushState Apr 19 20:49:41 volumio volumio[979]: info: CoreStateMachine::serviceStop Apr 19 20:49:41 volumio volumio[979]: info: CorePlayQueue::getTrack 4 Apr 19 20:49:41 volumio volumio[979]: info: CoreCommandRouter::serviceStop Apr 19 20:49:41 volumio volumio[979]: info: [1745088581907] ControllerUPNPBrowser::stop Apr 19 20:49:41 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand stop Apr 19 20:49:41 volumio volumio[979]: info: CorePlayQueue::clearPlayQueue Apr 19 20:49:41 volumio volumio[979]: info: CorePlayQueue::saveQueue Apr 19 20:49:41 volumio volumio[979]: info: CoreCommandRouter::volumioPushQueue Apr 19 20:49:41 volumio volumio[979]: info: CoreStateMachine::addQueueItems Apr 19 20:49:41 volumio volumio[979]: info: CorePlayQueue::addQueueItems Apr 19 20:49:41 volumio volumio[979]: info: Preload queue cleared Apr 19 20:49:41 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23211 Apr 19 20:49:41 volumio volumio[979]: info: Exploding uri upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23211 in service upnp_browser Apr 19 20:49:41 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23183 Apr 19 20:49:41 volumio volumio[979]: info: Exploding uri upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23183 in service upnp_browser Apr 19 20:49:41 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23173 Apr 19 20:49:41 volumio volumio[979]: info: Exploding uri upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23173 in service upnp_browser Apr 19 20:49:41 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23182 Apr 19 20:49:41 volumio volumio[979]: info: Exploding uri upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23182 in service upnp_browser Apr 19 20:49:41 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23206 Apr 19 20:49:41 volumio volumio[979]: info: Exploding uri upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23206 in service upnp_browser Apr 19 20:49:41 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23175 Apr 19 20:49:41 volumio volumio[979]: info: Exploding uri upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23175 in service upnp_browser Apr 19 20:49:41 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23180 Apr 19 20:49:41 volumio volumio[979]: info: Exploding uri upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23180 in service upnp_browser Apr 19 20:49:41 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23179 Apr 19 20:49:41 volumio volumio[979]: info: Exploding uri upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23179 in service upnp_browser Apr 19 20:49:41 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23178 Apr 19 20:49:41 volumio volumio[979]: info: Exploding uri upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23178 in service upnp_browser Apr 19 20:49:41 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23198 Apr 19 20:49:41 volumio volumio[979]: info: Exploding uri upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23198 in service upnp_browser Apr 19 20:49:41 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23208 Apr 19 20:49:41 volumio volumio[979]: info: Exploding uri upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23208 in service upnp_browser Apr 19 20:49:41 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23166 Apr 19 20:49:41 volumio volumio[979]: info: Exploding uri upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23166 in service upnp_browser Apr 19 20:49:41 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23164 Apr 19 20:49:41 volumio volumio[979]: info: Exploding uri upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23164 in service upnp_browser Apr 19 20:49:41 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23209 Apr 19 20:49:41 volumio volumio[979]: info: Exploding uri upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23209 in service upnp_browser Apr 19 20:49:41 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23177 Apr 19 20:49:41 volumio volumio[979]: info: Exploding uri upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23177 in service upnp_browser Apr 19 20:49:41 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23172 Apr 19 20:49:41 volumio volumio[979]: info: Exploding uri upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23172 in service upnp_browser Apr 19 20:49:41 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23165 Apr 19 20:49:41 volumio volumio[979]: info: Exploding uri upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23165 in service upnp_browser Apr 19 20:49:41 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23168 Apr 19 20:49:41 volumio volumio[979]: info: Exploding uri upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23168 in service upnp_browser Apr 19 20:49:41 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23210 Apr 19 20:49:41 volumio volumio[979]: info: Exploding uri upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23210 in service upnp_browser Apr 19 20:49:41 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23203 Apr 19 20:49:41 volumio volumio[979]: info: Exploding uri upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23203 in service upnp_browser Apr 19 20:49:41 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23174 Apr 19 20:49:41 volumio volumio[979]: info: Exploding uri upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23174 in service upnp_browser Apr 19 20:49:41 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23201 Apr 19 20:49:41 volumio volumio[979]: info: Exploding uri upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23201 in service upnp_browser Apr 19 20:49:41 volumio volumio[979]: info: Adding Item to queue: upnp/http://192.168.0.6:50001/ContentDirectory/control@22$@138482 Apr 19 20:49:41 volumio volumio[979]: info: Using cached record of: upnp/http://192.168.0.6:50001/ContentDirectory/control@22$@138482 Apr 19 20:49:41 volumio volumio[979]: info: Adding Item to queue: upnp/http://192.168.0.6:50001/ContentDirectory/control@22$@138441 Apr 19 20:49:41 volumio volumio[979]: info: Using cached record of: upnp/http://192.168.0.6:50001/ContentDirectory/control@22$@138441 Apr 19 20:49:41 volumio volumio[979]: info: Apr 19 20:49:41 volumio volumio[979]: ---------------------------- MPD announces state update: player Apr 19 20:49:41 volumio volumio[979]: info: sendMpdCommand stop took 72 milliseconds Apr 19 20:49:41 volumio volumio[979]: info: ControllerMpd::getState Apr 19 20:49:41 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 19 20:49:41 volumio volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 19 20:49:41 volumio volumio[979]: verbose: ControllerMpd::parseState Apr 19 20:49:41 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 19 20:49:41 volumio volumio[979]: info: sendMpdCommand playlistinfo took 0 milliseconds Apr 19 20:49:41 volumio volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 19 20:49:41 volumio volumio[979]: info: ControllerMpd::pushState Apr 19 20:49:41 volumio volumio[979]: info: CoreCommandRouter::servicePushState Apr 19 20:49:41 volumio volumio[979]: info: CoreStateMachine::pushState Apr 19 20:49:41 volumio volumio[979]: info: CorePlayQueue::getTrack 4 Apr 19 20:49:41 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 19 20:49:41 volumio volumio[979]: info: CoreCommandRouter::volumioPushState Apr 19 20:49:41 volumio volumio[979]: info: CorePlayQueue::getTrack 4 Apr 19 20:49:41 volumio volumio[979]: 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":"Let Her Down Easy","artist":"George Michael","album":"Symphonica","uri":"http://192.168.0.6:50002/m/NDLNA/132201.flac","trackType":"flac"} Apr 19 20:49:41 volumio volumio[979]: verbose: CURRENT POSITION 4 Apr 19 20:49:41 volumio volumio[979]: info: CoreStateMachine::syncState stateService stop Apr 19 20:49:41 volumio volumio[979]: info: CoreStateMachine::syncState currentStatus stop Apr 19 20:49:41 volumio volumio[979]: info: CoreStateMachine::pushState Apr 19 20:49:41 volumio volumio[979]: info: CorePlayQueue::getTrack 4 Apr 19 20:49:41 volumio volumio[979]: info: CoreCommandRouter::volumioPushState Apr 19 20:49:41 volumio volumio[979]: info: No code Apr 19 20:49:41 volumio volumio[979]: info: CoreStateMachine::pushState Apr 19 20:49:41 volumio volumio[979]: info: CorePlayQueue::getTrack 4 Apr 19 20:49:41 volumio volumio[979]: info: CoreCommandRouter::volumioPushState Apr 19 20:49:41 volumio volumio[979]: info: ------------------------------ 18ms Apr 19 20:49:42 volumio volumio[979]: info: CoreCommandRouter::volumioPushQueue Apr 19 20:49:42 volumio volumio[979]: info: CorePlayQueue::saveQueue Apr 19 20:49:42 volumio volumio[979]: info: CoreStateMachine::updateTrackBlock Apr 19 20:49:42 volumio volumio[979]: info: CorePlayQueue::getTrackBlock Apr 19 20:49:42 volumio volumio[979]: info: CoreCommandRouter::volumioPlay Apr 19 20:49:42 volumio volumio[979]: info: CoreStateMachine::play index 23 Apr 19 20:49:42 volumio volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 19 20:49:42 volumio volumio[979]: info: CoreStateMachine::addQueueItems Apr 19 20:49:42 volumio volumio[979]: info: CorePlayQueue::addQueueItems Apr 19 20:49:42 volumio volumio[979]: info: Preload queue cleared Apr 19 20:49:42 volumio volumio[979]: info: Adding Item to queue: upnp/http://192.168.0.6:50001/ContentDirectory/control@22$@138782 Apr 19 20:49:42 volumio volumio[979]: info: Using cached record of: upnp/http://192.168.0.6:50001/ContentDirectory/control@22$@138782 Apr 19 20:49:42 volumio volumio[979]: info: CoreStateMachine::stop Apr 19 20:49:42 volumio volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 19 20:49:42 volumio volumio[979]: info: CoreCommandRouter::volumioPushQueue Apr 19 20:49:42 volumio volumio[979]: info: CorePlayQueue::saveQueue Apr 19 20:49:42 volumio volumio[979]: info: CoreStateMachine::play index undefined Apr 19 20:49:42 volumio volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 19 20:49:42 volumio volumio[979]: info: CoreStateMachine::updateTrackBlock Apr 19 20:49:42 volumio volumio[979]: info: CorePlayQueue::getTrackBlock Apr 19 20:49:42 volumio volumio[979]: info: CorePlayQueue::getTrack 23 Apr 19 20:49:42 volumio volumio[979]: info: CoreStateMachine::startPlaybackTimer Apr 19 20:49:42 volumio volumio[979]: info: CorePlayQueue::getTrack 23 Apr 19 20:49:42 volumio volumio[979]: info: [1745088582144] ControllerUPNPBrowser::clearAddPlayTrack Apr 19 20:49:42 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand stop Apr 19 20:49:42 volumio volumio[979]: info: sendMpdCommand stop took 11 milliseconds Apr 19 20:49:42 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand clear Apr 19 20:49:42 volumio volumio[979]: info: Apr 19 20:49:42 volumio volumio[979]: ---------------------------- MPD announces system playlist update Apr 19 20:49:42 volumio volumio[979]: info: Ignoring MPD Status Update Apr 19 20:49:42 volumio volumio[979]: info: sendMpdCommand clear took 2 milliseconds Apr 19 20:49:42 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.0.6:50002/m/NDLNA/138479.dff" Apr 19 20:49:42 volumio volumio[979]: error: updateQueue error: null Apr 19 20:49:42 volumio volumio[979]: info: ------------------------------ 2ms Apr 19 20:49:42 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.0.6:50002/m/NDLNA/138479.dff" Apr 19 20:49:42 volumio volumio[979]: info: Apr 19 20:49:42 volumio volumio[979]: ---------------------------- MPD announces system playlist update Apr 19 20:49:42 volumio volumio[979]: info: Ignoring MPD Status Update Apr 19 20:49:42 volumio volumio[979]: info: sendMpdCommand add "http://192.168.0.6:50002/m/NDLNA/138479.dff" took 2 milliseconds Apr 19 20:49:42 volumio volumio[979]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 19 20:49:42 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand play Apr 19 20:49:42 volumio volumio[979]: info: ------------------------------ 3ms Apr 19 20:49:42 volumio volumio[979]: info: sendMpdCommand play took 1 milliseconds Apr 19 20:49:42 volumio volumio[979]: info: Apr 19 20:49:42 volumio volumio[979]: ---------------------------- MPD announces state update: player Apr 19 20:49:42 volumio volumio[979]: info: ControllerMpd::getState Apr 19 20:49:42 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 19 20:49:42 volumio volumio[979]: info: Apr 19 20:49:42 volumio volumio[979]: ---------------------------- MPD announces state update: player Apr 19 20:49:42 volumio volumio[979]: info: sendMpdCommand status took 38 milliseconds Apr 19 20:49:42 volumio volumio[979]: info: ControllerMpd::getState Apr 19 20:49:42 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 19 20:49:42 volumio volumio[979]: verbose: ControllerMpd::parseState Apr 19 20:49:42 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 19 20:49:42 volumio volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 19 20:49:42 volumio volumio[979]: verbose: ControllerMpd::parseState Apr 19 20:49:42 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 19 20:49:42 volumio volumio[979]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 19 20:49:42 volumio volumio[979]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 19 20:49:42 volumio volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 19 20:49:42 volumio volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 19 20:49:42 volumio volumio[979]: info: ControllerMpd::pushState Apr 19 20:49:42 volumio volumio[979]: info: CoreCommandRouter::servicePushState Apr 19 20:49:42 volumio volumio[979]: info: CorePlayQueue::getTrack 23 Apr 19 20:49:42 volumio volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":244,"samplerate":"5.64 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"138479.dff","artist":null,"album":null,"uri":"http://192.168.0.6:50002/m/NDLNA/138479.dff","trackType":"dff"} Apr 19 20:49:42 volumio volumio[979]: verbose: CURRENT POSITION 23 Apr 19 20:49:42 volumio volumio[979]: info: CoreStateMachine::syncState stateService play Apr 19 20:49:42 volumio volumio[979]: info: CoreStateMachine::syncState currentStatus stop Apr 19 20:49:42 volumio volumio[979]: info: ControllerMpd::pushState Apr 19 20:49:42 volumio volumio[979]: info: CoreCommandRouter::servicePushState Apr 19 20:49:42 volumio volumio[979]: info: CorePlayQueue::getTrack 23 Apr 19 20:49:42 volumio volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":244,"samplerate":"5.64 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"138479.dff","artist":null,"album":null,"uri":"http://192.168.0.6:50002/m/NDLNA/138479.dff","trackType":"dff"} Apr 19 20:49:42 volumio volumio[979]: verbose: CURRENT POSITION 23 Apr 19 20:49:42 volumio volumio[979]: info: CoreStateMachine::syncState stateService play Apr 19 20:49:42 volumio volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 19 20:49:42 volumio volumio[979]: info: Received an update from plugin. extracting info from payload Apr 19 20:49:42 volumio volumio[979]: info: CoreStateMachine::pushState Apr 19 20:49:42 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 19 20:49:42 volumio volumio[979]: info: CoreCommandRouter::volumioPushState Apr 19 20:49:42 volumio volumio[979]: info: CoreStateMachine::pushState Apr 19 20:49:42 volumio volumio[979]: info: CoreCommandRouter::volumioPushState Apr 19 20:49:42 volumio volumio[979]: info: ------------------------------ 50ms Apr 19 20:49:42 volumio volumio[979]: info: ------------------------------ 21ms Apr 19 20:49:48 volumio volumio[979]: info: Preload queue cleared Apr 19 20:49:48 volumio volumio[979]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 19 20:49:48 volumio volumio[979]: info: CoreStateMachine::ClearQueue Apr 19 20:49:48 volumio volumio[979]: info: CoreStateMachine::stop Apr 19 20:49:48 volumio volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 19 20:49:48 volumio volumio[979]: info: CoreStateMachine::stPlaybackTimer Apr 19 20:49:48 volumio volumio[979]: info: CoreStateMachine::updateTrackBlock Apr 19 20:49:48 volumio volumio[979]: info: CorePlayQueue::getTrackBlock Apr 19 20:49:48 volumio volumio[979]: info: CoreStateMachine::pushState Apr 19 20:49:48 volumio volumio[979]: info: CorePlayQueue::getTrack 23 Apr 19 20:49:48 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 19 20:49:48 volumio volumio[979]: info: CoreCommandRouter::volumioPushState Apr 19 20:49:48 volumio volumio[979]: info: CoreStateMachine::serviceStop Apr 19 20:49:48 volumio volumio[979]: info: CorePlayQueue::getTrack 23 Apr 19 20:49:48 volumio volumio[979]: info: CoreCommandRouter::serviceStop Apr 19 20:49:48 volumio volumio[979]: info: [1745088588881] ControllerUPNPBrowser::stop Apr 19 20:49:48 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand stop Apr 19 20:49:48 volumio volumio[979]: info: CorePlayQueue::clearPlayQueue Apr 19 20:49:48 volumio volumio[979]: info: CorePlayQueue::saveQueue Apr 19 20:49:48 volumio volumio[979]: info: CoreCommandRouter::volumioPushQueue Apr 19 20:49:48 volumio volumio[979]: info: CoreStateMachine::addQueueItems Apr 19 20:49:48 volumio volumio[979]: info: CorePlayQueue::addQueueItems Apr 19 20:49:48 volumio volumio[979]: info: Preload queue cleared Apr 19 20:49:48 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23211 Apr 19 20:49:48 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23211 Apr 19 20:49:48 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23183 Apr 19 20:49:48 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23183 Apr 19 20:49:48 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23173 Apr 19 20:49:48 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23173 Apr 19 20:49:48 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23182 Apr 19 20:49:48 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23182 Apr 19 20:49:48 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23206 Apr 19 20:49:48 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23206 Apr 19 20:49:48 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23175 Apr 19 20:49:48 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23175 Apr 19 20:49:48 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23180 Apr 19 20:49:48 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23180 Apr 19 20:49:48 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23179 Apr 19 20:49:48 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23179 Apr 19 20:49:48 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23178 Apr 19 20:49:48 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23178 Apr 19 20:49:48 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23198 Apr 19 20:49:48 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23198 Apr 19 20:49:48 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23208 Apr 19 20:49:48 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23208 Apr 19 20:49:48 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23166 Apr 19 20:49:48 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23166 Apr 19 20:49:48 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23164 Apr 19 20:49:48 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23164 Apr 19 20:49:48 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23209 Apr 19 20:49:48 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23209 Apr 19 20:49:48 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23177 Apr 19 20:49:48 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23177 Apr 19 20:49:48 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23172 Apr 19 20:49:48 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23172 Apr 19 20:49:48 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23165 Apr 19 20:49:48 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23165 Apr 19 20:49:48 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23168 Apr 19 20:49:48 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23168 Apr 19 20:49:48 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23210 Apr 19 20:49:48 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23210 Apr 19 20:49:48 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23203 Apr 19 20:49:48 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23203 Apr 19 20:49:48 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23174 Apr 19 20:49:48 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23174 Apr 19 20:49:48 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23201 Apr 19 20:49:48 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23201 Apr 19 20:49:48 volumio volumio[979]: info: Adding Item to queue: upnp/http://192.168.0.6:50001/ContentDirectory/control@22$@138482 Apr 19 20:49:48 volumio volumio[979]: info: Using cached record of: upnp/http://192.168.0.6:50001/ContentDirectory/control@22$@138482 Apr 19 20:49:48 volumio volumio[979]: info: Adding Item to queue: upnp/http://192.168.0.6:50001/ContentDirectory/control@22$@138441 Apr 19 20:49:48 volumio volumio[979]: info: Using cached record of: upnp/http://192.168.0.6:50001/ContentDirectory/control@22$@138441 Apr 19 20:49:48 volumio volumio[979]: info: Adding Item to queue: upnp/http://192.168.0.6:50001/ContentDirectory/control@22$@138782 Apr 19 20:49:48 volumio volumio[979]: info: Using cached record of: upnp/http://192.168.0.6:50001/ContentDirectory/control@22$@138782 Apr 19 20:49:48 volumio volumio[979]: info: CoreCommandRouter::volumioPushQueue Apr 19 20:49:48 volumio volumio[979]: info: CorePlayQueue::saveQueue Apr 19 20:49:48 volumio volumio[979]: info: CoreStateMachine::updateTrackBlock Apr 19 20:49:48 volumio volumio[979]: info: CorePlayQueue::getTrackBlock Apr 19 20:49:48 volumio volumio[979]: info: CoreCommandRouter::volumioPlay Apr 19 20:49:48 volumio volumio[979]: info: CoreStateMachine::play index 24 Apr 19 20:49:48 volumio volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 19 20:49:48 volumio volumio[979]: info: CoreStateMachine::stop Apr 19 20:49:48 volumio volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 19 20:49:48 volumio volumio[979]: info: CoreStateMachine::play index undefined Apr 19 20:49:48 volumio volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 19 20:49:48 volumio volumio[979]: info: CorePlayQueue::getTrack 24 Apr 19 20:49:48 volumio volumio[979]: info: CoreStateMachine::startPlaybackTimer Apr 19 20:49:48 volumio volumio[979]: info: CorePlayQueue::getTrack 24 Apr 19 20:49:48 volumio volumio[979]: info: [1745088588912] ControllerUPNPBrowser::clearAddPlayTrack Apr 19 20:49:48 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand stop Apr 19 20:49:48 volumio volumio[979]: info: sendMpdCommand stop took 57 milliseconds Apr 19 20:49:48 volumio volumio[979]: info: Apr 19 20:49:48 volumio volumio[979]: ---------------------------- MPD announces state update: player Apr 19 20:49:48 volumio volumio[979]: info: ControllerMpd::getState Apr 19 20:49:48 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 19 20:49:48 volumio volumio[979]: info: sendMpdCommand stop took 27 milliseconds Apr 19 20:49:48 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand clear Apr 19 20:49:48 volumio volumio[979]: info: Apr 19 20:49:48 volumio volumio[979]: ---------------------------- MPD announces system playlist update Apr 19 20:49:48 volumio volumio[979]: info: Ignoring MPD Status Update Apr 19 20:49:48 volumio volumio[979]: info: sendMpdCommand status took 2 milliseconds Apr 19 20:49:48 volumio volumio[979]: info: sendMpdCommand clear took 1 milliseconds Apr 19 20:49:48 volumio volumio[979]: verbose: ControllerMpd::parseState Apr 19 20:49:48 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 19 20:49:48 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.0.6:50002/m/NDLNA/138477.dff" Apr 19 20:49:48 volumio volumio[979]: error: updateQueue error: null Apr 19 20:49:48 volumio volumio[979]: info: ------------------------------ 2ms Apr 19 20:49:48 volumio volumio[979]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 19 20:49:48 volumio volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 19 20:49:48 volumio volumio[979]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 19 20:49:48 volumio volumio[979]: info: ------------------------------ 5ms Apr 19 20:49:48 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.0.6:50002/m/NDLNA/138477.dff" Apr 19 20:49:48 volumio volumio[979]: info: Apr 19 20:49:48 volumio volumio[979]: ---------------------------- MPD announces system playlist update Apr 19 20:49:48 volumio volumio[979]: info: Ignoring MPD Status Update Apr 19 20:49:48 volumio volumio[979]: info: sendMpdCommand add "http://192.168.0.6:50002/m/NDLNA/138477.dff" took 1 milliseconds Apr 19 20:49:48 volumio volumio[979]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 19 20:49:48 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand play Apr 19 20:49:48 volumio volumio[979]: info: ------------------------------ 1ms Apr 19 20:49:48 volumio volumio[979]: info: sendMpdCommand play took 1 milliseconds Apr 19 20:49:49 volumio volumio[979]: info: Apr 19 20:49:49 volumio volumio[979]: ---------------------------- MPD announces state update: player Apr 19 20:49:49 volumio volumio[979]: info: ControllerMpd::getState Apr 19 20:49:49 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 19 20:49:49 volumio volumio[979]: info: Apr 19 20:49:49 volumio volumio[979]: ---------------------------- MPD announces state update: player Apr 19 20:49:49 volumio volumio[979]: info: sendMpdCommand status took 6 milliseconds Apr 19 20:49:49 volumio volumio[979]: info: ControllerMpd::getState Apr 19 20:49:49 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 19 20:49:49 volumio volumio[979]: verbose: ControllerMpd::parseState Apr 19 20:49:49 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 19 20:49:49 volumio volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 19 20:49:49 volumio volumio[979]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 19 20:49:49 volumio volumio[979]: verbose: ControllerMpd::parseState Apr 19 20:49:49 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 19 20:49:49 volumio volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 19 20:49:49 volumio volumio[979]: info: ControllerMpd::pushState Apr 19 20:49:49 volumio volumio[979]: info: CoreCommandRouter::servicePushState Apr 19 20:49:49 volumio volumio[979]: info: CorePlayQueue::getTrack 24 Apr 19 20:49:49 volumio volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":317,"samplerate":"5.64 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"138477.dff","artist":null,"album":null,"uri":"http://192.168.0.6:50002/m/NDLNA/138477.dff","trackType":"dff"} Apr 19 20:49:49 volumio volumio[979]: verbose: CURRENT POSITION 24 Apr 19 20:49:49 volumio volumio[979]: info: CoreStateMachine::syncState stateService play Apr 19 20:49:49 volumio volumio[979]: info: CoreStateMachine::syncState currentStatus stop Apr 19 20:49:49 volumio volumio[979]: info: ------------------------------ 11ms Apr 19 20:49:49 volumio volumio[979]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 19 20:49:49 volumio volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 19 20:49:49 volumio volumio[979]: info: ControllerMpd::pushState Apr 19 20:49:49 volumio volumio[979]: info: CoreCommandRouter::servicePushState Apr 19 20:49:49 volumio volumio[979]: info: CorePlayQueue::getTrack 24 Apr 19 20:49:49 volumio volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":317,"samplerate":"5.64 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"138477.dff","artist":null,"album":null,"uri":"http://192.168.0.6:50002/m/NDLNA/138477.dff","trackType":"dff"} Apr 19 20:49:49 volumio volumio[979]: verbose: CURRENT POSITION 24 Apr 19 20:49:49 volumio volumio[979]: info: CoreStateMachine::syncState stateService play Apr 19 20:49:49 volumio volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 19 20:49:49 volumio volumio[979]: info: Received an update from plugin. extracting info from payload Apr 19 20:49:49 volumio volumio[979]: info: CoreStateMachine::pushState Apr 19 20:49:49 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 19 20:49:49 volumio volumio[979]: info: CoreCommandRouter::volumioPushState Apr 19 20:49:49 volumio volumio[979]: info: CoreStateMachine::pushState Apr 19 20:49:49 volumio volumio[979]: info: CoreCommandRouter::volumioPushState Apr 19 20:49:49 volumio volumio[979]: info: ------------------------------ 16ms Apr 19 20:49:52 volumio volumio[979]: info: Preload queue cleared Apr 19 20:49:52 volumio volumio[979]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 19 20:49:52 volumio volumio[979]: info: CoreStateMachine::ClearQueue Apr 19 20:49:52 volumio volumio[979]: info: CoreStateMachine::stop Apr 19 20:49:52 volumio volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 19 20:49:52 volumio volumio[979]: info: CoreStateMachine::stPlaybackTimer Apr 19 20:49:52 volumio volumio[979]: info: CoreStateMachine::updateTrackBlock Apr 19 20:49:52 volumio volumio[979]: info: CorePlayQueue::getTrackBlock Apr 19 20:49:52 volumio volumio[979]: info: CoreStateMachine::pushState Apr 19 20:49:52 volumio volumio[979]: info: CorePlayQueue::getTrack 24 Apr 19 20:49:52 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 19 20:49:52 volumio volumio[979]: info: CoreCommandRouter::volumioPushState Apr 19 20:49:52 volumio volumio[979]: info: CoreStateMachine::serviceStop Apr 19 20:49:52 volumio volumio[979]: info: CorePlayQueue::getTrack 24 Apr 19 20:49:52 volumio volumio[979]: info: CoreCommandRouter::serviceStop Apr 19 20:49:52 volumio volumio[979]: info: [1745088592537] ControllerUPNPBrowser::stop Apr 19 20:49:52 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand stop Apr 19 20:49:52 volumio volumio[979]: info: CorePlayQueue::clearPlayQueue Apr 19 20:49:52 volumio volumio[979]: info: CorePlayQueue::saveQueue Apr 19 20:49:52 volumio volumio[979]: info: CoreCommandRouter::volumioPushQueue Apr 19 20:49:52 volumio volumio[979]: info: CoreStateMachine::addQueueItems Apr 19 20:49:52 volumio volumio[979]: info: CorePlayQueue::addQueueItems Apr 19 20:49:52 volumio volumio[979]: info: Preload queue cleared Apr 19 20:49:52 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23211 Apr 19 20:49:52 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23211 Apr 19 20:49:52 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23183 Apr 19 20:49:52 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23183 Apr 19 20:49:52 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23173 Apr 19 20:49:52 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23173 Apr 19 20:49:52 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23182 Apr 19 20:49:52 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23182 Apr 19 20:49:52 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23206 Apr 19 20:49:52 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23206 Apr 19 20:49:52 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23175 Apr 19 20:49:52 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23175 Apr 19 20:49:52 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23180 Apr 19 20:49:52 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23180 Apr 19 20:49:52 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23179 Apr 19 20:49:52 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23179 Apr 19 20:49:52 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23178 Apr 19 20:49:52 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23178 Apr 19 20:49:52 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23198 Apr 19 20:49:52 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23198 Apr 19 20:49:52 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23208 Apr 19 20:49:52 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23208 Apr 19 20:49:52 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23166 Apr 19 20:49:52 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23166 Apr 19 20:49:52 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23164 Apr 19 20:49:52 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23164 Apr 19 20:49:52 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23209 Apr 19 20:49:52 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23209 Apr 19 20:49:52 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23177 Apr 19 20:49:52 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23177 Apr 19 20:49:52 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23172 Apr 19 20:49:52 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23172 Apr 19 20:49:52 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23165 Apr 19 20:49:52 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23165 Apr 19 20:49:52 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23168 Apr 19 20:49:52 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23168 Apr 19 20:49:52 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23210 Apr 19 20:49:52 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23210 Apr 19 20:49:52 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23203 Apr 19 20:49:52 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23203 Apr 19 20:49:52 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23174 Apr 19 20:49:52 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23174 Apr 19 20:49:52 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23201 Apr 19 20:49:52 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23201 Apr 19 20:49:52 volumio volumio[979]: info: Adding Item to queue: upnp/http://192.168.0.6:50001/ContentDirectory/control@22$@138482 Apr 19 20:49:52 volumio volumio[979]: info: Using cached record of: upnp/http://192.168.0.6:50001/ContentDirectory/control@22$@138482 Apr 19 20:49:52 volumio volumio[979]: info: Adding Item to queue: upnp/http://192.168.0.6:50001/ContentDirectory/control@22$@138441 Apr 19 20:49:52 volumio volumio[979]: info: Using cached record of: upnp/http://192.168.0.6:50001/ContentDirectory/control@22$@138441 Apr 19 20:49:52 volumio volumio[979]: info: CoreCommandRouter::volumioPushQueue Apr 19 20:49:52 volumio volumio[979]: info: CorePlayQueue::saveQueue Apr 19 20:49:52 volumio volumio[979]: info: CoreStateMachine::updateTrackBlock Apr 19 20:49:52 volumio volumio[979]: info: CorePlayQueue::getTrackBlock Apr 19 20:49:52 volumio volumio[979]: info: CoreCommandRouter::volumioPlay Apr 19 20:49:52 volumio volumio[979]: info: CoreStateMachine::play index 23 Apr 19 20:49:52 volumio volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 19 20:49:52 volumio volumio[979]: info: CoreStateMachine::addQueueItems Apr 19 20:49:52 volumio volumio[979]: info: CorePlayQueue::addQueueItems Apr 19 20:49:52 volumio volumio[979]: info: Preload queue cleared Apr 19 20:49:52 volumio volumio[979]: info: Adding Item to queue: upnp/http://192.168.0.6:50001/ContentDirectory/control@22$@138782 Apr 19 20:49:52 volumio volumio[979]: info: Using cached record of: upnp/http://192.168.0.6:50001/ContentDirectory/control@22$@138782 Apr 19 20:49:52 volumio volumio[979]: info: CoreStateMachine::stop Apr 19 20:49:52 volumio volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 19 20:49:52 volumio volumio[979]: info: CoreCommandRouter::volumioPushQueue Apr 19 20:49:52 volumio volumio[979]: info: CorePlayQueue::saveQueue Apr 19 20:49:52 volumio volumio[979]: info: CoreStateMachine::play index undefined Apr 19 20:49:52 volumio volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 19 20:49:52 volumio volumio[979]: info: CoreStateMachine::updateTrackBlock Apr 19 20:49:52 volumio volumio[979]: info: CorePlayQueue::getTrackBlock Apr 19 20:49:52 volumio volumio[979]: info: CorePlayQueue::getTrack 23 Apr 19 20:49:52 volumio volumio[979]: info: CoreStateMachine::startPlaybackTimer Apr 19 20:49:52 volumio volumio[979]: info: CorePlayQueue::getTrack 23 Apr 19 20:49:52 volumio volumio[979]: info: [1745088592568] ControllerUPNPBrowser::clearAddPlayTrack Apr 19 20:49:52 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand stop Apr 19 20:49:52 volumio volumio[979]: info: Apr 19 20:49:52 volumio volumio[979]: ---------------------------- MPD announces state update: player Apr 19 20:49:52 volumio volumio[979]: info: sendMpdCommand stop took 39 milliseconds Apr 19 20:49:52 volumio volumio[979]: info: ControllerMpd::getState Apr 19 20:49:52 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 19 20:49:52 volumio volumio[979]: info: sendMpdCommand stop took 8 milliseconds Apr 19 20:49:52 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand clear Apr 19 20:49:52 volumio volumio[979]: info: Apr 19 20:49:52 volumio volumio[979]: ---------------------------- MPD announces system playlist update Apr 19 20:49:52 volumio volumio[979]: info: Ignoring MPD Status Update Apr 19 20:49:52 volumio volumio[979]: info: sendMpdCommand status took 2 milliseconds Apr 19 20:49:52 volumio volumio[979]: info: sendMpdCommand clear took 1 milliseconds Apr 19 20:49:52 volumio volumio[979]: verbose: ControllerMpd::parseState Apr 19 20:49:52 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 19 20:49:52 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.0.6:50002/m/NDLNA/138479.dff" Apr 19 20:49:52 volumio volumio[979]: error: updateQueue error: null Apr 19 20:49:52 volumio volumio[979]: info: ------------------------------ 3ms Apr 19 20:49:52 volumio volumio[979]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 19 20:49:52 volumio volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 19 20:49:52 volumio volumio[979]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 19 20:49:52 volumio volumio[979]: info: ------------------------------ 6ms Apr 19 20:49:52 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.0.6:50002/m/NDLNA/138479.dff" Apr 19 20:49:52 volumio volumio[979]: info: Apr 19 20:49:52 volumio volumio[979]: ---------------------------- MPD announces system playlist update Apr 19 20:49:52 volumio volumio[979]: info: Ignoring MPD Status Update Apr 19 20:49:52 volumio volumio[979]: info: sendMpdCommand add "http://192.168.0.6:50002/m/NDLNA/138479.dff" took 1 milliseconds Apr 19 20:49:52 volumio volumio[979]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 19 20:49:52 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand play Apr 19 20:49:52 volumio volumio[979]: info: ------------------------------ 2ms Apr 19 20:49:52 volumio volumio[979]: info: sendMpdCommand play took 1 milliseconds Apr 19 20:49:52 volumio volumio[979]: info: Apr 19 20:49:52 volumio volumio[979]: ---------------------------- MPD announces state update: player Apr 19 20:49:52 volumio volumio[979]: info: ControllerMpd::getState Apr 19 20:49:52 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 19 20:49:52 volumio volumio[979]: info: Apr 19 20:49:52 volumio volumio[979]: ---------------------------- MPD announces state update: player Apr 19 20:49:52 volumio volumio[979]: info: sendMpdCommand status took 5 milliseconds Apr 19 20:49:52 volumio volumio[979]: info: ControllerMpd::getState Apr 19 20:49:52 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 19 20:49:52 volumio volumio[979]: verbose: ControllerMpd::parseState Apr 19 20:49:52 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 19 20:49:52 volumio volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 19 20:49:52 volumio volumio[979]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 19 20:49:52 volumio volumio[979]: verbose: ControllerMpd::parseState Apr 19 20:49:52 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 19 20:49:52 volumio volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 19 20:49:52 volumio volumio[979]: info: ControllerMpd::pushState Apr 19 20:49:52 volumio volumio[979]: info: CoreCommandRouter::servicePushState Apr 19 20:49:52 volumio volumio[979]: info: CorePlayQueue::getTrack 23 Apr 19 20:49:52 volumio volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":244,"samplerate":"5.64 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"138479.dff","artist":null,"album":null,"uri":"http://192.168.0.6:50002/m/NDLNA/138479.dff","trackType":"dff"} Apr 19 20:49:52 volumio volumio[979]: verbose: CURRENT POSITION 23 Apr 19 20:49:52 volumio volumio[979]: info: CoreStateMachine::syncState stateService play Apr 19 20:49:52 volumio volumio[979]: info: CoreStateMachine::syncState currentStatus stop Apr 19 20:49:52 volumio volumio[979]: info: ------------------------------ 9ms Apr 19 20:49:52 volumio volumio[979]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 19 20:49:52 volumio volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 19 20:49:52 volumio volumio[979]: info: ControllerMpd::pushState Apr 19 20:49:52 volumio volumio[979]: info: CoreCommandRouter::servicePushState Apr 19 20:49:52 volumio volumio[979]: info: CorePlayQueue::getTrack 23 Apr 19 20:49:52 volumio volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":244,"samplerate":"5.64 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"138479.dff","artist":null,"album":null,"uri":"http://192.168.0.6:50002/m/NDLNA/138479.dff","trackType":"dff"} Apr 19 20:49:52 volumio volumio[979]: verbose: CURRENT POSITION 23 Apr 19 20:49:52 volumio volumio[979]: info: CoreStateMachine::syncState stateService play Apr 19 20:49:52 volumio volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 19 20:49:52 volumio volumio[979]: info: Received an update from plugin. extracting info from payload Apr 19 20:49:52 volumio volumio[979]: info: CoreStateMachine::pushState Apr 19 20:49:52 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 19 20:49:52 volumio volumio[979]: info: CoreCommandRouter::volumioPushState Apr 19 20:49:52 volumio volumio[979]: info: CoreStateMachine::pushState Apr 19 20:49:52 volumio volumio[979]: info: CoreCommandRouter::volumioPushState Apr 19 20:49:52 volumio volumio[979]: info: ------------------------------ 20ms Apr 19 20:49:59 volumio volumio[979]: info: Preload queue cleared Apr 19 20:49:59 volumio volumio[979]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 19 20:49:59 volumio volumio[979]: info: CoreStateMachine::ClearQueue Apr 19 20:49:59 volumio volumio[979]: info: CoreStateMachine::stop Apr 19 20:49:59 volumio volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 19 20:49:59 volumio volumio[979]: info: CoreStateMachine::stPlaybackTimer Apr 19 20:49:59 volumio volumio[979]: info: CoreStateMachine::updateTrackBlock Apr 19 20:49:59 volumio volumio[979]: info: CorePlayQueue::getTrackBlock Apr 19 20:49:59 volumio volumio[979]: info: CoreStateMachine::pushState Apr 19 20:49:59 volumio volumio[979]: info: CorePlayQueue::getTrack 23 Apr 19 20:49:59 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 19 20:49:59 volumio volumio[979]: info: CoreCommandRouter::volumioPushState Apr 19 20:49:59 volumio volumio[979]: info: CoreStateMachine::serviceStop Apr 19 20:49:59 volumio volumio[979]: info: CorePlayQueue::getTrack 23 Apr 19 20:49:59 volumio volumio[979]: info: CoreCommandRouter::serviceStop Apr 19 20:49:59 volumio volumio[979]: info: [1745088599456] ControllerUPNPBrowser::stop Apr 19 20:49:59 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand stop Apr 19 20:49:59 volumio volumio[979]: info: CorePlayQueue::clearPlayQueue Apr 19 20:49:59 volumio volumio[979]: info: CorePlayQueue::saveQueue Apr 19 20:49:59 volumio volumio[979]: info: CoreCommandRouter::volumioPushQueue Apr 19 20:49:59 volumio volumio[979]: info: CoreStateMachine::addQueueItems Apr 19 20:49:59 volumio volumio[979]: info: CorePlayQueue::addQueueItems Apr 19 20:49:59 volumio volumio[979]: info: Preload queue cleared Apr 19 20:49:59 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23211 Apr 19 20:49:59 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23211 Apr 19 20:49:59 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23183 Apr 19 20:49:59 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23183 Apr 19 20:49:59 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23173 Apr 19 20:49:59 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23173 Apr 19 20:49:59 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23182 Apr 19 20:49:59 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23182 Apr 19 20:49:59 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23206 Apr 19 20:49:59 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23206 Apr 19 20:49:59 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23175 Apr 19 20:49:59 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23175 Apr 19 20:49:59 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23180 Apr 19 20:49:59 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23180 Apr 19 20:49:59 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23179 Apr 19 20:49:59 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23179 Apr 19 20:49:59 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23178 Apr 19 20:49:59 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23178 Apr 19 20:49:59 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23198 Apr 19 20:49:59 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23198 Apr 19 20:49:59 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23208 Apr 19 20:49:59 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23208 Apr 19 20:49:59 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23166 Apr 19 20:49:59 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23166 Apr 19 20:49:59 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23164 Apr 19 20:49:59 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23164 Apr 19 20:49:59 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23209 Apr 19 20:49:59 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23209 Apr 19 20:49:59 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23177 Apr 19 20:49:59 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23177 Apr 19 20:49:59 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23172 Apr 19 20:49:59 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23172 Apr 19 20:49:59 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23165 Apr 19 20:49:59 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23165 Apr 19 20:49:59 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23168 Apr 19 20:49:59 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23168 Apr 19 20:49:59 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23210 Apr 19 20:49:59 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23210 Apr 19 20:49:59 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23203 Apr 19 20:49:59 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23203 Apr 19 20:49:59 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23174 Apr 19 20:49:59 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23174 Apr 19 20:49:59 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23201 Apr 19 20:49:59 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23201 Apr 19 20:49:59 volumio volumio[979]: info: Adding Item to queue: upnp/http://192.168.0.6:50001/ContentDirectory/control@22$@138482 Apr 19 20:49:59 volumio volumio[979]: info: Using cached record of: upnp/http://192.168.0.6:50001/ContentDirectory/control@22$@138482 Apr 19 20:49:59 volumio volumio[979]: info: CoreCommandRouter::volumioPushQueue Apr 19 20:49:59 volumio volumio[979]: info: CorePlayQueue::saveQueue Apr 19 20:49:59 volumio volumio[979]: info: CoreStateMachine::updateTrackBlock Apr 19 20:49:59 volumio volumio[979]: info: CorePlayQueue::getTrackBlock Apr 19 20:49:59 volumio volumio[979]: info: CoreCommandRouter::volumioPlay Apr 19 20:49:59 volumio volumio[979]: info: CoreStateMachine::play index 22 Apr 19 20:49:59 volumio volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 19 20:49:59 volumio volumio[979]: info: CoreStateMachine::addQueueItems Apr 19 20:49:59 volumio volumio[979]: info: CorePlayQueue::addQueueItems Apr 19 20:49:59 volumio volumio[979]: info: Preload queue cleared Apr 19 20:49:59 volumio volumio[979]: info: Adding Item to queue: upnp/http://192.168.0.6:50001/ContentDirectory/control@22$@138441 Apr 19 20:49:59 volumio volumio[979]: info: Using cached record of: upnp/http://192.168.0.6:50001/ContentDirectory/control@22$@138441 Apr 19 20:49:59 volumio volumio[979]: info: Adding Item to queue: upnp/http://192.168.0.6:50001/ContentDirectory/control@22$@138782 Apr 19 20:49:59 volumio volumio[979]: info: Using cached record of: upnp/http://192.168.0.6:50001/ContentDirectory/control@22$@138782 Apr 19 20:49:59 volumio volumio[979]: info: CoreStateMachine::stop Apr 19 20:49:59 volumio volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 19 20:49:59 volumio volumio[979]: info: CoreCommandRouter::volumioPushQueue Apr 19 20:49:59 volumio volumio[979]: info: CorePlayQueue::saveQueue Apr 19 20:49:59 volumio volumio[979]: info: CoreStateMachine::play index undefined Apr 19 20:49:59 volumio volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 19 20:49:59 volumio volumio[979]: info: CoreStateMachine::updateTrackBlock Apr 19 20:49:59 volumio volumio[979]: info: CorePlayQueue::getTrackBlock Apr 19 20:49:59 volumio volumio[979]: info: CorePlayQueue::getTrack 22 Apr 19 20:49:59 volumio volumio[979]: info: CoreStateMachine::startPlaybackTimer Apr 19 20:49:59 volumio volumio[979]: info: CorePlayQueue::getTrack 22 Apr 19 20:49:59 volumio volumio[979]: info: [1745088599486] ControllerUPNPBrowser::clearAddPlayTrack Apr 19 20:49:59 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand stop Apr 19 20:49:59 volumio volumio[979]: info: Apr 19 20:49:59 volumio volumio[979]: ---------------------------- MPD announces state update: player Apr 19 20:49:59 volumio volumio[979]: info: sendMpdCommand stop took 36 milliseconds Apr 19 20:49:59 volumio volumio[979]: info: ControllerMpd::getState Apr 19 20:49:59 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 19 20:49:59 volumio volumio[979]: info: sendMpdCommand stop took 7 milliseconds Apr 19 20:49:59 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand clear Apr 19 20:49:59 volumio volumio[979]: info: Apr 19 20:49:59 volumio volumio[979]: ---------------------------- MPD announces system playlist update Apr 19 20:49:59 volumio volumio[979]: info: Ignoring MPD Status Update Apr 19 20:49:59 volumio volumio[979]: info: sendMpdCommand status took 2 milliseconds Apr 19 20:49:59 volumio volumio[979]: info: sendMpdCommand clear took 1 milliseconds Apr 19 20:49:59 volumio volumio[979]: verbose: ControllerMpd::parseState Apr 19 20:49:59 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 19 20:49:59 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.0.6:50002/m/NDLNA/138476.dff" Apr 19 20:49:59 volumio volumio[979]: error: updateQueue error: null Apr 19 20:49:59 volumio volumio[979]: info: ------------------------------ 2ms Apr 19 20:49:59 volumio volumio[979]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 19 20:49:59 volumio volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 19 20:49:59 volumio volumio[979]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 19 20:49:59 volumio volumio[979]: info: ------------------------------ 4ms Apr 19 20:49:59 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.0.6:50002/m/NDLNA/138476.dff" Apr 19 20:49:59 volumio volumio[979]: info: Apr 19 20:49:59 volumio volumio[979]: ---------------------------- MPD announces system playlist update Apr 19 20:49:59 volumio volumio[979]: info: Ignoring MPD Status Update Apr 19 20:49:59 volumio volumio[979]: info: sendMpdCommand add "http://192.168.0.6:50002/m/NDLNA/138476.dff" took 1 milliseconds Apr 19 20:49:59 volumio volumio[979]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 19 20:49:59 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand play Apr 19 20:49:59 volumio volumio[979]: info: ------------------------------ 1ms Apr 19 20:49:59 volumio volumio[979]: info: sendMpdCommand play took 1 milliseconds Apr 19 20:49:59 volumio volumio[979]: info: Apr 19 20:49:59 volumio volumio[979]: ---------------------------- MPD announces state update: player Apr 19 20:49:59 volumio volumio[979]: info: ControllerMpd::getState Apr 19 20:49:59 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 19 20:49:59 volumio volumio[979]: info: Apr 19 20:49:59 volumio volumio[979]: ---------------------------- MPD announces state update: player Apr 19 20:49:59 volumio volumio[979]: info: sendMpdCommand status took 5 milliseconds Apr 19 20:49:59 volumio volumio[979]: info: ControllerMpd::getState Apr 19 20:49:59 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 19 20:49:59 volumio volumio[979]: verbose: ControllerMpd::parseState Apr 19 20:49:59 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 19 20:49:59 volumio volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 19 20:49:59 volumio volumio[979]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 19 20:49:59 volumio volumio[979]: verbose: ControllerMpd::parseState Apr 19 20:49:59 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 19 20:49:59 volumio volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 19 20:49:59 volumio volumio[979]: info: ControllerMpd::pushState Apr 19 20:49:59 volumio volumio[979]: info: CoreCommandRouter::servicePushState Apr 19 20:49:59 volumio volumio[979]: info: CorePlayQueue::getTrack 22 Apr 19 20:49:59 volumio volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":285,"samplerate":"5.64 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"138476.dff","artist":null,"album":null,"uri":"http://192.168.0.6:50002/m/NDLNA/138476.dff","trackType":"dff"} Apr 19 20:49:59 volumio volumio[979]: verbose: CURRENT POSITION 22 Apr 19 20:49:59 volumio volumio[979]: info: CoreStateMachine::syncState stateService play Apr 19 20:49:59 volumio volumio[979]: info: CoreStateMachine::syncState currentStatus stop Apr 19 20:49:59 volumio volumio[979]: info: ------------------------------ 9ms Apr 19 20:49:59 volumio volumio[979]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 19 20:49:59 volumio volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 19 20:49:59 volumio volumio[979]: info: ControllerMpd::pushState Apr 19 20:49:59 volumio volumio[979]: info: CoreCommandRouter::servicePushState Apr 19 20:49:59 volumio volumio[979]: info: CorePlayQueue::getTrack 22 Apr 19 20:49:59 volumio volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":285,"samplerate":"5.64 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"138476.dff","artist":null,"album":null,"uri":"http://192.168.0.6:50002/m/NDLNA/138476.dff","trackType":"dff"} Apr 19 20:49:59 volumio volumio[979]: verbose: CURRENT POSITION 22 Apr 19 20:49:59 volumio volumio[979]: info: CoreStateMachine::syncState stateService play Apr 19 20:49:59 volumio volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 19 20:49:59 volumio volumio[979]: info: Received an update from plugin. extracting info from payload Apr 19 20:49:59 volumio volumio[979]: info: CoreStateMachine::pushState Apr 19 20:49:59 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 19 20:49:59 volumio volumio[979]: info: CoreCommandRouter::volumioPushState Apr 19 20:49:59 volumio volumio[979]: info: CoreStateMachine::pushState Apr 19 20:49:59 volumio volumio[979]: info: CoreCommandRouter::volumioPushState Apr 19 20:49:59 volumio volumio[979]: info: ------------------------------ 15ms Apr 19 20:50:04 volumio volumio[979]: info: Preload queue cleared Apr 19 20:50:04 volumio volumio[979]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 19 20:50:04 volumio volumio[979]: info: CoreStateMachine::ClearQueue Apr 19 20:50:04 volumio volumio[979]: info: CoreStateMachine::stop Apr 19 20:50:04 volumio volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 19 20:50:04 volumio volumio[979]: info: CoreStateMachine::stPlaybackTimer Apr 19 20:50:04 volumio volumio[979]: info: CoreStateMachine::updateTrackBlock Apr 19 20:50:04 volumio volumio[979]: info: CorePlayQueue::getTrackBlock Apr 19 20:50:04 volumio volumio[979]: info: CoreStateMachine::pushState Apr 19 20:50:04 volumio volumio[979]: info: CorePlayQueue::getTrack 22 Apr 19 20:50:04 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 19 20:50:04 volumio volumio[979]: info: CoreCommandRouter::volumioPushState Apr 19 20:50:04 volumio volumio[979]: info: CoreStateMachine::serviceStop Apr 19 20:50:04 volumio volumio[979]: info: CorePlayQueue::getTrack 22 Apr 19 20:50:04 volumio volumio[979]: info: CoreCommandRouter::serviceStop Apr 19 20:50:04 volumio volumio[979]: info: [1745088604492] ControllerUPNPBrowser::stop Apr 19 20:50:04 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand stop Apr 19 20:50:04 volumio volumio[979]: info: CorePlayQueue::clearPlayQueue Apr 19 20:50:04 volumio volumio[979]: info: CorePlayQueue::saveQueue Apr 19 20:50:04 volumio volumio[979]: info: CoreCommandRouter::volumioPushQueue Apr 19 20:50:04 volumio volumio[979]: info: CoreStateMachine::addQueueItems Apr 19 20:50:04 volumio volumio[979]: info: CorePlayQueue::addQueueItems Apr 19 20:50:04 volumio volumio[979]: info: Preload queue cleared Apr 19 20:50:04 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23211 Apr 19 20:50:04 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23211 Apr 19 20:50:04 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23183 Apr 19 20:50:04 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23183 Apr 19 20:50:04 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23173 Apr 19 20:50:04 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23173 Apr 19 20:50:04 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23182 Apr 19 20:50:04 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23182 Apr 19 20:50:04 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23206 Apr 19 20:50:04 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23206 Apr 19 20:50:04 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23175 Apr 19 20:50:04 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23175 Apr 19 20:50:04 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23180 Apr 19 20:50:04 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23180 Apr 19 20:50:04 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23179 Apr 19 20:50:04 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23179 Apr 19 20:50:04 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23178 Apr 19 20:50:04 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23178 Apr 19 20:50:04 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23198 Apr 19 20:50:04 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23198 Apr 19 20:50:04 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23208 Apr 19 20:50:04 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23208 Apr 19 20:50:04 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23166 Apr 19 20:50:04 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23166 Apr 19 20:50:04 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23164 Apr 19 20:50:04 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23164 Apr 19 20:50:04 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23209 Apr 19 20:50:04 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23209 Apr 19 20:50:04 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23177 Apr 19 20:50:04 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23177 Apr 19 20:50:04 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23172 Apr 19 20:50:04 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23172 Apr 19 20:50:04 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23165 Apr 19 20:50:04 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23165 Apr 19 20:50:04 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23168 Apr 19 20:50:04 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23168 Apr 19 20:50:04 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23210 Apr 19 20:50:04 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23210 Apr 19 20:50:04 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23203 Apr 19 20:50:04 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23203 Apr 19 20:50:04 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23174 Apr 19 20:50:04 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23174 Apr 19 20:50:04 volumio volumio[979]: info: Adding Item to queue: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23201 Apr 19 20:50:04 volumio volumio[979]: info: Using cached record of: upnp/folder/http://192.168.0.6:50001/ContentDirectory/control@22$23201 Apr 19 20:50:04 volumio volumio[979]: info: Adding Item to queue: upnp/http://192.168.0.6:50001/ContentDirectory/control@22$@138482 Apr 19 20:50:04 volumio volumio[979]: info: Using cached record of: upnp/http://192.168.0.6:50001/ContentDirectory/control@22$@138482 Apr 19 20:50:04 volumio volumio[979]: info: Adding Item to queue: upnp/http://192.168.0.6:50001/ContentDirectory/control@22$@138441 Apr 19 20:50:04 volumio volumio[979]: info: Using cached record of: upnp/http://192.168.0.6:50001/ContentDirectory/control@22$@138441 Apr 19 20:50:04 volumio volumio[979]: info: CoreCommandRouter::volumioPushQueue Apr 19 20:50:04 volumio volumio[979]: info: CorePlayQueue::saveQueue Apr 19 20:50:04 volumio volumio[979]: info: CoreStateMachine::updateTrackBlock Apr 19 20:50:04 volumio volumio[979]: info: CorePlayQueue::getTrackBlock Apr 19 20:50:04 volumio volumio[979]: info: CoreCommandRouter::volumioPlay Apr 19 20:50:04 volumio volumio[979]: info: CoreStateMachine::play index 23 Apr 19 20:50:04 volumio volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 19 20:50:04 volumio volumio[979]: info: CoreStateMachine::addQueueItems Apr 19 20:50:04 volumio volumio[979]: info: CorePlayQueue::addQueueItems Apr 19 20:50:04 volumio volumio[979]: info: Preload queue cleared Apr 19 20:50:04 volumio volumio[979]: info: Adding Item to queue: upnp/http://192.168.0.6:50001/ContentDirectory/control@22$@138782 Apr 19 20:50:04 volumio volumio[979]: info: Using cached record of: upnp/http://192.168.0.6:50001/ContentDirectory/control@22$@138782 Apr 19 20:50:04 volumio volumio[979]: info: CoreStateMachine::stop Apr 19 20:50:04 volumio volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 19 20:50:04 volumio volumio[979]: info: CoreCommandRouter::volumioPushQueue Apr 19 20:50:04 volumio volumio[979]: info: CorePlayQueue::saveQueue Apr 19 20:50:04 volumio volumio[979]: info: CoreStateMachine::play index undefined Apr 19 20:50:04 volumio volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 19 20:50:04 volumio volumio[979]: info: CoreStateMachine::updateTrackBlock Apr 19 20:50:04 volumio volumio[979]: info: CorePlayQueue::getTrackBlock Apr 19 20:50:04 volumio volumio[979]: info: CorePlayQueue::getTrack 23 Apr 19 20:50:04 volumio volumio[979]: info: CoreStateMachine::startPlaybackTimer Apr 19 20:50:04 volumio volumio[979]: info: CorePlayQueue::getTrack 23 Apr 19 20:50:04 volumio volumio[979]: info: [1745088604519] ControllerUPNPBrowser::clearAddPlayTrack Apr 19 20:50:04 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand stop Apr 19 20:50:04 volumio volumio[979]: info: Apr 19 20:50:04 volumio volumio[979]: ---------------------------- MPD announces state update: player Apr 19 20:50:04 volumio volumio[979]: info: sendMpdCommand stop took 40 milliseconds Apr 19 20:50:04 volumio volumio[979]: info: ControllerMpd::getState Apr 19 20:50:04 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 19 20:50:04 volumio volumio[979]: info: sendMpdCommand stop took 14 milliseconds Apr 19 20:50:04 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand clear Apr 19 20:50:04 volumio volumio[979]: info: sendMpdCommand status took 2 milliseconds Apr 19 20:50:04 volumio volumio[979]: verbose: ControllerMpd::parseState Apr 19 20:50:04 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 19 20:50:04 volumio volumio[979]: info: Apr 19 20:50:04 volumio volumio[979]: ---------------------------- MPD announces system playlist update Apr 19 20:50:04 volumio volumio[979]: info: Ignoring MPD Status Update Apr 19 20:50:04 volumio volumio[979]: info: sendMpdCommand clear took 3 milliseconds Apr 19 20:50:04 volumio volumio[979]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 19 20:50:04 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.0.6:50002/m/NDLNA/138479.dff" Apr 19 20:50:04 volumio volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 19 20:50:04 volumio volumio[979]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 19 20:50:04 volumio volumio[979]: info: ------------------------------ 7ms Apr 19 20:50:04 volumio volumio[979]: error: updateQueue error: null Apr 19 20:50:04 volumio volumio[979]: info: ------------------------------ 3ms Apr 19 20:50:04 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.0.6:50002/m/NDLNA/138479.dff" Apr 19 20:50:04 volumio volumio[979]: info: Apr 19 20:50:04 volumio volumio[979]: ---------------------------- MPD announces system playlist update Apr 19 20:50:04 volumio volumio[979]: info: Ignoring MPD Status Update Apr 19 20:50:04 volumio volumio[979]: info: sendMpdCommand add "http://192.168.0.6:50002/m/NDLNA/138479.dff" took 2 milliseconds Apr 19 20:50:04 volumio volumio[979]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 19 20:50:04 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand play Apr 19 20:50:04 volumio volumio[979]: info: ------------------------------ 1ms Apr 19 20:50:04 volumio volumio[979]: info: sendMpdCommand play took 1 milliseconds Apr 19 20:50:04 volumio volumio[979]: info: Apr 19 20:50:04 volumio volumio[979]: ---------------------------- MPD announces state update: player Apr 19 20:50:04 volumio volumio[979]: info: ControllerMpd::getState Apr 19 20:50:04 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 19 20:50:04 volumio volumio[979]: info: Apr 19 20:50:04 volumio volumio[979]: ---------------------------- MPD announces state update: player Apr 19 20:50:04 volumio volumio[979]: info: sendMpdCommand status took 6 milliseconds Apr 19 20:50:04 volumio volumio[979]: info: ControllerMpd::getState Apr 19 20:50:04 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 19 20:50:04 volumio volumio[979]: verbose: ControllerMpd::parseState Apr 19 20:50:04 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 19 20:50:04 volumio volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 19 20:50:04 volumio volumio[979]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 19 20:50:04 volumio volumio[979]: verbose: ControllerMpd::parseState Apr 19 20:50:04 volumio volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 19 20:50:04 volumio volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 19 20:50:04 volumio volumio[979]: info: ControllerMpd::pushState Apr 19 20:50:04 volumio volumio[979]: info: CoreCommandRouter::servicePushState Apr 19 20:50:04 volumio volumio[979]: info: CorePlayQueue::getTrack 23 Apr 19 20:50:04 volumio volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":244,"samplerate":"5.64 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"138479.dff","artist":null,"album":null,"uri":"http://192.168.0.6:50002/m/NDLNA/138479.dff","trackType":"dff"} Apr 19 20:50:04 volumio volumio[979]: verbose: CURRENT POSITION 23 Apr 19 20:50:04 volumio volumio[979]: info: CoreStateMachine::syncState stateService play Apr 19 20:50:04 volumio volumio[979]: info: CoreStateMachine::syncState currentStatus stop Apr 19 20:50:04 volumio volumio[979]: info: ------------------------------ 9ms Apr 19 20:50:04 volumio volumio[979]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 19 20:50:04 volumio volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 19 20:50:04 volumio volumio[979]: info: ControllerMpd::pushState Apr 19 20:50:04 volumio volumio[979]: info: CoreCommandRouter::servicePushState Apr 19 20:50:04 volumio volumio[979]: info: CorePlayQueue::getTrack 23 Apr 19 20:50:04 volumio volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":244,"samplerate":"5.64 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"138479.dff","artist":null,"album":null,"uri":"http://192.168.0.6:50002/m/NDLNA/138479.dff","trackType":"dff"} Apr 19 20:50:04 volumio volumio[979]: verbose: CURRENT POSITION 23 Apr 19 20:50:04 volumio volumio[979]: info: CoreStateMachine::syncState stateService play Apr 19 20:50:04 volumio volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 19 20:50:04 volumio volumio[979]: info: Received an update from plugin. extracting info from payload Apr 19 20:50:04 volumio volumio[979]: info: CoreStateMachine::pushState Apr 19 20:50:04 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 19 20:50:04 volumio volumio[979]: info: CoreCommandRouter::volumioPushState Apr 19 20:50:04 volumio volumio[979]: info: CoreStateMachine::pushState Apr 19 20:50:04 volumio volumio[979]: info: CoreCommandRouter::volumioPushState Apr 19 20:50:04 volumio volumio[979]: info: ------------------------------ 14ms Apr 19 20:50:10 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Apr 19 20:50:11 volumio volumio[979]: info: Preload queue cleared Apr 19 20:50:13 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Apr 19 20:50:13 volumio volumio[979]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 19 20:50:13 volumio volumio[979]: TypeError: Cannot read property 'length' of undefined Apr 19 20:50:13 volumio volumio[979]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Apr 19 20:50:13 volumio volumio[979]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Apr 19 20:50:13 volumio volumio[979]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Apr 19 20:50:13 volumio volumio[979]: at Parser.emit (events.js:315:20) Apr 19 20:50:13 volumio volumio[979]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Apr 19 20:50:13 volumio volumio[979]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Apr 19 20:50:13 volumio volumio[979]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Apr 19 20:50:13 volumio volumio[979]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Apr 19 20:50:13 volumio volumio[979]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Apr 19 20:50:13 volumio volumio[979]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Apr 19 20:50:13 volumio volumio[979]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Apr 19 20:50:13 volumio volumio[979]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Apr 19 20:50:13 volumio volumio[979]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Apr 19 20:50:13 volumio volumio[979]: at IncomingMessage.emit (events.js:327:22) Apr 19 20:50:13 volumio volumio[979]: at endReadableNT (internal/streams/readable.js:1327:12) Apr 19 20:50:13 volumio volumio[979]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Apr 19 20:50:13 volumio volumio[979]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 19 20:50:13 volumio sudo[1960]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-04-19 20:49 Apr 19 20:50:13 volumio sudo[1960]: 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="e32c2c71ae78852844c70357816bdd871c155ab8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 31 Mar 2025 06:54:47 PM CEST" VOLUMIO_VERSION="3.799" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="436f3f84f6d0b4ffc344f0bc132a32e8"