-- Logs begin at Thu 2019-02-14 17:11:59 +07, end at Sat 2024-11-30 12:01:27 +07. -- Nov 30 12:00:00 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 30 12:00:01 vol.raspi volumio[957]: info: Preload queue cleared Nov 30 12:00:04 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 30 12:00:04 vol.raspi volumio[957]: info: Preload queue cleared Nov 30 12:00:07 vol.raspi ntpd[825]: Soliciting pool server 103.184.124.23 Nov 30 12:00:08 vol.raspi volumio[957]: info: Preload queue cleared Nov 30 12:00:08 vol.raspi volumio[957]: info: CoreCommandRouter::volumioReplaceandPlayItems Nov 30 12:00:08 vol.raspi volumio[957]: info: CoreStateMachine::ClearQueue Nov 30 12:00:08 vol.raspi volumio[957]: info: CoreStateMachine::stop Nov 30 12:00:08 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 30 12:00:08 vol.raspi volumio[957]: info: CorePlayQueue::clearPlayQueue Nov 30 12:00:08 vol.raspi volumio[957]: info: CorePlayQueue::saveQueue Nov 30 12:00:08 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushQueue Nov 30 12:00:08 vol.raspi volumio[957]: info: CoreStateMachine::addQueueItems Nov 30 12:00:08 vol.raspi volumio[957]: info: CorePlayQueue::addQueueItems Nov 30 12:00:08 vol.raspi volumio[957]: info: Preload queue cleared Nov 30 12:00:08 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$3$0$0 Nov 30 12:00:08 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$3$0$0 Nov 30 12:00:08 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$3$0$1 Nov 30 12:00:08 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$3$0$1 Nov 30 12:00:08 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$3$0$2 Nov 30 12:00:08 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$3$0$2 Nov 30 12:00:08 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$3$0$3 Nov 30 12:00:08 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$3$0$3 Nov 30 12:00:08 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$3$0$4 Nov 30 12:00:08 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$3$0$4 Nov 30 12:00:08 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushQueue Nov 30 12:00:08 vol.raspi volumio[957]: info: CorePlayQueue::saveQueue Nov 30 12:00:08 vol.raspi volumio[957]: info: CoreStateMachine::updateTrackBlock Nov 30 12:00:08 vol.raspi volumio[957]: info: CorePlayQueue::getTrackBlock Nov 30 12:00:08 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPlay Nov 30 12:00:08 vol.raspi volumio[957]: info: CoreStateMachine::play index 4 Nov 30 12:00:08 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 30 12:00:08 vol.raspi volumio[957]: info: CoreStateMachine::addQueueItems Nov 30 12:00:08 vol.raspi volumio[957]: info: CorePlayQueue::addQueueItems Nov 30 12:00:08 vol.raspi volumio[957]: info: Preload queue cleared Nov 30 12:00:08 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$3$0$5 Nov 30 12:00:08 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$3$0$5 Nov 30 12:00:08 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$3$0$6 Nov 30 12:00:08 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$3$0$6 Nov 30 12:00:08 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$3$0$7 Nov 30 12:00:08 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$3$0$7 Nov 30 12:00:08 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$3$0$8 Nov 30 12:00:08 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$3$0$8 Nov 30 12:00:08 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$3$0$9 Nov 30 12:00:08 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$3$0$9 Nov 30 12:00:08 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$3$0$A Nov 30 12:00:08 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$3$0$A Nov 30 12:00:08 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$3$0$B Nov 30 12:00:08 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$3$0$B Nov 30 12:00:08 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$3$0$C Nov 30 12:00:08 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$3$0$C Nov 30 12:00:08 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$3$0$D Nov 30 12:00:08 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$3$0$D Nov 30 12:00:08 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$3$0$E Nov 30 12:00:08 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$3$0$E Nov 30 12:00:08 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$3$0$F Nov 30 12:00:08 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$3$0$F Nov 30 12:00:08 vol.raspi volumio[957]: info: CoreStateMachine::stop Nov 30 12:00:08 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 30 12:00:08 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushQueue Nov 30 12:00:08 vol.raspi volumio[957]: info: CorePlayQueue::saveQueue Nov 30 12:00:08 vol.raspi volumio[957]: info: CoreStateMachine::play index undefined Nov 30 12:00:08 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 30 12:00:08 vol.raspi volumio[957]: info: CoreStateMachine::updateTrackBlock Nov 30 12:00:08 vol.raspi volumio[957]: info: CorePlayQueue::getTrackBlock Nov 30 12:00:08 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 4 Nov 30 12:00:08 vol.raspi volumio[957]: info: CoreStateMachine::startPlaybackTimer Nov 30 12:00:08 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 4 Nov 30 12:00:08 vol.raspi volumio[957]: info: [1732942808512] ControllerUPNPBrowser::clearAddPlayTrack Nov 30 12:00:08 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand stop Nov 30 12:00:08 vol.raspi volumio[957]: info: sendMpdCommand stop took 3 milliseconds Nov 30 12:00:08 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand clear Nov 30 12:00:08 vol.raspi volumio[957]: info: Nov 30 12:00:08 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:00:08 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:00:08 vol.raspi volumio[957]: info: sendMpdCommand clear took 1 milliseconds Nov 30 12:00:08 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.223:8200/MediaItems/5036.flac" Nov 30 12:00:08 vol.raspi volumio[957]: error: updateQueue error: null Nov 30 12:00:08 vol.raspi volumio[957]: info: ------------------------------ 1ms Nov 30 12:00:08 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.223:8200/MediaItems/5036.flac" Nov 30 12:00:08 vol.raspi volumio[957]: info: Nov 30 12:00:08 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:00:08 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:00:08 vol.raspi volumio[957]: info: sendMpdCommand add "http://192.168.1.223:8200/MediaItems/5036.flac" took 1 milliseconds Nov 30 12:00:08 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 30 12:00:08 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand play Nov 30 12:00:08 vol.raspi volumio[957]: info: ------------------------------ 1ms Nov 30 12:00:08 vol.raspi volumio[957]: info: sendMpdCommand play took 2 milliseconds Nov 30 12:00:08 vol.raspi volumio[957]: info: Nov 30 12:00:08 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:00:08 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:00:08 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:00:08 vol.raspi kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Nov 30 12:00:08 vol.raspi volumio[957]: info: Nov 30 12:00:08 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:00:08 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:00:08 vol.raspi volumio[957]: info: Nov 30 12:00:08 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:00:08 vol.raspi volumio[957]: info: sendMpdCommand status took 18 milliseconds Nov 30 12:00:08 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:00:08 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:00:08 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:00:08 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 12:00:08 vol.raspi volumio[957]: info: ------------------------------ 2ms Nov 30 12:00:08 vol.raspi volumio[957]: info: sendMpdCommand status took 1 milliseconds Nov 30 12:00:08 vol.raspi volumio[957]: info: sendMpdCommand playlistinfo took 2 milliseconds Nov 30 12:00:08 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:00:08 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 12:00:08 vol.raspi volumio[957]: verbose: ControllerMpd::parseTrackInfo Nov 30 12:00:08 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:00:08 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:00:08 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 4 Nov 30 12:00:08 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":183,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"The First Noël","artist":"Boney M","album":"The Most Beautiful Christmas Songs Of The World","uri":"http://192.168.1.223:8200/MediaItems/5036.flac","trackType":"flac"} Nov 30 12:00:08 vol.raspi volumio[957]: verbose: CURRENT POSITION 4 Nov 30 12:00:08 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService play Nov 30 12:00:08 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus stop Nov 30 12:00:08 vol.raspi volumio[957]: info: ------------------------------ 24ms Nov 30 12:00:08 vol.raspi volumio[957]: info: sendMpdCommand playlistinfo took 2 milliseconds Nov 30 12:00:08 vol.raspi volumio[957]: verbose: ControllerMpd::parseTrackInfo Nov 30 12:00:08 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:00:08 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:00:08 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 4 Nov 30 12:00:08 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"play","position":0,"seek":869,"duration":183,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"802 Kbps","isStreaming":false,"title":"The First Noël","artist":"Boney M","album":"The Most Beautiful Christmas Songs Of The World","uri":"http://192.168.1.223:8200/MediaItems/5036.flac","trackType":"flac"} Nov 30 12:00:08 vol.raspi volumio[957]: verbose: CURRENT POSITION 4 Nov 30 12:00:08 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService play Nov 30 12:00:08 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus play Nov 30 12:00:08 vol.raspi volumio[957]: info: Received an update from plugin. extracting info from payload Nov 30 12:00:08 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:00:08 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:00:08 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:00:08 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:00:08 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:00:08 vol.raspi volumio[957]: info: ------------------------------ 12ms Nov 30 12:00:08 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:00:08 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:00:08 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:00:08 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:00:08 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:00:08 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:00:08 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 31 Nov 30 12:00:08 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 31 Nov 30 12:00:09 vol.raspi ntpd[825]: Soliciting pool server 115.165.161.155 Nov 30 12:00:33 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 30 12:00:33 vol.raspi volumio[957]: info: Preload queue cleared Nov 30 12:00:43 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 30 12:00:43 vol.raspi volumio[957]: info: Preload queue cleared Nov 30 12:00:51 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 30 12:00:52 vol.raspi volumio[957]: info: Preload queue cleared Nov 30 12:00:52 vol.raspi volumio[957]: info: Preloading song: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$0 Nov 30 12:00:52 vol.raspi volumio[957]: info: Preloading song: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$1 Nov 30 12:00:52 vol.raspi volumio[957]: info: Preloading song: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$2 Nov 30 12:00:52 vol.raspi volumio[957]: info: Preloading song: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$3 Nov 30 12:00:52 vol.raspi volumio[957]: info: Preloading song: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$4 Nov 30 12:00:52 vol.raspi volumio[957]: info: Preloading song: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$5 Nov 30 12:00:52 vol.raspi volumio[957]: info: Preloading song: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$6 Nov 30 12:00:52 vol.raspi volumio[957]: info: Preloading song: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$7 Nov 30 12:00:52 vol.raspi volumio[957]: info: Preloading song: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$8 Nov 30 12:00:52 vol.raspi volumio[957]: info: Preloading song: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$9 Nov 30 12:00:52 vol.raspi volumio[957]: info: Preloading song: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$A Nov 30 12:00:52 vol.raspi volumio[957]: info: Exploding uri upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$0 in service upnp_browser Nov 30 12:00:52 vol.raspi volumio[957]: info: Exploding uri upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$1 in service upnp_browser Nov 30 12:00:52 vol.raspi volumio[957]: info: Exploding uri upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$2 in service upnp_browser Nov 30 12:00:52 vol.raspi volumio[957]: info: Exploding uri upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$3 in service upnp_browser Nov 30 12:00:52 vol.raspi volumio[957]: info: Exploding uri upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$4 in service upnp_browser Nov 30 12:00:52 vol.raspi volumio[957]: info: Exploding uri upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$5 in service upnp_browser Nov 30 12:00:52 vol.raspi volumio[957]: info: Exploding uri upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$6 in service upnp_browser Nov 30 12:00:52 vol.raspi volumio[957]: info: Exploding uri upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$7 in service upnp_browser Nov 30 12:00:52 vol.raspi volumio[957]: info: Exploding uri upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$8 in service upnp_browser Nov 30 12:00:52 vol.raspi volumio[957]: info: Exploding uri upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$9 in service upnp_browser Nov 30 12:00:52 vol.raspi volumio[957]: info: Exploding uri upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$A in service upnp_browser Nov 30 12:00:54 vol.raspi volumio[957]: info: Preload queue cleared Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreCommandRouter::volumioReplaceandPlayItems Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreStateMachine::ClearQueue Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreStateMachine::stop Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreStateMachine::stPlaybackTimer Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreStateMachine::updateTrackBlock Nov 30 12:00:54 vol.raspi volumio[957]: info: CorePlayQueue::getTrackBlock Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:00:54 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 4 Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreStateMachine::serviceStop Nov 30 12:00:54 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 4 Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreCommandRouter::serviceStop Nov 30 12:00:54 vol.raspi volumio[957]: info: [1732942854215] ControllerUPNPBrowser::stop Nov 30 12:00:54 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand stop Nov 30 12:00:54 vol.raspi volumio[957]: info: CorePlayQueue::clearPlayQueue Nov 30 12:00:54 vol.raspi volumio[957]: info: CorePlayQueue::saveQueue Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushQueue Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreStateMachine::addQueueItems Nov 30 12:00:54 vol.raspi volumio[957]: info: CorePlayQueue::addQueueItems Nov 30 12:00:54 vol.raspi volumio[957]: info: Preload queue cleared Nov 30 12:00:54 vol.raspi volumio[957]: info: Adding Item to queue: upnp/folder/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$B Nov 30 12:00:54 vol.raspi volumio[957]: info: Exploding uri upnp/folder/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$B in service upnp_browser Nov 30 12:00:54 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$0 Nov 30 12:00:54 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$0 Nov 30 12:00:54 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 31 Nov 30 12:00:54 vol.raspi volumio[957]: info: sendMpdCommand stop took 10 milliseconds Nov 30 12:00:54 vol.raspi volumio[957]: info: Nov 30 12:00:54 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:00:54 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:00:54 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:00:54 vol.raspi volumio[957]: info: sendMpdCommand status took 1 milliseconds Nov 30 12:00:54 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:00:54 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 12:00:54 vol.raspi volumio[957]: info: sendMpdCommand playlistinfo took 0 milliseconds Nov 30 12:00:54 vol.raspi volumio[957]: verbose: ControllerMpd::parseTrackInfo Nov 30 12:00:54 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:00:54 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 4 Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:00:54 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 4 Nov 30 12:00:54 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"The First Noël","artist":"Boney M","album":"The Most Beautiful Christmas Songs Of The World","uri":"http://192.168.1.223:8200/MediaItems/5036.flac","trackType":"flac"} Nov 30 12:00:54 vol.raspi volumio[957]: verbose: CURRENT POSITION 4 Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService stop Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus stop Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:00:54 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 4 Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:00:54 vol.raspi volumio[957]: info: No code Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:00:54 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 4 Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:00:54 vol.raspi volumio[957]: info: ------------------------------ 9ms Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushQueue Nov 30 12:00:54 vol.raspi volumio[957]: info: CorePlayQueue::saveQueue Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreStateMachine::updateTrackBlock Nov 30 12:00:54 vol.raspi volumio[957]: info: CorePlayQueue::getTrackBlock Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPlay Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreStateMachine::play index 1 Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreStateMachine::addQueueItems Nov 30 12:00:54 vol.raspi volumio[957]: info: CorePlayQueue::addQueueItems Nov 30 12:00:54 vol.raspi volumio[957]: info: Preload queue cleared Nov 30 12:00:54 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$1 Nov 30 12:00:54 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$1 Nov 30 12:00:54 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$2 Nov 30 12:00:54 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$2 Nov 30 12:00:54 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$3 Nov 30 12:00:54 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$3 Nov 30 12:00:54 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$4 Nov 30 12:00:54 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$4 Nov 30 12:00:54 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$5 Nov 30 12:00:54 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$5 Nov 30 12:00:54 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$6 Nov 30 12:00:54 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$6 Nov 30 12:00:54 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$7 Nov 30 12:00:54 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$7 Nov 30 12:00:54 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$8 Nov 30 12:00:54 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$8 Nov 30 12:00:54 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$9 Nov 30 12:00:54 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$9 Nov 30 12:00:54 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$A Nov 30 12:00:54 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$A Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreStateMachine::stop Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushQueue Nov 30 12:00:54 vol.raspi volumio[957]: info: CorePlayQueue::saveQueue Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreStateMachine::play index undefined Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreStateMachine::updateTrackBlock Nov 30 12:00:54 vol.raspi volumio[957]: info: CorePlayQueue::getTrackBlock Nov 30 12:00:54 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 1 Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreStateMachine::startPlaybackTimer Nov 30 12:00:54 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 1 Nov 30 12:00:54 vol.raspi volumio[957]: info: [1732942854244] ControllerUPNPBrowser::clearAddPlayTrack Nov 30 12:00:54 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand stop Nov 30 12:00:54 vol.raspi volumio[957]: info: sendMpdCommand stop took 1 milliseconds Nov 30 12:00:54 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand clear Nov 30 12:00:54 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 31 Nov 30 12:00:54 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 31 Nov 30 12:00:54 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 31 Nov 30 12:00:54 vol.raspi volumio[957]: info: Nov 30 12:00:54 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:00:54 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:00:54 vol.raspi volumio[957]: info: sendMpdCommand clear took 5 milliseconds Nov 30 12:00:54 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.223:8200/MediaItems/11993.flac" Nov 30 12:00:54 vol.raspi volumio[957]: error: updateQueue error: null Nov 30 12:00:54 vol.raspi volumio[957]: info: ------------------------------ 2ms Nov 30 12:00:54 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.223:8200/MediaItems/11993.flac" Nov 30 12:00:54 vol.raspi volumio[957]: info: Nov 30 12:00:54 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:00:54 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:00:54 vol.raspi volumio[957]: info: sendMpdCommand add "http://192.168.1.223:8200/MediaItems/11993.flac" took 1 milliseconds Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 30 12:00:54 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand play Nov 30 12:00:54 vol.raspi volumio[957]: info: ------------------------------ 2ms Nov 30 12:00:54 vol.raspi volumio[957]: info: sendMpdCommand play took 1 milliseconds Nov 30 12:00:54 vol.raspi volumio[957]: info: Nov 30 12:00:54 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:00:54 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:00:54 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:00:54 vol.raspi kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Nov 30 12:00:54 vol.raspi volumio[957]: info: Nov 30 12:00:54 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:00:54 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:00:54 vol.raspi volumio[957]: info: Nov 30 12:00:54 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:00:54 vol.raspi volumio[957]: info: sendMpdCommand status took 16 milliseconds Nov 30 12:00:54 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:00:54 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:00:54 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:00:54 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 12:00:54 vol.raspi volumio[957]: info: ------------------------------ 2ms Nov 30 12:00:54 vol.raspi volumio[957]: info: sendMpdCommand status took 3 milliseconds Nov 30 12:00:54 vol.raspi volumio[957]: info: sendMpdCommand playlistinfo took 2 milliseconds Nov 30 12:00:54 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:00:54 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 12:00:54 vol.raspi volumio[957]: verbose: ControllerMpd::parseTrackInfo Nov 30 12:00:54 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:00:54 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 1 Nov 30 12:00:54 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":340,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Ha Noi va toi {Le Vinh}","artist":"Ngoc Tan","album":"Khoanh khac {Hacova}","uri":"http://192.168.1.223:8200/MediaItems/11993.flac","trackType":"flac"} Nov 30 12:00:54 vol.raspi volumio[957]: verbose: CURRENT POSITION 1 Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService play Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus stop Nov 30 12:00:54 vol.raspi volumio[957]: info: ------------------------------ 20ms Nov 30 12:00:54 vol.raspi volumio[957]: info: sendMpdCommand playlistinfo took 2 milliseconds Nov 30 12:00:54 vol.raspi volumio[957]: verbose: ControllerMpd::parseTrackInfo Nov 30 12:00:54 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:00:54 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 1 Nov 30 12:00:54 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"play","position":0,"seek":869,"duration":340,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"479 Kbps","isStreaming":false,"title":"Ha Noi va toi {Le Vinh}","artist":"Ngoc Tan","album":"Khoanh khac {Hacova}","uri":"http://192.168.1.223:8200/MediaItems/11993.flac","trackType":"flac"} Nov 30 12:00:54 vol.raspi volumio[957]: verbose: CURRENT POSITION 1 Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService play Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus play Nov 30 12:00:54 vol.raspi volumio[957]: info: Received an update from plugin. extracting info from payload Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:00:54 vol.raspi volumio[957]: info: ------------------------------ 12ms Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:00:54 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:00:54 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:00:54 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:00:54 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 31 Nov 30 12:00:54 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 31 Nov 30 12:00:56 vol.raspi volumio[957]: info: VolumeController::SetAlsaVolume+ Nov 30 12:00:56 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetState Nov 30 12:00:56 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:00:56 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:00:56 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:00:56 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:00:56 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:00:56 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:00:56 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 32 Nov 30 12:00:56 vol.raspi volumio[957]: SPOTIFY: SPOTIFY VOLUME 31 Nov 30 12:00:56 vol.raspi volumio[957]: SPOTIFY: VOLUMIO VOLUME 32 Nov 30 12:00:56 vol.raspi volumio[957]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 30 12:00:56 vol.raspi volumio[957]: info: VolumeController::SetAlsaVolume+ Nov 30 12:00:56 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetState Nov 30 12:00:56 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:00:56 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:00:56 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:00:56 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:00:56 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:00:56 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:00:56 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 33 Nov 30 12:00:56 vol.raspi volumio[957]: SPOTIFY: SPOTIFY VOLUME 31 Nov 30 12:00:56 vol.raspi volumio[957]: SPOTIFY: VOLUMIO VOLUME 33 Nov 30 12:00:56 vol.raspi volumio[957]: SPOTIFY: DELTA VOLUME ENOUGH: true Nov 30 12:00:56 vol.raspi volumio[957]: info: Setting Spotify Volume from Volumio: 33 Nov 30 12:00:56 vol.raspi volumio[957]: info: VolumeController::SetAlsaVolume+ Nov 30 12:00:56 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetState Nov 30 12:00:56 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:00:56 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:00:56 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:00:56 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:00:56 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:00:56 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:00:56 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 34 Nov 30 12:00:56 vol.raspi volumio[957]: SPOTIFY: SPOTIFY VOLUME 33 Nov 30 12:00:56 vol.raspi volumio[957]: SPOTIFY: VOLUMIO VOLUME 34 Nov 30 12:00:56 vol.raspi volumio[957]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 30 12:00:57 vol.raspi volumio[957]: info: VolumeController::SetAlsaVolume+ Nov 30 12:00:57 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetState Nov 30 12:00:57 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:00:57 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:00:57 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:00:57 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:00:57 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:00:57 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:00:57 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:00:57 vol.raspi volumio[957]: SPOTIFY: SPOTIFY VOLUME 33 Nov 30 12:00:57 vol.raspi volumio[957]: SPOTIFY: VOLUMIO VOLUME 35 Nov 30 12:00:57 vol.raspi volumio[957]: SPOTIFY: DELTA VOLUME ENOUGH: true Nov 30 12:00:57 vol.raspi volumio[957]: info: Setting Spotify Volume from Volumio: 35 Nov 30 12:00:58 vol.raspi volumio[957]: SPOTIFY: SETTING SPOTIFY VOLUME 35 Nov 30 12:00:58 vol.raspi volumio[957]: info: Sending Spotify command with payload to local API: /player/volume Nov 30 12:01:03 vol.raspi volumio[957]: info: Preload queue cleared Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreCommandRouter::volumioReplaceandPlayItems Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreStateMachine::ClearQueue Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreStateMachine::stop Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreStateMachine::stPlaybackTimer Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreStateMachine::updateTrackBlock Nov 30 12:01:03 vol.raspi volumio[957]: info: CorePlayQueue::getTrackBlock Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:03 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 1 Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreStateMachine::serviceStop Nov 30 12:01:03 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 1 Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreCommandRouter::serviceStop Nov 30 12:01:03 vol.raspi volumio[957]: info: [1732942863871] ControllerUPNPBrowser::stop Nov 30 12:01:03 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand stop Nov 30 12:01:03 vol.raspi volumio[957]: info: CorePlayQueue::clearPlayQueue Nov 30 12:01:03 vol.raspi volumio[957]: info: CorePlayQueue::saveQueue Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushQueue Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreStateMachine::addQueueItems Nov 30 12:01:03 vol.raspi volumio[957]: info: CorePlayQueue::addQueueItems Nov 30 12:01:03 vol.raspi volumio[957]: info: Preload queue cleared Nov 30 12:01:03 vol.raspi volumio[957]: info: Adding Item to queue: upnp/folder/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$B Nov 30 12:01:03 vol.raspi volumio[957]: info: Using cached record of: upnp/folder/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$B Nov 30 12:01:03 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$0 Nov 30 12:01:03 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$0 Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushQueue Nov 30 12:01:03 vol.raspi volumio[957]: info: CorePlayQueue::saveQueue Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreStateMachine::updateTrackBlock Nov 30 12:01:03 vol.raspi volumio[957]: info: CorePlayQueue::getTrackBlock Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPlay Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreStateMachine::play index 1 Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreStateMachine::addQueueItems Nov 30 12:01:03 vol.raspi volumio[957]: info: CorePlayQueue::addQueueItems Nov 30 12:01:03 vol.raspi volumio[957]: info: Preload queue cleared Nov 30 12:01:03 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$1 Nov 30 12:01:03 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$1 Nov 30 12:01:03 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$2 Nov 30 12:01:03 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$2 Nov 30 12:01:03 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$3 Nov 30 12:01:03 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$3 Nov 30 12:01:03 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$4 Nov 30 12:01:03 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$4 Nov 30 12:01:03 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$5 Nov 30 12:01:03 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$5 Nov 30 12:01:03 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$6 Nov 30 12:01:03 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$6 Nov 30 12:01:03 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$7 Nov 30 12:01:03 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$7 Nov 30 12:01:03 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$8 Nov 30 12:01:03 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$8 Nov 30 12:01:03 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$9 Nov 30 12:01:03 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$9 Nov 30 12:01:03 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$A Nov 30 12:01:03 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$A Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreStateMachine::stop Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushQueue Nov 30 12:01:03 vol.raspi volumio[957]: info: CorePlayQueue::saveQueue Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreStateMachine::play index undefined Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreStateMachine::updateTrackBlock Nov 30 12:01:03 vol.raspi volumio[957]: info: CorePlayQueue::getTrackBlock Nov 30 12:01:03 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 1 Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreStateMachine::startPlaybackTimer Nov 30 12:01:03 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 1 Nov 30 12:01:03 vol.raspi volumio[957]: info: [1732942863882] ControllerUPNPBrowser::clearAddPlayTrack Nov 30 12:01:03 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand stop Nov 30 12:01:03 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:03 vol.raspi volumio[957]: info: Nov 30 12:01:03 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:03 vol.raspi volumio[957]: info: sendMpdCommand stop took 14 milliseconds Nov 30 12:01:03 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:03 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:03 vol.raspi volumio[957]: info: sendMpdCommand stop took 4 milliseconds Nov 30 12:01:03 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand clear Nov 30 12:01:03 vol.raspi volumio[957]: info: Nov 30 12:01:03 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:01:03 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:01:03 vol.raspi volumio[957]: info: sendMpdCommand status took 1 milliseconds Nov 30 12:01:03 vol.raspi volumio[957]: info: sendMpdCommand clear took 1 milliseconds Nov 30 12:01:03 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:03 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 12:01:03 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.223:8200/MediaItems/11993.flac" Nov 30 12:01:03 vol.raspi volumio[957]: error: updateQueue error: null Nov 30 12:01:03 vol.raspi volumio[957]: info: ------------------------------ 2ms Nov 30 12:01:03 vol.raspi volumio[957]: info: sendMpdCommand playlistinfo took 2 milliseconds Nov 30 12:01:03 vol.raspi volumio[957]: verbose: ControllerMpd::parseTrackInfo Nov 30 12:01:03 vol.raspi volumio[957]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Nov 30 12:01:03 vol.raspi volumio[957]: info: ------------------------------ 5ms Nov 30 12:01:03 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.223:8200/MediaItems/11993.flac" Nov 30 12:01:03 vol.raspi volumio[957]: info: Nov 30 12:01:03 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:01:03 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:01:03 vol.raspi volumio[957]: info: sendMpdCommand add "http://192.168.1.223:8200/MediaItems/11993.flac" took 1 milliseconds Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 30 12:01:03 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand play Nov 30 12:01:03 vol.raspi volumio[957]: info: ------------------------------ 2ms Nov 30 12:01:03 vol.raspi volumio[957]: info: sendMpdCommand play took 1 milliseconds Nov 30 12:01:03 vol.raspi volumio[957]: info: Nov 30 12:01:03 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:03 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:03 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:03 vol.raspi kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Nov 30 12:01:03 vol.raspi volumio[957]: info: sendMpdCommand status took 15 milliseconds Nov 30 12:01:03 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:03 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 12:01:03 vol.raspi volumio[957]: info: Nov 30 12:01:03 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:01:03 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:01:03 vol.raspi volumio[957]: info: Nov 30 12:01:03 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:03 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:03 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:03 vol.raspi volumio[957]: info: sendMpdCommand playlistinfo took 2 milliseconds Nov 30 12:01:03 vol.raspi volumio[957]: verbose: ControllerMpd::parseTrackInfo Nov 30 12:01:03 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:03 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 1 Nov 30 12:01:03 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":340,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Ha Noi va toi {Le Vinh}","artist":"Ngoc Tan","album":"Khoanh khac {Hacova}","uri":"http://192.168.1.223:8200/MediaItems/11993.flac","trackType":"flac"} Nov 30 12:01:03 vol.raspi volumio[957]: verbose: CURRENT POSITION 1 Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService play Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus stop Nov 30 12:01:03 vol.raspi volumio[957]: info: ------------------------------ 20ms Nov 30 12:01:03 vol.raspi volumio[957]: info: ------------------------------ 4ms Nov 30 12:01:03 vol.raspi volumio[957]: info: sendMpdCommand status took 3 milliseconds Nov 30 12:01:03 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:03 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 12:01:03 vol.raspi volumio[957]: info: sendMpdCommand playlistinfo took 1 milliseconds Nov 30 12:01:03 vol.raspi volumio[957]: verbose: ControllerMpd::parseTrackInfo Nov 30 12:01:03 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:03 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 1 Nov 30 12:01:03 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"play","position":0,"seek":869,"duration":340,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"479 Kbps","isStreaming":false,"title":"Ha Noi va toi {Le Vinh}","artist":"Ngoc Tan","album":"Khoanh khac {Hacova}","uri":"http://192.168.1.223:8200/MediaItems/11993.flac","trackType":"flac"} Nov 30 12:01:03 vol.raspi volumio[957]: verbose: CURRENT POSITION 1 Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService play Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus play Nov 30 12:01:03 vol.raspi volumio[957]: info: Received an update from plugin. extracting info from payload Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:03 vol.raspi volumio[957]: info: ------------------------------ 11ms Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:03 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:03 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:03 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:03 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:03 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:04 vol.raspi ntpd[825]: Soliciting pool server 103.184.124.23 Nov 30 12:01:06 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPrevious Nov 30 12:01:06 vol.raspi volumio[957]: info: CoreStateMachine::previous Nov 30 12:01:06 vol.raspi volumio[957]: info: ControllerMpd::seek Nov 30 12:01:06 vol.raspi volumio[957]: error: null Nov 30 12:01:06 vol.raspi volumio[957]: info: Nov 30 12:01:06 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:06 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:06 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:06 vol.raspi volumio[957]: info: sendMpdCommand status took 0 milliseconds Nov 30 12:01:06 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:06 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 12:01:06 vol.raspi volumio[957]: info: sendMpdCommand playlistinfo took 0 milliseconds Nov 30 12:01:06 vol.raspi volumio[957]: verbose: ControllerMpd::parseTrackInfo Nov 30 12:01:06 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:06 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:06 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 1 Nov 30 12:01:06 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":340,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"492 Kbps","isStreaming":false,"title":"Ha Noi va toi {Le Vinh}","artist":"Ngoc Tan","album":"Khoanh khac {Hacova}","uri":"http://192.168.1.223:8200/MediaItems/11993.flac","trackType":"flac"} Nov 30 12:01:06 vol.raspi volumio[957]: verbose: CURRENT POSITION 1 Nov 30 12:01:06 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService play Nov 30 12:01:06 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus play Nov 30 12:01:06 vol.raspi volumio[957]: info: Received an update from plugin. extracting info from payload Nov 30 12:01:06 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:06 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:06 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:06 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:06 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:06 vol.raspi volumio[957]: info: ------------------------------ 11ms Nov 30 12:01:06 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:06 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:06 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:06 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:06 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:06 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:06 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:06 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:08 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPrevious Nov 30 12:01:08 vol.raspi volumio[957]: info: CoreStateMachine::previous Nov 30 12:01:08 vol.raspi volumio[957]: info: ControllerMpd::previous Nov 30 12:01:08 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand previous Nov 30 12:01:08 vol.raspi volumio[957]: info: Nov 30 12:01:08 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:08 vol.raspi volumio[957]: info: sendMpdCommand previous took 2 milliseconds Nov 30 12:01:08 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:08 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:08 vol.raspi volumio[957]: info: sendMpdCommand status took 1 milliseconds Nov 30 12:01:08 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:08 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 12:01:08 vol.raspi volumio[957]: info: sendMpdCommand playlistinfo took 0 milliseconds Nov 30 12:01:08 vol.raspi volumio[957]: verbose: ControllerMpd::parseTrackInfo Nov 30 12:01:08 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:08 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:08 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 1 Nov 30 12:01:08 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":340,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"432 Kbps","isStreaming":false,"title":"Ha Noi va toi {Le Vinh}","artist":"Ngoc Tan","album":"Khoanh khac {Hacova}","uri":"http://192.168.1.223:8200/MediaItems/11993.flac","trackType":"flac"} Nov 30 12:01:08 vol.raspi volumio[957]: verbose: CURRENT POSITION 1 Nov 30 12:01:08 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService play Nov 30 12:01:08 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus play Nov 30 12:01:08 vol.raspi volumio[957]: info: Received an update from plugin. extracting info from payload Nov 30 12:01:08 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:08 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:08 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:08 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:08 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:08 vol.raspi volumio[957]: info: ------------------------------ 8ms Nov 30 12:01:08 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:08 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:08 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:08 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:08 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:08 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:08 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:08 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:10 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPrevious Nov 30 12:01:10 vol.raspi volumio[957]: info: CoreStateMachine::previous Nov 30 12:01:10 vol.raspi volumio[957]: info: ControllerMpd::seek Nov 30 12:01:10 vol.raspi volumio[957]: error: null Nov 30 12:01:10 vol.raspi volumio[957]: info: Nov 30 12:01:10 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:10 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:10 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:10 vol.raspi volumio[957]: info: sendMpdCommand status took 1 milliseconds Nov 30 12:01:10 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:10 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 12:01:10 vol.raspi volumio[957]: info: sendMpdCommand playlistinfo took 0 milliseconds Nov 30 12:01:10 vol.raspi volumio[957]: verbose: ControllerMpd::parseTrackInfo Nov 30 12:01:10 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:10 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:10 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 1 Nov 30 12:01:10 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":340,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"408 Kbps","isStreaming":false,"title":"Ha Noi va toi {Le Vinh}","artist":"Ngoc Tan","album":"Khoanh khac {Hacova}","uri":"http://192.168.1.223:8200/MediaItems/11993.flac","trackType":"flac"} Nov 30 12:01:10 vol.raspi volumio[957]: verbose: CURRENT POSITION 1 Nov 30 12:01:10 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService play Nov 30 12:01:10 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus play Nov 30 12:01:10 vol.raspi volumio[957]: info: Received an update from plugin. extracting info from payload Nov 30 12:01:10 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:10 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:10 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:10 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:10 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:10 vol.raspi volumio[957]: info: ------------------------------ 8ms Nov 30 12:01:10 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:10 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:10 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:10 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:10 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:10 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:10 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:10 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:11 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPrevious Nov 30 12:01:11 vol.raspi volumio[957]: info: CoreStateMachine::previous Nov 30 12:01:11 vol.raspi volumio[957]: info: ControllerMpd::previous Nov 30 12:01:11 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand previous Nov 30 12:01:11 vol.raspi volumio[957]: info: sendMpdCommand previous took 2 milliseconds Nov 30 12:01:11 vol.raspi volumio[957]: info: Nov 30 12:01:11 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:11 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:11 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:11 vol.raspi volumio[957]: info: sendMpdCommand status took 1 milliseconds Nov 30 12:01:11 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:11 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 12:01:11 vol.raspi volumio[957]: info: sendMpdCommand playlistinfo took 0 milliseconds Nov 30 12:01:11 vol.raspi volumio[957]: verbose: ControllerMpd::parseTrackInfo Nov 30 12:01:11 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:11 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:11 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 1 Nov 30 12:01:11 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":340,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"432 Kbps","isStreaming":false,"title":"Ha Noi va toi {Le Vinh}","artist":"Ngoc Tan","album":"Khoanh khac {Hacova}","uri":"http://192.168.1.223:8200/MediaItems/11993.flac","trackType":"flac"} Nov 30 12:01:11 vol.raspi volumio[957]: verbose: CURRENT POSITION 1 Nov 30 12:01:11 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService play Nov 30 12:01:11 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus play Nov 30 12:01:11 vol.raspi volumio[957]: info: Received an update from plugin. extracting info from payload Nov 30 12:01:11 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:11 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:11 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:11 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:11 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:11 vol.raspi volumio[957]: info: ------------------------------ 8ms Nov 30 12:01:11 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:11 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:11 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:11 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:11 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:11 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:11 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:11 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:13 vol.raspi ntpd[825]: Soliciting pool server 115.165.161.155 Nov 30 12:01:13 vol.raspi volumio[957]: info: CoreCommandRouter::volumioNext Nov 30 12:01:13 vol.raspi volumio[957]: info: CoreStateMachine::next Nov 30 12:01:13 vol.raspi volumio[957]: info: ControllerMpd::next Nov 30 12:01:13 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand next Nov 30 12:01:13 vol.raspi volumio[957]: info: sendMpdCommand next took 6 milliseconds Nov 30 12:01:13 vol.raspi volumio[957]: info: Nov 30 12:01:13 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:13 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:13 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:13 vol.raspi volumio[957]: info: sendMpdCommand status took 1 milliseconds Nov 30 12:01:13 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:13 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:13 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:13 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:13 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:13 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:13 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 1 Nov 30 12:01:13 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Nov 30 12:01:13 vol.raspi volumio[957]: verbose: CURRENT POSITION 1 Nov 30 12:01:13 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService stop Nov 30 12:01:13 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus play Nov 30 12:01:13 vol.raspi volumio[957]: info: CoreStateMachine::play index undefined Nov 30 12:01:13 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 30 12:01:13 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:13 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 2 Nov 30 12:01:13 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:13 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:13 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 2 Nov 30 12:01:13 vol.raspi volumio[957]: info: CoreStateMachine::startPlaybackTimer Nov 30 12:01:13 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 2 Nov 30 12:01:13 vol.raspi volumio[957]: info: [1732942873736] ControllerUPNPBrowser::clearAddPlayTrack Nov 30 12:01:13 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand stop Nov 30 12:01:13 vol.raspi volumio[957]: info: ------------------------------ 8ms Nov 30 12:01:13 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:13 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 2 Nov 30 12:01:13 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:13 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:13 vol.raspi volumio[957]: info: sendMpdCommand stop took 4 milliseconds Nov 30 12:01:13 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand clear Nov 30 12:01:13 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:13 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:13 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:13 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:13 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:13 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:13 vol.raspi volumio[957]: info: Nov 30 12:01:13 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:01:13 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:01:13 vol.raspi volumio[957]: info: sendMpdCommand clear took 12 milliseconds Nov 30 12:01:13 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.223:8200/MediaItems/11994.flac" Nov 30 12:01:13 vol.raspi volumio[957]: error: updateQueue error: null Nov 30 12:01:13 vol.raspi volumio[957]: info: ------------------------------ 2ms Nov 30 12:01:13 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.223:8200/MediaItems/11994.flac" Nov 30 12:01:13 vol.raspi volumio[957]: info: Nov 30 12:01:13 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:01:13 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:01:13 vol.raspi volumio[957]: info: sendMpdCommand add "http://192.168.1.223:8200/MediaItems/11994.flac" took 1 milliseconds Nov 30 12:01:13 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 30 12:01:13 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand play Nov 30 12:01:13 vol.raspi volumio[957]: info: ------------------------------ 1ms Nov 30 12:01:13 vol.raspi volumio[957]: info: sendMpdCommand play took 1 milliseconds Nov 30 12:01:13 vol.raspi volumio[957]: info: Nov 30 12:01:13 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:13 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:13 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:13 vol.raspi kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Nov 30 12:01:13 vol.raspi volumio[957]: info: Nov 30 12:01:13 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:01:13 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:01:13 vol.raspi volumio[957]: info: Nov 30 12:01:13 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:13 vol.raspi volumio[957]: info: sendMpdCommand status took 16 milliseconds Nov 30 12:01:13 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:13 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:13 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:13 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 12:01:13 vol.raspi volumio[957]: info: ------------------------------ 2ms Nov 30 12:01:13 vol.raspi volumio[957]: info: sendMpdCommand status took 2 milliseconds Nov 30 12:01:13 vol.raspi volumio[957]: info: sendMpdCommand playlistinfo took 2 milliseconds Nov 30 12:01:13 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:13 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 12:01:13 vol.raspi volumio[957]: verbose: ControllerMpd::parseTrackInfo Nov 30 12:01:13 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:13 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:13 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 2 Nov 30 12:01:13 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":303,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1 Kbps","isStreaming":false,"title":"Dung quen nhau {Duc Minh}","artist":"Ngoc Tan","album":"Khoanh khac {Hacova}","uri":"http://192.168.1.223:8200/MediaItems/11994.flac","trackType":"flac"} Nov 30 12:01:13 vol.raspi volumio[957]: verbose: CURRENT POSITION 2 Nov 30 12:01:13 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService play Nov 30 12:01:13 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus stop Nov 30 12:01:13 vol.raspi volumio[957]: info: ------------------------------ 20ms Nov 30 12:01:13 vol.raspi volumio[957]: info: sendMpdCommand playlistinfo took 2 milliseconds Nov 30 12:01:13 vol.raspi volumio[957]: verbose: ControllerMpd::parseTrackInfo Nov 30 12:01:13 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:13 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:13 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 2 Nov 30 12:01:13 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"play","position":0,"seek":869,"duration":303,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"510 Kbps","isStreaming":false,"title":"Dung quen nhau {Duc Minh}","artist":"Ngoc Tan","album":"Khoanh khac {Hacova}","uri":"http://192.168.1.223:8200/MediaItems/11994.flac","trackType":"flac"} Nov 30 12:01:13 vol.raspi volumio[957]: verbose: CURRENT POSITION 2 Nov 30 12:01:13 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService play Nov 30 12:01:13 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus play Nov 30 12:01:13 vol.raspi volumio[957]: info: Received an update from plugin. extracting info from payload Nov 30 12:01:13 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:13 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:13 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:13 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:13 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:13 vol.raspi volumio[957]: info: ------------------------------ 11ms Nov 30 12:01:13 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:13 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:13 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:13 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:13 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:13 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:13 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:13 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:14 vol.raspi ntpd[825]: Soliciting pool server 2400:6760:0:300::23 Nov 30 12:01:14 vol.raspi volumio[957]: info: CoreCommandRouter::volumioNext Nov 30 12:01:14 vol.raspi volumio[957]: info: CoreStateMachine::next Nov 30 12:01:14 vol.raspi volumio[957]: info: ControllerMpd::next Nov 30 12:01:14 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand next Nov 30 12:01:14 vol.raspi volumio[957]: info: sendMpdCommand next took 6 milliseconds Nov 30 12:01:14 vol.raspi volumio[957]: info: Nov 30 12:01:14 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:14 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:14 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:14 vol.raspi volumio[957]: info: sendMpdCommand status took 0 milliseconds Nov 30 12:01:14 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:14 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:14 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:14 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:14 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:14 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:14 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 2 Nov 30 12:01:14 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Nov 30 12:01:14 vol.raspi volumio[957]: verbose: CURRENT POSITION 2 Nov 30 12:01:14 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService stop Nov 30 12:01:14 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus play Nov 30 12:01:14 vol.raspi volumio[957]: info: CoreStateMachine::play index undefined Nov 30 12:01:14 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 30 12:01:14 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:14 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 3 Nov 30 12:01:14 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:14 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:14 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 3 Nov 30 12:01:14 vol.raspi volumio[957]: info: CoreStateMachine::startPlaybackTimer Nov 30 12:01:14 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 3 Nov 30 12:01:14 vol.raspi volumio[957]: info: [1732942874839] ControllerUPNPBrowser::clearAddPlayTrack Nov 30 12:01:14 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand stop Nov 30 12:01:14 vol.raspi volumio[957]: info: ------------------------------ 7ms Nov 30 12:01:14 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:14 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 3 Nov 30 12:01:14 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:14 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:14 vol.raspi volumio[957]: info: sendMpdCommand stop took 3 milliseconds Nov 30 12:01:14 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand clear Nov 30 12:01:14 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:14 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:14 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:14 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:14 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:14 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:14 vol.raspi volumio[957]: info: Nov 30 12:01:14 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:01:14 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:01:14 vol.raspi volumio[957]: info: sendMpdCommand clear took 15 milliseconds Nov 30 12:01:14 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.223:8200/MediaItems/11995.flac" Nov 30 12:01:14 vol.raspi volumio[957]: error: updateQueue error: null Nov 30 12:01:14 vol.raspi volumio[957]: info: ------------------------------ 2ms Nov 30 12:01:14 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.223:8200/MediaItems/11995.flac" Nov 30 12:01:14 vol.raspi volumio[957]: info: Nov 30 12:01:14 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:01:14 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:01:14 vol.raspi volumio[957]: info: sendMpdCommand add "http://192.168.1.223:8200/MediaItems/11995.flac" took 1 milliseconds Nov 30 12:01:14 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 30 12:01:14 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand play Nov 30 12:01:14 vol.raspi volumio[957]: info: ------------------------------ 1ms Nov 30 12:01:14 vol.raspi volumio[957]: info: sendMpdCommand play took 1 milliseconds Nov 30 12:01:14 vol.raspi volumio[957]: info: Nov 30 12:01:14 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:14 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:14 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:14 vol.raspi kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Nov 30 12:01:14 vol.raspi volumio[957]: info: Nov 30 12:01:14 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:01:14 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:01:14 vol.raspi volumio[957]: info: Nov 30 12:01:14 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:14 vol.raspi volumio[957]: info: sendMpdCommand status took 16 milliseconds Nov 30 12:01:14 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:14 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:14 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:14 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 12:01:14 vol.raspi volumio[957]: info: ------------------------------ 7ms Nov 30 12:01:14 vol.raspi volumio[957]: info: sendMpdCommand status took 3 milliseconds Nov 30 12:01:14 vol.raspi volumio[957]: info: sendMpdCommand playlistinfo took 3 milliseconds Nov 30 12:01:14 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:14 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 12:01:14 vol.raspi volumio[957]: verbose: ControllerMpd::parseTrackInfo Nov 30 12:01:14 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:14 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:14 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 3 Nov 30 12:01:14 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":316,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Ha Noi mua la bay {Huu Xuan}","artist":"Ngoc Tan","album":"Khoanh khac {Hacova}","uri":"http://192.168.1.223:8200/MediaItems/11995.flac","trackType":"flac"} Nov 30 12:01:14 vol.raspi volumio[957]: verbose: CURRENT POSITION 3 Nov 30 12:01:14 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService play Nov 30 12:01:14 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus stop Nov 30 12:01:14 vol.raspi volumio[957]: info: ------------------------------ 27ms Nov 30 12:01:14 vol.raspi volumio[957]: info: sendMpdCommand playlistinfo took 2 milliseconds Nov 30 12:01:14 vol.raspi volumio[957]: verbose: ControllerMpd::parseTrackInfo Nov 30 12:01:14 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:14 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:14 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 3 Nov 30 12:01:14 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"play","position":0,"seek":869,"duration":316,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"483 Kbps","isStreaming":false,"title":"Ha Noi mua la bay {Huu Xuan}","artist":"Ngoc Tan","album":"Khoanh khac {Hacova}","uri":"http://192.168.1.223:8200/MediaItems/11995.flac","trackType":"flac"} Nov 30 12:01:14 vol.raspi volumio[957]: verbose: CURRENT POSITION 3 Nov 30 12:01:14 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService play Nov 30 12:01:14 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus play Nov 30 12:01:14 vol.raspi volumio[957]: info: Received an update from plugin. extracting info from payload Nov 30 12:01:14 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:14 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:14 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:14 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:14 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:14 vol.raspi volumio[957]: info: ------------------------------ 19ms Nov 30 12:01:14 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:14 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:14 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:14 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:14 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:14 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:14 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:14 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:15 vol.raspi volumio[957]: info: CoreCommandRouter::volumioNext Nov 30 12:01:15 vol.raspi volumio[957]: info: CoreStateMachine::next Nov 30 12:01:15 vol.raspi volumio[957]: info: ControllerMpd::next Nov 30 12:01:15 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand next Nov 30 12:01:15 vol.raspi volumio[957]: info: sendMpdCommand next took 4 milliseconds Nov 30 12:01:15 vol.raspi volumio[957]: info: Nov 30 12:01:15 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:15 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:15 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:15 vol.raspi volumio[957]: info: sendMpdCommand status took 1 milliseconds Nov 30 12:01:15 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:15 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:15 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:15 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:15 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:15 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:15 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 3 Nov 30 12:01:15 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Nov 30 12:01:15 vol.raspi volumio[957]: verbose: CURRENT POSITION 3 Nov 30 12:01:15 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService stop Nov 30 12:01:15 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus play Nov 30 12:01:15 vol.raspi volumio[957]: info: CoreStateMachine::play index undefined Nov 30 12:01:15 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 30 12:01:15 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:15 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 4 Nov 30 12:01:15 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:15 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:15 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 4 Nov 30 12:01:15 vol.raspi volumio[957]: info: CoreStateMachine::startPlaybackTimer Nov 30 12:01:15 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 4 Nov 30 12:01:15 vol.raspi volumio[957]: info: [1732942875256] ControllerUPNPBrowser::clearAddPlayTrack Nov 30 12:01:15 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand stop Nov 30 12:01:15 vol.raspi volumio[957]: info: ------------------------------ 6ms Nov 30 12:01:15 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:15 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 4 Nov 30 12:01:15 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:15 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:15 vol.raspi volumio[957]: info: sendMpdCommand stop took 3 milliseconds Nov 30 12:01:15 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand clear Nov 30 12:01:15 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:15 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:15 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:15 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:15 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:15 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:15 vol.raspi volumio[957]: info: Nov 30 12:01:15 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:01:15 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:01:15 vol.raspi volumio[957]: info: sendMpdCommand clear took 11 milliseconds Nov 30 12:01:15 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.223:8200/MediaItems/11996.flac" Nov 30 12:01:15 vol.raspi volumio[957]: error: updateQueue error: null Nov 30 12:01:15 vol.raspi volumio[957]: info: ------------------------------ 3ms Nov 30 12:01:15 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.223:8200/MediaItems/11996.flac" Nov 30 12:01:15 vol.raspi volumio[957]: info: Nov 30 12:01:15 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:01:15 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:01:15 vol.raspi volumio[957]: info: sendMpdCommand add "http://192.168.1.223:8200/MediaItems/11996.flac" took 1 milliseconds Nov 30 12:01:15 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 30 12:01:15 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand play Nov 30 12:01:15 vol.raspi volumio[957]: info: ------------------------------ 1ms Nov 30 12:01:15 vol.raspi volumio[957]: info: sendMpdCommand play took 1 milliseconds Nov 30 12:01:15 vol.raspi volumio[957]: info: Nov 30 12:01:15 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:15 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:15 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:15 vol.raspi kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Nov 30 12:01:15 vol.raspi volumio[957]: info: sendMpdCommand status took 16 milliseconds Nov 30 12:01:15 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:15 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 12:01:15 vol.raspi volumio[957]: info: Nov 30 12:01:15 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:01:15 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:01:15 vol.raspi volumio[957]: info: Nov 30 12:01:15 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:15 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:15 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:15 vol.raspi volumio[957]: info: sendMpdCommand playlistinfo took 1 milliseconds Nov 30 12:01:15 vol.raspi volumio[957]: verbose: ControllerMpd::parseTrackInfo Nov 30 12:01:15 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:15 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:15 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 4 Nov 30 12:01:15 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":352,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"368 Kbps","isStreaming":false,"title":"Anh se den {Luong Hai}","artist":"Ngoc Tan","album":"Khoanh khac {Hacova}","uri":"http://192.168.1.223:8200/MediaItems/11996.flac","trackType":"flac"} Nov 30 12:01:15 vol.raspi volumio[957]: verbose: CURRENT POSITION 4 Nov 30 12:01:15 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService play Nov 30 12:01:15 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus stop Nov 30 12:01:15 vol.raspi volumio[957]: info: ------------------------------ 19ms Nov 30 12:01:15 vol.raspi volumio[957]: info: ------------------------------ 3ms Nov 30 12:01:15 vol.raspi volumio[957]: info: sendMpdCommand status took 3 milliseconds Nov 30 12:01:15 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:15 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 12:01:15 vol.raspi volumio[957]: info: sendMpdCommand playlistinfo took 1 milliseconds Nov 30 12:01:15 vol.raspi volumio[957]: verbose: ControllerMpd::parseTrackInfo Nov 30 12:01:15 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:15 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:15 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 4 Nov 30 12:01:15 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"play","position":0,"seek":869,"duration":352,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"495 Kbps","isStreaming":false,"title":"Anh se den {Luong Hai}","artist":"Ngoc Tan","album":"Khoanh khac {Hacova}","uri":"http://192.168.1.223:8200/MediaItems/11996.flac","trackType":"flac"} Nov 30 12:01:15 vol.raspi volumio[957]: verbose: CURRENT POSITION 4 Nov 30 12:01:15 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService play Nov 30 12:01:15 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus play Nov 30 12:01:15 vol.raspi volumio[957]: info: Received an update from plugin. extracting info from payload Nov 30 12:01:15 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:15 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:15 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:15 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:15 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:15 vol.raspi volumio[957]: info: ------------------------------ 10ms Nov 30 12:01:15 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:15 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:15 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:15 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:15 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:15 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:15 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:15 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreCommandRouter::volumioNext Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::next Nov 30 12:01:16 vol.raspi volumio[957]: info: ControllerMpd::next Nov 30 12:01:16 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand next Nov 30 12:01:16 vol.raspi volumio[957]: info: sendMpdCommand next took 6 milliseconds Nov 30 12:01:16 vol.raspi volumio[957]: info: Nov 30 12:01:16 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:16 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:16 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:16 vol.raspi volumio[957]: info: sendMpdCommand status took 0 milliseconds Nov 30 12:01:16 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:16 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:16 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 4 Nov 30 12:01:16 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Nov 30 12:01:16 vol.raspi volumio[957]: verbose: CURRENT POSITION 4 Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService stop Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus play Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::play index undefined Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:16 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 5 Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:16 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 5 Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::startPlaybackTimer Nov 30 12:01:16 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 5 Nov 30 12:01:16 vol.raspi volumio[957]: info: [1732942876072] ControllerUPNPBrowser::clearAddPlayTrack Nov 30 12:01:16 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand stop Nov 30 12:01:16 vol.raspi volumio[957]: info: ------------------------------ 7ms Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:16 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 5 Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:16 vol.raspi volumio[957]: info: sendMpdCommand stop took 4 milliseconds Nov 30 12:01:16 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand clear Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:16 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:16 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:16 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:16 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:16 vol.raspi volumio[957]: info: Nov 30 12:01:16 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:01:16 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:01:16 vol.raspi volumio[957]: info: sendMpdCommand clear took 10 milliseconds Nov 30 12:01:16 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.223:8200/MediaItems/11997.flac" Nov 30 12:01:16 vol.raspi volumio[957]: error: updateQueue error: null Nov 30 12:01:16 vol.raspi volumio[957]: info: ------------------------------ 1ms Nov 30 12:01:16 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.223:8200/MediaItems/11997.flac" Nov 30 12:01:16 vol.raspi volumio[957]: info: Nov 30 12:01:16 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:01:16 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:01:16 vol.raspi volumio[957]: info: sendMpdCommand add "http://192.168.1.223:8200/MediaItems/11997.flac" took 0 milliseconds Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 30 12:01:16 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand play Nov 30 12:01:16 vol.raspi volumio[957]: info: ------------------------------ 2ms Nov 30 12:01:16 vol.raspi volumio[957]: info: sendMpdCommand play took 1 milliseconds Nov 30 12:01:16 vol.raspi volumio[957]: info: Nov 30 12:01:16 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:16 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:16 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:16 vol.raspi kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Nov 30 12:01:16 vol.raspi volumio[957]: info: sendMpdCommand status took 15 milliseconds Nov 30 12:01:16 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:16 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 12:01:16 vol.raspi volumio[957]: info: Nov 30 12:01:16 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:01:16 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:01:16 vol.raspi volumio[957]: info: Nov 30 12:01:16 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:16 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:16 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:16 vol.raspi volumio[957]: info: sendMpdCommand playlistinfo took 3 milliseconds Nov 30 12:01:16 vol.raspi volumio[957]: info: ------------------------------ 2ms Nov 30 12:01:16 vol.raspi volumio[957]: info: sendMpdCommand status took 1 milliseconds Nov 30 12:01:16 vol.raspi volumio[957]: verbose: ControllerMpd::parseTrackInfo Nov 30 12:01:16 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:16 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 12:01:16 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:16 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 5 Nov 30 12:01:16 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":400,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Sapa Thanh pho trong suong {Vinh Cat}","artist":"Ngoc Tan","album":"Khoanh khac {Hacova}","uri":"http://192.168.1.223:8200/MediaItems/11997.flac","trackType":"flac"} Nov 30 12:01:16 vol.raspi volumio[957]: verbose: CURRENT POSITION 5 Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService play Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus stop Nov 30 12:01:16 vol.raspi volumio[957]: info: ------------------------------ 21ms Nov 30 12:01:16 vol.raspi volumio[957]: info: sendMpdCommand playlistinfo took 1 milliseconds Nov 30 12:01:16 vol.raspi volumio[957]: verbose: ControllerMpd::parseTrackInfo Nov 30 12:01:16 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:16 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 5 Nov 30 12:01:16 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"play","position":0,"seek":869,"duration":400,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"604 Kbps","isStreaming":false,"title":"Sapa Thanh pho trong suong {Vinh Cat}","artist":"Ngoc Tan","album":"Khoanh khac {Hacova}","uri":"http://192.168.1.223:8200/MediaItems/11997.flac","trackType":"flac"} Nov 30 12:01:16 vol.raspi volumio[957]: verbose: CURRENT POSITION 5 Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService play Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus play Nov 30 12:01:16 vol.raspi volumio[957]: info: Received an update from plugin. extracting info from payload Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:16 vol.raspi volumio[957]: info: ------------------------------ 10ms Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:16 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:16 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:16 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:16 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreCommandRouter::volumioNext Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::next Nov 30 12:01:16 vol.raspi volumio[957]: info: ControllerMpd::next Nov 30 12:01:16 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand next Nov 30 12:01:16 vol.raspi volumio[957]: info: Nov 30 12:01:16 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:16 vol.raspi volumio[957]: info: sendMpdCommand next took 6 milliseconds Nov 30 12:01:16 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:16 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:16 vol.raspi volumio[957]: info: sendMpdCommand status took 0 milliseconds Nov 30 12:01:16 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:16 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:16 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 5 Nov 30 12:01:16 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Nov 30 12:01:16 vol.raspi volumio[957]: verbose: CURRENT POSITION 5 Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService stop Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus play Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::play index undefined Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:16 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 6 Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:16 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 6 Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::startPlaybackTimer Nov 30 12:01:16 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 6 Nov 30 12:01:16 vol.raspi volumio[957]: info: [1732942876582] ControllerUPNPBrowser::clearAddPlayTrack Nov 30 12:01:16 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand stop Nov 30 12:01:16 vol.raspi volumio[957]: info: ------------------------------ 7ms Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:16 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 6 Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:16 vol.raspi volumio[957]: info: sendMpdCommand stop took 4 milliseconds Nov 30 12:01:16 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand clear Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:16 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:16 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:16 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:16 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:16 vol.raspi volumio[957]: info: Nov 30 12:01:16 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:01:16 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:01:16 vol.raspi volumio[957]: info: sendMpdCommand clear took 10 milliseconds Nov 30 12:01:16 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.223:8200/MediaItems/11998.flac" Nov 30 12:01:16 vol.raspi volumio[957]: error: updateQueue error: null Nov 30 12:01:16 vol.raspi volumio[957]: info: ------------------------------ 2ms Nov 30 12:01:16 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.223:8200/MediaItems/11998.flac" Nov 30 12:01:16 vol.raspi volumio[957]: info: Nov 30 12:01:16 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:01:16 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:01:16 vol.raspi volumio[957]: info: sendMpdCommand add "http://192.168.1.223:8200/MediaItems/11998.flac" took 1 milliseconds Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 30 12:01:16 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand play Nov 30 12:01:16 vol.raspi volumio[957]: info: ------------------------------ 1ms Nov 30 12:01:16 vol.raspi volumio[957]: info: sendMpdCommand play took 1 milliseconds Nov 30 12:01:16 vol.raspi volumio[957]: info: Nov 30 12:01:16 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:16 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:16 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:16 vol.raspi kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Nov 30 12:01:16 vol.raspi volumio[957]: info: Nov 30 12:01:16 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:16 vol.raspi volumio[957]: info: sendMpdCommand status took 15 milliseconds Nov 30 12:01:16 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:16 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:16 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:16 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 12:01:16 vol.raspi volumio[957]: info: Nov 30 12:01:16 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:01:16 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:01:16 vol.raspi volumio[957]: info: Nov 30 12:01:16 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:16 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:16 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:16 vol.raspi volumio[957]: info: sendMpdCommand status took 3 milliseconds Nov 30 12:01:16 vol.raspi volumio[957]: info: sendMpdCommand playlistinfo took 3 milliseconds Nov 30 12:01:16 vol.raspi volumio[957]: info: ------------------------------ 2ms Nov 30 12:01:16 vol.raspi volumio[957]: info: sendMpdCommand status took 2 milliseconds Nov 30 12:01:16 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:16 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 12:01:16 vol.raspi volumio[957]: verbose: ControllerMpd::parseTrackInfo Nov 30 12:01:16 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:16 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 12:01:16 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:16 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 6 Nov 30 12:01:16 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":294,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Bien dem {Le Vinh}","artist":"Ngoc Tan","album":"Khoanh khac {Hacova}","uri":"http://192.168.1.223:8200/MediaItems/11998.flac","trackType":"flac"} Nov 30 12:01:16 vol.raspi volumio[957]: verbose: CURRENT POSITION 6 Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService play Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus stop Nov 30 12:01:16 vol.raspi volumio[957]: info: ------------------------------ 22ms Nov 30 12:01:16 vol.raspi volumio[957]: info: sendMpdCommand playlistinfo took 2 milliseconds Nov 30 12:01:16 vol.raspi volumio[957]: info: sendMpdCommand playlistinfo took 2 milliseconds Nov 30 12:01:16 vol.raspi volumio[957]: verbose: ControllerMpd::parseTrackInfo Nov 30 12:01:16 vol.raspi volumio[957]: verbose: ControllerMpd::parseTrackInfo Nov 30 12:01:16 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:16 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 6 Nov 30 12:01:16 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"play","position":0,"seek":869,"duration":294,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"367 Kbps","isStreaming":false,"title":"Bien dem {Le Vinh}","artist":"Ngoc Tan","album":"Khoanh khac {Hacova}","uri":"http://192.168.1.223:8200/MediaItems/11998.flac","trackType":"flac"} Nov 30 12:01:16 vol.raspi volumio[957]: verbose: CURRENT POSITION 6 Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService play Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus play Nov 30 12:01:16 vol.raspi volumio[957]: info: Received an update from plugin. extracting info from payload Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:16 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:16 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 6 Nov 30 12:01:16 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"play","position":0,"seek":869,"duration":294,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"367 Kbps","isStreaming":false,"title":"Bien dem {Le Vinh}","artist":"Ngoc Tan","album":"Khoanh khac {Hacova}","uri":"http://192.168.1.223:8200/MediaItems/11998.flac","trackType":"flac"} Nov 30 12:01:16 vol.raspi volumio[957]: verbose: CURRENT POSITION 6 Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService play Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus play Nov 30 12:01:16 vol.raspi volumio[957]: info: Received an update from plugin. extracting info from payload Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:16 vol.raspi volumio[957]: info: ------------------------------ 15ms Nov 30 12:01:16 vol.raspi volumio[957]: info: ------------------------------ 13ms Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:16 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:16 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:16 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:16 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:16 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:16 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:16 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:16 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:16 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::volumioNext Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::next Nov 30 12:01:17 vol.raspi volumio[957]: info: ControllerMpd::next Nov 30 12:01:17 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand next Nov 30 12:01:17 vol.raspi volumio[957]: info: Nov 30 12:01:17 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:17 vol.raspi volumio[957]: info: sendMpdCommand next took 6 milliseconds Nov 30 12:01:17 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:17 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:17 vol.raspi volumio[957]: info: sendMpdCommand status took 0 milliseconds Nov 30 12:01:17 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:17 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:17 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 6 Nov 30 12:01:17 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Nov 30 12:01:17 vol.raspi volumio[957]: verbose: CURRENT POSITION 6 Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService stop Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus play Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::play index undefined Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:17 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 7 Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:17 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 7 Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::startPlaybackTimer Nov 30 12:01:17 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 7 Nov 30 12:01:17 vol.raspi volumio[957]: info: [1732942877328] ControllerUPNPBrowser::clearAddPlayTrack Nov 30 12:01:17 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand stop Nov 30 12:01:17 vol.raspi volumio[957]: info: ------------------------------ 7ms Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:17 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 7 Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:17 vol.raspi volumio[957]: info: sendMpdCommand stop took 4 milliseconds Nov 30 12:01:17 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand clear Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:17 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:17 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:17 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:17 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:17 vol.raspi volumio[957]: info: Nov 30 12:01:17 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:01:17 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:01:17 vol.raspi volumio[957]: info: sendMpdCommand clear took 11 milliseconds Nov 30 12:01:17 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.223:8200/MediaItems/11999.flac" Nov 30 12:01:17 vol.raspi volumio[957]: error: updateQueue error: null Nov 30 12:01:17 vol.raspi volumio[957]: info: ------------------------------ 1ms Nov 30 12:01:17 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.223:8200/MediaItems/11999.flac" Nov 30 12:01:17 vol.raspi volumio[957]: info: sendMpdCommand add "http://192.168.1.223:8200/MediaItems/11999.flac" took 0 milliseconds Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 30 12:01:17 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand play Nov 30 12:01:17 vol.raspi volumio[957]: info: Nov 30 12:01:17 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:01:17 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:01:17 vol.raspi volumio[957]: info: sendMpdCommand play took 1 milliseconds Nov 30 12:01:17 vol.raspi volumio[957]: info: ------------------------------ 1ms Nov 30 12:01:17 vol.raspi volumio[957]: info: Nov 30 12:01:17 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:17 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:17 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:17 vol.raspi kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Nov 30 12:01:17 vol.raspi volumio[957]: info: sendMpdCommand status took 15 milliseconds Nov 30 12:01:17 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:17 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 12:01:17 vol.raspi volumio[957]: info: Nov 30 12:01:17 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:17 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:17 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:17 vol.raspi volumio[957]: info: Nov 30 12:01:17 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:01:17 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:01:17 vol.raspi volumio[957]: info: Nov 30 12:01:17 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:17 vol.raspi volumio[957]: info: sendMpdCommand playlistinfo took 3 milliseconds Nov 30 12:01:17 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:17 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:17 vol.raspi volumio[957]: verbose: ControllerMpd::parseTrackInfo Nov 30 12:01:17 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:17 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 7 Nov 30 12:01:17 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":248,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Cau hat ben song {Tuan Phuong}","artist":"Ngoc Tan","album":"Khoanh khac {Hacova}","uri":"http://192.168.1.223:8200/MediaItems/11999.flac","trackType":"flac"} Nov 30 12:01:17 vol.raspi volumio[957]: verbose: CURRENT POSITION 7 Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService play Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus stop Nov 30 12:01:17 vol.raspi volumio[957]: info: ------------------------------ 20ms Nov 30 12:01:17 vol.raspi volumio[957]: info: sendMpdCommand status took 4 milliseconds Nov 30 12:01:17 vol.raspi volumio[957]: info: ------------------------------ 3ms Nov 30 12:01:17 vol.raspi volumio[957]: info: sendMpdCommand status took 2 milliseconds Nov 30 12:01:17 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:17 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 12:01:17 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:17 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 12:01:17 vol.raspi volumio[957]: info: sendMpdCommand playlistinfo took 1 milliseconds Nov 30 12:01:17 vol.raspi volumio[957]: info: sendMpdCommand playlistinfo took 1 milliseconds Nov 30 12:01:17 vol.raspi volumio[957]: verbose: ControllerMpd::parseTrackInfo Nov 30 12:01:17 vol.raspi volumio[957]: verbose: ControllerMpd::parseTrackInfo Nov 30 12:01:17 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:17 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 7 Nov 30 12:01:17 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"play","position":0,"seek":571,"duration":248,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"700 Kbps","isStreaming":false,"title":"Cau hat ben song {Tuan Phuong}","artist":"Ngoc Tan","album":"Khoanh khac {Hacova}","uri":"http://192.168.1.223:8200/MediaItems/11999.flac","trackType":"flac"} Nov 30 12:01:17 vol.raspi volumio[957]: verbose: CURRENT POSITION 7 Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService play Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus play Nov 30 12:01:17 vol.raspi volumio[957]: info: Received an update from plugin. extracting info from payload Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:17 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:17 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 7 Nov 30 12:01:17 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"play","position":0,"seek":869,"duration":248,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"762 Kbps","isStreaming":false,"title":"Cau hat ben song {Tuan Phuong}","artist":"Ngoc Tan","album":"Khoanh khac {Hacova}","uri":"http://192.168.1.223:8200/MediaItems/11999.flac","trackType":"flac"} Nov 30 12:01:17 vol.raspi volumio[957]: verbose: CURRENT POSITION 7 Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService play Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus play Nov 30 12:01:17 vol.raspi volumio[957]: info: Received an update from plugin. extracting info from payload Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:17 vol.raspi volumio[957]: info: ------------------------------ 16ms Nov 30 12:01:17 vol.raspi volumio[957]: info: ------------------------------ 15ms Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:17 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:17 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:17 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:17 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:17 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:17 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:17 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:17 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::volumioNext Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::next Nov 30 12:01:17 vol.raspi volumio[957]: info: ControllerMpd::next Nov 30 12:01:17 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand next Nov 30 12:01:17 vol.raspi volumio[957]: info: Nov 30 12:01:17 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:17 vol.raspi volumio[957]: info: sendMpdCommand next took 6 milliseconds Nov 30 12:01:17 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:17 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:17 vol.raspi volumio[957]: info: sendMpdCommand status took 1 milliseconds Nov 30 12:01:17 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:17 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:17 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 7 Nov 30 12:01:17 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Nov 30 12:01:17 vol.raspi volumio[957]: verbose: CURRENT POSITION 7 Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService stop Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus play Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::play index undefined Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:17 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 8 Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:17 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 8 Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::startPlaybackTimer Nov 30 12:01:17 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 8 Nov 30 12:01:17 vol.raspi volumio[957]: info: [1732942877779] ControllerUPNPBrowser::clearAddPlayTrack Nov 30 12:01:17 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand stop Nov 30 12:01:17 vol.raspi volumio[957]: info: ------------------------------ 7ms Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:17 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 8 Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:17 vol.raspi volumio[957]: info: sendMpdCommand stop took 3 milliseconds Nov 30 12:01:17 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand clear Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:17 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:17 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:17 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:17 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:17 vol.raspi volumio[957]: info: Nov 30 12:01:17 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:01:17 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:01:17 vol.raspi volumio[957]: info: sendMpdCommand clear took 10 milliseconds Nov 30 12:01:17 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.223:8200/MediaItems/12000.flac" Nov 30 12:01:17 vol.raspi volumio[957]: error: updateQueue error: null Nov 30 12:01:17 vol.raspi volumio[957]: info: ------------------------------ 2ms Nov 30 12:01:17 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.223:8200/MediaItems/12000.flac" Nov 30 12:01:17 vol.raspi volumio[957]: info: Nov 30 12:01:17 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:01:17 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:01:17 vol.raspi volumio[957]: info: sendMpdCommand add "http://192.168.1.223:8200/MediaItems/12000.flac" took 12 milliseconds Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 30 12:01:17 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand play Nov 30 12:01:17 vol.raspi volumio[957]: info: ------------------------------ 2ms Nov 30 12:01:17 vol.raspi kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Nov 30 12:01:17 vol.raspi volumio[957]: info: Nov 30 12:01:17 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:17 vol.raspi volumio[957]: info: sendMpdCommand play took 28 milliseconds Nov 30 12:01:17 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:17 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:17 vol.raspi volumio[957]: info: Nov 30 12:01:17 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:01:17 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:01:17 vol.raspi volumio[957]: info: Nov 30 12:01:17 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:17 vol.raspi volumio[957]: info: sendMpdCommand status took 20 milliseconds Nov 30 12:01:17 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:17 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:17 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:17 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 12:01:17 vol.raspi volumio[957]: info: ------------------------------ 23ms Nov 30 12:01:17 vol.raspi volumio[957]: info: sendMpdCommand status took 22 milliseconds Nov 30 12:01:17 vol.raspi volumio[957]: info: sendMpdCommand playlistinfo took 22 milliseconds Nov 30 12:01:17 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:17 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 12:01:17 vol.raspi volumio[957]: verbose: ControllerMpd::parseTrackInfo Nov 30 12:01:17 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:17 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 8 Nov 30 12:01:17 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":342,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Loi to tinh cua bien {Luong Hai}","artist":"Ngoc Tan","album":"Khoanh khac {Hacova}","uri":"http://192.168.1.223:8200/MediaItems/12000.flac","trackType":"flac"} Nov 30 12:01:17 vol.raspi volumio[957]: verbose: CURRENT POSITION 8 Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService play Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus stop Nov 30 12:01:17 vol.raspi volumio[957]: info: ------------------------------ 46ms Nov 30 12:01:17 vol.raspi volumio[957]: info: sendMpdCommand playlistinfo took 3 milliseconds Nov 30 12:01:17 vol.raspi volumio[957]: verbose: ControllerMpd::parseTrackInfo Nov 30 12:01:17 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:17 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 8 Nov 30 12:01:17 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"play","position":0,"seek":869,"duration":342,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"612 Kbps","isStreaming":false,"title":"Loi to tinh cua bien {Luong Hai}","artist":"Ngoc Tan","album":"Khoanh khac {Hacova}","uri":"http://192.168.1.223:8200/MediaItems/12000.flac","trackType":"flac"} Nov 30 12:01:17 vol.raspi volumio[957]: verbose: CURRENT POSITION 8 Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService play Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus play Nov 30 12:01:17 vol.raspi volumio[957]: info: Received an update from plugin. extracting info from payload Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:17 vol.raspi volumio[957]: info: ------------------------------ 43ms Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:17 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:17 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:17 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:17 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:17 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreCommandRouter::volumioNext Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::next Nov 30 12:01:18 vol.raspi volumio[957]: info: ControllerMpd::next Nov 30 12:01:18 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand next Nov 30 12:01:18 vol.raspi volumio[957]: info: Nov 30 12:01:18 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:18 vol.raspi volumio[957]: info: sendMpdCommand next took 5 milliseconds Nov 30 12:01:18 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:18 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:18 vol.raspi volumio[957]: info: sendMpdCommand status took 1 milliseconds Nov 30 12:01:18 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:18 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:18 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 8 Nov 30 12:01:18 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Nov 30 12:01:18 vol.raspi volumio[957]: verbose: CURRENT POSITION 8 Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService stop Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus play Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::play index undefined Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:18 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 9 Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:18 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 9 Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::startPlaybackTimer Nov 30 12:01:18 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 9 Nov 30 12:01:18 vol.raspi volumio[957]: info: [1732942878163] ControllerUPNPBrowser::clearAddPlayTrack Nov 30 12:01:18 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand stop Nov 30 12:01:18 vol.raspi volumio[957]: info: ------------------------------ 6ms Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:18 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 9 Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:18 vol.raspi volumio[957]: info: sendMpdCommand stop took 3 milliseconds Nov 30 12:01:18 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand clear Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:18 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:18 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:18 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:18 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:18 vol.raspi volumio[957]: info: Nov 30 12:01:18 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:01:18 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:01:18 vol.raspi volumio[957]: info: sendMpdCommand clear took 15 milliseconds Nov 30 12:01:18 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.223:8200/MediaItems/12001.flac" Nov 30 12:01:18 vol.raspi volumio[957]: error: updateQueue error: null Nov 30 12:01:18 vol.raspi volumio[957]: info: ------------------------------ 1ms Nov 30 12:01:18 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.223:8200/MediaItems/12001.flac" Nov 30 12:01:18 vol.raspi volumio[957]: info: Nov 30 12:01:18 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:01:18 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:01:18 vol.raspi volumio[957]: info: sendMpdCommand add "http://192.168.1.223:8200/MediaItems/12001.flac" took 0 milliseconds Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 30 12:01:18 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand play Nov 30 12:01:18 vol.raspi volumio[957]: info: ------------------------------ 2ms Nov 30 12:01:18 vol.raspi volumio[957]: info: sendMpdCommand play took 1 milliseconds Nov 30 12:01:18 vol.raspi volumio[957]: info: Nov 30 12:01:18 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:18 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:18 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:18 vol.raspi kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Nov 30 12:01:18 vol.raspi volumio[957]: info: Nov 30 12:01:18 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:01:18 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:01:18 vol.raspi volumio[957]: info: Nov 30 12:01:18 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:18 vol.raspi volumio[957]: info: sendMpdCommand status took 16 milliseconds Nov 30 12:01:18 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:18 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:18 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:18 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 12:01:18 vol.raspi volumio[957]: info: ------------------------------ 2ms Nov 30 12:01:18 vol.raspi volumio[957]: info: sendMpdCommand status took 2 milliseconds Nov 30 12:01:18 vol.raspi volumio[957]: info: sendMpdCommand playlistinfo took 2 milliseconds Nov 30 12:01:18 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:18 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 12:01:18 vol.raspi volumio[957]: verbose: ControllerMpd::parseTrackInfo Nov 30 12:01:18 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:18 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 9 Nov 30 12:01:18 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":239,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Tro ve {Hoang Phuc Thang}","artist":"Ngoc Tan","album":"Khoanh khac {Hacova}","uri":"http://192.168.1.223:8200/MediaItems/12001.flac","trackType":"flac"} Nov 30 12:01:18 vol.raspi volumio[957]: verbose: CURRENT POSITION 9 Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService play Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus stop Nov 30 12:01:18 vol.raspi volumio[957]: info: ------------------------------ 21ms Nov 30 12:01:18 vol.raspi volumio[957]: info: sendMpdCommand playlistinfo took 1 milliseconds Nov 30 12:01:18 vol.raspi volumio[957]: verbose: ControllerMpd::parseTrackInfo Nov 30 12:01:18 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:18 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 9 Nov 30 12:01:18 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"play","position":0,"seek":869,"duration":239,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"433 Kbps","isStreaming":false,"title":"Tro ve {Hoang Phuc Thang}","artist":"Ngoc Tan","album":"Khoanh khac {Hacova}","uri":"http://192.168.1.223:8200/MediaItems/12001.flac","trackType":"flac"} Nov 30 12:01:18 vol.raspi volumio[957]: verbose: CURRENT POSITION 9 Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService play Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus play Nov 30 12:01:18 vol.raspi volumio[957]: info: Received an update from plugin. extracting info from payload Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:18 vol.raspi volumio[957]: info: ------------------------------ 10ms Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:18 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:18 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:18 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:18 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreCommandRouter::volumioNext Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::next Nov 30 12:01:18 vol.raspi volumio[957]: info: ControllerMpd::next Nov 30 12:01:18 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand next Nov 30 12:01:18 vol.raspi volumio[957]: info: Nov 30 12:01:18 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:18 vol.raspi volumio[957]: info: sendMpdCommand next took 5 milliseconds Nov 30 12:01:18 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:18 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:18 vol.raspi volumio[957]: info: sendMpdCommand status took 1 milliseconds Nov 30 12:01:18 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:18 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:18 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 9 Nov 30 12:01:18 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Nov 30 12:01:18 vol.raspi volumio[957]: verbose: CURRENT POSITION 9 Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService stop Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus play Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::play index undefined Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:18 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 10 Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:18 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 10 Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::startPlaybackTimer Nov 30 12:01:18 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 10 Nov 30 12:01:18 vol.raspi volumio[957]: info: [1732942878554] ControllerUPNPBrowser::clearAddPlayTrack Nov 30 12:01:18 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand stop Nov 30 12:01:18 vol.raspi volumio[957]: info: ------------------------------ 6ms Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:18 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 10 Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:18 vol.raspi volumio[957]: info: sendMpdCommand stop took 3 milliseconds Nov 30 12:01:18 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand clear Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:18 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:18 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:18 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:18 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:18 vol.raspi volumio[957]: info: Nov 30 12:01:18 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:01:18 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:01:18 vol.raspi volumio[957]: info: sendMpdCommand clear took 10 milliseconds Nov 30 12:01:18 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.223:8200/MediaItems/12002.flac" Nov 30 12:01:18 vol.raspi volumio[957]: error: updateQueue error: null Nov 30 12:01:18 vol.raspi volumio[957]: info: ------------------------------ 1ms Nov 30 12:01:18 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.223:8200/MediaItems/12002.flac" Nov 30 12:01:18 vol.raspi volumio[957]: info: Nov 30 12:01:18 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:01:18 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:01:18 vol.raspi volumio[957]: info: sendMpdCommand add "http://192.168.1.223:8200/MediaItems/12002.flac" took 1 milliseconds Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 30 12:01:18 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand play Nov 30 12:01:18 vol.raspi volumio[957]: info: ------------------------------ 1ms Nov 30 12:01:18 vol.raspi volumio[957]: info: sendMpdCommand play took 1 milliseconds Nov 30 12:01:18 vol.raspi volumio[957]: info: Nov 30 12:01:18 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:18 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:18 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:18 vol.raspi kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Nov 30 12:01:18 vol.raspi volumio[957]: info: sendMpdCommand status took 15 milliseconds Nov 30 12:01:18 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:18 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 12:01:18 vol.raspi volumio[957]: info: Nov 30 12:01:18 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:01:18 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:01:18 vol.raspi volumio[957]: info: Nov 30 12:01:18 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:18 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:18 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:18 vol.raspi volumio[957]: info: sendMpdCommand playlistinfo took 2 milliseconds Nov 30 12:01:18 vol.raspi volumio[957]: verbose: ControllerMpd::parseTrackInfo Nov 30 12:01:18 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:18 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 10 Nov 30 12:01:18 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":315,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Ha Noi ngay tro ve {Phu Quang}","artist":"Ngoc Tan","album":"Khoanh khac {Hacova}","uri":"http://192.168.1.223:8200/MediaItems/12002.flac","trackType":"flac"} Nov 30 12:01:18 vol.raspi volumio[957]: verbose: CURRENT POSITION 10 Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService play Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus stop Nov 30 12:01:18 vol.raspi volumio[957]: info: ------------------------------ 19ms Nov 30 12:01:18 vol.raspi volumio[957]: info: ------------------------------ 3ms Nov 30 12:01:18 vol.raspi volumio[957]: info: sendMpdCommand status took 2 milliseconds Nov 30 12:01:18 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:18 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 12:01:18 vol.raspi volumio[957]: info: sendMpdCommand playlistinfo took 0 milliseconds Nov 30 12:01:18 vol.raspi volumio[957]: verbose: ControllerMpd::parseTrackInfo Nov 30 12:01:18 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:18 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 10 Nov 30 12:01:18 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"play","position":0,"seek":869,"duration":315,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"390 Kbps","isStreaming":false,"title":"Ha Noi ngay tro ve {Phu Quang}","artist":"Ngoc Tan","album":"Khoanh khac {Hacova}","uri":"http://192.168.1.223:8200/MediaItems/12002.flac","trackType":"flac"} Nov 30 12:01:18 vol.raspi volumio[957]: verbose: CURRENT POSITION 10 Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService play Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus play Nov 30 12:01:18 vol.raspi volumio[957]: info: Received an update from plugin. extracting info from payload Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:18 vol.raspi volumio[957]: info: ------------------------------ 11ms Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:18 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:18 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:18 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:18 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:18 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:19 vol.raspi volumio[957]: info: CoreCommandRouter::volumioNext Nov 30 12:01:19 vol.raspi volumio[957]: info: CoreStateMachine::next Nov 30 12:01:19 vol.raspi volumio[957]: info: ControllerMpd::next Nov 30 12:01:19 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand next Nov 30 12:01:19 vol.raspi volumio[957]: info: Nov 30 12:01:19 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:19 vol.raspi volumio[957]: info: sendMpdCommand next took 6 milliseconds Nov 30 12:01:19 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:19 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:19 vol.raspi volumio[957]: info: sendMpdCommand status took 1 milliseconds Nov 30 12:01:19 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:19 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:19 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:19 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:19 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:19 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:19 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 10 Nov 30 12:01:19 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Nov 30 12:01:19 vol.raspi volumio[957]: verbose: CURRENT POSITION 10 Nov 30 12:01:19 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService stop Nov 30 12:01:19 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus play Nov 30 12:01:19 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:19 vol.raspi volumio[957]: info: CoreStateMachine::stPlaybackTimer Nov 30 12:01:19 vol.raspi volumio[957]: info: ------------------------------ 9ms Nov 30 12:01:19 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:19 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:19 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:19 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:19 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:19 vol.raspi volumio[957]: info: CoreCommandRouter::volumioNext Nov 30 12:01:19 vol.raspi volumio[957]: info: CoreStateMachine::next Nov 30 12:01:19 vol.raspi volumio[957]: info: ControllerMpd::next Nov 30 12:01:19 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand next Nov 30 12:01:24 vol.raspi volumio[957]: info: Preload queue cleared Nov 30 12:01:24 vol.raspi volumio[957]: info: CoreCommandRouter::volumioReplaceandPlayItems Nov 30 12:01:24 vol.raspi volumio[957]: info: CoreStateMachine::ClearQueue Nov 30 12:01:24 vol.raspi volumio[957]: info: CoreStateMachine::stop Nov 30 12:01:24 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 30 12:01:24 vol.raspi volumio[957]: info: CorePlayQueue::clearPlayQueue Nov 30 12:01:24 vol.raspi volumio[957]: info: CorePlayQueue::saveQueue Nov 30 12:01:24 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushQueue Nov 30 12:01:24 vol.raspi volumio[957]: info: CoreStateMachine::addQueueItems Nov 30 12:01:24 vol.raspi volumio[957]: info: CorePlayQueue::addQueueItems Nov 30 12:01:24 vol.raspi volumio[957]: info: Preload queue cleared Nov 30 12:01:24 vol.raspi volumio[957]: info: Adding Item to queue: upnp/folder/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$B Nov 30 12:01:24 vol.raspi volumio[957]: info: Using cached record of: upnp/folder/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$B Nov 30 12:01:24 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$0 Nov 30 12:01:24 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$0 Nov 30 12:01:24 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushQueue Nov 30 12:01:24 vol.raspi volumio[957]: info: CorePlayQueue::saveQueue Nov 30 12:01:24 vol.raspi volumio[957]: info: CoreStateMachine::updateTrackBlock Nov 30 12:01:24 vol.raspi volumio[957]: info: CorePlayQueue::getTrackBlock Nov 30 12:01:24 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPlay Nov 30 12:01:24 vol.raspi volumio[957]: info: CoreStateMachine::play index 1 Nov 30 12:01:24 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 30 12:01:24 vol.raspi volumio[957]: info: CoreStateMachine::addQueueItems Nov 30 12:01:24 vol.raspi volumio[957]: info: CorePlayQueue::addQueueItems Nov 30 12:01:24 vol.raspi volumio[957]: info: Preload queue cleared Nov 30 12:01:24 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$1 Nov 30 12:01:24 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$1 Nov 30 12:01:24 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$2 Nov 30 12:01:24 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$2 Nov 30 12:01:24 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$3 Nov 30 12:01:24 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$3 Nov 30 12:01:24 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$4 Nov 30 12:01:24 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$4 Nov 30 12:01:24 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$5 Nov 30 12:01:24 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$5 Nov 30 12:01:24 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$6 Nov 30 12:01:24 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$6 Nov 30 12:01:24 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$7 Nov 30 12:01:24 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$7 Nov 30 12:01:24 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$8 Nov 30 12:01:24 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$8 Nov 30 12:01:24 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$9 Nov 30 12:01:24 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$9 Nov 30 12:01:24 vol.raspi volumio[957]: info: Adding Item to queue: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$A Nov 30 12:01:24 vol.raspi volumio[957]: info: Using cached record of: upnp/http://192.168.1.223:8200/ctl/ContentDir@64$2$3$F$4$A Nov 30 12:01:24 vol.raspi volumio[957]: info: CoreStateMachine::stop Nov 30 12:01:24 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 30 12:01:24 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushQueue Nov 30 12:01:24 vol.raspi volumio[957]: info: CorePlayQueue::saveQueue Nov 30 12:01:24 vol.raspi volumio[957]: info: CoreStateMachine::play index undefined Nov 30 12:01:24 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 30 12:01:24 vol.raspi volumio[957]: info: CoreStateMachine::updateTrackBlock Nov 30 12:01:24 vol.raspi volumio[957]: info: CorePlayQueue::getTrackBlock Nov 30 12:01:24 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 1 Nov 30 12:01:24 vol.raspi volumio[957]: info: CoreStateMachine::startPlaybackTimer Nov 30 12:01:24 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 1 Nov 30 12:01:24 vol.raspi volumio[957]: info: [1732942884259] ControllerUPNPBrowser::clearAddPlayTrack Nov 30 12:01:24 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand stop Nov 30 12:01:24 vol.raspi volumio[957]: info: sendMpdCommand stop took 2 milliseconds Nov 30 12:01:24 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand clear Nov 30 12:01:24 vol.raspi volumio[957]: info: Nov 30 12:01:24 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:01:24 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:01:24 vol.raspi volumio[957]: info: sendMpdCommand clear took 1 milliseconds Nov 30 12:01:24 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.223:8200/MediaItems/11993.flac" Nov 30 12:01:24 vol.raspi volumio[957]: error: updateQueue error: null Nov 30 12:01:24 vol.raspi volumio[957]: info: ------------------------------ 1ms Nov 30 12:01:24 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.223:8200/MediaItems/11993.flac" Nov 30 12:01:24 vol.raspi volumio[957]: info: Nov 30 12:01:24 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:01:24 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:01:24 vol.raspi volumio[957]: info: sendMpdCommand add "http://192.168.1.223:8200/MediaItems/11993.flac" took 1 milliseconds Nov 30 12:01:24 vol.raspi volumio[957]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 30 12:01:24 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand play Nov 30 12:01:24 vol.raspi volumio[957]: info: ------------------------------ 1ms Nov 30 12:01:24 vol.raspi volumio[957]: info: sendMpdCommand play took 1 milliseconds Nov 30 12:01:24 vol.raspi volumio[957]: info: Nov 30 12:01:24 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:24 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:24 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:24 vol.raspi kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Nov 30 12:01:24 vol.raspi volumio[957]: info: sendMpdCommand status took 16 milliseconds Nov 30 12:01:24 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:24 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 12:01:24 vol.raspi volumio[957]: info: Nov 30 12:01:24 vol.raspi volumio[957]: ---------------------------- MPD announces system playlist update Nov 30 12:01:24 vol.raspi volumio[957]: info: Ignoring MPD Status Update Nov 30 12:01:24 vol.raspi volumio[957]: info: Nov 30 12:01:24 vol.raspi volumio[957]: ---------------------------- MPD announces state update: player Nov 30 12:01:24 vol.raspi volumio[957]: info: ControllerMpd::getState Nov 30 12:01:24 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand status Nov 30 12:01:24 vol.raspi volumio[957]: info: sendMpdCommand playlistinfo took 2 milliseconds Nov 30 12:01:24 vol.raspi volumio[957]: verbose: ControllerMpd::parseTrackInfo Nov 30 12:01:24 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:24 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:24 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 1 Nov 30 12:01:24 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":340,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Ha Noi va toi {Le Vinh}","artist":"Ngoc Tan","album":"Khoanh khac {Hacova}","uri":"http://192.168.1.223:8200/MediaItems/11993.flac","trackType":"flac"} Nov 30 12:01:24 vol.raspi volumio[957]: verbose: CURRENT POSITION 1 Nov 30 12:01:24 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService play Nov 30 12:01:24 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus stop Nov 30 12:01:24 vol.raspi volumio[957]: info: ------------------------------ 20ms Nov 30 12:01:24 vol.raspi volumio[957]: info: ------------------------------ 4ms Nov 30 12:01:24 vol.raspi volumio[957]: info: sendMpdCommand status took 3 milliseconds Nov 30 12:01:24 vol.raspi volumio[957]: verbose: ControllerMpd::parseState Nov 30 12:01:24 vol.raspi volumio[957]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 12:01:24 vol.raspi volumio[957]: info: sendMpdCommand playlistinfo took 0 milliseconds Nov 30 12:01:24 vol.raspi volumio[957]: verbose: ControllerMpd::parseTrackInfo Nov 30 12:01:24 vol.raspi volumio[957]: info: ControllerMpd::pushState Nov 30 12:01:24 vol.raspi volumio[957]: info: CoreCommandRouter::servicePushState Nov 30 12:01:24 vol.raspi volumio[957]: info: CorePlayQueue::getTrack 1 Nov 30 12:01:24 vol.raspi volumio[957]: verbose: STATE SERVICE {"status":"play","position":0,"seek":869,"duration":340,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"479 Kbps","isStreaming":false,"title":"Ha Noi va toi {Le Vinh}","artist":"Ngoc Tan","album":"Khoanh khac {Hacova}","uri":"http://192.168.1.223:8200/MediaItems/11993.flac","trackType":"flac"} Nov 30 12:01:24 vol.raspi volumio[957]: verbose: CURRENT POSITION 1 Nov 30 12:01:24 vol.raspi volumio[957]: info: CoreStateMachine::syncState stateService play Nov 30 12:01:24 vol.raspi volumio[957]: info: CoreStateMachine::syncState currentStatus play Nov 30 12:01:24 vol.raspi volumio[957]: info: Received an update from plugin. extracting info from payload Nov 30 12:01:24 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:24 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 12:01:24 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:24 vol.raspi volumio[957]: info: CoreStateMachine::pushState Nov 30 12:01:24 vol.raspi volumio[957]: info: CoreCommandRouter::volumioPushState Nov 30 12:01:24 vol.raspi volumio[957]: info: ------------------------------ 10ms Nov 30 12:01:24 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:24 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:24 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:24 vol.raspi volumio[957]: info: CoreCommandRouter::volumioGetQueue Nov 30 12:01:24 vol.raspi volumio[957]: info: CoreStateMachine::getQueue Nov 30 12:01:24 vol.raspi volumio[957]: info: CorePlayQueue::getQueue Nov 30 12:01:24 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:24 vol.raspi volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Nov 30 12:01:26 vol.raspi volumio[957]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 30 12:01:26 vol.raspi volumio[957]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 30 12:01:26 vol.raspi volumio[957]: TypeError: Cannot read property 'length' of undefined Nov 30 12:01:26 vol.raspi volumio[957]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Nov 30 12:01:26 vol.raspi volumio[957]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Nov 30 12:01:26 vol.raspi volumio[957]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Nov 30 12:01:26 vol.raspi volumio[957]: at Parser.emit (events.js:315:20) Nov 30 12:01:26 vol.raspi volumio[957]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Nov 30 12:01:26 vol.raspi volumio[957]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Nov 30 12:01:26 vol.raspi volumio[957]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Nov 30 12:01:26 vol.raspi volumio[957]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Nov 30 12:01:26 vol.raspi volumio[957]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Nov 30 12:01:26 vol.raspi volumio[957]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Nov 30 12:01:26 vol.raspi volumio[957]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Nov 30 12:01:26 vol.raspi volumio[957]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Nov 30 12:01:26 vol.raspi volumio[957]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Nov 30 12:01:26 vol.raspi volumio[957]: at IncomingMessage.emit (events.js:327:22) Nov 30 12:01:26 vol.raspi volumio[957]: at endReadableNT (internal/streams/readable.js:1327:12) Nov 30 12:01:26 vol.raspi volumio[957]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Nov 30 12:01:26 vol.raspi volumio[957]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 30 12:01:27 vol.raspi sudo[10036]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-30 12:00 Nov 30 12:01:27 vol.raspi sudo[10036]: 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="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 06:51:56 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="b9009e0280f50389e80a537357ff3961"