-- Logs begin at Sat 2025-08-30 21:39:10 MSK, end at Sat 2025-08-30 21:43:50 MSK. -- Aug 30 21:42:00 volumio volumio[1109]: info: CoreCommandRouter::volumioPushQueue Aug 30 21:42:00 volumio volumio[1109]: info: CorePlayQueue::saveQueue Aug 30 21:42:00 volumio volumio[1109]: info: CoreStateMachine::updateTrackBlock Aug 30 21:42:00 volumio volumio[1109]: info: CorePlayQueue::getTrackBlock Aug 30 21:42:00 volumio volumio[1109]: info: CoreCommandRouter::volumioPlay Aug 30 21:42:00 volumio volumio[1109]: info: CoreStateMachine::play index 0 Aug 30 21:42:00 volumio volumio[1109]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 21:42:00 volumio volumio[1109]: info: CoreStateMachine::stop Aug 30 21:42:00 volumio volumio[1109]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 21:42:00 volumio volumio[1109]: info: CoreStateMachine::play index undefined Aug 30 21:42:00 volumio volumio[1109]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 21:42:00 volumio volumio[1109]: info: CorePlayQueue::getTrack 0 Aug 30 21:42:00 volumio volumio[1109]: info: CoreStateMachine::startPlaybackTimer Aug 30 21:42:00 volumio volumio[1109]: info: CorePlayQueue::getTrack 0 Aug 30 21:42:00 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand stop Aug 30 21:42:00 volumio volumio[1109]: info: sendMpdCommand stop took 1 milliseconds Aug 30 21:42:00 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand clear Aug 30 21:42:00 volumio volumio[1109]: info: sendMpdCommand clear took 0 milliseconds Aug 30 21:42:00 volumio volumio[1109]: info: Aug 30 21:42:00 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:42:00 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:42:00 volumio volumio[1109]: error: updateQueue error: null Aug 30 21:42:00 volumio volumio[1109]: info: ------------------------------ 1ms Aug 30 21:42:00 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand addid "http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-mar-96.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D1d79565d44efb2471a9e515098e8b4ce822f7270b1e5eb62957f9e608d2a9690%2Clid%3D1548%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c17bd6%2F0%2F4872503%2Fee85dc43.188539156.1.130604695%2F2.mp3&ext=.mp3" Aug 30 21:42:00 volumio volumio[1109]: info: Aug 30 21:42:00 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:42:00 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:42:00 volumio volumio[1109]: info: sendMpdCommand addid "http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-mar-96.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D1d79565d44efb2471a9e515098e8b4ce822f7270b1e5eb62957f9e608d2a9690%2Clid%3D1548%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c17bd6%2F0%2F4872503%2Fee85dc43.188539156.1.130604695%2F2.mp3&ext=.mp3" took 1 milliseconds Aug 30 21:42:00 volumio volumio[1109]: verbose: MPD COMMAND [object Object] Aug 30 21:42:00 volumio volumio[1109]: verbose: MPD COMMAND [object Object] Aug 30 21:42:00 volumio volumio[1109]: verbose: MPD COMMAND [object Object] Aug 30 21:42:00 volumio volumio[1109]: info: Aug 30 21:42:00 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:42:00 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:42:00 volumio volumio[1109]: info: ------------------------------ 1ms Aug 30 21:42:00 volumio volumio[1109]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 30 21:42:00 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand play Aug 30 21:42:00 volumio volumio[1109]: info: ------------------------------ 1ms Aug 30 21:42:00 volumio volumio[1109]: info: sendMpdCommand play took 2 milliseconds Aug 30 21:42:01 volumio volumio[1109]: info: Aug 30 21:42:01 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:42:01 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:42:01 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:42:01 volumio volumio[1109]: info: sendMpdCommand status took 2 milliseconds Aug 30 21:42:01 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:42:01 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 30 21:42:01 volumio volumio[1109]: info: Aug 30 21:42:01 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:42:01 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:42:01 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:42:01 volumio volumio[1109]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 30 21:42:01 volumio volumio[1109]: verbose: ControllerMpd::parseTrackInfo Aug 30 21:42:01 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:42:01 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:42:01 volumio volumio[1109]: info: CorePlayQueue::getTrack 0 Aug 30 21:42:01 volumio volumio[1109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":180,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Идеальный аквариум","artist":"Декор аквариума","album":"Идеальный аквариум","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-mar-96.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D1d79565d44efb2471a9e515098e8b4ce822f7270b1e5eb62957f9e608d2a9690%2Clid%3D1548%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c17bd6%2F0%2F4872503%2Fee85dc43.188539156.1.130604695%2F2.mp3&ext=.mp3","trackType":"mp3"} Aug 30 21:42:01 volumio volumio[1109]: verbose: CURRENT POSITION 0 Aug 30 21:42:01 volumio volumio[1109]: info: CoreStateMachine::syncState stateService play Aug 30 21:42:01 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus stop Aug 30 21:42:01 volumio volumio[1109]: info: ------------------------------ 4ms Aug 30 21:42:01 volumio volumio[1109]: info: sendMpdCommand status took 1 milliseconds Aug 30 21:42:01 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:42:01 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 30 21:42:01 volumio volumio[1109]: info: sendMpdCommand playlistinfo took 0 milliseconds Aug 30 21:42:01 volumio volumio[1109]: verbose: ControllerMpd::parseTrackInfo Aug 30 21:42:01 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:42:01 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:42:01 volumio volumio[1109]: info: CorePlayQueue::getTrack 0 Aug 30 21:42:01 volumio volumio[1109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":754,"duration":180,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Идеальный аквариум","artist":"Декор аквариума","album":"Идеальный аквариум","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-mar-96.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D1d79565d44efb2471a9e515098e8b4ce822f7270b1e5eb62957f9e608d2a9690%2Clid%3D1548%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c17bd6%2F0%2F4872503%2Fee85dc43.188539156.1.130604695%2F2.mp3&ext=.mp3","trackType":"mp3"} Aug 30 21:42:01 volumio volumio[1109]: verbose: CURRENT POSITION 0 Aug 30 21:42:01 volumio volumio[1109]: info: CoreStateMachine::syncState stateService play Aug 30 21:42:01 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus play Aug 30 21:42:01 volumio volumio[1109]: info: Received an update from plugin. extracting info from payload Aug 30 21:42:01 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:42:01 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:42:01 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:42:01 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:42:01 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:42:01 volumio volumio[1109]: info: ------------------------------ 15ms Aug 30 21:42:01 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:42:01 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:42:01 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:42:01 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:42:01 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:42:01 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:42:01 volumio volumio[1109]: info: Preload queue cleared Aug 30 21:42:01 volumio volumio[1109]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 30 21:42:01 volumio volumio[1109]: info: CoreStateMachine::ClearQueue Aug 30 21:42:01 volumio volumio[1109]: info: CoreStateMachine::stop Aug 30 21:42:01 volumio volumio[1109]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 21:42:01 volumio volumio[1109]: info: CoreStateMachine::stPlaybackTimer Aug 30 21:42:01 volumio volumio[1109]: info: CoreStateMachine::updateTrackBlock Aug 30 21:42:01 volumio volumio[1109]: info: CorePlayQueue::getTrackBlock Aug 30 21:42:01 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:42:01 volumio volumio[1109]: info: CorePlayQueue::getTrack 0 Aug 30 21:42:01 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:42:01 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:42:01 volumio volumio[1109]: info: CoreStateMachine::serviceStop Aug 30 21:42:01 volumio volumio[1109]: info: CorePlayQueue::getTrack 0 Aug 30 21:42:01 volumio volumio[1109]: info: CoreCommandRouter::serviceStop Aug 30 21:42:01 volumio volumio[1109]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 30 21:42:01 volumio volumio[1109]: info: ControllerMpd::stop Aug 30 21:42:01 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand stop Aug 30 21:42:01 volumio volumio[1109]: info: CorePlayQueue::clearPlayQueue Aug 30 21:42:01 volumio volumio[1109]: info: CorePlayQueue::saveQueue Aug 30 21:42:01 volumio volumio[1109]: info: CoreCommandRouter::volumioPushQueue Aug 30 21:42:01 volumio volumio[1109]: info: CoreStateMachine::addQueueItems Aug 30 21:42:01 volumio volumio[1109]: info: CorePlayQueue::addQueueItems Aug 30 21:42:01 volumio volumio[1109]: info: Preload queue cleared Aug 30 21:42:01 volumio volumio[1109]: info: Adding Item to queue: yandex_music/artist/22937915 Aug 30 21:42:01 volumio volumio[1109]: info: Using cached record of: yandex_music/artist/22937915 Aug 30 21:42:01 volumio volumio[1109]: info: CoreCommandRouter::volumioPushQueue Aug 30 21:42:01 volumio volumio[1109]: info: CorePlayQueue::saveQueue Aug 30 21:42:01 volumio volumio[1109]: info: CoreStateMachine::updateTrackBlock Aug 30 21:42:01 volumio volumio[1109]: info: CorePlayQueue::getTrackBlock Aug 30 21:42:01 volumio volumio[1109]: info: CoreCommandRouter::volumioPlay Aug 30 21:42:01 volumio volumio[1109]: info: CoreStateMachine::play index 0 Aug 30 21:42:01 volumio volumio[1109]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 21:42:01 volumio volumio[1109]: info: CoreStateMachine::stop Aug 30 21:42:01 volumio volumio[1109]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 21:42:01 volumio volumio[1109]: info: CoreStateMachine::play index undefined Aug 30 21:42:01 volumio volumio[1109]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 21:42:01 volumio volumio[1109]: info: CorePlayQueue::getTrack 0 Aug 30 21:42:01 volumio volumio[1109]: info: CoreStateMachine::startPlaybackTimer Aug 30 21:42:01 volumio volumio[1109]: info: CorePlayQueue::getTrack 0 Aug 30 21:42:01 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand stop Aug 30 21:42:01 volumio volumio[1109]: info: Aug 30 21:42:01 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:42:01 volumio volumio[1109]: info: sendMpdCommand stop took 22 milliseconds Aug 30 21:42:01 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:42:01 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:42:01 volumio volumio[1109]: info: sendMpdCommand stop took 12 milliseconds Aug 30 21:42:01 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand clear Aug 30 21:42:01 volumio volumio[1109]: info: Aug 30 21:42:01 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:42:01 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:42:01 volumio volumio[1109]: info: sendMpdCommand status took 0 milliseconds Aug 30 21:42:01 volumio volumio[1109]: info: sendMpdCommand clear took 0 milliseconds Aug 30 21:42:01 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:42:01 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 30 21:42:01 volumio volumio[1109]: error: updateQueue error: null Aug 30 21:42:01 volumio volumio[1109]: info: ------------------------------ 3ms Aug 30 21:42:01 volumio volumio[1109]: info: sendMpdCommand playlistinfo took 2 milliseconds Aug 30 21:42:01 volumio volumio[1109]: verbose: ControllerMpd::parseTrackInfo Aug 30 21:42:01 volumio volumio[1109]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Aug 30 21:42:01 volumio volumio[1109]: info: ------------------------------ 5ms Aug 30 21:42:01 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand addid "http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-spbmiran-21.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D8338b94da741afd69a9cbdba65c81cc66fd0648579e373410ef1738e85acb4d0%2Clid%3D1506%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c17bd6%2F0%2F4872503%2Fee85dc43.188539156.1.130604695%2F2.mp3&ext=.mp3" Aug 30 21:42:01 volumio volumio[1109]: info: Aug 30 21:42:01 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:42:01 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:42:01 volumio volumio[1109]: info: sendMpdCommand addid "http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-spbmiran-21.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D8338b94da741afd69a9cbdba65c81cc66fd0648579e373410ef1738e85acb4d0%2Clid%3D1506%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c17bd6%2F0%2F4872503%2Fee85dc43.188539156.1.130604695%2F2.mp3&ext=.mp3" took 1 milliseconds Aug 30 21:42:01 volumio volumio[1109]: verbose: MPD COMMAND [object Object] Aug 30 21:42:01 volumio volumio[1109]: verbose: MPD COMMAND [object Object] Aug 30 21:42:01 volumio volumio[1109]: verbose: MPD COMMAND [object Object] Aug 30 21:42:01 volumio volumio[1109]: info: Aug 30 21:42:01 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:42:01 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:42:01 volumio volumio[1109]: info: ------------------------------ 1ms Aug 30 21:42:01 volumio volumio[1109]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 30 21:42:01 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand play Aug 30 21:42:01 volumio volumio[1109]: info: ------------------------------ 0ms Aug 30 21:42:01 volumio volumio[1109]: info: sendMpdCommand play took 1 milliseconds Aug 30 21:42:02 volumio volumio[1109]: info: Aug 30 21:42:02 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:42:02 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:42:02 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:42:02 volumio volumio[1109]: info: Aug 30 21:42:02 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:42:02 volumio volumio[1109]: info: sendMpdCommand status took 3 milliseconds Aug 30 21:42:02 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:42:02 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:42:02 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:42:02 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 30 21:42:02 volumio volumio[1109]: info: sendMpdCommand status took 1 milliseconds Aug 30 21:42:02 volumio volumio[1109]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 30 21:42:02 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:42:02 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 30 21:42:02 volumio volumio[1109]: verbose: ControllerMpd::parseTrackInfo Aug 30 21:42:02 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:42:02 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:42:02 volumio volumio[1109]: info: CorePlayQueue::getTrack 0 Aug 30 21:42:02 volumio volumio[1109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":180,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Идеальный аквариум","artist":"Декор аквариума","album":"Идеальный аквариум","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-spbmiran-21.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D8338b94da741afd69a9cbdba65c81cc66fd0648579e373410ef1738e85acb4d0%2Clid%3D1506%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c17bd6%2F0%2F4872503%2Fee85dc43.188539156.1.130604695%2F2.mp3&ext=.mp3","trackType":"mp3"} Aug 30 21:42:02 volumio volumio[1109]: verbose: CURRENT POSITION 0 Aug 30 21:42:02 volumio volumio[1109]: info: CoreStateMachine::syncState stateService play Aug 30 21:42:02 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus stop Aug 30 21:42:02 volumio volumio[1109]: info: ------------------------------ 6ms Aug 30 21:42:02 volumio volumio[1109]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 30 21:42:02 volumio volumio[1109]: verbose: ControllerMpd::parseTrackInfo Aug 30 21:42:02 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:42:02 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:42:02 volumio volumio[1109]: info: CorePlayQueue::getTrack 0 Aug 30 21:42:02 volumio volumio[1109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":728,"duration":180,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Идеальный аквариум","artist":"Декор аквариума","album":"Идеальный аквариум","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-spbmiran-21.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D8338b94da741afd69a9cbdba65c81cc66fd0648579e373410ef1738e85acb4d0%2Clid%3D1506%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c17bd6%2F0%2F4872503%2Fee85dc43.188539156.1.130604695%2F2.mp3&ext=.mp3","trackType":"mp3"} Aug 30 21:42:02 volumio volumio[1109]: verbose: CURRENT POSITION 0 Aug 30 21:42:02 volumio volumio[1109]: info: CoreStateMachine::syncState stateService play Aug 30 21:42:02 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus play Aug 30 21:42:02 volumio volumio[1109]: info: Received an update from plugin. extracting info from payload Aug 30 21:42:02 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:42:02 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:42:02 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:42:02 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:42:02 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:42:02 volumio volumio[1109]: info: ------------------------------ 14ms Aug 30 21:42:02 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:42:02 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:42:02 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:42:02 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:42:02 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:42:02 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:42:03 volumio volumio[1109]: info: CoreCommandRouter::volumioGetState Aug 30 21:42:03 volumio sudo[3012]: root : TTY=unknown ; PWD=/data/plugins/user_interface/peppy_screensaver ; USER=root ; COMMAND=/bin/bash run_peppymeter.sh Aug 30 21:42:03 volumio sudo[3012]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 30 21:42:04 volumio volumio[1109]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 12 Aug 30 21:42:04 volumio volumio[1109]: info: CoreCommandRouter::volumioGetState Aug 30 21:42:04 volumio volumio[1109]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 13 Aug 30 21:42:04 volumio volumio[1109]: info: CoreCommandRouter::volumioGetState Aug 30 21:42:09 volumio volumio[1109]: info: CoreCommandRouter::volumioNext Aug 30 21:42:09 volumio volumio[1109]: info: CoreStateMachine::next Aug 30 21:42:09 volumio volumio[1109]: info: ControllerMpd::next Aug 30 21:42:09 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand next Aug 30 21:42:09 volumio volumio[1109]: info: sendMpdCommand next took 5 milliseconds Aug 30 21:42:09 volumio volumio[1109]: info: Aug 30 21:42:09 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:42:09 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:42:09 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:42:09 volumio volumio[1109]: info: sendMpdCommand status took 1 milliseconds Aug 30 21:42:09 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:42:09 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:42:09 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:42:09 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:42:09 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:42:09 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:42:09 volumio volumio[1109]: info: CorePlayQueue::getTrack 0 Aug 30 21:42:09 volumio volumio[1109]: 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} Aug 30 21:42:09 volumio volumio[1109]: verbose: CURRENT POSITION 0 Aug 30 21:42:09 volumio volumio[1109]: info: CoreStateMachine::syncState stateService stop Aug 30 21:42:09 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus play Aug 30 21:42:09 volumio volumio[1109]: info: CoreStateMachine::play index undefined Aug 30 21:42:09 volumio volumio[1109]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 21:42:09 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:42:09 volumio volumio[1109]: info: CorePlayQueue::getTrack 1 Aug 30 21:42:09 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:42:09 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:42:09 volumio volumio[1109]: info: CorePlayQueue::getTrack 1 Aug 30 21:42:09 volumio volumio[1109]: info: CoreStateMachine::startPlaybackTimer Aug 30 21:42:09 volumio volumio[1109]: info: CorePlayQueue::getTrack 1 Aug 30 21:42:09 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand stop Aug 30 21:42:09 volumio volumio[1109]: info: ------------------------------ 13ms Aug 30 21:42:09 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:42:09 volumio volumio[1109]: info: CorePlayQueue::getTrack 1 Aug 30 21:42:09 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:42:09 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:42:09 volumio volumio[1109]: info: sendMpdCommand stop took 14 milliseconds Aug 30 21:42:09 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand clear Aug 30 21:42:09 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:42:09 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:42:09 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:42:09 volumio volumio[1109]: info: Aug 30 21:42:09 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:42:09 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:42:09 volumio volumio[1109]: info: sendMpdCommand clear took 9 milliseconds Aug 30 21:42:09 volumio volumio[1109]: error: updateQueue error: null Aug 30 21:42:09 volumio volumio[1109]: info: ------------------------------ 5ms Aug 30 21:42:10 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand addid "http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-m9-18.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D55e0c700094d31cbe30b965442c7dfc8b1ade19147a20bd4c195f4f67a4fe1a4%2Clid%3D1521%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c19cd9%2F0%2F10243567%2F5d288d01.188539160.1.130604698%2F2.mp3&ext=.mp3" Aug 30 21:42:10 volumio volumio[1109]: info: Aug 30 21:42:10 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:42:10 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:42:10 volumio volumio[1109]: info: sendMpdCommand addid "http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-m9-18.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D55e0c700094d31cbe30b965442c7dfc8b1ade19147a20bd4c195f4f67a4fe1a4%2Clid%3D1521%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c19cd9%2F0%2F10243567%2F5d288d01.188539160.1.130604698%2F2.mp3&ext=.mp3" took 1 milliseconds Aug 30 21:42:10 volumio volumio[1109]: verbose: MPD COMMAND [object Object] Aug 30 21:42:10 volumio volumio[1109]: verbose: MPD COMMAND [object Object] Aug 30 21:42:10 volumio volumio[1109]: verbose: MPD COMMAND [object Object] Aug 30 21:42:10 volumio volumio[1109]: info: Aug 30 21:42:10 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:42:10 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:42:10 volumio volumio[1109]: info: ------------------------------ 0ms Aug 30 21:42:10 volumio volumio[1109]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 30 21:42:10 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand play Aug 30 21:42:10 volumio volumio[1109]: info: ------------------------------ 1ms Aug 30 21:42:10 volumio volumio[1109]: info: sendMpdCommand play took 0 milliseconds Aug 30 21:42:10 volumio volumio[1109]: info: Aug 30 21:42:10 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:42:10 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:42:10 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:42:10 volumio volumio[1109]: info: Aug 30 21:42:10 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:42:10 volumio volumio[1109]: info: sendMpdCommand status took 1 milliseconds Aug 30 21:42:10 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:42:10 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:42:10 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:42:10 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 30 21:42:10 volumio volumio[1109]: info: sendMpdCommand status took 0 milliseconds Aug 30 21:42:10 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:42:10 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 30 21:42:10 volumio volumio[1109]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 30 21:42:10 volumio volumio[1109]: verbose: ControllerMpd::parseTrackInfo Aug 30 21:42:10 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:42:10 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:42:10 volumio volumio[1109]: info: CorePlayQueue::getTrack 1 Aug 30 21:42:10 volumio volumio[1109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":180,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Аквариум мечты","artist":"Декор аквариума","album":"Идеальный аквариум","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-m9-18.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D55e0c700094d31cbe30b965442c7dfc8b1ade19147a20bd4c195f4f67a4fe1a4%2Clid%3D1521%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c19cd9%2F0%2F10243567%2F5d288d01.188539160.1.130604698%2F2.mp3&ext=.mp3","trackType":"mp3"} Aug 30 21:42:10 volumio volumio[1109]: verbose: CURRENT POSITION 1 Aug 30 21:42:10 volumio volumio[1109]: info: CoreStateMachine::syncState stateService play Aug 30 21:42:10 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus stop Aug 30 21:42:10 volumio volumio[1109]: info: ------------------------------ 5ms Aug 30 21:42:10 volumio volumio[1109]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 30 21:42:10 volumio volumio[1109]: verbose: ControllerMpd::parseTrackInfo Aug 30 21:42:10 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:42:10 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:42:10 volumio volumio[1109]: info: CorePlayQueue::getTrack 1 Aug 30 21:42:10 volumio volumio[1109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":353,"duration":180,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Аквариум мечты","artist":"Декор аквариума","album":"Идеальный аквариум","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-m9-18.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D55e0c700094d31cbe30b965442c7dfc8b1ade19147a20bd4c195f4f67a4fe1a4%2Clid%3D1521%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c19cd9%2F0%2F10243567%2F5d288d01.188539160.1.130604698%2F2.mp3&ext=.mp3","trackType":"mp3"} Aug 30 21:42:10 volumio volumio[1109]: verbose: CURRENT POSITION 1 Aug 30 21:42:10 volumio volumio[1109]: info: CoreStateMachine::syncState stateService play Aug 30 21:42:10 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus play Aug 30 21:42:10 volumio volumio[1109]: info: Received an update from plugin. extracting info from payload Aug 30 21:42:10 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:42:10 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:42:10 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:42:10 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:42:10 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:42:10 volumio volumio[1109]: info: ------------------------------ 20ms Aug 30 21:42:10 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:42:10 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:42:10 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:42:10 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:42:10 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:42:10 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:42:13 volumio volumio[1109]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 13 Aug 30 21:42:13 volumio volumio[1109]: info: CoreCommandRouter::volumioGetState Aug 30 21:42:16 volumio volumio[1109]: info: Preload queue cleared Aug 30 21:42:16 volumio volumio[1109]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 30 21:42:16 volumio volumio[1109]: info: CoreStateMachine::ClearQueue Aug 30 21:42:16 volumio volumio[1109]: info: CoreStateMachine::stop Aug 30 21:42:16 volumio volumio[1109]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 21:42:16 volumio volumio[1109]: info: CoreStateMachine::stPlaybackTimer Aug 30 21:42:16 volumio volumio[1109]: info: CoreStateMachine::updateTrackBlock Aug 30 21:42:16 volumio volumio[1109]: info: CorePlayQueue::getTrackBlock Aug 30 21:42:16 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:42:16 volumio volumio[1109]: info: CorePlayQueue::getTrack 1 Aug 30 21:42:16 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:42:16 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:42:16 volumio volumio[1109]: info: CoreStateMachine::serviceStop Aug 30 21:42:16 volumio volumio[1109]: info: CorePlayQueue::getTrack 1 Aug 30 21:42:16 volumio volumio[1109]: info: CoreCommandRouter::serviceStop Aug 30 21:42:16 volumio volumio[1109]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 30 21:42:16 volumio volumio[1109]: info: ControllerMpd::stop Aug 30 21:42:16 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand stop Aug 30 21:42:16 volumio volumio[1109]: info: CorePlayQueue::clearPlayQueue Aug 30 21:42:16 volumio volumio[1109]: info: CorePlayQueue::saveQueue Aug 30 21:42:16 volumio volumio[1109]: info: CoreCommandRouter::volumioPushQueue Aug 30 21:42:16 volumio volumio[1109]: info: CoreStateMachine::addQueueItems Aug 30 21:42:16 volumio volumio[1109]: info: CorePlayQueue::addQueueItems Aug 30 21:42:16 volumio volumio[1109]: info: Preload queue cleared Aug 30 21:42:16 volumio volumio[1109]: info: Adding Item to queue: yandex_music/album/33575436 Aug 30 21:42:16 volumio volumio[1109]: info: Exploding uri yandex_music/album/33575436 in service yandex_music Aug 30 21:42:16 volumio volumio[1109]: info: Aug 30 21:42:16 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:42:16 volumio volumio[1109]: info: sendMpdCommand stop took 22 milliseconds Aug 30 21:42:16 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:42:16 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:42:16 volumio volumio[1109]: info: sendMpdCommand status took 4 milliseconds Aug 30 21:42:16 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:42:16 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 30 21:42:16 volumio volumio[1109]: info: sendMpdCommand playlistinfo took 0 milliseconds Aug 30 21:42:16 volumio volumio[1109]: verbose: ControllerMpd::parseTrackInfo Aug 30 21:42:16 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:42:16 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:42:16 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:42:16 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:42:16 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:42:16 volumio volumio[1109]: info: CorePlayQueue::getTrack 1 Aug 30 21:42:16 volumio volumio[1109]: 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":"Аквариум мечты","artist":"Декор аквариума","album":"Идеальный аквариум","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-m9-18.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D55e0c700094d31cbe30b965442c7dfc8b1ade19147a20bd4c195f4f67a4fe1a4%2Clid%3D1521%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c19cd9%2F0%2F10243567%2F5d288d01.188539160.1.130604698%2F2.mp3&ext=.mp3","trackType":"mp3"} Aug 30 21:42:16 volumio volumio[1109]: verbose: CURRENT POSITION 1 Aug 30 21:42:16 volumio volumio[1109]: info: CoreStateMachine::syncState stateService stop Aug 30 21:42:16 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus stop Aug 30 21:42:16 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:42:16 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:42:16 volumio volumio[1109]: info: No code Aug 30 21:42:16 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:42:16 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:42:16 volumio volumio[1109]: info: ------------------------------ 30ms Aug 30 21:42:16 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:42:16 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:42:16 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:42:16 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:42:16 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:42:16 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:42:16 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:42:16 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:42:16 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:42:16 volumio volumio[1109]: info: CoreCommandRouter::volumioPushQueue Aug 30 21:42:16 volumio volumio[1109]: info: CorePlayQueue::saveQueue Aug 30 21:42:16 volumio volumio[1109]: info: CoreStateMachine::updateTrackBlock Aug 30 21:42:16 volumio volumio[1109]: info: CorePlayQueue::getTrackBlock Aug 30 21:42:16 volumio volumio[1109]: info: CoreCommandRouter::volumioPlay Aug 30 21:42:16 volumio volumio[1109]: info: CoreStateMachine::play index 0 Aug 30 21:42:16 volumio volumio[1109]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 21:42:16 volumio volumio[1109]: info: CoreStateMachine::stop Aug 30 21:42:16 volumio volumio[1109]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 21:42:16 volumio volumio[1109]: info: CoreStateMachine::play index undefined Aug 30 21:42:16 volumio volumio[1109]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 21:42:16 volumio volumio[1109]: info: CorePlayQueue::getTrack 0 Aug 30 21:42:16 volumio volumio[1109]: info: CoreStateMachine::startPlaybackTimer Aug 30 21:42:16 volumio volumio[1109]: info: CorePlayQueue::getTrack 0 Aug 30 21:42:16 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand stop Aug 30 21:42:16 volumio volumio[1109]: info: sendMpdCommand stop took 2 milliseconds Aug 30 21:42:16 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand clear Aug 30 21:42:16 volumio volumio[1109]: info: Aug 30 21:42:16 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:42:16 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:42:16 volumio volumio[1109]: info: sendMpdCommand clear took 1 milliseconds Aug 30 21:42:16 volumio volumio[1109]: error: updateQueue error: null Aug 30 21:42:16 volumio volumio[1109]: info: ------------------------------ 4ms Aug 30 21:42:16 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand addid "http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-spbmiran-10.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3Db4e010342f5746f70c70efdea5f347935ca0a5ad55065d57fcb28f6348d19693%2Clid%3D1506%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c14fa0%2F0%2F483339%2F51d3fb20.190980063.18.131853780%2F320.mp3&ext=.mp3" Aug 30 21:42:16 volumio volumio[1109]: info: Aug 30 21:42:16 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:42:16 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:42:16 volumio volumio[1109]: info: sendMpdCommand addid "http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-spbmiran-10.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3Db4e010342f5746f70c70efdea5f347935ca0a5ad55065d57fcb28f6348d19693%2Clid%3D1506%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c14fa0%2F0%2F483339%2F51d3fb20.190980063.18.131853780%2F320.mp3&ext=.mp3" took 0 milliseconds Aug 30 21:42:16 volumio volumio[1109]: verbose: MPD COMMAND [object Object] Aug 30 21:42:16 volumio volumio[1109]: verbose: MPD COMMAND [object Object] Aug 30 21:42:16 volumio volumio[1109]: verbose: MPD COMMAND [object Object] Aug 30 21:42:16 volumio volumio[1109]: info: Aug 30 21:42:16 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:42:16 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:42:16 volumio volumio[1109]: info: ------------------------------ 1ms Aug 30 21:42:16 volumio volumio[1109]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 30 21:42:16 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand play Aug 30 21:42:16 volumio volumio[1109]: info: ------------------------------ 1ms Aug 30 21:42:16 volumio volumio[1109]: info: sendMpdCommand play took 1 milliseconds Aug 30 21:42:17 volumio volumio[1109]: info: Aug 30 21:42:17 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:42:17 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:42:17 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:42:17 volumio volumio[1109]: info: Aug 30 21:42:17 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:42:17 volumio volumio[1109]: info: sendMpdCommand status took 4 milliseconds Aug 30 21:42:17 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:42:17 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:42:17 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:42:17 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 30 21:42:17 volumio volumio[1109]: info: sendMpdCommand status took 1 milliseconds Aug 30 21:42:17 volumio volumio[1109]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 30 21:42:17 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:42:17 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 30 21:42:17 volumio volumio[1109]: verbose: ControllerMpd::parseTrackInfo Aug 30 21:42:17 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:42:17 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:42:17 volumio volumio[1109]: info: CorePlayQueue::getTrack 0 Aug 30 21:42:17 volumio volumio[1109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":298,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"К вершинам успеха","artist":"Музыка для расслабления вашей жизни","album":"Завораживающая природа","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-spbmiran-10.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3Db4e010342f5746f70c70efdea5f347935ca0a5ad55065d57fcb28f6348d19693%2Clid%3D1506%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c14fa0%2F0%2F483339%2F51d3fb20.190980063.18.131853780%2F320.mp3&ext=.mp3","trackType":"mp3"} Aug 30 21:42:17 volumio volumio[1109]: verbose: CURRENT POSITION 0 Aug 30 21:42:17 volumio volumio[1109]: info: CoreStateMachine::syncState stateService play Aug 30 21:42:17 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus stop Aug 30 21:42:17 volumio volumio[1109]: info: ------------------------------ 7ms Aug 30 21:42:17 volumio volumio[1109]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 30 21:42:17 volumio volumio[1109]: verbose: ControllerMpd::parseTrackInfo Aug 30 21:42:17 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:42:17 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:42:17 volumio volumio[1109]: info: CorePlayQueue::getTrack 0 Aug 30 21:42:17 volumio volumio[1109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":781,"duration":298,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"К вершинам успеха","artist":"Музыка для расслабления вашей жизни","album":"Завораживающая природа","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-spbmiran-10.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3Db4e010342f5746f70c70efdea5f347935ca0a5ad55065d57fcb28f6348d19693%2Clid%3D1506%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c14fa0%2F0%2F483339%2F51d3fb20.190980063.18.131853780%2F320.mp3&ext=.mp3","trackType":"mp3"} Aug 30 21:42:17 volumio volumio[1109]: verbose: CURRENT POSITION 0 Aug 30 21:42:17 volumio volumio[1109]: info: CoreStateMachine::syncState stateService play Aug 30 21:42:17 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus play Aug 30 21:42:17 volumio volumio[1109]: info: Received an update from plugin. extracting info from payload Aug 30 21:42:17 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:42:17 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:42:17 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:42:17 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:42:17 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:42:17 volumio volumio[1109]: info: ------------------------------ 18ms Aug 30 21:42:17 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:42:17 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:42:17 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:42:17 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:42:17 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:42:17 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:42:20 volumio volumio[1109]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 13 Aug 30 21:42:20 volumio volumio[1109]: info: CoreCommandRouter::volumioGetState Aug 30 21:42:22 volumio volumio[1109]: info: CoreCommandRouter::volumioNext Aug 30 21:42:22 volumio volumio[1109]: info: CoreStateMachine::next Aug 30 21:42:22 volumio volumio[1109]: info: ControllerMpd::next Aug 30 21:42:22 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand next Aug 30 21:42:22 volumio volumio[1109]: info: sendMpdCommand next took 6 milliseconds Aug 30 21:42:22 volumio volumio[1109]: info: Aug 30 21:42:22 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:42:22 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:42:22 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:42:22 volumio volumio[1109]: info: sendMpdCommand status took 1 milliseconds Aug 30 21:42:22 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:42:22 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:42:22 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:42:22 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:42:22 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:42:22 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:42:22 volumio volumio[1109]: info: CorePlayQueue::getTrack 0 Aug 30 21:42:22 volumio volumio[1109]: 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} Aug 30 21:42:22 volumio volumio[1109]: verbose: CURRENT POSITION 0 Aug 30 21:42:22 volumio volumio[1109]: info: CoreStateMachine::syncState stateService stop Aug 30 21:42:22 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus play Aug 30 21:42:22 volumio volumio[1109]: info: CoreStateMachine::play index undefined Aug 30 21:42:22 volumio volumio[1109]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 21:42:22 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:42:22 volumio volumio[1109]: info: CorePlayQueue::getTrack 1 Aug 30 21:42:22 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:42:22 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:42:22 volumio volumio[1109]: info: CorePlayQueue::getTrack 1 Aug 30 21:42:22 volumio volumio[1109]: info: CoreStateMachine::startPlaybackTimer Aug 30 21:42:22 volumio volumio[1109]: info: CorePlayQueue::getTrack 1 Aug 30 21:42:22 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand stop Aug 30 21:42:22 volumio volumio[1109]: info: ------------------------------ 16ms Aug 30 21:42:22 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:42:22 volumio volumio[1109]: info: CorePlayQueue::getTrack 1 Aug 30 21:42:22 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:42:22 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:42:22 volumio volumio[1109]: info: sendMpdCommand stop took 10 milliseconds Aug 30 21:42:22 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand clear Aug 30 21:42:22 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:42:22 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:42:22 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:42:22 volumio volumio[1109]: info: Aug 30 21:42:22 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:42:22 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:42:22 volumio volumio[1109]: info: sendMpdCommand clear took 7 milliseconds Aug 30 21:42:22 volumio volumio[1109]: error: updateQueue error: null Aug 30 21:42:22 volumio volumio[1109]: info: ------------------------------ 4ms Aug 30 21:42:22 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand addid "http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-spbmiran-22.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D362146eff2bc8f099617a2741421d8e1c045ed5e2ca487fc5543b818e99f1f39%2Clid%3D1507%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c07db5%2F0%2F16261%2F0878ceb7.190980065.18.131853781%2F320.mp3&ext=.mp3" Aug 30 21:42:22 volumio volumio[1109]: info: Aug 30 21:42:22 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:42:22 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:42:22 volumio volumio[1109]: info: sendMpdCommand addid "http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-spbmiran-22.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D362146eff2bc8f099617a2741421d8e1c045ed5e2ca487fc5543b818e99f1f39%2Clid%3D1507%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c07db5%2F0%2F16261%2F0878ceb7.190980065.18.131853781%2F320.mp3&ext=.mp3" took 1 milliseconds Aug 30 21:42:22 volumio volumio[1109]: verbose: MPD COMMAND [object Object] Aug 30 21:42:22 volumio volumio[1109]: verbose: MPD COMMAND [object Object] Aug 30 21:42:22 volumio volumio[1109]: verbose: MPD COMMAND [object Object] Aug 30 21:42:22 volumio volumio[1109]: info: Aug 30 21:42:22 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:42:22 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:42:22 volumio volumio[1109]: info: ------------------------------ 1ms Aug 30 21:42:22 volumio volumio[1109]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 30 21:42:22 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand play Aug 30 21:42:22 volumio volumio[1109]: info: ------------------------------ 2ms Aug 30 21:42:22 volumio volumio[1109]: info: sendMpdCommand play took 1 milliseconds Aug 30 21:42:24 volumio volumio[1109]: info: Aug 30 21:42:24 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:42:24 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:42:24 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:42:24 volumio volumio[1109]: info: Aug 30 21:42:24 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:42:24 volumio volumio[1109]: info: sendMpdCommand status took 4 milliseconds Aug 30 21:42:24 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:42:24 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:42:24 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:42:24 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 30 21:42:24 volumio volumio[1109]: info: sendMpdCommand status took 0 milliseconds Aug 30 21:42:24 volumio volumio[1109]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 30 21:42:24 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:42:24 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 30 21:42:24 volumio volumio[1109]: verbose: ControllerMpd::parseTrackInfo Aug 30 21:42:24 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:42:24 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:42:24 volumio volumio[1109]: info: CorePlayQueue::getTrack 1 Aug 30 21:42:24 volumio volumio[1109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":298,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Летние поля","artist":"Музыка для расслабления вашей жизни","album":"Завораживающая природа","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-spbmiran-22.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D362146eff2bc8f099617a2741421d8e1c045ed5e2ca487fc5543b818e99f1f39%2Clid%3D1507%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c07db5%2F0%2F16261%2F0878ceb7.190980065.18.131853781%2F320.mp3&ext=.mp3","trackType":"mp3"} Aug 30 21:42:24 volumio volumio[1109]: verbose: CURRENT POSITION 1 Aug 30 21:42:24 volumio volumio[1109]: info: CoreStateMachine::syncState stateService play Aug 30 21:42:24 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus stop Aug 30 21:42:24 volumio volumio[1109]: info: ------------------------------ 6ms Aug 30 21:42:24 volumio volumio[1109]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 30 21:42:24 volumio volumio[1109]: verbose: ControllerMpd::parseTrackInfo Aug 30 21:42:24 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:42:24 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:42:24 volumio volumio[1109]: info: CorePlayQueue::getTrack 1 Aug 30 21:42:24 volumio volumio[1109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":781,"duration":298,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Летние поля","artist":"Музыка для расслабления вашей жизни","album":"Завораживающая природа","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-spbmiran-22.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D362146eff2bc8f099617a2741421d8e1c045ed5e2ca487fc5543b818e99f1f39%2Clid%3D1507%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c07db5%2F0%2F16261%2F0878ceb7.190980065.18.131853781%2F320.mp3&ext=.mp3","trackType":"mp3"} Aug 30 21:42:24 volumio volumio[1109]: verbose: CURRENT POSITION 1 Aug 30 21:42:24 volumio volumio[1109]: info: CoreStateMachine::syncState stateService play Aug 30 21:42:24 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus play Aug 30 21:42:24 volumio volumio[1109]: info: Received an update from plugin. extracting info from payload Aug 30 21:42:24 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:42:24 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:42:24 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:42:24 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:42:24 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:42:24 volumio volumio[1109]: info: ------------------------------ 16ms Aug 30 21:42:24 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:42:24 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:42:24 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:42:24 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:42:24 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:42:24 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:42:25 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 30 21:42:25 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 30 21:42:25 volumio volumio[1109]: info: Discovery: Getting this device information Aug 30 21:42:25 volumio volumio[1109]: info: CoreCommandRouter::volumioGetState Aug 30 21:42:25 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 30 21:42:27 volumio volumio[1109]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 13 Aug 30 21:42:27 volumio volumio[1109]: info: CoreCommandRouter::volumioGetState Aug 30 21:42:55 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 30 21:42:55 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 30 21:42:55 volumio volumio[1109]: info: Discovery: Getting this device information Aug 30 21:42:55 volumio volumio[1109]: info: CoreCommandRouter::volumioGetState Aug 30 21:42:55 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 30 21:43:03 volumio volumio[1109]: info: CoreCommandRouter::volumioNext Aug 30 21:43:03 volumio volumio[1109]: info: CoreStateMachine::next Aug 30 21:43:03 volumio volumio[1109]: info: ControllerMpd::next Aug 30 21:43:03 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand next Aug 30 21:43:03 volumio volumio[1109]: info: sendMpdCommand next took 9 milliseconds Aug 30 21:43:03 volumio volumio[1109]: info: Aug 30 21:43:03 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:43:03 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:43:03 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:43:03 volumio volumio[1109]: info: sendMpdCommand status took 0 milliseconds Aug 30 21:43:03 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:43:03 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:43:03 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:43:03 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:03 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:43:03 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:03 volumio volumio[1109]: info: CorePlayQueue::getTrack 1 Aug 30 21:43:03 volumio volumio[1109]: 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} Aug 30 21:43:03 volumio volumio[1109]: verbose: CURRENT POSITION 1 Aug 30 21:43:03 volumio volumio[1109]: info: CoreStateMachine::syncState stateService stop Aug 30 21:43:03 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus play Aug 30 21:43:03 volumio volumio[1109]: info: CoreStateMachine::play index undefined Aug 30 21:43:03 volumio volumio[1109]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 21:43:03 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:03 volumio volumio[1109]: info: CorePlayQueue::getTrack 2 Aug 30 21:43:03 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:43:03 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:03 volumio volumio[1109]: info: CorePlayQueue::getTrack 2 Aug 30 21:43:03 volumio volumio[1109]: info: CoreStateMachine::startPlaybackTimer Aug 30 21:43:03 volumio volumio[1109]: info: CorePlayQueue::getTrack 2 Aug 30 21:43:03 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand stop Aug 30 21:43:03 volumio volumio[1109]: info: ------------------------------ 22ms Aug 30 21:43:03 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:03 volumio volumio[1109]: info: CorePlayQueue::getTrack 2 Aug 30 21:43:03 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:43:03 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:03 volumio volumio[1109]: info: sendMpdCommand stop took 10 milliseconds Aug 30 21:43:03 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand clear Aug 30 21:43:03 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:43:03 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:43:03 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:43:03 volumio volumio[1109]: info: Aug 30 21:43:03 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:43:03 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:43:03 volumio volumio[1109]: info: sendMpdCommand clear took 10 milliseconds Aug 30 21:43:03 volumio volumio[1109]: error: updateQueue error: null Aug 30 21:43:03 volumio volumio[1109]: info: ------------------------------ 4ms Aug 30 21:43:04 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand addid "http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-m9-149.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D0ea2f374d9c2931fccae314278e4474eb70aca75786fd3ce4053e0ad37bb661b%2Clid%3D1521%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c1a7c7%2F0%2F5465116%2F58a7c33a.190980067.24.131853784%2F320.mp3&ext=.mp3" Aug 30 21:43:04 volumio volumio[1109]: info: Aug 30 21:43:04 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:43:04 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:43:04 volumio volumio[1109]: info: sendMpdCommand addid "http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-m9-149.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D0ea2f374d9c2931fccae314278e4474eb70aca75786fd3ce4053e0ad37bb661b%2Clid%3D1521%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c1a7c7%2F0%2F5465116%2F58a7c33a.190980067.24.131853784%2F320.mp3&ext=.mp3" took 1 milliseconds Aug 30 21:43:04 volumio volumio[1109]: verbose: MPD COMMAND [object Object] Aug 30 21:43:04 volumio volumio[1109]: verbose: MPD COMMAND [object Object] Aug 30 21:43:04 volumio volumio[1109]: verbose: MPD COMMAND [object Object] Aug 30 21:43:04 volumio volumio[1109]: info: Aug 30 21:43:04 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:43:04 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:43:04 volumio volumio[1109]: info: ------------------------------ 1ms Aug 30 21:43:04 volumio volumio[1109]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 30 21:43:04 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand play Aug 30 21:43:04 volumio volumio[1109]: info: ------------------------------ 0ms Aug 30 21:43:04 volumio volumio[1109]: info: sendMpdCommand play took 1 milliseconds Aug 30 21:43:05 volumio volumio[1109]: info: Aug 30 21:43:05 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:43:05 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:43:05 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:43:05 volumio volumio[1109]: info: Aug 30 21:43:05 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:43:05 volumio volumio[1109]: info: sendMpdCommand status took 3 milliseconds Aug 30 21:43:05 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:43:05 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:43:05 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:43:05 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 30 21:43:05 volumio volumio[1109]: info: sendMpdCommand status took 1 milliseconds Aug 30 21:43:05 volumio volumio[1109]: info: sendMpdCommand playlistinfo took 0 milliseconds Aug 30 21:43:05 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:43:05 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 30 21:43:05 volumio volumio[1109]: verbose: ControllerMpd::parseTrackInfo Aug 30 21:43:05 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:43:05 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:43:05 volumio volumio[1109]: info: CorePlayQueue::getTrack 2 Aug 30 21:43:05 volumio volumio[1109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":298,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Отражения в воде","artist":"Музыка для расслабления вашей жизни","album":"Завораживающая природа","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-m9-149.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D0ea2f374d9c2931fccae314278e4474eb70aca75786fd3ce4053e0ad37bb661b%2Clid%3D1521%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c1a7c7%2F0%2F5465116%2F58a7c33a.190980067.24.131853784%2F320.mp3&ext=.mp3","trackType":"mp3"} Aug 30 21:43:05 volumio volumio[1109]: verbose: CURRENT POSITION 2 Aug 30 21:43:05 volumio volumio[1109]: info: CoreStateMachine::syncState stateService play Aug 30 21:43:05 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus stop Aug 30 21:43:05 volumio volumio[1109]: info: ------------------------------ 6ms Aug 30 21:43:05 volumio volumio[1109]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 30 21:43:05 volumio volumio[1109]: verbose: ControllerMpd::parseTrackInfo Aug 30 21:43:05 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:43:05 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:43:05 volumio volumio[1109]: info: CorePlayQueue::getTrack 2 Aug 30 21:43:05 volumio volumio[1109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":781,"duration":298,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Отражения в воде","artist":"Музыка для расслабления вашей жизни","album":"Завораживающая природа","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-m9-149.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D0ea2f374d9c2931fccae314278e4474eb70aca75786fd3ce4053e0ad37bb661b%2Clid%3D1521%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c1a7c7%2F0%2F5465116%2F58a7c33a.190980067.24.131853784%2F320.mp3&ext=.mp3","trackType":"mp3"} Aug 30 21:43:05 volumio volumio[1109]: verbose: CURRENT POSITION 2 Aug 30 21:43:05 volumio volumio[1109]: info: CoreStateMachine::syncState stateService play Aug 30 21:43:05 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus play Aug 30 21:43:05 volumio volumio[1109]: info: Received an update from plugin. extracting info from payload Aug 30 21:43:05 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:05 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:43:05 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:05 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:05 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:05 volumio volumio[1109]: info: ------------------------------ 19ms Aug 30 21:43:05 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:43:05 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:43:05 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:43:05 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:43:05 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:43:05 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:43:08 volumio volumio[1109]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 13 Aug 30 21:43:08 volumio volumio[1109]: info: CoreCommandRouter::volumioGetState Aug 30 21:43:08 volumio volumio[1109]: info: CoreCommandRouter::volumioNext Aug 30 21:43:08 volumio volumio[1109]: info: CoreStateMachine::next Aug 30 21:43:08 volumio volumio[1109]: info: ControllerMpd::next Aug 30 21:43:08 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand next Aug 30 21:43:08 volumio volumio[1109]: info: sendMpdCommand next took 23 milliseconds Aug 30 21:43:08 volumio volumio[1109]: info: Aug 30 21:43:08 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:43:08 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:43:08 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:43:08 volumio volumio[1109]: info: sendMpdCommand status took 0 milliseconds Aug 30 21:43:08 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:43:08 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:43:08 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:43:08 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:08 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:43:08 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:08 volumio volumio[1109]: info: CorePlayQueue::getTrack 2 Aug 30 21:43:08 volumio volumio[1109]: 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} Aug 30 21:43:08 volumio volumio[1109]: verbose: CURRENT POSITION 2 Aug 30 21:43:08 volumio volumio[1109]: info: CoreStateMachine::syncState stateService stop Aug 30 21:43:08 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus play Aug 30 21:43:08 volumio volumio[1109]: info: CoreStateMachine::play index undefined Aug 30 21:43:08 volumio volumio[1109]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 21:43:08 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:08 volumio volumio[1109]: info: CorePlayQueue::getTrack 3 Aug 30 21:43:08 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:43:08 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:08 volumio volumio[1109]: info: CorePlayQueue::getTrack 3 Aug 30 21:43:08 volumio volumio[1109]: info: CoreStateMachine::startPlaybackTimer Aug 30 21:43:08 volumio volumio[1109]: info: CorePlayQueue::getTrack 3 Aug 30 21:43:08 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand stop Aug 30 21:43:08 volumio volumio[1109]: info: ------------------------------ 16ms Aug 30 21:43:08 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:08 volumio volumio[1109]: info: CorePlayQueue::getTrack 3 Aug 30 21:43:08 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:43:08 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:08 volumio volumio[1109]: info: sendMpdCommand stop took 14 milliseconds Aug 30 21:43:08 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand clear Aug 30 21:43:08 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:43:08 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:43:08 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:43:08 volumio volumio[1109]: info: Aug 30 21:43:08 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:43:08 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:43:08 volumio volumio[1109]: info: sendMpdCommand clear took 4 milliseconds Aug 30 21:43:08 volumio volumio[1109]: error: updateQueue error: null Aug 30 21:43:08 volumio volumio[1109]: info: ------------------------------ 4ms Aug 30 21:43:08 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand addid "http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-m9-44.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D6c4afc8e5ada765fa52c8ad124da897b6236935ad0b7ecdb7f56623f7d1b83f0%2Clid%3D1521%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c15d3c%2F0%2F12620037%2Fad7f32a0.190980068.1.131853785%2F2.mp3&ext=.mp3" Aug 30 21:43:08 volumio volumio[1109]: info: Aug 30 21:43:08 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:43:08 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:43:08 volumio volumio[1109]: info: sendMpdCommand addid "http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-m9-44.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D6c4afc8e5ada765fa52c8ad124da897b6236935ad0b7ecdb7f56623f7d1b83f0%2Clid%3D1521%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c15d3c%2F0%2F12620037%2Fad7f32a0.190980068.1.131853785%2F2.mp3&ext=.mp3" took 1 milliseconds Aug 30 21:43:08 volumio volumio[1109]: verbose: MPD COMMAND [object Object] Aug 30 21:43:08 volumio volumio[1109]: verbose: MPD COMMAND [object Object] Aug 30 21:43:08 volumio volumio[1109]: verbose: MPD COMMAND [object Object] Aug 30 21:43:08 volumio volumio[1109]: info: Aug 30 21:43:08 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:43:08 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:43:08 volumio volumio[1109]: info: ------------------------------ 1ms Aug 30 21:43:08 volumio volumio[1109]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 30 21:43:08 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand play Aug 30 21:43:08 volumio volumio[1109]: info: ------------------------------ 1ms Aug 30 21:43:08 volumio volumio[1109]: info: sendMpdCommand play took 0 milliseconds Aug 30 21:43:09 volumio volumio[1109]: info: Aug 30 21:43:09 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:43:09 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:43:09 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:43:09 volumio volumio[1109]: info: Aug 30 21:43:09 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:43:09 volumio volumio[1109]: info: sendMpdCommand status took 2 milliseconds Aug 30 21:43:09 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:43:09 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:43:09 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:43:09 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 30 21:43:09 volumio volumio[1109]: info: sendMpdCommand status took 1 milliseconds Aug 30 21:43:09 volumio volumio[1109]: info: sendMpdCommand playlistinfo took 0 milliseconds Aug 30 21:43:09 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:43:09 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 30 21:43:09 volumio volumio[1109]: verbose: ControllerMpd::parseTrackInfo Aug 30 21:43:09 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:43:09 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:43:09 volumio volumio[1109]: info: CorePlayQueue::getTrack 3 Aug 30 21:43:09 volumio volumio[1109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":298,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Под звёздами","artist":"Музыка для расслабления вашей жизни","album":"Завораживающая природа","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-m9-44.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D6c4afc8e5ada765fa52c8ad124da897b6236935ad0b7ecdb7f56623f7d1b83f0%2Clid%3D1521%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c15d3c%2F0%2F12620037%2Fad7f32a0.190980068.1.131853785%2F2.mp3&ext=.mp3","trackType":"mp3"} Aug 30 21:43:09 volumio volumio[1109]: verbose: CURRENT POSITION 3 Aug 30 21:43:09 volumio volumio[1109]: info: CoreStateMachine::syncState stateService play Aug 30 21:43:09 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus stop Aug 30 21:43:09 volumio volumio[1109]: info: ------------------------------ 5ms Aug 30 21:43:09 volumio volumio[1109]: info: sendMpdCommand playlistinfo took 0 milliseconds Aug 30 21:43:09 volumio volumio[1109]: verbose: ControllerMpd::parseTrackInfo Aug 30 21:43:09 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:43:09 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:43:09 volumio volumio[1109]: info: CorePlayQueue::getTrack 3 Aug 30 21:43:09 volumio volumio[1109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":758,"duration":298,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Под звёздами","artist":"Музыка для расслабления вашей жизни","album":"Завораживающая природа","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-m9-44.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D6c4afc8e5ada765fa52c8ad124da897b6236935ad0b7ecdb7f56623f7d1b83f0%2Clid%3D1521%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c15d3c%2F0%2F12620037%2Fad7f32a0.190980068.1.131853785%2F2.mp3&ext=.mp3","trackType":"mp3"} Aug 30 21:43:09 volumio volumio[1109]: verbose: CURRENT POSITION 3 Aug 30 21:43:09 volumio volumio[1109]: info: CoreStateMachine::syncState stateService play Aug 30 21:43:09 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus play Aug 30 21:43:09 volumio volumio[1109]: info: Received an update from plugin. extracting info from payload Aug 30 21:43:09 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:09 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:43:09 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:09 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:09 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:09 volumio volumio[1109]: info: ------------------------------ 18ms Aug 30 21:43:09 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:43:09 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:43:09 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:43:09 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:43:09 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:43:09 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:43:11 volumio volumio[1109]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 13 Aug 30 21:43:11 volumio volumio[1109]: info: CoreCommandRouter::volumioGetState Aug 30 21:43:18 volumio volumio[1109]: info: CoreCommandRouter::volumioNext Aug 30 21:43:18 volumio volumio[1109]: info: CoreStateMachine::next Aug 30 21:43:18 volumio volumio[1109]: info: ControllerMpd::next Aug 30 21:43:18 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand next Aug 30 21:43:18 volumio volumio[1109]: info: sendMpdCommand next took 2 milliseconds Aug 30 21:43:18 volumio volumio[1109]: info: Aug 30 21:43:18 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:43:18 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:43:18 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:43:18 volumio volumio[1109]: info: sendMpdCommand status took 0 milliseconds Aug 30 21:43:18 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:43:18 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:43:18 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:43:18 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:18 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:43:18 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:18 volumio volumio[1109]: info: CorePlayQueue::getTrack 3 Aug 30 21:43:18 volumio volumio[1109]: 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} Aug 30 21:43:18 volumio volumio[1109]: verbose: CURRENT POSITION 3 Aug 30 21:43:18 volumio volumio[1109]: info: CoreStateMachine::syncState stateService stop Aug 30 21:43:18 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus play Aug 30 21:43:18 volumio volumio[1109]: info: CoreStateMachine::play index undefined Aug 30 21:43:18 volumio volumio[1109]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 21:43:18 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:18 volumio volumio[1109]: info: CorePlayQueue::getTrack 4 Aug 30 21:43:18 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:43:18 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:18 volumio volumio[1109]: info: CorePlayQueue::getTrack 4 Aug 30 21:43:18 volumio volumio[1109]: info: CoreStateMachine::startPlaybackTimer Aug 30 21:43:18 volumio volumio[1109]: info: CorePlayQueue::getTrack 4 Aug 30 21:43:18 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand stop Aug 30 21:43:18 volumio volumio[1109]: info: ------------------------------ 14ms Aug 30 21:43:18 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:18 volumio volumio[1109]: info: CorePlayQueue::getTrack 4 Aug 30 21:43:18 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:43:18 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:18 volumio volumio[1109]: info: sendMpdCommand stop took 13 milliseconds Aug 30 21:43:18 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand clear Aug 30 21:43:18 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:43:18 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:43:18 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:43:18 volumio volumio[1109]: info: Aug 30 21:43:18 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:43:18 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:43:18 volumio volumio[1109]: info: sendMpdCommand clear took 7 milliseconds Aug 30 21:43:18 volumio volumio[1109]: error: updateQueue error: null Aug 30 21:43:18 volumio volumio[1109]: info: ------------------------------ 3ms Aug 30 21:43:18 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand addid "http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-mar-79.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3Dbc33f4748a77516462b49fa67976e79a025202b6b58340ddd978884ae199fd65%2Clid%3D1548%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c10da5%2F0%2F14555369%2Fd139fa51.190980070.1.131853787%2F2.mp3&ext=.mp3" Aug 30 21:43:18 volumio volumio[1109]: info: Aug 30 21:43:18 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:43:18 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:43:18 volumio volumio[1109]: info: sendMpdCommand addid "http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-mar-79.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3Dbc33f4748a77516462b49fa67976e79a025202b6b58340ddd978884ae199fd65%2Clid%3D1548%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c10da5%2F0%2F14555369%2Fd139fa51.190980070.1.131853787%2F2.mp3&ext=.mp3" took 1 milliseconds Aug 30 21:43:18 volumio volumio[1109]: verbose: MPD COMMAND [object Object] Aug 30 21:43:18 volumio volumio[1109]: verbose: MPD COMMAND [object Object] Aug 30 21:43:18 volumio volumio[1109]: verbose: MPD COMMAND [object Object] Aug 30 21:43:18 volumio volumio[1109]: info: Aug 30 21:43:18 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:43:18 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:43:18 volumio volumio[1109]: info: ------------------------------ 1ms Aug 30 21:43:18 volumio volumio[1109]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 30 21:43:18 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand play Aug 30 21:43:18 volumio volumio[1109]: info: ------------------------------ 1ms Aug 30 21:43:18 volumio volumio[1109]: info: sendMpdCommand play took 0 milliseconds Aug 30 21:43:19 volumio volumio[1109]: info: Aug 30 21:43:19 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:43:19 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:43:19 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:43:19 volumio volumio[1109]: info: sendMpdCommand status took 3 milliseconds Aug 30 21:43:19 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:43:19 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 30 21:43:19 volumio volumio[1109]: info: Aug 30 21:43:19 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:43:19 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:43:19 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:43:19 volumio volumio[1109]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 30 21:43:19 volumio volumio[1109]: verbose: ControllerMpd::parseTrackInfo Aug 30 21:43:19 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:43:19 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:43:19 volumio volumio[1109]: info: CorePlayQueue::getTrack 4 Aug 30 21:43:19 volumio volumio[1109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":298,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Мысли на высоте","artist":"Музыка для расслабления вашей жизни","album":"Завораживающая природа","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-mar-79.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3Dbc33f4748a77516462b49fa67976e79a025202b6b58340ddd978884ae199fd65%2Clid%3D1548%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c10da5%2F0%2F14555369%2Fd139fa51.190980070.1.131853787%2F2.mp3&ext=.mp3","trackType":"mp3"} Aug 30 21:43:19 volumio volumio[1109]: verbose: CURRENT POSITION 4 Aug 30 21:43:19 volumio volumio[1109]: info: CoreStateMachine::syncState stateService play Aug 30 21:43:19 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus stop Aug 30 21:43:19 volumio volumio[1109]: info: ------------------------------ 6ms Aug 30 21:43:19 volumio volumio[1109]: info: sendMpdCommand status took 1 milliseconds Aug 30 21:43:19 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:43:19 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 30 21:43:19 volumio volumio[1109]: info: sendMpdCommand playlistinfo took 0 milliseconds Aug 30 21:43:19 volumio volumio[1109]: verbose: ControllerMpd::parseTrackInfo Aug 30 21:43:19 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:43:19 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:43:19 volumio volumio[1109]: info: CorePlayQueue::getTrack 4 Aug 30 21:43:19 volumio volumio[1109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":781,"duration":298,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Мысли на высоте","artist":"Музыка для расслабления вашей жизни","album":"Завораживающая природа","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-mar-79.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3Dbc33f4748a77516462b49fa67976e79a025202b6b58340ddd978884ae199fd65%2Clid%3D1548%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c10da5%2F0%2F14555369%2Fd139fa51.190980070.1.131853787%2F2.mp3&ext=.mp3","trackType":"mp3"} Aug 30 21:43:19 volumio volumio[1109]: verbose: CURRENT POSITION 4 Aug 30 21:43:19 volumio volumio[1109]: info: CoreStateMachine::syncState stateService play Aug 30 21:43:19 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus play Aug 30 21:43:19 volumio volumio[1109]: info: Received an update from plugin. extracting info from payload Aug 30 21:43:19 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:19 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:43:19 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:19 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:19 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:19 volumio volumio[1109]: info: ------------------------------ 17ms Aug 30 21:43:19 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:43:19 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:43:19 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:43:19 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:43:19 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:43:19 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:43:22 volumio volumio[1109]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 13 Aug 30 21:43:22 volumio volumio[1109]: info: CoreCommandRouter::volumioGetState Aug 30 21:43:25 volumio volumio[1109]: info: CoreCommandRouter::volumioNext Aug 30 21:43:25 volumio volumio[1109]: info: CoreStateMachine::next Aug 30 21:43:25 volumio volumio[1109]: info: ControllerMpd::next Aug 30 21:43:25 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand next Aug 30 21:43:25 volumio volumio[1109]: info: sendMpdCommand next took 9 milliseconds Aug 30 21:43:25 volumio volumio[1109]: info: Aug 30 21:43:25 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:43:25 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:43:25 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:43:25 volumio volumio[1109]: info: sendMpdCommand status took 0 milliseconds Aug 30 21:43:25 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:43:25 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:43:25 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:43:25 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:25 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:43:25 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:25 volumio volumio[1109]: info: CorePlayQueue::getTrack 4 Aug 30 21:43:25 volumio volumio[1109]: 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} Aug 30 21:43:25 volumio volumio[1109]: verbose: CURRENT POSITION 4 Aug 30 21:43:25 volumio volumio[1109]: info: CoreStateMachine::syncState stateService stop Aug 30 21:43:25 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus play Aug 30 21:43:25 volumio volumio[1109]: info: CoreStateMachine::play index undefined Aug 30 21:43:25 volumio volumio[1109]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 21:43:25 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:25 volumio volumio[1109]: info: CorePlayQueue::getTrack 5 Aug 30 21:43:25 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:43:25 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:25 volumio volumio[1109]: info: CorePlayQueue::getTrack 5 Aug 30 21:43:25 volumio volumio[1109]: info: CoreStateMachine::startPlaybackTimer Aug 30 21:43:25 volumio volumio[1109]: info: CorePlayQueue::getTrack 5 Aug 30 21:43:25 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand stop Aug 30 21:43:25 volumio volumio[1109]: info: ------------------------------ 17ms Aug 30 21:43:25 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:25 volumio volumio[1109]: info: CorePlayQueue::getTrack 5 Aug 30 21:43:25 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:43:25 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:25 volumio volumio[1109]: info: sendMpdCommand stop took 9 milliseconds Aug 30 21:43:25 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand clear Aug 30 21:43:25 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:43:25 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:43:25 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:43:25 volumio volumio[1109]: info: Aug 30 21:43:25 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:43:25 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:43:25 volumio volumio[1109]: info: sendMpdCommand clear took 8 milliseconds Aug 30 21:43:25 volumio volumio[1109]: error: updateQueue error: null Aug 30 21:43:25 volumio volumio[1109]: info: ------------------------------ 3ms Aug 30 21:43:25 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 30 21:43:25 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 30 21:43:25 volumio volumio[1109]: info: Discovery: Getting this device information Aug 30 21:43:25 volumio volumio[1109]: info: CoreCommandRouter::volumioGetState Aug 30 21:43:25 volumio volumio[1109]: info: CorePlayQueue::getTrack 5 Aug 30 21:43:25 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 30 21:43:25 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand addid "http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-spbmiran-13.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D0128276582dd6396e08a24f3fcad503f6655e54ef7ca156e5c1a76d524c1de33%2Clid%3D1506%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c19603%2F0%2F10243567%2Fabd4b130.190980071.1.131853788%2F2.mp3&ext=.mp3" Aug 30 21:43:25 volumio volumio[1109]: info: Aug 30 21:43:25 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:43:25 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:43:25 volumio volumio[1109]: info: sendMpdCommand addid "http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-spbmiran-13.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D0128276582dd6396e08a24f3fcad503f6655e54ef7ca156e5c1a76d524c1de33%2Clid%3D1506%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c19603%2F0%2F10243567%2Fabd4b130.190980071.1.131853788%2F2.mp3&ext=.mp3" took 1 milliseconds Aug 30 21:43:25 volumio volumio[1109]: verbose: MPD COMMAND [object Object] Aug 30 21:43:25 volumio volumio[1109]: verbose: MPD COMMAND [object Object] Aug 30 21:43:25 volumio volumio[1109]: verbose: MPD COMMAND [object Object] Aug 30 21:43:25 volumio volumio[1109]: info: Aug 30 21:43:25 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:43:25 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:43:25 volumio volumio[1109]: info: ------------------------------ 1ms Aug 30 21:43:25 volumio volumio[1109]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 30 21:43:25 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand play Aug 30 21:43:25 volumio volumio[1109]: info: ------------------------------ 0ms Aug 30 21:43:25 volumio volumio[1109]: info: sendMpdCommand play took 0 milliseconds Aug 30 21:43:26 volumio volumio[1109]: info: Aug 30 21:43:26 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:43:26 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:43:26 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:43:26 volumio volumio[1109]: info: Aug 30 21:43:26 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:43:26 volumio volumio[1109]: info: sendMpdCommand status took 3 milliseconds Aug 30 21:43:26 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:43:26 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:43:26 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:43:26 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 30 21:43:26 volumio volumio[1109]: info: sendMpdCommand status took 0 milliseconds Aug 30 21:43:26 volumio volumio[1109]: info: sendMpdCommand playlistinfo took 0 milliseconds Aug 30 21:43:26 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:43:26 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 30 21:43:26 volumio volumio[1109]: verbose: ControllerMpd::parseTrackInfo Aug 30 21:43:26 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:43:26 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:43:26 volumio volumio[1109]: info: CorePlayQueue::getTrack 5 Aug 30 21:43:26 volumio volumio[1109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":298,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Цветы в горах","artist":"Музыка для расслабления вашей жизни","album":"Завораживающая природа","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-spbmiran-13.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D0128276582dd6396e08a24f3fcad503f6655e54ef7ca156e5c1a76d524c1de33%2Clid%3D1506%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c19603%2F0%2F10243567%2Fabd4b130.190980071.1.131853788%2F2.mp3&ext=.mp3","trackType":"mp3"} Aug 30 21:43:26 volumio volumio[1109]: verbose: CURRENT POSITION 5 Aug 30 21:43:26 volumio volumio[1109]: info: CoreStateMachine::syncState stateService play Aug 30 21:43:26 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus stop Aug 30 21:43:26 volumio volumio[1109]: info: ------------------------------ 6ms Aug 30 21:43:26 volumio volumio[1109]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 30 21:43:26 volumio volumio[1109]: verbose: ControllerMpd::parseTrackInfo Aug 30 21:43:26 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:43:26 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:43:26 volumio volumio[1109]: info: CorePlayQueue::getTrack 5 Aug 30 21:43:26 volumio volumio[1109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":781,"duration":298,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Цветы в горах","artist":"Музыка для расслабления вашей жизни","album":"Завораживающая природа","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-spbmiran-13.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D0128276582dd6396e08a24f3fcad503f6655e54ef7ca156e5c1a76d524c1de33%2Clid%3D1506%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c19603%2F0%2F10243567%2Fabd4b130.190980071.1.131853788%2F2.mp3&ext=.mp3","trackType":"mp3"} Aug 30 21:43:26 volumio volumio[1109]: verbose: CURRENT POSITION 5 Aug 30 21:43:26 volumio volumio[1109]: info: CoreStateMachine::syncState stateService play Aug 30 21:43:26 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus play Aug 30 21:43:26 volumio volumio[1109]: info: Received an update from plugin. extracting info from payload Aug 30 21:43:26 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:26 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:43:26 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:26 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:26 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:26 volumio volumio[1109]: info: ------------------------------ 16ms Aug 30 21:43:26 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:43:26 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:43:26 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:43:26 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:43:26 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:43:26 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:43:28 volumio volumio[1109]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 13 Aug 30 21:43:28 volumio volumio[1109]: info: CoreCommandRouter::volumioGetState Aug 30 21:43:28 volumio volumio[1109]: info: CoreCommandRouter::volumioNext Aug 30 21:43:28 volumio volumio[1109]: info: CoreStateMachine::next Aug 30 21:43:28 volumio volumio[1109]: info: ControllerMpd::next Aug 30 21:43:28 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand next Aug 30 21:43:28 volumio volumio[1109]: info: sendMpdCommand next took 9 milliseconds Aug 30 21:43:28 volumio volumio[1109]: info: Aug 30 21:43:28 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:43:28 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:43:28 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:43:28 volumio volumio[1109]: info: sendMpdCommand status took 1 milliseconds Aug 30 21:43:28 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:43:28 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:43:28 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:43:28 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:28 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:43:28 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:28 volumio volumio[1109]: info: CorePlayQueue::getTrack 5 Aug 30 21:43:28 volumio volumio[1109]: 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} Aug 30 21:43:28 volumio volumio[1109]: verbose: CURRENT POSITION 5 Aug 30 21:43:28 volumio volumio[1109]: info: CoreStateMachine::syncState stateService stop Aug 30 21:43:28 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus play Aug 30 21:43:28 volumio volumio[1109]: info: CoreStateMachine::play index undefined Aug 30 21:43:28 volumio volumio[1109]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 21:43:28 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:28 volumio volumio[1109]: info: CorePlayQueue::getTrack 6 Aug 30 21:43:28 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:43:28 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:28 volumio volumio[1109]: info: CorePlayQueue::getTrack 6 Aug 30 21:43:28 volumio volumio[1109]: info: CoreStateMachine::startPlaybackTimer Aug 30 21:43:28 volumio volumio[1109]: info: CorePlayQueue::getTrack 6 Aug 30 21:43:28 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand stop Aug 30 21:43:28 volumio volumio[1109]: info: ------------------------------ 16ms Aug 30 21:43:28 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:28 volumio volumio[1109]: info: CorePlayQueue::getTrack 6 Aug 30 21:43:28 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:43:28 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:28 volumio volumio[1109]: info: sendMpdCommand stop took 11 milliseconds Aug 30 21:43:28 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand clear Aug 30 21:43:28 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:43:28 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:43:28 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:43:28 volumio volumio[1109]: info: Aug 30 21:43:28 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:43:28 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:43:28 volumio volumio[1109]: info: sendMpdCommand clear took 4 milliseconds Aug 30 21:43:28 volumio volumio[1109]: error: updateQueue error: null Aug 30 21:43:28 volumio volumio[1109]: info: ------------------------------ 2ms Aug 30 21:43:29 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand addid "http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-spbmiran-16.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3Db60740081af3a527f37143cc0aab85a978ee8b966686afa6350a0430f6da3d6a%2Clid%3D1507%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c156b7%2F0%2F10030070%2Fe146a50c.190980072.1.131853789%2F2.mp3&ext=.mp3" Aug 30 21:43:29 volumio volumio[1109]: info: Aug 30 21:43:29 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:43:29 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:43:29 volumio volumio[1109]: info: sendMpdCommand addid "http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-spbmiran-16.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3Db60740081af3a527f37143cc0aab85a978ee8b966686afa6350a0430f6da3d6a%2Clid%3D1507%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c156b7%2F0%2F10030070%2Fe146a50c.190980072.1.131853789%2F2.mp3&ext=.mp3" took 0 milliseconds Aug 30 21:43:29 volumio volumio[1109]: verbose: MPD COMMAND [object Object] Aug 30 21:43:29 volumio volumio[1109]: verbose: MPD COMMAND [object Object] Aug 30 21:43:29 volumio volumio[1109]: info: Aug 30 21:43:29 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:43:29 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:43:29 volumio volumio[1109]: info: ------------------------------ 1ms Aug 30 21:43:29 volumio volumio[1109]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 30 21:43:29 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand play Aug 30 21:43:29 volumio volumio[1109]: info: ------------------------------ 1ms Aug 30 21:43:29 volumio volumio[1109]: info: sendMpdCommand play took 1 milliseconds Aug 30 21:43:30 volumio volumio[1109]: info: Aug 30 21:43:30 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:43:30 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:43:30 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:43:30 volumio volumio[1109]: info: sendMpdCommand status took 3 milliseconds Aug 30 21:43:30 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:43:30 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 30 21:43:30 volumio volumio[1109]: info: Aug 30 21:43:30 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:43:30 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:43:30 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:43:30 volumio volumio[1109]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 30 21:43:30 volumio volumio[1109]: verbose: ControllerMpd::parseTrackInfo Aug 30 21:43:30 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:43:30 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:43:30 volumio volumio[1109]: info: CorePlayQueue::getTrack 6 Aug 30 21:43:30 volumio volumio[1109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":298,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Шаги по снегу","artist":"Музыка для расслабления вашей жизни","album":"Завораживающая природа","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-spbmiran-16.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3Db60740081af3a527f37143cc0aab85a978ee8b966686afa6350a0430f6da3d6a%2Clid%3D1507%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c156b7%2F0%2F10030070%2Fe146a50c.190980072.1.131853789%2F2.mp3&ext=.mp3","trackType":"mp3"} Aug 30 21:43:30 volumio volumio[1109]: verbose: CURRENT POSITION 6 Aug 30 21:43:30 volumio volumio[1109]: info: CoreStateMachine::syncState stateService play Aug 30 21:43:30 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus stop Aug 30 21:43:30 volumio volumio[1109]: info: ------------------------------ 4ms Aug 30 21:43:30 volumio volumio[1109]: info: sendMpdCommand status took 1 milliseconds Aug 30 21:43:30 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:43:30 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 30 21:43:30 volumio volumio[1109]: info: sendMpdCommand playlistinfo took 0 milliseconds Aug 30 21:43:30 volumio volumio[1109]: verbose: ControllerMpd::parseTrackInfo Aug 30 21:43:30 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:43:30 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:43:30 volumio volumio[1109]: info: CorePlayQueue::getTrack 6 Aug 30 21:43:30 volumio volumio[1109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":11,"duration":298,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Шаги по снегу","artist":"Музыка для расслабления вашей жизни","album":"Завораживающая природа","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-spbmiran-16.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3Db60740081af3a527f37143cc0aab85a978ee8b966686afa6350a0430f6da3d6a%2Clid%3D1507%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c156b7%2F0%2F10030070%2Fe146a50c.190980072.1.131853789%2F2.mp3&ext=.mp3","trackType":"mp3"} Aug 30 21:43:30 volumio volumio[1109]: verbose: CURRENT POSITION 6 Aug 30 21:43:30 volumio volumio[1109]: info: CoreStateMachine::syncState stateService play Aug 30 21:43:30 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus play Aug 30 21:43:30 volumio volumio[1109]: info: Received an update from plugin. extracting info from payload Aug 30 21:43:30 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:30 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:43:30 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:30 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:30 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:30 volumio volumio[1109]: info: ------------------------------ 15ms Aug 30 21:43:30 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:43:30 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:43:30 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:43:30 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:43:30 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:43:30 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:43:32 volumio volumio[1109]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 13 Aug 30 21:43:32 volumio volumio[1109]: info: CoreCommandRouter::volumioGetState Aug 30 21:43:34 volumio volumio[1109]: info: CoreCommandRouter::volumioNext Aug 30 21:43:34 volumio volumio[1109]: info: CoreStateMachine::next Aug 30 21:43:34 volumio volumio[1109]: info: ControllerMpd::next Aug 30 21:43:34 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand next Aug 30 21:43:34 volumio volumio[1109]: info: sendMpdCommand next took 19 milliseconds Aug 30 21:43:34 volumio volumio[1109]: info: Aug 30 21:43:34 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:43:34 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:43:34 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:43:34 volumio volumio[1109]: info: sendMpdCommand status took 0 milliseconds Aug 30 21:43:34 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:43:34 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:43:34 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:43:34 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:34 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:43:34 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:34 volumio volumio[1109]: info: CorePlayQueue::getTrack 6 Aug 30 21:43:34 volumio volumio[1109]: 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} Aug 30 21:43:34 volumio volumio[1109]: verbose: CURRENT POSITION 6 Aug 30 21:43:34 volumio volumio[1109]: info: CoreStateMachine::syncState stateService stop Aug 30 21:43:34 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus play Aug 30 21:43:34 volumio volumio[1109]: info: CoreStateMachine::play index undefined Aug 30 21:43:34 volumio volumio[1109]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 21:43:34 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:34 volumio volumio[1109]: info: CorePlayQueue::getTrack 7 Aug 30 21:43:34 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:43:34 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:34 volumio volumio[1109]: info: CorePlayQueue::getTrack 7 Aug 30 21:43:34 volumio volumio[1109]: info: CoreStateMachine::startPlaybackTimer Aug 30 21:43:34 volumio volumio[1109]: info: CorePlayQueue::getTrack 7 Aug 30 21:43:34 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand stop Aug 30 21:43:34 volumio volumio[1109]: info: ------------------------------ 17ms Aug 30 21:43:34 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:34 volumio volumio[1109]: info: CorePlayQueue::getTrack 7 Aug 30 21:43:34 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:43:34 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:34 volumio volumio[1109]: info: sendMpdCommand stop took 10 milliseconds Aug 30 21:43:34 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand clear Aug 30 21:43:34 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:43:34 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:43:34 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:43:34 volumio volumio[1109]: info: Aug 30 21:43:34 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:43:34 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:43:34 volumio volumio[1109]: info: sendMpdCommand clear took 6 milliseconds Aug 30 21:43:34 volumio volumio[1109]: error: updateQueue error: null Aug 30 21:43:34 volumio volumio[1109]: info: ------------------------------ 3ms Aug 30 21:43:34 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand addid "http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-m9-26.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3Dcbb496ee5275d009ee4c2ad9c607099f0f5e2e58e6498be9287baa98492ad632%2Clid%3D1521%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c1bb57%2F0%2F1635105%2F85654df5.190980073.1.131853790%2F2.mp3&ext=.mp3" Aug 30 21:43:34 volumio volumio[1109]: info: Aug 30 21:43:34 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:43:34 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:43:34 volumio volumio[1109]: info: sendMpdCommand addid "http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-m9-26.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3Dcbb496ee5275d009ee4c2ad9c607099f0f5e2e58e6498be9287baa98492ad632%2Clid%3D1521%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c1bb57%2F0%2F1635105%2F85654df5.190980073.1.131853790%2F2.mp3&ext=.mp3" took 1 milliseconds Aug 30 21:43:34 volumio volumio[1109]: verbose: MPD COMMAND [object Object] Aug 30 21:43:34 volumio volumio[1109]: verbose: MPD COMMAND [object Object] Aug 30 21:43:34 volumio volumio[1109]: info: Aug 30 21:43:34 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:43:34 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:43:34 volumio volumio[1109]: info: ------------------------------ 1ms Aug 30 21:43:34 volumio volumio[1109]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 30 21:43:34 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand play Aug 30 21:43:34 volumio volumio[1109]: info: ------------------------------ 0ms Aug 30 21:43:34 volumio volumio[1109]: info: sendMpdCommand play took 0 milliseconds Aug 30 21:43:35 volumio volumio[1109]: info: Aug 30 21:43:35 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:43:35 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:43:35 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:43:35 volumio volumio[1109]: info: Aug 30 21:43:35 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:43:35 volumio volumio[1109]: info: sendMpdCommand status took 3 milliseconds Aug 30 21:43:35 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:43:35 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:43:35 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:43:35 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 30 21:43:35 volumio volumio[1109]: info: sendMpdCommand status took 1 milliseconds Aug 30 21:43:35 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:43:35 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 30 21:43:35 volumio volumio[1109]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 30 21:43:35 volumio volumio[1109]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 30 21:43:35 volumio volumio[1109]: verbose: ControllerMpd::parseTrackInfo Aug 30 21:43:35 volumio volumio[1109]: verbose: ControllerMpd::parseTrackInfo Aug 30 21:43:35 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:43:35 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:43:35 volumio volumio[1109]: info: CorePlayQueue::getTrack 7 Aug 30 21:43:35 volumio volumio[1109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":298,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Счастье в горах","artist":"Музыка для расслабления вашей жизни","album":"Завораживающая природа","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-m9-26.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3Dcbb496ee5275d009ee4c2ad9c607099f0f5e2e58e6498be9287baa98492ad632%2Clid%3D1521%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c1bb57%2F0%2F1635105%2F85654df5.190980073.1.131853790%2F2.mp3&ext=.mp3","trackType":"mp3"} Aug 30 21:43:35 volumio volumio[1109]: verbose: CURRENT POSITION 7 Aug 30 21:43:35 volumio volumio[1109]: info: CoreStateMachine::syncState stateService play Aug 30 21:43:35 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus stop Aug 30 21:43:35 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:43:35 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:43:35 volumio volumio[1109]: info: CorePlayQueue::getTrack 7 Aug 30 21:43:35 volumio volumio[1109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":758,"duration":298,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Счастье в горах","artist":"Музыка для расслабления вашей жизни","album":"Завораживающая природа","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-m9-26.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3Dcbb496ee5275d009ee4c2ad9c607099f0f5e2e58e6498be9287baa98492ad632%2Clid%3D1521%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c1bb57%2F0%2F1635105%2F85654df5.190980073.1.131853790%2F2.mp3&ext=.mp3","trackType":"mp3"} Aug 30 21:43:35 volumio volumio[1109]: verbose: CURRENT POSITION 7 Aug 30 21:43:35 volumio volumio[1109]: info: CoreStateMachine::syncState stateService play Aug 30 21:43:35 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus play Aug 30 21:43:35 volumio volumio[1109]: info: Received an update from plugin. extracting info from payload Aug 30 21:43:35 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:35 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:43:35 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:35 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:35 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:35 volumio volumio[1109]: info: ------------------------------ 9ms Aug 30 21:43:35 volumio volumio[1109]: info: ------------------------------ 18ms Aug 30 21:43:35 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:43:35 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:43:35 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:43:35 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:43:35 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:43:35 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:43:37 volumio volumio[1109]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 13 Aug 30 21:43:37 volumio volumio[1109]: info: CoreCommandRouter::volumioGetState Aug 30 21:43:41 volumio volumio[1109]: info: CoreCommandRouter::volumioNext Aug 30 21:43:41 volumio volumio[1109]: info: CoreStateMachine::next Aug 30 21:43:41 volumio volumio[1109]: info: ControllerMpd::next Aug 30 21:43:41 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand next Aug 30 21:43:41 volumio volumio[1109]: info: sendMpdCommand next took 9 milliseconds Aug 30 21:43:41 volumio volumio[1109]: info: Aug 30 21:43:41 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:43:41 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:43:41 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:43:41 volumio volumio[1109]: info: sendMpdCommand status took 0 milliseconds Aug 30 21:43:41 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:43:41 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:43:41 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:43:41 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:41 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:43:41 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:41 volumio volumio[1109]: info: CorePlayQueue::getTrack 7 Aug 30 21:43:41 volumio volumio[1109]: 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} Aug 30 21:43:41 volumio volumio[1109]: verbose: CURRENT POSITION 7 Aug 30 21:43:41 volumio volumio[1109]: info: CoreStateMachine::syncState stateService stop Aug 30 21:43:41 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus play Aug 30 21:43:41 volumio volumio[1109]: info: CoreStateMachine::play index undefined Aug 30 21:43:41 volumio volumio[1109]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 21:43:41 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:41 volumio volumio[1109]: info: CorePlayQueue::getTrack 8 Aug 30 21:43:41 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:43:41 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:41 volumio volumio[1109]: info: CorePlayQueue::getTrack 8 Aug 30 21:43:41 volumio volumio[1109]: info: CoreStateMachine::startPlaybackTimer Aug 30 21:43:41 volumio volumio[1109]: info: CorePlayQueue::getTrack 8 Aug 30 21:43:41 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand stop Aug 30 21:43:41 volumio volumio[1109]: info: ------------------------------ 13ms Aug 30 21:43:41 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:41 volumio volumio[1109]: info: CorePlayQueue::getTrack 8 Aug 30 21:43:41 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:43:41 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:41 volumio volumio[1109]: info: sendMpdCommand stop took 11 milliseconds Aug 30 21:43:41 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand clear Aug 30 21:43:42 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:43:42 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:43:42 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:43:42 volumio volumio[1109]: info: Aug 30 21:43:42 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:43:42 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:43:42 volumio volumio[1109]: info: sendMpdCommand clear took 7 milliseconds Aug 30 21:43:42 volumio volumio[1109]: error: updateQueue error: null Aug 30 21:43:42 volumio volumio[1109]: info: ------------------------------ 2ms Aug 30 21:43:42 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand addid "http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-mar-142.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D2bf03c5ee144a6f291eaffaf4a499e187881343d64ec6537a3ab533f196ec9ac%2Clid%3D1548%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c1aeca%2F0%2F151272%2Fc414baa7.190980075.1.131853792%2F2.mp3&ext=.mp3" Aug 30 21:43:42 volumio volumio[1109]: info: Aug 30 21:43:42 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:43:42 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:43:42 volumio volumio[1109]: info: sendMpdCommand addid "http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-mar-142.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D2bf03c5ee144a6f291eaffaf4a499e187881343d64ec6537a3ab533f196ec9ac%2Clid%3D1548%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c1aeca%2F0%2F151272%2Fc414baa7.190980075.1.131853792%2F2.mp3&ext=.mp3" took 1 milliseconds Aug 30 21:43:42 volumio volumio[1109]: verbose: MPD COMMAND [object Object] Aug 30 21:43:42 volumio volumio[1109]: verbose: MPD COMMAND [object Object] Aug 30 21:43:42 volumio volumio[1109]: verbose: MPD COMMAND [object Object] Aug 30 21:43:42 volumio volumio[1109]: info: Aug 30 21:43:42 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:43:42 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:43:42 volumio volumio[1109]: info: ------------------------------ 1ms Aug 30 21:43:42 volumio volumio[1109]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 30 21:43:42 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand play Aug 30 21:43:42 volumio volumio[1109]: info: ------------------------------ 1ms Aug 30 21:43:42 volumio volumio[1109]: info: sendMpdCommand play took 1 milliseconds Aug 30 21:43:42 volumio volumio[1109]: info: Aug 30 21:43:42 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:43:42 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:43:42 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:43:42 volumio volumio[1109]: info: Aug 30 21:43:42 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:43:42 volumio volumio[1109]: info: sendMpdCommand status took 4 milliseconds Aug 30 21:43:42 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:43:42 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:43:42 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:43:42 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 30 21:43:42 volumio volumio[1109]: info: sendMpdCommand status took 0 milliseconds Aug 30 21:43:42 volumio volumio[1109]: info: sendMpdCommand playlistinfo took 0 milliseconds Aug 30 21:43:42 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:43:42 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 30 21:43:42 volumio volumio[1109]: verbose: ControllerMpd::parseTrackInfo Aug 30 21:43:42 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:43:42 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:43:42 volumio volumio[1109]: info: CorePlayQueue::getTrack 8 Aug 30 21:43:42 volumio volumio[1109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":298,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"К спорту и краю","artist":"Музыка для расслабления вашей жизни","album":"Завораживающая природа","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-mar-142.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D2bf03c5ee144a6f291eaffaf4a499e187881343d64ec6537a3ab533f196ec9ac%2Clid%3D1548%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c1aeca%2F0%2F151272%2Fc414baa7.190980075.1.131853792%2F2.mp3&ext=.mp3","trackType":"mp3"} Aug 30 21:43:42 volumio volumio[1109]: verbose: CURRENT POSITION 8 Aug 30 21:43:42 volumio volumio[1109]: info: CoreStateMachine::syncState stateService play Aug 30 21:43:42 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus stop Aug 30 21:43:42 volumio volumio[1109]: info: ------------------------------ 6ms Aug 30 21:43:42 volumio volumio[1109]: info: sendMpdCommand playlistinfo took 0 milliseconds Aug 30 21:43:42 volumio volumio[1109]: verbose: ControllerMpd::parseTrackInfo Aug 30 21:43:42 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:43:42 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:43:42 volumio volumio[1109]: info: CorePlayQueue::getTrack 8 Aug 30 21:43:42 volumio volumio[1109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":781,"duration":298,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"К спорту и краю","artist":"Музыка для расслабления вашей жизни","album":"Завораживающая природа","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-mar-142.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D2bf03c5ee144a6f291eaffaf4a499e187881343d64ec6537a3ab533f196ec9ac%2Clid%3D1548%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c1aeca%2F0%2F151272%2Fc414baa7.190980075.1.131853792%2F2.mp3&ext=.mp3","trackType":"mp3"} Aug 30 21:43:42 volumio volumio[1109]: verbose: CURRENT POSITION 8 Aug 30 21:43:42 volumio volumio[1109]: info: CoreStateMachine::syncState stateService play Aug 30 21:43:42 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus play Aug 30 21:43:42 volumio volumio[1109]: info: Received an update from plugin. extracting info from payload Aug 30 21:43:42 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:42 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:43:42 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:42 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:42 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:42 volumio volumio[1109]: info: ------------------------------ 13ms Aug 30 21:43:42 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:43:42 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:43:42 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:43:42 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:43:42 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:43:42 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:43:44 volumio volumio[1109]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 13 Aug 30 21:43:44 volumio volumio[1109]: info: CoreCommandRouter::volumioGetState Aug 30 21:43:47 volumio volumio[1109]: info: CoreCommandRouter::volumioNext Aug 30 21:43:47 volumio volumio[1109]: info: CoreStateMachine::next Aug 30 21:43:47 volumio volumio[1109]: info: ControllerMpd::next Aug 30 21:43:47 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand next Aug 30 21:43:47 volumio volumio[1109]: info: sendMpdCommand next took 17 milliseconds Aug 30 21:43:47 volumio volumio[1109]: info: Aug 30 21:43:47 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:43:47 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:43:47 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:43:47 volumio volumio[1109]: info: sendMpdCommand status took 0 milliseconds Aug 30 21:43:47 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:43:47 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:43:47 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:43:47 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:47 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:43:47 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:47 volumio volumio[1109]: info: CorePlayQueue::getTrack 8 Aug 30 21:43:47 volumio volumio[1109]: 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} Aug 30 21:43:47 volumio volumio[1109]: verbose: CURRENT POSITION 8 Aug 30 21:43:47 volumio volumio[1109]: info: CoreStateMachine::syncState stateService stop Aug 30 21:43:47 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus play Aug 30 21:43:47 volumio volumio[1109]: info: CoreStateMachine::play index undefined Aug 30 21:43:47 volumio volumio[1109]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 21:43:47 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:47 volumio volumio[1109]: info: CorePlayQueue::getTrack 9 Aug 30 21:43:47 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:43:47 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:47 volumio volumio[1109]: info: CorePlayQueue::getTrack 9 Aug 30 21:43:47 volumio volumio[1109]: info: CoreStateMachine::startPlaybackTimer Aug 30 21:43:47 volumio volumio[1109]: info: CorePlayQueue::getTrack 9 Aug 30 21:43:47 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand stop Aug 30 21:43:47 volumio volumio[1109]: info: ------------------------------ 18ms Aug 30 21:43:47 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:47 volumio volumio[1109]: info: CorePlayQueue::getTrack 9 Aug 30 21:43:47 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:43:47 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:47 volumio volumio[1109]: info: sendMpdCommand stop took 11 milliseconds Aug 30 21:43:47 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand clear Aug 30 21:43:47 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:43:47 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:43:47 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:43:47 volumio volumio[1109]: info: Aug 30 21:43:47 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:43:47 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:43:47 volumio volumio[1109]: info: sendMpdCommand clear took 5 milliseconds Aug 30 21:43:47 volumio volumio[1109]: error: updateQueue error: null Aug 30 21:43:47 volumio volumio[1109]: info: ------------------------------ 3ms Aug 30 21:43:47 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand addid "http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-spbmiran-15.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3Da8dd929ed31559077614076bc4ec2e93460fe46f651c0f474fbc1bdba2b30fca%2Clid%3D1507%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c098f5%2F0%2F237887%2F28a3039a.190980076.1.131853793%2F2.mp3&ext=.mp3" Aug 30 21:43:47 volumio volumio[1109]: info: Aug 30 21:43:47 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:43:47 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:43:47 volumio volumio[1109]: info: sendMpdCommand addid "http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-spbmiran-15.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3Da8dd929ed31559077614076bc4ec2e93460fe46f651c0f474fbc1bdba2b30fca%2Clid%3D1507%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c098f5%2F0%2F237887%2F28a3039a.190980076.1.131853793%2F2.mp3&ext=.mp3" took 1 milliseconds Aug 30 21:43:47 volumio volumio[1109]: verbose: MPD COMMAND [object Object] Aug 30 21:43:47 volumio volumio[1109]: verbose: MPD COMMAND [object Object] Aug 30 21:43:47 volumio volumio[1109]: verbose: MPD COMMAND [object Object] Aug 30 21:43:47 volumio volumio[1109]: info: Aug 30 21:43:47 volumio volumio[1109]: ---------------------------- MPD announces system playlist update Aug 30 21:43:47 volumio volumio[1109]: info: Ignoring MPD Status Update Aug 30 21:43:47 volumio volumio[1109]: info: ------------------------------ 1ms Aug 30 21:43:47 volumio volumio[1109]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 30 21:43:47 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand play Aug 30 21:43:47 volumio volumio[1109]: info: ------------------------------ 1ms Aug 30 21:43:47 volumio volumio[1109]: info: sendMpdCommand play took 0 milliseconds Aug 30 21:43:48 volumio volumio[1109]: info: Aug 30 21:43:48 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:43:48 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:43:48 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:43:48 volumio volumio[1109]: info: Aug 30 21:43:48 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:43:48 volumio volumio[1109]: info: sendMpdCommand status took 3 milliseconds Aug 30 21:43:48 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:43:48 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:43:48 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:43:48 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 30 21:43:48 volumio volumio[1109]: info: sendMpdCommand status took 1 milliseconds Aug 30 21:43:48 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:43:48 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 30 21:43:48 volumio volumio[1109]: info: sendMpdCommand playlistinfo took 2 milliseconds Aug 30 21:43:48 volumio volumio[1109]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 30 21:43:48 volumio volumio[1109]: verbose: ControllerMpd::parseTrackInfo Aug 30 21:43:48 volumio volumio[1109]: verbose: ControllerMpd::parseTrackInfo Aug 30 21:43:48 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:43:48 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:43:48 volumio volumio[1109]: info: CorePlayQueue::getTrack 9 Aug 30 21:43:48 volumio volumio[1109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":298,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"В сердце гор","artist":"Музыка для расслабления вашей жизни","album":"Завораживающая природа","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-spbmiran-15.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3Da8dd929ed31559077614076bc4ec2e93460fe46f651c0f474fbc1bdba2b30fca%2Clid%3D1507%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c098f5%2F0%2F237887%2F28a3039a.190980076.1.131853793%2F2.mp3&ext=.mp3","trackType":"mp3"} Aug 30 21:43:48 volumio volumio[1109]: verbose: CURRENT POSITION 9 Aug 30 21:43:48 volumio volumio[1109]: info: CoreStateMachine::syncState stateService play Aug 30 21:43:48 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus stop Aug 30 21:43:48 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:43:48 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:43:48 volumio volumio[1109]: info: CorePlayQueue::getTrack 9 Aug 30 21:43:48 volumio volumio[1109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":341,"duration":298,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"В сердце гор","artist":"Музыка для расслабления вашей жизни","album":"Завораживающая природа","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-spbmiran-15.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3Da8dd929ed31559077614076bc4ec2e93460fe46f651c0f474fbc1bdba2b30fca%2Clid%3D1507%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68c098f5%2F0%2F237887%2F28a3039a.190980076.1.131853793%2F2.mp3&ext=.mp3","trackType":"mp3"} Aug 30 21:43:48 volumio volumio[1109]: verbose: CURRENT POSITION 9 Aug 30 21:43:48 volumio volumio[1109]: info: CoreStateMachine::syncState stateService play Aug 30 21:43:48 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus play Aug 30 21:43:48 volumio volumio[1109]: info: Received an update from plugin. extracting info from payload Aug 30 21:43:48 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:48 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:43:48 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:48 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:48 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:48 volumio volumio[1109]: info: ------------------------------ 12ms Aug 30 21:43:48 volumio volumio[1109]: info: ------------------------------ 16ms Aug 30 21:43:48 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:43:48 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:43:48 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:43:48 volumio volumio[1109]: info: CoreCommandRouter::volumioGetQueue Aug 30 21:43:48 volumio volumio[1109]: info: CoreStateMachine::getQueue Aug 30 21:43:48 volumio volumio[1109]: info: CorePlayQueue::getQueue Aug 30 21:43:50 volumio volumio[1109]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 13 Aug 30 21:43:50 volumio volumio[1109]: info: CoreCommandRouter::volumioGetState Aug 30 21:43:50 volumio volumio[1109]: info: CoreCommandRouter::volumioNext Aug 30 21:43:50 volumio volumio[1109]: info: CoreStateMachine::next Aug 30 21:43:50 volumio volumio[1109]: info: ControllerMpd::next Aug 30 21:43:50 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand next Aug 30 21:43:50 volumio volumio[1109]: info: sendMpdCommand next took 19 milliseconds Aug 30 21:43:50 volumio volumio[1109]: info: Aug 30 21:43:50 volumio volumio[1109]: ---------------------------- MPD announces state update: player Aug 30 21:43:50 volumio volumio[1109]: info: ControllerMpd::getState Aug 30 21:43:50 volumio volumio[1109]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:43:50 volumio volumio[1109]: info: sendMpdCommand status took 1 milliseconds Aug 30 21:43:50 volumio volumio[1109]: verbose: ControllerMpd::parseState Aug 30 21:43:50 volumio volumio[1109]: info: ControllerMpd::pushState Aug 30 21:43:50 volumio volumio[1109]: info: CoreCommandRouter::servicePushState Aug 30 21:43:50 volumio volumio[1109]: info: CoreStateMachine::pushState Aug 30 21:43:50 volumio volumio[1109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:43:50 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:50 volumio volumio[1109]: info: CorePlayQueue::getTrack 9 Aug 30 21:43:50 volumio volumio[1109]: 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} Aug 30 21:43:50 volumio volumio[1109]: verbose: CURRENT POSITION 9 Aug 30 21:43:50 volumio volumio[1109]: info: CoreStateMachine::syncState stateService stop Aug 30 21:43:50 volumio volumio[1109]: info: CoreStateMachine::syncState currentStatus play Aug 30 21:43:50 volumio volumio[1109]: info: CoreCommandRouter::volumioPushState Aug 30 21:43:50 volumio volumio[1109]: info: CoreStateMachine::stPlaybackTimer Aug 30 21:43:50 volumio volumio[1109]: info: ------------------------------ 12ms Aug 30 21:43:50 volumio volumio[1109]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 30 21:43:50 volumio volumio[1109]: Error: ENOTDIR: not a directory, scandir '/tmp/peppyrunning' Aug 30 21:43:50 volumio volumio[1109]: at Object.readdirSync (fs.js:1048:3) Aug 30 21:43:50 volumio volumio[1109]: at rmkidsSync (/data/plugins/user_interface/peppy_screensaver/node_modules/rimraf/rimraf.js:349:11) Aug 30 21:43:50 volumio volumio[1109]: at rmdirSync (/data/plugins/user_interface/peppy_screensaver/node_modules/rimraf/rimraf.js:342:7) Aug 30 21:43:50 volumio volumio[1109]: at Function.rimrafSync [as sync] (/data/plugins/user_interface/peppy_screensaver/node_modules/rimraf/rimraf.js:319:62) Aug 30 21:43:50 volumio volumio[1109]: at Object.removeSync (/data/plugins/user_interface/peppy_screensaver/node_modules/fs-extra/lib/remove/index.js:4:17) Aug 30 21:43:50 volumio volumio[1109]: at Socket. (/data/plugins/user_interface/peppy_screensaver/index.js:225:48) Aug 30 21:43:50 volumio volumio[1109]: at Socket.Emitter.emit (/data/plugins/user_interface/peppy_screensaver/node_modules/component-emitter/index.js:145:20) Aug 30 21:43:50 volumio volumio[1109]: at Socket.onevent (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-client/lib/socket.js:278:10) Aug 30 21:43:50 volumio volumio[1109]: at Socket.onpacket (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-client/lib/socket.js:236:12) Aug 30 21:43:50 volumio volumio[1109]: at Manager. (/data/plugins/user_interface/peppy_screensaver/node_modules/component-bind/index.js:21:15) Aug 30 21:43:50 volumio volumio[1109]: at Manager.Emitter.emit (/data/plugins/user_interface/peppy_screensaver/node_modules/component-emitter/index.js:145:20) Aug 30 21:43:50 volumio volumio[1109]: at Manager.ondecoded (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-client/lib/manager.js:349:8) Aug 30 21:43:50 volumio volumio[1109]: at Decoder. (/data/plugins/user_interface/peppy_screensaver/node_modules/component-bind/index.js:21:15) Aug 30 21:43:50 volumio volumio[1109]: at Decoder.Emitter.emit (/data/plugins/user_interface/peppy_screensaver/node_modules/component-emitter/index.js:145:20) Aug 30 21:43:50 volumio volumio[1109]: at Decoder.add (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-parser/index.js:251:12) Aug 30 21:43:50 volumio volumio[1109]: at Manager.ondata (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-client/lib/manager.js:339:16) { Aug 30 21:43:50 volumio volumio[1109]: errno: -20, Aug 30 21:43:50 volumio volumio[1109]: syscall: 'scandir', Aug 30 21:43:50 volumio volumio[1109]: code: 'ENOTDIR', Aug 30 21:43:50 volumio volumio[1109]: path: '/tmp/peppyrunning' Aug 30 21:43:50 volumio volumio[1109]: } Aug 30 21:43:50 volumio volumio[1109]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 30 21:43:50 volumio sudo[3977]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-08-30 21:42 Aug 30 21:43:50 volumio sudo[3977]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="669bb6cc406bb77b11c5184fedb8a4dfd19ba4ec" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 11:08:46 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="9ef0bfa9b61509be20c9051562554f31"