-- Logs begin at Tue 2024-10-01 23:04:32 CEST, end at Tue 2024-10-01 23:08:26 CEST. -- Oct 01 23:07:10 volumio volumio[978]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 01 23:07:10 volumio volumio[978]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 01 23:07:10 volumio volumio[978]: info: Discovery: Getting this device information Oct 01 23:07:10 volumio volumio[978]: info: CoreCommandRouter::volumioGetState Oct 01 23:07:10 volumio volumio[978]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 01 23:07:28 volumio volumio[1228]: ....................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................++++ Oct 01 23:07:28 volumio volumio[1228]: e is 65537 (0x010001) Oct 01 23:07:28 volumio volumio[1228]: writing RSA key Oct 01 23:07:40 volumio volumio[978]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 01 23:07:40 volumio volumio[978]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 01 23:07:40 volumio volumio[978]: info: Discovery: Getting this device information Oct 01 23:07:40 volumio volumio[978]: info: CoreCommandRouter::volumioGetState Oct 01 23:07:40 volumio volumio[978]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 01 23:07:42 volumio volumio[978]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 01 23:07:42 volumio volumio[978]: info: Preload queue cleared Oct 01 23:07:43 volumio volumio[978]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 01 23:07:43 volumio volumio[978]: info: Preload queue cleared Oct 01 23:07:43 volumio volumio[978]: info: Preloading song: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$0 Oct 01 23:07:43 volumio volumio[978]: info: Preloading song: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$1 Oct 01 23:07:43 volumio volumio[978]: info: Preloading song: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$2 Oct 01 23:07:43 volumio volumio[978]: info: Preloading song: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$3 Oct 01 23:07:43 volumio volumio[978]: info: Preloading song: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$4 Oct 01 23:07:43 volumio volumio[978]: info: Preloading song: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$5 Oct 01 23:07:43 volumio volumio[978]: info: Preloading song: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$6 Oct 01 23:07:43 volumio volumio[978]: info: Preloading song: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$7 Oct 01 23:07:43 volumio volumio[978]: info: Preloading song: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$8 Oct 01 23:07:43 volumio volumio[978]: info: Preloading song: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$9 Oct 01 23:07:43 volumio volumio[978]: info: Preloading song: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$A Oct 01 23:07:43 volumio volumio[978]: info: Preloading song: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$B Oct 01 23:07:43 volumio volumio[978]: info: Exploding uri upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$0 in service upnp_browser Oct 01 23:07:43 volumio volumio[978]: info: Exploding uri upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$1 in service upnp_browser Oct 01 23:07:43 volumio volumio[978]: info: Exploding uri upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$2 in service upnp_browser Oct 01 23:07:43 volumio volumio[978]: info: Exploding uri upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$3 in service upnp_browser Oct 01 23:07:43 volumio volumio[978]: info: Exploding uri upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$4 in service upnp_browser Oct 01 23:07:44 volumio volumio[978]: info: Exploding uri upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$5 in service upnp_browser Oct 01 23:07:44 volumio volumio[978]: info: Exploding uri upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$6 in service upnp_browser Oct 01 23:07:44 volumio volumio[978]: info: Exploding uri upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$7 in service upnp_browser Oct 01 23:07:44 volumio volumio[978]: info: Exploding uri upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$8 in service upnp_browser Oct 01 23:07:44 volumio volumio[978]: info: Exploding uri upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$9 in service upnp_browser Oct 01 23:07:44 volumio volumio[978]: info: Exploding uri upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$A in service upnp_browser Oct 01 23:07:44 volumio volumio[978]: info: Exploding uri upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$B in service upnp_browser Oct 01 23:07:52 volumio volumio[978]: info: Preload queue cleared Oct 01 23:07:52 volumio volumio[978]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 01 23:07:52 volumio volumio[978]: info: CoreStateMachine::ClearQueue Oct 01 23:07:52 volumio volumio[978]: info: CoreStateMachine::stop Oct 01 23:07:52 volumio volumio[978]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 01 23:07:52 volumio volumio[978]: info: CoreStateMachine::stPlaybackTimer Oct 01 23:07:52 volumio volumio[978]: info: CoreStateMachine::updateTrackBlock Oct 01 23:07:52 volumio volumio[978]: info: CorePlayQueue::getTrackBlock Oct 01 23:07:52 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:07:52 volumio volumio[978]: info: CorePlayQueue::getTrack 7 Oct 01 23:07:52 volumio volumio[978]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 01 23:07:52 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:07:52 volumio volumio[978]: info: CoreStateMachine::serviceStop Oct 01 23:07:52 volumio volumio[978]: info: CorePlayQueue::getTrack 7 Oct 01 23:07:52 volumio volumio[978]: info: CoreCommandRouter::serviceStop Oct 01 23:07:52 volumio volumio[978]: info: [1727816872865] ControllerUPNPBrowser::stop Oct 01 23:07:52 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand stop Oct 01 23:07:52 volumio volumio[978]: info: CorePlayQueue::clearPlayQueue Oct 01 23:07:52 volumio volumio[978]: info: CorePlayQueue::saveQueue Oct 01 23:07:52 volumio volumio[978]: info: CoreCommandRouter::volumioPushQueue Oct 01 23:07:52 volumio volumio[978]: info: CoreStateMachine::addQueueItems Oct 01 23:07:52 volumio volumio[978]: info: CorePlayQueue::addQueueItems Oct 01 23:07:52 volumio volumio[978]: info: Preload queue cleared Oct 01 23:07:52 volumio volumio[978]: info: Adding Item to queue: upnp/folder/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$C Oct 01 23:07:52 volumio volumio[978]: info: Exploding uri upnp/folder/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$C in service upnp_browser Oct 01 23:07:52 volumio volumio[978]: info: Adding Item to queue: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$0 Oct 01 23:07:52 volumio volumio[978]: info: Using cached record of: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$0 Oct 01 23:07:52 volumio volumio[978]: info: Adding Item to queue: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$1 Oct 01 23:07:52 volumio volumio[978]: info: Using cached record of: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$1 Oct 01 23:07:52 volumio volumio[978]: info: Adding Item to queue: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$2 Oct 01 23:07:52 volumio volumio[978]: info: Using cached record of: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$2 Oct 01 23:07:52 volumio volumio[978]: info: Adding Item to queue: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$3 Oct 01 23:07:52 volumio volumio[978]: info: Using cached record of: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$3 Oct 01 23:07:52 volumio volumio[978]: info: Adding Item to queue: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$4 Oct 01 23:07:52 volumio volumio[978]: info: Using cached record of: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$4 Oct 01 23:07:52 volumio volumio[978]: info: Adding Item to queue: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$5 Oct 01 23:07:52 volumio volumio[978]: info: Using cached record of: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$5 Oct 01 23:07:52 volumio volumio[978]: info: Adding Item to queue: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$6 Oct 01 23:07:52 volumio volumio[978]: info: Using cached record of: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$6 Oct 01 23:07:52 volumio volumio[978]: info: Adding Item to queue: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$7 Oct 01 23:07:52 volumio volumio[978]: info: Using cached record of: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$7 Oct 01 23:07:52 volumio volumio[978]: info: Adding Item to queue: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$8 Oct 01 23:07:52 volumio volumio[978]: info: Using cached record of: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$8 Oct 01 23:07:52 volumio volumio[978]: info: Adding Item to queue: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$9 Oct 01 23:07:52 volumio volumio[978]: info: Using cached record of: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$9 Oct 01 23:07:52 volumio volumio[978]: info: Adding Item to queue: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$A Oct 01 23:07:52 volumio volumio[978]: info: Using cached record of: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$A Oct 01 23:07:52 volumio volumio[978]: info: Adding Item to queue: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$B Oct 01 23:07:52 volumio volumio[978]: info: Using cached record of: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$B Oct 01 23:07:52 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:07:52 volumio volumio[978]: info: Oct 01 23:07:52 volumio volumio[978]: ---------------------------- MPD announces state update: player Oct 01 23:07:52 volumio volumio[978]: info: sendMpdCommand stop took 40 milliseconds Oct 01 23:07:52 volumio volumio[978]: info: ControllerMpd::getState Oct 01 23:07:52 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand status Oct 01 23:07:52 volumio volumio[978]: info: sendMpdCommand status took 2 milliseconds Oct 01 23:07:52 volumio volumio[978]: verbose: ControllerMpd::parseState Oct 01 23:07:52 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 01 23:07:52 volumio volumio[978]: info: Oct 01 23:07:52 volumio volumio[978]: ---------------------------- MPD announces state update: player Oct 01 23:07:52 volumio volumio[978]: info: ControllerMpd::getState Oct 01 23:07:52 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand status Oct 01 23:07:52 volumio volumio[978]: info: Oct 01 23:07:52 volumio volumio[978]: ---------------------------- MPD announces state update: player Oct 01 23:07:52 volumio volumio[978]: info: ControllerMpd::getState Oct 01 23:07:52 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand status Oct 01 23:07:52 volumio volumio[978]: info: Oct 01 23:07:52 volumio volumio[978]: ---------------------------- MPD announces state update: player Oct 01 23:07:52 volumio volumio[978]: info: ControllerMpd::getState Oct 01 23:07:52 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand status Oct 01 23:07:52 volumio volumio[978]: info: sendMpdCommand playlistinfo took 12 milliseconds Oct 01 23:07:52 volumio volumio[978]: info: sendMpdCommand status took 10 milliseconds Oct 01 23:07:52 volumio volumio[978]: info: sendMpdCommand status took 9 milliseconds Oct 01 23:07:52 volumio volumio[978]: info: sendMpdCommand status took 4 milliseconds Oct 01 23:07:52 volumio volumio[978]: verbose: ControllerMpd::parseTrackInfo Oct 01 23:07:52 volumio volumio[978]: verbose: ControllerMpd::parseState Oct 01 23:07:52 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 01 23:07:52 volumio volumio[978]: verbose: ControllerMpd::parseState Oct 01 23:07:52 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 01 23:07:52 volumio volumio[978]: verbose: ControllerMpd::parseState Oct 01 23:07:52 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 01 23:07:52 volumio volumio[978]: info: ControllerMpd::pushState Oct 01 23:07:52 volumio volumio[978]: info: CoreCommandRouter::servicePushState Oct 01 23:07:52 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:07:52 volumio volumio[978]: info: CorePlayQueue::getTrack 7 Oct 01 23:07:52 volumio volumio[978]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 01 23:07:52 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:07:52 volumio volumio[978]: info: CorePlayQueue::getTrack 7 Oct 01 23:07:52 volumio volumio[978]: 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":"How High the Moon ¿","artist":"The Oscar Peterson Trio","album":"At The Stratford Shakespearean Festival {rec. 8 Aout 1956}","uri":"http://192.168.0.41:8200/MediaItems/7709.flac","trackType":"flac"} Oct 01 23:07:52 volumio volumio[978]: verbose: CURRENT POSITION 7 Oct 01 23:07:52 volumio volumio[978]: info: CoreStateMachine::syncState stateService stop Oct 01 23:07:52 volumio volumio[978]: info: CoreStateMachine::syncState currentStatus stop Oct 01 23:07:52 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:07:52 volumio volumio[978]: info: CorePlayQueue::getTrack 7 Oct 01 23:07:52 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:07:52 volumio volumio[978]: info: No code Oct 01 23:07:52 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:07:52 volumio volumio[978]: info: CorePlayQueue::getTrack 7 Oct 01 23:07:52 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:07:52 volumio volumio[978]: info: ------------------------------ 63ms Oct 01 23:07:52 volumio volumio[978]: info: CoreCommandRouter::volumioPushQueue Oct 01 23:07:52 volumio volumio[978]: info: CorePlayQueue::saveQueue Oct 01 23:07:52 volumio volumio[978]: info: CoreStateMachine::updateTrackBlock Oct 01 23:07:52 volumio volumio[978]: info: CorePlayQueue::getTrackBlock Oct 01 23:07:52 volumio volumio[978]: info: CoreCommandRouter::volumioPlay Oct 01 23:07:52 volumio volumio[978]: info: CoreStateMachine::play index 10 Oct 01 23:07:52 volumio volumio[978]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 01 23:07:52 volumio volumio[978]: info: CoreStateMachine::stop Oct 01 23:07:52 volumio volumio[978]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 01 23:07:52 volumio volumio[978]: info: CoreStateMachine::play index undefined Oct 01 23:07:52 volumio volumio[978]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 01 23:07:52 volumio volumio[978]: info: CorePlayQueue::getTrack 10 Oct 01 23:07:52 volumio volumio[978]: info: CoreStateMachine::startPlaybackTimer Oct 01 23:07:52 volumio volumio[978]: info: CorePlayQueue::getTrack 10 Oct 01 23:07:52 volumio volumio[978]: info: [1727816872990] ControllerUPNPBrowser::clearAddPlayTrack Oct 01 23:07:52 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand stop Oct 01 23:07:52 volumio volumio[978]: info: sendMpdCommand playlistinfo took 68 milliseconds Oct 01 23:07:52 volumio volumio[978]: info: sendMpdCommand playlistinfo took 69 milliseconds Oct 01 23:07:52 volumio volumio[978]: info: sendMpdCommand playlistinfo took 68 milliseconds Oct 01 23:07:52 volumio volumio[978]: info: sendMpdCommand stop took 4 milliseconds Oct 01 23:07:52 volumio volumio[978]: verbose: ControllerMpd::parseTrackInfo Oct 01 23:07:52 volumio volumio[978]: verbose: ControllerMpd::parseTrackInfo Oct 01 23:07:52 volumio volumio[978]: verbose: ControllerMpd::parseTrackInfo Oct 01 23:07:52 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand clear Oct 01 23:07:52 volumio volumio[978]: info: ControllerMpd::pushState Oct 01 23:07:52 volumio volumio[978]: info: CoreCommandRouter::servicePushState Oct 01 23:07:52 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:07:52 volumio volumio[978]: info: CorePlayQueue::getTrack 10 Oct 01 23:07:52 volumio volumio[978]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 01 23:07:52 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:07:53 volumio volumio[978]: info: CorePlayQueue::getTrack 10 Oct 01 23:07:53 volumio volumio[978]: 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":"How High the Moon ¿","artist":"The Oscar Peterson Trio","album":"At The Stratford Shakespearean Festival {rec. 8 Aout 1956}","uri":"http://192.168.0.41:8200/MediaItems/7709.flac","trackType":"flac"} Oct 01 23:07:53 volumio volumio[978]: verbose: CURRENT POSITION 10 Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::syncState stateService stop Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::syncState currentStatus stop Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:07:53 volumio volumio[978]: info: CorePlayQueue::getTrack 10 Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:07:53 volumio volumio[978]: info: No code Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:07:53 volumio volumio[978]: info: CorePlayQueue::getTrack 10 Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:07:53 volumio volumio[978]: info: ControllerMpd::pushState Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::servicePushState Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:07:53 volumio volumio[978]: info: CorePlayQueue::getTrack 10 Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:07:53 volumio volumio[978]: info: CorePlayQueue::getTrack 10 Oct 01 23:07:53 volumio volumio[978]: 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":"How High the Moon ¿","artist":"The Oscar Peterson Trio","album":"At The Stratford Shakespearean Festival {rec. 8 Aout 1956}","uri":"http://192.168.0.41:8200/MediaItems/7709.flac","trackType":"flac"} Oct 01 23:07:53 volumio volumio[978]: verbose: CURRENT POSITION 10 Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::syncState stateService stop Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::syncState currentStatus stop Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:07:53 volumio volumio[978]: info: CorePlayQueue::getTrack 10 Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:07:53 volumio volumio[978]: info: No code Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:07:53 volumio volumio[978]: info: CorePlayQueue::getTrack 10 Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:07:53 volumio volumio[978]: info: ControllerMpd::pushState Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::servicePushState Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:07:53 volumio volumio[978]: info: CorePlayQueue::getTrack 10 Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:07:53 volumio volumio[978]: info: CorePlayQueue::getTrack 10 Oct 01 23:07:53 volumio volumio[978]: 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":"How High the Moon ¿","artist":"The Oscar Peterson Trio","album":"At The Stratford Shakespearean Festival {rec. 8 Aout 1956}","uri":"http://192.168.0.41:8200/MediaItems/7709.flac","trackType":"flac"} Oct 01 23:07:53 volumio volumio[978]: verbose: CURRENT POSITION 10 Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::syncState stateService stop Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::syncState currentStatus stop Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:07:53 volumio volumio[978]: info: CorePlayQueue::getTrack 10 Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:07:53 volumio volumio[978]: info: No code Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:07:53 volumio volumio[978]: info: CorePlayQueue::getTrack 10 Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:07:53 volumio volumio[978]: info: ------------------------------ 209ms Oct 01 23:07:53 volumio volumio[978]: info: ------------------------------ 208ms Oct 01 23:07:53 volumio volumio[978]: info: ------------------------------ 207ms Oct 01 23:07:53 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:07:53 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:07:53 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:07:53 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:07:53 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:07:53 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:07:53 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:07:53 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:07:53 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:07:53 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:07:53 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:07:53 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:07:53 volumio volumio[978]: info: Oct 01 23:07:53 volumio volumio[978]: ---------------------------- MPD announces system playlist update Oct 01 23:07:53 volumio volumio[978]: info: Ignoring MPD Status Update Oct 01 23:07:53 volumio volumio[978]: info: sendMpdCommand clear took 167 milliseconds Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.0.41:8200/MediaItems/9574.flac" Oct 01 23:07:53 volumio volumio[978]: info: Oct 01 23:07:53 volumio volumio[978]: ---------------------------- MPD announces system playlist update Oct 01 23:07:53 volumio volumio[978]: info: Ignoring MPD Status Update Oct 01 23:07:53 volumio volumio[978]: info: Oct 01 23:07:53 volumio volumio[978]: ---------------------------- MPD announces system playlist update Oct 01 23:07:53 volumio volumio[978]: info: Ignoring MPD Status Update Oct 01 23:07:53 volumio volumio[978]: info: Oct 01 23:07:53 volumio volumio[978]: ---------------------------- MPD announces system playlist update Oct 01 23:07:53 volumio volumio[978]: info: Ignoring MPD Status Update Oct 01 23:07:53 volumio volumio[978]: error: updateQueue error: null Oct 01 23:07:53 volumio volumio[978]: info: ------------------------------ 229ms Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.0.41:8200/MediaItems/9574.flac" Oct 01 23:07:53 volumio volumio[978]: error: updateQueue error: null Oct 01 23:07:53 volumio volumio[978]: error: updateQueue error: null Oct 01 23:07:53 volumio volumio[978]: error: updateQueue error: null Oct 01 23:07:53 volumio volumio[978]: info: Oct 01 23:07:53 volumio volumio[978]: ---------------------------- MPD announces system playlist update Oct 01 23:07:53 volumio volumio[978]: info: Ignoring MPD Status Update Oct 01 23:07:53 volumio volumio[978]: info: ------------------------------ 231ms Oct 01 23:07:53 volumio volumio[978]: info: ------------------------------ 229ms Oct 01 23:07:53 volumio volumio[978]: info: ------------------------------ 229ms Oct 01 23:07:53 volumio volumio[978]: info: sendMpdCommand add "http://192.168.0.41:8200/MediaItems/9574.flac" took 8 milliseconds Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand play Oct 01 23:07:53 volumio volumio[978]: info: Oct 01 23:07:53 volumio volumio[978]: ---------------------------- MPD announces system playlist update Oct 01 23:07:53 volumio volumio[978]: info: Ignoring MPD Status Update Oct 01 23:07:53 volumio volumio[978]: info: Oct 01 23:07:53 volumio volumio[978]: ---------------------------- MPD announces system playlist update Oct 01 23:07:53 volumio volumio[978]: info: Ignoring MPD Status Update Oct 01 23:07:53 volumio volumio[978]: info: Oct 01 23:07:53 volumio volumio[978]: ---------------------------- MPD announces system playlist update Oct 01 23:07:53 volumio volumio[978]: info: Ignoring MPD Status Update Oct 01 23:07:53 volumio volumio[978]: info: ------------------------------ 13ms Oct 01 23:07:53 volumio volumio[978]: info: sendMpdCommand play took 8 milliseconds Oct 01 23:07:53 volumio volumio[978]: info: ------------------------------ 8ms Oct 01 23:07:53 volumio volumio[978]: info: ------------------------------ 6ms Oct 01 23:07:53 volumio volumio[978]: info: ------------------------------ 4ms Oct 01 23:07:53 volumio volumio[978]: info: Oct 01 23:07:53 volumio volumio[978]: ---------------------------- MPD announces state update: player Oct 01 23:07:53 volumio volumio[978]: info: ControllerMpd::getState Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand status Oct 01 23:07:53 volumio volumio[978]: info: Oct 01 23:07:53 volumio volumio[978]: ---------------------------- MPD announces state update: player Oct 01 23:07:53 volumio volumio[978]: info: ControllerMpd::getState Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand status Oct 01 23:07:53 volumio volumio[978]: info: Oct 01 23:07:53 volumio volumio[978]: ---------------------------- MPD announces state update: player Oct 01 23:07:53 volumio volumio[978]: info: ControllerMpd::getState Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand status Oct 01 23:07:53 volumio volumio[978]: info: Oct 01 23:07:53 volumio volumio[978]: ---------------------------- MPD announces state update: player Oct 01 23:07:53 volumio volumio[978]: info: ControllerMpd::getState Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand status Oct 01 23:07:53 volumio volumio[978]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Oct 01 23:07:53 volumio volumio[978]: info: FusionDsp - ---- read samplerate from file: 44100 Oct 01 23:07:53 volumio volumio[978]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 01 23:07:53 volumio volumio[978]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Oct 01 23:07:53 volumio volumio[978]: info: FusionDsp - ---- read samplerate from file: 44100 Oct 01 23:07:53 volumio volumio[978]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 01 23:07:53 volumio volumio[978]: info: Oct 01 23:07:53 volumio volumio[978]: ---------------------------- MPD announces state update: player Oct 01 23:07:53 volumio volumio[978]: info: sendMpdCommand status took 24 milliseconds Oct 01 23:07:53 volumio volumio[978]: info: ControllerMpd::getState Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand status Oct 01 23:07:53 volumio volumio[978]: info: sendMpdCommand status took 24 milliseconds Oct 01 23:07:53 volumio volumio[978]: info: sendMpdCommand status took 22 milliseconds Oct 01 23:07:53 volumio volumio[978]: info: sendMpdCommand status took 22 milliseconds Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::parseState Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::parseState Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::parseState Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::parseState Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 01 23:07:53 volumio volumio[978]: info: Oct 01 23:07:53 volumio volumio[978]: ---------------------------- MPD announces state update: player Oct 01 23:07:53 volumio volumio[978]: info: ControllerMpd::getState Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand status Oct 01 23:07:53 volumio volumio[978]: info: Oct 01 23:07:53 volumio volumio[978]: ---------------------------- MPD announces state update: player Oct 01 23:07:53 volumio volumio[978]: info: ControllerMpd::getState Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand status Oct 01 23:07:53 volumio volumio[978]: info: Oct 01 23:07:53 volumio volumio[978]: ---------------------------- MPD announces state update: player Oct 01 23:07:53 volumio volumio[978]: info: ControllerMpd::getState Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand status Oct 01 23:07:53 volumio volumio[978]: info: sendMpdCommand status took 17 milliseconds Oct 01 23:07:53 volumio volumio[978]: info: sendMpdCommand playlistinfo took 15 milliseconds Oct 01 23:07:53 volumio volumio[978]: info: sendMpdCommand playlistinfo took 14 milliseconds Oct 01 23:07:53 volumio volumio[978]: info: sendMpdCommand playlistinfo took 14 milliseconds Oct 01 23:07:53 volumio volumio[978]: info: sendMpdCommand playlistinfo took 14 milliseconds Oct 01 23:07:53 volumio volumio[978]: info: sendMpdCommand status took 7 milliseconds Oct 01 23:07:53 volumio volumio[978]: info: sendMpdCommand status took 6 milliseconds Oct 01 23:07:53 volumio volumio[978]: info: sendMpdCommand status took 4 milliseconds Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::parseState Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::parseTrackInfo Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::parseTrackInfo Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::parseTrackInfo Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::parseTrackInfo Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::parseState Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::parseState Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::parseState Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 01 23:07:53 volumio volumio[978]: info: ControllerMpd::pushState Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::servicePushState Oct 01 23:07:53 volumio volumio[978]: info: CorePlayQueue::getTrack 10 Oct 01 23:07:53 volumio volumio[978]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":329,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"9574.flac","artist":null,"album":null,"uri":"http://192.168.0.41:8200/MediaItems/9574.flac","trackType":"flac"} Oct 01 23:07:53 volumio volumio[978]: verbose: CURRENT POSITION 10 Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::syncState stateService play Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::syncState currentStatus stop Oct 01 23:07:53 volumio volumio[978]: info: ControllerMpd::pushState Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::servicePushState Oct 01 23:07:53 volumio volumio[978]: info: CorePlayQueue::getTrack 10 Oct 01 23:07:53 volumio volumio[978]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":329,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"9574.flac","artist":null,"album":null,"uri":"http://192.168.0.41:8200/MediaItems/9574.flac","trackType":"flac"} Oct 01 23:07:53 volumio volumio[978]: verbose: CURRENT POSITION 10 Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::syncState stateService play Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::syncState currentStatus play Oct 01 23:07:53 volumio volumio[978]: info: Received an update from plugin. extracting info from payload Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:07:53 volumio volumio[978]: info: ControllerMpd::pushState Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::servicePushState Oct 01 23:07:53 volumio volumio[978]: info: CorePlayQueue::getTrack 10 Oct 01 23:07:53 volumio volumio[978]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":329,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"9574.flac","artist":null,"album":null,"uri":"http://192.168.0.41:8200/MediaItems/9574.flac","trackType":"flac"} Oct 01 23:07:53 volumio volumio[978]: verbose: CURRENT POSITION 10 Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::syncState stateService play Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::syncState currentStatus play Oct 01 23:07:53 volumio volumio[978]: info: Received an update from plugin. extracting info from payload Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:07:53 volumio volumio[978]: info: ControllerMpd::pushState Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::servicePushState Oct 01 23:07:53 volumio volumio[978]: info: CorePlayQueue::getTrack 10 Oct 01 23:07:53 volumio volumio[978]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":329,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"9574.flac","artist":null,"album":null,"uri":"http://192.168.0.41:8200/MediaItems/9574.flac","trackType":"flac"} Oct 01 23:07:53 volumio volumio[978]: verbose: CURRENT POSITION 10 Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::syncState stateService play Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::syncState currentStatus play Oct 01 23:07:53 volumio volumio[978]: info: Received an update from plugin. extracting info from payload Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:07:53 volumio volumio[978]: info: ------------------------------ 87ms Oct 01 23:07:53 volumio volumio[978]: info: ------------------------------ 149ms Oct 01 23:07:53 volumio volumio[978]: info: ------------------------------ 148ms Oct 01 23:07:53 volumio volumio[978]: info: ------------------------------ 148ms Oct 01 23:07:53 volumio volumio[978]: info: Oct 01 23:07:53 volumio volumio[978]: ---------------------------- MPD announces system playlist update Oct 01 23:07:53 volumio volumio[978]: info: Ignoring MPD Status Update Oct 01 23:07:53 volumio volumio[978]: info: Oct 01 23:07:53 volumio volumio[978]: ---------------------------- MPD announces state update: player Oct 01 23:07:53 volumio volumio[978]: info: sendMpdCommand playlistinfo took 111 milliseconds Oct 01 23:07:53 volumio volumio[978]: info: sendMpdCommand playlistinfo took 111 milliseconds Oct 01 23:07:53 volumio volumio[978]: info: sendMpdCommand playlistinfo took 111 milliseconds Oct 01 23:07:53 volumio volumio[978]: info: sendMpdCommand playlistinfo took 110 milliseconds Oct 01 23:07:53 volumio volumio[978]: info: ControllerMpd::getState Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand status Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::parseTrackInfo Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::parseTrackInfo Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::parseTrackInfo Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::parseTrackInfo Oct 01 23:07:53 volumio volumio[978]: info: ControllerMpd::pushState Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::servicePushState Oct 01 23:07:53 volumio volumio[978]: info: CorePlayQueue::getTrack 10 Oct 01 23:07:53 volumio volumio[978]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":329,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"9574.flac","artist":null,"album":null,"uri":"http://192.168.0.41:8200/MediaItems/9574.flac","trackType":"flac"} Oct 01 23:07:53 volumio volumio[978]: verbose: CURRENT POSITION 10 Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::syncState stateService play Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::syncState currentStatus play Oct 01 23:07:53 volumio volumio[978]: info: Received an update from plugin. extracting info from payload Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:07:53 volumio volumio[978]: info: ControllerMpd::pushState Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::servicePushState Oct 01 23:07:53 volumio volumio[978]: info: CorePlayQueue::getTrack 10 Oct 01 23:07:53 volumio volumio[978]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":329,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"9574.flac","artist":null,"album":null,"uri":"http://192.168.0.41:8200/MediaItems/9574.flac","trackType":"flac"} Oct 01 23:07:53 volumio volumio[978]: verbose: CURRENT POSITION 10 Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::syncState stateService play Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::syncState currentStatus play Oct 01 23:07:53 volumio volumio[978]: info: Received an update from plugin. extracting info from payload Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:07:53 volumio volumio[978]: info: ControllerMpd::pushState Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::servicePushState Oct 01 23:07:53 volumio volumio[978]: info: CorePlayQueue::getTrack 10 Oct 01 23:07:53 volumio volumio[978]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":329,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"9574.flac","artist":null,"album":null,"uri":"http://192.168.0.41:8200/MediaItems/9574.flac","trackType":"flac"} Oct 01 23:07:53 volumio volumio[978]: verbose: CURRENT POSITION 10 Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::syncState stateService play Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::syncState currentStatus play Oct 01 23:07:53 volumio volumio[978]: info: Received an update from plugin. extracting info from payload Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:07:53 volumio volumio[978]: info: ControllerMpd::pushState Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::servicePushState Oct 01 23:07:53 volumio volumio[978]: info: CorePlayQueue::getTrack 10 Oct 01 23:07:53 volumio volumio[978]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":329,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"9574.flac","artist":null,"album":null,"uri":"http://192.168.0.41:8200/MediaItems/9574.flac","trackType":"flac"} Oct 01 23:07:53 volumio volumio[978]: verbose: CURRENT POSITION 10 Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::syncState stateService play Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::syncState currentStatus play Oct 01 23:07:53 volumio volumio[978]: info: Received an update from plugin. extracting info from payload Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:07:53 volumio volumio[978]: info: ------------------------------ 269ms Oct 01 23:07:53 volumio volumio[978]: info: ------------------------------ 257ms Oct 01 23:07:53 volumio volumio[978]: info: ------------------------------ 257ms Oct 01 23:07:53 volumio volumio[978]: info: ------------------------------ 257ms Oct 01 23:07:53 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:07:53 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:07:53 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:07:53 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:07:53 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:07:53 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:07:53 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:07:53 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:07:53 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:07:53 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:07:53 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:07:53 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:07:53 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:07:53 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:07:53 volumio volumio[978]: info: Oct 01 23:07:53 volumio volumio[978]: ---------------------------- MPD announces system playlist update Oct 01 23:07:53 volumio volumio[978]: info: Ignoring MPD Status Update Oct 01 23:07:53 volumio volumio[978]: info: Oct 01 23:07:53 volumio volumio[978]: ---------------------------- MPD announces state update: player Oct 01 23:07:53 volumio volumio[978]: info: ControllerMpd::getState Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand status Oct 01 23:07:53 volumio volumio[978]: info: Oct 01 23:07:53 volumio volumio[978]: ---------------------------- MPD announces system playlist update Oct 01 23:07:53 volumio volumio[978]: info: Ignoring MPD Status Update Oct 01 23:07:53 volumio volumio[978]: info: Oct 01 23:07:53 volumio volumio[978]: ---------------------------- MPD announces state update: player Oct 01 23:07:53 volumio volumio[978]: info: ControllerMpd::getState Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand status Oct 01 23:07:53 volumio volumio[978]: info: Oct 01 23:07:53 volumio volumio[978]: ---------------------------- MPD announces system playlist update Oct 01 23:07:53 volumio volumio[978]: info: Ignoring MPD Status Update Oct 01 23:07:53 volumio volumio[978]: info: Oct 01 23:07:53 volumio volumio[978]: ---------------------------- MPD announces state update: player Oct 01 23:07:53 volumio volumio[978]: info: ControllerMpd::getState Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand status Oct 01 23:07:53 volumio volumio[978]: info: ------------------------------ 194ms Oct 01 23:07:53 volumio volumio[978]: info: sendMpdCommand status took 189 milliseconds Oct 01 23:07:53 volumio volumio[978]: info: ------------------------------ 14ms Oct 01 23:07:53 volumio volumio[978]: info: sendMpdCommand status took 11 milliseconds Oct 01 23:07:53 volumio volumio[978]: info: ------------------------------ 11ms Oct 01 23:07:53 volumio volumio[978]: info: sendMpdCommand status took 9 milliseconds Oct 01 23:07:53 volumio volumio[978]: info: ------------------------------ 8ms Oct 01 23:07:53 volumio volumio[978]: info: sendMpdCommand status took 7 milliseconds Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::parseState Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::parseState Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::parseState Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::parseState Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 01 23:07:53 volumio volumio[978]: info: FusionDsp - crossfeed bauer Oct 01 23:07:53 volumio volumio[978]: info: FusionDsp - highcross: Oct 01 23:07:53 volumio volumio[978]: type: Biquad Oct 01 23:07:53 volumio volumio[978]: parameters: Oct 01 23:07:53 volumio volumio[978]: type: Highshelf Oct 01 23:07:53 volumio volumio[978]: freq: 700 Oct 01 23:07:53 volumio volumio[978]: slope: 6 Oct 01 23:07:53 volumio volumio[978]: gain: 4.5 Oct 01 23:07:53 volumio volumio[978]: lpcross: Oct 01 23:07:53 volumio volumio[978]: type: Biquad Oct 01 23:07:53 volumio volumio[978]: parameters: Oct 01 23:07:53 volumio volumio[978]: type: LowpassFO Oct 01 23:07:53 volumio volumio[978]: freq: 700 Oct 01 23:07:53 volumio volumio[978]: delay: Oct 01 23:07:53 volumio volumio[978]: type: Delay Oct 01 23:07:53 volumio volumio[978]: parameters: Oct 01 23:07:53 volumio volumio[978]: delay: 0.32 Oct 01 23:07:53 volumio volumio[978]: unit: ms Oct 01 23:07:53 volumio volumio[978]: subsample: false Oct 01 23:07:53 volumio volumio[978]: Oct 01 23:07:53 volumio volumio[978]: eq1: Oct 01 23:07:53 volumio volumio[978]: type: Biquad Oct 01 23:07:53 volumio volumio[978]: parameters: Oct 01 23:07:53 volumio volumio[978]: type: Lowshelf Oct 01 23:07:53 volumio volumio[978]: freq: 105 Oct 01 23:07:53 volumio volumio[978]: q: 0.70 Oct 01 23:07:53 volumio volumio[978]: gain: 3.4 Oct 01 23:07:53 volumio volumio[978]: eq2: Oct 01 23:07:53 volumio volumio[978]: type: Biquad Oct 01 23:07:53 volumio volumio[978]: parameters: Oct 01 23:07:53 volumio volumio[978]: type: Peaking Oct 01 23:07:53 volumio volumio[978]: freq: 236 Oct 01 23:07:53 volumio volumio[978]: q: 0.53 Oct 01 23:07:53 volumio volumio[978]: gain: -2.4 Oct 01 23:07:53 volumio volumio[978]: eq3: Oct 01 23:07:53 volumio volumio[978]: type: Biquad Oct 01 23:07:53 volumio volumio[978]: parameters: Oct 01 23:07:53 volumio volumio[978]: type: Peaking Oct 01 23:07:53 volumio volumio[978]: freq: 1659 Oct 01 23:07:53 volumio volumio[978]: q: 1.76 Oct 01 23:07:53 volumio volumio[978]: gain: 6.9 Oct 01 23:07:53 volumio volumio[978]: eq4: Oct 01 23:07:53 volumio volumio[978]: type: Biquad Oct 01 23:07:53 volumio volumio[978]: parameters: Oct 01 23:07:53 volumio volumio[978]: type: Peaking Oct 01 23:07:53 volumio volumio[978]: freq: 592 Oct 01 23:07:53 volumio volumio[978]: q: 1.17 Oct 01 23:07:53 volumio volumio[978]: gain: -1.5 Oct 01 23:07:53 volumio volumio[978]: eq5: Oct 01 23:07:53 volumio volumio[978]: type: Biquad Oct 01 23:07:53 volumio volumio[978]: parameters: Oct 01 23:07:53 volumio volumio[978]: type: Peaking Oct 01 23:07:53 volumio volumio[978]: freq: 5982 Oct 01 23:07:53 volumio volumio[978]: q: 3.16 Oct 01 23:07:53 volumio volumio[978]: gain: -4.0 Oct 01 23:07:53 volumio volumio[978]: eq6: Oct 01 23:07:53 volumio volumio[978]: type: Biquad Oct 01 23:07:53 volumio volumio[978]: parameters: Oct 01 23:07:53 volumio volumio[978]: type: Highshelf Oct 01 23:07:53 volumio volumio[978]: freq: 10000 Oct 01 23:07:53 volumio volumio[978]: q: 0.70 Oct 01 23:07:53 volumio volumio[978]: gain: -1.5 Oct 01 23:07:53 volumio volumio[978]: eq7: Oct 01 23:07:53 volumio volumio[978]: type: Biquad Oct 01 23:07:53 volumio volumio[978]: parameters: Oct 01 23:07:53 volumio volumio[978]: type: Peaking Oct 01 23:07:53 volumio volumio[978]: freq: 3426 Oct 01 23:07:53 volumio volumio[978]: q: 5.91 Oct 01 23:07:53 volumio volumio[978]: gain: 2.9 Oct 01 23:07:53 volumio volumio[978]: eq8: Oct 01 23:07:53 volumio volumio[978]: type: Biquad Oct 01 23:07:53 volumio volumio[978]: parameters: Oct 01 23:07:53 volumio volumio[978]: type: Peaking Oct 01 23:07:53 volumio volumio[978]: freq: 2858 Oct 01 23:07:53 volumio volumio[978]: q: 5.45 Oct 01 23:07:53 volumio volumio[978]: gain: -1.9 Oct 01 23:07:53 volumio volumio[978]: eq9: Oct 01 23:07:53 volumio volumio[978]: type: Biquad Oct 01 23:07:53 volumio volumio[978]: parameters: Oct 01 23:07:53 volumio volumio[978]: type: Peaking Oct 01 23:07:53 volumio volumio[978]: freq: 4145 Oct 01 23:07:53 volumio volumio[978]: q: 6.00 Oct 01 23:07:53 volumio volumio[978]: gain: -1.5 Oct 01 23:07:53 volumio volumio[978]: eq10: Oct 01 23:07:53 volumio volumio[978]: type: Biquad Oct 01 23:07:53 volumio volumio[978]: parameters: Oct 01 23:07:53 volumio volumio[978]: type: Peaking Oct 01 23:07:53 volumio volumio[978]: freq: 54 Oct 01 23:07:53 volumio volumio[978]: q: 1.78 Oct 01 23:07:53 volumio volumio[978]: gain: -0.2 Oct 01 23:07:53 volumio volumio[978]: info: FusionDsp - crossfeed bauer Oct 01 23:07:53 volumio volumio[978]: info: FusionDsp - highcross: Oct 01 23:07:53 volumio volumio[978]: type: Biquad Oct 01 23:07:53 volumio volumio[978]: parameters: Oct 01 23:07:53 volumio volumio[978]: type: Highshelf Oct 01 23:07:53 volumio volumio[978]: freq: 700 Oct 01 23:07:53 volumio volumio[978]: slope: 6 Oct 01 23:07:53 volumio volumio[978]: gain: 4.5 Oct 01 23:07:53 volumio volumio[978]: lpcross: Oct 01 23:07:53 volumio volumio[978]: type: Biquad Oct 01 23:07:53 volumio volumio[978]: parameters: Oct 01 23:07:53 volumio volumio[978]: type: LowpassFO Oct 01 23:07:53 volumio volumio[978]: freq: 700 Oct 01 23:07:53 volumio volumio[978]: delay: Oct 01 23:07:53 volumio volumio[978]: type: Delay Oct 01 23:07:53 volumio volumio[978]: parameters: Oct 01 23:07:53 volumio volumio[978]: delay: 0.32 Oct 01 23:07:53 volumio volumio[978]: unit: ms Oct 01 23:07:53 volumio volumio[978]: subsample: false Oct 01 23:07:53 volumio volumio[978]: Oct 01 23:07:53 volumio volumio[978]: eq1: Oct 01 23:07:53 volumio volumio[978]: type: Biquad Oct 01 23:07:53 volumio volumio[978]: parameters: Oct 01 23:07:53 volumio volumio[978]: type: Lowshelf Oct 01 23:07:53 volumio volumio[978]: freq: 105 Oct 01 23:07:53 volumio volumio[978]: q: 0.70 Oct 01 23:07:53 volumio volumio[978]: gain: 3.4 Oct 01 23:07:53 volumio volumio[978]: eq2: Oct 01 23:07:53 volumio volumio[978]: type: Biquad Oct 01 23:07:53 volumio volumio[978]: parameters: Oct 01 23:07:53 volumio volumio[978]: type: Peaking Oct 01 23:07:53 volumio volumio[978]: freq: 236 Oct 01 23:07:53 volumio volumio[978]: q: 0.53 Oct 01 23:07:53 volumio volumio[978]: gain: -2.4 Oct 01 23:07:53 volumio volumio[978]: eq3: Oct 01 23:07:53 volumio volumio[978]: type: Biquad Oct 01 23:07:53 volumio volumio[978]: parameters: Oct 01 23:07:53 volumio volumio[978]: type: Peaking Oct 01 23:07:53 volumio volumio[978]: freq: 1659 Oct 01 23:07:53 volumio volumio[978]: q: 1.76 Oct 01 23:07:53 volumio volumio[978]: gain: 6.9 Oct 01 23:07:53 volumio volumio[978]: eq4: Oct 01 23:07:53 volumio volumio[978]: type: Biquad Oct 01 23:07:53 volumio volumio[978]: parameters: Oct 01 23:07:53 volumio volumio[978]: type: Peaking Oct 01 23:07:53 volumio volumio[978]: freq: 592 Oct 01 23:07:53 volumio volumio[978]: q: 1.17 Oct 01 23:07:53 volumio volumio[978]: gain: -1.5 Oct 01 23:07:53 volumio volumio[978]: eq5: Oct 01 23:07:53 volumio volumio[978]: type: Biquad Oct 01 23:07:53 volumio volumio[978]: parameters: Oct 01 23:07:53 volumio volumio[978]: type: Peaking Oct 01 23:07:53 volumio volumio[978]: freq: 5982 Oct 01 23:07:53 volumio volumio[978]: q: 3.16 Oct 01 23:07:53 volumio volumio[978]: gain: -4.0 Oct 01 23:07:53 volumio volumio[978]: eq6: Oct 01 23:07:53 volumio volumio[978]: type: Biquad Oct 01 23:07:53 volumio volumio[978]: parameters: Oct 01 23:07:53 volumio volumio[978]: type: Highshelf Oct 01 23:07:53 volumio volumio[978]: freq: 10000 Oct 01 23:07:53 volumio volumio[978]: q: 0.70 Oct 01 23:07:53 volumio volumio[978]: gain: -1.5 Oct 01 23:07:53 volumio volumio[978]: eq7: Oct 01 23:07:53 volumio volumio[978]: type: Biquad Oct 01 23:07:53 volumio volumio[978]: parameters: Oct 01 23:07:53 volumio volumio[978]: type: Peaking Oct 01 23:07:53 volumio volumio[978]: freq: 3426 Oct 01 23:07:53 volumio volumio[978]: q: 5.91 Oct 01 23:07:53 volumio volumio[978]: gain: 2.9 Oct 01 23:07:53 volumio volumio[978]: eq8: Oct 01 23:07:53 volumio volumio[978]: type: Biquad Oct 01 23:07:53 volumio volumio[978]: parameters: Oct 01 23:07:53 volumio volumio[978]: type: Peaking Oct 01 23:07:53 volumio volumio[978]: freq: 2858 Oct 01 23:07:53 volumio volumio[978]: q: 5.45 Oct 01 23:07:53 volumio volumio[978]: gain: -1.9 Oct 01 23:07:53 volumio volumio[978]: eq9: Oct 01 23:07:53 volumio volumio[978]: type: Biquad Oct 01 23:07:53 volumio volumio[978]: parameters: Oct 01 23:07:53 volumio volumio[978]: type: Peaking Oct 01 23:07:53 volumio volumio[978]: freq: 4145 Oct 01 23:07:53 volumio volumio[978]: q: 6.00 Oct 01 23:07:53 volumio volumio[978]: gain: -1.5 Oct 01 23:07:53 volumio volumio[978]: eq10: Oct 01 23:07:53 volumio volumio[978]: type: Biquad Oct 01 23:07:53 volumio volumio[978]: parameters: Oct 01 23:07:53 volumio volumio[978]: type: Peaking Oct 01 23:07:53 volumio volumio[978]: freq: 54 Oct 01 23:07:53 volumio volumio[978]: q: 1.78 Oct 01 23:07:53 volumio volumio[978]: gain: -0.2 Oct 01 23:07:53 volumio volumio[978]: info: sendMpdCommand playlistinfo took 25 milliseconds Oct 01 23:07:53 volumio volumio[978]: info: sendMpdCommand playlistinfo took 24 milliseconds Oct 01 23:07:53 volumio volumio[978]: info: sendMpdCommand playlistinfo took 25 milliseconds Oct 01 23:07:53 volumio volumio[978]: verbose: ControllerMpd::parseTrackInfo Oct 01 23:07:53 volumio volumio[978]: info: ControllerMpd::pushState Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::servicePushState Oct 01 23:07:53 volumio volumio[978]: info: CorePlayQueue::getTrack 10 Oct 01 23:07:53 volumio volumio[978]: verbose: STATE SERVICE {"status":"play","position":0,"seek":960,"duration":329,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"875 Kbps","isStreaming":false,"title":"Something the Boy Said","artist":"Sting","album":"Ten Summoner's Tales","uri":"http://192.168.0.41:8200/MediaItems/9574.flac","trackType":"flac"} Oct 01 23:07:53 volumio volumio[978]: verbose: CURRENT POSITION 10 Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::syncState stateService play Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::syncState currentStatus play Oct 01 23:07:53 volumio volumio[978]: info: Received an update from plugin. extracting info from payload Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:07:53 volumio volumio[978]: info: ControllerMpd::pushState Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::servicePushState Oct 01 23:07:53 volumio volumio[978]: info: CorePlayQueue::getTrack 10 Oct 01 23:07:53 volumio volumio[978]: verbose: STATE SERVICE {"status":"play","position":0,"seek":960,"duration":329,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"664 Kbps","isStreaming":false,"title":"Something the Boy Said","artist":"Sting","album":"Ten Summoner's Tales","uri":"http://192.168.0.41:8200/MediaItems/9574.flac","trackType":"flac"} Oct 01 23:07:53 volumio volumio[978]: verbose: CURRENT POSITION 10 Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::syncState stateService play Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::syncState currentStatus play Oct 01 23:07:53 volumio volumio[978]: info: Received an update from plugin. extracting info from payload Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:07:53 volumio volumio[978]: info: ControllerMpd::pushState Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::servicePushState Oct 01 23:07:53 volumio volumio[978]: info: CorePlayQueue::getTrack 10 Oct 01 23:07:53 volumio volumio[978]: verbose: STATE SERVICE {"status":"play","position":0,"seek":960,"duration":329,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"664 Kbps","isStreaming":false,"title":"Something the Boy Said","artist":"Sting","album":"Ten Summoner's Tales","uri":"http://192.168.0.41:8200/MediaItems/9574.flac","trackType":"flac"} Oct 01 23:07:53 volumio volumio[978]: verbose: CURRENT POSITION 10 Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::syncState stateService play Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::syncState currentStatus play Oct 01 23:07:53 volumio volumio[978]: info: Received an update from plugin. extracting info from payload Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:07:53 volumio volumio[978]: info: ControllerMpd::pushState Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::servicePushState Oct 01 23:07:53 volumio volumio[978]: info: CorePlayQueue::getTrack 10 Oct 01 23:07:53 volumio volumio[978]: verbose: STATE SERVICE {"status":"play","position":0,"seek":960,"duration":329,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"664 Kbps","isStreaming":false,"title":"Something the Boy Said","artist":"Sting","album":"Ten Summoner's Tales","uri":"http://192.168.0.41:8200/MediaItems/9574.flac","trackType":"flac"} Oct 01 23:07:53 volumio volumio[978]: verbose: CURRENT POSITION 10 Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::syncState stateService play Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::syncState currentStatus play Oct 01 23:07:53 volumio volumio[978]: info: Received an update from plugin. extracting info from payload Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:07:53 volumio volumio[978]: info: ------------------------------ 349ms Oct 01 23:07:53 volumio volumio[978]: info: ------------------------------ 168ms Oct 01 23:07:53 volumio volumio[978]: info: ------------------------------ 166ms Oct 01 23:07:53 volumio volumio[978]: info: ------------------------------ 164ms Oct 01 23:07:53 volumio volumio[978]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Oct 01 23:07:53 volumio volumio[978]: 2+0 records in Oct 01 23:07:53 volumio volumio[978]: 2+0 records out Oct 01 23:07:53 volumio volumio[978]: 65536 bytes (66 kB, 64 KiB) copied, 0.000670307 s, 97.8 MB/s Oct 01 23:07:53 volumio volumio[978]: info: camilladsp spawned new process with pid 1639, instance 1, run: true Oct 01 23:07:53 volumio volumio[978]: info: CoreCommandRouter::volumioGetQueue Oct 01 23:07:53 volumio volumio[978]: info: CoreStateMachine::getQueue Oct 01 23:07:53 volumio volumio[978]: info: CorePlayQueue::getQueue Oct 01 23:07:54 volumio volumio[978]: info: CoreCommandRouter::volumioGetQueue Oct 01 23:07:54 volumio volumio[978]: info: CoreStateMachine::getQueue Oct 01 23:07:54 volumio volumio[978]: info: CorePlayQueue::getQueue Oct 01 23:07:54 volumio volumio[978]: info: CoreCommandRouter::volumioGetQueue Oct 01 23:07:54 volumio volumio[978]: info: CoreStateMachine::getQueue Oct 01 23:07:54 volumio volumio[978]: info: CorePlayQueue::getQueue Oct 01 23:07:54 volumio volumio[978]: info: CoreCommandRouter::volumioGetQueue Oct 01 23:07:54 volumio volumio[978]: info: CoreStateMachine::getQueue Oct 01 23:07:54 volumio volumio[978]: info: CorePlayQueue::getQueue Oct 01 23:07:54 volumio volumio[978]: info: CoreCommandRouter::volumioGetQueue Oct 01 23:07:54 volumio volumio[978]: info: CoreStateMachine::getQueue Oct 01 23:07:54 volumio volumio[978]: info: CorePlayQueue::getQueue Oct 01 23:07:54 volumio volumio[978]: info: CoreCommandRouter::volumioGetQueue Oct 01 23:07:54 volumio volumio[978]: info: CoreStateMachine::getQueue Oct 01 23:07:54 volumio volumio[978]: info: CorePlayQueue::getQueue Oct 01 23:07:54 volumio volumio[978]: info: CoreCommandRouter::volumioGetQueue Oct 01 23:07:54 volumio volumio[978]: info: CoreStateMachine::getQueue Oct 01 23:07:54 volumio volumio[978]: info: CorePlayQueue::getQueue Oct 01 23:07:54 volumio volumio[978]: info: CoreCommandRouter::volumioGetQueue Oct 01 23:07:54 volumio volumio[978]: info: CoreStateMachine::getQueue Oct 01 23:07:54 volumio volumio[978]: info: CorePlayQueue::getQueue Oct 01 23:07:54 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:07:54 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:07:54 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:07:54 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:07:54 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:07:54 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:07:54 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:07:54 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:07:54 volumio volumio[978]: error: FusionDsp - WebSocket error: [object Object] Oct 01 23:07:54 volumio volumio[978]: error: FusionDsp - WebSocket error: [object Object] Oct 01 23:08:10 volumio volumio[978]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 01 23:08:10 volumio volumio[978]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 01 23:08:10 volumio volumio[978]: info: Discovery: Getting this device information Oct 01 23:08:10 volumio volumio[978]: info: CoreCommandRouter::volumioGetState Oct 01 23:08:10 volumio volumio[978]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 01 23:08:13 volumio volumio[978]: info: Preload queue cleared Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::ClearQueue Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::stop Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::stPlaybackTimer Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::updateTrackBlock Oct 01 23:08:13 volumio volumio[978]: info: CorePlayQueue::getTrackBlock Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:08:13 volumio volumio[978]: info: CorePlayQueue::getTrack 10 Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::serviceStop Oct 01 23:08:13 volumio volumio[978]: info: CorePlayQueue::getTrack 10 Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::serviceStop Oct 01 23:08:13 volumio volumio[978]: info: [1727816893109] ControllerUPNPBrowser::stop Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand stop Oct 01 23:08:13 volumio volumio[978]: info: CorePlayQueue::clearPlayQueue Oct 01 23:08:13 volumio volumio[978]: info: CorePlayQueue::saveQueue Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::volumioPushQueue Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::addQueueItems Oct 01 23:08:13 volumio volumio[978]: info: CorePlayQueue::addQueueItems Oct 01 23:08:13 volumio volumio[978]: info: Preload queue cleared Oct 01 23:08:13 volumio volumio[978]: info: Adding Item to queue: upnp/folder/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$C Oct 01 23:08:13 volumio volumio[978]: info: Using cached record of: upnp/folder/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$C Oct 01 23:08:13 volumio volumio[978]: info: Adding Item to queue: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$0 Oct 01 23:08:13 volumio volumio[978]: info: Using cached record of: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$0 Oct 01 23:08:13 volumio volumio[978]: info: Adding Item to queue: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$1 Oct 01 23:08:13 volumio volumio[978]: info: Using cached record of: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$1 Oct 01 23:08:13 volumio volumio[978]: info: Adding Item to queue: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$2 Oct 01 23:08:13 volumio volumio[978]: info: Using cached record of: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$2 Oct 01 23:08:13 volumio volumio[978]: info: Adding Item to queue: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$3 Oct 01 23:08:13 volumio volumio[978]: info: Using cached record of: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$3 Oct 01 23:08:13 volumio volumio[978]: info: Adding Item to queue: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$4 Oct 01 23:08:13 volumio volumio[978]: info: Using cached record of: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$4 Oct 01 23:08:13 volumio volumio[978]: info: Adding Item to queue: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$5 Oct 01 23:08:13 volumio volumio[978]: info: Using cached record of: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$5 Oct 01 23:08:13 volumio volumio[978]: info: Adding Item to queue: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$6 Oct 01 23:08:13 volumio volumio[978]: info: Using cached record of: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$6 Oct 01 23:08:13 volumio volumio[978]: info: Adding Item to queue: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$7 Oct 01 23:08:13 volumio volumio[978]: info: Using cached record of: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$7 Oct 01 23:08:13 volumio volumio[978]: info: Adding Item to queue: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$8 Oct 01 23:08:13 volumio volumio[978]: info: Using cached record of: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$8 Oct 01 23:08:13 volumio volumio[978]: info: Adding Item to queue: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$9 Oct 01 23:08:13 volumio volumio[978]: info: Using cached record of: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$9 Oct 01 23:08:13 volumio volumio[978]: info: Adding Item to queue: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$A Oct 01 23:08:13 volumio volumio[978]: info: Using cached record of: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$A Oct 01 23:08:13 volumio volumio[978]: info: Adding Item to queue: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$B Oct 01 23:08:13 volumio volumio[978]: info: Using cached record of: upnp/http://192.168.0.41:8200/ctl/ContentDir@64$0$82$3$B Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::volumioPushQueue Oct 01 23:08:13 volumio volumio[978]: info: CorePlayQueue::saveQueue Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::updateTrackBlock Oct 01 23:08:13 volumio volumio[978]: info: CorePlayQueue::getTrackBlock Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::volumioPlay Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::play index 9 Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::stop Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::play index undefined Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 01 23:08:13 volumio volumio[978]: info: CorePlayQueue::getTrack 9 Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::startPlaybackTimer Oct 01 23:08:13 volumio volumio[978]: info: CorePlayQueue::getTrack 9 Oct 01 23:08:13 volumio volumio[978]: info: [1727816893152] ControllerUPNPBrowser::clearAddPlayTrack Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand stop Oct 01 23:08:13 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:08:13 volumio volumio[978]: info: Oct 01 23:08:13 volumio volumio[978]: ---------------------------- MPD announces state update: player Oct 01 23:08:13 volumio volumio[978]: info: sendMpdCommand stop took 53 milliseconds Oct 01 23:08:13 volumio volumio[978]: info: ControllerMpd::getState Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand status Oct 01 23:08:13 volumio volumio[978]: info: sendMpdCommand stop took 10 milliseconds Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand clear Oct 01 23:08:13 volumio volumio[978]: info: Oct 01 23:08:13 volumio volumio[978]: ---------------------------- MPD announces state update: player Oct 01 23:08:13 volumio volumio[978]: info: ControllerMpd::getState Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand status Oct 01 23:08:13 volumio volumio[978]: info: Oct 01 23:08:13 volumio volumio[978]: ---------------------------- MPD announces state update: player Oct 01 23:08:13 volumio volumio[978]: info: ControllerMpd::getState Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand status Oct 01 23:08:13 volumio volumio[978]: info: Oct 01 23:08:13 volumio volumio[978]: ---------------------------- MPD announces state update: player Oct 01 23:08:13 volumio volumio[978]: info: ControllerMpd::getState Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand status Oct 01 23:08:13 volumio volumio[978]: info: Oct 01 23:08:13 volumio volumio[978]: ---------------------------- MPD announces system playlist update Oct 01 23:08:13 volumio volumio[978]: info: Ignoring MPD Status Update Oct 01 23:08:13 volumio volumio[978]: info: sendMpdCommand status took 11 milliseconds Oct 01 23:08:13 volumio volumio[978]: info: sendMpdCommand clear took 10 milliseconds Oct 01 23:08:13 volumio volumio[978]: info: sendMpdCommand status took 9 milliseconds Oct 01 23:08:13 volumio volumio[978]: info: sendMpdCommand status took 7 milliseconds Oct 01 23:08:13 volumio volumio[978]: info: sendMpdCommand status took 5 milliseconds Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::parseState Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.0.41:8200/MediaItems/9573.flac" Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::parseState Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::parseState Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::parseState Oct 01 23:08:13 volumio volumio[978]: info: ControllerMpd::pushState Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::servicePushState Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:08:13 volumio volumio[978]: info: CorePlayQueue::getTrack 9 Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:08:13 volumio volumio[978]: info: CorePlayQueue::getTrack 9 Oct 01 23:08:13 volumio volumio[978]: 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} Oct 01 23:08:13 volumio volumio[978]: verbose: CURRENT POSITION 9 Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::syncState stateService stop Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::syncState currentStatus stop Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:08:13 volumio volumio[978]: info: CorePlayQueue::getTrack 9 Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:08:13 volumio volumio[978]: info: No code Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:08:13 volumio volumio[978]: info: CorePlayQueue::getTrack 9 Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:08:13 volumio volumio[978]: info: ControllerMpd::pushState Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::servicePushState Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:08:13 volumio volumio[978]: info: CorePlayQueue::getTrack 9 Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:08:13 volumio volumio[978]: info: CorePlayQueue::getTrack 9 Oct 01 23:08:13 volumio volumio[978]: 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} Oct 01 23:08:13 volumio volumio[978]: verbose: CURRENT POSITION 9 Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::syncState stateService stop Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::syncState currentStatus stop Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:08:13 volumio volumio[978]: info: CorePlayQueue::getTrack 9 Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:08:13 volumio volumio[978]: info: No code Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:08:13 volumio volumio[978]: info: CorePlayQueue::getTrack 9 Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:08:13 volumio volumio[978]: info: ControllerMpd::pushState Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::servicePushState Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:08:13 volumio volumio[978]: info: CorePlayQueue::getTrack 9 Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:08:13 volumio volumio[978]: info: CorePlayQueue::getTrack 9 Oct 01 23:08:13 volumio volumio[978]: 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} Oct 01 23:08:13 volumio volumio[978]: verbose: CURRENT POSITION 9 Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::syncState stateService stop Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::syncState currentStatus stop Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:08:13 volumio volumio[978]: info: CorePlayQueue::getTrack 9 Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:08:13 volumio volumio[978]: info: No code Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:08:13 volumio volumio[978]: info: CorePlayQueue::getTrack 9 Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:08:13 volumio volumio[978]: info: ------------------------------ 153ms Oct 01 23:08:13 volumio volumio[978]: info: ------------------------------ 153ms Oct 01 23:08:13 volumio volumio[978]: info: ------------------------------ 153ms Oct 01 23:08:13 volumio volumio[978]: info: Oct 01 23:08:13 volumio volumio[978]: ---------------------------- MPD announces system playlist update Oct 01 23:08:13 volumio volumio[978]: info: Ignoring MPD Status Update Oct 01 23:08:13 volumio volumio[978]: info: Oct 01 23:08:13 volumio volumio[978]: ---------------------------- MPD announces system playlist update Oct 01 23:08:13 volumio volumio[978]: info: Ignoring MPD Status Update Oct 01 23:08:13 volumio volumio[978]: info: Oct 01 23:08:13 volumio volumio[978]: ---------------------------- MPD announces system playlist update Oct 01 23:08:13 volumio volumio[978]: info: Ignoring MPD Status Update Oct 01 23:08:13 volumio volumio[978]: error: updateQueue error: null Oct 01 23:08:13 volumio volumio[978]: info: ------------------------------ 160ms Oct 01 23:08:13 volumio volumio[978]: info: sendMpdCommand playlistinfo took 158 milliseconds Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::parseTrackInfo Oct 01 23:08:13 volumio volumio[978]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Oct 01 23:08:13 volumio volumio[978]: info: ------------------------------ 175ms Oct 01 23:08:13 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:08:13 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:08:13 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:08:13 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:08:13 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:08:13 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:08:13 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:08:13 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:08:13 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:08:13 volumio volumio[978]: error: updateQueue error: null Oct 01 23:08:13 volumio volumio[978]: error: updateQueue error: null Oct 01 23:08:13 volumio volumio[978]: error: updateQueue error: null Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.0.41:8200/MediaItems/9573.flac" Oct 01 23:08:13 volumio volumio[978]: info: ------------------------------ 45ms Oct 01 23:08:13 volumio volumio[978]: info: ------------------------------ 44ms Oct 01 23:08:13 volumio volumio[978]: info: ------------------------------ 43ms Oct 01 23:08:13 volumio volumio[978]: info: Oct 01 23:08:13 volumio volumio[978]: ---------------------------- MPD announces system playlist update Oct 01 23:08:13 volumio volumio[978]: info: Ignoring MPD Status Update Oct 01 23:08:13 volumio volumio[978]: info: sendMpdCommand add "http://192.168.0.41:8200/MediaItems/9573.flac" took 7 milliseconds Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand play Oct 01 23:08:13 volumio volumio[978]: info: Oct 01 23:08:13 volumio volumio[978]: ---------------------------- MPD announces system playlist update Oct 01 23:08:13 volumio volumio[978]: info: Ignoring MPD Status Update Oct 01 23:08:13 volumio volumio[978]: info: Oct 01 23:08:13 volumio volumio[978]: ---------------------------- MPD announces system playlist update Oct 01 23:08:13 volumio volumio[978]: info: Ignoring MPD Status Update Oct 01 23:08:13 volumio volumio[978]: info: Oct 01 23:08:13 volumio volumio[978]: ---------------------------- MPD announces system playlist update Oct 01 23:08:13 volumio volumio[978]: info: Ignoring MPD Status Update Oct 01 23:08:13 volumio volumio[978]: info: ------------------------------ 14ms Oct 01 23:08:13 volumio volumio[978]: info: sendMpdCommand play took 12 milliseconds Oct 01 23:08:13 volumio volumio[978]: info: ------------------------------ 7ms Oct 01 23:08:13 volumio volumio[978]: info: ------------------------------ 7ms Oct 01 23:08:13 volumio volumio[978]: info: ------------------------------ 5ms Oct 01 23:08:13 volumio volumio[978]: info: Oct 01 23:08:13 volumio volumio[978]: ---------------------------- MPD announces state update: player Oct 01 23:08:13 volumio volumio[978]: info: ControllerMpd::getState Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand status Oct 01 23:08:13 volumio volumio[978]: info: Oct 01 23:08:13 volumio volumio[978]: ---------------------------- MPD announces state update: player Oct 01 23:08:13 volumio volumio[978]: info: ControllerMpd::getState Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand status Oct 01 23:08:13 volumio volumio[978]: info: Oct 01 23:08:13 volumio volumio[978]: ---------------------------- MPD announces state update: player Oct 01 23:08:13 volumio volumio[978]: info: ControllerMpd::getState Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand status Oct 01 23:08:13 volumio volumio[978]: info: Oct 01 23:08:13 volumio volumio[978]: ---------------------------- MPD announces state update: player Oct 01 23:08:13 volumio volumio[978]: info: ControllerMpd::getState Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand status Oct 01 23:08:13 volumio volumio[978]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Oct 01 23:08:13 volumio volumio[978]: info: FusionDsp - ---- read samplerate from file: 44100 Oct 01 23:08:13 volumio volumio[978]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 01 23:08:13 volumio volumio[978]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Oct 01 23:08:13 volumio volumio[978]: info: FusionDsp - ---- read samplerate from file: 44100 Oct 01 23:08:13 volumio volumio[978]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 01 23:08:13 volumio volumio[978]: info: Oct 01 23:08:13 volumio volumio[978]: ---------------------------- MPD announces state update: player Oct 01 23:08:13 volumio volumio[978]: info: sendMpdCommand status took 21 milliseconds Oct 01 23:08:13 volumio volumio[978]: info: ControllerMpd::getState Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand status Oct 01 23:08:13 volumio volumio[978]: info: sendMpdCommand status took 21 milliseconds Oct 01 23:08:13 volumio volumio[978]: info: sendMpdCommand status took 19 milliseconds Oct 01 23:08:13 volumio volumio[978]: info: sendMpdCommand status took 18 milliseconds Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::parseState Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::parseState Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::parseState Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::parseState Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 01 23:08:13 volumio volumio[978]: info: Oct 01 23:08:13 volumio volumio[978]: ---------------------------- MPD announces state update: player Oct 01 23:08:13 volumio volumio[978]: info: ControllerMpd::getState Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand status Oct 01 23:08:13 volumio volumio[978]: info: Oct 01 23:08:13 volumio volumio[978]: ---------------------------- MPD announces state update: player Oct 01 23:08:13 volumio volumio[978]: info: ControllerMpd::getState Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand status Oct 01 23:08:13 volumio volumio[978]: info: Oct 01 23:08:13 volumio volumio[978]: ---------------------------- MPD announces state update: player Oct 01 23:08:13 volumio volumio[978]: info: ControllerMpd::getState Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand status Oct 01 23:08:13 volumio volumio[978]: info: sendMpdCommand status took 26 milliseconds Oct 01 23:08:13 volumio volumio[978]: info: sendMpdCommand playlistinfo took 25 milliseconds Oct 01 23:08:13 volumio volumio[978]: info: sendMpdCommand playlistinfo took 14 milliseconds Oct 01 23:08:13 volumio volumio[978]: info: sendMpdCommand playlistinfo took 13 milliseconds Oct 01 23:08:13 volumio volumio[978]: info: sendMpdCommand playlistinfo took 14 milliseconds Oct 01 23:08:13 volumio volumio[978]: info: sendMpdCommand status took 9 milliseconds Oct 01 23:08:13 volumio volumio[978]: info: sendMpdCommand status took 7 milliseconds Oct 01 23:08:13 volumio volumio[978]: info: sendMpdCommand status took 5 milliseconds Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::parseState Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::parseTrackInfo Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::parseTrackInfo Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::parseTrackInfo Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::parseTrackInfo Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::parseState Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::parseState Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::parseState Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 01 23:08:13 volumio volumio[978]: info: ControllerMpd::pushState Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::servicePushState Oct 01 23:08:13 volumio volumio[978]: info: CorePlayQueue::getTrack 9 Oct 01 23:08:13 volumio volumio[978]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":279,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"9573.flac","artist":null,"album":null,"uri":"http://192.168.0.41:8200/MediaItems/9573.flac","trackType":"flac"} Oct 01 23:08:13 volumio volumio[978]: verbose: CURRENT POSITION 9 Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::syncState stateService play Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::syncState currentStatus stop Oct 01 23:08:13 volumio volumio[978]: info: ControllerMpd::pushState Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::servicePushState Oct 01 23:08:13 volumio volumio[978]: info: CorePlayQueue::getTrack 9 Oct 01 23:08:13 volumio volumio[978]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":279,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"9573.flac","artist":null,"album":null,"uri":"http://192.168.0.41:8200/MediaItems/9573.flac","trackType":"flac"} Oct 01 23:08:13 volumio volumio[978]: verbose: CURRENT POSITION 9 Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::syncState stateService play Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::syncState currentStatus play Oct 01 23:08:13 volumio volumio[978]: info: Received an update from plugin. extracting info from payload Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:08:13 volumio volumio[978]: info: ControllerMpd::pushState Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::servicePushState Oct 01 23:08:13 volumio volumio[978]: info: CorePlayQueue::getTrack 9 Oct 01 23:08:13 volumio volumio[978]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":279,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"9573.flac","artist":null,"album":null,"uri":"http://192.168.0.41:8200/MediaItems/9573.flac","trackType":"flac"} Oct 01 23:08:13 volumio volumio[978]: verbose: CURRENT POSITION 9 Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::syncState stateService play Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::syncState currentStatus play Oct 01 23:08:13 volumio volumio[978]: info: Received an update from plugin. extracting info from payload Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:08:13 volumio volumio[978]: info: ControllerMpd::pushState Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::servicePushState Oct 01 23:08:13 volumio volumio[978]: info: CorePlayQueue::getTrack 9 Oct 01 23:08:13 volumio volumio[978]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":279,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"9573.flac","artist":null,"album":null,"uri":"http://192.168.0.41:8200/MediaItems/9573.flac","trackType":"flac"} Oct 01 23:08:13 volumio volumio[978]: verbose: CURRENT POSITION 9 Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::syncState stateService play Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::syncState currentStatus play Oct 01 23:08:13 volumio volumio[978]: info: Received an update from plugin. extracting info from payload Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:08:13 volumio volumio[978]: info: ------------------------------ 99ms Oct 01 23:08:13 volumio volumio[978]: info: ------------------------------ 173ms Oct 01 23:08:13 volumio volumio[978]: info: ------------------------------ 172ms Oct 01 23:08:13 volumio volumio[978]: info: ------------------------------ 171ms Oct 01 23:08:13 volumio volumio[978]: info: Oct 01 23:08:13 volumio volumio[978]: ---------------------------- MPD announces system playlist update Oct 01 23:08:13 volumio volumio[978]: info: Ignoring MPD Status Update Oct 01 23:08:13 volumio volumio[978]: info: Oct 01 23:08:13 volumio volumio[978]: ---------------------------- MPD announces state update: player Oct 01 23:08:13 volumio volumio[978]: info: sendMpdCommand playlistinfo took 129 milliseconds Oct 01 23:08:13 volumio volumio[978]: info: sendMpdCommand playlistinfo took 126 milliseconds Oct 01 23:08:13 volumio volumio[978]: info: sendMpdCommand playlistinfo took 124 milliseconds Oct 01 23:08:13 volumio volumio[978]: info: sendMpdCommand playlistinfo took 124 milliseconds Oct 01 23:08:13 volumio volumio[978]: info: ControllerMpd::getState Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand status Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::parseTrackInfo Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::parseTrackInfo Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::parseTrackInfo Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::parseTrackInfo Oct 01 23:08:13 volumio volumio[978]: info: ControllerMpd::pushState Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::servicePushState Oct 01 23:08:13 volumio volumio[978]: info: CorePlayQueue::getTrack 9 Oct 01 23:08:13 volumio volumio[978]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":279,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"9573.flac","artist":null,"album":null,"uri":"http://192.168.0.41:8200/MediaItems/9573.flac","trackType":"flac"} Oct 01 23:08:13 volumio volumio[978]: verbose: CURRENT POSITION 9 Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::syncState stateService play Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::syncState currentStatus play Oct 01 23:08:13 volumio volumio[978]: info: Received an update from plugin. extracting info from payload Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:08:13 volumio volumio[978]: info: ControllerMpd::pushState Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::servicePushState Oct 01 23:08:13 volumio volumio[978]: info: CorePlayQueue::getTrack 9 Oct 01 23:08:13 volumio volumio[978]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":279,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"9573.flac","artist":null,"album":null,"uri":"http://192.168.0.41:8200/MediaItems/9573.flac","trackType":"flac"} Oct 01 23:08:13 volumio volumio[978]: verbose: CURRENT POSITION 9 Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::syncState stateService play Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::syncState currentStatus play Oct 01 23:08:13 volumio volumio[978]: info: Received an update from plugin. extracting info from payload Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:08:13 volumio volumio[978]: info: ControllerMpd::pushState Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::servicePushState Oct 01 23:08:13 volumio volumio[978]: info: CorePlayQueue::getTrack 9 Oct 01 23:08:13 volumio volumio[978]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":279,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"9573.flac","artist":null,"album":null,"uri":"http://192.168.0.41:8200/MediaItems/9573.flac","trackType":"flac"} Oct 01 23:08:13 volumio volumio[978]: verbose: CURRENT POSITION 9 Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::syncState stateService play Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::syncState currentStatus play Oct 01 23:08:13 volumio volumio[978]: info: Received an update from plugin. extracting info from payload Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:08:13 volumio volumio[978]: info: ControllerMpd::pushState Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::servicePushState Oct 01 23:08:13 volumio volumio[978]: info: CorePlayQueue::getTrack 9 Oct 01 23:08:13 volumio volumio[978]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":279,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"9573.flac","artist":null,"album":null,"uri":"http://192.168.0.41:8200/MediaItems/9573.flac","trackType":"flac"} Oct 01 23:08:13 volumio volumio[978]: verbose: CURRENT POSITION 9 Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::syncState stateService play Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::syncState currentStatus play Oct 01 23:08:13 volumio volumio[978]: info: Received an update from plugin. extracting info from payload Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:08:13 volumio volumio[978]: info: ------------------------------ 310ms Oct 01 23:08:13 volumio volumio[978]: info: ------------------------------ 293ms Oct 01 23:08:13 volumio volumio[978]: info: ------------------------------ 291ms Oct 01 23:08:13 volumio volumio[978]: info: ------------------------------ 289ms Oct 01 23:08:13 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:08:13 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:08:13 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:08:13 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:08:13 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:08:13 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:08:13 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:08:13 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:08:13 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:08:13 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:08:13 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:08:13 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:08:13 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:08:13 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:08:13 volumio volumio[978]: info: Oct 01 23:08:13 volumio volumio[978]: ---------------------------- MPD announces system playlist update Oct 01 23:08:13 volumio volumio[978]: info: Ignoring MPD Status Update Oct 01 23:08:13 volumio volumio[978]: info: Oct 01 23:08:13 volumio volumio[978]: ---------------------------- MPD announces state update: player Oct 01 23:08:13 volumio volumio[978]: info: ControllerMpd::getState Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand status Oct 01 23:08:13 volumio volumio[978]: info: Oct 01 23:08:13 volumio volumio[978]: ---------------------------- MPD announces system playlist update Oct 01 23:08:13 volumio volumio[978]: info: Ignoring MPD Status Update Oct 01 23:08:13 volumio volumio[978]: info: Oct 01 23:08:13 volumio volumio[978]: ---------------------------- MPD announces state update: player Oct 01 23:08:13 volumio volumio[978]: info: ControllerMpd::getState Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand status Oct 01 23:08:13 volumio volumio[978]: info: Oct 01 23:08:13 volumio volumio[978]: ---------------------------- MPD announces system playlist update Oct 01 23:08:13 volumio volumio[978]: info: Ignoring MPD Status Update Oct 01 23:08:13 volumio volumio[978]: info: Oct 01 23:08:13 volumio volumio[978]: ---------------------------- MPD announces state update: player Oct 01 23:08:13 volumio volumio[978]: info: ControllerMpd::getState Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand status Oct 01 23:08:13 volumio volumio[978]: info: ------------------------------ 208ms Oct 01 23:08:13 volumio volumio[978]: info: sendMpdCommand status took 206 milliseconds Oct 01 23:08:13 volumio volumio[978]: info: ------------------------------ 12ms Oct 01 23:08:13 volumio volumio[978]: info: sendMpdCommand status took 11 milliseconds Oct 01 23:08:13 volumio volumio[978]: info: ------------------------------ 11ms Oct 01 23:08:13 volumio volumio[978]: info: sendMpdCommand status took 10 milliseconds Oct 01 23:08:13 volumio volumio[978]: info: ------------------------------ 9ms Oct 01 23:08:13 volumio volumio[978]: info: sendMpdCommand status took 8 milliseconds Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::parseState Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::parseState Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::parseState Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::parseState Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 01 23:08:13 volumio volumio[978]: info: FusionDsp - crossfeed bauer Oct 01 23:08:13 volumio volumio[978]: info: FusionDsp - highcross: Oct 01 23:08:13 volumio volumio[978]: type: Biquad Oct 01 23:08:13 volumio volumio[978]: parameters: Oct 01 23:08:13 volumio volumio[978]: type: Highshelf Oct 01 23:08:13 volumio volumio[978]: freq: 700 Oct 01 23:08:13 volumio volumio[978]: slope: 6 Oct 01 23:08:13 volumio volumio[978]: gain: 4.5 Oct 01 23:08:13 volumio volumio[978]: lpcross: Oct 01 23:08:13 volumio volumio[978]: type: Biquad Oct 01 23:08:13 volumio volumio[978]: parameters: Oct 01 23:08:13 volumio volumio[978]: type: LowpassFO Oct 01 23:08:13 volumio volumio[978]: freq: 700 Oct 01 23:08:13 volumio volumio[978]: delay: Oct 01 23:08:13 volumio volumio[978]: type: Delay Oct 01 23:08:13 volumio volumio[978]: parameters: Oct 01 23:08:13 volumio volumio[978]: delay: 0.32 Oct 01 23:08:13 volumio volumio[978]: unit: ms Oct 01 23:08:13 volumio volumio[978]: subsample: false Oct 01 23:08:13 volumio volumio[978]: Oct 01 23:08:13 volumio volumio[978]: eq1: Oct 01 23:08:13 volumio volumio[978]: type: Biquad Oct 01 23:08:13 volumio volumio[978]: parameters: Oct 01 23:08:13 volumio volumio[978]: type: Lowshelf Oct 01 23:08:13 volumio volumio[978]: freq: 105 Oct 01 23:08:13 volumio volumio[978]: q: 0.70 Oct 01 23:08:13 volumio volumio[978]: gain: 3.4 Oct 01 23:08:13 volumio volumio[978]: eq2: Oct 01 23:08:13 volumio volumio[978]: type: Biquad Oct 01 23:08:13 volumio volumio[978]: parameters: Oct 01 23:08:13 volumio volumio[978]: type: Peaking Oct 01 23:08:13 volumio volumio[978]: freq: 236 Oct 01 23:08:13 volumio volumio[978]: q: 0.53 Oct 01 23:08:13 volumio volumio[978]: gain: -2.4 Oct 01 23:08:13 volumio volumio[978]: eq3: Oct 01 23:08:13 volumio volumio[978]: type: Biquad Oct 01 23:08:13 volumio volumio[978]: parameters: Oct 01 23:08:13 volumio volumio[978]: type: Peaking Oct 01 23:08:13 volumio volumio[978]: freq: 1659 Oct 01 23:08:13 volumio volumio[978]: q: 1.76 Oct 01 23:08:13 volumio volumio[978]: gain: 6.9 Oct 01 23:08:13 volumio volumio[978]: eq4: Oct 01 23:08:13 volumio volumio[978]: type: Biquad Oct 01 23:08:13 volumio volumio[978]: parameters: Oct 01 23:08:13 volumio volumio[978]: type: Peaking Oct 01 23:08:13 volumio volumio[978]: freq: 592 Oct 01 23:08:13 volumio volumio[978]: q: 1.17 Oct 01 23:08:13 volumio volumio[978]: gain: -1.5 Oct 01 23:08:13 volumio volumio[978]: eq5: Oct 01 23:08:13 volumio volumio[978]: type: Biquad Oct 01 23:08:13 volumio volumio[978]: parameters: Oct 01 23:08:13 volumio volumio[978]: type: Peaking Oct 01 23:08:13 volumio volumio[978]: freq: 5982 Oct 01 23:08:13 volumio volumio[978]: q: 3.16 Oct 01 23:08:13 volumio volumio[978]: gain: -4.0 Oct 01 23:08:13 volumio volumio[978]: eq6: Oct 01 23:08:13 volumio volumio[978]: type: Biquad Oct 01 23:08:13 volumio volumio[978]: parameters: Oct 01 23:08:13 volumio volumio[978]: type: Highshelf Oct 01 23:08:13 volumio volumio[978]: freq: 10000 Oct 01 23:08:13 volumio volumio[978]: q: 0.70 Oct 01 23:08:13 volumio volumio[978]: gain: -1.5 Oct 01 23:08:13 volumio volumio[978]: eq7: Oct 01 23:08:13 volumio volumio[978]: type: Biquad Oct 01 23:08:13 volumio volumio[978]: parameters: Oct 01 23:08:13 volumio volumio[978]: type: Peaking Oct 01 23:08:13 volumio volumio[978]: freq: 3426 Oct 01 23:08:13 volumio volumio[978]: q: 5.91 Oct 01 23:08:13 volumio volumio[978]: gain: 2.9 Oct 01 23:08:13 volumio volumio[978]: eq8: Oct 01 23:08:13 volumio volumio[978]: type: Biquad Oct 01 23:08:13 volumio volumio[978]: parameters: Oct 01 23:08:13 volumio volumio[978]: type: Peaking Oct 01 23:08:13 volumio volumio[978]: freq: 2858 Oct 01 23:08:13 volumio volumio[978]: q: 5.45 Oct 01 23:08:13 volumio volumio[978]: gain: -1.9 Oct 01 23:08:13 volumio volumio[978]: eq9: Oct 01 23:08:13 volumio volumio[978]: type: Biquad Oct 01 23:08:13 volumio volumio[978]: parameters: Oct 01 23:08:13 volumio volumio[978]: type: Peaking Oct 01 23:08:13 volumio volumio[978]: freq: 4145 Oct 01 23:08:13 volumio volumio[978]: q: 6.00 Oct 01 23:08:13 volumio volumio[978]: gain: -1.5 Oct 01 23:08:13 volumio volumio[978]: eq10: Oct 01 23:08:13 volumio volumio[978]: type: Biquad Oct 01 23:08:13 volumio volumio[978]: parameters: Oct 01 23:08:13 volumio volumio[978]: type: Peaking Oct 01 23:08:13 volumio volumio[978]: freq: 54 Oct 01 23:08:13 volumio volumio[978]: q: 1.78 Oct 01 23:08:13 volumio volumio[978]: gain: -0.2 Oct 01 23:08:13 volumio volumio[978]: info: FusionDsp - crossfeed bauer Oct 01 23:08:13 volumio volumio[978]: info: FusionDsp - highcross: Oct 01 23:08:13 volumio volumio[978]: type: Biquad Oct 01 23:08:13 volumio volumio[978]: parameters: Oct 01 23:08:13 volumio volumio[978]: type: Highshelf Oct 01 23:08:13 volumio volumio[978]: freq: 700 Oct 01 23:08:13 volumio volumio[978]: slope: 6 Oct 01 23:08:13 volumio volumio[978]: gain: 4.5 Oct 01 23:08:13 volumio volumio[978]: lpcross: Oct 01 23:08:13 volumio volumio[978]: type: Biquad Oct 01 23:08:13 volumio volumio[978]: parameters: Oct 01 23:08:13 volumio volumio[978]: type: LowpassFO Oct 01 23:08:13 volumio volumio[978]: freq: 700 Oct 01 23:08:13 volumio volumio[978]: delay: Oct 01 23:08:13 volumio volumio[978]: type: Delay Oct 01 23:08:13 volumio volumio[978]: parameters: Oct 01 23:08:13 volumio volumio[978]: delay: 0.32 Oct 01 23:08:13 volumio volumio[978]: unit: ms Oct 01 23:08:13 volumio volumio[978]: subsample: false Oct 01 23:08:13 volumio volumio[978]: Oct 01 23:08:13 volumio volumio[978]: eq1: Oct 01 23:08:13 volumio volumio[978]: type: Biquad Oct 01 23:08:13 volumio volumio[978]: parameters: Oct 01 23:08:13 volumio volumio[978]: type: Lowshelf Oct 01 23:08:13 volumio volumio[978]: freq: 105 Oct 01 23:08:13 volumio volumio[978]: q: 0.70 Oct 01 23:08:13 volumio volumio[978]: gain: 3.4 Oct 01 23:08:13 volumio volumio[978]: eq2: Oct 01 23:08:13 volumio volumio[978]: type: Biquad Oct 01 23:08:13 volumio volumio[978]: parameters: Oct 01 23:08:13 volumio volumio[978]: type: Peaking Oct 01 23:08:13 volumio volumio[978]: freq: 236 Oct 01 23:08:13 volumio volumio[978]: q: 0.53 Oct 01 23:08:13 volumio volumio[978]: gain: -2.4 Oct 01 23:08:13 volumio volumio[978]: eq3: Oct 01 23:08:13 volumio volumio[978]: type: Biquad Oct 01 23:08:13 volumio volumio[978]: parameters: Oct 01 23:08:13 volumio volumio[978]: type: Peaking Oct 01 23:08:13 volumio volumio[978]: freq: 1659 Oct 01 23:08:13 volumio volumio[978]: q: 1.76 Oct 01 23:08:13 volumio volumio[978]: gain: 6.9 Oct 01 23:08:13 volumio volumio[978]: eq4: Oct 01 23:08:13 volumio volumio[978]: type: Biquad Oct 01 23:08:13 volumio volumio[978]: parameters: Oct 01 23:08:13 volumio volumio[978]: type: Peaking Oct 01 23:08:13 volumio volumio[978]: freq: 592 Oct 01 23:08:13 volumio volumio[978]: q: 1.17 Oct 01 23:08:13 volumio volumio[978]: gain: -1.5 Oct 01 23:08:13 volumio volumio[978]: eq5: Oct 01 23:08:13 volumio volumio[978]: type: Biquad Oct 01 23:08:13 volumio volumio[978]: parameters: Oct 01 23:08:13 volumio volumio[978]: type: Peaking Oct 01 23:08:13 volumio volumio[978]: freq: 5982 Oct 01 23:08:13 volumio volumio[978]: q: 3.16 Oct 01 23:08:13 volumio volumio[978]: gain: -4.0 Oct 01 23:08:13 volumio volumio[978]: eq6: Oct 01 23:08:13 volumio volumio[978]: type: Biquad Oct 01 23:08:13 volumio volumio[978]: parameters: Oct 01 23:08:13 volumio volumio[978]: type: Highshelf Oct 01 23:08:13 volumio volumio[978]: freq: 10000 Oct 01 23:08:13 volumio volumio[978]: q: 0.70 Oct 01 23:08:13 volumio volumio[978]: gain: -1.5 Oct 01 23:08:13 volumio volumio[978]: eq7: Oct 01 23:08:13 volumio volumio[978]: type: Biquad Oct 01 23:08:13 volumio volumio[978]: parameters: Oct 01 23:08:13 volumio volumio[978]: type: Peaking Oct 01 23:08:13 volumio volumio[978]: freq: 3426 Oct 01 23:08:13 volumio volumio[978]: q: 5.91 Oct 01 23:08:13 volumio volumio[978]: gain: 2.9 Oct 01 23:08:13 volumio volumio[978]: eq8: Oct 01 23:08:13 volumio volumio[978]: type: Biquad Oct 01 23:08:13 volumio volumio[978]: parameters: Oct 01 23:08:13 volumio volumio[978]: type: Peaking Oct 01 23:08:13 volumio volumio[978]: freq: 2858 Oct 01 23:08:13 volumio volumio[978]: q: 5.45 Oct 01 23:08:13 volumio volumio[978]: gain: -1.9 Oct 01 23:08:13 volumio volumio[978]: eq9: Oct 01 23:08:13 volumio volumio[978]: type: Biquad Oct 01 23:08:13 volumio volumio[978]: parameters: Oct 01 23:08:13 volumio volumio[978]: type: Peaking Oct 01 23:08:13 volumio volumio[978]: freq: 4145 Oct 01 23:08:13 volumio volumio[978]: q: 6.00 Oct 01 23:08:13 volumio volumio[978]: gain: -1.5 Oct 01 23:08:13 volumio volumio[978]: eq10: Oct 01 23:08:13 volumio volumio[978]: type: Biquad Oct 01 23:08:13 volumio volumio[978]: parameters: Oct 01 23:08:13 volumio volumio[978]: type: Peaking Oct 01 23:08:13 volumio volumio[978]: freq: 54 Oct 01 23:08:13 volumio volumio[978]: q: 1.78 Oct 01 23:08:13 volumio volumio[978]: gain: -0.2 Oct 01 23:08:13 volumio volumio[978]: info: sendMpdCommand playlistinfo took 20 milliseconds Oct 01 23:08:13 volumio volumio[978]: info: sendMpdCommand playlistinfo took 21 milliseconds Oct 01 23:08:13 volumio volumio[978]: info: sendMpdCommand playlistinfo took 20 milliseconds Oct 01 23:08:13 volumio volumio[978]: info: sendMpdCommand playlistinfo took 21 milliseconds Oct 01 23:08:13 volumio volumio[978]: verbose: ControllerMpd::parseTrackInfo Oct 01 23:08:13 volumio volumio[978]: info: ControllerMpd::pushState Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::servicePushState Oct 01 23:08:13 volumio volumio[978]: info: CorePlayQueue::getTrack 9 Oct 01 23:08:13 volumio volumio[978]: verbose: STATE SERVICE {"status":"play","position":0,"seek":960,"duration":279,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"657 Kbps","isStreaming":false,"title":"Shape of My Heart","artist":"Sting","album":"Ten Summoner's Tales","uri":"http://192.168.0.41:8200/MediaItems/9573.flac","trackType":"flac"} Oct 01 23:08:13 volumio volumio[978]: verbose: CURRENT POSITION 9 Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::syncState stateService play Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::syncState currentStatus play Oct 01 23:08:13 volumio volumio[978]: info: Received an update from plugin. extracting info from payload Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:08:13 volumio volumio[978]: info: ControllerMpd::pushState Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::servicePushState Oct 01 23:08:13 volumio volumio[978]: info: CorePlayQueue::getTrack 9 Oct 01 23:08:13 volumio volumio[978]: verbose: STATE SERVICE {"status":"play","position":0,"seek":960,"duration":279,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"587 Kbps","isStreaming":false,"title":"Shape of My Heart","artist":"Sting","album":"Ten Summoner's Tales","uri":"http://192.168.0.41:8200/MediaItems/9573.flac","trackType":"flac"} Oct 01 23:08:13 volumio volumio[978]: verbose: CURRENT POSITION 9 Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::syncState stateService play Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::syncState currentStatus play Oct 01 23:08:13 volumio volumio[978]: info: Received an update from plugin. extracting info from payload Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:08:13 volumio volumio[978]: info: ControllerMpd::pushState Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::servicePushState Oct 01 23:08:13 volumio volumio[978]: info: CorePlayQueue::getTrack 9 Oct 01 23:08:13 volumio volumio[978]: verbose: STATE SERVICE {"status":"play","position":0,"seek":960,"duration":279,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"587 Kbps","isStreaming":false,"title":"Shape of My Heart","artist":"Sting","album":"Ten Summoner's Tales","uri":"http://192.168.0.41:8200/MediaItems/9573.flac","trackType":"flac"} Oct 01 23:08:13 volumio volumio[978]: verbose: CURRENT POSITION 9 Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::syncState stateService play Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::syncState currentStatus play Oct 01 23:08:13 volumio volumio[978]: info: Received an update from plugin. extracting info from payload Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:08:13 volumio volumio[978]: info: ControllerMpd::pushState Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::servicePushState Oct 01 23:08:13 volumio volumio[978]: info: CorePlayQueue::getTrack 9 Oct 01 23:08:13 volumio volumio[978]: verbose: STATE SERVICE {"status":"play","position":0,"seek":960,"duration":279,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"587 Kbps","isStreaming":false,"title":"Shape of My Heart","artist":"Sting","album":"Ten Summoner's Tales","uri":"http://192.168.0.41:8200/MediaItems/9573.flac","trackType":"flac"} Oct 01 23:08:13 volumio volumio[978]: verbose: CURRENT POSITION 9 Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::syncState stateService play Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::syncState currentStatus play Oct 01 23:08:13 volumio volumio[978]: info: Received an update from plugin. extracting info from payload Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:08:13 volumio volumio[978]: info: CoreStateMachine::pushState Oct 01 23:08:13 volumio volumio[978]: info: CoreCommandRouter::volumioPushState Oct 01 23:08:13 volumio volumio[978]: info: ------------------------------ 390ms Oct 01 23:08:13 volumio volumio[978]: info: ------------------------------ 193ms Oct 01 23:08:13 volumio volumio[978]: info: ------------------------------ 191ms Oct 01 23:08:13 volumio volumio[978]: info: ------------------------------ 190ms Oct 01 23:08:14 volumio volumio[978]: info: CoreCommandRouter::volumioGetQueue Oct 01 23:08:14 volumio volumio[978]: info: CoreStateMachine::getQueue Oct 01 23:08:14 volumio volumio[978]: info: CorePlayQueue::getQueue Oct 01 23:08:14 volumio volumio[978]: info: CoreCommandRouter::volumioGetQueue Oct 01 23:08:14 volumio volumio[978]: info: CoreStateMachine::getQueue Oct 01 23:08:14 volumio volumio[978]: info: CorePlayQueue::getQueue Oct 01 23:08:14 volumio volumio[978]: info: CoreCommandRouter::volumioGetQueue Oct 01 23:08:14 volumio volumio[978]: info: CoreStateMachine::getQueue Oct 01 23:08:14 volumio volumio[978]: info: CorePlayQueue::getQueue Oct 01 23:08:14 volumio volumio[978]: info: CoreCommandRouter::volumioGetQueue Oct 01 23:08:14 volumio volumio[978]: info: CoreStateMachine::getQueue Oct 01 23:08:14 volumio volumio[978]: info: CorePlayQueue::getQueue Oct 01 23:08:14 volumio volumio[978]: info: CoreCommandRouter::volumioGetQueue Oct 01 23:08:14 volumio volumio[978]: info: CoreStateMachine::getQueue Oct 01 23:08:14 volumio volumio[978]: info: CorePlayQueue::getQueue Oct 01 23:08:14 volumio volumio[978]: info: CoreCommandRouter::volumioGetQueue Oct 01 23:08:14 volumio volumio[978]: info: CoreStateMachine::getQueue Oct 01 23:08:14 volumio volumio[978]: info: CorePlayQueue::getQueue Oct 01 23:08:14 volumio volumio[978]: info: CoreCommandRouter::volumioGetQueue Oct 01 23:08:14 volumio volumio[978]: info: CoreStateMachine::getQueue Oct 01 23:08:14 volumio volumio[978]: info: CorePlayQueue::getQueue Oct 01 23:08:14 volumio volumio[978]: info: CoreCommandRouter::volumioGetQueue Oct 01 23:08:14 volumio volumio[978]: info: CoreStateMachine::getQueue Oct 01 23:08:14 volumio volumio[978]: info: CorePlayQueue::getQueue Oct 01 23:08:14 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:08:14 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:08:14 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:08:14 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:08:14 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:08:14 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:08:14 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:08:14 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:08:14 volumio volumio[978]: error: FusionDsp - WebSocket error: [object Object] Oct 01 23:08:14 volumio volumio[978]: error: FusionDsp - WebSocket error: [object Object] Oct 01 23:08:14 volumio volumio[978]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Oct 01 23:08:14 volumio volumio[978]: 2+0 records in Oct 01 23:08:14 volumio volumio[978]: 2+0 records out Oct 01 23:08:14 volumio volumio[978]: 65536 bytes (66 kB, 64 KiB) copied, 0.000449111 s, 146 MB/s Oct 01 23:08:14 volumio volumio[978]: info: camilladsp spawned new process with pid 1693, instance 1, run: true Oct 01 23:08:14 volumio go-librespot[1148]: time="2024-10-01T23:08:14+02:00" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 104.199.65.124:4070: connect: connection timed out" Oct 01 23:08:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 01 23:08:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 01 23:08:14 volumio volumio[978]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Oct 01 23:08:14 volumio volumio[978]: (node:978) UnhandledPromiseRejectionWarning: Error: socket hang up Oct 01 23:08:14 volumio volumio[978]: at connResetException (internal/errors.js:607:14) Oct 01 23:08:14 volumio volumio[978]: at Socket.socketOnEnd (_http_client.js:493:23) Oct 01 23:08:14 volumio volumio[978]: at Socket.emit (events.js:327:22) Oct 01 23:08:14 volumio volumio[978]: at endReadableNT (internal/streams/readable.js:1327:12) Oct 01 23:08:14 volumio volumio[978]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Oct 01 23:08:14 volumio volumio[978]: (Use `node --trace-warnings ...` to show where the warning was created) Oct 01 23:08:14 volumio volumio[978]: (node:978) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 1) Oct 01 23:08:14 volumio volumio[978]: (node:978) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code. Oct 01 23:08:14 volumio volumio[978]: info: Connection to go-librespot Websocket closed Oct 01 23:08:17 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 01 23:08:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Oct 01 23:08:17 volumio systemd[1]: Stopped go-librespot Daemon. Oct 01 23:08:17 volumio volumio[978]: info: Initializing connection to go-librespot Websocket Oct 01 23:08:17 volumio volumio[978]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 01 23:08:17 volumio systemd[1]: Started go-librespot Daemon. Oct 01 23:08:17 volumio go-librespot[1710]: Librespot-go daemon starting... Oct 01 23:08:17 volumio go-librespot[1710]: time="2024-10-01T23:08:17+02:00" level=info msg="generated new device id: 7a5c8d66439da6036bdafeae1916b7eafdaca5a8" Oct 01 23:08:17 volumio go-librespot[1710]: time="2024-10-01T23:08:17+02:00" level=debug msg="stored credentials found for w6wifrmurdeutkvl4pjjrwi9n" Oct 01 23:08:18 volumio go-librespot[1710]: time="2024-10-01T23:08:18+02:00" level=debug msg="obtained new client token: AAA0Ymp/aKdHBFdjVhcglPZLrmecc2QhfCLIkXfBNwsBGEHUPajHU7+lIQ991bEzlKlu3cGvNL5IGIIdTxUHjqMZ0MewBEOb41QOmsMcTiv9zifZ3gVa5V/BwPzjbdTvYONkw8RAV8ahlKaPexLo3FWgtrUTaw2g+F5J58fCNaSx9wZA5tGgvG71U2nGjEasCDSoD4r2rM65aQ13o2s5kQNY2sCjIyCuzI2kT8BEimZvrzzO8B6TfDa6hhMy" Oct 01 23:08:18 volumio go-librespot[1710]: time="2024-10-01T23:08:18+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 01 23:08:20 volumio volumio[978]: info: Initializing connection to go-librespot Websocket Oct 01 23:08:20 volumio go-librespot[1710]: time="2024-10-01T23:08:20+02:00" level=debug msg="new websocket client" Oct 01 23:08:20 volumio volumio[978]: info: Connection to go-librespot Websocket established Oct 01 23:08:23 volumio volumio[978]: info: Getting Spotify volume Oct 01 23:08:23 volumio volumio[978]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Oct 01 23:08:23 volumio volumio[978]: info: CoreCommandRouter::volumioGetState Oct 01 23:08:23 volumio volumio[978]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 01 23:08:25 volumio volumio[978]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 01 23:08:25 volumio volumio[978]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 01 23:08:25 volumio volumio[978]: TypeError: Cannot read property 'length' of undefined Oct 01 23:08:25 volumio volumio[978]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Oct 01 23:08:25 volumio volumio[978]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Oct 01 23:08:25 volumio volumio[978]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Oct 01 23:08:25 volumio volumio[978]: at Parser.emit (events.js:315:20) Oct 01 23:08:25 volumio volumio[978]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Oct 01 23:08:25 volumio volumio[978]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Oct 01 23:08:25 volumio volumio[978]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Oct 01 23:08:25 volumio volumio[978]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Oct 01 23:08:25 volumio volumio[978]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Oct 01 23:08:25 volumio volumio[978]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Oct 01 23:08:25 volumio volumio[978]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Oct 01 23:08:25 volumio volumio[978]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Oct 01 23:08:25 volumio volumio[978]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Oct 01 23:08:25 volumio volumio[978]: at IncomingMessage.emit (events.js:327:22) Oct 01 23:08:25 volumio volumio[978]: at endReadableNT (internal/streams/readable.js:1327:12) Oct 01 23:08:25 volumio volumio[978]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Oct 01 23:08:25 volumio volumio[978]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 01 23:08:26 volumio sudo[1744]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-01 23:07 Oct 01 23:08:26 volumio sudo[1744]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="bba9e3185e150dd0995f9a49355b34fc6218d5a2" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 05:01:09 PM CEST" VOLUMIO_VERSION="3.757" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="e0a6dc7e914e3fb93cbf2123f2f73eac"