-- Logs begin at Thu 2019-02-14 18:12:00 CST, end at Wed 2025-01-15 16:19:04 CST. -- Jan 15 16:18:07 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 15 16:18:08 volumio volumio[923]: info: Preload queue cleared Jan 15 16:18:08 volumio volumio[923]: info: Preloading song: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660210436 Jan 15 16:18:08 volumio volumio[923]: info: Preloading song: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660407044 Jan 15 16:18:08 volumio volumio[923]: info: Preloading song: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660603652 Jan 15 16:18:08 volumio volumio[923]: info: Preloading song: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660669188 Jan 15 16:18:08 volumio volumio[923]: info: Preloading song: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660931332 Jan 15 16:18:08 volumio volumio[923]: info: Preloading song: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660013828 Jan 15 16:18:08 volumio volumio[923]: info: Preloading song: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660865796 Jan 15 16:18:08 volumio volumio[923]: info: Preloading song: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660800260 Jan 15 16:18:08 volumio volumio[923]: info: Preloading song: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660079364 Jan 15 16:18:08 volumio volumio[923]: info: Preloading song: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660734724 Jan 15 16:18:08 volumio volumio[923]: info: Preloading song: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660341508 Jan 15 16:18:08 volumio volumio[923]: info: Preloading song: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19659948292 Jan 15 16:18:08 volumio volumio[923]: info: Preloading song: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660275972 Jan 15 16:18:08 volumio volumio[923]: info: Preloading song: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660144900 Jan 15 16:18:08 volumio volumio[923]: info: Preloading song: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660538116 Jan 15 16:18:08 volumio volumio[923]: info: Preloading song: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660472580 Jan 15 16:18:08 volumio volumio[923]: info: Exploding uri upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660210436 in service upnp_browser Jan 15 16:18:08 volumio volumio[923]: info: Exploding uri upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660407044 in service upnp_browser Jan 15 16:18:08 volumio volumio[923]: info: Exploding uri upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660603652 in service upnp_browser Jan 15 16:18:08 volumio volumio[923]: info: Exploding uri upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660669188 in service upnp_browser Jan 15 16:18:08 volumio volumio[923]: info: Exploding uri upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660931332 in service upnp_browser Jan 15 16:18:08 volumio volumio[923]: info: Exploding uri upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660013828 in service upnp_browser Jan 15 16:18:08 volumio volumio[923]: info: Exploding uri upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660865796 in service upnp_browser Jan 15 16:18:08 volumio volumio[923]: info: Exploding uri upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660800260 in service upnp_browser Jan 15 16:18:08 volumio volumio[923]: info: Exploding uri upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660079364 in service upnp_browser Jan 15 16:18:08 volumio volumio[923]: info: Exploding uri upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660734724 in service upnp_browser Jan 15 16:18:08 volumio volumio[923]: info: Exploding uri upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660341508 in service upnp_browser Jan 15 16:18:08 volumio volumio[923]: info: Exploding uri upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19659948292 in service upnp_browser Jan 15 16:18:08 volumio volumio[923]: info: Exploding uri upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660275972 in service upnp_browser Jan 15 16:18:08 volumio volumio[923]: info: Exploding uri upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660144900 in service upnp_browser Jan 15 16:18:08 volumio volumio[923]: info: Exploding uri upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660538116 in service upnp_browser Jan 15 16:18:08 volumio volumio[923]: info: Exploding uri upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660472580 in service upnp_browser Jan 15 16:18:11 volumio volumio[923]: info: Preload queue cleared Jan 15 16:18:11 volumio volumio[923]: info: CoreCommandRouter::volumioReplaceandPlayItems Jan 15 16:18:11 volumio volumio[923]: info: CoreStateMachine::ClearQueue Jan 15 16:18:11 volumio volumio[923]: info: CoreStateMachine::stop Jan 15 16:18:11 volumio volumio[923]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 15 16:18:11 volumio volumio[923]: info: CorePlayQueue::clearPlayQueue Jan 15 16:18:11 volumio volumio[923]: info: CorePlayQueue::saveQueue Jan 15 16:18:11 volumio volumio[923]: info: CoreCommandRouter::volumioPushQueue Jan 15 16:18:11 volumio volumio[923]: info: CoreStateMachine::addQueueItems Jan 15 16:18:11 volumio volumio[923]: info: CorePlayQueue::addQueueItems Jan 15 16:18:11 volumio volumio[923]: info: Preload queue cleared Jan 15 16:18:11 volumio volumio[923]: info: Adding Item to queue: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660210436 Jan 15 16:18:11 volumio volumio[923]: info: Using cached record of: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660210436 Jan 15 16:18:11 volumio volumio[923]: info: CoreCommandRouter::volumioPushQueue Jan 15 16:18:11 volumio volumio[923]: info: CorePlayQueue::saveQueue Jan 15 16:18:11 volumio volumio[923]: info: CoreStateMachine::updateTrackBlock Jan 15 16:18:11 volumio volumio[923]: info: CorePlayQueue::getTrackBlock Jan 15 16:18:11 volumio volumio[923]: info: CoreCommandRouter::volumioPlay Jan 15 16:18:11 volumio volumio[923]: info: CoreStateMachine::play index 0 Jan 15 16:18:11 volumio volumio[923]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 15 16:18:11 volumio volumio[923]: info: CoreStateMachine::addQueueItems Jan 15 16:18:11 volumio volumio[923]: info: CorePlayQueue::addQueueItems Jan 15 16:18:11 volumio volumio[923]: info: Preload queue cleared Jan 15 16:18:11 volumio volumio[923]: info: Adding Item to queue: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660407044 Jan 15 16:18:11 volumio volumio[923]: info: Using cached record of: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660407044 Jan 15 16:18:11 volumio volumio[923]: info: Adding Item to queue: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660603652 Jan 15 16:18:11 volumio volumio[923]: info: Using cached record of: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660603652 Jan 15 16:18:11 volumio volumio[923]: info: Adding Item to queue: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660669188 Jan 15 16:18:11 volumio volumio[923]: info: Using cached record of: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660669188 Jan 15 16:18:11 volumio volumio[923]: info: Adding Item to queue: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660931332 Jan 15 16:18:11 volumio volumio[923]: info: Using cached record of: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660931332 Jan 15 16:18:11 volumio volumio[923]: info: Adding Item to queue: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660013828 Jan 15 16:18:11 volumio volumio[923]: info: Using cached record of: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660013828 Jan 15 16:18:11 volumio volumio[923]: info: Adding Item to queue: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660865796 Jan 15 16:18:11 volumio volumio[923]: info: Using cached record of: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660865796 Jan 15 16:18:11 volumio volumio[923]: info: Adding Item to queue: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660800260 Jan 15 16:18:11 volumio volumio[923]: info: Using cached record of: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660800260 Jan 15 16:18:11 volumio volumio[923]: info: Adding Item to queue: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660079364 Jan 15 16:18:11 volumio volumio[923]: info: Using cached record of: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660079364 Jan 15 16:18:11 volumio volumio[923]: info: Adding Item to queue: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660734724 Jan 15 16:18:11 volumio volumio[923]: info: Using cached record of: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660734724 Jan 15 16:18:11 volumio volumio[923]: info: Adding Item to queue: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660341508 Jan 15 16:18:11 volumio volumio[923]: info: Using cached record of: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660341508 Jan 15 16:18:11 volumio volumio[923]: info: Adding Item to queue: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19659948292 Jan 15 16:18:11 volumio volumio[923]: info: Using cached record of: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19659948292 Jan 15 16:18:11 volumio volumio[923]: info: Adding Item to queue: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660275972 Jan 15 16:18:11 volumio volumio[923]: info: Using cached record of: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660275972 Jan 15 16:18:11 volumio volumio[923]: info: Adding Item to queue: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660144900 Jan 15 16:18:11 volumio volumio[923]: info: Using cached record of: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660144900 Jan 15 16:18:11 volumio volumio[923]: info: Adding Item to queue: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660538116 Jan 15 16:18:11 volumio volumio[923]: info: Using cached record of: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660538116 Jan 15 16:18:11 volumio volumio[923]: info: Adding Item to queue: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660472580 Jan 15 16:18:11 volumio volumio[923]: info: Using cached record of: upnp/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613$19660472580 Jan 15 16:18:11 volumio volumio[923]: info: CoreStateMachine::stop Jan 15 16:18:11 volumio volumio[923]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 15 16:18:11 volumio volumio[923]: info: CoreCommandRouter::volumioPushQueue Jan 15 16:18:11 volumio volumio[923]: info: CorePlayQueue::saveQueue Jan 15 16:18:11 volumio volumio[923]: info: CoreStateMachine::play index undefined Jan 15 16:18:11 volumio volumio[923]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 15 16:18:11 volumio volumio[923]: info: CoreStateMachine::updateTrackBlock Jan 15 16:18:11 volumio volumio[923]: info: CorePlayQueue::getTrackBlock Jan 15 16:18:11 volumio volumio[923]: info: CorePlayQueue::getTrack 0 Jan 15 16:18:11 volumio volumio[923]: info: CoreStateMachine::startPlaybackTimer Jan 15 16:18:11 volumio volumio[923]: info: CorePlayQueue::getTrack 0 Jan 15 16:18:11 volumio volumio[923]: info: [1736929091569] ControllerUPNPBrowser::clearAddPlayTrack Jan 15 16:18:11 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand stop Jan 15 16:18:11 volumio volumio[923]: info: sendMpdCommand stop took 4 milliseconds Jan 15 16:18:11 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand clear Jan 15 16:18:11 volumio volumio[923]: info: sendMpdCommand clear took 1 milliseconds Jan 15 16:18:11 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand load "http://10.0.0.231:8200/MediaItems/A0$128$146$2239627541$2240020757$2288910613$19660210436.dsf?type=1,client=32,mime=audio/dsd,pn=,ext=.dsf" Jan 15 16:18:11 volumio volumio[923]: info: Jan 15 16:18:11 volumio volumio[923]: ---------------------------- MPD announces system playlist update Jan 15 16:18:11 volumio volumio[923]: info: Ignoring MPD Status Update Jan 15 16:18:11 volumio volumio[923]: info: Jan 15 16:18:11 volumio volumio[923]: ---------------------------- MPD announces system playlist update Jan 15 16:18:11 volumio volumio[923]: info: Ignoring MPD Status Update Jan 15 16:18:11 volumio volumio[923]: info: Jan 15 16:18:11 volumio volumio[923]: ---------------------------- MPD announces system playlist update Jan 15 16:18:11 volumio volumio[923]: info: Ignoring MPD Status Update Jan 15 16:18:11 volumio volumio[923]: error: Upnp client error: Error: This socket has been ended by the other party Jan 15 16:18:11 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand add "http://10.0.0.231:8200/MediaItems/A0$128$146$2239627541$2240020757$2288910613$19660210436.dsf?type=1,client=32,mime=audio/dsd,pn=,ext=.dsf" Jan 15 16:18:11 volumio volumio[923]: error: updateQueue error: null Jan 15 16:18:11 volumio volumio[923]: error: updateQueue error: null Jan 15 16:18:11 volumio volumio[923]: error: updateQueue error: null Jan 15 16:18:11 volumio volumio[923]: info: Jan 15 16:18:11 volumio volumio[923]: ---------------------------- MPD announces system playlist update Jan 15 16:18:11 volumio volumio[923]: info: Ignoring MPD Status Update Jan 15 16:18:11 volumio volumio[923]: info: ------------------------------ 69ms Jan 15 16:18:11 volumio volumio[923]: info: ------------------------------ 68ms Jan 15 16:18:11 volumio volumio[923]: info: ------------------------------ 67ms Jan 15 16:18:11 volumio volumio[923]: info: sendMpdCommand add "http://10.0.0.231:8200/MediaItems/A0$128$146$2239627541$2240020757$2288910613$19660210436.dsf?type=1,client=32,mime=audio/dsd,pn=,ext=.dsf" took 3 milliseconds Jan 15 16:18:11 volumio volumio[923]: info: CoreStateMachine::setConsumeUpdateService mpd Jan 15 16:18:11 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand play Jan 15 16:18:11 volumio volumio[923]: info: Jan 15 16:18:11 volumio volumio[923]: ---------------------------- MPD announces system playlist update Jan 15 16:18:11 volumio volumio[923]: info: Ignoring MPD Status Update Jan 15 16:18:11 volumio volumio[923]: info: Jan 15 16:18:11 volumio volumio[923]: ---------------------------- MPD announces system playlist update Jan 15 16:18:11 volumio volumio[923]: info: Ignoring MPD Status Update Jan 15 16:18:11 volumio volumio[923]: info: ------------------------------ 5ms Jan 15 16:18:11 volumio volumio[923]: info: sendMpdCommand play took 4 milliseconds Jan 15 16:18:11 volumio volumio[923]: info: ------------------------------ 3ms Jan 15 16:18:11 volumio volumio[923]: info: ------------------------------ 4ms Jan 15 16:18:11 volumio volumio[923]: info: Jan 15 16:18:11 volumio volumio[923]: ---------------------------- MPD announces state update: player Jan 15 16:18:11 volumio volumio[923]: info: ControllerMpd::getState Jan 15 16:18:11 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand status Jan 15 16:18:11 volumio volumio[923]: info: Jan 15 16:18:11 volumio volumio[923]: ---------------------------- MPD announces state update: player Jan 15 16:18:11 volumio volumio[923]: info: ControllerMpd::getState Jan 15 16:18:11 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand status Jan 15 16:18:11 volumio volumio[923]: info: Jan 15 16:18:11 volumio volumio[923]: ---------------------------- MPD announces state update: player Jan 15 16:18:11 volumio volumio[923]: info: ControllerMpd::getState Jan 15 16:18:11 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand status Jan 15 16:18:11 volumio volumio[923]: info: Jan 15 16:18:11 volumio volumio[923]: ---------------------------- MPD announces state update: player Jan 15 16:18:11 volumio volumio[923]: info: sendMpdCommand status took 11 milliseconds Jan 15 16:18:11 volumio volumio[923]: info: sendMpdCommand status took 10 milliseconds Jan 15 16:18:11 volumio volumio[923]: info: sendMpdCommand status took 9 milliseconds Jan 15 16:18:11 volumio volumio[923]: info: ControllerMpd::getState Jan 15 16:18:11 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand status Jan 15 16:18:11 volumio volumio[923]: verbose: ControllerMpd::parseState Jan 15 16:18:11 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 15 16:18:11 volumio volumio[923]: verbose: ControllerMpd::parseState Jan 15 16:18:11 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 15 16:18:11 volumio volumio[923]: verbose: ControllerMpd::parseState Jan 15 16:18:11 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 15 16:18:11 volumio volumio[923]: info: Jan 15 16:18:11 volumio volumio[923]: ---------------------------- MPD announces state update: player Jan 15 16:18:11 volumio volumio[923]: info: ControllerMpd::getState Jan 15 16:18:11 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand status Jan 15 16:18:11 volumio volumio[923]: info: Jan 15 16:18:11 volumio volumio[923]: ---------------------------- MPD announces state update: player Jan 15 16:18:11 volumio volumio[923]: info: ControllerMpd::getState Jan 15 16:18:11 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand status Jan 15 16:18:11 volumio volumio[923]: info: sendMpdCommand status took 6 milliseconds Jan 15 16:18:11 volumio volumio[923]: info: sendMpdCommand playlistinfo took 5 milliseconds Jan 15 16:18:11 volumio volumio[923]: info: sendMpdCommand playlistinfo took 5 milliseconds Jan 15 16:18:11 volumio volumio[923]: info: sendMpdCommand playlistinfo took 6 milliseconds Jan 15 16:18:11 volumio volumio[923]: info: sendMpdCommand status took 4 milliseconds Jan 15 16:18:11 volumio volumio[923]: verbose: ControllerMpd::parseState Jan 15 16:18:11 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 15 16:18:11 volumio volumio[923]: verbose: ControllerMpd::parseTrackInfo Jan 15 16:18:11 volumio volumio[923]: verbose: ControllerMpd::parseTrackInfo Jan 15 16:18:11 volumio volumio[923]: verbose: ControllerMpd::parseTrackInfo Jan 15 16:18:11 volumio volumio[923]: verbose: ControllerMpd::parseState Jan 15 16:18:11 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 15 16:18:11 volumio volumio[923]: info: ControllerMpd::pushState Jan 15 16:18:11 volumio volumio[923]: info: CoreCommandRouter::servicePushState Jan 15 16:18:11 volumio volumio[923]: info: CorePlayQueue::getTrack 0 Jan 15 16:18:11 volumio volumio[923]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":191,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"dsd,pn=,ext=.dsf","artist":null,"album":null,"uri":"http://10.0.0.231:8200/MediaItems/A0$128$146$2239627541$2240020757$2288910613$19660210436.dsf?type=1,client=32,mime=audio/dsd,pn=,ext=.dsf","trackType":"dsf"} Jan 15 16:18:11 volumio volumio[923]: verbose: CURRENT POSITION 0 Jan 15 16:18:11 volumio volumio[923]: info: CoreStateMachine::syncState stateService play Jan 15 16:18:11 volumio volumio[923]: info: CoreStateMachine::syncState currentStatus stop Jan 15 16:18:11 volumio volumio[923]: info: ControllerMpd::pushState Jan 15 16:18:11 volumio volumio[923]: info: CoreCommandRouter::servicePushState Jan 15 16:18:11 volumio volumio[923]: info: CorePlayQueue::getTrack 0 Jan 15 16:18:11 volumio volumio[923]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":191,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"dsd,pn=,ext=.dsf","artist":null,"album":null,"uri":"http://10.0.0.231:8200/MediaItems/A0$128$146$2239627541$2240020757$2288910613$19660210436.dsf?type=1,client=32,mime=audio/dsd,pn=,ext=.dsf","trackType":"dsf"} Jan 15 16:18:11 volumio volumio[923]: verbose: CURRENT POSITION 0 Jan 15 16:18:11 volumio volumio[923]: info: CoreStateMachine::syncState stateService play Jan 15 16:18:11 volumio volumio[923]: info: CoreStateMachine::syncState currentStatus play Jan 15 16:18:11 volumio volumio[923]: info: Received an update from plugin. extracting info from payload Jan 15 16:18:11 volumio volumio[923]: info: CoreStateMachine::pushState Jan 15 16:18:11 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 15 16:18:11 volumio volumio[923]: info: CoreCommandRouter::volumioPushState Jan 15 16:18:11 volumio volumio[923]: info: CoreStateMachine::pushState Jan 15 16:18:11 volumio volumio[923]: info: CoreCommandRouter::volumioPushState Jan 15 16:18:11 volumio volumio[923]: info: ControllerMpd::pushState Jan 15 16:18:11 volumio volumio[923]: info: CoreCommandRouter::servicePushState Jan 15 16:18:11 volumio volumio[923]: info: CorePlayQueue::getTrack 0 Jan 15 16:18:11 volumio volumio[923]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":191,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"dsd,pn=,ext=.dsf","artist":null,"album":null,"uri":"http://10.0.0.231:8200/MediaItems/A0$128$146$2239627541$2240020757$2288910613$19660210436.dsf?type=1,client=32,mime=audio/dsd,pn=,ext=.dsf","trackType":"dsf"} Jan 15 16:18:11 volumio volumio[923]: verbose: CURRENT POSITION 0 Jan 15 16:18:11 volumio volumio[923]: info: CoreStateMachine::syncState stateService play Jan 15 16:18:11 volumio volumio[923]: info: CoreStateMachine::syncState currentStatus play Jan 15 16:18:11 volumio volumio[923]: info: Received an update from plugin. extracting info from payload Jan 15 16:18:11 volumio volumio[923]: info: CoreStateMachine::pushState Jan 15 16:18:11 volumio volumio[923]: info: CoreCommandRouter::volumioPushState Jan 15 16:18:11 volumio volumio[923]: info: CoreStateMachine::pushState Jan 15 16:18:11 volumio volumio[923]: info: CoreCommandRouter::volumioPushState Jan 15 16:18:11 volumio volumio[923]: info: ------------------------------ 39ms Jan 15 16:18:11 volumio volumio[923]: info: ------------------------------ 68ms Jan 15 16:18:11 volumio volumio[923]: info: ------------------------------ 68ms Jan 15 16:18:11 volumio volumio[923]: info: sendMpdCommand status took 55 milliseconds Jan 15 16:18:11 volumio volumio[923]: info: sendMpdCommand playlistinfo took 54 milliseconds Jan 15 16:18:11 volumio volumio[923]: info: sendMpdCommand playlistinfo took 51 milliseconds Jan 15 16:18:11 volumio volumio[923]: verbose: ControllerMpd::parseState Jan 15 16:18:11 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 15 16:18:11 volumio volumio[923]: verbose: ControllerMpd::parseTrackInfo Jan 15 16:18:11 volumio volumio[923]: verbose: ControllerMpd::parseTrackInfo Jan 15 16:18:11 volumio volumio[923]: info: ControllerMpd::pushState Jan 15 16:18:11 volumio volumio[923]: info: CoreCommandRouter::servicePushState Jan 15 16:18:11 volumio volumio[923]: info: CorePlayQueue::getTrack 0 Jan 15 16:18:11 volumio volumio[923]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":191,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"dsd,pn=,ext=.dsf","artist":null,"album":null,"uri":"http://10.0.0.231:8200/MediaItems/A0$128$146$2239627541$2240020757$2288910613$19660210436.dsf?type=1,client=32,mime=audio/dsd,pn=,ext=.dsf","trackType":"dsf"} Jan 15 16:18:11 volumio volumio[923]: verbose: CURRENT POSITION 0 Jan 15 16:18:11 volumio volumio[923]: info: CoreStateMachine::syncState stateService play Jan 15 16:18:11 volumio volumio[923]: info: CoreStateMachine::syncState currentStatus play Jan 15 16:18:11 volumio volumio[923]: info: Received an update from plugin. extracting info from payload Jan 15 16:18:11 volumio volumio[923]: info: CoreStateMachine::pushState Jan 15 16:18:11 volumio volumio[923]: info: CoreCommandRouter::volumioPushState Jan 15 16:18:11 volumio volumio[923]: info: CoreStateMachine::pushState Jan 15 16:18:11 volumio volumio[923]: info: CoreCommandRouter::volumioPushState Jan 15 16:18:11 volumio volumio[923]: info: ControllerMpd::pushState Jan 15 16:18:11 volumio volumio[923]: info: CoreCommandRouter::servicePushState Jan 15 16:18:11 volumio volumio[923]: info: CorePlayQueue::getTrack 0 Jan 15 16:18:11 volumio volumio[923]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":191,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"dsd,pn=,ext=.dsf","artist":null,"album":null,"uri":"http://10.0.0.231:8200/MediaItems/A0$128$146$2239627541$2240020757$2288910613$19660210436.dsf?type=1,client=32,mime=audio/dsd,pn=,ext=.dsf","trackType":"dsf"} Jan 15 16:18:11 volumio volumio[923]: verbose: CURRENT POSITION 0 Jan 15 16:18:11 volumio volumio[923]: info: CoreStateMachine::syncState stateService play Jan 15 16:18:11 volumio volumio[923]: info: CoreStateMachine::syncState currentStatus play Jan 15 16:18:11 volumio volumio[923]: info: Received an update from plugin. extracting info from payload Jan 15 16:18:11 volumio volumio[923]: info: CoreStateMachine::pushState Jan 15 16:18:11 volumio volumio[923]: info: CoreCommandRouter::volumioPushState Jan 15 16:18:11 volumio volumio[923]: info: CoreStateMachine::pushState Jan 15 16:18:11 volumio volumio[923]: info: CoreCommandRouter::volumioPushState Jan 15 16:18:11 volumio volumio[923]: info: ------------------------------ 125ms Jan 15 16:18:11 volumio volumio[923]: info: ------------------------------ 121ms Jan 15 16:18:11 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Jan 15 16:18:11 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Jan 15 16:18:11 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Jan 15 16:18:11 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Jan 15 16:18:11 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Jan 15 16:18:11 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Jan 15 16:18:11 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Jan 15 16:18:11 volumio volumio[923]: info: sendMpdCommand playlistinfo took 106 milliseconds Jan 15 16:18:11 volumio volumio[923]: verbose: ControllerMpd::parseTrackInfo Jan 15 16:18:11 volumio volumio[923]: info: ControllerMpd::pushState Jan 15 16:18:11 volumio volumio[923]: info: CoreCommandRouter::servicePushState Jan 15 16:18:11 volumio volumio[923]: info: CorePlayQueue::getTrack 0 Jan 15 16:18:11 volumio volumio[923]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":191,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"dsd,pn=,ext=.dsf","artist":null,"album":null,"uri":"http://10.0.0.231:8200/MediaItems/A0$128$146$2239627541$2240020757$2288910613$19660210436.dsf?type=1,client=32,mime=audio/dsd,pn=,ext=.dsf","trackType":"dsf"} Jan 15 16:18:11 volumio volumio[923]: verbose: CURRENT POSITION 0 Jan 15 16:18:11 volumio volumio[923]: info: CoreStateMachine::syncState stateService play Jan 15 16:18:11 volumio volumio[923]: info: CoreStateMachine::syncState currentStatus play Jan 15 16:18:11 volumio volumio[923]: info: Received an update from plugin. extracting info from payload Jan 15 16:18:11 volumio volumio[923]: info: CoreStateMachine::pushState Jan 15 16:18:11 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 15 16:18:11 volumio volumio[923]: info: CoreCommandRouter::volumioPushState Jan 15 16:18:11 volumio volumio[923]: info: CoreStateMachine::pushState Jan 15 16:18:11 volumio volumio[923]: info: CoreCommandRouter::volumioPushState Jan 15 16:18:11 volumio volumio[923]: info: ------------------------------ 197ms Jan 15 16:18:11 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Jan 15 16:18:11 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Jan 15 16:18:11 volumio volumio[923]: info: CoreCommandRouter::volumioGetState Jan 15 16:18:18 volumio volumio[923]: info: Preload queue cleared Jan 15 16:18:18 volumio volumio[923]: info: CoreCommandRouter::volumioReplaceandPlayItems Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::ClearQueue Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::stop Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::stPlaybackTimer Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::updateTrackBlock Jan 15 16:18:18 volumio volumio[923]: info: CorePlayQueue::getTrackBlock Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::pushState Jan 15 16:18:18 volumio volumio[923]: info: CorePlayQueue::getTrack 0 Jan 15 16:18:18 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 15 16:18:18 volumio volumio[923]: info: CoreCommandRouter::volumioPushState Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::serviceStop Jan 15 16:18:18 volumio volumio[923]: info: CorePlayQueue::getTrack 0 Jan 15 16:18:18 volumio volumio[923]: info: CoreCommandRouter::serviceStop Jan 15 16:18:18 volumio volumio[923]: info: [1736929098706] ControllerUPNPBrowser::stop Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand stop Jan 15 16:18:18 volumio volumio[923]: info: CorePlayQueue::clearPlayQueue Jan 15 16:18:18 volumio volumio[923]: info: CorePlayQueue::saveQueue Jan 15 16:18:18 volumio volumio[923]: info: CoreCommandRouter::volumioPushQueue Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::addQueueItems Jan 15 16:18:18 volumio volumio[923]: info: CorePlayQueue::addQueueItems Jan 15 16:18:18 volumio volumio[923]: info: Preload queue cleared Jan 15 16:18:18 volumio volumio[923]: info: Adding Item to queue: upnp/folder/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613 Jan 15 16:18:18 volumio volumio[923]: info: Exploding uri upnp/folder/http://10.0.0.231:8200/ctl/ContentDir@A0$128$146$2239627541$2240020757$2288910613 in service upnp_browser Jan 15 16:18:18 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Jan 15 16:18:18 volumio volumio[923]: info: Jan 15 16:18:18 volumio volumio[923]: ---------------------------- MPD announces state update: player Jan 15 16:18:18 volumio volumio[923]: info: sendMpdCommand stop took 22 milliseconds Jan 15 16:18:18 volumio volumio[923]: info: ControllerMpd::getState Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand status Jan 15 16:18:18 volumio volumio[923]: info: sendMpdCommand status took 1 milliseconds Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::parseState Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 15 16:18:18 volumio volumio[923]: info: Jan 15 16:18:18 volumio volumio[923]: ---------------------------- MPD announces state update: player Jan 15 16:18:18 volumio volumio[923]: info: ControllerMpd::getState Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand status Jan 15 16:18:18 volumio volumio[923]: info: Jan 15 16:18:18 volumio volumio[923]: ---------------------------- MPD announces state update: player Jan 15 16:18:18 volumio volumio[923]: info: ControllerMpd::getState Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand status Jan 15 16:18:18 volumio volumio[923]: info: sendMpdCommand playlistinfo took 33 milliseconds Jan 15 16:18:18 volumio volumio[923]: info: sendMpdCommand status took 4 milliseconds Jan 15 16:18:18 volumio volumio[923]: info: sendMpdCommand status took 3 milliseconds Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::parseTrackInfo Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::parseState Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::parseState Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 15 16:18:18 volumio volumio[923]: info: ControllerMpd::pushState Jan 15 16:18:18 volumio volumio[923]: info: CoreCommandRouter::servicePushState Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::pushState Jan 15 16:18:18 volumio volumio[923]: info: CorePlayQueue::getTrack 0 Jan 15 16:18:18 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 15 16:18:18 volumio volumio[923]: info: CoreCommandRouter::volumioPushState Jan 15 16:18:18 volumio volumio[923]: info: CorePlayQueue::getTrack 0 Jan 15 16:18:18 volumio volumio[923]: 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":"dsd,pn=,ext=.dsf","artist":null,"album":null,"uri":"http://10.0.0.231:8200/MediaItems/A0$128$146$2239627541$2240020757$2288910613$19660210436.dsf?type=1,client=32,mime=audio/dsd,pn=,ext=.dsf","trackType":"dsf"} Jan 15 16:18:18 volumio volumio[923]: verbose: CURRENT POSITION 0 Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::syncState stateService stop Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::syncState currentStatus stop Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::pushState Jan 15 16:18:18 volumio volumio[923]: info: CorePlayQueue::getTrack 0 Jan 15 16:18:18 volumio volumio[923]: info: CoreCommandRouter::volumioPushState Jan 15 16:18:18 volumio volumio[923]: info: No code Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::pushState Jan 15 16:18:18 volumio volumio[923]: info: CorePlayQueue::getTrack 0 Jan 15 16:18:18 volumio volumio[923]: info: CoreCommandRouter::volumioPushState Jan 15 16:18:18 volumio volumio[923]: info: ------------------------------ 69ms Jan 15 16:18:18 volumio volumio[923]: info: sendMpdCommand playlistinfo took 40 milliseconds Jan 15 16:18:18 volumio volumio[923]: info: sendMpdCommand playlistinfo took 39 milliseconds Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::parseTrackInfo Jan 15 16:18:18 volumio volumio[923]: info: ControllerMpd::pushState Jan 15 16:18:18 volumio volumio[923]: info: CoreCommandRouter::servicePushState Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::pushState Jan 15 16:18:18 volumio volumio[923]: info: CorePlayQueue::getTrack 0 Jan 15 16:18:18 volumio volumio[923]: info: CoreCommandRouter::volumioPushState Jan 15 16:18:18 volumio volumio[923]: info: CorePlayQueue::getTrack 0 Jan 15 16:18:18 volumio volumio[923]: 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":"dsd,pn=,ext=.dsf","artist":null,"album":null,"uri":"http://10.0.0.231:8200/MediaItems/A0$128$146$2239627541$2240020757$2288910613$19660210436.dsf?type=1,client=32,mime=audio/dsd,pn=,ext=.dsf","trackType":"dsf"} Jan 15 16:18:18 volumio volumio[923]: verbose: CURRENT POSITION 0 Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::syncState stateService stop Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::syncState currentStatus stop Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::pushState Jan 15 16:18:18 volumio volumio[923]: info: CorePlayQueue::getTrack 0 Jan 15 16:18:18 volumio volumio[923]: info: CoreCommandRouter::volumioPushState Jan 15 16:18:18 volumio volumio[923]: info: No code Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::pushState Jan 15 16:18:18 volumio volumio[923]: info: CorePlayQueue::getTrack 0 Jan 15 16:18:18 volumio volumio[923]: info: CoreCommandRouter::volumioPushState Jan 15 16:18:18 volumio volumio[923]: info: ControllerMpd::pushState Jan 15 16:18:18 volumio volumio[923]: info: CoreCommandRouter::servicePushState Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::pushState Jan 15 16:18:18 volumio volumio[923]: info: CorePlayQueue::getTrack 0 Jan 15 16:18:18 volumio volumio[923]: info: CoreCommandRouter::volumioPushState Jan 15 16:18:18 volumio volumio[923]: info: CorePlayQueue::getTrack 0 Jan 15 16:18:18 volumio volumio[923]: 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":"dsd,pn=,ext=.dsf","artist":null,"album":null,"uri":"http://10.0.0.231:8200/MediaItems/A0$128$146$2239627541$2240020757$2288910613$19660210436.dsf?type=1,client=32,mime=audio/dsd,pn=,ext=.dsf","trackType":"dsf"} Jan 15 16:18:18 volumio volumio[923]: verbose: CURRENT POSITION 0 Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::syncState stateService stop Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::syncState currentStatus stop Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::pushState Jan 15 16:18:18 volumio volumio[923]: info: CorePlayQueue::getTrack 0 Jan 15 16:18:18 volumio volumio[923]: info: CoreCommandRouter::volumioPushState Jan 15 16:18:18 volumio volumio[923]: info: No code Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::pushState Jan 15 16:18:18 volumio volumio[923]: info: CorePlayQueue::getTrack 0 Jan 15 16:18:18 volumio volumio[923]: info: CoreCommandRouter::volumioPushState Jan 15 16:18:18 volumio volumio[923]: info: ------------------------------ 112ms Jan 15 16:18:18 volumio volumio[923]: info: ------------------------------ 112ms Jan 15 16:18:18 volumio volumio[923]: info: CoreCommandRouter::volumioPushQueue Jan 15 16:18:18 volumio volumio[923]: info: CorePlayQueue::saveQueue Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::updateTrackBlock Jan 15 16:18:18 volumio volumio[923]: info: CorePlayQueue::getTrackBlock Jan 15 16:18:18 volumio volumio[923]: info: CoreCommandRouter::volumioPlay Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::play index 0 Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::stop Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::play index undefined Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 15 16:18:18 volumio volumio[923]: info: CorePlayQueue::getTrack 0 Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::startPlaybackTimer Jan 15 16:18:18 volumio volumio[923]: info: CorePlayQueue::getTrack 0 Jan 15 16:18:18 volumio volumio[923]: info: [1736929098903] ControllerUPNPBrowser::clearAddPlayTrack Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand stop Jan 15 16:18:18 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Jan 15 16:18:18 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Jan 15 16:18:18 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Jan 15 16:18:18 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Jan 15 16:18:18 volumio volumio[923]: info: touch_display: Setting screensaver timeout to 120 seconds. Jan 15 16:18:18 volumio volumio[923]: info: sendMpdCommand stop took 16 milliseconds Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand clear Jan 15 16:18:18 volumio volumio[923]: info: Jan 15 16:18:18 volumio volumio[923]: ---------------------------- MPD announces system playlist update Jan 15 16:18:18 volumio volumio[923]: info: Ignoring MPD Status Update Jan 15 16:18:18 volumio volumio[923]: info: sendMpdCommand clear took 4 milliseconds Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand load "http://10.0.0.231:8200/MediaItems/A0$128$146$2239627541$2240020757$2288910613$19660210436.dsf?type=1,client=32,mime=audio/dsd,pn=,ext=.dsf" Jan 15 16:18:18 volumio volumio[923]: info: Jan 15 16:18:18 volumio volumio[923]: ---------------------------- MPD announces system playlist update Jan 15 16:18:18 volumio volumio[923]: info: Ignoring MPD Status Update Jan 15 16:18:18 volumio volumio[923]: info: Jan 15 16:18:18 volumio volumio[923]: ---------------------------- MPD announces system playlist update Jan 15 16:18:18 volumio volumio[923]: info: Ignoring MPD Status Update Jan 15 16:18:18 volumio volumio[923]: error: updateQueue error: null Jan 15 16:18:18 volumio volumio[923]: info: ------------------------------ 5ms Jan 15 16:18:18 volumio volumio[923]: error: updateQueue error: null Jan 15 16:18:18 volumio volumio[923]: error: updateQueue error: null Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand add "http://10.0.0.231:8200/MediaItems/A0$128$146$2239627541$2240020757$2288910613$19660210436.dsf?type=1,client=32,mime=audio/dsd,pn=,ext=.dsf" Jan 15 16:18:18 volumio volumio[923]: info: ------------------------------ 10ms Jan 15 16:18:18 volumio volumio[923]: info: ------------------------------ 9ms Jan 15 16:18:18 volumio volumio[923]: info: Jan 15 16:18:18 volumio volumio[923]: ---------------------------- MPD announces system playlist update Jan 15 16:18:18 volumio volumio[923]: info: Ignoring MPD Status Update Jan 15 16:18:18 volumio volumio[923]: info: sendMpdCommand add "http://10.0.0.231:8200/MediaItems/A0$128$146$2239627541$2240020757$2288910613$19660210436.dsf?type=1,client=32,mime=audio/dsd,pn=,ext=.dsf" took 3 milliseconds Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::setConsumeUpdateService mpd Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand play Jan 15 16:18:18 volumio volumio[923]: info: Jan 15 16:18:18 volumio volumio[923]: ---------------------------- MPD announces system playlist update Jan 15 16:18:18 volumio volumio[923]: info: Ignoring MPD Status Update Jan 15 16:18:18 volumio volumio[923]: info: Jan 15 16:18:18 volumio volumio[923]: ---------------------------- MPD announces system playlist update Jan 15 16:18:18 volumio volumio[923]: info: Ignoring MPD Status Update Jan 15 16:18:18 volumio volumio[923]: info: ------------------------------ 5ms Jan 15 16:18:18 volumio volumio[923]: info: sendMpdCommand play took 4 milliseconds Jan 15 16:18:18 volumio volumio[923]: info: ------------------------------ 4ms Jan 15 16:18:18 volumio volumio[923]: info: ------------------------------ 3ms Jan 15 16:18:18 volumio volumio[923]: info: Jan 15 16:18:18 volumio volumio[923]: ---------------------------- MPD announces state update: player Jan 15 16:18:18 volumio volumio[923]: info: ControllerMpd::getState Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand status Jan 15 16:18:18 volumio volumio[923]: info: Jan 15 16:18:18 volumio volumio[923]: ---------------------------- MPD announces state update: player Jan 15 16:18:18 volumio volumio[923]: info: ControllerMpd::getState Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand status Jan 15 16:18:18 volumio volumio[923]: info: Jan 15 16:18:18 volumio volumio[923]: ---------------------------- MPD announces state update: player Jan 15 16:18:18 volumio volumio[923]: info: ControllerMpd::getState Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand status Jan 15 16:18:18 volumio volumio[923]: info: Jan 15 16:18:18 volumio volumio[923]: ---------------------------- MPD announces state update: player Jan 15 16:18:18 volumio volumio[923]: info: sendMpdCommand status took 6 milliseconds Jan 15 16:18:18 volumio volumio[923]: info: ControllerMpd::getState Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand status Jan 15 16:18:18 volumio volumio[923]: info: sendMpdCommand status took 5 milliseconds Jan 15 16:18:18 volumio volumio[923]: info: sendMpdCommand status took 4 milliseconds Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::parseState Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::parseState Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::parseState Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 15 16:18:18 volumio volumio[923]: info: Jan 15 16:18:18 volumio volumio[923]: ---------------------------- MPD announces state update: player Jan 15 16:18:18 volumio volumio[923]: info: ControllerMpd::getState Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand status Jan 15 16:18:18 volumio volumio[923]: info: Jan 15 16:18:18 volumio volumio[923]: ---------------------------- MPD announces state update: player Jan 15 16:18:18 volumio volumio[923]: info: ControllerMpd::getState Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand status Jan 15 16:18:18 volumio volumio[923]: info: sendMpdCommand status took 7 milliseconds Jan 15 16:18:18 volumio volumio[923]: info: sendMpdCommand playlistinfo took 6 milliseconds Jan 15 16:18:18 volumio volumio[923]: info: sendMpdCommand playlistinfo took 6 milliseconds Jan 15 16:18:18 volumio volumio[923]: info: sendMpdCommand playlistinfo took 5 milliseconds Jan 15 16:18:18 volumio volumio[923]: info: sendMpdCommand status took 4 milliseconds Jan 15 16:18:18 volumio volumio[923]: info: sendMpdCommand status took 3 milliseconds Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::parseState Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::parseTrackInfo Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::parseTrackInfo Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::parseTrackInfo Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::parseState Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::parseState Jan 15 16:18:18 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 15 16:18:18 volumio volumio[923]: info: ControllerMpd::pushState Jan 15 16:18:18 volumio volumio[923]: info: CoreCommandRouter::servicePushState Jan 15 16:18:18 volumio volumio[923]: info: CorePlayQueue::getTrack 0 Jan 15 16:18:18 volumio volumio[923]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":191,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"dsd,pn=,ext=.dsf","artist":null,"album":null,"uri":"http://10.0.0.231:8200/MediaItems/A0$128$146$2239627541$2240020757$2288910613$19660210436.dsf?type=1,client=32,mime=audio/dsd,pn=,ext=.dsf","trackType":"dsf"} Jan 15 16:18:18 volumio volumio[923]: verbose: CURRENT POSITION 0 Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::syncState stateService play Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::syncState currentStatus stop Jan 15 16:18:18 volumio volumio[923]: info: ControllerMpd::pushState Jan 15 16:18:18 volumio volumio[923]: info: CoreCommandRouter::servicePushState Jan 15 16:18:18 volumio volumio[923]: info: CorePlayQueue::getTrack 0 Jan 15 16:18:18 volumio volumio[923]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":191,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"dsd,pn=,ext=.dsf","artist":null,"album":null,"uri":"http://10.0.0.231:8200/MediaItems/A0$128$146$2239627541$2240020757$2288910613$19660210436.dsf?type=1,client=32,mime=audio/dsd,pn=,ext=.dsf","trackType":"dsf"} Jan 15 16:18:18 volumio volumio[923]: verbose: CURRENT POSITION 0 Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::syncState stateService play Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::syncState currentStatus play Jan 15 16:18:18 volumio volumio[923]: info: Received an update from plugin. extracting info from payload Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::pushState Jan 15 16:18:18 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 15 16:18:18 volumio volumio[923]: info: CoreCommandRouter::volumioPushState Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::pushState Jan 15 16:18:18 volumio volumio[923]: info: CoreCommandRouter::volumioPushState Jan 15 16:18:18 volumio volumio[923]: info: ControllerMpd::pushState Jan 15 16:18:18 volumio volumio[923]: info: CoreCommandRouter::servicePushState Jan 15 16:18:18 volumio volumio[923]: info: CorePlayQueue::getTrack 0 Jan 15 16:18:18 volumio volumio[923]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":191,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"dsd,pn=,ext=.dsf","artist":null,"album":null,"uri":"http://10.0.0.231:8200/MediaItems/A0$128$146$2239627541$2240020757$2288910613$19660210436.dsf?type=1,client=32,mime=audio/dsd,pn=,ext=.dsf","trackType":"dsf"} Jan 15 16:18:18 volumio volumio[923]: verbose: CURRENT POSITION 0 Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::syncState stateService play Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::syncState currentStatus play Jan 15 16:18:18 volumio volumio[923]: info: Received an update from plugin. extracting info from payload Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::pushState Jan 15 16:18:18 volumio volumio[923]: info: CoreCommandRouter::volumioPushState Jan 15 16:18:18 volumio volumio[923]: info: CoreStateMachine::pushState Jan 15 16:18:18 volumio volumio[923]: info: CoreCommandRouter::volumioPushState Jan 15 16:18:18 volumio volumio[923]: info: ------------------------------ 36ms Jan 15 16:18:19 volumio volumio[923]: info: ------------------------------ 69ms Jan 15 16:18:19 volumio volumio[923]: info: ------------------------------ 68ms Jan 15 16:18:19 volumio volumio[923]: info: sendMpdCommand playlistinfo took 57 milliseconds Jan 15 16:18:19 volumio volumio[923]: info: sendMpdCommand playlistinfo took 57 milliseconds Jan 15 16:18:19 volumio volumio[923]: info: sendMpdCommand playlistinfo took 56 milliseconds Jan 15 16:18:19 volumio volumio[923]: verbose: ControllerMpd::parseTrackInfo Jan 15 16:18:19 volumio volumio[923]: info: ControllerMpd::pushState Jan 15 16:18:19 volumio volumio[923]: info: CoreCommandRouter::servicePushState Jan 15 16:18:19 volumio volumio[923]: info: CorePlayQueue::getTrack 0 Jan 15 16:18:19 volumio volumio[923]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":191,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"dsd,pn=,ext=.dsf","artist":null,"album":null,"uri":"http://10.0.0.231:8200/MediaItems/A0$128$146$2239627541$2240020757$2288910613$19660210436.dsf?type=1,client=32,mime=audio/dsd,pn=,ext=.dsf","trackType":"dsf"} Jan 15 16:18:19 volumio volumio[923]: verbose: CURRENT POSITION 0 Jan 15 16:18:19 volumio volumio[923]: info: CoreStateMachine::syncState stateService play Jan 15 16:18:19 volumio volumio[923]: info: CoreStateMachine::syncState currentStatus play Jan 15 16:18:19 volumio volumio[923]: info: Received an update from plugin. extracting info from payload Jan 15 16:18:19 volumio volumio[923]: info: CoreStateMachine::pushState Jan 15 16:18:19 volumio volumio[923]: info: CoreCommandRouter::volumioPushState Jan 15 16:18:19 volumio volumio[923]: info: CoreStateMachine::pushState Jan 15 16:18:19 volumio volumio[923]: info: CoreCommandRouter::volumioPushState Jan 15 16:18:19 volumio volumio[923]: info: ControllerMpd::pushState Jan 15 16:18:19 volumio volumio[923]: info: CoreCommandRouter::servicePushState Jan 15 16:18:19 volumio volumio[923]: info: CorePlayQueue::getTrack 0 Jan 15 16:18:19 volumio volumio[923]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":191,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"dsd,pn=,ext=.dsf","artist":null,"album":null,"uri":"http://10.0.0.231:8200/MediaItems/A0$128$146$2239627541$2240020757$2288910613$19660210436.dsf?type=1,client=32,mime=audio/dsd,pn=,ext=.dsf","trackType":"dsf"} Jan 15 16:18:19 volumio volumio[923]: verbose: CURRENT POSITION 0 Jan 15 16:18:19 volumio volumio[923]: info: CoreStateMachine::syncState stateService play Jan 15 16:18:19 volumio volumio[923]: info: CoreStateMachine::syncState currentStatus play Jan 15 16:18:19 volumio volumio[923]: info: Received an update from plugin. extracting info from payload Jan 15 16:18:19 volumio volumio[923]: info: CoreStateMachine::pushState Jan 15 16:18:19 volumio volumio[923]: info: CoreCommandRouter::volumioPushState Jan 15 16:18:19 volumio volumio[923]: info: CoreStateMachine::pushState Jan 15 16:18:19 volumio volumio[923]: info: CoreCommandRouter::volumioPushState Jan 15 16:18:19 volumio volumio[923]: info: ControllerMpd::pushState Jan 15 16:18:19 volumio volumio[923]: info: CoreCommandRouter::servicePushState Jan 15 16:18:19 volumio volumio[923]: info: CorePlayQueue::getTrack 0 Jan 15 16:18:19 volumio volumio[923]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":191,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"dsd,pn=,ext=.dsf","artist":null,"album":null,"uri":"http://10.0.0.231:8200/MediaItems/A0$128$146$2239627541$2240020757$2288910613$19660210436.dsf?type=1,client=32,mime=audio/dsd,pn=,ext=.dsf","trackType":"dsf"} Jan 15 16:18:19 volumio volumio[923]: verbose: CURRENT POSITION 0 Jan 15 16:18:19 volumio volumio[923]: info: CoreStateMachine::syncState stateService play Jan 15 16:18:19 volumio volumio[923]: info: CoreStateMachine::syncState currentStatus play Jan 15 16:18:19 volumio volumio[923]: info: Received an update from plugin. extracting info from payload Jan 15 16:18:19 volumio volumio[923]: info: CoreStateMachine::pushState Jan 15 16:18:19 volumio volumio[923]: info: CoreCommandRouter::volumioPushState Jan 15 16:18:19 volumio volumio[923]: info: CoreStateMachine::pushState Jan 15 16:18:19 volumio volumio[923]: info: CoreCommandRouter::volumioPushState Jan 15 16:18:19 volumio volumio[923]: info: ------------------------------ 169ms Jan 15 16:18:19 volumio volumio[923]: info: ------------------------------ 166ms Jan 15 16:18:19 volumio volumio[923]: info: ------------------------------ 167ms Jan 15 16:18:19 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Jan 15 16:18:19 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Jan 15 16:18:19 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Jan 15 16:18:19 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Jan 15 16:18:19 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Jan 15 16:18:19 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Jan 15 16:18:19 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Jan 15 16:18:19 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Jan 15 16:18:19 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Jan 15 16:18:19 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Jan 15 16:18:20 volumio volumio[923]: info: CoreCommandRouter::volumioPause Jan 15 16:18:20 volumio volumio[923]: info: CoreStateMachine::pause Jan 15 16:18:20 volumio volumio[923]: info: CoreStateMachine::stPlaybackTimer Jan 15 16:18:20 volumio volumio[923]: info: CoreStateMachine::servicePause Jan 15 16:18:20 volumio volumio[923]: info: CorePlayQueue::getTrack 0 Jan 15 16:18:20 volumio volumio[923]: info: CoreCommandRouter::servicePause Jan 15 16:18:20 volumio volumio[923]: info: [1736929100884] ControllerUPNPBrowser::pause Jan 15 16:18:20 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand pause Jan 15 16:18:20 volumio volumio[923]: info: sendMpdCommand pause took 1 milliseconds Jan 15 16:18:20 volumio volumio[923]: info: Jan 15 16:18:20 volumio volumio[923]: ---------------------------- MPD announces state update: player Jan 15 16:18:20 volumio volumio[923]: info: ControllerMpd::getState Jan 15 16:18:20 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand status Jan 15 16:18:20 volumio volumio[923]: info: Jan 15 16:18:20 volumio volumio[923]: ---------------------------- MPD announces state update: player Jan 15 16:18:20 volumio volumio[923]: info: ControllerMpd::getState Jan 15 16:18:20 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand status Jan 15 16:18:20 volumio volumio[923]: info: Jan 15 16:18:20 volumio volumio[923]: ---------------------------- MPD announces state update: player Jan 15 16:18:20 volumio volumio[923]: info: ControllerMpd::getState Jan 15 16:18:20 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand status Jan 15 16:18:20 volumio volumio[923]: info: sendMpdCommand status took 3 milliseconds Jan 15 16:18:20 volumio volumio[923]: info: sendMpdCommand status took 2 milliseconds Jan 15 16:18:20 volumio volumio[923]: info: sendMpdCommand status took 1 milliseconds Jan 15 16:18:20 volumio volumio[923]: verbose: ControllerMpd::parseState Jan 15 16:18:20 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 15 16:18:20 volumio volumio[923]: verbose: ControllerMpd::parseState Jan 15 16:18:20 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 15 16:18:20 volumio volumio[923]: verbose: ControllerMpd::parseState Jan 15 16:18:20 volumio volumio[923]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 15 16:18:20 volumio volumio[923]: info: sendMpdCommand playlistinfo took 2 milliseconds Jan 15 16:18:20 volumio volumio[923]: info: sendMpdCommand playlistinfo took 1 milliseconds Jan 15 16:18:20 volumio volumio[923]: info: sendMpdCommand playlistinfo took 1 milliseconds Jan 15 16:18:20 volumio volumio[923]: verbose: ControllerMpd::parseTrackInfo Jan 15 16:18:20 volumio volumio[923]: verbose: ControllerMpd::parseTrackInfo Jan 15 16:18:20 volumio volumio[923]: verbose: ControllerMpd::parseTrackInfo Jan 15 16:18:20 volumio volumio[923]: info: ControllerMpd::pushState Jan 15 16:18:20 volumio volumio[923]: info: CoreCommandRouter::servicePushState Jan 15 16:18:20 volumio volumio[923]: info: CorePlayQueue::getTrack 0 Jan 15 16:18:20 volumio volumio[923]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":2167,"duration":191,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"dsd,pn=,ext=.dsf","artist":null,"album":null,"uri":"http://10.0.0.231:8200/MediaItems/A0$128$146$2239627541$2240020757$2288910613$19660210436.dsf?type=1,client=32,mime=audio/dsd,pn=,ext=.dsf","trackType":"dsf"} Jan 15 16:18:20 volumio volumio[923]: verbose: CURRENT POSITION 0 Jan 15 16:18:20 volumio volumio[923]: info: CoreStateMachine::syncState stateService pause Jan 15 16:18:20 volumio volumio[923]: info: CoreStateMachine::syncState currentStatus pause Jan 15 16:18:20 volumio volumio[923]: info: CoreStateMachine::pushState Jan 15 16:18:20 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 15 16:18:20 volumio volumio[923]: info: CoreCommandRouter::volumioPushState Jan 15 16:18:20 volumio volumio[923]: info: CoreStateMachine::stPlaybackTimer Jan 15 16:18:20 volumio volumio[923]: info: ControllerMpd::pushState Jan 15 16:18:20 volumio volumio[923]: info: CoreCommandRouter::servicePushState Jan 15 16:18:20 volumio volumio[923]: info: CorePlayQueue::getTrack 0 Jan 15 16:18:20 volumio volumio[923]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":2167,"duration":191,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"dsd,pn=,ext=.dsf","artist":null,"album":null,"uri":"http://10.0.0.231:8200/MediaItems/A0$128$146$2239627541$2240020757$2288910613$19660210436.dsf?type=1,client=32,mime=audio/dsd,pn=,ext=.dsf","trackType":"dsf"} Jan 15 16:18:20 volumio volumio[923]: verbose: CURRENT POSITION 0 Jan 15 16:18:20 volumio volumio[923]: info: CoreStateMachine::syncState stateService pause Jan 15 16:18:20 volumio volumio[923]: info: CoreStateMachine::syncState currentStatus pause Jan 15 16:18:20 volumio volumio[923]: info: CoreStateMachine::pushState Jan 15 16:18:20 volumio volumio[923]: info: CoreCommandRouter::volumioPushState Jan 15 16:18:20 volumio volumio[923]: info: CoreStateMachine::stPlaybackTimer Jan 15 16:18:20 volumio volumio[923]: info: ControllerMpd::pushState Jan 15 16:18:20 volumio volumio[923]: info: CoreCommandRouter::servicePushState Jan 15 16:18:20 volumio volumio[923]: info: CorePlayQueue::getTrack 0 Jan 15 16:18:20 volumio volumio[923]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":2167,"duration":191,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"dsd,pn=,ext=.dsf","artist":null,"album":null,"uri":"http://10.0.0.231:8200/MediaItems/A0$128$146$2239627541$2240020757$2288910613$19660210436.dsf?type=1,client=32,mime=audio/dsd,pn=,ext=.dsf","trackType":"dsf"} Jan 15 16:18:20 volumio volumio[923]: verbose: CURRENT POSITION 0 Jan 15 16:18:20 volumio volumio[923]: info: CoreStateMachine::syncState stateService pause Jan 15 16:18:20 volumio volumio[923]: info: CoreStateMachine::syncState currentStatus pause Jan 15 16:18:20 volumio volumio[923]: info: CoreStateMachine::pushState Jan 15 16:18:20 volumio volumio[923]: info: CoreCommandRouter::volumioPushState Jan 15 16:18:20 volumio volumio[923]: info: CoreStateMachine::stPlaybackTimer Jan 15 16:18:20 volumio volumio[923]: info: ------------------------------ 36ms Jan 15 16:18:20 volumio volumio[923]: info: ------------------------------ 34ms Jan 15 16:18:20 volumio volumio[923]: info: ------------------------------ 34ms Jan 15 16:18:20 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Jan 15 16:18:20 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Jan 15 16:18:20 volumio volumio[923]: info: touch_display: Setting screensaver timeout to 120 seconds. Jan 15 16:18:24 volumio volumio[923]: info: CoreCommandRouter::volumioGetState Jan 15 16:18:26 volumio volumio[923]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 15 16:18:26 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Jan 15 16:18:26 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 15 16:18:26 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jan 15 16:18:26 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 15 16:18:26 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 15 16:18:26 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 15 16:18:26 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 15 16:18:26 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 15 16:18:26 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 15 16:18:26 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 15 16:18:26 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Jan 15 16:18:26 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jan 15 16:18:30 volumio volumio[923]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Jan 15 16:18:30 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Jan 15 16:18:30 volumio volumio[923]: info: Preparing to save Alsa Options, stopping services first Jan 15 16:18:30 volumio volumio[923]: info: CoreCommandRouter::volumioGetState Jan 15 16:18:30 volumio volumio[923]: info: CoreCommandRouter::volumioPause Jan 15 16:18:30 volumio volumio[923]: info: CoreStateMachine::pause Jan 15 16:18:30 volumio volumio[923]: info: Saving Audio Output to: {"output_device":{"value":"5","label":"HIFIMAN-SP1000"},"i2s":false,"i2sid":{"value":"adafruit-max98357","label":"Adafruit MAX98357"}} Jan 15 16:18:30 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jan 15 16:18:31 volumio volumio[923]: info: Setting mixer PCM for card HIFIMAN-SP1000 Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::volumioUpdateVolumeSettings Jan 15 16:18:31 volumio volumio[923]: info: Updating Volume Controller Parameters: Device: 5 Name: HIFIMAN-SP1000 Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Jan 15 16:18:31 volumio volumio[923]: info: Disabling external Volume Control Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 15 16:18:31 volumio volumio[923]: info: Preparing to generate the ALSA configuration file Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jan 15 16:18:31 volumio volumio[923]: info: VolumeController:: Volume=41 Mute =false Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::volumioGetState Jan 15 16:18:31 volumio volumio[923]: info: CoreStateMachine::pushState Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::volumioPushState Jan 15 16:18:31 volumio volumio[923]: info: Asound.conf file written Jan 15 16:18:31 volumio sudo[3180]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Jan 15 16:18:31 volumio sudo[3180]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 16:18:31 volumio sudo[3180]: pam_unix(sudo:session): session closed for user root Jan 15 16:18:31 volumio volumio[923]: info: Output device has changed, restarting MPD Jan 15 16:18:31 volumio sudo[3185]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 15 16:18:31 volumio sudo[3185]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 16:18:31 volumio volumio[923]: info: Output device has changed, restarting Shairport Sync Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 15 16:18:31 volumio sudo[3185]: pam_unix(sudo:session): session closed for user root Jan 15 16:18:31 volumio sudo[3188]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 15 16:18:31 volumio sudo[3188]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 16:18:31 volumio systemd[1]: musicservicesshield.service: Succeeded. Jan 15 16:18:31 volumio systemd[1]: Stopped Shield Volumio Music Services in the User CPU Set. Jan 15 16:18:31 volumio systemd[1]: Stopping Shield Volumio Music Services in the User CPU Set... Jan 15 16:18:31 volumio systemd[1]: Stopping Music Player Daemon... Jan 15 16:18:31 volumio volumio[923]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 15 16:18:31 volumio volumio[923]: info: Output device has changed, restarting MPD Jan 15 16:18:31 volumio systemd[1]: mpd.service: Succeeded. Jan 15 16:18:31 volumio systemd[1]: Stopped Music Player Daemon. Jan 15 16:18:31 volumio sudo[3195]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 15 16:18:31 volumio sudo[3195]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 16:18:31 volumio volumio[923]: info: Output device has changed, restarting Shairport Sync Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 15 16:18:31 volumio systemd[1]: Starting Music Player Daemon... Jan 15 16:18:31 volumio sudo[3195]: pam_unix(sudo:session): session closed for user root Jan 15 16:18:31 volumio sudo[3198]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 15 16:18:31 volumio sudo[3198]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 16:18:31 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Jan 15 16:18:31 volumio systemd[1]: mpd.service: Succeeded. Jan 15 16:18:31 volumio systemd[1]: Stopped Music Player Daemon. Jan 15 16:18:31 volumio systemd[1]: Starting Music Player Daemon... Jan 15 16:18:31 volumio volumio[923]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 15 16:18:31 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 Jan 15 16:18:31 volumio volumio[923]: SPOTIFY: SPOTIFY VOLUME 86 Jan 15 16:18:31 volumio volumio[923]: SPOTIFY: VOLUMIO VOLUME 41 Jan 15 16:18:31 volumio volumio[923]: SPOTIFY: DELTA VOLUME ENOUGH: true Jan 15 16:18:31 volumio volumio[923]: info: Setting Spotify Volume from Volumio: 41 Jan 15 16:18:31 volumio volumio[923]: info: MPD Permissions set Jan 15 16:18:31 volumio volumio[923]: info: MPD Permissions set Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::volumioGetState Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 16:18:31 volumio sudo[3204]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 15 16:18:31 volumio sudo[3204]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 16:18:31 volumio sudo[3204]: pam_unix(sudo:session): session closed for user root Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 15 16:18:31 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 16:18:31 volumio volumio[923]: info: Starting Shairport Sync Jan 15 16:18:31 volumio volumio[923]: info: Starting Shairport Sync Jan 15 16:18:31 volumio sudo[3216]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 15 16:18:31 volumio sudo[3216]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 16:18:31 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jan 15 16:18:31 volumio systemd[1]: shairport-sync.service: Succeeded. Jan 15 16:18:31 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jan 15 16:18:31 volumio sudo[3219]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 15 16:18:31 volumio sudo[3219]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 16:18:31 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jan 15 16:18:31 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jan 15 16:18:31 volumio sudo[3216]: pam_unix(sudo:session): session closed for user root Jan 15 16:18:31 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Jan 15 16:18:31 volumio systemd[1]: shairport-sync.service: Succeeded. Jan 15 16:18:31 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jan 15 16:18:31 volumio volumio[923]: info: Shairport-Sync Started Jan 15 16:18:31 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jan 15 16:18:31 volumio sudo[3219]: pam_unix(sudo:session): session closed for user root Jan 15 16:18:31 volumio volumio[923]: info: Shairport-Sync Started Jan 15 16:18:32 volumio mpd[3214]: Jan 15 16:18 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 15 16:18:32 volumio systemd[1]: Started Music Player Daemon. Jan 15 16:18:32 volumio sudo[3188]: pam_unix(sudo:session): session closed for user root Jan 15 16:18:32 volumio sudo[3198]: pam_unix(sudo:session): session closed for user root Jan 15 16:18:32 volumio volumio[923]: error: MPD error: The expression evaluated to a falsy value: Jan 15 16:18:32 volumio volumio[923]: assert.ok(self.idling) Jan 15 16:18:32 volumio volumio[923]: error: The expression evaluated to a falsy value: Jan 15 16:18:32 volumio volumio[923]: assert.ok(self.idling) Jan 15 16:18:32 volumio volumio[923]: error: updateQueue error: null Jan 15 16:18:32 volumio systemd[1]: Starting Shield Volumio Music Services in the User CPU Set... Jan 15 16:18:32 volumio volumio[3227]: cset: --> shielding system active with Jan 15 16:18:32 volumio volumio[3227]: cset: "system" cpuset of CPUSPEC(1-3) with 234 tasks running Jan 15 16:18:32 volumio volumio[3227]: cset: "user" cpuset of CPUSPEC(0) with 3 tasks running Jan 15 16:18:32 volumio systemd[1]: Started Shield Volumio Music Services in the User CPU Set. Jan 15 16:18:33 volumio volumio[923]: SPOTIFY: SETTING SPOTIFY VOLUME 41 Jan 15 16:18:33 volumio volumio[923]: info: Sending Spotify command with payload to local API: /player/volume Jan 15 16:18:35 volumio volumio[923]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Jan 15 16:18:35 volumio volumio[923]: info: CoreStateMachine::getcurrentVolume Jan 15 16:18:35 volumio volumio[923]: info: CoreCommandRouter::volumioRetrievevolume Jan 15 16:18:35 volumio volumio[923]: info: VolumeController:: Volume=41 Mute =false Jan 15 16:18:35 volumio volumio[923]: info: CoreCommandRouter::volumioGetState Jan 15 16:18:35 volumio volumio[923]: info: CoreStateMachine::pushState Jan 15 16:18:35 volumio volumio[923]: info: CoreCommandRouter::volumioPushState Jan 15 16:18:35 volumio volumio[923]: info: CoreStateMachine::updateTrackBlock Jan 15 16:18:35 volumio volumio[923]: info: CorePlayQueue::getTrackBlock Jan 15 16:18:35 volumio volumio[923]: info: CoreCommandRouter::volumioRetrievevolume Jan 15 16:18:35 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 Jan 15 16:18:35 volumio volumio[923]: info: VolumeController:: Volume=41 Mute =false Jan 15 16:18:35 volumio volumio[923]: info: CoreCommandRouter::volumioGetState Jan 15 16:18:35 volumio volumio[923]: info: CoreStateMachine::pushState Jan 15 16:18:35 volumio volumio[923]: info: CoreCommandRouter::volumioPushState Jan 15 16:18:35 volumio volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 Jan 15 16:18:40 volumio volumio[923]: info: CoreCommandRouter::volumioGetState Jan 15 16:19:03 volumio volumio[923]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 15 16:19:03 volumio volumio[923]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 15 16:19:03 volumio volumio[923]: TypeError: Cannot read property 'length' of undefined Jan 15 16:19:03 volumio volumio[923]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Jan 15 16:19:03 volumio volumio[923]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Jan 15 16:19:03 volumio volumio[923]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Jan 15 16:19:03 volumio volumio[923]: at Parser.emit (events.js:315:20) Jan 15 16:19:03 volumio volumio[923]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Jan 15 16:19:03 volumio volumio[923]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Jan 15 16:19:03 volumio volumio[923]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Jan 15 16:19:03 volumio volumio[923]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Jan 15 16:19:03 volumio volumio[923]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Jan 15 16:19:03 volumio volumio[923]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Jan 15 16:19:03 volumio volumio[923]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Jan 15 16:19:03 volumio volumio[923]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Jan 15 16:19:03 volumio volumio[923]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Jan 15 16:19:03 volumio volumio[923]: at IncomingMessage.emit (events.js:327:22) Jan 15 16:19:03 volumio volumio[923]: at endReadableNT (internal/streams/readable.js:1327:12) Jan 15 16:19:03 volumio volumio[923]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jan 15 16:19:03 volumio volumio[923]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 15 16:19:04 volumio sudo[3350]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-15 16:18 Jan 15 16:19:04 volumio sudo[3350]: 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="f6610a1100d2380eef33bd3004af43153c786f96" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="1c0e5daee99fe3a72cc38b0d1fe6cd78d7f001fe" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 16 Dec 2024 09:30:04 AM CET" VOLUMIO_VERSION="3.785" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fe0ac4b79aed19ccde4b5bd83d468193"