-- Logs begin at Thu 2019-02-14 13:11:59 MSK, end at Mon 2025-02-17 22:26:54 MSK. -- Feb 17 22:25:04 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Feb 17 22:25:05 volumio volumio[960]: info: Preload queue cleared Feb 17 22:25:05 volumio volumio[960]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$0 Feb 17 22:25:05 volumio volumio[960]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$1 Feb 17 22:25:05 volumio volumio[960]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$2 Feb 17 22:25:05 volumio volumio[960]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$3 Feb 17 22:25:05 volumio volumio[960]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$4 Feb 17 22:25:05 volumio volumio[960]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$5 Feb 17 22:25:05 volumio volumio[960]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$6 Feb 17 22:25:05 volumio volumio[960]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$7 Feb 17 22:25:05 volumio volumio[960]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$8 Feb 17 22:25:05 volumio volumio[960]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$9 Feb 17 22:25:05 volumio volumio[960]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$A Feb 17 22:25:05 volumio volumio[960]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$B Feb 17 22:25:05 volumio volumio[960]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$C Feb 17 22:25:05 volumio volumio[960]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$0 in service upnp_browser Feb 17 22:25:05 volumio volumio[960]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$1 in service upnp_browser Feb 17 22:25:05 volumio volumio[960]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$2 in service upnp_browser Feb 17 22:25:05 volumio volumio[960]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$3 in service upnp_browser Feb 17 22:25:05 volumio volumio[960]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$4 in service upnp_browser Feb 17 22:25:05 volumio volumio[960]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$5 in service upnp_browser Feb 17 22:25:05 volumio volumio[960]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$6 in service upnp_browser Feb 17 22:25:05 volumio volumio[960]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$7 in service upnp_browser Feb 17 22:25:05 volumio volumio[960]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$8 in service upnp_browser Feb 17 22:25:05 volumio volumio[960]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$9 in service upnp_browser Feb 17 22:25:05 volumio volumio[960]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$A in service upnp_browser Feb 17 22:25:05 volumio volumio[960]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$B in service upnp_browser Feb 17 22:25:05 volumio volumio[960]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$C in service upnp_browser Feb 17 22:25:06 volumio volumio[960]: info: Preload queue cleared Feb 17 22:25:06 volumio volumio[960]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 17 22:25:06 volumio volumio[960]: info: CoreStateMachine::ClearQueue Feb 17 22:25:06 volumio volumio[960]: info: CoreStateMachine::stop Feb 17 22:25:06 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 17 22:25:06 volumio volumio[960]: info: CoreStateMachine::stPlaybackTimer Feb 17 22:25:06 volumio volumio[960]: info: CoreStateMachine::updateTrackBlock Feb 17 22:25:06 volumio volumio[960]: info: CorePlayQueue::getTrackBlock Feb 17 22:25:06 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:25:06 volumio volumio[960]: info: CorePlayQueue::getTrack 1 Feb 17 22:25:06 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 22:25:06 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:25:06 volumio volumio[960]: info: CoreStateMachine::serviceStop Feb 17 22:25:06 volumio volumio[960]: info: CorePlayQueue::getTrack 1 Feb 17 22:25:06 volumio volumio[960]: info: CoreCommandRouter::serviceStop Feb 17 22:25:06 volumio volumio[960]: info: [1739820306406] ControllerUPNPBrowser::stop Feb 17 22:25:06 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand stop Feb 17 22:25:06 volumio volumio[960]: info: CorePlayQueue::clearPlayQueue Feb 17 22:25:06 volumio volumio[960]: info: CorePlayQueue::saveQueue Feb 17 22:25:06 volumio volumio[960]: info: CoreCommandRouter::volumioPushQueue Feb 17 22:25:06 volumio volumio[960]: info: CoreStateMachine::addQueueItems Feb 17 22:25:06 volumio volumio[960]: info: CorePlayQueue::addQueueItems Feb 17 22:25:06 volumio volumio[960]: info: Preload queue cleared Feb 17 22:25:06 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$0 Feb 17 22:25:06 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$0 Feb 17 22:25:06 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$1 Feb 17 22:25:06 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$1 Feb 17 22:25:06 volumio volumio[960]: info: CoreCommandRouter::volumioPushQueue Feb 17 22:25:06 volumio volumio[960]: info: CorePlayQueue::saveQueue Feb 17 22:25:06 volumio volumio[960]: info: CoreStateMachine::updateTrackBlock Feb 17 22:25:06 volumio volumio[960]: info: CorePlayQueue::getTrackBlock Feb 17 22:25:06 volumio volumio[960]: info: CoreCommandRouter::volumioPlay Feb 17 22:25:06 volumio volumio[960]: info: CoreStateMachine::play index 1 Feb 17 22:25:06 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 17 22:25:06 volumio volumio[960]: info: CoreStateMachine::addQueueItems Feb 17 22:25:06 volumio volumio[960]: info: CorePlayQueue::addQueueItems Feb 17 22:25:06 volumio volumio[960]: info: Preload queue cleared Feb 17 22:25:06 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$2 Feb 17 22:25:06 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$2 Feb 17 22:25:06 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$3 Feb 17 22:25:06 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$3 Feb 17 22:25:06 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$4 Feb 17 22:25:06 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$4 Feb 17 22:25:06 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$5 Feb 17 22:25:06 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$5 Feb 17 22:25:06 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$6 Feb 17 22:25:06 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$6 Feb 17 22:25:06 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$7 Feb 17 22:25:06 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$7 Feb 17 22:25:06 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$8 Feb 17 22:25:06 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$8 Feb 17 22:25:06 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$9 Feb 17 22:25:06 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$9 Feb 17 22:25:06 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$A Feb 17 22:25:06 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$A Feb 17 22:25:06 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$B Feb 17 22:25:06 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$B Feb 17 22:25:06 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$C Feb 17 22:25:06 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$C Feb 17 22:25:06 volumio volumio[960]: info: CoreStateMachine::stop Feb 17 22:25:06 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 17 22:25:06 volumio volumio[960]: info: CoreCommandRouter::volumioPushQueue Feb 17 22:25:06 volumio volumio[960]: info: CorePlayQueue::saveQueue Feb 17 22:25:06 volumio volumio[960]: info: CoreStateMachine::play index undefined Feb 17 22:25:06 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 17 22:25:06 volumio volumio[960]: info: CoreStateMachine::updateTrackBlock Feb 17 22:25:06 volumio volumio[960]: info: CorePlayQueue::getTrackBlock Feb 17 22:25:06 volumio volumio[960]: info: CorePlayQueue::getTrack 1 Feb 17 22:25:06 volumio volumio[960]: info: CoreStateMachine::startPlaybackTimer Feb 17 22:25:06 volumio volumio[960]: info: CorePlayQueue::getTrack 1 Feb 17 22:25:06 volumio volumio[960]: info: [1739820306459] ControllerUPNPBrowser::clearAddPlayTrack Feb 17 22:25:06 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand stop Feb 17 22:25:06 volumio volumio[960]: info: Feb 17 22:25:06 volumio volumio[960]: ---------------------------- MPD announces state update: player Feb 17 22:25:06 volumio volumio[960]: info: sendMpdCommand stop took 143 milliseconds Feb 17 22:25:06 volumio volumio[960]: info: ControllerMpd::getState Feb 17 22:25:06 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status Feb 17 22:25:06 volumio volumio[960]: info: sendMpdCommand stop took 91 milliseconds Feb 17 22:25:06 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand clear Feb 17 22:25:06 volumio volumio[960]: info: Feb 17 22:25:06 volumio volumio[960]: ---------------------------- MPD announces state update: player Feb 17 22:25:06 volumio volumio[960]: info: ControllerMpd::getState Feb 17 22:25:06 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status Feb 17 22:25:06 volumio volumio[960]: info: Feb 17 22:25:06 volumio volumio[960]: ---------------------------- MPD announces system playlist update Feb 17 22:25:06 volumio volumio[960]: info: Ignoring MPD Status Update Feb 17 22:25:06 volumio volumio[960]: info: sendMpdCommand status took 6 milliseconds Feb 17 22:25:06 volumio volumio[960]: info: sendMpdCommand clear took 5 milliseconds Feb 17 22:25:06 volumio volumio[960]: info: sendMpdCommand status took 3 milliseconds Feb 17 22:25:06 volumio volumio[960]: verbose: ControllerMpd::parseState Feb 17 22:25:06 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 17 22:25:06 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.1:8200/MediaItems/12443.flac" Feb 17 22:25:06 volumio volumio[960]: verbose: ControllerMpd::parseState Feb 17 22:25:06 volumio volumio[960]: info: ControllerMpd::pushState Feb 17 22:25:06 volumio volumio[960]: info: CoreCommandRouter::servicePushState Feb 17 22:25:06 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:25:06 volumio volumio[960]: info: CorePlayQueue::getTrack 1 Feb 17 22:25:06 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 22:25:06 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:25:06 volumio volumio[960]: info: CorePlayQueue::getTrack 1 Feb 17 22:25:06 volumio volumio[960]: 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} Feb 17 22:25:06 volumio volumio[960]: verbose: CURRENT POSITION 1 Feb 17 22:25:06 volumio volumio[960]: info: CoreStateMachine::syncState stateService stop Feb 17 22:25:06 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus stop Feb 17 22:25:06 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:25:06 volumio volumio[960]: info: CorePlayQueue::getTrack 1 Feb 17 22:25:06 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:25:06 volumio volumio[960]: info: No code Feb 17 22:25:06 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:25:06 volumio volumio[960]: info: CorePlayQueue::getTrack 1 Feb 17 22:25:06 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:25:06 volumio volumio[960]: info: ------------------------------ 54ms Feb 17 22:25:06 volumio volumio[960]: info: Feb 17 22:25:06 volumio volumio[960]: ---------------------------- MPD announces system playlist update Feb 17 22:25:06 volumio volumio[960]: info: Ignoring MPD Status Update Feb 17 22:25:06 volumio volumio[960]: error: updateQueue error: null Feb 17 22:25:06 volumio volumio[960]: info: ------------------------------ 56ms Feb 17 22:25:06 volumio volumio[960]: info: sendMpdCommand playlistinfo took 54 milliseconds Feb 17 22:25:06 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo Feb 17 22:25:06 volumio volumio[960]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Feb 17 22:25:06 volumio volumio[960]: info: ------------------------------ 64ms Feb 17 22:25:06 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.1:8200/MediaItems/12443.flac" Feb 17 22:25:06 volumio volumio[960]: error: updateQueue error: null Feb 17 22:25:06 volumio volumio[960]: info: Feb 17 22:25:06 volumio volumio[960]: ---------------------------- MPD announces system playlist update Feb 17 22:25:06 volumio volumio[960]: info: Ignoring MPD Status Update Feb 17 22:25:06 volumio volumio[960]: info: ------------------------------ 104ms Feb 17 22:25:06 volumio volumio[960]: info: sendMpdCommand add "http://192.168.1.1:8200/MediaItems/12443.flac" took 3 milliseconds Feb 17 22:25:06 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 17 22:25:06 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand play Feb 17 22:25:06 volumio volumio[960]: info: Feb 17 22:25:06 volumio volumio[960]: ---------------------------- MPD announces system playlist update Feb 17 22:25:06 volumio volumio[960]: info: Ignoring MPD Status Update Feb 17 22:25:06 volumio volumio[960]: info: ------------------------------ 8ms Feb 17 22:25:06 volumio volumio[960]: info: sendMpdCommand play took 6 milliseconds Feb 17 22:25:06 volumio volumio[960]: info: ------------------------------ 4ms Feb 17 22:25:06 volumio volumio[960]: info: Feb 17 22:25:06 volumio volumio[960]: ---------------------------- MPD announces state update: player Feb 17 22:25:06 volumio volumio[960]: info: ControllerMpd::getState Feb 17 22:25:06 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status Feb 17 22:25:06 volumio volumio[960]: info: Feb 17 22:25:06 volumio volumio[960]: ---------------------------- MPD announces state update: player Feb 17 22:25:06 volumio volumio[960]: info: ControllerMpd::getState Feb 17 22:25:06 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status Feb 17 22:25:07 volumio volumio[960]: info: sendMpdCommand status took 535 milliseconds Feb 17 22:25:07 volumio volumio[960]: verbose: ControllerMpd::parseState Feb 17 22:25:07 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 17 22:25:07 volumio volumio[960]: info: Feb 17 22:25:07 volumio volumio[960]: ---------------------------- MPD announces system playlist update Feb 17 22:25:07 volumio volumio[960]: info: Ignoring MPD Status Update Feb 17 22:25:07 volumio volumio[960]: info: Feb 17 22:25:07 volumio volumio[960]: ---------------------------- MPD announces state update: player Feb 17 22:25:07 volumio volumio[960]: info: ControllerMpd::getState Feb 17 22:25:07 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status Feb 17 22:25:07 volumio volumio[960]: info: sendMpdCommand status took 539 milliseconds Feb 17 22:25:07 volumio volumio[960]: verbose: ControllerMpd::parseState Feb 17 22:25:07 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 17 22:25:07 volumio volumio[960]: info: Feb 17 22:25:07 volumio volumio[960]: ---------------------------- MPD announces system playlist update Feb 17 22:25:07 volumio volumio[960]: info: Ignoring MPD Status Update Feb 17 22:25:07 volumio volumio[960]: info: Feb 17 22:25:07 volumio volumio[960]: ---------------------------- MPD announces state update: player Feb 17 22:25:07 volumio volumio[960]: info: ControllerMpd::getState Feb 17 22:25:07 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status Feb 17 22:25:07 volumio volumio[960]: info: sendMpdCommand playlistinfo took 16 milliseconds Feb 17 22:25:07 volumio volumio[960]: info: ------------------------------ 16ms Feb 17 22:25:07 volumio volumio[960]: info: sendMpdCommand status took 15 milliseconds Feb 17 22:25:07 volumio volumio[960]: info: sendMpdCommand playlistinfo took 13 milliseconds Feb 17 22:25:07 volumio volumio[960]: info: ------------------------------ 11ms Feb 17 22:25:07 volumio volumio[960]: info: sendMpdCommand status took 9 milliseconds Feb 17 22:25:07 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo Feb 17 22:25:07 volumio volumio[960]: verbose: ControllerMpd::parseState Feb 17 22:25:07 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 17 22:25:07 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo Feb 17 22:25:07 volumio volumio[960]: verbose: ControllerMpd::parseState Feb 17 22:25:07 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 17 22:25:07 volumio volumio[960]: info: ControllerMpd::pushState Feb 17 22:25:07 volumio volumio[960]: info: CoreCommandRouter::servicePushState Feb 17 22:25:07 volumio volumio[960]: info: CorePlayQueue::getTrack 1 Feb 17 22:25:07 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":222,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Twilight","artist":"Electric Light Orchestra","album":"Time","uri":"http://192.168.1.1:8200/MediaItems/12443.flac","trackType":"flac"} Feb 17 22:25:07 volumio volumio[960]: verbose: CURRENT POSITION 1 Feb 17 22:25:07 volumio volumio[960]: info: CoreStateMachine::syncState stateService play Feb 17 22:25:07 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus stop Feb 17 22:25:07 volumio volumio[960]: info: ControllerMpd::pushState Feb 17 22:25:07 volumio volumio[960]: info: CoreCommandRouter::servicePushState Feb 17 22:25:07 volumio volumio[960]: info: CorePlayQueue::getTrack 1 Feb 17 22:25:07 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":598,"duration":222,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1865 Kbps","isStreaming":false,"title":"Twilight","artist":"Electric Light Orchestra","album":"Time","uri":"http://192.168.1.1:8200/MediaItems/12443.flac","trackType":"flac"} Feb 17 22:25:07 volumio volumio[960]: verbose: CURRENT POSITION 1 Feb 17 22:25:07 volumio volumio[960]: info: CoreStateMachine::syncState stateService play Feb 17 22:25:07 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus play Feb 17 22:25:07 volumio volumio[960]: info: Received an update from plugin. extracting info from payload Feb 17 22:25:07 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:25:07 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 22:25:07 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:25:07 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:25:07 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:25:07 volumio volumio[960]: info: ------------------------------ 580ms Feb 17 22:25:07 volumio volumio[960]: info: ------------------------------ 599ms Feb 17 22:25:07 volumio volumio[960]: info: sendMpdCommand playlistinfo took 44 milliseconds Feb 17 22:25:07 volumio volumio[960]: info: sendMpdCommand playlistinfo took 43 milliseconds Feb 17 22:25:07 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo Feb 17 22:25:07 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo Feb 17 22:25:07 volumio volumio[960]: info: ControllerMpd::pushState Feb 17 22:25:07 volumio volumio[960]: info: CoreCommandRouter::servicePushState Feb 17 22:25:07 volumio volumio[960]: info: CorePlayQueue::getTrack 1 Feb 17 22:25:07 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":986,"duration":222,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1832 Kbps","isStreaming":false,"title":"Twilight","artist":"Electric Light Orchestra","album":"Time","uri":"http://192.168.1.1:8200/MediaItems/12443.flac","trackType":"flac"} Feb 17 22:25:07 volumio volumio[960]: verbose: CURRENT POSITION 1 Feb 17 22:25:07 volumio volumio[960]: info: CoreStateMachine::syncState stateService play Feb 17 22:25:07 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus play Feb 17 22:25:07 volumio volumio[960]: info: Received an update from plugin. extracting info from payload Feb 17 22:25:07 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:25:07 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 22:25:07 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:25:07 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:25:07 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:25:07 volumio volumio[960]: info: ControllerMpd::pushState Feb 17 22:25:07 volumio volumio[960]: info: CoreCommandRouter::servicePushState Feb 17 22:25:07 volumio volumio[960]: info: CorePlayQueue::getTrack 1 Feb 17 22:25:07 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":986,"duration":222,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1832 Kbps","isStreaming":false,"title":"Twilight","artist":"Electric Light Orchestra","album":"Time","uri":"http://192.168.1.1:8200/MediaItems/12443.flac","trackType":"flac"} Feb 17 22:25:07 volumio volumio[960]: verbose: CURRENT POSITION 1 Feb 17 22:25:07 volumio volumio[960]: info: CoreStateMachine::syncState stateService play Feb 17 22:25:07 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus play Feb 17 22:25:07 volumio volumio[960]: info: Received an update from plugin. extracting info from payload Feb 17 22:25:07 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:25:07 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:25:07 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:25:07 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:25:07 volumio volumio[960]: info: ------------------------------ 149ms Feb 17 22:25:07 volumio volumio[960]: info: ------------------------------ 143ms Feb 17 22:25:07 volumio volumio[960]: info: CoreCommandRouter::volumioGetQueue Feb 17 22:25:07 volumio volumio[960]: info: CoreStateMachine::getQueue Feb 17 22:25:07 volumio volumio[960]: info: CorePlayQueue::getQueue Feb 17 22:25:07 volumio volumio[960]: info: CoreCommandRouter::volumioGetQueue Feb 17 22:25:07 volumio volumio[960]: info: CoreStateMachine::getQueue Feb 17 22:25:07 volumio volumio[960]: info: CorePlayQueue::getQueue Feb 17 22:25:07 volumio volumio[960]: info: CoreCommandRouter::volumioGetQueue Feb 17 22:25:07 volumio volumio[960]: info: CoreStateMachine::getQueue Feb 17 22:25:07 volumio volumio[960]: info: CorePlayQueue::getQueue Feb 17 22:25:07 volumio volumio[960]: info: CoreCommandRouter::volumioGetQueue Feb 17 22:25:07 volumio volumio[960]: info: CoreStateMachine::getQueue Feb 17 22:25:07 volumio volumio[960]: info: CorePlayQueue::getQueue Feb 17 22:25:07 volumio volumio[960]: info: CoreCommandRouter::volumioGetQueue Feb 17 22:25:07 volumio volumio[960]: info: CoreStateMachine::getQueue Feb 17 22:25:07 volumio volumio[960]: info: CorePlayQueue::getQueue Feb 17 22:25:07 volumio volumio[960]: info: CoreCommandRouter::volumioGetQueue Feb 17 22:25:07 volumio volumio[960]: info: CoreStateMachine::getQueue Feb 17 22:25:07 volumio volumio[960]: info: CorePlayQueue::getQueue Feb 17 22:25:34 volumio volumio[960]: info: Preload queue cleared Feb 17 22:25:34 volumio volumio[960]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 17 22:25:34 volumio volumio[960]: info: CoreStateMachine::ClearQueue Feb 17 22:25:34 volumio volumio[960]: info: CoreStateMachine::stop Feb 17 22:25:34 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 17 22:25:34 volumio volumio[960]: info: CoreStateMachine::stPlaybackTimer Feb 17 22:25:34 volumio volumio[960]: info: CoreStateMachine::updateTrackBlock Feb 17 22:25:34 volumio volumio[960]: info: CorePlayQueue::getTrackBlock Feb 17 22:25:34 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:25:34 volumio volumio[960]: info: CorePlayQueue::getTrack 1 Feb 17 22:25:34 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 22:25:34 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:25:34 volumio volumio[960]: info: CoreStateMachine::serviceStop Feb 17 22:25:34 volumio volumio[960]: info: CorePlayQueue::getTrack 1 Feb 17 22:25:34 volumio volumio[960]: info: CoreCommandRouter::serviceStop Feb 17 22:25:34 volumio volumio[960]: info: [1739820334713] ControllerUPNPBrowser::stop Feb 17 22:25:34 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand stop Feb 17 22:25:34 volumio volumio[960]: info: CorePlayQueue::clearPlayQueue Feb 17 22:25:34 volumio volumio[960]: info: CorePlayQueue::saveQueue Feb 17 22:25:34 volumio volumio[960]: info: CoreCommandRouter::volumioPushQueue Feb 17 22:25:34 volumio volumio[960]: info: CoreStateMachine::addQueueItems Feb 17 22:25:34 volumio volumio[960]: info: CorePlayQueue::addQueueItems Feb 17 22:25:34 volumio volumio[960]: info: Preload queue cleared Feb 17 22:25:34 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$0 Feb 17 22:25:34 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$0 Feb 17 22:25:34 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$1 Feb 17 22:25:34 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$1 Feb 17 22:25:34 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$2 Feb 17 22:25:34 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$2 Feb 17 22:25:34 volumio volumio[960]: info: CoreCommandRouter::volumioPushQueue Feb 17 22:25:34 volumio volumio[960]: info: CorePlayQueue::saveQueue Feb 17 22:25:34 volumio volumio[960]: info: CoreStateMachine::updateTrackBlock Feb 17 22:25:34 volumio volumio[960]: info: CorePlayQueue::getTrackBlock Feb 17 22:25:34 volumio volumio[960]: info: CoreCommandRouter::volumioPlay Feb 17 22:25:34 volumio volumio[960]: info: CoreStateMachine::play index 2 Feb 17 22:25:34 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 17 22:25:34 volumio volumio[960]: info: CoreStateMachine::addQueueItems Feb 17 22:25:34 volumio volumio[960]: info: CorePlayQueue::addQueueItems Feb 17 22:25:34 volumio volumio[960]: info: Preload queue cleared Feb 17 22:25:34 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$3 Feb 17 22:25:34 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$3 Feb 17 22:25:34 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$4 Feb 17 22:25:34 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$4 Feb 17 22:25:34 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$5 Feb 17 22:25:34 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$5 Feb 17 22:25:34 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$6 Feb 17 22:25:34 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$6 Feb 17 22:25:34 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$7 Feb 17 22:25:34 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$7 Feb 17 22:25:34 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$8 Feb 17 22:25:34 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$8 Feb 17 22:25:34 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$9 Feb 17 22:25:34 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$9 Feb 17 22:25:34 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$A Feb 17 22:25:34 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$A Feb 17 22:25:34 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$B Feb 17 22:25:34 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$B Feb 17 22:25:34 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$C Feb 17 22:25:34 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$0$C Feb 17 22:25:34 volumio volumio[960]: info: CoreStateMachine::stop Feb 17 22:25:34 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 17 22:25:34 volumio volumio[960]: info: CoreCommandRouter::volumioPushQueue Feb 17 22:25:34 volumio volumio[960]: info: CorePlayQueue::saveQueue Feb 17 22:25:34 volumio volumio[960]: info: CoreStateMachine::play index undefined Feb 17 22:25:34 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 17 22:25:34 volumio volumio[960]: info: CoreStateMachine::updateTrackBlock Feb 17 22:25:34 volumio volumio[960]: info: CorePlayQueue::getTrackBlock Feb 17 22:25:34 volumio volumio[960]: info: CorePlayQueue::getTrack 2 Feb 17 22:25:34 volumio volumio[960]: info: CoreStateMachine::startPlaybackTimer Feb 17 22:25:34 volumio volumio[960]: info: CorePlayQueue::getTrack 2 Feb 17 22:25:34 volumio volumio[960]: info: [1739820334761] ControllerUPNPBrowser::clearAddPlayTrack Feb 17 22:25:34 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand stop Feb 17 22:25:34 volumio volumio[960]: info: Feb 17 22:25:34 volumio volumio[960]: ---------------------------- MPD announces state update: player Feb 17 22:25:34 volumio volumio[960]: info: sendMpdCommand stop took 165 milliseconds Feb 17 22:25:34 volumio volumio[960]: info: ControllerMpd::getState Feb 17 22:25:34 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status Feb 17 22:25:34 volumio volumio[960]: info: sendMpdCommand stop took 118 milliseconds Feb 17 22:25:34 volumio volumio[960]: info: sendMpdCommand status took 2 milliseconds Feb 17 22:25:34 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand clear Feb 17 22:25:34 volumio volumio[960]: verbose: ControllerMpd::parseState Feb 17 22:25:34 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 17 22:25:34 volumio volumio[960]: info: Feb 17 22:25:34 volumio volumio[960]: ---------------------------- MPD announces state update: player Feb 17 22:25:34 volumio volumio[960]: info: ControllerMpd::getState Feb 17 22:25:34 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status Feb 17 22:25:34 volumio volumio[960]: info: Feb 17 22:25:34 volumio volumio[960]: ---------------------------- MPD announces system playlist update Feb 17 22:25:34 volumio volumio[960]: info: Ignoring MPD Status Update Feb 17 22:25:34 volumio volumio[960]: info: sendMpdCommand clear took 5 milliseconds Feb 17 22:25:34 volumio volumio[960]: info: sendMpdCommand playlistinfo took 6 milliseconds Feb 17 22:25:34 volumio volumio[960]: info: sendMpdCommand status took 3 milliseconds Feb 17 22:25:34 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.1:8200/MediaItems/12444.flac" Feb 17 22:25:34 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo Feb 17 22:25:34 volumio volumio[960]: verbose: ControllerMpd::parseState Feb 17 22:25:34 volumio volumio[960]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Feb 17 22:25:34 volumio volumio[960]: info: ControllerMpd::pushState Feb 17 22:25:34 volumio volumio[960]: info: CoreCommandRouter::servicePushState Feb 17 22:25:34 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:25:34 volumio volumio[960]: info: CorePlayQueue::getTrack 2 Feb 17 22:25:34 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 22:25:34 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:25:34 volumio volumio[960]: info: CorePlayQueue::getTrack 2 Feb 17 22:25:34 volumio volumio[960]: 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} Feb 17 22:25:34 volumio volumio[960]: verbose: CURRENT POSITION 2 Feb 17 22:25:34 volumio volumio[960]: info: CoreStateMachine::syncState stateService stop Feb 17 22:25:34 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus stop Feb 17 22:25:34 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:25:34 volumio volumio[960]: info: CorePlayQueue::getTrack 2 Feb 17 22:25:34 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:25:34 volumio volumio[960]: info: No code Feb 17 22:25:34 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:25:34 volumio volumio[960]: info: CorePlayQueue::getTrack 2 Feb 17 22:25:34 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:25:34 volumio volumio[960]: info: ------------------------------ 30ms Feb 17 22:25:34 volumio volumio[960]: info: ------------------------------ 51ms Feb 17 22:25:34 volumio volumio[960]: info: Feb 17 22:25:34 volumio volumio[960]: ---------------------------- MPD announces system playlist update Feb 17 22:25:34 volumio volumio[960]: info: Ignoring MPD Status Update Feb 17 22:25:34 volumio volumio[960]: error: updateQueue error: null Feb 17 22:25:34 volumio volumio[960]: info: ------------------------------ 52ms Feb 17 22:25:35 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.1:8200/MediaItems/12444.flac" Feb 17 22:25:35 volumio volumio[960]: error: updateQueue error: null Feb 17 22:25:35 volumio volumio[960]: info: ------------------------------ 356ms Feb 17 22:25:35 volumio volumio[960]: info: Feb 17 22:25:35 volumio volumio[960]: ---------------------------- MPD announces system playlist update Feb 17 22:25:35 volumio volumio[960]: info: Ignoring MPD Status Update Feb 17 22:25:35 volumio volumio[960]: info: sendMpdCommand add "http://192.168.1.1:8200/MediaItems/12444.flac" took 4 milliseconds Feb 17 22:25:35 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 17 22:25:35 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand play Feb 17 22:25:35 volumio volumio[960]: info: Feb 17 22:25:35 volumio volumio[960]: ---------------------------- MPD announces system playlist update Feb 17 22:25:35 volumio volumio[960]: info: Ignoring MPD Status Update Feb 17 22:25:35 volumio volumio[960]: info: ------------------------------ 6ms Feb 17 22:25:35 volumio volumio[960]: info: sendMpdCommand play took 5 milliseconds Feb 17 22:25:35 volumio volumio[960]: info: ------------------------------ 5ms Feb 17 22:25:35 volumio volumio[960]: info: Feb 17 22:25:35 volumio volumio[960]: ---------------------------- MPD announces state update: player Feb 17 22:25:35 volumio volumio[960]: info: ControllerMpd::getState Feb 17 22:25:35 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status Feb 17 22:25:35 volumio volumio[960]: info: Feb 17 22:25:35 volumio volumio[960]: ---------------------------- MPD announces state update: player Feb 17 22:25:35 volumio volumio[960]: info: ControllerMpd::getState Feb 17 22:25:35 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status Feb 17 22:25:35 volumio volumio[960]: info: Feb 17 22:25:35 volumio volumio[960]: ---------------------------- MPD announces system playlist update Feb 17 22:25:35 volumio volumio[960]: info: Ignoring MPD Status Update Feb 17 22:25:35 volumio volumio[960]: info: Feb 17 22:25:35 volumio volumio[960]: ---------------------------- MPD announces state update: player Feb 17 22:25:35 volumio volumio[960]: info: sendMpdCommand status took 308 milliseconds Feb 17 22:25:35 volumio volumio[960]: info: ControllerMpd::getState Feb 17 22:25:35 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status Feb 17 22:25:35 volumio volumio[960]: verbose: ControllerMpd::parseState Feb 17 22:25:35 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 17 22:25:35 volumio volumio[960]: info: sendMpdCommand status took 308 milliseconds Feb 17 22:25:35 volumio volumio[960]: verbose: ControllerMpd::parseState Feb 17 22:25:35 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 17 22:25:35 volumio volumio[960]: info: Feb 17 22:25:35 volumio volumio[960]: ---------------------------- MPD announces system playlist update Feb 17 22:25:35 volumio volumio[960]: info: Ignoring MPD Status Update Feb 17 22:25:35 volumio volumio[960]: info: Feb 17 22:25:35 volumio volumio[960]: ---------------------------- MPD announces state update: player Feb 17 22:25:35 volumio volumio[960]: info: ControllerMpd::getState Feb 17 22:25:35 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status Feb 17 22:25:35 volumio volumio[960]: info: ------------------------------ 17ms Feb 17 22:25:35 volumio volumio[960]: info: sendMpdCommand status took 13 milliseconds Feb 17 22:25:35 volumio volumio[960]: info: sendMpdCommand playlistinfo took 13 milliseconds Feb 17 22:25:35 volumio volumio[960]: info: sendMpdCommand playlistinfo took 11 milliseconds Feb 17 22:25:35 volumio volumio[960]: info: ------------------------------ 9ms Feb 17 22:25:35 volumio volumio[960]: verbose: ControllerMpd::parseState Feb 17 22:25:35 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 17 22:25:35 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo Feb 17 22:25:35 volumio volumio[960]: info: ControllerMpd::pushState Feb 17 22:25:35 volumio volumio[960]: info: CoreCommandRouter::servicePushState Feb 17 22:25:35 volumio volumio[960]: info: CorePlayQueue::getTrack 2 Feb 17 22:25:35 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":191,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Yours Truly, 2095","artist":"Electric Light Orchestra","album":"Time","uri":"http://192.168.1.1:8200/MediaItems/12444.flac","trackType":"flac"} Feb 17 22:25:35 volumio volumio[960]: verbose: CURRENT POSITION 2 Feb 17 22:25:35 volumio volumio[960]: info: CoreStateMachine::syncState stateService play Feb 17 22:25:35 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus stop Feb 17 22:25:35 volumio volumio[960]: info: ControllerMpd::pushState Feb 17 22:25:35 volumio volumio[960]: info: CoreCommandRouter::servicePushState Feb 17 22:25:35 volumio volumio[960]: info: CorePlayQueue::getTrack 2 Feb 17 22:25:35 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":399,"duration":191,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1768 Kbps","isStreaming":false,"title":"Yours Truly, 2095","artist":"Electric Light Orchestra","album":"Time","uri":"http://192.168.1.1:8200/MediaItems/12444.flac","trackType":"flac"} Feb 17 22:25:35 volumio volumio[960]: verbose: CURRENT POSITION 2 Feb 17 22:25:35 volumio volumio[960]: info: CoreStateMachine::syncState stateService play Feb 17 22:25:35 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus play Feb 17 22:25:35 volumio volumio[960]: info: Received an update from plugin. extracting info from payload Feb 17 22:25:35 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:25:35 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 22:25:35 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:25:35 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:25:35 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:25:35 volumio volumio[960]: info: ------------------------------ 350ms Feb 17 22:25:35 volumio volumio[960]: info: ------------------------------ 368ms Feb 17 22:25:35 volumio volumio[960]: info: sendMpdCommand status took 56 milliseconds Feb 17 22:25:35 volumio volumio[960]: info: sendMpdCommand playlistinfo took 48 milliseconds Feb 17 22:25:35 volumio volumio[960]: verbose: ControllerMpd::parseState Feb 17 22:25:35 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 17 22:25:35 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo Feb 17 22:25:35 volumio volumio[960]: info: ControllerMpd::pushState Feb 17 22:25:35 volumio volumio[960]: info: CoreCommandRouter::servicePushState Feb 17 22:25:35 volumio volumio[960]: info: CorePlayQueue::getTrack 2 Feb 17 22:25:35 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":986,"duration":191,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1681 Kbps","isStreaming":false,"title":"Yours Truly, 2095","artist":"Electric Light Orchestra","album":"Time","uri":"http://192.168.1.1:8200/MediaItems/12444.flac","trackType":"flac"} Feb 17 22:25:35 volumio volumio[960]: verbose: CURRENT POSITION 2 Feb 17 22:25:35 volumio volumio[960]: info: CoreStateMachine::syncState stateService play Feb 17 22:25:35 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus play Feb 17 22:25:35 volumio volumio[960]: info: Received an update from plugin. extracting info from payload Feb 17 22:25:35 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:25:35 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 22:25:35 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:25:35 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:25:35 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:25:35 volumio volumio[960]: info: ------------------------------ 106ms Feb 17 22:25:35 volumio volumio[960]: info: CoreCommandRouter::volumioGetQueue Feb 17 22:25:35 volumio volumio[960]: info: CoreStateMachine::getQueue Feb 17 22:25:35 volumio volumio[960]: info: CorePlayQueue::getQueue Feb 17 22:25:35 volumio volumio[960]: info: CoreCommandRouter::volumioGetQueue Feb 17 22:25:35 volumio volumio[960]: info: CoreStateMachine::getQueue Feb 17 22:25:35 volumio volumio[960]: info: CorePlayQueue::getQueue Feb 17 22:25:35 volumio volumio[960]: info: CoreCommandRouter::volumioGetQueue Feb 17 22:25:35 volumio volumio[960]: info: CoreStateMachine::getQueue Feb 17 22:25:35 volumio volumio[960]: info: CorePlayQueue::getQueue Feb 17 22:25:35 volumio volumio[960]: info: CoreCommandRouter::volumioGetQueue Feb 17 22:25:35 volumio volumio[960]: info: CoreStateMachine::getQueue Feb 17 22:25:35 volumio volumio[960]: info: CorePlayQueue::getQueue Feb 17 22:25:35 volumio volumio[960]: info: sendMpdCommand playlistinfo took 122 milliseconds Feb 17 22:25:35 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo Feb 17 22:25:35 volumio volumio[960]: info: ControllerMpd::pushState Feb 17 22:25:35 volumio volumio[960]: info: CoreCommandRouter::servicePushState Feb 17 22:25:35 volumio volumio[960]: info: CorePlayQueue::getTrack 2 Feb 17 22:25:35 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":986,"duration":191,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1681 Kbps","isStreaming":false,"title":"Yours Truly, 2095","artist":"Electric Light Orchestra","album":"Time","uri":"http://192.168.1.1:8200/MediaItems/12444.flac","trackType":"flac"} Feb 17 22:25:35 volumio volumio[960]: verbose: CURRENT POSITION 2 Feb 17 22:25:35 volumio volumio[960]: info: CoreStateMachine::syncState stateService play Feb 17 22:25:35 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus play Feb 17 22:25:35 volumio volumio[960]: info: Received an update from plugin. extracting info from payload Feb 17 22:25:35 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:25:35 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 22:25:35 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:25:35 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:25:35 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:25:35 volumio volumio[960]: info: ------------------------------ 219ms Feb 17 22:25:35 volumio volumio[960]: info: CoreCommandRouter::volumioGetQueue Feb 17 22:25:35 volumio volumio[960]: info: CoreStateMachine::getQueue Feb 17 22:25:35 volumio volumio[960]: info: CorePlayQueue::getQueue Feb 17 22:25:35 volumio volumio[960]: info: CoreCommandRouter::volumioGetQueue Feb 17 22:25:35 volumio volumio[960]: info: CoreStateMachine::getQueue Feb 17 22:25:35 volumio volumio[960]: info: CorePlayQueue::getQueue Feb 17 22:25:46 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Feb 17 22:25:46 volumio volumio[960]: info: Preload queue cleared Feb 17 22:25:47 volumio volumio[960]: info: Preload queue cleared Feb 17 22:25:47 volumio volumio[960]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 17 22:25:47 volumio volumio[960]: info: CoreStateMachine::ClearQueue Feb 17 22:25:47 volumio volumio[960]: info: CoreStateMachine::stop Feb 17 22:25:47 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 17 22:25:47 volumio volumio[960]: info: CoreStateMachine::stPlaybackTimer Feb 17 22:25:47 volumio volumio[960]: info: CoreStateMachine::updateTrackBlock Feb 17 22:25:47 volumio volumio[960]: info: CorePlayQueue::getTrackBlock Feb 17 22:25:47 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:25:47 volumio volumio[960]: info: CorePlayQueue::getTrack 2 Feb 17 22:25:47 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 22:25:47 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:25:47 volumio volumio[960]: info: CoreStateMachine::serviceStop Feb 17 22:25:47 volumio volumio[960]: info: CorePlayQueue::getTrack 2 Feb 17 22:25:47 volumio volumio[960]: info: CoreCommandRouter::serviceStop Feb 17 22:25:47 volumio volumio[960]: info: [1739820347642] ControllerUPNPBrowser::stop Feb 17 22:25:47 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand stop Feb 17 22:25:47 volumio volumio[960]: info: CorePlayQueue::clearPlayQueue Feb 17 22:25:47 volumio volumio[960]: info: CorePlayQueue::saveQueue Feb 17 22:25:47 volumio volumio[960]: info: CoreCommandRouter::volumioPushQueue Feb 17 22:25:47 volumio volumio[960]: info: CoreStateMachine::addQueueItems Feb 17 22:25:47 volumio volumio[960]: info: CorePlayQueue::addQueueItems Feb 17 22:25:47 volumio volumio[960]: info: Preload queue cleared Feb 17 22:25:47 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$1$0 Feb 17 22:25:47 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$1$0 Feb 17 22:25:47 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$1$1 Feb 17 22:25:47 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$1$1 Feb 17 22:25:47 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$1$2 Feb 17 22:25:47 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$1$2 Feb 17 22:25:47 volumio volumio[960]: info: CoreCommandRouter::volumioPushQueue Feb 17 22:25:47 volumio volumio[960]: info: CorePlayQueue::saveQueue Feb 17 22:25:47 volumio volumio[960]: info: CoreStateMachine::updateTrackBlock Feb 17 22:25:47 volumio volumio[960]: info: CorePlayQueue::getTrackBlock Feb 17 22:25:47 volumio volumio[960]: info: CoreCommandRouter::volumioPlay Feb 17 22:25:47 volumio volumio[960]: info: CoreStateMachine::play index 2 Feb 17 22:25:47 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 17 22:25:47 volumio volumio[960]: info: CoreStateMachine::addQueueItems Feb 17 22:25:47 volumio volumio[960]: info: CorePlayQueue::addQueueItems Feb 17 22:25:47 volumio volumio[960]: info: Preload queue cleared Feb 17 22:25:47 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$1$3 Feb 17 22:25:47 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$1$3 Feb 17 22:25:47 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$1$4 Feb 17 22:25:47 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$1$4 Feb 17 22:25:47 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$1$5 Feb 17 22:25:47 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$1$5 Feb 17 22:25:47 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$1$6 Feb 17 22:25:47 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$1$6 Feb 17 22:25:47 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$1$7 Feb 17 22:25:47 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$1$7 Feb 17 22:25:47 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$1$8 Feb 17 22:25:47 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$1$8 Feb 17 22:25:47 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$1$9 Feb 17 22:25:47 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$1$9 Feb 17 22:25:47 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$1$A Feb 17 22:25:47 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$1$A Feb 17 22:25:47 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$1$B Feb 17 22:25:47 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$1$B Feb 17 22:25:47 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$1$C Feb 17 22:25:47 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$16$1$C Feb 17 22:25:47 volumio volumio[960]: info: CoreStateMachine::stop Feb 17 22:25:47 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 17 22:25:47 volumio volumio[960]: info: CoreCommandRouter::volumioPushQueue Feb 17 22:25:47 volumio volumio[960]: info: CorePlayQueue::saveQueue Feb 17 22:25:47 volumio volumio[960]: info: CoreStateMachine::play index undefined Feb 17 22:25:47 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 17 22:25:47 volumio volumio[960]: info: CoreStateMachine::updateTrackBlock Feb 17 22:25:47 volumio volumio[960]: info: CorePlayQueue::getTrackBlock Feb 17 22:25:47 volumio volumio[960]: info: CorePlayQueue::getTrack 2 Feb 17 22:25:47 volumio volumio[960]: info: CoreStateMachine::startPlaybackTimer Feb 17 22:25:47 volumio volumio[960]: info: CorePlayQueue::getTrack 2 Feb 17 22:25:47 volumio volumio[960]: info: [1739820347695] ControllerUPNPBrowser::clearAddPlayTrack Feb 17 22:25:47 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand stop Feb 17 22:25:47 volumio volumio[960]: info: sendMpdCommand stop took 167 milliseconds Feb 17 22:25:47 volumio volumio[960]: info: Feb 17 22:25:47 volumio volumio[960]: ---------------------------- MPD announces state update: player Feb 17 22:25:47 volumio volumio[960]: info: ControllerMpd::getState Feb 17 22:25:47 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status Feb 17 22:25:47 volumio volumio[960]: info: sendMpdCommand stop took 116 milliseconds Feb 17 22:25:47 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand clear Feb 17 22:25:47 volumio volumio[960]: info: Feb 17 22:25:47 volumio volumio[960]: ---------------------------- MPD announces state update: player Feb 17 22:25:47 volumio volumio[960]: info: ControllerMpd::getState Feb 17 22:25:47 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status Feb 17 22:25:47 volumio volumio[960]: info: Feb 17 22:25:47 volumio volumio[960]: ---------------------------- MPD announces system playlist update Feb 17 22:25:47 volumio volumio[960]: info: Ignoring MPD Status Update Feb 17 22:25:47 volumio volumio[960]: info: sendMpdCommand status took 5 milliseconds Feb 17 22:25:47 volumio volumio[960]: info: sendMpdCommand clear took 4 milliseconds Feb 17 22:25:47 volumio volumio[960]: verbose: ControllerMpd::parseState Feb 17 22:25:47 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 17 22:25:47 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.1:8200/MediaItems/12476.flac" Feb 17 22:25:47 volumio volumio[960]: error: updateQueue error: null Feb 17 22:25:47 volumio volumio[960]: info: sendMpdCommand status took 7 milliseconds Feb 17 22:25:47 volumio volumio[960]: info: ------------------------------ 7ms Feb 17 22:25:47 volumio volumio[960]: info: sendMpdCommand playlistinfo took 5 milliseconds Feb 17 22:25:47 volumio volumio[960]: verbose: ControllerMpd::parseState Feb 17 22:25:47 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo Feb 17 22:25:47 volumio volumio[960]: info: ControllerMpd::pushState Feb 17 22:25:47 volumio volumio[960]: info: CoreCommandRouter::servicePushState Feb 17 22:25:47 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:25:47 volumio volumio[960]: info: CorePlayQueue::getTrack 2 Feb 17 22:25:47 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 22:25:47 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:25:47 volumio volumio[960]: info: CorePlayQueue::getTrack 2 Feb 17 22:25:47 volumio volumio[960]: 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} Feb 17 22:25:47 volumio volumio[960]: verbose: CURRENT POSITION 2 Feb 17 22:25:47 volumio volumio[960]: info: CoreStateMachine::syncState stateService stop Feb 17 22:25:47 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus stop Feb 17 22:25:47 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:25:47 volumio volumio[960]: info: CorePlayQueue::getTrack 2 Feb 17 22:25:47 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:25:47 volumio volumio[960]: info: No code Feb 17 22:25:47 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:25:47 volumio volumio[960]: info: CorePlayQueue::getTrack 2 Feb 17 22:25:47 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:25:47 volumio volumio[960]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Feb 17 22:25:47 volumio volumio[960]: info: ------------------------------ 60ms Feb 17 22:25:47 volumio volumio[960]: info: ------------------------------ 64ms Feb 17 22:25:47 volumio volumio[960]: info: Feb 17 22:25:47 volumio volumio[960]: ---------------------------- MPD announces system playlist update Feb 17 22:25:47 volumio volumio[960]: info: Ignoring MPD Status Update Feb 17 22:25:47 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.1:8200/MediaItems/12476.flac" Feb 17 22:25:47 volumio volumio[960]: error: updateQueue error: null Feb 17 22:25:47 volumio volumio[960]: info: Feb 17 22:25:47 volumio volumio[960]: ---------------------------- MPD announces system playlist update Feb 17 22:25:47 volumio volumio[960]: info: Ignoring MPD Status Update Feb 17 22:25:47 volumio volumio[960]: info: ------------------------------ 77ms Feb 17 22:25:47 volumio volumio[960]: info: sendMpdCommand add "http://192.168.1.1:8200/MediaItems/12476.flac" took 2 milliseconds Feb 17 22:25:47 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 17 22:25:47 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand play Feb 17 22:25:47 volumio volumio[960]: info: Feb 17 22:25:47 volumio volumio[960]: ---------------------------- MPD announces system playlist update Feb 17 22:25:47 volumio volumio[960]: info: Ignoring MPD Status Update Feb 17 22:25:47 volumio volumio[960]: info: ------------------------------ 6ms Feb 17 22:25:47 volumio volumio[960]: info: sendMpdCommand play took 5 milliseconds Feb 17 22:25:47 volumio volumio[960]: info: ------------------------------ 5ms Feb 17 22:25:47 volumio volumio[960]: info: Feb 17 22:25:47 volumio volumio[960]: ---------------------------- MPD announces state update: player Feb 17 22:25:47 volumio volumio[960]: info: ControllerMpd::getState Feb 17 22:25:47 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status Feb 17 22:25:47 volumio volumio[960]: info: Feb 17 22:25:47 volumio volumio[960]: ---------------------------- MPD announces state update: player Feb 17 22:25:47 volumio volumio[960]: info: ControllerMpd::getState Feb 17 22:25:47 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status Feb 17 22:25:48 volumio volumio[960]: info: sendMpdCommand status took 538 milliseconds Feb 17 22:25:48 volumio volumio[960]: verbose: ControllerMpd::parseState Feb 17 22:25:48 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 17 22:25:48 volumio volumio[960]: info: Feb 17 22:25:48 volumio volumio[960]: ---------------------------- MPD announces system playlist update Feb 17 22:25:48 volumio volumio[960]: info: Ignoring MPD Status Update Feb 17 22:25:48 volumio volumio[960]: info: Feb 17 22:25:48 volumio volumio[960]: ---------------------------- MPD announces state update: player Feb 17 22:25:48 volumio volumio[960]: info: ControllerMpd::getState Feb 17 22:25:48 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status Feb 17 22:25:48 volumio volumio[960]: info: sendMpdCommand status took 552 milliseconds Feb 17 22:25:48 volumio volumio[960]: verbose: ControllerMpd::parseState Feb 17 22:25:48 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 17 22:25:48 volumio volumio[960]: info: Feb 17 22:25:48 volumio volumio[960]: ---------------------------- MPD announces system playlist update Feb 17 22:25:48 volumio volumio[960]: info: Ignoring MPD Status Update Feb 17 22:25:48 volumio volumio[960]: info: Feb 17 22:25:48 volumio volumio[960]: ---------------------------- MPD announces state update: player Feb 17 22:25:48 volumio volumio[960]: info: ControllerMpd::getState Feb 17 22:25:48 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status Feb 17 22:25:48 volumio volumio[960]: info: sendMpdCommand playlistinfo took 12 milliseconds Feb 17 22:25:48 volumio volumio[960]: info: ------------------------------ 12ms Feb 17 22:25:48 volumio volumio[960]: info: sendMpdCommand status took 10 milliseconds Feb 17 22:25:48 volumio volumio[960]: info: sendMpdCommand playlistinfo took 8 milliseconds Feb 17 22:25:48 volumio volumio[960]: info: ------------------------------ 8ms Feb 17 22:25:48 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo Feb 17 22:25:48 volumio volumio[960]: verbose: ControllerMpd::parseState Feb 17 22:25:48 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 17 22:25:48 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo Feb 17 22:25:48 volumio volumio[960]: info: ControllerMpd::pushState Feb 17 22:25:48 volumio volumio[960]: info: CoreCommandRouter::servicePushState Feb 17 22:25:48 volumio volumio[960]: info: CorePlayQueue::getTrack 2 Feb 17 22:25:48 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":191,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"6014 Kbps","isStreaming":false,"title":"Yours Truly, 2095","artist":"Electric Light Orchestra","album":"Time","uri":"http://192.168.1.1:8200/MediaItems/12476.flac","trackType":"flac"} Feb 17 22:25:48 volumio volumio[960]: verbose: CURRENT POSITION 2 Feb 17 22:25:48 volumio volumio[960]: info: CoreStateMachine::syncState stateService play Feb 17 22:25:48 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus stop Feb 17 22:25:48 volumio volumio[960]: info: ControllerMpd::pushState Feb 17 22:25:48 volumio volumio[960]: info: CoreCommandRouter::servicePushState Feb 17 22:25:48 volumio volumio[960]: info: CorePlayQueue::getTrack 2 Feb 17 22:25:48 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":438,"duration":191,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"6133 Kbps","isStreaming":false,"title":"Yours Truly, 2095","artist":"Electric Light Orchestra","album":"Time","uri":"http://192.168.1.1:8200/MediaItems/12476.flac","trackType":"flac"} Feb 17 22:25:48 volumio volumio[960]: verbose: CURRENT POSITION 2 Feb 17 22:25:48 volumio volumio[960]: info: CoreStateMachine::syncState stateService play Feb 17 22:25:48 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus play Feb 17 22:25:48 volumio volumio[960]: info: Received an update from plugin. extracting info from payload Feb 17 22:25:48 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:25:48 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 22:25:48 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:25:48 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:25:48 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:25:48 volumio volumio[960]: info: ------------------------------ 596ms Feb 17 22:25:48 volumio volumio[960]: info: ------------------------------ 615ms Feb 17 22:25:48 volumio volumio[960]: info: sendMpdCommand status took 59 milliseconds Feb 17 22:25:48 volumio volumio[960]: info: sendMpdCommand playlistinfo took 53 milliseconds Feb 17 22:25:48 volumio volumio[960]: verbose: ControllerMpd::parseState Feb 17 22:25:48 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 17 22:25:48 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo Feb 17 22:25:48 volumio volumio[960]: info: ControllerMpd::pushState Feb 17 22:25:48 volumio volumio[960]: info: CoreCommandRouter::servicePushState Feb 17 22:25:48 volumio volumio[960]: info: CorePlayQueue::getTrack 2 Feb 17 22:25:48 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":994,"duration":191,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5382 Kbps","isStreaming":false,"title":"Yours Truly, 2095","artist":"Electric Light Orchestra","album":"Time","uri":"http://192.168.1.1:8200/MediaItems/12476.flac","trackType":"flac"} Feb 17 22:25:48 volumio volumio[960]: verbose: CURRENT POSITION 2 Feb 17 22:25:48 volumio volumio[960]: info: CoreStateMachine::syncState stateService play Feb 17 22:25:48 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus play Feb 17 22:25:48 volumio volumio[960]: info: Received an update from plugin. extracting info from payload Feb 17 22:25:48 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:25:48 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 22:25:48 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:25:48 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:25:48 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:25:48 volumio volumio[960]: info: ------------------------------ 104ms Feb 17 22:25:48 volumio volumio[960]: info: CoreCommandRouter::volumioGetQueue Feb 17 22:25:48 volumio volumio[960]: info: CoreStateMachine::getQueue Feb 17 22:25:48 volumio volumio[960]: info: CorePlayQueue::getQueue Feb 17 22:25:48 volumio volumio[960]: info: CoreCommandRouter::volumioGetQueue Feb 17 22:25:48 volumio volumio[960]: info: CoreStateMachine::getQueue Feb 17 22:25:48 volumio volumio[960]: info: CorePlayQueue::getQueue Feb 17 22:25:48 volumio volumio[960]: info: CoreCommandRouter::volumioGetQueue Feb 17 22:25:48 volumio volumio[960]: info: CoreStateMachine::getQueue Feb 17 22:25:48 volumio volumio[960]: info: CorePlayQueue::getQueue Feb 17 22:25:48 volumio volumio[960]: info: CoreCommandRouter::volumioGetQueue Feb 17 22:25:48 volumio volumio[960]: info: CoreStateMachine::getQueue Feb 17 22:25:48 volumio volumio[960]: info: CorePlayQueue::getQueue Feb 17 22:25:48 volumio volumio[960]: info: sendMpdCommand playlistinfo took 103 milliseconds Feb 17 22:25:48 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo Feb 17 22:25:48 volumio volumio[960]: info: ControllerMpd::pushState Feb 17 22:25:48 volumio volumio[960]: info: CoreCommandRouter::servicePushState Feb 17 22:25:48 volumio volumio[960]: info: CorePlayQueue::getTrack 2 Feb 17 22:25:48 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":994,"duration":191,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5382 Kbps","isStreaming":false,"title":"Yours Truly, 2095","artist":"Electric Light Orchestra","album":"Time","uri":"http://192.168.1.1:8200/MediaItems/12476.flac","trackType":"flac"} Feb 17 22:25:48 volumio volumio[960]: verbose: CURRENT POSITION 2 Feb 17 22:25:48 volumio volumio[960]: info: CoreStateMachine::syncState stateService play Feb 17 22:25:48 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus play Feb 17 22:25:48 volumio volumio[960]: info: Received an update from plugin. extracting info from payload Feb 17 22:25:48 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:25:48 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 22:25:48 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:25:48 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:25:48 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:25:48 volumio volumio[960]: info: ------------------------------ 199ms Feb 17 22:25:48 volumio volumio[960]: info: CoreCommandRouter::volumioGetQueue Feb 17 22:25:48 volumio volumio[960]: info: CoreStateMachine::getQueue Feb 17 22:25:48 volumio volumio[960]: info: CorePlayQueue::getQueue Feb 17 22:25:48 volumio volumio[960]: info: CoreCommandRouter::volumioGetQueue Feb 17 22:25:48 volumio volumio[960]: info: CoreStateMachine::getQueue Feb 17 22:25:48 volumio volumio[960]: info: CorePlayQueue::getQueue Feb 17 22:26:18 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Feb 17 22:26:18 volumio volumio[960]: info: Preload queue cleared Feb 17 22:26:18 volumio volumio[960]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$0 Feb 17 22:26:18 volumio volumio[960]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$1 Feb 17 22:26:18 volumio volumio[960]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$2 Feb 17 22:26:18 volumio volumio[960]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$3 Feb 17 22:26:18 volumio volumio[960]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$4 Feb 17 22:26:18 volumio volumio[960]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$5 Feb 17 22:26:18 volumio volumio[960]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$6 Feb 17 22:26:18 volumio volumio[960]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$7 Feb 17 22:26:18 volumio volumio[960]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$8 Feb 17 22:26:18 volumio volumio[960]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$9 Feb 17 22:26:18 volumio volumio[960]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$A Feb 17 22:26:18 volumio volumio[960]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$B Feb 17 22:26:18 volumio volumio[960]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$C Feb 17 22:26:18 volumio volumio[960]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$D Feb 17 22:26:18 volumio volumio[960]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$E Feb 17 22:26:18 volumio volumio[960]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$F Feb 17 22:26:18 volumio volumio[960]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$10 Feb 17 22:26:18 volumio volumio[960]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$0 in service upnp_browser Feb 17 22:26:18 volumio volumio[960]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$1 in service upnp_browser Feb 17 22:26:18 volumio volumio[960]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$2 in service upnp_browser Feb 17 22:26:18 volumio volumio[960]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$3 in service upnp_browser Feb 17 22:26:18 volumio volumio[960]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$4 in service upnp_browser Feb 17 22:26:18 volumio volumio[960]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$5 in service upnp_browser Feb 17 22:26:18 volumio volumio[960]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$6 in service upnp_browser Feb 17 22:26:18 volumio volumio[960]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$7 in service upnp_browser Feb 17 22:26:18 volumio volumio[960]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$8 in service upnp_browser Feb 17 22:26:18 volumio volumio[960]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$9 in service upnp_browser Feb 17 22:26:18 volumio volumio[960]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$A in service upnp_browser Feb 17 22:26:18 volumio volumio[960]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$B in service upnp_browser Feb 17 22:26:19 volumio volumio[960]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$C in service upnp_browser Feb 17 22:26:19 volumio volumio[960]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$D in service upnp_browser Feb 17 22:26:19 volumio volumio[960]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$E in service upnp_browser Feb 17 22:26:19 volumio volumio[960]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$F in service upnp_browser Feb 17 22:26:19 volumio volumio[960]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$10 in service upnp_browser Feb 17 22:26:19 volumio volumio[960]: info: Preload queue cleared Feb 17 22:26:19 volumio volumio[960]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 17 22:26:19 volumio volumio[960]: info: CoreStateMachine::ClearQueue Feb 17 22:26:19 volumio volumio[960]: info: CoreStateMachine::stop Feb 17 22:26:19 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 17 22:26:19 volumio volumio[960]: info: CoreStateMachine::stPlaybackTimer Feb 17 22:26:19 volumio volumio[960]: info: CoreStateMachine::updateTrackBlock Feb 17 22:26:19 volumio volumio[960]: info: CorePlayQueue::getTrackBlock Feb 17 22:26:19 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:26:19 volumio volumio[960]: info: CorePlayQueue::getTrack 2 Feb 17 22:26:19 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 22:26:19 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:26:19 volumio volumio[960]: info: CoreStateMachine::serviceStop Feb 17 22:26:19 volumio volumio[960]: info: CorePlayQueue::getTrack 2 Feb 17 22:26:19 volumio volumio[960]: info: CoreCommandRouter::serviceStop Feb 17 22:26:19 volumio volumio[960]: info: [1739820379734] ControllerUPNPBrowser::stop Feb 17 22:26:19 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand stop Feb 17 22:26:19 volumio volumio[960]: info: CorePlayQueue::clearPlayQueue Feb 17 22:26:19 volumio volumio[960]: info: CorePlayQueue::saveQueue Feb 17 22:26:19 volumio volumio[960]: info: CoreCommandRouter::volumioPushQueue Feb 17 22:26:19 volumio volumio[960]: info: CoreStateMachine::addQueueItems Feb 17 22:26:19 volumio volumio[960]: info: CorePlayQueue::addQueueItems Feb 17 22:26:19 volumio volumio[960]: info: Preload queue cleared Feb 17 22:26:19 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$0 Feb 17 22:26:19 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$0 Feb 17 22:26:19 volumio volumio[960]: info: CoreCommandRouter::volumioPushQueue Feb 17 22:26:19 volumio volumio[960]: info: CorePlayQueue::saveQueue Feb 17 22:26:19 volumio volumio[960]: info: CoreStateMachine::updateTrackBlock Feb 17 22:26:19 volumio volumio[960]: info: CorePlayQueue::getTrackBlock Feb 17 22:26:19 volumio volumio[960]: info: CoreCommandRouter::volumioPlay Feb 17 22:26:19 volumio volumio[960]: info: CoreStateMachine::play index 0 Feb 17 22:26:19 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 17 22:26:19 volumio volumio[960]: info: CoreStateMachine::addQueueItems Feb 17 22:26:19 volumio volumio[960]: info: CorePlayQueue::addQueueItems Feb 17 22:26:19 volumio volumio[960]: info: Preload queue cleared Feb 17 22:26:19 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$1 Feb 17 22:26:19 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$1 Feb 17 22:26:19 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$2 Feb 17 22:26:19 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$2 Feb 17 22:26:19 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$3 Feb 17 22:26:19 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$3 Feb 17 22:26:19 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$4 Feb 17 22:26:19 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$4 Feb 17 22:26:19 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$5 Feb 17 22:26:19 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$5 Feb 17 22:26:19 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$6 Feb 17 22:26:19 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$6 Feb 17 22:26:19 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$7 Feb 17 22:26:19 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$7 Feb 17 22:26:19 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$8 Feb 17 22:26:19 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$8 Feb 17 22:26:19 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$9 Feb 17 22:26:19 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$9 Feb 17 22:26:19 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$A Feb 17 22:26:19 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$A Feb 17 22:26:19 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$B Feb 17 22:26:19 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$B Feb 17 22:26:19 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$C Feb 17 22:26:19 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$C Feb 17 22:26:19 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$D Feb 17 22:26:19 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$D Feb 17 22:26:19 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$E Feb 17 22:26:19 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$E Feb 17 22:26:19 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$F Feb 17 22:26:19 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$F Feb 17 22:26:19 volumio volumio[960]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$10 Feb 17 22:26:19 volumio volumio[960]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@1$14$0$F$10 Feb 17 22:26:19 volumio volumio[960]: info: CoreStateMachine::stop Feb 17 22:26:19 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 17 22:26:19 volumio volumio[960]: info: CoreCommandRouter::volumioPushQueue Feb 17 22:26:19 volumio volumio[960]: info: CorePlayQueue::saveQueue Feb 17 22:26:19 volumio volumio[960]: info: CoreStateMachine::play index undefined Feb 17 22:26:19 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 17 22:26:19 volumio volumio[960]: info: CoreStateMachine::updateTrackBlock Feb 17 22:26:19 volumio volumio[960]: info: CorePlayQueue::getTrackBlock Feb 17 22:26:19 volumio volumio[960]: info: CorePlayQueue::getTrack 0 Feb 17 22:26:19 volumio volumio[960]: info: CoreStateMachine::startPlaybackTimer Feb 17 22:26:19 volumio volumio[960]: info: CorePlayQueue::getTrack 0 Feb 17 22:26:19 volumio volumio[960]: info: [1739820379785] ControllerUPNPBrowser::clearAddPlayTrack Feb 17 22:26:19 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand stop Feb 17 22:26:19 volumio volumio[960]: info: sendMpdCommand stop took 143 milliseconds Feb 17 22:26:19 volumio volumio[960]: info: Feb 17 22:26:19 volumio volumio[960]: ---------------------------- MPD announces state update: player Feb 17 22:26:19 volumio volumio[960]: info: ControllerMpd::getState Feb 17 22:26:19 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status Feb 17 22:26:19 volumio volumio[960]: info: sendMpdCommand stop took 93 milliseconds Feb 17 22:26:19 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand clear Feb 17 22:26:19 volumio volumio[960]: info: Feb 17 22:26:19 volumio volumio[960]: ---------------------------- MPD announces state update: player Feb 17 22:26:19 volumio volumio[960]: info: ControllerMpd::getState Feb 17 22:26:19 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status Feb 17 22:26:19 volumio volumio[960]: info: Feb 17 22:26:19 volumio volumio[960]: ---------------------------- MPD announces system playlist update Feb 17 22:26:19 volumio volumio[960]: info: Ignoring MPD Status Update Feb 17 22:26:19 volumio volumio[960]: info: sendMpdCommand status took 5 milliseconds Feb 17 22:26:19 volumio volumio[960]: info: sendMpdCommand clear took 5 milliseconds Feb 17 22:26:19 volumio volumio[960]: verbose: ControllerMpd::parseState Feb 17 22:26:19 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 17 22:26:19 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.1:8200/MediaItems/586.flac" Feb 17 22:26:19 volumio volumio[960]: info: sendMpdCommand status took 6 milliseconds Feb 17 22:26:19 volumio volumio[960]: verbose: ControllerMpd::parseState Feb 17 22:26:19 volumio volumio[960]: info: ControllerMpd::pushState Feb 17 22:26:19 volumio volumio[960]: info: CoreCommandRouter::servicePushState Feb 17 22:26:19 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:26:19 volumio volumio[960]: info: CorePlayQueue::getTrack 0 Feb 17 22:26:19 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 22:26:19 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:26:19 volumio volumio[960]: info: CorePlayQueue::getTrack 0 Feb 17 22:26:19 volumio volumio[960]: 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} Feb 17 22:26:19 volumio volumio[960]: verbose: CURRENT POSITION 0 Feb 17 22:26:19 volumio volumio[960]: info: CoreStateMachine::syncState stateService stop Feb 17 22:26:19 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus stop Feb 17 22:26:19 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:26:19 volumio volumio[960]: info: CorePlayQueue::getTrack 0 Feb 17 22:26:19 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:26:19 volumio volumio[960]: info: No code Feb 17 22:26:19 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:26:19 volumio volumio[960]: info: CorePlayQueue::getTrack 0 Feb 17 22:26:19 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:26:19 volumio volumio[960]: info: ------------------------------ 54ms Feb 17 22:26:19 volumio volumio[960]: info: Feb 17 22:26:19 volumio volumio[960]: ---------------------------- MPD announces system playlist update Feb 17 22:26:19 volumio volumio[960]: info: Ignoring MPD Status Update Feb 17 22:26:19 volumio volumio[960]: error: updateQueue error: null Feb 17 22:26:19 volumio volumio[960]: info: ------------------------------ 69ms Feb 17 22:26:19 volumio volumio[960]: info: sendMpdCommand playlistinfo took 69 milliseconds Feb 17 22:26:19 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.1:8200/MediaItems/586.flac" Feb 17 22:26:19 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo Feb 17 22:26:19 volumio volumio[960]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Feb 17 22:26:19 volumio volumio[960]: info: ------------------------------ 78ms Feb 17 22:26:19 volumio volumio[960]: error: updateQueue error: null Feb 17 22:26:19 volumio volumio[960]: info: Feb 17 22:26:19 volumio volumio[960]: ---------------------------- MPD announces system playlist update Feb 17 22:26:19 volumio volumio[960]: info: Ignoring MPD Status Update Feb 17 22:26:19 volumio volumio[960]: info: ------------------------------ 22ms Feb 17 22:26:19 volumio volumio[960]: info: sendMpdCommand add "http://192.168.1.1:8200/MediaItems/586.flac" took 5 milliseconds Feb 17 22:26:19 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 17 22:26:19 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand play Feb 17 22:26:19 volumio volumio[960]: info: Feb 17 22:26:19 volumio volumio[960]: ---------------------------- MPD announces system playlist update Feb 17 22:26:19 volumio volumio[960]: info: Ignoring MPD Status Update Feb 17 22:26:19 volumio volumio[960]: info: ------------------------------ 10ms Feb 17 22:26:19 volumio volumio[960]: info: sendMpdCommand play took 8 milliseconds Feb 17 22:26:19 volumio volumio[960]: info: ------------------------------ 7ms Feb 17 22:26:19 volumio volumio[960]: info: Feb 17 22:26:19 volumio volumio[960]: ---------------------------- MPD announces state update: player Feb 17 22:26:19 volumio volumio[960]: info: ControllerMpd::getState Feb 17 22:26:19 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status Feb 17 22:26:19 volumio volumio[960]: info: Feb 17 22:26:19 volumio volumio[960]: ---------------------------- MPD announces state update: player Feb 17 22:26:19 volumio volumio[960]: info: ControllerMpd::getState Feb 17 22:26:19 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status Feb 17 22:26:20 volumio volumio[960]: info: Feb 17 22:26:20 volumio volumio[960]: ---------------------------- MPD announces system playlist update Feb 17 22:26:20 volumio volumio[960]: info: Ignoring MPD Status Update Feb 17 22:26:20 volumio volumio[960]: info: Feb 17 22:26:20 volumio volumio[960]: ---------------------------- MPD announces state update: player Feb 17 22:26:20 volumio volumio[960]: info: sendMpdCommand status took 741 milliseconds Feb 17 22:26:20 volumio volumio[960]: info: ControllerMpd::getState Feb 17 22:26:20 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status Feb 17 22:26:20 volumio volumio[960]: verbose: ControllerMpd::parseState Feb 17 22:26:20 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 17 22:26:20 volumio volumio[960]: info: sendMpdCommand status took 733 milliseconds Feb 17 22:26:20 volumio volumio[960]: info: ------------------------------ 11ms Feb 17 22:26:20 volumio volumio[960]: info: sendMpdCommand status took 8 milliseconds Feb 17 22:26:20 volumio volumio[960]: info: sendMpdCommand playlistinfo took 9 milliseconds Feb 17 22:26:20 volumio volumio[960]: verbose: ControllerMpd::parseState Feb 17 22:26:20 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 17 22:26:20 volumio volumio[960]: verbose: ControllerMpd::parseState Feb 17 22:26:20 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 17 22:26:20 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo Feb 17 22:26:20 volumio volumio[960]: info: ControllerMpd::pushState Feb 17 22:26:20 volumio volumio[960]: info: CoreCommandRouter::servicePushState Feb 17 22:26:20 volumio volumio[960]: info: CorePlayQueue::getTrack 0 Feb 17 22:26:20 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":221,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"4 Kbps","isStreaming":false,"title":"586.flac","artist":null,"album":null,"uri":"http://192.168.1.1:8200/MediaItems/586.flac","trackType":"flac"} Feb 17 22:26:20 volumio volumio[960]: verbose: CURRENT POSITION 0 Feb 17 22:26:20 volumio volumio[960]: info: CoreStateMachine::syncState stateService play Feb 17 22:26:20 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus stop Feb 17 22:26:20 volumio volumio[960]: info: ------------------------------ 759ms Feb 17 22:26:20 volumio volumio[960]: info: Feb 17 22:26:20 volumio volumio[960]: ---------------------------- MPD announces system playlist update Feb 17 22:26:20 volumio volumio[960]: info: Ignoring MPD Status Update Feb 17 22:26:20 volumio volumio[960]: info: Feb 17 22:26:20 volumio volumio[960]: ---------------------------- MPD announces state update: player Feb 17 22:26:20 volumio volumio[960]: info: ControllerMpd::getState Feb 17 22:26:20 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status Feb 17 22:26:20 volumio volumio[960]: info: sendMpdCommand playlistinfo took 11 milliseconds Feb 17 22:26:20 volumio volumio[960]: info: sendMpdCommand playlistinfo took 13 milliseconds Feb 17 22:26:20 volumio volumio[960]: info: ------------------------------ 8ms Feb 17 22:26:20 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo Feb 17 22:26:20 volumio volumio[960]: info: ControllerMpd::pushState Feb 17 22:26:20 volumio volumio[960]: info: CoreCommandRouter::servicePushState Feb 17 22:26:20 volumio volumio[960]: info: CorePlayQueue::getTrack 0 Feb 17 22:26:20 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":114,"duration":221,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"4 Kbps","isStreaming":false,"title":"586.flac","artist":null,"album":null,"uri":"http://192.168.1.1:8200/MediaItems/586.flac","trackType":"flac"} Feb 17 22:26:20 volumio volumio[960]: verbose: CURRENT POSITION 0 Feb 17 22:26:20 volumio volumio[960]: info: CoreStateMachine::syncState stateService play Feb 17 22:26:20 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus play Feb 17 22:26:20 volumio volumio[960]: info: Received an update from plugin. extracting info from payload Feb 17 22:26:20 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:26:20 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 22:26:20 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:26:20 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:26:20 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:26:20 volumio volumio[960]: info: ControllerMpd::pushState Feb 17 22:26:20 volumio volumio[960]: info: CoreCommandRouter::servicePushState Feb 17 22:26:20 volumio volumio[960]: info: CorePlayQueue::getTrack 0 Feb 17 22:26:20 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":846,"duration":221,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"829 Kbps","isStreaming":false,"title":"586.flac","artist":null,"album":null,"uri":"http://192.168.1.1:8200/MediaItems/586.flac","trackType":"flac"} Feb 17 22:26:20 volumio volumio[960]: verbose: CURRENT POSITION 0 Feb 17 22:26:20 volumio volumio[960]: info: CoreStateMachine::syncState stateService play Feb 17 22:26:20 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus play Feb 17 22:26:20 volumio volumio[960]: info: Received an update from plugin. extracting info from payload Feb 17 22:26:20 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:26:20 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 22:26:20 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:26:20 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:26:20 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:26:20 volumio volumio[960]: info: ------------------------------ 829ms Feb 17 22:26:20 volumio volumio[960]: info: ------------------------------ 103ms Feb 17 22:26:20 volumio volumio[960]: info: sendMpdCommand status took 86 milliseconds Feb 17 22:26:20 volumio volumio[960]: verbose: ControllerMpd::parseState Feb 17 22:26:20 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 17 22:26:20 volumio volumio[960]: info: sendMpdCommand playlistinfo took 21 milliseconds Feb 17 22:26:20 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo Feb 17 22:26:20 volumio volumio[960]: info: ControllerMpd::pushState Feb 17 22:26:20 volumio volumio[960]: info: CoreCommandRouter::servicePushState Feb 17 22:26:20 volumio volumio[960]: info: CorePlayQueue::getTrack 0 Feb 17 22:26:20 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":846,"duration":221,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"829 Kbps","isStreaming":false,"title":"586.flac","artist":null,"album":null,"uri":"http://192.168.1.1:8200/MediaItems/586.flac","trackType":"flac"} Feb 17 22:26:20 volumio volumio[960]: verbose: CURRENT POSITION 0 Feb 17 22:26:20 volumio volumio[960]: info: CoreStateMachine::syncState stateService play Feb 17 22:26:20 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus play Feb 17 22:26:20 volumio volumio[960]: info: Received an update from plugin. extracting info from payload Feb 17 22:26:20 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:26:20 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 22:26:20 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:26:20 volumio volumio[960]: info: CoreStateMachine::pushState Feb 17 22:26:20 volumio volumio[960]: info: CoreCommandRouter::volumioPushState Feb 17 22:26:20 volumio volumio[960]: info: ------------------------------ 150ms Feb 17 22:26:52 volumio volumio[960]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 22:26:52 volumio volumio[960]: Error: connect ETIMEDOUT 146.75.118.79:443 Feb 17 22:26:52 volumio volumio[960]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) { Feb 17 22:26:52 volumio volumio[960]: errno: -110, Feb 17 22:26:52 volumio volumio[960]: code: 'ETIMEDOUT', Feb 17 22:26:52 volumio volumio[960]: syscall: 'connect', Feb 17 22:26:52 volumio volumio[960]: address: '146.75.118.79', Feb 17 22:26:52 volumio volumio[960]: port: 443 Feb 17 22:26:52 volumio volumio[960]: } Feb 17 22:26:52 volumio volumio[960]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 22:26:54 volumio sudo[7080]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-02-17 22:25 Feb 17 22:26:54 volumio sudo[7080]: 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"