-- Logs begin at Thu 2019-02-14 19:11:59 KST, end at Fri 2024-11-29 15:12:20 KST. -- Nov 29 15:11:02 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 29 15:11:02 volumio volumio[977]: info: Preload queue cleared Nov 29 15:11:04 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 29 15:11:04 volumio volumio[977]: info: Preload queue cleared Nov 29 15:11:04 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@419727 Nov 29 15:11:04 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@419728 Nov 29 15:11:04 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@419729 Nov 29 15:11:04 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@419730 Nov 29 15:11:04 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@419731 Nov 29 15:11:04 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@419732 Nov 29 15:11:04 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@419733 Nov 29 15:11:04 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@419734 Nov 29 15:11:04 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@419735 Nov 29 15:11:04 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@419736 Nov 29 15:11:04 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@419727 in service upnp_browser Nov 29 15:11:04 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@419728 in service upnp_browser Nov 29 15:11:04 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@419729 in service upnp_browser Nov 29 15:11:04 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@419730 in service upnp_browser Nov 29 15:11:04 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@419731 in service upnp_browser Nov 29 15:11:04 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@419732 in service upnp_browser Nov 29 15:11:05 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@419733 in service upnp_browser Nov 29 15:11:05 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@419734 in service upnp_browser Nov 29 15:11:05 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@419735 in service upnp_browser Nov 29 15:11:05 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@419736 in service upnp_browser Nov 29 15:11:05 volumio volumio[977]: info: Preload queue cleared Nov 29 15:11:05 volumio volumio[977]: info: CoreCommandRouter::volumioReplaceandPlayItems Nov 29 15:11:05 volumio volumio[977]: info: CoreStateMachine::ClearQueue Nov 29 15:11:05 volumio volumio[977]: info: CoreStateMachine::stop Nov 29 15:11:05 volumio volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 15:11:05 volumio volumio[977]: info: CoreStateMachine::stPlaybackTimer Nov 29 15:11:05 volumio volumio[977]: info: CoreStateMachine::updateTrackBlock Nov 29 15:11:05 volumio volumio[977]: info: CorePlayQueue::getTrackBlock Nov 29 15:11:05 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:05 volumio volumio[977]: info: CorePlayQueue::getTrack 0 Nov 29 15:11:05 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 29 15:11:05 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:05 volumio volumio[977]: info: CoreStateMachine::serviceStop Nov 29 15:11:05 volumio volumio[977]: info: CorePlayQueue::getTrack 0 Nov 29 15:11:05 volumio volumio[977]: info: CoreCommandRouter::serviceStop Nov 29 15:11:05 volumio volumio[977]: info: [1732860665918] ControllerUPNPBrowser::stop Nov 29 15:11:05 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand stop Nov 29 15:11:05 volumio volumio[977]: info: CorePlayQueue::clearPlayQueue Nov 29 15:11:05 volumio volumio[977]: info: CorePlayQueue::saveQueue Nov 29 15:11:05 volumio volumio[977]: info: CoreCommandRouter::volumioPushQueue Nov 29 15:11:05 volumio volumio[977]: info: CoreStateMachine::addQueueItems Nov 29 15:11:05 volumio volumio[977]: info: CorePlayQueue::addQueueItems Nov 29 15:11:05 volumio volumio[977]: info: Preload queue cleared Nov 29 15:11:05 volumio volumio[977]: info: Adding Item to queue: upnp/folder/http://192.168.0.12:50001/ContentDirectory/control@22$34546 Nov 29 15:11:05 volumio volumio[977]: info: Exploding uri upnp/folder/http://192.168.0.12:50001/ContentDirectory/control@22$34546 in service upnp_browser Nov 29 15:11:05 volumio volumio[977]: info: Nov 29 15:11:05 volumio volumio[977]: ---------------------------- MPD announces state update: player Nov 29 15:11:05 volumio volumio[977]: info: sendMpdCommand stop took 31 milliseconds Nov 29 15:11:05 volumio volumio[977]: info: ControllerMpd::getState Nov 29 15:11:05 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status Nov 29 15:11:05 volumio volumio[977]: info: sendMpdCommand status took 2 milliseconds Nov 29 15:11:05 volumio volumio[977]: verbose: ControllerMpd::parseState Nov 29 15:11:05 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 29 15:11:05 volumio volumio[977]: info: Nov 29 15:11:05 volumio volumio[977]: ---------------------------- MPD announces state update: player Nov 29 15:11:05 volumio volumio[977]: info: ControllerMpd::getState Nov 29 15:11:05 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status Nov 29 15:11:05 volumio volumio[977]: info: Nov 29 15:11:05 volumio volumio[977]: ---------------------------- MPD announces state update: player Nov 29 15:11:05 volumio volumio[977]: info: ControllerMpd::getState Nov 29 15:11:05 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status Nov 29 15:11:05 volumio volumio[977]: info: sendMpdCommand playlistinfo took 23 milliseconds Nov 29 15:11:05 volumio volumio[977]: info: sendMpdCommand status took 19 milliseconds Nov 29 15:11:05 volumio volumio[977]: info: sendMpdCommand status took 16 milliseconds Nov 29 15:11:05 volumio volumio[977]: verbose: ControllerMpd::parseTrackInfo Nov 29 15:11:05 volumio volumio[977]: verbose: ControllerMpd::parseState Nov 29 15:11:05 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 29 15:11:05 volumio volumio[977]: verbose: ControllerMpd::parseState Nov 29 15:11:05 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 29 15:11:05 volumio volumio[977]: info: ControllerMpd::pushState Nov 29 15:11:05 volumio volumio[977]: info: CoreCommandRouter::servicePushState Nov 29 15:11:05 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:05 volumio volumio[977]: info: CorePlayQueue::getTrack 0 Nov 29 15:11:05 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 29 15:11:05 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:05 volumio volumio[977]: info: CorePlayQueue::getTrack 0 Nov 29 15:11:05 volumio volumio[977]: 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":"id=403016.wav?format=WAV&downsample=false","artist":null,"album":null,"uri":"http://192.168.0.12:50002/transcoder/genericoder.cgi/id=403016.wav?format=WAV&downsample=false","trackType":""} Nov 29 15:11:05 volumio volumio[977]: verbose: CURRENT POSITION 0 Nov 29 15:11:05 volumio volumio[977]: info: CoreStateMachine::syncState stateService stop Nov 29 15:11:05 volumio volumio[977]: info: CoreStateMachine::syncState currentStatus stop Nov 29 15:11:05 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:05 volumio volumio[977]: info: CorePlayQueue::getTrack 0 Nov 29 15:11:05 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:05 volumio volumio[977]: info: No code Nov 29 15:11:05 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:05 volumio volumio[977]: info: CorePlayQueue::getTrack 0 Nov 29 15:11:05 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:06 volumio volumio[977]: info: ------------------------------ 71ms Nov 29 15:11:06 volumio volumio[977]: info: CoreCommandRouter::volumioPushQueue Nov 29 15:11:06 volumio volumio[977]: info: CorePlayQueue::saveQueue Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::updateTrackBlock Nov 29 15:11:06 volumio volumio[977]: info: CorePlayQueue::getTrackBlock Nov 29 15:11:06 volumio volumio[977]: info: CoreCommandRouter::volumioPlay Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::play index 0 Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::stop Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::play index undefined Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 15:11:06 volumio volumio[977]: info: CorePlayQueue::getTrack 0 Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::startPlaybackTimer Nov 29 15:11:06 volumio volumio[977]: info: CorePlayQueue::getTrack 0 Nov 29 15:11:06 volumio volumio[977]: info: [1732860666051] ControllerUPNPBrowser::clearAddPlayTrack Nov 29 15:11:06 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand stop Nov 29 15:11:06 volumio volumio[977]: info: sendMpdCommand playlistinfo took 71 milliseconds Nov 29 15:11:06 volumio volumio[977]: info: sendMpdCommand playlistinfo took 71 milliseconds Nov 29 15:11:06 volumio volumio[977]: info: sendMpdCommand stop took 3 milliseconds Nov 29 15:11:06 volumio volumio[977]: verbose: ControllerMpd::parseTrackInfo Nov 29 15:11:06 volumio volumio[977]: verbose: ControllerMpd::parseTrackInfo Nov 29 15:11:06 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand clear Nov 29 15:11:06 volumio volumio[977]: info: ControllerMpd::pushState Nov 29 15:11:06 volumio volumio[977]: info: CoreCommandRouter::servicePushState Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:06 volumio volumio[977]: info: CorePlayQueue::getTrack 0 Nov 29 15:11:06 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 29 15:11:06 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:06 volumio volumio[977]: info: CorePlayQueue::getTrack 0 Nov 29 15:11:06 volumio volumio[977]: 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":"id=403016.wav?format=WAV&downsample=false","artist":null,"album":null,"uri":"http://192.168.0.12:50002/transcoder/genericoder.cgi/id=403016.wav?format=WAV&downsample=false","trackType":""} Nov 29 15:11:06 volumio volumio[977]: verbose: CURRENT POSITION 0 Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::syncState stateService stop Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::syncState currentStatus stop Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:06 volumio volumio[977]: info: CorePlayQueue::getTrack 0 Nov 29 15:11:06 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:06 volumio volumio[977]: info: No code Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:06 volumio volumio[977]: info: CorePlayQueue::getTrack 0 Nov 29 15:11:06 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:06 volumio volumio[977]: info: ControllerMpd::pushState Nov 29 15:11:06 volumio volumio[977]: info: CoreCommandRouter::servicePushState Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:06 volumio volumio[977]: info: CorePlayQueue::getTrack 0 Nov 29 15:11:06 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:06 volumio volumio[977]: info: CorePlayQueue::getTrack 0 Nov 29 15:11:06 volumio volumio[977]: 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":"id=403016.wav?format=WAV&downsample=false","artist":null,"album":null,"uri":"http://192.168.0.12:50002/transcoder/genericoder.cgi/id=403016.wav?format=WAV&downsample=false","trackType":""} Nov 29 15:11:06 volumio volumio[977]: verbose: CURRENT POSITION 0 Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::syncState stateService stop Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::syncState currentStatus stop Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:06 volumio volumio[977]: info: CorePlayQueue::getTrack 0 Nov 29 15:11:06 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:06 volumio volumio[977]: info: No code Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:06 volumio volumio[977]: info: CorePlayQueue::getTrack 0 Nov 29 15:11:06 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:06 volumio volumio[977]: info: ------------------------------ 165ms Nov 29 15:11:06 volumio volumio[977]: info: ------------------------------ 161ms Nov 29 15:11:06 volumio volumio[977]: info: Nov 29 15:11:06 volumio volumio[977]: ---------------------------- MPD announces system playlist update Nov 29 15:11:06 volumio volumio[977]: info: Ignoring MPD Status Update Nov 29 15:11:06 volumio volumio[977]: info: sendMpdCommand clear took 92 milliseconds Nov 29 15:11:06 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.0.12:50002/transcoder/genericoder.cgi/id=419727.wav?format=WAV&downsample=false" Nov 29 15:11:06 volumio volumio[977]: info: Nov 29 15:11:06 volumio volumio[977]: ---------------------------- MPD announces system playlist update Nov 29 15:11:06 volumio volumio[977]: info: Ignoring MPD Status Update Nov 29 15:11:06 volumio volumio[977]: info: Nov 29 15:11:06 volumio volumio[977]: ---------------------------- MPD announces system playlist update Nov 29 15:11:06 volumio volumio[977]: info: Ignoring MPD Status Update Nov 29 15:11:06 volumio volumio[977]: error: updateQueue error: null Nov 29 15:11:06 volumio volumio[977]: info: ------------------------------ 27ms Nov 29 15:11:06 volumio volumio[977]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Angra/Angels%20Cry/6ba2dac7-11c0-4b17-865c-9b8a66d2cf57.png' Nov 29 15:11:06 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.0.12:50002/transcoder/genericoder.cgi/id=419727.wav?format=WAV&downsample=false" Nov 29 15:11:06 volumio volumio[977]: error: updateQueue error: null Nov 29 15:11:06 volumio volumio[977]: error: updateQueue error: null Nov 29 15:11:06 volumio volumio[977]: info: Nov 29 15:11:06 volumio volumio[977]: ---------------------------- MPD announces system playlist update Nov 29 15:11:06 volumio volumio[977]: info: Ignoring MPD Status Update Nov 29 15:11:06 volumio volumio[977]: info: ------------------------------ 205ms Nov 29 15:11:06 volumio volumio[977]: info: ------------------------------ 203ms Nov 29 15:11:06 volumio volumio[977]: info: sendMpdCommand add "http://192.168.0.12:50002/transcoder/genericoder.cgi/id=419727.wav?format=WAV&downsample=false" took 4 milliseconds Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 29 15:11:06 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand play Nov 29 15:11:06 volumio volumio[977]: info: Nov 29 15:11:06 volumio volumio[977]: ---------------------------- MPD announces system playlist update Nov 29 15:11:06 volumio volumio[977]: info: Ignoring MPD Status Update Nov 29 15:11:06 volumio volumio[977]: info: Nov 29 15:11:06 volumio volumio[977]: ---------------------------- MPD announces system playlist update Nov 29 15:11:06 volumio volumio[977]: info: Ignoring MPD Status Update Nov 29 15:11:06 volumio volumio[977]: info: ------------------------------ 11ms Nov 29 15:11:06 volumio volumio[977]: info: sendMpdCommand play took 6 milliseconds Nov 29 15:11:06 volumio volumio[977]: info: ------------------------------ 5ms Nov 29 15:11:06 volumio volumio[977]: info: ------------------------------ 3ms Nov 29 15:11:06 volumio volumio[977]: info: Nov 29 15:11:06 volumio volumio[977]: ---------------------------- MPD announces state update: player Nov 29 15:11:06 volumio volumio[977]: info: ControllerMpd::getState Nov 29 15:11:06 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status Nov 29 15:11:06 volumio volumio[977]: info: Nov 29 15:11:06 volumio volumio[977]: ---------------------------- MPD announces state update: player Nov 29 15:11:06 volumio volumio[977]: info: ControllerMpd::getState Nov 29 15:11:06 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status Nov 29 15:11:06 volumio volumio[977]: info: Nov 29 15:11:06 volumio volumio[977]: ---------------------------- MPD announces state update: player Nov 29 15:11:06 volumio volumio[977]: info: ControllerMpd::getState Nov 29 15:11:06 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status Nov 29 15:11:06 volumio volumio[977]: info: Nov 29 15:11:06 volumio volumio[977]: ---------------------------- MPD announces state update: player Nov 29 15:11:06 volumio volumio[977]: info: ControllerMpd::getState Nov 29 15:11:06 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status Nov 29 15:11:06 volumio volumio[977]: info: sendMpdCommand status took 8 milliseconds Nov 29 15:11:06 volumio volumio[977]: info: sendMpdCommand status took 6 milliseconds Nov 29 15:11:06 volumio volumio[977]: info: sendMpdCommand status took 5 milliseconds Nov 29 15:11:06 volumio volumio[977]: verbose: ControllerMpd::parseState Nov 29 15:11:06 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 29 15:11:06 volumio volumio[977]: verbose: ControllerMpd::parseState Nov 29 15:11:06 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 29 15:11:06 volumio volumio[977]: verbose: ControllerMpd::parseState Nov 29 15:11:06 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 29 15:11:06 volumio volumio[977]: info: Nov 29 15:11:06 volumio volumio[977]: ---------------------------- MPD announces state update: player Nov 29 15:11:06 volumio volumio[977]: info: ControllerMpd::getState Nov 29 15:11:06 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status Nov 29 15:11:06 volumio volumio[977]: info: Nov 29 15:11:06 volumio volumio[977]: ---------------------------- MPD announces state update: player Nov 29 15:11:06 volumio volumio[977]: info: ControllerMpd::getState Nov 29 15:11:06 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status Nov 29 15:11:06 volumio volumio[977]: info: sendMpdCommand status took 12 milliseconds Nov 29 15:11:06 volumio volumio[977]: info: sendMpdCommand playlistinfo took 10 milliseconds Nov 29 15:11:06 volumio volumio[977]: info: sendMpdCommand playlistinfo took 9 milliseconds Nov 29 15:11:06 volumio volumio[977]: info: sendMpdCommand playlistinfo took 9 milliseconds Nov 29 15:11:06 volumio volumio[977]: info: sendMpdCommand status took 6 milliseconds Nov 29 15:11:06 volumio volumio[977]: verbose: ControllerMpd::parseState Nov 29 15:11:06 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 29 15:11:06 volumio volumio[977]: verbose: ControllerMpd::parseTrackInfo Nov 29 15:11:06 volumio volumio[977]: verbose: ControllerMpd::parseTrackInfo Nov 29 15:11:06 volumio volumio[977]: verbose: ControllerMpd::parseTrackInfo Nov 29 15:11:06 volumio volumio[977]: verbose: ControllerMpd::parseState Nov 29 15:11:06 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 29 15:11:06 volumio volumio[977]: info: ControllerMpd::pushState Nov 29 15:11:06 volumio volumio[977]: info: CoreCommandRouter::servicePushState Nov 29 15:11:06 volumio volumio[977]: info: CorePlayQueue::getTrack 0 Nov 29 15:11:06 volumio volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":75,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"id=419727.wav?format=WAV&downsample=false","artist":null,"album":null,"uri":"http://192.168.0.12:50002/transcoder/genericoder.cgi/id=419727.wav?format=WAV&downsample=false","trackType":""} Nov 29 15:11:06 volumio volumio[977]: verbose: CURRENT POSITION 0 Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::syncState stateService play Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::syncState currentStatus stop Nov 29 15:11:06 volumio volumio[977]: info: ControllerMpd::pushState Nov 29 15:11:06 volumio volumio[977]: info: CoreCommandRouter::servicePushState Nov 29 15:11:06 volumio volumio[977]: info: CorePlayQueue::getTrack 0 Nov 29 15:11:06 volumio volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":75,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"id=419727.wav?format=WAV&downsample=false","artist":null,"album":null,"uri":"http://192.168.0.12:50002/transcoder/genericoder.cgi/id=419727.wav?format=WAV&downsample=false","trackType":""} Nov 29 15:11:06 volumio volumio[977]: verbose: CURRENT POSITION 0 Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::syncState stateService play Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::syncState currentStatus play Nov 29 15:11:06 volumio volumio[977]: info: Received an update from plugin. extracting info from payload Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:06 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 29 15:11:06 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:06 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:06 volumio volumio[977]: info: ControllerMpd::pushState Nov 29 15:11:06 volumio volumio[977]: info: CoreCommandRouter::servicePushState Nov 29 15:11:06 volumio volumio[977]: info: CorePlayQueue::getTrack 0 Nov 29 15:11:06 volumio volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":75,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"id=419727.wav?format=WAV&downsample=false","artist":null,"album":null,"uri":"http://192.168.0.12:50002/transcoder/genericoder.cgi/id=419727.wav?format=WAV&downsample=false","trackType":""} Nov 29 15:11:06 volumio volumio[977]: verbose: CURRENT POSITION 0 Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::syncState stateService play Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::syncState currentStatus play Nov 29 15:11:06 volumio volumio[977]: info: Received an update from plugin. extracting info from payload Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:06 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:06 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:06 volumio volumio[977]: info: ------------------------------ 57ms Nov 29 15:11:06 volumio volumio[977]: info: ------------------------------ 93ms Nov 29 15:11:06 volumio volumio[977]: info: ------------------------------ 93ms Nov 29 15:11:06 volumio volumio[977]: info: sendMpdCommand status took 80 milliseconds Nov 29 15:11:06 volumio volumio[977]: info: sendMpdCommand playlistinfo took 75 milliseconds Nov 29 15:11:06 volumio volumio[977]: info: sendMpdCommand playlistinfo took 73 milliseconds Nov 29 15:11:06 volumio volumio[977]: verbose: ControllerMpd::parseState Nov 29 15:11:06 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 29 15:11:06 volumio volumio[977]: verbose: ControllerMpd::parseTrackInfo Nov 29 15:11:06 volumio volumio[977]: verbose: ControllerMpd::parseTrackInfo Nov 29 15:11:06 volumio volumio[977]: info: ControllerMpd::pushState Nov 29 15:11:06 volumio volumio[977]: info: CoreCommandRouter::servicePushState Nov 29 15:11:06 volumio volumio[977]: info: CorePlayQueue::getTrack 0 Nov 29 15:11:06 volumio volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":75,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"id=419727.wav?format=WAV&downsample=false","artist":null,"album":null,"uri":"http://192.168.0.12:50002/transcoder/genericoder.cgi/id=419727.wav?format=WAV&downsample=false","trackType":""} Nov 29 15:11:06 volumio volumio[977]: verbose: CURRENT POSITION 0 Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::syncState stateService play Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::syncState currentStatus play Nov 29 15:11:06 volumio volumio[977]: info: Received an update from plugin. extracting info from payload Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:06 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 29 15:11:06 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:06 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:06 volumio volumio[977]: info: ControllerMpd::pushState Nov 29 15:11:06 volumio volumio[977]: info: CoreCommandRouter::servicePushState Nov 29 15:11:06 volumio volumio[977]: info: CorePlayQueue::getTrack 0 Nov 29 15:11:06 volumio volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":75,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"id=419727.wav?format=WAV&downsample=false","artist":null,"album":null,"uri":"http://192.168.0.12:50002/transcoder/genericoder.cgi/id=419727.wav?format=WAV&downsample=false","trackType":""} Nov 29 15:11:06 volumio volumio[977]: verbose: CURRENT POSITION 0 Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::syncState stateService play Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::syncState currentStatus play Nov 29 15:11:06 volumio volumio[977]: info: Received an update from plugin. extracting info from payload Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:06 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:06 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:06 volumio volumio[977]: info: ------------------------------ 170ms Nov 29 15:11:06 volumio volumio[977]: info: ------------------------------ 163ms Nov 29 15:11:06 volumio volumio[977]: info: sendMpdCommand playlistinfo took 98 milliseconds Nov 29 15:11:06 volumio volumio[977]: verbose: ControllerMpd::parseTrackInfo Nov 29 15:11:06 volumio volumio[977]: info: ControllerMpd::pushState Nov 29 15:11:06 volumio volumio[977]: info: CoreCommandRouter::servicePushState Nov 29 15:11:06 volumio volumio[977]: info: CorePlayQueue::getTrack 0 Nov 29 15:11:06 volumio volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":75,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"id=419727.wav?format=WAV&downsample=false","artist":null,"album":null,"uri":"http://192.168.0.12:50002/transcoder/genericoder.cgi/id=419727.wav?format=WAV&downsample=false","trackType":""} Nov 29 15:11:06 volumio volumio[977]: verbose: CURRENT POSITION 0 Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::syncState stateService play Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::syncState currentStatus play Nov 29 15:11:06 volumio volumio[977]: info: Received an update from plugin. extracting info from payload Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:06 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:06 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:06 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:06 volumio volumio[977]: info: ------------------------------ 220ms Nov 29 15:11:37 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 29 15:11:37 volumio volumio[977]: info: Preload queue cleared Nov 29 15:11:37 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@391313 Nov 29 15:11:37 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@391314 Nov 29 15:11:37 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@391315 Nov 29 15:11:37 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@391316 Nov 29 15:11:37 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@391317 Nov 29 15:11:37 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@391318 Nov 29 15:11:37 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@391319 Nov 29 15:11:37 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@391320 Nov 29 15:11:37 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@391321 Nov 29 15:11:37 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@391322 Nov 29 15:11:37 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@391323 Nov 29 15:11:37 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@391324 Nov 29 15:11:37 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@391325 Nov 29 15:11:37 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@391326 Nov 29 15:11:37 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@391327 Nov 29 15:11:37 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@391313 in service upnp_browser Nov 29 15:11:37 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@391314 in service upnp_browser Nov 29 15:11:37 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@391315 in service upnp_browser Nov 29 15:11:37 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@391316 in service upnp_browser Nov 29 15:11:37 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@391317 in service upnp_browser Nov 29 15:11:37 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@391318 in service upnp_browser Nov 29 15:11:37 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@391319 in service upnp_browser Nov 29 15:11:37 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@391320 in service upnp_browser Nov 29 15:11:38 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@391321 in service upnp_browser Nov 29 15:11:38 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@391322 in service upnp_browser Nov 29 15:11:38 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@391323 in service upnp_browser Nov 29 15:11:38 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@391324 in service upnp_browser Nov 29 15:11:38 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@391325 in service upnp_browser Nov 29 15:11:38 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@391326 in service upnp_browser Nov 29 15:11:38 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@391327 in service upnp_browser Nov 29 15:11:40 volumio volumio[977]: info: CoreCommandRouter::volumioplayNextItems Nov 29 15:11:40 volumio volumio[977]: info: CoreStateMachine::playNextItems Nov 29 15:11:40 volumio volumio[977]: info: CorePlayQueue::addPlayNextItems Nov 29 15:11:40 volumio volumio[977]: info: Preload queue cleared Nov 29 15:11:40 volumio volumio[977]: info: Adding Item to play next: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@391313 Nov 29 15:11:40 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@391313 Nov 29 15:11:40 volumio volumio[977]: info: CoreCommandRouter::volumioPushQueue Nov 29 15:11:40 volumio volumio[977]: info: CorePlayQueue::saveQueue Nov 29 15:11:40 volumio volumio[977]: info: CoreStateMachine::updateTrackBlock Nov 29 15:11:40 volumio volumio[977]: info: CorePlayQueue::getTrackBlock Nov 29 15:11:42 volumio volumio[977]: info: CoreCommandRouter::volumioNext Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::next Nov 29 15:11:42 volumio volumio[977]: info: ControllerMpd::next Nov 29 15:11:42 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand next Nov 29 15:11:42 volumio volumio[977]: info: sendMpdCommand next took 6 milliseconds Nov 29 15:11:42 volumio volumio[977]: info: Nov 29 15:11:42 volumio volumio[977]: ---------------------------- MPD announces state update: player Nov 29 15:11:42 volumio volumio[977]: info: ControllerMpd::getState Nov 29 15:11:42 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status Nov 29 15:11:42 volumio volumio[977]: info: Nov 29 15:11:42 volumio volumio[977]: ---------------------------- MPD announces state update: player Nov 29 15:11:42 volumio volumio[977]: info: ControllerMpd::getState Nov 29 15:11:42 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status Nov 29 15:11:42 volumio volumio[977]: info: Nov 29 15:11:42 volumio volumio[977]: ---------------------------- MPD announces state update: player Nov 29 15:11:42 volumio volumio[977]: info: ControllerMpd::getState Nov 29 15:11:42 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status Nov 29 15:11:42 volumio volumio[977]: info: sendMpdCommand status took 6 milliseconds Nov 29 15:11:42 volumio volumio[977]: info: sendMpdCommand status took 5 milliseconds Nov 29 15:11:42 volumio volumio[977]: info: sendMpdCommand status took 3 milliseconds Nov 29 15:11:42 volumio volumio[977]: verbose: ControllerMpd::parseState Nov 29 15:11:42 volumio volumio[977]: verbose: ControllerMpd::parseState Nov 29 15:11:42 volumio volumio[977]: verbose: ControllerMpd::parseState Nov 29 15:11:42 volumio volumio[977]: info: ControllerMpd::pushState Nov 29 15:11:42 volumio volumio[977]: info: CoreCommandRouter::servicePushState Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:42 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 29 15:11:42 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:42 volumio volumio[977]: info: CorePlayQueue::getTrack 0 Nov 29 15:11:42 volumio volumio[977]: 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} Nov 29 15:11:42 volumio volumio[977]: verbose: CURRENT POSITION 0 Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::syncState stateService stop Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::syncState currentStatus play Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::play index undefined Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:42 volumio volumio[977]: info: CorePlayQueue::getTrack 1 Nov 29 15:11:42 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 29 15:11:42 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:42 volumio volumio[977]: info: ControllerMpd::pushState Nov 29 15:11:42 volumio volumio[977]: info: CoreCommandRouter::servicePushState Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:42 volumio volumio[977]: info: CorePlayQueue::getTrack 1 Nov 29 15:11:42 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:42 volumio volumio[977]: info: CorePlayQueue::getTrack 1 Nov 29 15:11:42 volumio volumio[977]: 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} Nov 29 15:11:42 volumio volumio[977]: verbose: CURRENT POSITION 1 Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::syncState stateService stop Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::syncState currentStatus stop Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:42 volumio volumio[977]: info: CorePlayQueue::getTrack 1 Nov 29 15:11:42 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:42 volumio volumio[977]: info: No code Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:42 volumio volumio[977]: info: CorePlayQueue::getTrack 1 Nov 29 15:11:42 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:42 volumio volumio[977]: info: ControllerMpd::pushState Nov 29 15:11:42 volumio volumio[977]: info: CoreCommandRouter::servicePushState Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:42 volumio volumio[977]: info: CorePlayQueue::getTrack 1 Nov 29 15:11:42 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:42 volumio volumio[977]: info: CorePlayQueue::getTrack 1 Nov 29 15:11:42 volumio volumio[977]: 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} Nov 29 15:11:42 volumio volumio[977]: verbose: CURRENT POSITION 1 Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::syncState stateService stop Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::syncState currentStatus stop Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:42 volumio volumio[977]: info: CorePlayQueue::getTrack 1 Nov 29 15:11:42 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:42 volumio volumio[977]: info: No code Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:42 volumio volumio[977]: info: CorePlayQueue::getTrack 1 Nov 29 15:11:42 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:42 volumio volumio[977]: info: CorePlayQueue::getTrack 1 Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::startPlaybackTimer Nov 29 15:11:42 volumio volumio[977]: info: CorePlayQueue::getTrack 1 Nov 29 15:11:42 volumio volumio[977]: info: [1732860702219] ControllerUPNPBrowser::clearAddPlayTrack Nov 29 15:11:42 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand stop Nov 29 15:11:42 volumio volumio[977]: info: ------------------------------ 96ms Nov 29 15:11:42 volumio volumio[977]: info: ------------------------------ 95ms Nov 29 15:11:42 volumio volumio[977]: info: ------------------------------ 94ms Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:42 volumio volumio[977]: info: CorePlayQueue::getTrack 1 Nov 29 15:11:42 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 29 15:11:42 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:42 volumio volumio[977]: info: sendMpdCommand stop took 20 milliseconds Nov 29 15:11:42 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand clear Nov 29 15:11:42 volumio volumio[977]: info: Nov 29 15:11:42 volumio volumio[977]: ---------------------------- MPD announces system playlist update Nov 29 15:11:42 volumio volumio[977]: info: Ignoring MPD Status Update Nov 29 15:11:42 volumio volumio[977]: info: sendMpdCommand clear took 19 milliseconds Nov 29 15:11:42 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.0.12:50002/transcoder/genericoder.cgi/id=419728.wav?format=WAV&downsample=false" Nov 29 15:11:42 volumio volumio[977]: info: Nov 29 15:11:42 volumio volumio[977]: ---------------------------- MPD announces system playlist update Nov 29 15:11:42 volumio volumio[977]: info: Ignoring MPD Status Update Nov 29 15:11:42 volumio volumio[977]: info: Nov 29 15:11:42 volumio volumio[977]: ---------------------------- MPD announces system playlist update Nov 29 15:11:42 volumio volumio[977]: info: Ignoring MPD Status Update Nov 29 15:11:42 volumio volumio[977]: error: updateQueue error: null Nov 29 15:11:42 volumio volumio[977]: info: ------------------------------ 10ms Nov 29 15:11:42 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.0.12:50002/transcoder/genericoder.cgi/id=419728.wav?format=WAV&downsample=false" Nov 29 15:11:42 volumio volumio[977]: error: updateQueue error: null Nov 29 15:11:42 volumio volumio[977]: error: updateQueue error: null Nov 29 15:11:42 volumio volumio[977]: info: Nov 29 15:11:42 volumio volumio[977]: ---------------------------- MPD announces system playlist update Nov 29 15:11:42 volumio volumio[977]: info: Ignoring MPD Status Update Nov 29 15:11:42 volumio volumio[977]: info: ------------------------------ 91ms Nov 29 15:11:42 volumio volumio[977]: info: ------------------------------ 89ms Nov 29 15:11:42 volumio volumio[977]: info: sendMpdCommand add "http://192.168.0.12:50002/transcoder/genericoder.cgi/id=419728.wav?format=WAV&downsample=false" took 4 milliseconds Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 29 15:11:42 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand play Nov 29 15:11:42 volumio volumio[977]: info: Nov 29 15:11:42 volumio volumio[977]: ---------------------------- MPD announces system playlist update Nov 29 15:11:42 volumio volumio[977]: info: Ignoring MPD Status Update Nov 29 15:11:42 volumio volumio[977]: info: Nov 29 15:11:42 volumio volumio[977]: ---------------------------- MPD announces system playlist update Nov 29 15:11:42 volumio volumio[977]: info: Ignoring MPD Status Update Nov 29 15:11:42 volumio volumio[977]: info: ------------------------------ 11ms Nov 29 15:11:42 volumio volumio[977]: info: sendMpdCommand play took 8 milliseconds Nov 29 15:11:42 volumio volumio[977]: info: ------------------------------ 7ms Nov 29 15:11:42 volumio volumio[977]: info: Nov 29 15:11:42 volumio volumio[977]: ---------------------------- MPD announces state update: player Nov 29 15:11:42 volumio volumio[977]: info: ControllerMpd::getState Nov 29 15:11:42 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status Nov 29 15:11:42 volumio volumio[977]: info: Nov 29 15:11:42 volumio volumio[977]: ---------------------------- MPD announces state update: player Nov 29 15:11:42 volumio volumio[977]: info: ControllerMpd::getState Nov 29 15:11:42 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status Nov 29 15:11:42 volumio volumio[977]: info: Nov 29 15:11:42 volumio volumio[977]: ---------------------------- MPD announces state update: player Nov 29 15:11:42 volumio volumio[977]: info: ControllerMpd::getState Nov 29 15:11:42 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status Nov 29 15:11:42 volumio volumio[977]: info: sendMpdCommand status took 9 milliseconds Nov 29 15:11:42 volumio volumio[977]: info: sendMpdCommand status took 5 milliseconds Nov 29 15:11:42 volumio volumio[977]: verbose: ControllerMpd::parseState Nov 29 15:11:42 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 29 15:11:42 volumio volumio[977]: verbose: ControllerMpd::parseState Nov 29 15:11:42 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 29 15:11:42 volumio volumio[977]: info: Nov 29 15:11:42 volumio volumio[977]: ---------------------------- MPD announces state update: player Nov 29 15:11:42 volumio volumio[977]: info: ControllerMpd::getState Nov 29 15:11:42 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status Nov 29 15:11:42 volumio volumio[977]: info: Nov 29 15:11:42 volumio volumio[977]: ---------------------------- MPD announces state update: player Nov 29 15:11:42 volumio volumio[977]: info: ControllerMpd::getState Nov 29 15:11:42 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status Nov 29 15:11:42 volumio volumio[977]: info: sendMpdCommand status took 12 milliseconds Nov 29 15:11:42 volumio volumio[977]: info: sendMpdCommand playlistinfo took 10 milliseconds Nov 29 15:11:42 volumio volumio[977]: info: sendMpdCommand playlistinfo took 9 milliseconds Nov 29 15:11:42 volumio volumio[977]: info: sendMpdCommand status took 7 milliseconds Nov 29 15:11:42 volumio volumio[977]: info: sendMpdCommand status took 5 milliseconds Nov 29 15:11:42 volumio volumio[977]: verbose: ControllerMpd::parseState Nov 29 15:11:42 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 29 15:11:42 volumio volumio[977]: verbose: ControllerMpd::parseTrackInfo Nov 29 15:11:42 volumio volumio[977]: verbose: ControllerMpd::parseTrackInfo Nov 29 15:11:42 volumio volumio[977]: verbose: ControllerMpd::parseState Nov 29 15:11:42 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 29 15:11:42 volumio volumio[977]: verbose: ControllerMpd::parseState Nov 29 15:11:42 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 29 15:11:42 volumio volumio[977]: info: ControllerMpd::pushState Nov 29 15:11:42 volumio volumio[977]: info: CoreCommandRouter::servicePushState Nov 29 15:11:42 volumio volumio[977]: info: CorePlayQueue::getTrack 1 Nov 29 15:11:42 volumio volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":304,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"id=419728.wav?format=WAV&downsample=false","artist":null,"album":null,"uri":"http://192.168.0.12:50002/transcoder/genericoder.cgi/id=419728.wav?format=WAV&downsample=false","trackType":""} Nov 29 15:11:42 volumio volumio[977]: verbose: CURRENT POSITION 1 Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::syncState stateService play Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::syncState currentStatus stop Nov 29 15:11:42 volumio volumio[977]: info: ControllerMpd::pushState Nov 29 15:11:42 volumio volumio[977]: info: CoreCommandRouter::servicePushState Nov 29 15:11:42 volumio volumio[977]: info: CorePlayQueue::getTrack 1 Nov 29 15:11:42 volumio volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":304,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"id=419728.wav?format=WAV&downsample=false","artist":null,"album":null,"uri":"http://192.168.0.12:50002/transcoder/genericoder.cgi/id=419728.wav?format=WAV&downsample=false","trackType":""} Nov 29 15:11:42 volumio volumio[977]: verbose: CURRENT POSITION 1 Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::syncState stateService play Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::syncState currentStatus play Nov 29 15:11:42 volumio volumio[977]: info: Received an update from plugin. extracting info from payload Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:42 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 29 15:11:42 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:42 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:42 volumio volumio[977]: info: ------------------------------ 56ms Nov 29 15:11:42 volumio volumio[977]: info: ------------------------------ 75ms Nov 29 15:11:42 volumio volumio[977]: info: Nov 29 15:11:42 volumio volumio[977]: ---------------------------- MPD announces state update: player Nov 29 15:11:42 volumio volumio[977]: info: ControllerMpd::getState Nov 29 15:11:42 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status Nov 29 15:11:42 volumio volumio[977]: info: sendMpdCommand playlistinfo took 57 milliseconds Nov 29 15:11:42 volumio volumio[977]: info: sendMpdCommand playlistinfo took 54 milliseconds Nov 29 15:11:42 volumio volumio[977]: info: sendMpdCommand playlistinfo took 54 milliseconds Nov 29 15:11:42 volumio volumio[977]: info: sendMpdCommand status took 5 milliseconds Nov 29 15:11:42 volumio volumio[977]: verbose: ControllerMpd::parseTrackInfo Nov 29 15:11:42 volumio volumio[977]: verbose: ControllerMpd::parseTrackInfo Nov 29 15:11:42 volumio volumio[977]: verbose: ControllerMpd::parseTrackInfo Nov 29 15:11:42 volumio volumio[977]: verbose: ControllerMpd::parseState Nov 29 15:11:42 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 29 15:11:42 volumio volumio[977]: info: ControllerMpd::pushState Nov 29 15:11:42 volumio volumio[977]: info: CoreCommandRouter::servicePushState Nov 29 15:11:42 volumio volumio[977]: info: CorePlayQueue::getTrack 1 Nov 29 15:11:42 volumio volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":304,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"id=419728.wav?format=WAV&downsample=false","artist":null,"album":null,"uri":"http://192.168.0.12:50002/transcoder/genericoder.cgi/id=419728.wav?format=WAV&downsample=false","trackType":""} Nov 29 15:11:42 volumio volumio[977]: verbose: CURRENT POSITION 1 Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::syncState stateService play Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::syncState currentStatus play Nov 29 15:11:42 volumio volumio[977]: info: Received an update from plugin. extracting info from payload Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:42 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 29 15:11:42 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:42 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:42 volumio volumio[977]: info: ControllerMpd::pushState Nov 29 15:11:42 volumio volumio[977]: info: CoreCommandRouter::servicePushState Nov 29 15:11:42 volumio volumio[977]: info: CorePlayQueue::getTrack 1 Nov 29 15:11:42 volumio volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":304,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"id=419728.wav?format=WAV&downsample=false","artist":null,"album":null,"uri":"http://192.168.0.12:50002/transcoder/genericoder.cgi/id=419728.wav?format=WAV&downsample=false","trackType":""} Nov 29 15:11:42 volumio volumio[977]: verbose: CURRENT POSITION 1 Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::syncState stateService play Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::syncState currentStatus play Nov 29 15:11:42 volumio volumio[977]: info: Received an update from plugin. extracting info from payload Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:42 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:42 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:42 volumio volumio[977]: info: ControllerMpd::pushState Nov 29 15:11:42 volumio volumio[977]: info: CoreCommandRouter::servicePushState Nov 29 15:11:42 volumio volumio[977]: info: CorePlayQueue::getTrack 1 Nov 29 15:11:42 volumio volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":304,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"id=419728.wav?format=WAV&downsample=false","artist":null,"album":null,"uri":"http://192.168.0.12:50002/transcoder/genericoder.cgi/id=419728.wav?format=WAV&downsample=false","trackType":""} Nov 29 15:11:42 volumio volumio[977]: verbose: CURRENT POSITION 1 Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::syncState stateService play Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::syncState currentStatus play Nov 29 15:11:42 volumio volumio[977]: info: Received an update from plugin. extracting info from payload Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:42 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:42 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:42 volumio volumio[977]: info: ------------------------------ 194ms Nov 29 15:11:42 volumio volumio[977]: info: ------------------------------ 188ms Nov 29 15:11:42 volumio volumio[977]: info: ------------------------------ 188ms Nov 29 15:11:42 volumio volumio[977]: info: sendMpdCommand playlistinfo took 139 milliseconds Nov 29 15:11:42 volumio volumio[977]: verbose: ControllerMpd::parseTrackInfo Nov 29 15:11:42 volumio volumio[977]: info: ControllerMpd::pushState Nov 29 15:11:42 volumio volumio[977]: info: CoreCommandRouter::servicePushState Nov 29 15:11:42 volumio volumio[977]: info: CorePlayQueue::getTrack 1 Nov 29 15:11:42 volumio volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":846,"duration":304,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"id=419728.wav?format=WAV&downsample=false","artist":null,"album":null,"uri":"http://192.168.0.12:50002/transcoder/genericoder.cgi/id=419728.wav?format=WAV&downsample=false","trackType":""} Nov 29 15:11:42 volumio volumio[977]: verbose: CURRENT POSITION 1 Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::syncState stateService play Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::syncState currentStatus play Nov 29 15:11:42 volumio volumio[977]: info: Received an update from plugin. extracting info from payload Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:42 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 29 15:11:42 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:42 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:11:42 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:11:42 volumio volumio[977]: info: ------------------------------ 184ms Nov 29 15:11:46 volumio volumio[977]: info: Listing playlists Nov 29 15:11:52 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 29 15:11:52 volumio volumio[977]: info: Preload queue cleared Nov 29 15:11:52 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@398947 Nov 29 15:11:52 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@398948 Nov 29 15:11:52 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@398949 Nov 29 15:11:52 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@398950 Nov 29 15:11:52 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@398951 Nov 29 15:11:52 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@398952 Nov 29 15:11:52 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@398953 Nov 29 15:11:52 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@398954 Nov 29 15:11:52 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@398955 Nov 29 15:11:52 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@398956 Nov 29 15:11:52 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@398957 Nov 29 15:11:52 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@398958 Nov 29 15:11:52 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@398959 Nov 29 15:11:52 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@398960 Nov 29 15:11:52 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@398961 Nov 29 15:11:52 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@398962 Nov 29 15:11:52 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@398963 Nov 29 15:11:52 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@398964 Nov 29 15:11:52 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@398947 in service upnp_browser Nov 29 15:11:52 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@398948 in service upnp_browser Nov 29 15:11:53 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@398949 in service upnp_browser Nov 29 15:11:53 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@398950 in service upnp_browser Nov 29 15:11:53 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@398951 in service upnp_browser Nov 29 15:11:53 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@398952 in service upnp_browser Nov 29 15:11:53 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@398953 in service upnp_browser Nov 29 15:11:53 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@398954 in service upnp_browser Nov 29 15:11:53 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@398955 in service upnp_browser Nov 29 15:11:53 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@398956 in service upnp_browser Nov 29 15:11:53 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@398957 in service upnp_browser Nov 29 15:11:53 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@398958 in service upnp_browser Nov 29 15:11:53 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@398959 in service upnp_browser Nov 29 15:11:53 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@398960 in service upnp_browser Nov 29 15:11:53 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@398961 in service upnp_browser Nov 29 15:11:53 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@398962 in service upnp_browser Nov 29 15:11:53 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@398963 in service upnp_browser Nov 29 15:11:53 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@398964 in service upnp_browser Nov 29 15:11:57 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 29 15:11:57 volumio volumio[977]: info: Preload queue cleared Nov 29 15:11:58 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 29 15:11:58 volumio volumio[977]: info: Preload queue cleared Nov 29 15:11:58 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408146 Nov 29 15:11:58 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408147 Nov 29 15:11:58 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408150 Nov 29 15:11:58 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408143 Nov 29 15:11:58 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408144 Nov 29 15:11:58 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408145 Nov 29 15:11:58 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408148 Nov 29 15:11:58 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408149 Nov 29 15:11:58 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408146 in service upnp_browser Nov 29 15:11:58 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408147 in service upnp_browser Nov 29 15:11:58 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408150 in service upnp_browser Nov 29 15:11:58 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408143 in service upnp_browser Nov 29 15:11:59 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408144 in service upnp_browser Nov 29 15:11:59 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408145 in service upnp_browser Nov 29 15:11:59 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408148 in service upnp_browser Nov 29 15:11:59 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408149 in service upnp_browser Nov 29 15:12:00 volumio volumio[977]: info: Preload queue cleared Nov 29 15:12:00 volumio volumio[977]: info: CoreCommandRouter::volumioReplaceandPlayItems Nov 29 15:12:00 volumio volumio[977]: info: CoreStateMachine::ClearQueue Nov 29 15:12:00 volumio volumio[977]: info: CoreStateMachine::stop Nov 29 15:12:00 volumio volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 15:12:00 volumio volumio[977]: info: CoreStateMachine::stPlaybackTimer Nov 29 15:12:00 volumio volumio[977]: info: CoreStateMachine::updateTrackBlock Nov 29 15:12:00 volumio volumio[977]: info: CorePlayQueue::getTrackBlock Nov 29 15:12:00 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:12:00 volumio volumio[977]: info: CorePlayQueue::getTrack 1 Nov 29 15:12:00 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 29 15:12:00 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:12:00 volumio volumio[977]: info: CoreStateMachine::serviceStop Nov 29 15:12:00 volumio volumio[977]: info: CorePlayQueue::getTrack 1 Nov 29 15:12:00 volumio volumio[977]: info: CoreCommandRouter::serviceStop Nov 29 15:12:00 volumio volumio[977]: info: [1732860720102] ControllerUPNPBrowser::stop Nov 29 15:12:00 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand stop Nov 29 15:12:00 volumio volumio[977]: info: CorePlayQueue::clearPlayQueue Nov 29 15:12:00 volumio volumio[977]: info: CorePlayQueue::saveQueue Nov 29 15:12:00 volumio volumio[977]: info: CoreCommandRouter::volumioPushQueue Nov 29 15:12:00 volumio volumio[977]: info: CoreStateMachine::addQueueItems Nov 29 15:12:00 volumio volumio[977]: info: CorePlayQueue::addQueueItems Nov 29 15:12:00 volumio volumio[977]: info: Preload queue cleared Nov 29 15:12:00 volumio volumio[977]: info: Adding Item to queue: upnp/folder/http://192.168.0.12:50001/ContentDirectory/control@22$33092 Nov 29 15:12:00 volumio volumio[977]: info: Exploding uri upnp/folder/http://192.168.0.12:50001/ContentDirectory/control@22$33092 in service upnp_browser Nov 29 15:12:00 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408146 Nov 29 15:12:00 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408146 Nov 29 15:12:00 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408147 Nov 29 15:12:00 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408147 Nov 29 15:12:00 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408150 Nov 29 15:12:00 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408150 Nov 29 15:12:00 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408143 Nov 29 15:12:00 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408143 Nov 29 15:12:00 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408144 Nov 29 15:12:00 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408144 Nov 29 15:12:00 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408145 Nov 29 15:12:00 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408145 Nov 29 15:12:00 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408148 Nov 29 15:12:00 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408148 Nov 29 15:12:00 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408149 Nov 29 15:12:00 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408149 Nov 29 15:12:00 volumio volumio[977]: info: sendMpdCommand stop took 32 milliseconds Nov 29 15:12:00 volumio volumio[977]: info: Nov 29 15:12:00 volumio volumio[977]: ---------------------------- MPD announces state update: player Nov 29 15:12:00 volumio volumio[977]: info: ControllerMpd::getState Nov 29 15:12:00 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status Nov 29 15:12:00 volumio volumio[977]: info: Nov 29 15:12:00 volumio volumio[977]: ---------------------------- MPD announces state update: player Nov 29 15:12:00 volumio volumio[977]: info: ControllerMpd::getState Nov 29 15:12:00 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status Nov 29 15:12:00 volumio volumio[977]: info: Nov 29 15:12:00 volumio volumio[977]: ---------------------------- MPD announces state update: player Nov 29 15:12:00 volumio volumio[977]: info: ControllerMpd::getState Nov 29 15:12:00 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand status Nov 29 15:12:00 volumio volumio[977]: info: CoreCommandRouter::volumioPushQueue Nov 29 15:12:00 volumio volumio[977]: info: CorePlayQueue::saveQueue Nov 29 15:12:00 volumio volumio[977]: info: CoreStateMachine::updateTrackBlock Nov 29 15:12:00 volumio volumio[977]: info: CorePlayQueue::getTrackBlock Nov 29 15:12:00 volumio volumio[977]: info: CoreCommandRouter::volumioPlay Nov 29 15:12:00 volumio volumio[977]: info: CoreStateMachine::play index 1 Nov 29 15:12:00 volumio volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 15:12:00 volumio volumio[977]: info: CoreStateMachine::stop Nov 29 15:12:00 volumio volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 15:12:00 volumio volumio[977]: info: CoreStateMachine::play index undefined Nov 29 15:12:00 volumio volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 15:12:00 volumio volumio[977]: info: CorePlayQueue::getTrack 1 Nov 29 15:12:00 volumio volumio[977]: info: sendMpdCommand status took 22 milliseconds Nov 29 15:12:00 volumio volumio[977]: info: sendMpdCommand status took 21 milliseconds Nov 29 15:12:00 volumio volumio[977]: info: sendMpdCommand status took 20 milliseconds Nov 29 15:12:00 volumio volumio[977]: verbose: ControllerMpd::parseState Nov 29 15:12:00 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 29 15:12:00 volumio volumio[977]: verbose: ControllerMpd::parseState Nov 29 15:12:00 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 29 15:12:00 volumio volumio[977]: verbose: ControllerMpd::parseState Nov 29 15:12:00 volumio volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 29 15:12:00 volumio volumio[977]: info: sendMpdCommand playlistinfo took 5 milliseconds Nov 29 15:12:00 volumio volumio[977]: info: sendMpdCommand playlistinfo took 5 milliseconds Nov 29 15:12:00 volumio volumio[977]: info: sendMpdCommand playlistinfo took 6 milliseconds Nov 29 15:12:00 volumio volumio[977]: verbose: ControllerMpd::parseTrackInfo Nov 29 15:12:00 volumio volumio[977]: verbose: ControllerMpd::parseTrackInfo Nov 29 15:12:00 volumio volumio[977]: verbose: ControllerMpd::parseTrackInfo Nov 29 15:12:00 volumio volumio[977]: info: ControllerMpd::pushState Nov 29 15:12:00 volumio volumio[977]: info: CoreCommandRouter::servicePushState Nov 29 15:12:00 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:12:00 volumio volumio[977]: info: CorePlayQueue::getTrack 0 Nov 29 15:12:00 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 29 15:12:00 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:12:00 volumio volumio[977]: info: CorePlayQueue::getTrack 0 Nov 29 15:12:00 volumio volumio[977]: 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":"id=419728.wav?format=WAV&downsample=false","artist":null,"album":null,"uri":"http://192.168.0.12:50002/transcoder/genericoder.cgi/id=419728.wav?format=WAV&downsample=false","trackType":""} Nov 29 15:12:00 volumio volumio[977]: verbose: CURRENT POSITION 0 Nov 29 15:12:00 volumio volumio[977]: info: CoreStateMachine::syncState stateService stop Nov 29 15:12:00 volumio volumio[977]: info: CoreStateMachine::syncState currentStatus stop Nov 29 15:12:00 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:12:00 volumio volumio[977]: info: CorePlayQueue::getTrack 0 Nov 29 15:12:00 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:12:00 volumio volumio[977]: info: No code Nov 29 15:12:00 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:12:00 volumio volumio[977]: info: CorePlayQueue::getTrack 0 Nov 29 15:12:00 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:12:00 volumio volumio[977]: info: ControllerMpd::pushState Nov 29 15:12:00 volumio volumio[977]: info: CoreCommandRouter::servicePushState Nov 29 15:12:00 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:12:00 volumio volumio[977]: info: CorePlayQueue::getTrack 0 Nov 29 15:12:00 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:12:00 volumio volumio[977]: info: CorePlayQueue::getTrack 0 Nov 29 15:12:00 volumio volumio[977]: 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":"id=419728.wav?format=WAV&downsample=false","artist":null,"album":null,"uri":"http://192.168.0.12:50002/transcoder/genericoder.cgi/id=419728.wav?format=WAV&downsample=false","trackType":""} Nov 29 15:12:00 volumio volumio[977]: verbose: CURRENT POSITION 0 Nov 29 15:12:00 volumio volumio[977]: info: CoreStateMachine::syncState stateService stop Nov 29 15:12:00 volumio volumio[977]: info: CoreStateMachine::syncState currentStatus stop Nov 29 15:12:00 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:12:00 volumio volumio[977]: info: CorePlayQueue::getTrack 0 Nov 29 15:12:00 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:12:00 volumio volumio[977]: info: No code Nov 29 15:12:00 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:12:00 volumio volumio[977]: info: CorePlayQueue::getTrack 0 Nov 29 15:12:00 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:12:00 volumio volumio[977]: info: ControllerMpd::pushState Nov 29 15:12:00 volumio volumio[977]: info: CoreCommandRouter::servicePushState Nov 29 15:12:00 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:12:00 volumio volumio[977]: info: CorePlayQueue::getTrack 0 Nov 29 15:12:00 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:12:00 volumio volumio[977]: info: CorePlayQueue::getTrack 0 Nov 29 15:12:00 volumio volumio[977]: 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":"id=419728.wav?format=WAV&downsample=false","artist":null,"album":null,"uri":"http://192.168.0.12:50002/transcoder/genericoder.cgi/id=419728.wav?format=WAV&downsample=false","trackType":""} Nov 29 15:12:00 volumio volumio[977]: verbose: CURRENT POSITION 0 Nov 29 15:12:00 volumio volumio[977]: info: CoreStateMachine::syncState stateService stop Nov 29 15:12:00 volumio volumio[977]: info: CoreStateMachine::syncState currentStatus stop Nov 29 15:12:00 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:12:00 volumio volumio[977]: info: CorePlayQueue::getTrack 0 Nov 29 15:12:00 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:12:00 volumio volumio[977]: info: No code Nov 29 15:12:00 volumio volumio[977]: info: CoreStateMachine::pushState Nov 29 15:12:00 volumio volumio[977]: info: CorePlayQueue::getTrack 0 Nov 29 15:12:00 volumio volumio[977]: info: CoreCommandRouter::volumioPushState Nov 29 15:12:00 volumio volumio[977]: info: ------------------------------ 116ms Nov 29 15:12:00 volumio volumio[977]: info: ------------------------------ 116ms Nov 29 15:12:00 volumio volumio[977]: info: ------------------------------ 116ms Nov 29 15:12:02 volumio volumio[977]: info: Preload queue cleared Nov 29 15:12:02 volumio volumio[977]: info: CoreCommandRouter::volumioReplaceandPlayItems Nov 29 15:12:02 volumio volumio[977]: info: CoreStateMachine::ClearQueue Nov 29 15:12:02 volumio volumio[977]: info: CoreStateMachine::stop Nov 29 15:12:02 volumio volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 15:12:02 volumio volumio[977]: info: CorePlayQueue::clearPlayQueue Nov 29 15:12:02 volumio volumio[977]: info: CorePlayQueue::saveQueue Nov 29 15:12:02 volumio volumio[977]: info: CoreCommandRouter::volumioPushQueue Nov 29 15:12:02 volumio volumio[977]: info: CoreStateMachine::addQueueItems Nov 29 15:12:02 volumio volumio[977]: info: CorePlayQueue::addQueueItems Nov 29 15:12:02 volumio volumio[977]: info: Preload queue cleared Nov 29 15:12:02 volumio volumio[977]: info: Adding Item to queue: upnp/folder/http://192.168.0.12:50001/ContentDirectory/control@22$33092 Nov 29 15:12:02 volumio volumio[977]: info: Using cached record of: upnp/folder/http://192.168.0.12:50001/ContentDirectory/control@22$33092 Nov 29 15:12:02 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408146 Nov 29 15:12:02 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408146 Nov 29 15:12:02 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408147 Nov 29 15:12:02 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408147 Nov 29 15:12:02 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408150 Nov 29 15:12:02 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408150 Nov 29 15:12:02 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408143 Nov 29 15:12:02 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408143 Nov 29 15:12:02 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408144 Nov 29 15:12:02 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408144 Nov 29 15:12:02 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408145 Nov 29 15:12:02 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408145 Nov 29 15:12:02 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408148 Nov 29 15:12:02 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408148 Nov 29 15:12:02 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408149 Nov 29 15:12:02 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408149 Nov 29 15:12:02 volumio volumio[977]: info: CoreCommandRouter::volumioPushQueue Nov 29 15:12:02 volumio volumio[977]: info: CorePlayQueue::saveQueue Nov 29 15:12:02 volumio volumio[977]: info: CoreStateMachine::updateTrackBlock Nov 29 15:12:02 volumio volumio[977]: info: CorePlayQueue::getTrackBlock Nov 29 15:12:02 volumio volumio[977]: info: CoreCommandRouter::volumioPlay Nov 29 15:12:02 volumio volumio[977]: info: CoreStateMachine::play index 1 Nov 29 15:12:02 volumio volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 15:12:02 volumio volumio[977]: info: CoreStateMachine::stop Nov 29 15:12:02 volumio volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 15:12:02 volumio volumio[977]: info: CoreStateMachine::play index undefined Nov 29 15:12:02 volumio volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 15:12:02 volumio volumio[977]: info: CorePlayQueue::getTrack 1 Nov 29 15:12:02 volumio volumio[977]: info: Preload queue cleared Nov 29 15:12:02 volumio volumio[977]: info: CoreCommandRouter::volumioReplaceandPlayItems Nov 29 15:12:02 volumio volumio[977]: info: CoreStateMachine::ClearQueue Nov 29 15:12:02 volumio volumio[977]: info: CoreStateMachine::stop Nov 29 15:12:02 volumio volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 15:12:02 volumio volumio[977]: info: CorePlayQueue::clearPlayQueue Nov 29 15:12:02 volumio volumio[977]: info: CorePlayQueue::saveQueue Nov 29 15:12:02 volumio volumio[977]: info: CoreCommandRouter::volumioPushQueue Nov 29 15:12:02 volumio volumio[977]: info: CoreStateMachine::addQueueItems Nov 29 15:12:02 volumio volumio[977]: info: CorePlayQueue::addQueueItems Nov 29 15:12:02 volumio volumio[977]: info: Preload queue cleared Nov 29 15:12:02 volumio volumio[977]: info: Adding Item to queue: upnp/folder/http://192.168.0.12:50001/ContentDirectory/control@22$33092 Nov 29 15:12:02 volumio volumio[977]: info: Using cached record of: upnp/folder/http://192.168.0.12:50001/ContentDirectory/control@22$33092 Nov 29 15:12:02 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408146 Nov 29 15:12:02 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408146 Nov 29 15:12:02 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408147 Nov 29 15:12:02 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408147 Nov 29 15:12:02 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408150 Nov 29 15:12:02 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408150 Nov 29 15:12:02 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408143 Nov 29 15:12:02 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408143 Nov 29 15:12:02 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408144 Nov 29 15:12:02 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408144 Nov 29 15:12:02 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408145 Nov 29 15:12:02 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408145 Nov 29 15:12:02 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408148 Nov 29 15:12:02 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408148 Nov 29 15:12:02 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408149 Nov 29 15:12:02 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408149 Nov 29 15:12:02 volumio volumio[977]: info: CoreCommandRouter::volumioPushQueue Nov 29 15:12:02 volumio volumio[977]: info: CorePlayQueue::saveQueue Nov 29 15:12:02 volumio volumio[977]: info: CoreStateMachine::updateTrackBlock Nov 29 15:12:02 volumio volumio[977]: info: CorePlayQueue::getTrackBlock Nov 29 15:12:02 volumio volumio[977]: info: CoreCommandRouter::volumioPlay Nov 29 15:12:02 volumio volumio[977]: info: CoreStateMachine::play index 2 Nov 29 15:12:02 volumio volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 15:12:02 volumio volumio[977]: info: CoreStateMachine::stop Nov 29 15:12:02 volumio volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 15:12:02 volumio volumio[977]: info: CoreStateMachine::play index undefined Nov 29 15:12:02 volumio volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 15:12:02 volumio volumio[977]: info: CorePlayQueue::getTrack 2 Nov 29 15:12:03 volumio volumio[977]: info: Preload queue cleared Nov 29 15:12:03 volumio volumio[977]: info: CoreCommandRouter::volumioReplaceandPlayItems Nov 29 15:12:03 volumio volumio[977]: info: CoreStateMachine::ClearQueue Nov 29 15:12:03 volumio volumio[977]: info: CoreStateMachine::stop Nov 29 15:12:03 volumio volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 15:12:03 volumio volumio[977]: info: CorePlayQueue::clearPlayQueue Nov 29 15:12:03 volumio volumio[977]: info: CorePlayQueue::saveQueue Nov 29 15:12:03 volumio volumio[977]: info: CoreCommandRouter::volumioPushQueue Nov 29 15:12:03 volumio volumio[977]: info: CoreStateMachine::addQueueItems Nov 29 15:12:03 volumio volumio[977]: info: CorePlayQueue::addQueueItems Nov 29 15:12:03 volumio volumio[977]: info: Preload queue cleared Nov 29 15:12:03 volumio volumio[977]: info: Adding Item to queue: upnp/folder/http://192.168.0.12:50001/ContentDirectory/control@22$33092 Nov 29 15:12:03 volumio volumio[977]: info: Using cached record of: upnp/folder/http://192.168.0.12:50001/ContentDirectory/control@22$33092 Nov 29 15:12:03 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408146 Nov 29 15:12:03 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408146 Nov 29 15:12:03 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408147 Nov 29 15:12:03 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408147 Nov 29 15:12:03 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408150 Nov 29 15:12:03 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408150 Nov 29 15:12:03 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408143 Nov 29 15:12:03 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408143 Nov 29 15:12:03 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408144 Nov 29 15:12:03 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408144 Nov 29 15:12:03 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408145 Nov 29 15:12:03 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408145 Nov 29 15:12:03 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408148 Nov 29 15:12:03 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408148 Nov 29 15:12:03 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408149 Nov 29 15:12:03 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408149 Nov 29 15:12:03 volumio volumio[977]: info: CoreCommandRouter::volumioPushQueue Nov 29 15:12:03 volumio volumio[977]: info: CorePlayQueue::saveQueue Nov 29 15:12:03 volumio volumio[977]: info: CoreStateMachine::updateTrackBlock Nov 29 15:12:03 volumio volumio[977]: info: CorePlayQueue::getTrackBlock Nov 29 15:12:03 volumio volumio[977]: info: CoreCommandRouter::volumioPlay Nov 29 15:12:03 volumio volumio[977]: info: CoreStateMachine::play index 4 Nov 29 15:12:03 volumio volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 15:12:03 volumio volumio[977]: info: CoreStateMachine::stop Nov 29 15:12:03 volumio volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 15:12:03 volumio volumio[977]: info: CoreStateMachine::play index undefined Nov 29 15:12:03 volumio volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 15:12:03 volumio volumio[977]: info: CorePlayQueue::getTrack 4 Nov 29 15:12:07 volumio volumio[977]: info: Preload queue cleared Nov 29 15:12:07 volumio volumio[977]: info: CoreCommandRouter::volumioReplaceandPlayItems Nov 29 15:12:07 volumio volumio[977]: info: CoreStateMachine::ClearQueue Nov 29 15:12:07 volumio volumio[977]: info: CoreStateMachine::stop Nov 29 15:12:07 volumio volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 15:12:07 volumio volumio[977]: info: CorePlayQueue::clearPlayQueue Nov 29 15:12:07 volumio volumio[977]: info: CorePlayQueue::saveQueue Nov 29 15:12:07 volumio volumio[977]: info: CoreCommandRouter::volumioPushQueue Nov 29 15:12:07 volumio volumio[977]: info: CoreStateMachine::addQueueItems Nov 29 15:12:07 volumio volumio[977]: info: CorePlayQueue::addQueueItems Nov 29 15:12:07 volumio volumio[977]: info: Preload queue cleared Nov 29 15:12:07 volumio volumio[977]: info: Adding Item to queue: upnp/folder/http://192.168.0.12:50001/ContentDirectory/control@22$33092 Nov 29 15:12:07 volumio volumio[977]: info: Using cached record of: upnp/folder/http://192.168.0.12:50001/ContentDirectory/control@22$33092 Nov 29 15:12:07 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408146 Nov 29 15:12:07 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408146 Nov 29 15:12:07 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408147 Nov 29 15:12:07 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408147 Nov 29 15:12:07 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408150 Nov 29 15:12:07 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408150 Nov 29 15:12:07 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408143 Nov 29 15:12:07 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408143 Nov 29 15:12:07 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408144 Nov 29 15:12:07 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408144 Nov 29 15:12:07 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408145 Nov 29 15:12:07 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408145 Nov 29 15:12:07 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408148 Nov 29 15:12:07 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408148 Nov 29 15:12:07 volumio volumio[977]: info: Adding Item to queue: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408149 Nov 29 15:12:07 volumio volumio[977]: info: Using cached record of: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408149 Nov 29 15:12:07 volumio volumio[977]: info: CoreCommandRouter::volumioPushQueue Nov 29 15:12:07 volumio volumio[977]: info: CorePlayQueue::saveQueue Nov 29 15:12:07 volumio volumio[977]: info: CoreStateMachine::updateTrackBlock Nov 29 15:12:07 volumio volumio[977]: info: CorePlayQueue::getTrackBlock Nov 29 15:12:07 volumio volumio[977]: info: CoreCommandRouter::volumioPlay Nov 29 15:12:07 volumio volumio[977]: info: CoreStateMachine::play index 3 Nov 29 15:12:07 volumio volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 15:12:07 volumio volumio[977]: info: CoreStateMachine::stop Nov 29 15:12:07 volumio volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 15:12:07 volumio volumio[977]: info: CoreStateMachine::play index undefined Nov 29 15:12:07 volumio volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 15:12:07 volumio volumio[977]: info: CorePlayQueue::getTrack 3 Nov 29 15:12:11 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 29 15:12:11 volumio volumio[977]: info: Preload queue cleared Nov 29 15:12:11 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408181 Nov 29 15:12:11 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408183 Nov 29 15:12:11 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408182 Nov 29 15:12:11 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408184 Nov 29 15:12:11 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408185 Nov 29 15:12:11 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408186 Nov 29 15:12:11 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408187 Nov 29 15:12:11 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408188 Nov 29 15:12:11 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408189 Nov 29 15:12:11 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408190 Nov 29 15:12:11 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408191 Nov 29 15:12:11 volumio volumio[977]: info: Preloading song: upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408192 Nov 29 15:12:11 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408181 in service upnp_browser Nov 29 15:12:11 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408183 in service upnp_browser Nov 29 15:12:11 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408182 in service upnp_browser Nov 29 15:12:11 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408184 in service upnp_browser Nov 29 15:12:11 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408185 in service upnp_browser Nov 29 15:12:11 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408186 in service upnp_browser Nov 29 15:12:11 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408187 in service upnp_browser Nov 29 15:12:11 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408188 in service upnp_browser Nov 29 15:12:11 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408189 in service upnp_browser Nov 29 15:12:11 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408190 in service upnp_browser Nov 29 15:12:11 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408191 in service upnp_browser Nov 29 15:12:11 volumio volumio[977]: info: Exploding uri upnp/http://192.168.0.12:50001/ContentDirectory/control@22$@408192 in service upnp_browser Nov 29 15:12:16 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 29 15:12:17 volumio volumio[977]: info: Preload queue cleared Nov 29 15:12:19 volumio volumio[977]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 29 15:12:20 volumio volumio[977]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 29 15:12:20 volumio volumio[977]: TypeError: Cannot read property 'length' of undefined Nov 29 15:12:20 volumio volumio[977]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Nov 29 15:12:20 volumio volumio[977]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Nov 29 15:12:20 volumio volumio[977]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Nov 29 15:12:20 volumio volumio[977]: at Parser.emit (events.js:315:20) Nov 29 15:12:20 volumio volumio[977]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Nov 29 15:12:20 volumio volumio[977]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Nov 29 15:12:20 volumio volumio[977]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Nov 29 15:12:20 volumio volumio[977]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Nov 29 15:12:20 volumio volumio[977]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Nov 29 15:12:20 volumio volumio[977]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Nov 29 15:12:20 volumio volumio[977]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Nov 29 15:12:20 volumio volumio[977]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Nov 29 15:12:20 volumio volumio[977]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Nov 29 15:12:20 volumio volumio[977]: at IncomingMessage.emit (events.js:327:22) Nov 29 15:12:20 volumio volumio[977]: at endReadableNT (internal/streams/readable.js:1327:12) Nov 29 15:12:20 volumio volumio[977]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Nov 29 15:12:20 volumio volumio[977]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 29 15:12:20 volumio sudo[1778]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-29 15:11 Nov 29 15:12:20 volumio sudo[1778]: 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="bba9e3185e150dd0995f9a49355b34fc6218d5a2" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 05:01:09 PM CEST" VOLUMIO_VERSION="3.757" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="e0a6dc7e914e3fb93cbf2123f2f73eac"