-- Logs begin at Thu 2024-10-03 12:11:50 UTC, end at Thu 2024-10-03 13:32:44 UTC. -- Oct 03 13:31:08 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 03 13:31:08 volumio volumio[966]: info: CURURI: music-library/USB/2816E1C616E194DA/Кузьмин Владимир Oct 03 13:31:08 volumio volumio[966]: info: Preload queue cleared Oct 03 13:31:12 volumio volumio[966]: info: Preload queue cleared Oct 03 13:31:12 volumio volumio[966]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 03 13:31:12 volumio volumio[966]: info: CoreStateMachine::ClearQueue Oct 03 13:31:12 volumio volumio[966]: info: CoreStateMachine::stop Oct 03 13:31:12 volumio volumio[966]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 03 13:31:12 volumio volumio[966]: info: CorePlayQueue::clearPlayQueue Oct 03 13:31:12 volumio volumio[966]: info: CorePlayQueue::saveQueue Oct 03 13:31:12 volumio volumio[966]: info: CoreCommandRouter::volumioPushQueue Oct 03 13:31:12 volumio volumio[966]: info: CoreStateMachine::addQueueItems Oct 03 13:31:12 volumio volumio[966]: info: CorePlayQueue::addQueueItems Oct 03 13:31:12 volumio volumio[966]: info: Preload queue cleared Oct 03 13:31:12 volumio volumio[966]: info: Adding Item to queue: music-library/USB/2816E1C616E194DA/Кузьмин Владимир/Владимир Кузьмин и Динамик - Небесное притяжение (live) 1994 Oct 03 13:31:12 volumio volumio[966]: info: Exploding uri music-library/USB/2816E1C616E194DA/Кузьмин Владимир/Владимир Кузьмин и Динамик - Небесное притяжение (live) 1994 in service mpd Oct 03 13:31:12 volumio volumio[966]: info: ALBUMART /albumart?cacheid=135&web=%D0%92%D0%BB%D0%B0%D0%B4%D0%B8%D0%BC%D0%B8%D1%80%20%D0%9A%D1%83%D0%B7%D1%8C%D0%BC%D0%B8%D0%BD/%D0%9D%D0%B5%D0%B1%D0%B5%D1%81%D0%BD%D0%BE%D0%B5%20%D0%BF%D1%80%D0%B8%D1%82%D1%8F%D0%B6%D0%B5%D0%BD%D0%B8%D0%B5%20(live)/extralarge&path=%2Fmnt%2FUSB%2F2816E1C616E194DA%2F%D0%9A%D1%83%D0%B7%D1%8C%D0%BC%D0%B8%D0%BD%20%D0%92%D0%BB%D0%B0%D0%B4%D0%B8%D0%BC%D0%B8%D1%80%2F%D0%92%D0%BB%D0%B0%D0%B4%D0%B8%D0%BC%D0%B8%D1%80%20%D0%9A%D1%83%D0%B7%D1%8C%D0%BC%D0%B8%D0%BD%20%D0%B8%20%D0%94%D0%B8%D0%BD%D0%B0%D0%BC%D0%B8%D0%BA%20-%20%D0%9D%D0%B5%D0%B1%D0%B5%D1%81%D0%BD%D0%BE%D0%B5%20%D0%BF%D1%80%D0%B8%D1%82%D1%8F%D0%B6%D0%B5%D0%BD%D0%B8%D0%B5%20(live)%201994%2F%D0%92%D0%BB%D0%B0%D0%B4%D0%B8%D0%BC%D0%B8%D1%80%20%D0%9A%D1%83%D0%B7%D1%8C%D0%BC%D0%B8%D0%BD%20-%20%D0%9D%D0%B5%D0%B1%D0%B5%D1%81%D0%BD%D0%BE%D0%B5%20%D0%BF%D1%80%D0%B8%D1%82%D1%8F%D0%B6%D0%B5%D0%BD%D0%B8%D0%B5%20(live).flac&metadata=false Oct 03 13:31:12 volumio volumio[966]: info: URI /mnt/USB/2816E1C616E194DA/Кузьмин Владимир/Владимир Кузьмин и Динамик - Небесное притяжение (live) 1994/Владимир Кузьмин - Небесное притяжение (live).flac Oct 03 13:31:12 volumio volumio[966]: info: CoreCommandRouter::volumioPushQueue Oct 03 13:31:12 volumio volumio[966]: info: CorePlayQueue::saveQueue Oct 03 13:31:12 volumio volumio[966]: info: CoreStateMachine::updateTrackBlock Oct 03 13:31:12 volumio volumio[966]: info: CorePlayQueue::getTrackBlock Oct 03 13:31:12 volumio volumio[966]: info: CoreCommandRouter::volumioPlay Oct 03 13:31:12 volumio volumio[966]: info: CoreStateMachine::play index 0 Oct 03 13:31:12 volumio volumio[966]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 03 13:31:12 volumio volumio[966]: info: CoreStateMachine::stop Oct 03 13:31:12 volumio volumio[966]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 03 13:31:12 volumio volumio[966]: info: CoreStateMachine::play index undefined Oct 03 13:31:12 volumio volumio[966]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 03 13:31:12 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:12 volumio volumio[966]: info: CoreStateMachine::startPlaybackTimer Oct 03 13:31:12 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:12 volumio volumio[966]: verbose: ControllerMpd::clearAddPlayTracks USB/2816E1C616E194DA/Кузьмин Владимир/Владимир Кузьмин и Динамик - Небесное притяжение (live) 1994/Владимир Кузьмин - Небесное притяжение (live).flac Oct 03 13:31:12 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand stop Oct 03 13:31:12 volumio volumio[966]: info: sendMpdCommand stop took 3 milliseconds Oct 03 13:31:12 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand clear Oct 03 13:31:12 volumio volumio[966]: info: Oct 03 13:31:12 volumio volumio[966]: ---------------------------- MPD announces system playlist update Oct 03 13:31:12 volumio volumio[966]: info: Ignoring MPD Status Update Oct 03 13:31:12 volumio volumio[966]: info: sendMpdCommand clear took 2 milliseconds Oct 03 13:31:12 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand add "USB/2816E1C616E194DA/Кузьмин Владимир/Владимир Кузьмин и Динамик - Небесное притяжение (live) 1994/Владимир Кузьмин - Небесное притяжение (live).flac" Oct 03 13:31:12 volumio volumio[966]: info: Oct 03 13:31:12 volumio volumio[966]: ---------------------------- MPD announces system playlist update Oct 03 13:31:12 volumio volumio[966]: info: Ignoring MPD Status Update Oct 03 13:31:12 volumio volumio[966]: info: Oct 03 13:31:12 volumio volumio[966]: ---------------------------- MPD announces system playlist update Oct 03 13:31:12 volumio volumio[966]: info: Ignoring MPD Status Update Oct 03 13:31:12 volumio volumio[966]: info: Oct 03 13:31:12 volumio volumio[966]: ---------------------------- MPD announces system playlist update Oct 03 13:31:12 volumio volumio[966]: info: Ignoring MPD Status Update Oct 03 13:31:12 volumio volumio[966]: error: updateQueue error: null Oct 03 13:31:12 volumio volumio[966]: info: Oct 03 13:31:12 volumio volumio[966]: ---------------------------- MPD announces system playlist update Oct 03 13:31:12 volumio volumio[966]: info: Ignoring MPD Status Update Oct 03 13:31:12 volumio volumio[966]: info: ------------------------------ 13ms Oct 03 13:31:12 volumio volumio[966]: info: sendMpdCommand add "USB/2816E1C616E194DA/Кузьмин Владимир/Владимир Кузьмин и Динамик - Небесное притяжение (live) 1994/Владимир Кузьмин - Небесное притяжение (live).flac" took 10 milliseconds Oct 03 13:31:12 volumio volumio[966]: info: ------------------------------ 7ms Oct 03 13:31:12 volumio volumio[966]: info: ------------------------------ 7ms Oct 03 13:31:12 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand play Oct 03 13:31:12 volumio volumio[966]: info: Oct 03 13:31:12 volumio volumio[966]: ---------------------------- MPD announces system playlist update Oct 03 13:31:12 volumio volumio[966]: info: Ignoring MPD Status Update Oct 03 13:31:12 volumio volumio[966]: info: Oct 03 13:31:12 volumio volumio[966]: ---------------------------- MPD announces system playlist update Oct 03 13:31:12 volumio volumio[966]: info: Ignoring MPD Status Update Oct 03 13:31:12 volumio volumio[966]: error: Upnp client error: Error: This socket has been ended by the other party Oct 03 13:31:12 volumio volumio[966]: info: Oct 03 13:31:12 volumio volumio[966]: ---------------------------- MPD announces state update: player Oct 03 13:31:12 volumio volumio[966]: info: ------------------------------ 15ms Oct 03 13:31:12 volumio volumio[966]: info: ------------------------------ 14ms Oct 03 13:31:12 volumio volumio[966]: info: sendMpdCommand play took 11 milliseconds Oct 03 13:31:12 volumio volumio[966]: info: ------------------------------ 11ms Oct 03 13:31:12 volumio volumio[966]: info: ------------------------------ 11ms Oct 03 13:31:12 volumio volumio[966]: info: ControllerMpd::getState Oct 03 13:31:12 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand status Oct 03 13:31:12 volumio volumio[966]: info: Oct 03 13:31:12 volumio volumio[966]: ---------------------------- MPD announces state update: player Oct 03 13:31:12 volumio volumio[966]: info: ControllerMpd::getState Oct 03 13:31:12 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand status Oct 03 13:31:12 volumio volumio[966]: info: Oct 03 13:31:12 volumio volumio[966]: ---------------------------- MPD announces state update: player Oct 03 13:31:12 volumio volumio[966]: info: ControllerMpd::getState Oct 03 13:31:12 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand status Oct 03 13:31:12 volumio volumio[966]: info: Oct 03 13:31:12 volumio volumio[966]: ---------------------------- MPD announces system playlist update Oct 03 13:31:12 volumio volumio[966]: info: Ignoring MPD Status Update Oct 03 13:31:12 volumio volumio[966]: info: Oct 03 13:31:12 volumio volumio[966]: ---------------------------- MPD announces state update: player Oct 03 13:31:12 volumio volumio[966]: info: ControllerMpd::getState Oct 03 13:31:12 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand status Oct 03 13:31:12 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 03 13:31:12 volumio volumio[966]: info: sendMpdCommand status took 18 milliseconds Oct 03 13:31:12 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 03 13:31:12 volumio volumio[966]: info: sendMpdCommand status took 16 milliseconds Oct 03 13:31:12 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 03 13:31:12 volumio volumio[966]: info: sendMpdCommand status took 15 milliseconds Oct 03 13:31:12 volumio volumio[966]: info: ------------------------------ 14ms Oct 03 13:31:12 volumio volumio[966]: verbose: ControllerMpd::parseState Oct 03 13:31:12 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 03 13:31:12 volumio volumio[966]: verbose: ControllerMpd::parseState Oct 03 13:31:12 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 03 13:31:12 volumio volumio[966]: verbose: ControllerMpd::parseState Oct 03 13:31:12 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 03 13:31:12 volumio volumio[966]: info: Oct 03 13:31:12 volumio volumio[966]: ---------------------------- MPD announces state update: player Oct 03 13:31:12 volumio volumio[966]: info: ControllerMpd::getState Oct 03 13:31:12 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand status Oct 03 13:31:12 volumio volumio[966]: info: Oct 03 13:31:12 volumio volumio[966]: ---------------------------- MPD announces state update: player Oct 03 13:31:12 volumio volumio[966]: info: ControllerMpd::getState Oct 03 13:31:12 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand status Oct 03 13:31:12 volumio volumio[966]: info: Oct 03 13:31:12 volumio volumio[966]: ---------------------------- MPD announces state update: player Oct 03 13:31:12 volumio volumio[966]: info: ControllerMpd::getState Oct 03 13:31:12 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand status Oct 03 13:31:12 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 03 13:31:12 volumio volumio[966]: info: sendMpdCommand status took 30 milliseconds Oct 03 13:31:12 volumio volumio[966]: info: sendMpdCommand clearerror took 23 milliseconds Oct 03 13:31:12 volumio volumio[966]: info: sendMpdCommand clearerror took 22 milliseconds Oct 03 13:31:12 volumio volumio[966]: info: sendMpdCommand clearerror took 21 milliseconds Oct 03 13:31:12 volumio volumio[966]: info: sendMpdCommand playlistinfo took 14 milliseconds Oct 03 13:31:12 volumio volumio[966]: info: sendMpdCommand playlistinfo took 14 milliseconds Oct 03 13:31:12 volumio volumio[966]: info: sendMpdCommand playlistinfo took 13 milliseconds Oct 03 13:31:12 volumio volumio[966]: info: sendMpdCommand status took 11 milliseconds Oct 03 13:31:12 volumio volumio[966]: info: sendMpdCommand status took 10 milliseconds Oct 03 13:31:12 volumio volumio[966]: info: sendMpdCommand status took 10 milliseconds Oct 03 13:31:12 volumio volumio[966]: verbose: ControllerMpd::parseState Oct 03 13:31:12 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 03 13:31:12 volumio volumio[966]: verbose: ControllerMpd::parseTrackInfo Oct 03 13:31:12 volumio volumio[966]: verbose: ControllerMpd::parseTrackInfo Oct 03 13:31:12 volumio volumio[966]: verbose: ControllerMpd::parseTrackInfo Oct 03 13:31:12 volumio volumio[966]: verbose: ControllerMpd::parseState Oct 03 13:31:12 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 03 13:31:12 volumio volumio[966]: verbose: ControllerMpd::parseState Oct 03 13:31:12 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 03 13:31:12 volumio volumio[966]: verbose: ControllerMpd::parseState Oct 03 13:31:12 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 03 13:31:12 volumio volumio[966]: info: ControllerMpd::pushState Oct 03 13:31:12 volumio volumio[966]: info: CoreCommandRouter::servicePushState Oct 03 13:31:12 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:12 volumio volumio[966]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":4156,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Музыка телеграфных проводов","artist":"Владимир Кузьмин","album":"Небесное притяжение (live)","uri":"USB/2816E1C616E194DA/Кузьмин Владимир/Владимир Кузьмин и Динамик - Небесное притяжение (live) 1994/Владимир Кузьмин - Небесное притяжение (live).flac","trackType":"flac"} Oct 03 13:31:12 volumio volumio[966]: verbose: CURRENT POSITION 0 Oct 03 13:31:12 volumio volumio[966]: info: CoreStateMachine::syncState stateService pause Oct 03 13:31:12 volumio volumio[966]: info: CoreStateMachine::syncState currentStatus stop Oct 03 13:31:12 volumio volumio[966]: info: CoreStateMachine::pushState Oct 03 13:31:12 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:12 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 03 13:31:12 volumio volumio[966]: info: CoreCommandRouter::volumioPushState Oct 03 13:31:12 volumio volumio[966]: info: ControllerMpd::pushState Oct 03 13:31:12 volumio volumio[966]: info: CoreCommandRouter::servicePushState Oct 03 13:31:12 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:12 volumio volumio[966]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":4156,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Музыка телеграфных проводов","artist":"Владимир Кузьмин","album":"Небесное притяжение (live)","uri":"USB/2816E1C616E194DA/Кузьмин Владимир/Владимир Кузьмин и Динамик - Небесное притяжение (live) 1994/Владимир Кузьмин - Небесное притяжение (live).flac","trackType":"flac"} Oct 03 13:31:12 volumio volumio[966]: verbose: CURRENT POSITION 0 Oct 03 13:31:12 volumio volumio[966]: info: CoreStateMachine::syncState stateService pause Oct 03 13:31:12 volumio volumio[966]: info: CoreStateMachine::syncState currentStatus stop Oct 03 13:31:12 volumio volumio[966]: info: CoreStateMachine::pushState Oct 03 13:31:12 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:12 volumio volumio[966]: info: CoreCommandRouter::volumioPushState Oct 03 13:31:12 volumio volumio[966]: info: ControllerMpd::pushState Oct 03 13:31:12 volumio volumio[966]: info: CoreCommandRouter::servicePushState Oct 03 13:31:12 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:12 volumio volumio[966]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":4156,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Музыка телеграфных проводов","artist":"Владимир Кузьмин","album":"Небесное притяжение (live)","uri":"USB/2816E1C616E194DA/Кузьмин Владимир/Владимир Кузьмин и Динамик - Небесное притяжение (live) 1994/Владимир Кузьмин - Небесное притяжение (live).flac","trackType":"flac"} Oct 03 13:31:12 volumio volumio[966]: verbose: CURRENT POSITION 0 Oct 03 13:31:12 volumio volumio[966]: info: CoreStateMachine::syncState stateService pause Oct 03 13:31:12 volumio volumio[966]: info: CoreStateMachine::syncState currentStatus stop Oct 03 13:31:12 volumio volumio[966]: info: CoreStateMachine::pushState Oct 03 13:31:12 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:12 volumio volumio[966]: info: CoreCommandRouter::volumioPushState Oct 03 13:31:12 volumio volumio[966]: info: ------------------------------ 77ms Oct 03 13:31:12 volumio volumio[966]: info: ------------------------------ 72ms Oct 03 13:31:12 volumio volumio[966]: info: ------------------------------ 71ms Oct 03 13:31:12 volumio volumio[966]: info: sendMpdCommand clearerror took 45 milliseconds Oct 03 13:31:12 volumio volumio[966]: info: sendMpdCommand playlistinfo took 40 milliseconds Oct 03 13:31:12 volumio volumio[966]: info: sendMpdCommand playlistinfo took 38 milliseconds Oct 03 13:31:12 volumio volumio[966]: info: sendMpdCommand playlistinfo took 38 milliseconds Oct 03 13:31:12 volumio volumio[966]: info: sendMpdCommand playlistinfo took 38 milliseconds Oct 03 13:31:12 volumio volumio[966]: verbose: ControllerMpd::parseTrackInfo Oct 03 13:31:12 volumio volumio[966]: verbose: ControllerMpd::parseTrackInfo Oct 03 13:31:12 volumio volumio[966]: verbose: ControllerMpd::parseTrackInfo Oct 03 13:31:12 volumio volumio[966]: verbose: ControllerMpd::parseTrackInfo Oct 03 13:31:12 volumio volumio[966]: info: ControllerMpd::pushState Oct 03 13:31:12 volumio volumio[966]: info: CoreCommandRouter::servicePushState Oct 03 13:31:12 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:12 volumio volumio[966]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":4156,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Музыка телеграфных проводов","artist":"Владимир Кузьмин","album":"Небесное притяжение (live)","uri":"USB/2816E1C616E194DA/Кузьмин Владимир/Владимир Кузьмин и Динамик - Небесное притяжение (live) 1994/Владимир Кузьмин - Небесное притяжение (live).flac","trackType":"flac"} Oct 03 13:31:12 volumio volumio[966]: verbose: CURRENT POSITION 0 Oct 03 13:31:12 volumio volumio[966]: info: CoreStateMachine::syncState stateService pause Oct 03 13:31:12 volumio volumio[966]: info: CoreStateMachine::syncState currentStatus stop Oct 03 13:31:12 volumio volumio[966]: info: CoreStateMachine::pushState Oct 03 13:31:12 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:12 volumio volumio[966]: info: CoreCommandRouter::volumioPushState Oct 03 13:31:12 volumio volumio[966]: info: ControllerMpd::pushState Oct 03 13:31:12 volumio volumio[966]: info: CoreCommandRouter::servicePushState Oct 03 13:31:12 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:12 volumio volumio[966]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":4156,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Музыка телеграфных проводов","artist":"Владимир Кузьмин","album":"Небесное притяжение (live)","uri":"USB/2816E1C616E194DA/Кузьмин Владимир/Владимир Кузьмин и Динамик - Небесное притяжение (live) 1994/Владимир Кузьмин - Небесное притяжение (live).flac","trackType":"flac"} Oct 03 13:31:12 volumio volumio[966]: verbose: CURRENT POSITION 0 Oct 03 13:31:12 volumio volumio[966]: info: CoreStateMachine::syncState stateService pause Oct 03 13:31:12 volumio volumio[966]: info: CoreStateMachine::syncState currentStatus stop Oct 03 13:31:12 volumio volumio[966]: info: CoreStateMachine::pushState Oct 03 13:31:12 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:12 volumio volumio[966]: info: CoreCommandRouter::volumioPushState Oct 03 13:31:12 volumio volumio[966]: info: ControllerMpd::pushState Oct 03 13:31:12 volumio volumio[966]: info: CoreCommandRouter::servicePushState Oct 03 13:31:12 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:12 volumio volumio[966]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":4156,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Музыка телеграфных проводов","artist":"Владимир Кузьмин","album":"Небесное притяжение (live)","uri":"USB/2816E1C616E194DA/Кузьмин Владимир/Владимир Кузьмин и Динамик - Небесное притяжение (live) 1994/Владимир Кузьмин - Небесное притяжение (live).flac","trackType":"flac"} Oct 03 13:31:12 volumio volumio[966]: verbose: CURRENT POSITION 0 Oct 03 13:31:12 volumio volumio[966]: info: CoreStateMachine::syncState stateService pause Oct 03 13:31:12 volumio volumio[966]: info: CoreStateMachine::syncState currentStatus stop Oct 03 13:31:12 volumio volumio[966]: info: CoreStateMachine::pushState Oct 03 13:31:12 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:12 volumio volumio[966]: info: CoreCommandRouter::volumioPushState Oct 03 13:31:12 volumio volumio[966]: info: ControllerMpd::pushState Oct 03 13:31:12 volumio volumio[966]: info: CoreCommandRouter::servicePushState Oct 03 13:31:12 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:12 volumio volumio[966]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":4156,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Музыка телеграфных проводов","artist":"Владимир Кузьмин","album":"Небесное притяжение (live)","uri":"USB/2816E1C616E194DA/Кузьмин Владимир/Владимир Кузьмин и Динамик - Небесное притяжение (live) 1994/Владимир Кузьмин - Небесное притяжение (live).flac","trackType":"flac"} Oct 03 13:31:12 volumio volumio[966]: verbose: CURRENT POSITION 0 Oct 03 13:31:12 volumio volumio[966]: info: CoreStateMachine::syncState stateService pause Oct 03 13:31:12 volumio volumio[966]: info: CoreStateMachine::syncState currentStatus stop Oct 03 13:31:12 volumio volumio[966]: info: CoreStateMachine::pushState Oct 03 13:31:12 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:12 volumio volumio[966]: info: CoreCommandRouter::volumioPushState Oct 03 13:31:12 volumio volumio[966]: info: ------------------------------ 102ms Oct 03 13:31:12 volumio volumio[966]: info: ------------------------------ 80ms Oct 03 13:31:12 volumio volumio[966]: info: ------------------------------ 80ms Oct 03 13:31:12 volumio volumio[966]: info: ------------------------------ 78ms Oct 03 13:31:17 volumio kernel: usb 1-2.4: USB disconnect, device number 6 Oct 03 13:31:17 volumio thd[612]: Error reading device '/dev/input/event9' Oct 03 13:31:17 volumio acpid[1032]: input device has been disconnected, fd 10 Oct 03 13:31:18 volumio thd[612]: Error reading device '/dev/input/event1' Oct 03 13:31:21 volumio kernel: usb 1-2.1: new high-speed USB device number 7 using xhci_hcd Oct 03 13:31:22 volumio kernel: usb 1-2.1: config 1 has an invalid interface number: 255 but max is 3 Oct 03 13:31:22 volumio kernel: usb 1-2.1: config 1 has no interface number 3 Oct 03 13:31:22 volumio kernel: usb 1-2.1: New USB device found, idVendor=0d8c, idProduct=0158, bcdDevice= 0.08 Oct 03 13:31:22 volumio kernel: usb 1-2.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Oct 03 13:31:22 volumio kernel: usb 1-2.1: Product: Hifi Audio Oct 03 13:31:22 volumio kernel: usb 1-2.1: Manufacturer: C-Media Electronics Inc. Oct 03 13:31:22 volumio kernel: input: C-Media Electronics Inc. Hifi Audio as /devices/pci0000:00/0000:00:14.0/usb1/1-2/1-2.1/1-2.1:1.255/0003:0D8C:0158.0005/input/input26 Oct 03 13:31:22 volumio kernel: hid-generic 0003:0D8C:0158.0005: input,hidraw0: USB HID v1.11 Device [C-Media Electronics Inc. Hifi Audio] on usb-0000:00:14.0-2.1/input255 Oct 03 13:31:22 volumio systemd-udevd[2936]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Oct 03 13:31:23 volumio kernel: usbcore: registered new interface driver snd-usb-audio Oct 03 13:31:23 volumio systemd-udevd[2937]: Process '/usr/sbin/alsactl -E HOME=/run/alsa restore 5' failed with exit code 99. Oct 03 13:31:23 volumio volumio[966]: info: No valid Plugin REST Endpoint Oct 03 13:31:23 volumio volumio[966]: info: Oct 03 13:31:23 volumio volumio[966]: ---------------------------- USB Audio Device Attached Oct 03 13:31:23 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioAttach Oct 03 13:31:26 volumio volumio[966]: info: CoreCommandRouter::volumioGetState Oct 03 13:31:26 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:28 volumio volumio[966]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 03 13:31:28 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 03 13:31:28 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 03 13:31:28 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 03 13:31:28 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 03 13:31:28 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 03 13:31:28 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 03 13:31:28 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 03 13:31:28 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 03 13:31:28 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 03 13:31:28 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 03 13:31:28 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Oct 03 13:31:28 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 03 13:31:36 volumio volumio[966]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Oct 03 13:31:36 volumio volumio[966]: info: Preparing to save Alsa Options, stopping services first Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::volumioGetState Oct 03 13:31:36 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::volumioPause Oct 03 13:31:36 volumio volumio[966]: info: CoreStateMachine::pause Oct 03 13:31:36 volumio volumio[966]: info: Saving Audio Output to: {"output_device":{"value":"5","label":"Hifi Audio"}} Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 03 13:31:36 volumio volumio[966]: info: Setting mixer Headphones for card Hifi Audio Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::volumioUpdateVolumeSettings Oct 03 13:31:36 volumio volumio[966]: info: Updating Volume Controller Parameters: Device: 5 Name: Hifi Audio Mixer: Headphones Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Oct 03 13:31:36 volumio volumio[966]: info: Disabling external Volume Control Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 03 13:31:36 volumio volumio[966]: info: Preparing to generate the ALSA configuration file Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 03 13:31:36 volumio volumio[966]: info: VolumeController:: Volume=100 Mute =false Oct 03 13:31:36 volumio volumio[966]: info: CoreStateMachine::pushState Oct 03 13:31:36 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::volumioPushState Oct 03 13:31:36 volumio volumio[966]: info: Asound.conf file written Oct 03 13:31:36 volumio sudo[2974]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Oct 03 13:31:36 volumio sudo[2974]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 03 13:31:36 volumio sudo[2974]: pam_unix(sudo:session): session closed for user root Oct 03 13:31:36 volumio volumio[966]: Found hardware: "HdmiLpeAudio" "" "" "" "" Oct 03 13:31:36 volumio volumio[966]: Hardware is initialized using a generic method Oct 03 13:31:36 volumio volumio[966]: /usr/sbin/alsactl: set_control:1325: failed to obtain info for control #1 (No such file or directory) Oct 03 13:31:36 volumio volumio[966]: /usr/sbin/alsactl: set_control:1325: failed to obtain info for control #3 (No such file or directory) Oct 03 13:31:36 volumio volumio[966]: /usr/sbin/alsactl: set_control:1325: failed to obtain info for control #4 (No such file or directory) Oct 03 13:31:36 volumio volumio[966]: /usr/sbin/alsactl: set_control:1325: failed to obtain info for control #5 (No such file or directory) Oct 03 13:31:36 volumio volumio[966]: /usr/sbin/alsactl: set_control:1325: failed to obtain info for control #6 (No such file or directory) Oct 03 13:31:36 volumio volumio[966]: /usr/sbin/alsactl: set_control:1325: failed to obtain info for control #7 (No such file or directory) Oct 03 13:31:36 volumio volumio[966]: Found hardware: "USB-Audio" "USB Mixer" "USB0d8c:0158" "" "" Oct 03 13:31:36 volumio volumio[966]: Hardware is initialized using a generic method Oct 03 13:31:36 volumio volumio[966]: /usr/sbin/alsactl: set_control:1325: failed to obtain info for control #1 (No such file or directory) Oct 03 13:31:36 volumio volumio[966]: /usr/sbin/alsactl: set_control:1325: failed to obtain info for control #2 (No such file or directory) Oct 03 13:31:36 volumio volumio[966]: /usr/sbin/alsactl: set_control:1325: failed to obtain info for control #3 (No such file or directory) Oct 03 13:31:36 volumio volumio[966]: /usr/sbin/alsactl: set_control:1325: failed to obtain info for control #5 (No such file or directory) Oct 03 13:31:36 volumio volumio[966]: /usr/sbin/alsactl: set_control:1325: failed to obtain info for control #6 (No such file or directory) Oct 03 13:31:36 volumio volumio[966]: /usr/sbin/alsactl: set_control:1325: failed to obtain info for control #7 (No such file or directory) Oct 03 13:31:36 volumio volumio[966]: /usr/sbin/alsactl: set_control:1325: failed to obtain info for control #8 (No such file or directory) Oct 03 13:31:36 volumio volumio[966]: /usr/sbin/alsactl: set_control:1325: failed to obtain info for control #9 (No such file or directory) Oct 03 13:31:36 volumio volumio[966]: /usr/sbin/alsactl: set_control:1325: failed to obtain info for control #10 (No such file or directory) Oct 03 13:31:36 volumio volumio[966]: info: Output device has changed, restarting MPD Oct 03 13:31:36 volumio sudo[2979]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 03 13:31:36 volumio sudo[2979]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 03 13:31:36 volumio volumio[966]: info: Output device has changed, restarting Shairport Sync Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 03 13:31:36 volumio sudo[2979]: pam_unix(sudo:session): session closed for user root Oct 03 13:31:36 volumio sudo[2982]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 03 13:31:36 volumio sudo[2982]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 03 13:31:36 volumio systemd[1]: Stopping Music Player Daemon... Oct 03 13:31:36 volumio volumio[966]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 03 13:31:36 volumio volumio[966]: info: Output device has changed, restarting MPD Oct 03 13:31:36 volumio sudo[2988]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 03 13:31:36 volumio volumio[966]: info: Output device has changed, restarting Shairport Sync Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 03 13:31:36 volumio sudo[2988]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 03 13:31:36 volumio sudo[2988]: pam_unix(sudo:session): session closed for user root Oct 03 13:31:36 volumio systemd[1]: mpd.service: Succeeded. Oct 03 13:31:36 volumio systemd[1]: Stopped Music Player Daemon. Oct 03 13:31:36 volumio sudo[2990]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 03 13:31:36 volumio sudo[2990]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 03 13:31:36 volumio systemd[1]: Starting Music Player Daemon... Oct 03 13:31:36 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Oct 03 13:31:36 volumio systemd[1]: mpd.service: Succeeded. Oct 03 13:31:36 volumio systemd[1]: Stopped Music Player Daemon. Oct 03 13:31:36 volumio systemd[1]: Starting Music Player Daemon... Oct 03 13:31:36 volumio volumio[966]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 03 13:31:36 volumio volumio[966]: info: MPD Permissions set Oct 03 13:31:36 volumio volumio[966]: info: MPD Permissions set Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Oct 03 13:31:36 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:31:36 volumio volumio[966]: info: Starting Shairport Sync Oct 03 13:31:36 volumio volumio[966]: info: Starting Shairport Sync Oct 03 13:31:37 volumio sudo[3011]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 03 13:31:37 volumio sudo[3011]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 03 13:31:37 volumio sudo[3013]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 03 13:31:37 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 03 13:31:37 volumio sudo[3013]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 03 13:31:37 volumio systemd[1]: shairport-sync.service: Succeeded. Oct 03 13:31:37 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 03 13:31:37 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 03 13:31:37 volumio sudo[3011]: pam_unix(sudo:session): session closed for user root Oct 03 13:31:37 volumio volumio[966]: info: Shairport-Sync Started Oct 03 13:31:37 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 03 13:31:37 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Oct 03 13:31:37 volumio systemd[1]: shairport-sync.service: Succeeded. Oct 03 13:31:37 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 03 13:31:37 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 03 13:31:37 volumio sudo[3013]: pam_unix(sudo:session): session closed for user root Oct 03 13:31:37 volumio volumio[966]: info: Shairport-Sync Started Oct 03 13:31:37 volumio mpd[2997]: Oct 03 13:31 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 03 13:31:37 volumio mpd[2997]: Oct 03 13:31 : exception: Failed to open '/var/lib/mpd/tag_cache': No such file or directory Oct 03 13:31:37 volumio systemd[1]: Started Music Player Daemon. Oct 03 13:31:37 volumio sudo[2982]: pam_unix(sudo:session): session closed for user root Oct 03 13:31:37 volumio sudo[2990]: pam_unix(sudo:session): session closed for user root Oct 03 13:31:37 volumio volumio[966]: error: MPD error: The expression evaluated to a falsy value: Oct 03 13:31:37 volumio volumio[966]: assert.ok(self.idling) Oct 03 13:31:37 volumio volumio[966]: error: The expression evaluated to a falsy value: Oct 03 13:31:37 volumio volumio[966]: assert.ok(self.idling) Oct 03 13:31:37 volumio volumio[966]: error: updateQueue error: null Oct 03 13:31:40 volumio volumio[966]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Oct 03 13:31:40 volumio volumio[966]: info: CoreStateMachine::getcurrentVolume Oct 03 13:31:40 volumio volumio[966]: info: CoreCommandRouter::volumioRetrievevolume Oct 03 13:31:40 volumio volumio[966]: info: VolumeController:: Volume=100 Mute =false Oct 03 13:31:40 volumio volumio[966]: info: CoreStateMachine::pushState Oct 03 13:31:40 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:40 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 03 13:31:40 volumio volumio[966]: info: CoreCommandRouter::volumioPushState Oct 03 13:31:40 volumio volumio[966]: info: CoreStateMachine::updateTrackBlock Oct 03 13:31:40 volumio volumio[966]: info: CorePlayQueue::getTrackBlock Oct 03 13:31:40 volumio volumio[966]: info: CoreCommandRouter::volumioRetrievevolume Oct 03 13:31:40 volumio volumio[966]: info: VolumeController:: Volume=100 Mute =false Oct 03 13:31:40 volumio volumio[966]: info: CoreStateMachine::pushState Oct 03 13:31:40 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:40 volumio volumio[966]: info: CoreCommandRouter::volumioPushState Oct 03 13:31:49 volumio volumio[966]: info: MPD Database updated - AlbumList cache refreshed Oct 03 13:31:49 volumio volumio[966]: info: Oct 03 13:31:49 volumio volumio[966]: ---------------------------- MPD announces state update: database Oct 03 13:31:49 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand status Oct 03 13:31:49 volumio volumio[966]: info: Oct 03 13:31:49 volumio volumio[966]: ---------------------------- MPD announces state update: update Oct 03 13:31:49 volumio volumio[966]: info: ControllerMpd::getState Oct 03 13:31:49 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand status Oct 03 13:31:49 volumio volumio[966]: info: ControllerMpd::getState Oct 03 13:31:49 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand status Oct 03 13:31:49 volumio volumio[966]: info: MPD Database updated - AlbumList cache refreshed Oct 03 13:31:49 volumio volumio[966]: info: Oct 03 13:31:49 volumio volumio[966]: ---------------------------- MPD announces state update: database Oct 03 13:31:49 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand status Oct 03 13:31:49 volumio volumio[966]: info: Oct 03 13:31:49 volumio volumio[966]: ---------------------------- MPD announces state update: update Oct 03 13:31:49 volumio volumio[966]: info: ControllerMpd::getState Oct 03 13:31:49 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand status Oct 03 13:31:49 volumio volumio[966]: info: ControllerMpd::getState Oct 03 13:31:49 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand status Oct 03 13:31:50 volumio volumio[966]: info: sendMpdCommand status took 111 milliseconds Oct 03 13:31:50 volumio volumio[966]: info: sendMpdCommand status took 109 milliseconds Oct 03 13:31:50 volumio volumio[966]: info: sendMpdCommand status took 109 milliseconds Oct 03 13:31:50 volumio volumio[966]: verbose: ControllerMpd::parseState Oct 03 13:31:50 volumio volumio[966]: info: Command Router : Notfying DB Updatefalse Oct 03 13:31:50 volumio volumio[966]: info: CoreCommandRouter::Close All Modals sent Oct 03 13:31:50 volumio volumio[966]: verbose: ControllerMpd::parseState Oct 03 13:31:50 volumio volumio[966]: verbose: ControllerMpd::parseState Oct 03 13:31:50 volumio volumio[966]: info: ControllerMpd::pushState Oct 03 13:31:50 volumio volumio[966]: info: CoreCommandRouter::servicePushState Oct 03 13:31:50 volumio volumio[966]: info: CoreStateMachine::pushState Oct 03 13:31:50 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:50 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 03 13:31:50 volumio volumio[966]: info: CoreCommandRouter::volumioPushState Oct 03 13:31:50 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:50 volumio volumio[966]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Oct 03 13:31:50 volumio volumio[966]: verbose: CURRENT POSITION 0 Oct 03 13:31:50 volumio volumio[966]: info: CoreStateMachine::syncState stateService stop Oct 03 13:31:50 volumio volumio[966]: info: CoreStateMachine::syncState currentStatus stop Oct 03 13:31:50 volumio volumio[966]: info: CoreStateMachine::pushState Oct 03 13:31:50 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:50 volumio volumio[966]: info: CoreCommandRouter::volumioPushState Oct 03 13:31:50 volumio volumio[966]: info: No code Oct 03 13:31:50 volumio volumio[966]: info: CoreStateMachine::pushState Oct 03 13:31:50 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:50 volumio volumio[966]: info: CoreCommandRouter::volumioPushState Oct 03 13:31:50 volumio volumio[966]: info: ControllerMpd::pushState Oct 03 13:31:50 volumio volumio[966]: info: CoreCommandRouter::servicePushState Oct 03 13:31:50 volumio volumio[966]: info: CoreStateMachine::pushState Oct 03 13:31:50 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:50 volumio volumio[966]: info: CoreCommandRouter::volumioPushState Oct 03 13:31:50 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:50 volumio volumio[966]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Oct 03 13:31:50 volumio volumio[966]: verbose: CURRENT POSITION 0 Oct 03 13:31:50 volumio volumio[966]: info: CoreStateMachine::syncState stateService stop Oct 03 13:31:50 volumio volumio[966]: info: CoreStateMachine::syncState currentStatus stop Oct 03 13:31:50 volumio volumio[966]: info: CoreStateMachine::pushState Oct 03 13:31:50 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:50 volumio volumio[966]: info: CoreCommandRouter::volumioPushState Oct 03 13:31:50 volumio volumio[966]: info: No code Oct 03 13:31:50 volumio volumio[966]: info: CoreStateMachine::pushState Oct 03 13:31:50 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:50 volumio volumio[966]: info: CoreCommandRouter::volumioPushState Oct 03 13:31:50 volumio volumio[966]: info: ------------------------------ 812ms Oct 03 13:31:50 volumio volumio[966]: info: ------------------------------ 813ms Oct 03 13:31:50 volumio volumio[966]: info: sendMpdCommand status took 865 milliseconds Oct 03 13:31:50 volumio volumio[966]: info: sendMpdCommand status took 864 milliseconds Oct 03 13:31:50 volumio volumio[966]: info: sendMpdCommand status took 864 milliseconds Oct 03 13:31:50 volumio volumio[966]: verbose: ControllerMpd::parseState Oct 03 13:31:50 volumio volumio[966]: info: Command Router : Notfying DB Updatefalse Oct 03 13:31:50 volumio volumio[966]: info: CoreCommandRouter::Close All Modals sent Oct 03 13:31:50 volumio volumio[966]: verbose: ControllerMpd::parseState Oct 03 13:31:50 volumio volumio[966]: verbose: ControllerMpd::parseState Oct 03 13:31:50 volumio volumio[966]: info: ControllerMpd::pushState Oct 03 13:31:50 volumio volumio[966]: info: CoreCommandRouter::servicePushState Oct 03 13:31:50 volumio volumio[966]: info: CoreStateMachine::pushState Oct 03 13:31:50 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:50 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 03 13:31:50 volumio volumio[966]: info: CoreCommandRouter::volumioPushState Oct 03 13:31:50 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:50 volumio volumio[966]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Oct 03 13:31:50 volumio volumio[966]: verbose: CURRENT POSITION 0 Oct 03 13:31:50 volumio volumio[966]: info: CoreStateMachine::syncState stateService stop Oct 03 13:31:50 volumio volumio[966]: info: CoreStateMachine::syncState currentStatus stop Oct 03 13:31:50 volumio volumio[966]: info: CoreStateMachine::pushState Oct 03 13:31:50 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:50 volumio volumio[966]: info: CoreCommandRouter::volumioPushState Oct 03 13:31:50 volumio volumio[966]: info: No code Oct 03 13:31:50 volumio volumio[966]: info: CoreStateMachine::pushState Oct 03 13:31:50 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:50 volumio volumio[966]: info: CoreCommandRouter::volumioPushState Oct 03 13:31:50 volumio volumio[966]: info: ControllerMpd::pushState Oct 03 13:31:50 volumio volumio[966]: info: CoreCommandRouter::servicePushState Oct 03 13:31:50 volumio volumio[966]: info: CoreStateMachine::pushState Oct 03 13:31:50 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:50 volumio volumio[966]: info: CoreCommandRouter::volumioPushState Oct 03 13:31:50 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:50 volumio volumio[966]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Oct 03 13:31:50 volumio volumio[966]: verbose: CURRENT POSITION 0 Oct 03 13:31:50 volumio volumio[966]: info: CoreStateMachine::syncState stateService stop Oct 03 13:31:50 volumio volumio[966]: info: CoreStateMachine::syncState currentStatus stop Oct 03 13:31:50 volumio volumio[966]: info: CoreStateMachine::pushState Oct 03 13:31:50 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:50 volumio volumio[966]: info: CoreCommandRouter::volumioPushState Oct 03 13:31:50 volumio volumio[966]: info: No code Oct 03 13:31:50 volumio volumio[966]: info: CoreStateMachine::pushState Oct 03 13:31:50 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:50 volumio volumio[966]: info: CoreCommandRouter::volumioPushState Oct 03 13:31:50 volumio volumio[966]: info: ------------------------------ 1006ms Oct 03 13:31:50 volumio volumio[966]: info: ------------------------------ 1007ms Oct 03 13:31:50 volumio volumio[966]: info: CoreCommandRouter::volumioGetState Oct 03 13:31:50 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:53 volumio volumio[966]: info: Preload queue cleared Oct 03 13:31:53 volumio volumio[966]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 03 13:31:53 volumio volumio[966]: info: CoreStateMachine::ClearQueue Oct 03 13:31:53 volumio volumio[966]: info: CoreStateMachine::stop Oct 03 13:31:53 volumio volumio[966]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 03 13:31:53 volumio volumio[966]: info: CorePlayQueue::clearPlayQueue Oct 03 13:31:53 volumio volumio[966]: info: CorePlayQueue::saveQueue Oct 03 13:31:53 volumio volumio[966]: info: CoreCommandRouter::volumioPushQueue Oct 03 13:31:53 volumio volumio[966]: info: CoreStateMachine::addQueueItems Oct 03 13:31:53 volumio volumio[966]: info: CorePlayQueue::addQueueItems Oct 03 13:31:53 volumio volumio[966]: info: Preload queue cleared Oct 03 13:31:53 volumio volumio[966]: info: Adding Item to queue: music-library/USB/2816E1C616E194DA/Кузьмин Владимир/Владимир Кузьмин и Динамик - Небесное притяжение (live) 1994 Oct 03 13:31:53 volumio volumio[966]: info: Using cached record of: music-library/USB/2816E1C616E194DA/Кузьмин Владимир/Владимир Кузьмин и Динамик - Небесное притяжение (live) 1994 Oct 03 13:31:53 volumio volumio[966]: info: CoreCommandRouter::volumioPushQueue Oct 03 13:31:53 volumio volumio[966]: info: CorePlayQueue::saveQueue Oct 03 13:31:53 volumio volumio[966]: info: CoreStateMachine::updateTrackBlock Oct 03 13:31:53 volumio volumio[966]: info: CorePlayQueue::getTrackBlock Oct 03 13:31:53 volumio volumio[966]: info: CoreCommandRouter::volumioPlay Oct 03 13:31:53 volumio volumio[966]: info: CoreStateMachine::play index 0 Oct 03 13:31:53 volumio volumio[966]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 03 13:31:53 volumio volumio[966]: info: CoreStateMachine::stop Oct 03 13:31:53 volumio volumio[966]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 03 13:31:53 volumio volumio[966]: info: CoreStateMachine::play index undefined Oct 03 13:31:53 volumio volumio[966]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 03 13:31:53 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:53 volumio volumio[966]: info: CoreStateMachine::startPlaybackTimer Oct 03 13:31:53 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:53 volumio volumio[966]: verbose: ControllerMpd::clearAddPlayTracks USB/2816E1C616E194DA/Кузьмин Владимир/Владимир Кузьмин и Динамик - Небесное притяжение (live) 1994/Владимир Кузьмин - Небесное притяжение (live).flac Oct 03 13:31:53 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand stop Oct 03 13:31:53 volumio volumio[966]: info: sendMpdCommand stop took 4 milliseconds Oct 03 13:31:53 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand clear Oct 03 13:31:53 volumio volumio[966]: info: Oct 03 13:31:53 volumio volumio[966]: ---------------------------- MPD announces system playlist update Oct 03 13:31:53 volumio volumio[966]: info: Ignoring MPD Status Update Oct 03 13:31:53 volumio volumio[966]: info: sendMpdCommand clear took 3 milliseconds Oct 03 13:31:53 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand add "USB/2816E1C616E194DA/Кузьмин Владимир/Владимир Кузьмин и Динамик - Небесное притяжение (live) 1994/Владимир Кузьмин - Небесное притяжение (live).flac" Oct 03 13:31:53 volumio volumio[966]: info: Oct 03 13:31:53 volumio volumio[966]: ---------------------------- MPD announces system playlist update Oct 03 13:31:53 volumio volumio[966]: info: Ignoring MPD Status Update Oct 03 13:31:53 volumio volumio[966]: error: updateQueue error: null Oct 03 13:31:53 volumio volumio[966]: info: Oct 03 13:31:53 volumio volumio[966]: ---------------------------- MPD announces system playlist update Oct 03 13:31:53 volumio volumio[966]: info: Ignoring MPD Status Update Oct 03 13:31:53 volumio volumio[966]: info: ------------------------------ 7ms Oct 03 13:31:53 volumio volumio[966]: info: sendMpdCommand add "USB/2816E1C616E194DA/Кузьмин Владимир/Владимир Кузьмин и Динамик - Небесное притяжение (live) 1994/Владимир Кузьмин - Небесное притяжение (live).flac" took 5 milliseconds Oct 03 13:31:53 volumio volumio[966]: info: ------------------------------ 6ms Oct 03 13:31:53 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand play Oct 03 13:31:53 volumio volumio[966]: info: Oct 03 13:31:53 volumio volumio[966]: ---------------------------- MPD announces system playlist update Oct 03 13:31:53 volumio volumio[966]: info: Ignoring MPD Status Update Oct 03 13:31:53 volumio volumio[966]: info: ------------------------------ 7ms Oct 03 13:31:53 volumio volumio[966]: info: sendMpdCommand play took 6 milliseconds Oct 03 13:31:53 volumio volumio[966]: info: ------------------------------ 6ms Oct 03 13:31:53 volumio volumio[966]: info: Oct 03 13:31:53 volumio volumio[966]: ---------------------------- MPD announces state update: player Oct 03 13:31:53 volumio volumio[966]: info: ControllerMpd::getState Oct 03 13:31:53 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand status Oct 03 13:31:53 volumio volumio[966]: info: Oct 03 13:31:53 volumio volumio[966]: ---------------------------- MPD announces state update: player Oct 03 13:31:53 volumio volumio[966]: info: ControllerMpd::getState Oct 03 13:31:53 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand status Oct 03 13:31:53 volumio volumio[966]: info: Oct 03 13:31:53 volumio volumio[966]: ---------------------------- MPD announces state update: player Oct 03 13:31:53 volumio volumio[966]: info: sendMpdCommand status took 13 milliseconds Oct 03 13:31:53 volumio volumio[966]: info: ControllerMpd::getState Oct 03 13:31:53 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand status Oct 03 13:31:53 volumio volumio[966]: info: sendMpdCommand status took 13 milliseconds Oct 03 13:31:53 volumio volumio[966]: verbose: ControllerMpd::parseState Oct 03 13:31:53 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 03 13:31:53 volumio volumio[966]: verbose: ControllerMpd::parseState Oct 03 13:31:53 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 03 13:31:53 volumio volumio[966]: info: Oct 03 13:31:53 volumio volumio[966]: ---------------------------- MPD announces state update: player Oct 03 13:31:53 volumio volumio[966]: info: ControllerMpd::getState Oct 03 13:31:53 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand status Oct 03 13:31:53 volumio volumio[966]: info: sendMpdCommand status took 8 milliseconds Oct 03 13:31:53 volumio volumio[966]: info: sendMpdCommand playlistinfo took 7 milliseconds Oct 03 13:31:53 volumio volumio[966]: info: sendMpdCommand playlistinfo took 6 milliseconds Oct 03 13:31:53 volumio volumio[966]: info: sendMpdCommand status took 3 milliseconds Oct 03 13:31:53 volumio volumio[966]: verbose: ControllerMpd::parseState Oct 03 13:31:53 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 03 13:31:53 volumio volumio[966]: verbose: ControllerMpd::parseTrackInfo Oct 03 13:31:53 volumio volumio[966]: verbose: ControllerMpd::parseState Oct 03 13:31:53 volumio volumio[966]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 03 13:31:53 volumio volumio[966]: info: ControllerMpd::pushState Oct 03 13:31:53 volumio volumio[966]: info: CoreCommandRouter::servicePushState Oct 03 13:31:53 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:53 volumio volumio[966]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":4156,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"118 Kbps","isStreaming":false,"title":"Музыка телеграфных проводов","artist":"Владимир Кузьмин","album":"Небесное притяжение (live)","uri":"USB/2816E1C616E194DA/Кузьмин Владимир/Владимир Кузьмин и Динамик - Небесное притяжение (live) 1994/Владимир Кузьмин - Небесное притяжение (live).flac","trackType":"flac"} Oct 03 13:31:53 volumio volumio[966]: verbose: CURRENT POSITION 0 Oct 03 13:31:53 volumio volumio[966]: info: CoreStateMachine::syncState stateService play Oct 03 13:31:53 volumio volumio[966]: info: CoreStateMachine::syncState currentStatus stop Oct 03 13:31:53 volumio volumio[966]: info: ControllerMpd::pushState Oct 03 13:31:53 volumio volumio[966]: info: CoreCommandRouter::servicePushState Oct 03 13:31:53 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:53 volumio volumio[966]: verbose: STATE SERVICE {"status":"play","position":0,"seek":842,"duration":4156,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"118 Kbps","isStreaming":false,"title":"Музыка телеграфных проводов","artist":"Владимир Кузьмин","album":"Небесное притяжение (live)","uri":"USB/2816E1C616E194DA/Кузьмин Владимир/Владимир Кузьмин и Динамик - Небесное притяжение (live) 1994/Владимир Кузьмин - Небесное притяжение (live).flac","trackType":"flac"} Oct 03 13:31:53 volumio volumio[966]: verbose: CURRENT POSITION 0 Oct 03 13:31:53 volumio volumio[966]: info: CoreStateMachine::syncState stateService play Oct 03 13:31:53 volumio volumio[966]: info: CoreStateMachine::syncState currentStatus play Oct 03 13:31:53 volumio volumio[966]: info: Received an update from plugin. extracting info from payload Oct 03 13:31:53 volumio volumio[966]: info: CoreStateMachine::pushState Oct 03 13:31:53 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:53 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 03 13:31:53 volumio volumio[966]: info: CoreCommandRouter::volumioPushState Oct 03 13:31:53 volumio volumio[966]: info: CoreStateMachine::pushState Oct 03 13:31:53 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:53 volumio volumio[966]: info: CoreCommandRouter::volumioPushState Oct 03 13:31:53 volumio volumio[966]: info: ------------------------------ 42ms Oct 03 13:31:53 volumio volumio[966]: info: ------------------------------ 45ms Oct 03 13:31:53 volumio volumio[966]: info: sendMpdCommand playlistinfo took 23 milliseconds Oct 03 13:31:53 volumio volumio[966]: info: sendMpdCommand playlistinfo took 22 milliseconds Oct 03 13:31:53 volumio volumio[966]: verbose: ControllerMpd::parseTrackInfo Oct 03 13:31:53 volumio volumio[966]: verbose: ControllerMpd::parseTrackInfo Oct 03 13:31:53 volumio volumio[966]: info: ControllerMpd::pushState Oct 03 13:31:53 volumio volumio[966]: info: CoreCommandRouter::servicePushState Oct 03 13:31:53 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:53 volumio volumio[966]: verbose: STATE SERVICE {"status":"play","position":0,"seek":842,"duration":4156,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"126 Kbps","isStreaming":false,"title":"Музыка телеграфных проводов","artist":"Владимир Кузьмин","album":"Небесное притяжение (live)","uri":"USB/2816E1C616E194DA/Кузьмин Владимир/Владимир Кузьмин и Динамик - Небесное притяжение (live) 1994/Владимир Кузьмин - Небесное притяжение (live).flac","trackType":"flac"} Oct 03 13:31:53 volumio volumio[966]: verbose: CURRENT POSITION 0 Oct 03 13:31:53 volumio volumio[966]: info: CoreStateMachine::syncState stateService play Oct 03 13:31:53 volumio volumio[966]: info: CoreStateMachine::syncState currentStatus play Oct 03 13:31:53 volumio volumio[966]: info: Received an update from plugin. extracting info from payload Oct 03 13:31:53 volumio volumio[966]: info: CoreStateMachine::pushState Oct 03 13:31:53 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:53 volumio volumio[966]: info: CoreCommandRouter::volumioPushState Oct 03 13:31:53 volumio volumio[966]: info: CoreStateMachine::pushState Oct 03 13:31:53 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:53 volumio volumio[966]: info: CoreCommandRouter::volumioPushState Oct 03 13:31:53 volumio volumio[966]: info: ControllerMpd::pushState Oct 03 13:31:53 volumio volumio[966]: info: CoreCommandRouter::servicePushState Oct 03 13:31:53 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:53 volumio volumio[966]: verbose: STATE SERVICE {"status":"play","position":0,"seek":842,"duration":4156,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"126 Kbps","isStreaming":false,"title":"Музыка телеграфных проводов","artist":"Владимир Кузьмин","album":"Небесное притяжение (live)","uri":"USB/2816E1C616E194DA/Кузьмин Владимир/Владимир Кузьмин и Динамик - Небесное притяжение (live) 1994/Владимир Кузьмин - Небесное притяжение (live).flac","trackType":"flac"} Oct 03 13:31:53 volumio volumio[966]: verbose: CURRENT POSITION 0 Oct 03 13:31:53 volumio volumio[966]: info: CoreStateMachine::syncState stateService play Oct 03 13:31:53 volumio volumio[966]: info: CoreStateMachine::syncState currentStatus play Oct 03 13:31:53 volumio volumio[966]: info: Received an update from plugin. extracting info from payload Oct 03 13:31:53 volumio volumio[966]: info: CoreStateMachine::pushState Oct 03 13:31:53 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:53 volumio volumio[966]: info: CoreCommandRouter::volumioPushState Oct 03 13:31:53 volumio volumio[966]: info: CoreStateMachine::pushState Oct 03 13:31:53 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:31:53 volumio volumio[966]: info: CoreCommandRouter::volumioPushState Oct 03 13:31:53 volumio volumio[966]: info: ------------------------------ 58ms Oct 03 13:31:53 volumio volumio[966]: info: ------------------------------ 53ms Oct 03 13:32:33 volumio volumio[966]: info: CoreCommandRouter::volumioGetState Oct 03 13:32:33 volumio volumio[966]: info: CorePlayQueue::getTrack 0 Oct 03 13:32:38 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 03 13:32:38 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 03 13:32:41 volumio volumio[966]: info: Enabling plugin fusiondsp Oct 03 13:32:41 volumio volumio[966]: info: Loading plugin "fusiondsp"... Oct 03 13:32:41 volumio volumio[966]: error: Could not copy default configuration to /data/configuration/audio_interface/fusiondsp/config.json Oct 03 13:32:41 volumio volumio[966]: info: Preparing to generate the ALSA configuration file Oct 03 13:32:41 volumio volumio[966]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Oct 03 13:32:41 volumio volumio[966]: info: Reading ALSA contributions from plugins. Oct 03 13:32:41 volumio volumio[966]: error: Cannot write /etc/asound.conf: Error: ENOSPC: no space left on device, write Oct 03 13:32:41 volumio volumio[966]: info: Output device has changed, restarting MPD Oct 03 13:32:42 volumio volumio[966]: info: Output device has changed, restarting Shairport Sync Oct 03 13:32:42 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:32:42 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 03 13:32:42 volumio sudo[3083]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 03 13:32:42 volumio sudo[3085]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 03 13:32:42 volumio sudo[3085]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 03 13:32:42 volumio sudo[3083]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 03 13:32:42 volumio sudo[3083]: pam_unix(sudo:session): session closed for user root Oct 03 13:32:42 volumio systemd[1]: Stopping Music Player Daemon... Oct 03 13:32:42 volumio volumio[966]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 03 13:32:42 volumio volumio[966]: info: PLUGIN START: fusiondsp Oct 03 13:32:42 volumio volumio[966]: info: Loading i18n strings for locale ru Oct 03 13:32:42 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Oct 03 13:32:42 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:32:42 volumio volumio[966]: info: FusionDsp - mixtype--------------------- Hardware Oct 03 13:32:42 volumio volumio[966]: info: Preparing to generate the ALSA configuration file Oct 03 13:32:42 volumio systemd[1]: mpd.service: Succeeded. Oct 03 13:32:42 volumio systemd[1]: Stopped Music Player Daemon. Oct 03 13:32:42 volumio volumio[966]: info: Done. Oct 03 13:32:42 volumio volumio[966]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Oct 03 13:32:42 volumio volumio[966]: info: Reading ALSA contributions from plugins. Oct 03 13:32:42 volumio volumio[966]: info: MPD Permissions set Oct 03 13:32:42 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:32:42 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:32:42 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:32:42 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:32:42 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:32:42 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:32:42 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:32:42 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:32:42 volumio systemd[1]: Starting Music Player Daemon... Oct 03 13:32:42 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 03 13:32:42 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Oct 03 13:32:42 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:32:42 volumio volumio[966]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 03 13:32:42 volumio volumio[966]: info: Starting Shairport Sync Oct 03 13:32:42 volumio sudo[3099]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 03 13:32:42 volumio sudo[3099]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 03 13:32:42 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 03 13:32:42 volumio systemd[1]: shairport-sync.service: Succeeded. Oct 03 13:32:42 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 03 13:32:42 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 03 13:32:42 volumio sudo[3099]: pam_unix(sudo:session): session closed for user root Oct 03 13:32:42 volumio volumio[966]: info: Shairport-Sync Started Oct 03 13:32:42 volumio volumio[966]: error: Cannot write /etc/asound.conf: Error: ENOSPC: no space left on device, write Oct 03 13:32:42 volumio volumio[966]: info: Output device has changed, restarting MPD Oct 03 13:32:42 volumio sudo[3105]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 03 13:32:42 volumio sudo[3105]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 03 13:32:42 volumio volumio[966]: info: Output device has changed, restarting Shairport Sync Oct 03 13:32:42 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:32:42 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 03 13:32:42 volumio sudo[3105]: pam_unix(sudo:session): session closed for user root Oct 03 13:32:42 volumio sudo[3107]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 03 13:32:42 volumio sudo[3107]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 03 13:32:42 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Oct 03 13:32:42 volumio systemd[1]: mpd.service: Succeeded. Oct 03 13:32:42 volumio systemd[1]: Stopped Music Player Daemon. Oct 03 13:32:42 volumio volumio[966]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 03 13:32:42 volumio volumio[966]: info: MPD Permissions set Oct 03 13:32:42 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:32:42 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:32:42 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:32:42 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:32:42 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:32:42 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:32:42 volumio systemd[1]: Starting Music Player Daemon... Oct 03 13:32:42 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 03 13:32:42 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Oct 03 13:32:42 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:32:42 volumio volumio[966]: info: Starting Shairport Sync Oct 03 13:32:42 volumio sudo[3121]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 03 13:32:42 volumio sudo[3121]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 03 13:32:42 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 03 13:32:42 volumio systemd[1]: shairport-sync.service: Succeeded. Oct 03 13:32:42 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 03 13:32:42 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 03 13:32:42 volumio sudo[3121]: pam_unix(sudo:session): session closed for user root Oct 03 13:32:42 volumio volumio[966]: info: Shairport-Sync Started Oct 03 13:32:43 volumio volumio[966]: Configuration write error: Error: ENOENT: no such file or directory, open '/data/configuration/audio_interface/fusiondsp/config.json' Oct 03 13:32:43 volumio mpd[3113]: Oct 03 13:32 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 03 13:32:43 volumio mpd[3113]: Oct 03 13:32 : exception: Failed to open '/var/lib/mpd/tag_cache': No such file or directory Oct 03 13:32:43 volumio systemd[1]: Started Music Player Daemon. Oct 03 13:32:43 volumio sudo[3085]: pam_unix(sudo:session): session closed for user root Oct 03 13:32:43 volumio sudo[3107]: pam_unix(sudo:session): session closed for user root Oct 03 13:32:43 volumio volumio[966]: error: MPD error: The expression evaluated to a falsy value: Oct 03 13:32:43 volumio volumio[966]: assert.ok(self.idling) Oct 03 13:32:43 volumio volumio[966]: error: The expression evaluated to a falsy value: Oct 03 13:32:43 volumio volumio[966]: assert.ok(self.idling) Oct 03 13:32:43 volumio volumio[966]: error: updateQueue error: null Oct 03 13:32:44 volumio volumio[966]: info: camilladsp spawned new process with pid undefined, instance 1, run: true Oct 03 13:32:44 volumio volumio[966]: info: camilladsp service started and running in background, instance 1 Oct 03 13:32:44 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 03 13:32:44 volumio volumio[966]: /bin/sh: 1: cannot create /data/configuration/audio_interface/fusiondsp/hwinfo.json: Directory nonexistent Oct 03 13:32:44 volumio volumio[966]: error: FusionDsp - ----Hw detection failed :Error: Command failed: /data/plugins/audio_interface/fusiondsp/hw_params volumioHw >/data/configuration/audio_interface/fusiondsp/hwinfo.json Oct 03 13:32:44 volumio volumio[966]: /bin/sh: 1: cannot create /data/configuration/audio_interface/fusiondsp/hwinfo.json: Directory nonexistent Oct 03 13:32:44 volumio volumio[966]: info: FusionDsp loaded Oct 03 13:32:44 volumio volumio[966]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 03 13:32:44 volumio sudo[3139]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Oct 03 13:32:44 volumio sudo[3139]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 03 13:32:44 volumio volumio[966]: info: FusionDsp - Reporting Fusion DSP Enabled Oct 03 13:32:44 volumio volumio[966]: info: Adding Signal Path Element [object Object] Oct 03 13:32:44 volumio volumio[966]: info: Adding fusiondspeq DSP Signal Path Element Oct 03 13:32:44 volumio volumio[966]: info: FusionDsp - ---- installed callbackRead Oct 03 13:32:44 volumio sudo[3139]: pam_unix(sudo:session): session closed for user root Oct 03 13:32:44 volumio volumio[966]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 03 13:32:44 volumio volumio[966]: Error: spawn /data/plugins/audio_interface/fusiondsp/camilladsp EACCES Oct 03 13:32:44 volumio volumio[966]: at Process.ChildProcess._handle.onexit (internal/child_process.js:277:19) Oct 03 13:32:44 volumio volumio[966]: at onErrorNT (internal/child_process.js:472:16) Oct 03 13:32:44 volumio volumio[966]: at processTicksAndRejections (internal/process/task_queues.js:82:21) { Oct 03 13:32:44 volumio volumio[966]: errno: -13, Oct 03 13:32:44 volumio volumio[966]: code: 'EACCES', Oct 03 13:32:44 volumio volumio[966]: syscall: 'spawn /data/plugins/audio_interface/fusiondsp/camilladsp', Oct 03 13:32:44 volumio volumio[966]: path: '/data/plugins/audio_interface/fusiondsp/camilladsp', Oct 03 13:32:44 volumio volumio[966]: spawnargs: [ Oct 03 13:32:44 volumio volumio[966]: '-p', Oct 03 13:32:44 volumio volumio[966]: 9876, Oct 03 13:32:44 volumio volumio[966]: '-o', Oct 03 13:32:44 volumio volumio[966]: '/tmp/camilladsp.log', Oct 03 13:32:44 volumio volumio[966]: '-l', Oct 03 13:32:44 volumio volumio[966]: 'warn', Oct 03 13:32:44 volumio volumio[966]: '/data/configuration/audio_interface/fusiondsp/camilladsp.yml' Oct 03 13:32:44 volumio volumio[966]: ] Oct 03 13:32:44 volumio volumio[966]: } Oct 03 13:32:44 volumio volumio[966]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 03 13:32:44 volumio sudo[3150]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-03 13:31 Oct 03 13:32:44 volumio sudo[3150]: 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="e7445fab547cd22e23d9bef72406cfb610bc1d7d" VOLUMIO_FE_VERSION="5d5e99f8f803b3ec5fc5e8ca13bb4023600f3eee" VOLUMIO_FE3_VERSION="a6ae210575eae1ff43f06ab71e1cd17576840623" VOLUMIO_BE_VERSION="a9e1e1dd6072ffb15c0fcb8938d9ea0d8900c0da" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 24 Apr 2024 02:42:03 PM CEST" VOLUMIO_VERSION="3.661" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="c434411fe8754b648dc7feb1d8f43761"