-- Logs begin at Thu 2019-02-14 10:11:59 GMT, end at Sat 2025-06-07 14:37:42 BST. -- Jun 07 14:36:00 test volumio[890]: info: CoreCommandRouter::volumioPlay Jun 07 14:36:00 test volumio[890]: info: CoreStateMachine::play index undefined Jun 07 14:36:00 test volumio[890]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 07 14:36:00 test volumio[890]: info: CorePlayQueue::getTrack 3 Jun 07 14:36:00 test volumio[890]: info: CoreStateMachine::startPlaybackTimer Jun 07 14:36:00 test volumio[890]: info: CorePlayQueue::getTrack 3 Jun 07 14:36:00 test volumio[890]: info: ControllerMpd::resume Jun 07 14:36:00 test volumio[890]: verbose: ControllerMpd::sendMpdCommand play Jun 07 14:36:00 test volumio[890]: info: sendMpdCommand play took 4 milliseconds Jun 07 14:36:00 test volumio[890]: info: Jun 07 14:36:00 test volumio[890]: ---------------------------- MPD announces state update: player Jun 07 14:36:00 test volumio[890]: info: ControllerMpd::getState Jun 07 14:36:00 test volumio[890]: verbose: ControllerMpd::sendMpdCommand status Jun 07 14:36:00 test volumio[890]: info: Jun 07 14:36:00 test volumio[890]: ---------------------------- MPD announces state update: player Jun 07 14:36:00 test volumio[890]: info: ControllerMpd::getState Jun 07 14:36:00 test volumio[890]: verbose: ControllerMpd::sendMpdCommand status Jun 07 14:36:00 test volumio[890]: info: sendMpdCommand status took 3 milliseconds Jun 07 14:36:00 test volumio[890]: info: sendMpdCommand status took 2 milliseconds Jun 07 14:36:00 test volumio[890]: verbose: ControllerMpd::parseState Jun 07 14:36:00 test volumio[890]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 07 14:36:00 test volumio[890]: verbose: ControllerMpd::parseState Jun 07 14:36:00 test volumio[890]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 07 14:36:00 test volumio[890]: info: sendMpdCommand playlistinfo took 4 milliseconds Jun 07 14:36:00 test volumio[890]: info: sendMpdCommand playlistinfo took 3 milliseconds Jun 07 14:36:00 test volumio[890]: verbose: ControllerMpd::parseTrackInfo Jun 07 14:36:00 test volumio[890]: verbose: ControllerMpd::parseTrackInfo Jun 07 14:36:00 test volumio[890]: info: ControllerMpd::pushState Jun 07 14:36:00 test volumio[890]: info: CoreCommandRouter::servicePushState Jun 07 14:36:00 test volumio[890]: info: CorePlayQueue::getTrack 3 Jun 07 14:36:00 test volumio[890]: verbose: STATE SERVICE {"status":"play","position":0,"seek":33953,"duration":286,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1047 Kbps","isStreaming":false,"title":"Runaway","artist":"The Salsoul Orchestra","album":"Salsoul Classics, Disc Two","uri":"USB/38C6FBC0C6FB7C86/Folder 1; complete tracks/02 Runaway.flac","trackType":"flac"} Jun 07 14:36:00 test volumio[890]: verbose: CURRENT POSITION 3 Jun 07 14:36:00 test volumio[890]: info: CoreStateMachine::syncState stateService play Jun 07 14:36:00 test volumio[890]: info: CoreStateMachine::syncState currentStatus pause Jun 07 14:36:00 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:00 test volumio[890]: info: CorePlayQueue::getTrack 3 Jun 07 14:36:00 test volumio[890]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 07 14:36:00 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:00 test volumio[890]: info: ControllerMpd::pushState Jun 07 14:36:00 test volumio[890]: info: CoreCommandRouter::servicePushState Jun 07 14:36:00 test volumio[890]: info: CorePlayQueue::getTrack 3 Jun 07 14:36:00 test volumio[890]: verbose: STATE SERVICE {"status":"play","position":0,"seek":33953,"duration":286,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1047 Kbps","isStreaming":false,"title":"Runaway","artist":"The Salsoul Orchestra","album":"Salsoul Classics, Disc Two","uri":"USB/38C6FBC0C6FB7C86/Folder 1; complete tracks/02 Runaway.flac","trackType":"flac"} Jun 07 14:36:00 test volumio[890]: verbose: CURRENT POSITION 3 Jun 07 14:36:00 test volumio[890]: info: CoreStateMachine::syncState stateService play Jun 07 14:36:00 test volumio[890]: info: CoreStateMachine::syncState currentStatus play Jun 07 14:36:00 test volumio[890]: info: Received an update from plugin. extracting info from payload Jun 07 14:36:00 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:00 test volumio[890]: info: CorePlayQueue::getTrack 3 Jun 07 14:36:00 test volumio[890]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 07 14:36:00 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:00 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:00 test volumio[890]: info: CorePlayQueue::getTrack 3 Jun 07 14:36:00 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:00 test volumio[890]: info: ------------------------------ 45ms Jun 07 14:36:00 test volumio[890]: info: ------------------------------ 43ms Jun 07 14:36:00 test volumio[890]: info: [ASDebug] CurState: play PrevState: pause Jun 07 14:36:00 test volumio[890]: info: [ASDebug] Togle GPIO: ON Jun 07 14:36:00 test volumio[890]: info: [ASDebug] CurState: play PrevState: play Jun 07 14:36:00 test volumio[890]: info: [ASDebug] CurState: play PrevState: play Jun 07 14:36:18 test volumio[890]: info: CoreCommandRouter::volumioPause Jun 07 14:36:18 test volumio[890]: info: CoreStateMachine::pause Jun 07 14:36:18 test volumio[890]: info: CoreStateMachine::stPlaybackTimer Jun 07 14:36:18 test volumio[890]: info: CoreStateMachine::servicePause Jun 07 14:36:18 test volumio[890]: info: CorePlayQueue::getTrack 3 Jun 07 14:36:18 test volumio[890]: info: CoreCommandRouter::servicePause Jun 07 14:36:18 test volumio[890]: info: ControllerMpd::pause Jun 07 14:36:18 test volumio[890]: verbose: ControllerMpd::sendMpdCommand pause Jun 07 14:36:18 test volumio[890]: info: sendMpdCommand pause took 1 milliseconds Jun 07 14:36:18 test volumio[890]: info: Jun 07 14:36:18 test volumio[890]: ---------------------------- MPD announces state update: player Jun 07 14:36:18 test volumio[890]: info: ControllerMpd::getState Jun 07 14:36:18 test volumio[890]: verbose: ControllerMpd::sendMpdCommand status Jun 07 14:36:18 test volumio[890]: info: Jun 07 14:36:18 test volumio[890]: ---------------------------- MPD announces state update: player Jun 07 14:36:18 test volumio[890]: info: ControllerMpd::getState Jun 07 14:36:18 test volumio[890]: verbose: ControllerMpd::sendMpdCommand status Jun 07 14:36:18 test volumio[890]: info: sendMpdCommand status took 4 milliseconds Jun 07 14:36:18 test volumio[890]: info: sendMpdCommand status took 1 milliseconds Jun 07 14:36:18 test volumio[890]: verbose: ControllerMpd::parseState Jun 07 14:36:18 test volumio[890]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 07 14:36:18 test volumio[890]: verbose: ControllerMpd::parseState Jun 07 14:36:18 test volumio[890]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 07 14:36:18 test volumio[890]: info: sendMpdCommand playlistinfo took 2 milliseconds Jun 07 14:36:18 test volumio[890]: info: sendMpdCommand playlistinfo took 3 milliseconds Jun 07 14:36:18 test volumio[890]: verbose: ControllerMpd::parseTrackInfo Jun 07 14:36:18 test volumio[890]: verbose: ControllerMpd::parseTrackInfo Jun 07 14:36:18 test volumio[890]: info: ControllerMpd::pushState Jun 07 14:36:18 test volumio[890]: info: CoreCommandRouter::servicePushState Jun 07 14:36:18 test volumio[890]: info: CorePlayQueue::getTrack 3 Jun 07 14:36:18 test volumio[890]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":51822,"duration":286,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"892 Kbps","isStreaming":false,"title":"Runaway","artist":"The Salsoul Orchestra","album":"Salsoul Classics, Disc Two","uri":"USB/38C6FBC0C6FB7C86/Folder 1; complete tracks/02 Runaway.flac","trackType":"flac"} Jun 07 14:36:18 test volumio[890]: verbose: CURRENT POSITION 3 Jun 07 14:36:18 test volumio[890]: info: CoreStateMachine::syncState stateService pause Jun 07 14:36:18 test volumio[890]: info: CoreStateMachine::syncState currentStatus pause Jun 07 14:36:18 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:18 test volumio[890]: info: CorePlayQueue::getTrack 3 Jun 07 14:36:18 test volumio[890]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 07 14:36:18 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:18 test volumio[890]: info: CoreStateMachine::stPlaybackTimer Jun 07 14:36:18 test volumio[890]: info: ControllerMpd::pushState Jun 07 14:36:18 test volumio[890]: info: CoreCommandRouter::servicePushState Jun 07 14:36:18 test volumio[890]: info: CorePlayQueue::getTrack 3 Jun 07 14:36:18 test volumio[890]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":51822,"duration":286,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"892 Kbps","isStreaming":false,"title":"Runaway","artist":"The Salsoul Orchestra","album":"Salsoul Classics, Disc Two","uri":"USB/38C6FBC0C6FB7C86/Folder 1; complete tracks/02 Runaway.flac","trackType":"flac"} Jun 07 14:36:18 test volumio[890]: verbose: CURRENT POSITION 3 Jun 07 14:36:18 test volumio[890]: info: CoreStateMachine::syncState stateService pause Jun 07 14:36:18 test volumio[890]: info: CoreStateMachine::syncState currentStatus pause Jun 07 14:36:18 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:18 test volumio[890]: info: CorePlayQueue::getTrack 3 Jun 07 14:36:18 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:18 test volumio[890]: info: CoreStateMachine::stPlaybackTimer Jun 07 14:36:18 test volumio[890]: info: ------------------------------ 57ms Jun 07 14:36:18 test volumio[890]: info: ------------------------------ 56ms Jun 07 14:36:18 test volumio[890]: info: [ASDebug] CurState: pause PrevState: play Jun 07 14:36:18 test volumio[890]: info: [ASDebug] InitTimeout - Amp off in: 0 ms Jun 07 14:36:18 test volumio[890]: info: [ASDebug] CurState: pause PrevState: play Jun 07 14:36:18 test volumio[890]: info: [ASDebug] InitTimeout - Amp off in: 0 ms Jun 07 14:36:18 test volumio[890]: info: [ASDebug] Togle GPIO: OFF Jun 07 14:36:21 test volumio[890]: info: CoreCommandRouter::volumioPlay Jun 07 14:36:21 test volumio[890]: info: CoreStateMachine::play index undefined Jun 07 14:36:21 test volumio[890]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 07 14:36:21 test volumio[890]: info: CorePlayQueue::getTrack 3 Jun 07 14:36:21 test volumio[890]: info: CoreStateMachine::startPlaybackTimer Jun 07 14:36:21 test volumio[890]: info: CorePlayQueue::getTrack 3 Jun 07 14:36:21 test volumio[890]: info: ControllerMpd::resume Jun 07 14:36:21 test volumio[890]: verbose: ControllerMpd::sendMpdCommand play Jun 07 14:36:21 test volumio[890]: info: sendMpdCommand play took 7 milliseconds Jun 07 14:36:21 test volumio[890]: info: Jun 07 14:36:21 test volumio[890]: ---------------------------- MPD announces state update: player Jun 07 14:36:21 test volumio[890]: info: ControllerMpd::getState Jun 07 14:36:21 test volumio[890]: verbose: ControllerMpd::sendMpdCommand status Jun 07 14:36:21 test volumio[890]: info: Jun 07 14:36:21 test volumio[890]: ---------------------------- MPD announces state update: player Jun 07 14:36:21 test volumio[890]: info: ControllerMpd::getState Jun 07 14:36:21 test volumio[890]: verbose: ControllerMpd::sendMpdCommand status Jun 07 14:36:21 test volumio[890]: info: sendMpdCommand status took 5 milliseconds Jun 07 14:36:21 test volumio[890]: verbose: ControllerMpd::parseState Jun 07 14:36:21 test volumio[890]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 07 14:36:21 test volumio[890]: info: sendMpdCommand status took 5 milliseconds Jun 07 14:36:21 test volumio[890]: info: sendMpdCommand playlistinfo took 3 milliseconds Jun 07 14:36:21 test volumio[890]: verbose: ControllerMpd::parseState Jun 07 14:36:21 test volumio[890]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 07 14:36:21 test volumio[890]: verbose: ControllerMpd::parseTrackInfo Jun 07 14:36:21 test volumio[890]: info: ControllerMpd::pushState Jun 07 14:36:21 test volumio[890]: info: CoreCommandRouter::servicePushState Jun 07 14:36:21 test volumio[890]: info: CorePlayQueue::getTrack 3 Jun 07 14:36:21 test volumio[890]: verbose: STATE SERVICE {"status":"play","position":0,"seek":52692,"duration":286,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"840 Kbps","isStreaming":false,"title":"Runaway","artist":"The Salsoul Orchestra","album":"Salsoul Classics, Disc Two","uri":"USB/38C6FBC0C6FB7C86/Folder 1; complete tracks/02 Runaway.flac","trackType":"flac"} Jun 07 14:36:21 test volumio[890]: verbose: CURRENT POSITION 3 Jun 07 14:36:21 test volumio[890]: info: CoreStateMachine::syncState stateService play Jun 07 14:36:21 test volumio[890]: info: CoreStateMachine::syncState currentStatus pause Jun 07 14:36:21 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:21 test volumio[890]: info: CorePlayQueue::getTrack 3 Jun 07 14:36:21 test volumio[890]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 07 14:36:21 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:21 test volumio[890]: info: ------------------------------ 24ms Jun 07 14:36:21 test volumio[890]: info: sendMpdCommand playlistinfo took 15 milliseconds Jun 07 14:36:21 test volumio[890]: verbose: ControllerMpd::parseTrackInfo Jun 07 14:36:21 test volumio[890]: info: ControllerMpd::pushState Jun 07 14:36:21 test volumio[890]: info: CoreCommandRouter::servicePushState Jun 07 14:36:21 test volumio[890]: info: CorePlayQueue::getTrack 3 Jun 07 14:36:21 test volumio[890]: verbose: STATE SERVICE {"status":"play","position":0,"seek":52692,"duration":286,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"840 Kbps","isStreaming":false,"title":"Runaway","artist":"The Salsoul Orchestra","album":"Salsoul Classics, Disc Two","uri":"USB/38C6FBC0C6FB7C86/Folder 1; complete tracks/02 Runaway.flac","trackType":"flac"} Jun 07 14:36:21 test volumio[890]: verbose: CURRENT POSITION 3 Jun 07 14:36:21 test volumio[890]: info: CoreStateMachine::syncState stateService play Jun 07 14:36:21 test volumio[890]: info: CoreStateMachine::syncState currentStatus play Jun 07 14:36:21 test volumio[890]: info: Received an update from plugin. extracting info from payload Jun 07 14:36:21 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:21 test volumio[890]: info: CorePlayQueue::getTrack 3 Jun 07 14:36:21 test volumio[890]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 07 14:36:21 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:21 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:21 test volumio[890]: info: CorePlayQueue::getTrack 3 Jun 07 14:36:21 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:21 test volumio[890]: info: ------------------------------ 50ms Jun 07 14:36:21 test volumio[890]: info: [ASDebug] CurState: play PrevState: pause Jun 07 14:36:21 test volumio[890]: info: [ASDebug] Togle GPIO: ON Jun 07 14:36:21 test volumio[890]: info: [ASDebug] CurState: play PrevState: play Jun 07 14:36:21 test volumio[890]: info: [ASDebug] CurState: play PrevState: play Jun 07 14:36:33 test volumio[890]: info: CoreCommandRouter::volumioSeek Jun 07 14:36:33 test volumio[890]: info: CoreStateMachine::seek Jun 07 14:36:33 test volumio[890]: info: CorePlayQueue::getTrack 3 Jun 07 14:36:33 test volumio[890]: info: TRACKBLOCK {"uri":"mnt/USB/38C6FBC0C6FB7C86/Folder 1; complete tracks/02 Runaway.flac","service":"mpd","name":"Runaway","artist":"The Salsoul Orchestra","album":"Salsoul Classics, Disc Two","type":"track","tracknumber":0,"albumart":"/albumart?cacheid=356&web=The%20Salsoul%20Orchestra/Salsoul%20Classics%2C%20Disc%20Two/extralarge&path=%2FUSB%2F38C6FBC0C6FB7C86%2FFolder%201%3B%20complete%20tracks&metadata=false","duration":286,"samplerate":"44.1 kHz","bitdepth":"16 bit","trackType":"flac","channels":2} Jun 07 14:36:33 test volumio[890]: info: CoreStateMachine::startPlaybackTimer Jun 07 14:36:33 test volumio[890]: info: CorePlayQueue::getTrack 3 Jun 07 14:36:33 test volumio[890]: info: ControllerMpd::seek Jun 07 14:36:33 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:33 test volumio[890]: info: CorePlayQueue::getTrack 3 Jun 07 14:36:33 test volumio[890]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 07 14:36:33 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:33 test volumio[890]: error: null Jun 07 14:36:33 test volumio[890]: info: Jun 07 14:36:33 test volumio[890]: ---------------------------- MPD announces state update: player Jun 07 14:36:33 test volumio[890]: info: ControllerMpd::getState Jun 07 14:36:33 test volumio[890]: verbose: ControllerMpd::sendMpdCommand status Jun 07 14:36:33 test volumio[890]: info: Jun 07 14:36:33 test volumio[890]: ---------------------------- MPD announces state update: player Jun 07 14:36:33 test volumio[890]: info: ControllerMpd::getState Jun 07 14:36:33 test volumio[890]: verbose: ControllerMpd::sendMpdCommand status Jun 07 14:36:33 test volumio[890]: info: [ASDebug] CurState: play PrevState: play Jun 07 14:36:33 test volumio[890]: info: sendMpdCommand status took 97 milliseconds Jun 07 14:36:33 test volumio[890]: verbose: ControllerMpd::parseState Jun 07 14:36:33 test volumio[890]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 07 14:36:33 test volumio[890]: info: Jun 07 14:36:33 test volumio[890]: ---------------------------- MPD announces state update: player Jun 07 14:36:33 test volumio[890]: info: ControllerMpd::getState Jun 07 14:36:33 test volumio[890]: verbose: ControllerMpd::sendMpdCommand status Jun 07 14:36:33 test volumio[890]: info: Jun 07 14:36:33 test volumio[890]: ---------------------------- MPD announces state update: player Jun 07 14:36:33 test volumio[890]: info: ControllerMpd::getState Jun 07 14:36:33 test volumio[890]: verbose: ControllerMpd::sendMpdCommand status Jun 07 14:36:33 test volumio[890]: info: sendMpdCommand status took 112 milliseconds Jun 07 14:36:33 test volumio[890]: info: sendMpdCommand playlistinfo took 16 milliseconds Jun 07 14:36:33 test volumio[890]: verbose: ControllerMpd::parseState Jun 07 14:36:33 test volumio[890]: verbose: ControllerMpd::parseTrackInfo Jun 07 14:36:33 test volumio[890]: info: ControllerMpd::pushState Jun 07 14:36:33 test volumio[890]: info: CoreCommandRouter::servicePushState Jun 07 14:36:33 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:33 test volumio[890]: info: CorePlayQueue::getTrack 3 Jun 07 14:36:33 test volumio[890]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 07 14:36:33 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:33 test volumio[890]: info: CorePlayQueue::getTrack 3 Jun 07 14:36:33 test volumio[890]: 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} Jun 07 14:36:33 test volumio[890]: verbose: CURRENT POSITION 3 Jun 07 14:36:33 test volumio[890]: info: CoreStateMachine::syncState stateService stop Jun 07 14:36:33 test volumio[890]: info: CoreStateMachine::syncState currentStatus play Jun 07 14:36:33 test volumio[890]: info: CoreStateMachine::play index undefined Jun 07 14:36:33 test volumio[890]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 07 14:36:33 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:33 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:33 test volumio[890]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 07 14:36:33 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:33 test volumio[890]: info: ControllerMpd::pushState Jun 07 14:36:33 test volumio[890]: info: CoreCommandRouter::servicePushState Jun 07 14:36:33 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:33 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:33 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:33 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:33 test volumio[890]: 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":"Runaway","artist":"The Salsoul Orchestra","album":"Salsoul Classics, Disc Two","uri":"USB/38C6FBC0C6FB7C86/Folder 1; complete tracks/02 Runaway.flac","trackType":"flac"} Jun 07 14:36:33 test volumio[890]: verbose: CURRENT POSITION 4 Jun 07 14:36:33 test volumio[890]: info: CoreStateMachine::syncState stateService stop Jun 07 14:36:33 test volumio[890]: info: CoreStateMachine::syncState currentStatus stop Jun 07 14:36:33 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:33 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:33 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:33 test volumio[890]: info: No code Jun 07 14:36:33 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:33 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:33 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:33 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:33 test volumio[890]: info: CoreStateMachine::startPlaybackTimer Jun 07 14:36:33 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:33 test volumio[890]: verbose: ControllerMpd::clearAddPlayTracks USB/38C6FBC0C6FB7C86/Folder 1; complete tracks/06.1 The Rainmaker.flac Jun 07 14:36:33 test volumio[890]: verbose: ControllerMpd::sendMpdCommand stop Jun 07 14:36:33 test volumio[890]: info: ------------------------------ 172ms Jun 07 14:36:33 test volumio[890]: info: ------------------------------ 175ms Jun 07 14:36:33 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:33 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:33 test volumio[890]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 07 14:36:33 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:33 test volumio[890]: info: sendMpdCommand status took 75 milliseconds Jun 07 14:36:33 test volumio[890]: info: sendMpdCommand status took 74 milliseconds Jun 07 14:36:33 test volumio[890]: info: sendMpdCommand stop took 15 milliseconds Jun 07 14:36:33 test volumio[890]: verbose: ControllerMpd::parseState Jun 07 14:36:33 test volumio[890]: verbose: ControllerMpd::parseState Jun 07 14:36:33 test volumio[890]: verbose: ControllerMpd::sendMpdCommand clear Jun 07 14:36:33 test volumio[890]: info: ControllerMpd::pushState Jun 07 14:36:33 test volumio[890]: info: CoreCommandRouter::servicePushState Jun 07 14:36:33 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:33 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:33 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:33 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:33 test volumio[890]: 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} Jun 07 14:36:33 test volumio[890]: verbose: CURRENT POSITION 4 Jun 07 14:36:33 test volumio[890]: info: CoreStateMachine::syncState stateService stop Jun 07 14:36:33 test volumio[890]: info: CoreStateMachine::syncState currentStatus stop Jun 07 14:36:33 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:33 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:33 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:33 test volumio[890]: info: No code Jun 07 14:36:33 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:33 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:33 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:33 test volumio[890]: info: ControllerMpd::pushState Jun 07 14:36:33 test volumio[890]: info: CoreCommandRouter::servicePushState Jun 07 14:36:33 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:33 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:33 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:34 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:34 test volumio[890]: 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} Jun 07 14:36:34 test volumio[890]: verbose: CURRENT POSITION 4 Jun 07 14:36:34 test volumio[890]: info: CoreStateMachine::syncState stateService stop Jun 07 14:36:34 test volumio[890]: info: CoreStateMachine::syncState currentStatus stop Jun 07 14:36:34 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:34 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:34 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:34 test volumio[890]: info: No code Jun 07 14:36:34 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:34 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:34 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:34 test volumio[890]: info: ------------------------------ 129ms Jun 07 14:36:34 test volumio[890]: info: ------------------------------ 128ms Jun 07 14:36:34 test volumio[890]: info: [ASDebug] CurState: play PrevState: play Jun 07 14:36:34 test volumio[890]: info: [ASDebug] CurState: stop PrevState: play Jun 07 14:36:34 test volumio[890]: info: [ASDebug] InitTimeout - Amp off in: 0 ms Jun 07 14:36:34 test volumio[890]: info: [ASDebug] CurState: stop PrevState: play Jun 07 14:36:34 test volumio[890]: info: [ASDebug] InitTimeout - Amp off in: 0 ms Jun 07 14:36:34 test volumio[890]: info: [ASDebug] CurState: stop PrevState: play Jun 07 14:36:34 test volumio[890]: info: [ASDebug] InitTimeout - Amp off in: 0 ms Jun 07 14:36:34 test volumio[890]: info: [ASDebug] CurState: stop PrevState: play Jun 07 14:36:34 test volumio[890]: info: [ASDebug] InitTimeout - Amp off in: 0 ms Jun 07 14:36:34 test volumio[890]: info: [ASDebug] CurState: stop PrevState: play Jun 07 14:36:34 test volumio[890]: info: [ASDebug] InitTimeout - Amp off in: 0 ms Jun 07 14:36:34 test volumio[890]: info: [ASDebug] CurState: stop PrevState: play Jun 07 14:36:34 test volumio[890]: info: [ASDebug] InitTimeout - Amp off in: 0 ms Jun 07 14:36:34 test volumio[890]: info: [ASDebug] CurState: stop PrevState: play Jun 07 14:36:34 test volumio[890]: info: [ASDebug] InitTimeout - Amp off in: 0 ms Jun 07 14:36:34 test volumio[890]: info: [ASDebug] CurState: stop PrevState: play Jun 07 14:36:34 test volumio[890]: info: [ASDebug] InitTimeout - Amp off in: 0 ms Jun 07 14:36:34 test volumio[890]: info: [ASDebug] CurState: stop PrevState: play Jun 07 14:36:34 test volumio[890]: info: [ASDebug] InitTimeout - Amp off in: 0 ms Jun 07 14:36:34 test volumio[890]: info: [ASDebug] CurState: stop PrevState: play Jun 07 14:36:34 test volumio[890]: info: [ASDebug] InitTimeout - Amp off in: 0 ms Jun 07 14:36:34 test volumio[890]: info: [ASDebug] CurState: stop PrevState: play Jun 07 14:36:34 test volumio[890]: info: [ASDebug] InitTimeout - Amp off in: 0 ms Jun 07 14:36:34 test volumio[890]: info: [ASDebug] Togle GPIO: OFF Jun 07 14:36:34 test volumio[890]: info: Jun 07 14:36:34 test volumio[890]: ---------------------------- MPD announces system playlist update Jun 07 14:36:34 test volumio[890]: info: Ignoring MPD Status Update Jun 07 14:36:34 test volumio[890]: info: sendMpdCommand clear took 84 milliseconds Jun 07 14:36:34 test volumio[890]: verbose: ControllerMpd::sendMpdCommand add "USB/38C6FBC0C6FB7C86/Folder 1; complete tracks/06.1 The Rainmaker.flac" Jun 07 14:36:34 test volumio[890]: info: Jun 07 14:36:34 test volumio[890]: ---------------------------- MPD announces system playlist update Jun 07 14:36:34 test volumio[890]: info: Ignoring MPD Status Update Jun 07 14:36:34 test volumio[890]: error: updateQueue error: null Jun 07 14:36:34 test volumio[890]: info: Jun 07 14:36:34 test volumio[890]: ---------------------------- MPD announces system playlist update Jun 07 14:36:34 test volumio[890]: info: Ignoring MPD Status Update Jun 07 14:36:34 test volumio[890]: info: ------------------------------ 11ms Jun 07 14:36:34 test volumio[890]: info: sendMpdCommand add "USB/38C6FBC0C6FB7C86/Folder 1; complete tracks/06.1 The Rainmaker.flac" took 9 milliseconds Jun 07 14:36:34 test volumio[890]: info: ------------------------------ 9ms Jun 07 14:36:34 test volumio[890]: verbose: ControllerMpd::sendMpdCommand play Jun 07 14:36:34 test volumio[890]: info: Jun 07 14:36:34 test volumio[890]: ---------------------------- MPD announces system playlist update Jun 07 14:36:34 test volumio[890]: info: Ignoring MPD Status Update Jun 07 14:36:34 test volumio[890]: info: CoreCommandRouter::volumioSeek Jun 07 14:36:34 test volumio[890]: info: CoreStateMachine::seek Jun 07 14:36:34 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:34 test volumio[890]: info: TRACKBLOCK {"uri":"mnt/USB/38C6FBC0C6FB7C86/Folder 1; complete tracks/06.1 The Rainmaker.flac","service":"mpd","name":"The Rainmaker","artist":"Earl Klugh","album":"The Best of Earl Klugh, Volume 2","type":"track","tracknumber":0,"albumart":"/albumart?cacheid=356&web=Earl%20Klugh/The%20Best%20of%20Earl%20Klugh%2C%20Volume%202/extralarge&path=%2FUSB%2F38C6FBC0C6FB7C86%2FFolder%201%3B%20complete%20tracks&metadata=false","duration":318,"trackType":"flac"} Jun 07 14:36:34 test volumio[890]: info: CoreStateMachine::startPlaybackTimer Jun 07 14:36:34 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:34 test volumio[890]: info: ControllerMpd::seek Jun 07 14:36:34 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:34 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:34 test volumio[890]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 07 14:36:34 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:34 test volumio[890]: info: Jun 07 14:36:34 test volumio[890]: ---------------------------- MPD announces state update: player Jun 07 14:36:34 test volumio[890]: info: Jun 07 14:36:34 test volumio[890]: ---------------------------- MPD announces state update: player Jun 07 14:36:34 test volumio[890]: info: ------------------------------ 57ms Jun 07 14:36:34 test volumio[890]: info: sendMpdCommand play took 55 milliseconds Jun 07 14:36:34 test volumio[890]: info: ControllerMpd::getState Jun 07 14:36:34 test volumio[890]: verbose: ControllerMpd::sendMpdCommand status Jun 07 14:36:34 test volumio[890]: info: ------------------------------ 23ms Jun 07 14:36:34 test volumio[890]: info: ControllerMpd::getState Jun 07 14:36:34 test volumio[890]: verbose: ControllerMpd::sendMpdCommand status Jun 07 14:36:34 test volumio[890]: info: Jun 07 14:36:34 test volumio[890]: ---------------------------- MPD announces state update: player Jun 07 14:36:34 test volumio[890]: info: ControllerMpd::getState Jun 07 14:36:34 test volumio[890]: verbose: ControllerMpd::sendMpdCommand status Jun 07 14:36:34 test volumio[890]: info: [ASDebug] CurState: stop PrevState: stop Jun 07 14:36:34 test volumio[890]: error: null Jun 07 14:36:34 test volumio[890]: info: Jun 07 14:36:34 test volumio[890]: ---------------------------- MPD announces state update: player Jun 07 14:36:34 test volumio[890]: info: ControllerMpd::getState Jun 07 14:36:34 test volumio[890]: verbose: ControllerMpd::sendMpdCommand status Jun 07 14:36:34 test volumio[890]: info: sendMpdCommand status took 14 milliseconds Jun 07 14:36:34 test volumio[890]: info: sendMpdCommand status took 13 milliseconds Jun 07 14:36:34 test volumio[890]: info: sendMpdCommand status took 11 milliseconds Jun 07 14:36:34 test volumio[890]: verbose: ControllerMpd::parseState Jun 07 14:36:34 test volumio[890]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 07 14:36:34 test volumio[890]: verbose: ControllerMpd::parseState Jun 07 14:36:34 test volumio[890]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 07 14:36:34 test volumio[890]: verbose: ControllerMpd::parseState Jun 07 14:36:34 test volumio[890]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 07 14:36:34 test volumio[890]: info: Jun 07 14:36:34 test volumio[890]: ---------------------------- MPD announces state update: player Jun 07 14:36:34 test volumio[890]: info: ControllerMpd::getState Jun 07 14:36:34 test volumio[890]: verbose: ControllerMpd::sendMpdCommand status Jun 07 14:36:34 test volumio[890]: info: sendMpdCommand status took 9 milliseconds Jun 07 14:36:34 test volumio[890]: info: sendMpdCommand playlistinfo took 7 milliseconds Jun 07 14:36:34 test volumio[890]: info: sendMpdCommand playlistinfo took 6 milliseconds Jun 07 14:36:34 test volumio[890]: info: sendMpdCommand playlistinfo took 5 milliseconds Jun 07 14:36:34 test volumio[890]: info: sendMpdCommand status took 4 milliseconds Jun 07 14:36:34 test volumio[890]: verbose: ControllerMpd::parseState Jun 07 14:36:34 test volumio[890]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 07 14:36:34 test volumio[890]: verbose: ControllerMpd::parseTrackInfo Jun 07 14:36:34 test volumio[890]: verbose: ControllerMpd::parseTrackInfo Jun 07 14:36:34 test volumio[890]: verbose: ControllerMpd::parseTrackInfo Jun 07 14:36:34 test volumio[890]: verbose: ControllerMpd::parseState Jun 07 14:36:34 test volumio[890]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 07 14:36:34 test volumio[890]: info: ControllerMpd::pushState Jun 07 14:36:34 test volumio[890]: info: CoreCommandRouter::servicePushState Jun 07 14:36:34 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:34 test volumio[890]: verbose: STATE SERVICE {"status":"play","position":0,"seek":312457,"duration":318,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"397 Kbps","isStreaming":false,"title":"The Rainmaker","artist":"Earl Klugh","album":"The Best of Earl Klugh, Volume 2","uri":"USB/38C6FBC0C6FB7C86/Folder 1; complete tracks/06.1 The Rainmaker.flac","trackType":"flac"} Jun 07 14:36:34 test volumio[890]: verbose: CURRENT POSITION 4 Jun 07 14:36:34 test volumio[890]: info: CoreStateMachine::syncState stateService play Jun 07 14:36:34 test volumio[890]: info: CoreStateMachine::syncState currentStatus stop Jun 07 14:36:34 test volumio[890]: info: ControllerMpd::pushState Jun 07 14:36:34 test volumio[890]: info: CoreCommandRouter::servicePushState Jun 07 14:36:34 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:34 test volumio[890]: verbose: STATE SERVICE {"status":"play","position":0,"seek":312846,"duration":318,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"330 Kbps","isStreaming":false,"title":"The Rainmaker","artist":"Earl Klugh","album":"The Best of Earl Klugh, Volume 2","uri":"USB/38C6FBC0C6FB7C86/Folder 1; complete tracks/06.1 The Rainmaker.flac","trackType":"flac"} Jun 07 14:36:34 test volumio[890]: verbose: CURRENT POSITION 4 Jun 07 14:36:34 test volumio[890]: info: CoreStateMachine::syncState stateService play Jun 07 14:36:34 test volumio[890]: info: CoreStateMachine::syncState currentStatus play Jun 07 14:36:34 test volumio[890]: info: Received an update from plugin. extracting info from payload Jun 07 14:36:34 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:34 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:34 test volumio[890]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 07 14:36:34 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:34 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:34 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:34 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:34 test volumio[890]: info: ControllerMpd::pushState Jun 07 14:36:34 test volumio[890]: info: CoreCommandRouter::servicePushState Jun 07 14:36:34 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:34 test volumio[890]: verbose: STATE SERVICE {"status":"play","position":0,"seek":312846,"duration":318,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"289 Kbps","isStreaming":false,"title":"The Rainmaker","artist":"Earl Klugh","album":"The Best of Earl Klugh, Volume 2","uri":"USB/38C6FBC0C6FB7C86/Folder 1; complete tracks/06.1 The Rainmaker.flac","trackType":"flac"} Jun 07 14:36:34 test volumio[890]: verbose: CURRENT POSITION 4 Jun 07 14:36:34 test volumio[890]: info: CoreStateMachine::syncState stateService play Jun 07 14:36:34 test volumio[890]: info: CoreStateMachine::syncState currentStatus play Jun 07 14:36:34 test volumio[890]: info: Received an update from plugin. extracting info from payload Jun 07 14:36:34 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:34 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:34 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:34 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:34 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:34 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:34 test volumio[890]: info: ------------------------------ 47ms Jun 07 14:36:34 test volumio[890]: info: ------------------------------ 68ms Jun 07 14:36:34 test volumio[890]: info: ------------------------------ 64ms Jun 07 14:36:34 test volumio[890]: info: sendMpdCommand playlistinfo took 44 milliseconds Jun 07 14:36:34 test volumio[890]: info: sendMpdCommand playlistinfo took 44 milliseconds Jun 07 14:36:34 test volumio[890]: verbose: ControllerMpd::parseTrackInfo Jun 07 14:36:34 test volumio[890]: verbose: ControllerMpd::parseTrackInfo Jun 07 14:36:34 test volumio[890]: info: ControllerMpd::pushState Jun 07 14:36:34 test volumio[890]: info: CoreCommandRouter::servicePushState Jun 07 14:36:34 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:34 test volumio[890]: verbose: STATE SERVICE {"status":"play","position":0,"seek":312846,"duration":318,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"278 Kbps","isStreaming":false,"title":"The Rainmaker","artist":"Earl Klugh","album":"The Best of Earl Klugh, Volume 2","uri":"USB/38C6FBC0C6FB7C86/Folder 1; complete tracks/06.1 The Rainmaker.flac","trackType":"flac"} Jun 07 14:36:34 test volumio[890]: verbose: CURRENT POSITION 4 Jun 07 14:36:34 test volumio[890]: info: CoreStateMachine::syncState stateService play Jun 07 14:36:34 test volumio[890]: info: CoreStateMachine::syncState currentStatus play Jun 07 14:36:34 test volumio[890]: info: Received an update from plugin. extracting info from payload Jun 07 14:36:34 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:34 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:34 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:34 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:34 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:34 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:34 test volumio[890]: info: ControllerMpd::pushState Jun 07 14:36:34 test volumio[890]: info: CoreCommandRouter::servicePushState Jun 07 14:36:34 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:34 test volumio[890]: verbose: STATE SERVICE {"status":"play","position":0,"seek":312846,"duration":318,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"278 Kbps","isStreaming":false,"title":"The Rainmaker","artist":"Earl Klugh","album":"The Best of Earl Klugh, Volume 2","uri":"USB/38C6FBC0C6FB7C86/Folder 1; complete tracks/06.1 The Rainmaker.flac","trackType":"flac"} Jun 07 14:36:34 test volumio[890]: verbose: CURRENT POSITION 4 Jun 07 14:36:34 test volumio[890]: info: CoreStateMachine::syncState stateService play Jun 07 14:36:34 test volumio[890]: info: CoreStateMachine::syncState currentStatus play Jun 07 14:36:34 test volumio[890]: info: Received an update from plugin. extracting info from payload Jun 07 14:36:34 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:34 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:34 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:34 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:34 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:34 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:34 test volumio[890]: info: ------------------------------ 93ms Jun 07 14:36:34 test volumio[890]: info: ------------------------------ 87ms Jun 07 14:36:34 test volumio[890]: info: [ASDebug] CurState: play PrevState: stop Jun 07 14:36:34 test volumio[890]: info: [ASDebug] Togle GPIO: ON Jun 07 14:36:34 test volumio[890]: info: [ASDebug] CurState: play PrevState: play Jun 07 14:36:34 test volumio[890]: info: [ASDebug] CurState: play PrevState: play Jun 07 14:36:34 test volumio[890]: info: [ASDebug] CurState: play PrevState: play Jun 07 14:36:34 test volumio[890]: info: [ASDebug] CurState: play PrevState: play Jun 07 14:36:34 test volumio[890]: info: [ASDebug] CurState: play PrevState: play Jun 07 14:36:34 test volumio[890]: info: [ASDebug] CurState: play PrevState: play Jun 07 14:36:34 test volumio[890]: info: [ASDebug] CurState: play PrevState: play Jun 07 14:36:34 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:34 test volumio[890]: info: CorePlayQueue::getTrack 5 Jun 07 14:36:34 test volumio[890]: info: Prefetching next song Jun 07 14:36:34 test volumio[890]: info: DOING PREFETCH IN MPD Jun 07 14:36:34 test volumio[890]: verbose: ControllerMpd::sendMpdCommand add "USB/38C6FBC0C6FB7C86/Folder 1; complete tracks/02.1 Grandstand (Current Theme).flac" Jun 07 14:36:34 test volumio[890]: info: Jun 07 14:36:34 test volumio[890]: ---------------------------- MPD announces system playlist update Jun 07 14:36:34 test volumio[890]: info: Ignoring MPD Status Update Jun 07 14:36:34 test volumio[890]: info: sendMpdCommand add "USB/38C6FBC0C6FB7C86/Folder 1; complete tracks/02.1 Grandstand (Current Theme).flac" took 2 milliseconds Jun 07 14:36:34 test volumio[890]: verbose: ControllerMpd::sendMpdCommand consume 1 Jun 07 14:36:34 test volumio[890]: info: Jun 07 14:36:34 test volumio[890]: ---------------------------- MPD announces system playlist update Jun 07 14:36:34 test volumio[890]: info: Ignoring MPD Status Update Jun 07 14:36:34 test volumio[890]: info: Jun 07 14:36:34 test volumio[890]: ---------------------------- MPD announces state update: options Jun 07 14:36:34 test volumio[890]: info: ------------------------------ 8ms Jun 07 14:36:34 test volumio[890]: info: sendMpdCommand consume 1 took 5 milliseconds Jun 07 14:36:34 test volumio[890]: info: ControllerMpd::getState Jun 07 14:36:34 test volumio[890]: verbose: ControllerMpd::sendMpdCommand status Jun 07 14:36:34 test volumio[890]: info: ------------------------------ 5ms Jun 07 14:36:34 test volumio[890]: info: Jun 07 14:36:34 test volumio[890]: ---------------------------- MPD announces state update: options Jun 07 14:36:34 test volumio[890]: info: ControllerMpd::getState Jun 07 14:36:34 test volumio[890]: verbose: ControllerMpd::sendMpdCommand status Jun 07 14:36:34 test volumio[890]: info: sendMpdCommand status took 12 milliseconds Jun 07 14:36:34 test volumio[890]: verbose: ControllerMpd::parseState Jun 07 14:36:34 test volumio[890]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 07 14:36:34 test volumio[890]: info: sendMpdCommand status took 5 milliseconds Jun 07 14:36:34 test volumio[890]: info: sendMpdCommand playlistinfo took 3 milliseconds Jun 07 14:36:34 test volumio[890]: verbose: ControllerMpd::parseState Jun 07 14:36:34 test volumio[890]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 07 14:36:34 test volumio[890]: verbose: ControllerMpd::parseTrackInfo Jun 07 14:36:34 test volumio[890]: info: ControllerMpd::pushState Jun 07 14:36:34 test volumio[890]: info: CoreCommandRouter::servicePushState Jun 07 14:36:34 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:34 test volumio[890]: verbose: STATE SERVICE {"status":"play","position":0,"seek":313098,"duration":318,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"312 Kbps","isStreaming":false,"title":"The Rainmaker","artist":"Earl Klugh","album":"The Best of Earl Klugh, Volume 2","uri":"USB/38C6FBC0C6FB7C86/Folder 1; complete tracks/06.1 The Rainmaker.flac","trackType":"flac"} Jun 07 14:36:34 test volumio[890]: verbose: CURRENT POSITION 4 Jun 07 14:36:34 test volumio[890]: info: CoreStateMachine::syncState stateService play Jun 07 14:36:34 test volumio[890]: info: CoreStateMachine::syncState currentStatus play Jun 07 14:36:34 test volumio[890]: info: Received an update from plugin. extracting info from payload Jun 07 14:36:34 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:34 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:34 test volumio[890]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 07 14:36:34 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:34 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:34 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:34 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:34 test volumio[890]: info: ------------------------------ 53ms Jun 07 14:36:34 test volumio[890]: info: sendMpdCommand playlistinfo took 33 milliseconds Jun 07 14:36:34 test volumio[890]: verbose: ControllerMpd::parseTrackInfo Jun 07 14:36:34 test volumio[890]: info: ControllerMpd::pushState Jun 07 14:36:34 test volumio[890]: info: CoreCommandRouter::servicePushState Jun 07 14:36:34 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:34 test volumio[890]: verbose: STATE SERVICE {"status":"play","position":0,"seek":313098,"duration":318,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"312 Kbps","isStreaming":false,"title":"The Rainmaker","artist":"Earl Klugh","album":"The Best of Earl Klugh, Volume 2","uri":"USB/38C6FBC0C6FB7C86/Folder 1; complete tracks/06.1 The Rainmaker.flac","trackType":"flac"} Jun 07 14:36:34 test volumio[890]: verbose: CURRENT POSITION 4 Jun 07 14:36:34 test volumio[890]: info: CoreStateMachine::syncState stateService play Jun 07 14:36:34 test volumio[890]: info: CoreStateMachine::syncState currentStatus play Jun 07 14:36:34 test volumio[890]: info: Received an update from plugin. extracting info from payload Jun 07 14:36:34 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:34 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:34 test volumio[890]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 07 14:36:34 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:34 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:34 test volumio[890]: info: CorePlayQueue::getTrack 4 Jun 07 14:36:34 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:34 test volumio[890]: info: ------------------------------ 73ms Jun 07 14:36:34 test volumio[890]: info: [ASDebug] CurState: play PrevState: play Jun 07 14:36:34 test volumio[890]: info: [ASDebug] CurState: play PrevState: play Jun 07 14:36:34 test volumio[890]: info: [ASDebug] CurState: play PrevState: play Jun 07 14:36:34 test volumio[890]: info: [ASDebug] CurState: play PrevState: play Jun 07 14:36:38 test volumio[890]: info: CoreStateMachine::startPlaybackTimer Jun 07 14:36:38 test volumio[890]: info: CorePlayQueue::getTrack 5 Jun 07 14:36:39 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:39 test volumio[890]: info: CorePlayQueue::getTrack 5 Jun 07 14:36:39 test volumio[890]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 07 14:36:39 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:39 test volumio[890]: info: [ASDebug] CurState: play PrevState: play Jun 07 14:36:39 test volumio[890]: info: Jun 07 14:36:39 test volumio[890]: ---------------------------- MPD announces system playlist update Jun 07 14:36:39 test volumio[890]: info: Ignoring MPD Status Update Jun 07 14:36:39 test volumio[890]: info: Jun 07 14:36:39 test volumio[890]: ---------------------------- MPD announces state update: player Jun 07 14:36:39 test volumio[890]: info: ControllerMpd::getState Jun 07 14:36:39 test volumio[890]: verbose: ControllerMpd::sendMpdCommand status Jun 07 14:36:39 test volumio[890]: info: Jun 07 14:36:39 test volumio[890]: ---------------------------- MPD announces system playlist update Jun 07 14:36:39 test volumio[890]: info: Ignoring MPD Status Update Jun 07 14:36:39 test volumio[890]: info: Jun 07 14:36:39 test volumio[890]: ---------------------------- MPD announces state update: player Jun 07 14:36:39 test volumio[890]: info: ControllerMpd::getState Jun 07 14:36:39 test volumio[890]: verbose: ControllerMpd::sendMpdCommand status Jun 07 14:36:39 test volumio[890]: info: ------------------------------ 6ms Jun 07 14:36:39 test volumio[890]: info: sendMpdCommand status took 4 milliseconds Jun 07 14:36:39 test volumio[890]: info: ------------------------------ 4ms Jun 07 14:36:39 test volumio[890]: info: sendMpdCommand status took 3 milliseconds Jun 07 14:36:39 test volumio[890]: verbose: ControllerMpd::parseState Jun 07 14:36:39 test volumio[890]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 07 14:36:39 test volumio[890]: verbose: ControllerMpd::parseState Jun 07 14:36:39 test volumio[890]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 07 14:36:39 test volumio[890]: info: sendMpdCommand playlistinfo took 3 milliseconds Jun 07 14:36:39 test volumio[890]: info: sendMpdCommand playlistinfo took 2 milliseconds Jun 07 14:36:39 test volumio[890]: verbose: ControllerMpd::parseTrackInfo Jun 07 14:36:39 test volumio[890]: verbose: ControllerMpd::parseTrackInfo Jun 07 14:36:39 test volumio[890]: info: ControllerMpd::pushState Jun 07 14:36:39 test volumio[890]: info: CoreCommandRouter::servicePushState Jun 07 14:36:39 test volumio[890]: info: CorePlayQueue::getTrack 5 Jun 07 14:36:39 test volumio[890]: verbose: STATE SERVICE {"status":"play","position":0,"seek":22,"duration":147,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"661 Kbps","isStreaming":false,"title":"Grandstand (Current Theme)","artist":"Sound Stage Orchestra","album":"The Great Sporting Experience","uri":"USB/38C6FBC0C6FB7C86/Folder 1; complete tracks/02.1 Grandstand (Current Theme).flac","trackType":"flac"} Jun 07 14:36:39 test volumio[890]: verbose: CURRENT POSITION 5 Jun 07 14:36:39 test volumio[890]: info: CoreStateMachine::syncState stateService play Jun 07 14:36:39 test volumio[890]: info: CoreStateMachine::syncState currentStatus play Jun 07 14:36:39 test volumio[890]: info: Received an update from plugin. extracting info from payload Jun 07 14:36:39 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:39 test volumio[890]: info: CorePlayQueue::getTrack 5 Jun 07 14:36:39 test volumio[890]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 07 14:36:39 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:39 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:39 test volumio[890]: info: CorePlayQueue::getTrack 5 Jun 07 14:36:39 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:39 test volumio[890]: info: ControllerMpd::pushState Jun 07 14:36:39 test volumio[890]: info: CoreCommandRouter::servicePushState Jun 07 14:36:39 test volumio[890]: info: CorePlayQueue::getTrack 5 Jun 07 14:36:39 test volumio[890]: verbose: STATE SERVICE {"status":"play","position":0,"seek":22,"duration":147,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"661 Kbps","isStreaming":false,"title":"Grandstand (Current Theme)","artist":"Sound Stage Orchestra","album":"The Great Sporting Experience","uri":"USB/38C6FBC0C6FB7C86/Folder 1; complete tracks/02.1 Grandstand (Current Theme).flac","trackType":"flac"} Jun 07 14:36:39 test volumio[890]: verbose: CURRENT POSITION 5 Jun 07 14:36:39 test volumio[890]: info: CoreStateMachine::syncState stateService play Jun 07 14:36:39 test volumio[890]: info: CoreStateMachine::syncState currentStatus play Jun 07 14:36:39 test volumio[890]: info: Received an update from plugin. extracting info from payload Jun 07 14:36:39 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:39 test volumio[890]: info: CorePlayQueue::getTrack 5 Jun 07 14:36:39 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:39 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:39 test volumio[890]: info: CorePlayQueue::getTrack 5 Jun 07 14:36:39 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:39 test volumio[890]: info: ------------------------------ 49ms Jun 07 14:36:39 test volumio[890]: info: [ASDebug] CurState: play PrevState: play Jun 07 14:36:39 test volumio[890]: info: [ASDebug] CurState: play PrevState: play Jun 07 14:36:39 test volumio[890]: info: [ASDebug] CurState: play PrevState: play Jun 07 14:36:39 test volumio[890]: info: [ASDebug] CurState: play PrevState: play Jun 07 14:36:45 test volumio[890]: info: CoreCommandRouter::volumioPause Jun 07 14:36:45 test volumio[890]: info: CoreStateMachine::pause Jun 07 14:36:45 test volumio[890]: info: CoreStateMachine::stPlaybackTimer Jun 07 14:36:45 test volumio[890]: info: CoreStateMachine::servicePause Jun 07 14:36:45 test volumio[890]: info: CorePlayQueue::getTrack 5 Jun 07 14:36:45 test volumio[890]: info: CoreCommandRouter::servicePause Jun 07 14:36:45 test volumio[890]: info: ControllerMpd::pause Jun 07 14:36:45 test volumio[890]: verbose: ControllerMpd::sendMpdCommand pause Jun 07 14:36:45 test volumio[890]: info: Jun 07 14:36:45 test volumio[890]: ---------------------------- MPD announces state update: player Jun 07 14:36:45 test volumio[890]: info: sendMpdCommand pause took 4 milliseconds Jun 07 14:36:45 test volumio[890]: info: ControllerMpd::getState Jun 07 14:36:45 test volumio[890]: verbose: ControllerMpd::sendMpdCommand status Jun 07 14:36:45 test volumio[890]: info: Jun 07 14:36:45 test volumio[890]: ---------------------------- MPD announces state update: player Jun 07 14:36:45 test volumio[890]: info: ControllerMpd::getState Jun 07 14:36:45 test volumio[890]: verbose: ControllerMpd::sendMpdCommand status Jun 07 14:36:45 test volumio[890]: info: sendMpdCommand status took 4 milliseconds Jun 07 14:36:45 test volumio[890]: info: sendMpdCommand status took 1 milliseconds Jun 07 14:36:45 test volumio[890]: verbose: ControllerMpd::parseState Jun 07 14:36:45 test volumio[890]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 07 14:36:45 test volumio[890]: verbose: ControllerMpd::parseState Jun 07 14:36:45 test volumio[890]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 07 14:36:45 test volumio[890]: info: sendMpdCommand playlistinfo took 3 milliseconds Jun 07 14:36:45 test volumio[890]: info: sendMpdCommand playlistinfo took 2 milliseconds Jun 07 14:36:45 test volumio[890]: verbose: ControllerMpd::parseTrackInfo Jun 07 14:36:45 test volumio[890]: verbose: ControllerMpd::parseTrackInfo Jun 07 14:36:45 test volumio[890]: info: ControllerMpd::pushState Jun 07 14:36:45 test volumio[890]: info: CoreCommandRouter::servicePushState Jun 07 14:36:45 test volumio[890]: info: CorePlayQueue::getTrack 5 Jun 07 14:36:45 test volumio[890]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":5285,"duration":147,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1021 Kbps","isStreaming":false,"title":"Grandstand (Current Theme)","artist":"Sound Stage Orchestra","album":"The Great Sporting Experience","uri":"USB/38C6FBC0C6FB7C86/Folder 1; complete tracks/02.1 Grandstand (Current Theme).flac","trackType":"flac"} Jun 07 14:36:45 test volumio[890]: verbose: CURRENT POSITION 5 Jun 07 14:36:45 test volumio[890]: info: CoreStateMachine::syncState stateService pause Jun 07 14:36:45 test volumio[890]: info: CoreStateMachine::syncState currentStatus pause Jun 07 14:36:45 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:45 test volumio[890]: info: CorePlayQueue::getTrack 5 Jun 07 14:36:45 test volumio[890]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 07 14:36:45 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:45 test volumio[890]: info: CoreStateMachine::stPlaybackTimer Jun 07 14:36:45 test volumio[890]: info: ControllerMpd::pushState Jun 07 14:36:45 test volumio[890]: info: CoreCommandRouter::servicePushState Jun 07 14:36:45 test volumio[890]: info: CorePlayQueue::getTrack 5 Jun 07 14:36:45 test volumio[890]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":5285,"duration":147,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1021 Kbps","isStreaming":false,"title":"Grandstand (Current Theme)","artist":"Sound Stage Orchestra","album":"The Great Sporting Experience","uri":"USB/38C6FBC0C6FB7C86/Folder 1; complete tracks/02.1 Grandstand (Current Theme).flac","trackType":"flac"} Jun 07 14:36:45 test volumio[890]: verbose: CURRENT POSITION 5 Jun 07 14:36:45 test volumio[890]: info: CoreStateMachine::syncState stateService pause Jun 07 14:36:45 test volumio[890]: info: CoreStateMachine::syncState currentStatus pause Jun 07 14:36:45 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:45 test volumio[890]: info: CorePlayQueue::getTrack 5 Jun 07 14:36:45 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:45 test volumio[890]: info: CoreStateMachine::stPlaybackTimer Jun 07 14:36:45 test volumio[890]: info: ------------------------------ 35ms Jun 07 14:36:45 test volumio[890]: info: ------------------------------ 33ms Jun 07 14:36:45 test volumio[890]: info: [ASDebug] CurState: pause PrevState: play Jun 07 14:36:45 test volumio[890]: info: [ASDebug] InitTimeout - Amp off in: 0 ms Jun 07 14:36:45 test volumio[890]: info: [ASDebug] CurState: pause PrevState: play Jun 07 14:36:45 test volumio[890]: info: [ASDebug] InitTimeout - Amp off in: 0 ms Jun 07 14:36:45 test volumio[890]: info: [ASDebug] Togle GPIO: OFF Jun 07 14:36:47 test volumio[890]: info: CoreCommandRouter::volumioPlay Jun 07 14:36:47 test volumio[890]: info: CoreStateMachine::play index undefined Jun 07 14:36:47 test volumio[890]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 07 14:36:47 test volumio[890]: info: CorePlayQueue::getTrack 5 Jun 07 14:36:47 test volumio[890]: info: CoreStateMachine::startPlaybackTimer Jun 07 14:36:47 test volumio[890]: info: CorePlayQueue::getTrack 5 Jun 07 14:36:47 test volumio[890]: info: ControllerMpd::resume Jun 07 14:36:47 test volumio[890]: verbose: ControllerMpd::sendMpdCommand play Jun 07 14:36:47 test volumio[890]: info: sendMpdCommand play took 5 milliseconds Jun 07 14:36:47 test volumio[890]: info: Jun 07 14:36:47 test volumio[890]: ---------------------------- MPD announces state update: player Jun 07 14:36:47 test volumio[890]: info: ControllerMpd::getState Jun 07 14:36:47 test volumio[890]: verbose: ControllerMpd::sendMpdCommand status Jun 07 14:36:47 test volumio[890]: info: Jun 07 14:36:47 test volumio[890]: ---------------------------- MPD announces state update: player Jun 07 14:36:47 test volumio[890]: info: ControllerMpd::getState Jun 07 14:36:47 test volumio[890]: verbose: ControllerMpd::sendMpdCommand status Jun 07 14:36:47 test volumio[890]: info: sendMpdCommand status took 4 milliseconds Jun 07 14:36:47 test volumio[890]: info: sendMpdCommand status took 2 milliseconds Jun 07 14:36:47 test volumio[890]: verbose: ControllerMpd::parseState Jun 07 14:36:47 test volumio[890]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 07 14:36:47 test volumio[890]: verbose: ControllerMpd::parseState Jun 07 14:36:47 test volumio[890]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 07 14:36:47 test volumio[890]: info: sendMpdCommand playlistinfo took 4 milliseconds Jun 07 14:36:47 test volumio[890]: info: sendMpdCommand playlistinfo took 3 milliseconds Jun 07 14:36:47 test volumio[890]: verbose: ControllerMpd::parseTrackInfo Jun 07 14:36:47 test volumio[890]: verbose: ControllerMpd::parseTrackInfo Jun 07 14:36:47 test volumio[890]: info: ControllerMpd::pushState Jun 07 14:36:47 test volumio[890]: info: CoreCommandRouter::servicePushState Jun 07 14:36:47 test volumio[890]: info: CorePlayQueue::getTrack 5 Jun 07 14:36:47 test volumio[890]: verbose: STATE SERVICE {"status":"play","position":0,"seek":6154,"duration":147,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"954 Kbps","isStreaming":false,"title":"Grandstand (Current Theme)","artist":"Sound Stage Orchestra","album":"The Great Sporting Experience","uri":"USB/38C6FBC0C6FB7C86/Folder 1; complete tracks/02.1 Grandstand (Current Theme).flac","trackType":"flac"} Jun 07 14:36:47 test volumio[890]: verbose: CURRENT POSITION 5 Jun 07 14:36:47 test volumio[890]: info: CoreStateMachine::syncState stateService play Jun 07 14:36:47 test volumio[890]: info: CoreStateMachine::syncState currentStatus pause Jun 07 14:36:47 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:47 test volumio[890]: info: CorePlayQueue::getTrack 5 Jun 07 14:36:47 test volumio[890]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 07 14:36:47 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:47 test volumio[890]: info: ControllerMpd::pushState Jun 07 14:36:47 test volumio[890]: info: CoreCommandRouter::servicePushState Jun 07 14:36:47 test volumio[890]: info: CorePlayQueue::getTrack 5 Jun 07 14:36:47 test volumio[890]: verbose: STATE SERVICE {"status":"play","position":0,"seek":6154,"duration":147,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"954 Kbps","isStreaming":false,"title":"Grandstand (Current Theme)","artist":"Sound Stage Orchestra","album":"The Great Sporting Experience","uri":"USB/38C6FBC0C6FB7C86/Folder 1; complete tracks/02.1 Grandstand (Current Theme).flac","trackType":"flac"} Jun 07 14:36:47 test volumio[890]: verbose: CURRENT POSITION 5 Jun 07 14:36:47 test volumio[890]: info: CoreStateMachine::syncState stateService play Jun 07 14:36:47 test volumio[890]: info: CoreStateMachine::syncState currentStatus play Jun 07 14:36:47 test volumio[890]: info: Received an update from plugin. extracting info from payload Jun 07 14:36:47 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:47 test volumio[890]: info: CorePlayQueue::getTrack 5 Jun 07 14:36:47 test volumio[890]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 07 14:36:47 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:47 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:36:47 test volumio[890]: info: CorePlayQueue::getTrack 5 Jun 07 14:36:47 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:36:47 test volumio[890]: info: ------------------------------ 44ms Jun 07 14:36:47 test volumio[890]: info: ------------------------------ 43ms Jun 07 14:36:47 test volumio[890]: info: [ASDebug] CurState: play PrevState: pause Jun 07 14:36:47 test volumio[890]: info: [ASDebug] Togle GPIO: ON Jun 07 14:36:47 test volumio[890]: info: [ASDebug] CurState: play PrevState: play Jun 07 14:36:47 test volumio[890]: info: [ASDebug] CurState: play PrevState: play Jun 07 14:37:06 test volumio[890]: info: CoreCommandRouter::volumioPlay Jun 07 14:37:06 test volumio[890]: info: CoreStateMachine::play index 1 Jun 07 14:37:06 test volumio[890]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 07 14:37:06 test volumio[890]: info: CoreStateMachine::stop Jun 07 14:37:06 test volumio[890]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 07 14:37:06 test volumio[890]: info: CoreStateMachine::stPlaybackTimer Jun 07 14:37:06 test volumio[890]: info: CoreStateMachine::updateTrackBlock Jun 07 14:37:06 test volumio[890]: info: CorePlayQueue::getTrackBlock Jun 07 14:37:06 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:37:06 test volumio[890]: info: CorePlayQueue::getTrack 5 Jun 07 14:37:06 test volumio[890]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 07 14:37:06 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:37:06 test volumio[890]: info: CoreStateMachine::serviceStop Jun 07 14:37:06 test volumio[890]: info: CorePlayQueue::getTrack 5 Jun 07 14:37:06 test volumio[890]: info: CoreCommandRouter::serviceStop Jun 07 14:37:06 test volumio[890]: info: ControllerMpd::stop Jun 07 14:37:06 test volumio[890]: verbose: ControllerMpd::sendMpdCommand stop Jun 07 14:37:06 test volumio[890]: info: [ASDebug] CurState: stop PrevState: play Jun 07 14:37:06 test volumio[890]: info: [ASDebug] InitTimeout - Amp off in: 0 ms Jun 07 14:37:06 test volumio[890]: info: [ASDebug] Togle GPIO: OFF Jun 07 14:37:06 test volumio[890]: info: Jun 07 14:37:06 test volumio[890]: ---------------------------- MPD announces state update: player Jun 07 14:37:06 test volumio[890]: info: sendMpdCommand stop took 10 milliseconds Jun 07 14:37:06 test volumio[890]: info: ControllerMpd::getState Jun 07 14:37:06 test volumio[890]: verbose: ControllerMpd::sendMpdCommand status Jun 07 14:37:06 test volumio[890]: info: CoreStateMachine::play index undefined Jun 07 14:37:06 test volumio[890]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 07 14:37:06 test volumio[890]: info: CorePlayQueue::getTrack 1 Jun 07 14:37:06 test volumio[890]: info: CoreStateMachine::startPlaybackTimer Jun 07 14:37:06 test volumio[890]: info: CorePlayQueue::getTrack 1 Jun 07 14:37:06 test volumio[890]: verbose: ControllerMpd::clearAddPlayTracks USB/38C6FBC0C6FB7C86/Folder 1; complete tracks/06 Brothers Johnson.flac Jun 07 14:37:06 test volumio[890]: verbose: ControllerMpd::sendMpdCommand stop Jun 07 14:37:06 test volumio[890]: info: Jun 07 14:37:06 test volumio[890]: ---------------------------- MPD announces state update: player Jun 07 14:37:06 test volumio[890]: info: ControllerMpd::getState Jun 07 14:37:06 test volumio[890]: verbose: ControllerMpd::sendMpdCommand status Jun 07 14:37:06 test volumio[890]: info: sendMpdCommand status took 5 milliseconds Jun 07 14:37:06 test volumio[890]: info: sendMpdCommand stop took 3 milliseconds Jun 07 14:37:06 test volumio[890]: info: sendMpdCommand status took 2 milliseconds Jun 07 14:37:06 test volumio[890]: verbose: ControllerMpd::parseState Jun 07 14:37:06 test volumio[890]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 07 14:37:06 test volumio[890]: verbose: ControllerMpd::sendMpdCommand clear Jun 07 14:37:06 test volumio[890]: verbose: ControllerMpd::parseState Jun 07 14:37:06 test volumio[890]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 07 14:37:06 test volumio[890]: info: Jun 07 14:37:06 test volumio[890]: ---------------------------- MPD announces system playlist update Jun 07 14:37:06 test volumio[890]: info: Ignoring MPD Status Update Jun 07 14:37:06 test volumio[890]: info: sendMpdCommand playlistinfo took 3 milliseconds Jun 07 14:37:06 test volumio[890]: info: sendMpdCommand clear took 3 milliseconds Jun 07 14:37:06 test volumio[890]: info: sendMpdCommand playlistinfo took 3 milliseconds Jun 07 14:37:06 test volumio[890]: verbose: ControllerMpd::parseTrackInfo Jun 07 14:37:06 test volumio[890]: verbose: ControllerMpd::sendMpdCommand add "USB/38C6FBC0C6FB7C86/Folder 1; complete tracks/06 Brothers Johnson.flac" Jun 07 14:37:06 test volumio[890]: verbose: ControllerMpd::parseTrackInfo Jun 07 14:37:06 test volumio[890]: info: ControllerMpd::pushState Jun 07 14:37:06 test volumio[890]: info: CoreCommandRouter::servicePushState Jun 07 14:37:06 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:37:06 test volumio[890]: info: CorePlayQueue::getTrack 1 Jun 07 14:37:06 test volumio[890]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 07 14:37:06 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:37:06 test volumio[890]: info: CorePlayQueue::getTrack 1 Jun 07 14:37:06 test volumio[890]: 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":"Grandstand (Current Theme)","artist":"Sound Stage Orchestra","album":"The Great Sporting Experience","uri":"USB/38C6FBC0C6FB7C86/Folder 1; complete tracks/02.1 Grandstand (Current Theme).flac","trackType":"flac"} Jun 07 14:37:06 test volumio[890]: verbose: CURRENT POSITION 1 Jun 07 14:37:06 test volumio[890]: info: CoreStateMachine::syncState stateService stop Jun 07 14:37:06 test volumio[890]: info: CoreStateMachine::syncState currentStatus stop Jun 07 14:37:06 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:37:06 test volumio[890]: info: CorePlayQueue::getTrack 1 Jun 07 14:37:06 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:37:06 test volumio[890]: info: No code Jun 07 14:37:06 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:37:06 test volumio[890]: info: CorePlayQueue::getTrack 1 Jun 07 14:37:06 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:37:06 test volumio[890]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Jun 07 14:37:06 test volumio[890]: info: ------------------------------ 45ms Jun 07 14:37:06 test volumio[890]: info: ------------------------------ 41ms Jun 07 14:37:06 test volumio[890]: info: Jun 07 14:37:06 test volumio[890]: ---------------------------- MPD announces system playlist update Jun 07 14:37:06 test volumio[890]: info: Ignoring MPD Status Update Jun 07 14:37:06 test volumio[890]: error: updateQueue error: null Jun 07 14:37:06 test volumio[890]: info: Jun 07 14:37:06 test volumio[890]: ---------------------------- MPD announces system playlist update Jun 07 14:37:06 test volumio[890]: info: Ignoring MPD Status Update Jun 07 14:37:06 test volumio[890]: info: ------------------------------ 41ms Jun 07 14:37:06 test volumio[890]: info: sendMpdCommand add "USB/38C6FBC0C6FB7C86/Folder 1; complete tracks/06 Brothers Johnson.flac" took 39 milliseconds Jun 07 14:37:06 test volumio[890]: info: ------------------------------ 6ms Jun 07 14:37:06 test volumio[890]: verbose: ControllerMpd::sendMpdCommand play Jun 07 14:37:06 test volumio[890]: info: Jun 07 14:37:06 test volumio[890]: ---------------------------- MPD announces system playlist update Jun 07 14:37:06 test volumio[890]: info: Ignoring MPD Status Update Jun 07 14:37:06 test volumio[890]: info: [ASDebug] CurState: stop PrevState: stop Jun 07 14:37:06 test volumio[890]: info: [ASDebug] CurState: stop PrevState: stop Jun 07 14:37:06 test volumio[890]: info: [ASDebug] CurState: stop PrevState: stop Jun 07 14:37:06 test volumio[890]: info: Jun 07 14:37:06 test volumio[890]: ---------------------------- MPD announces state update: player Jun 07 14:37:06 test volumio[890]: info: ------------------------------ 29ms Jun 07 14:37:06 test volumio[890]: info: sendMpdCommand play took 28 milliseconds Jun 07 14:37:06 test volumio[890]: info: ------------------------------ 27ms Jun 07 14:37:06 test volumio[890]: info: ControllerMpd::getState Jun 07 14:37:06 test volumio[890]: verbose: ControllerMpd::sendMpdCommand status Jun 07 14:37:06 test volumio[890]: info: Jun 07 14:37:06 test volumio[890]: ---------------------------- MPD announces state update: player Jun 07 14:37:06 test volumio[890]: info: ControllerMpd::getState Jun 07 14:37:06 test volumio[890]: verbose: ControllerMpd::sendMpdCommand status Jun 07 14:37:06 test volumio[890]: info: Jun 07 14:37:06 test volumio[890]: ---------------------------- MPD announces state update: player Jun 07 14:37:06 test volumio[890]: info: ControllerMpd::getState Jun 07 14:37:06 test volumio[890]: verbose: ControllerMpd::sendMpdCommand status Jun 07 14:37:06 test volumio[890]: info: sendMpdCommand status took 8 milliseconds Jun 07 14:37:06 test volumio[890]: info: sendMpdCommand status took 6 milliseconds Jun 07 14:37:06 test volumio[890]: verbose: ControllerMpd::parseState Jun 07 14:37:06 test volumio[890]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 07 14:37:06 test volumio[890]: verbose: ControllerMpd::parseState Jun 07 14:37:06 test volumio[890]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 07 14:37:06 test volumio[890]: info: Jun 07 14:37:06 test volumio[890]: ---------------------------- MPD announces state update: player Jun 07 14:37:06 test volumio[890]: info: ControllerMpd::getState Jun 07 14:37:06 test volumio[890]: verbose: ControllerMpd::sendMpdCommand status Jun 07 14:37:06 test volumio[890]: info: sendMpdCommand status took 16 milliseconds Jun 07 14:37:06 test volumio[890]: verbose: ControllerMpd::parseState Jun 07 14:37:06 test volumio[890]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 07 14:37:06 test volumio[890]: info: sendMpdCommand playlistinfo took 15 milliseconds Jun 07 14:37:06 test volumio[890]: info: sendMpdCommand playlistinfo took 9 milliseconds Jun 07 14:37:06 test volumio[890]: info: sendMpdCommand status took 6 milliseconds Jun 07 14:37:06 test volumio[890]: verbose: ControllerMpd::parseTrackInfo Jun 07 14:37:06 test volumio[890]: verbose: ControllerMpd::parseTrackInfo Jun 07 14:37:06 test volumio[890]: verbose: ControllerMpd::parseState Jun 07 14:37:06 test volumio[890]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 07 14:37:06 test volumio[890]: info: ControllerMpd::pushState Jun 07 14:37:06 test volumio[890]: info: CoreCommandRouter::servicePushState Jun 07 14:37:06 test volumio[890]: info: CorePlayQueue::getTrack 1 Jun 07 14:37:06 test volumio[890]: verbose: STATE SERVICE {"status":"play","position":0,"seek":846,"duration":308,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"532 Kbps","isStreaming":false,"title":"Brothers Johnson","artist":"Streetwave","album":"Doin' It - Connoisseur Soul Collection Volume 4","uri":"USB/38C6FBC0C6FB7C86/Folder 1; complete tracks/06 Brothers Johnson.flac","trackType":"flac"} Jun 07 14:37:06 test volumio[890]: verbose: CURRENT POSITION 1 Jun 07 14:37:06 test volumio[890]: info: CoreStateMachine::syncState stateService play Jun 07 14:37:06 test volumio[890]: info: CoreStateMachine::syncState currentStatus stop Jun 07 14:37:06 test volumio[890]: info: ControllerMpd::pushState Jun 07 14:37:06 test volumio[890]: info: CoreCommandRouter::servicePushState Jun 07 14:37:06 test volumio[890]: info: CorePlayQueue::getTrack 1 Jun 07 14:37:06 test volumio[890]: verbose: STATE SERVICE {"status":"play","position":0,"seek":846,"duration":308,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"532 Kbps","isStreaming":false,"title":"Brothers Johnson","artist":"Streetwave","album":"Doin' It - Connoisseur Soul Collection Volume 4","uri":"USB/38C6FBC0C6FB7C86/Folder 1; complete tracks/06 Brothers Johnson.flac","trackType":"flac"} Jun 07 14:37:06 test volumio[890]: verbose: CURRENT POSITION 1 Jun 07 14:37:06 test volumio[890]: info: CoreStateMachine::syncState stateService play Jun 07 14:37:06 test volumio[890]: info: CoreStateMachine::syncState currentStatus play Jun 07 14:37:06 test volumio[890]: info: Received an update from plugin. extracting info from payload Jun 07 14:37:06 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:37:06 test volumio[890]: info: CorePlayQueue::getTrack 1 Jun 07 14:37:06 test volumio[890]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 07 14:37:06 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:37:06 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:37:06 test volumio[890]: info: CorePlayQueue::getTrack 1 Jun 07 14:37:06 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:37:06 test volumio[890]: info: ------------------------------ 57ms Jun 07 14:37:06 test volumio[890]: info: ------------------------------ 65ms Jun 07 14:37:06 test volumio[890]: info: sendMpdCommand playlistinfo took 43 milliseconds Jun 07 14:37:06 test volumio[890]: info: sendMpdCommand playlistinfo took 37 milliseconds Jun 07 14:37:06 test volumio[890]: verbose: ControllerMpd::parseTrackInfo Jun 07 14:37:06 test volumio[890]: verbose: ControllerMpd::parseTrackInfo Jun 07 14:37:06 test volumio[890]: info: ControllerMpd::pushState Jun 07 14:37:06 test volumio[890]: info: CoreCommandRouter::servicePushState Jun 07 14:37:06 test volumio[890]: info: CorePlayQueue::getTrack 1 Jun 07 14:37:06 test volumio[890]: verbose: STATE SERVICE {"status":"play","position":0,"seek":846,"duration":308,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"532 Kbps","isStreaming":false,"title":"Brothers Johnson","artist":"Streetwave","album":"Doin' It - Connoisseur Soul Collection Volume 4","uri":"USB/38C6FBC0C6FB7C86/Folder 1; complete tracks/06 Brothers Johnson.flac","trackType":"flac"} Jun 07 14:37:06 test volumio[890]: verbose: CURRENT POSITION 1 Jun 07 14:37:06 test volumio[890]: info: CoreStateMachine::syncState stateService play Jun 07 14:37:06 test volumio[890]: info: CoreStateMachine::syncState currentStatus play Jun 07 14:37:06 test volumio[890]: info: Received an update from plugin. extracting info from payload Jun 07 14:37:06 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:37:06 test volumio[890]: info: CorePlayQueue::getTrack 1 Jun 07 14:37:06 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:37:06 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:37:06 test volumio[890]: info: CorePlayQueue::getTrack 1 Jun 07 14:37:06 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:37:06 test volumio[890]: info: ControllerMpd::pushState Jun 07 14:37:06 test volumio[890]: info: CoreCommandRouter::servicePushState Jun 07 14:37:06 test volumio[890]: info: CorePlayQueue::getTrack 1 Jun 07 14:37:06 test volumio[890]: verbose: STATE SERVICE {"status":"play","position":0,"seek":846,"duration":308,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"532 Kbps","isStreaming":false,"title":"Brothers Johnson","artist":"Streetwave","album":"Doin' It - Connoisseur Soul Collection Volume 4","uri":"USB/38C6FBC0C6FB7C86/Folder 1; complete tracks/06 Brothers Johnson.flac","trackType":"flac"} Jun 07 14:37:06 test volumio[890]: verbose: CURRENT POSITION 1 Jun 07 14:37:06 test volumio[890]: info: CoreStateMachine::syncState stateService play Jun 07 14:37:06 test volumio[890]: info: CoreStateMachine::syncState currentStatus play Jun 07 14:37:06 test volumio[890]: info: Received an update from plugin. extracting info from payload Jun 07 14:37:06 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:37:06 test volumio[890]: info: CorePlayQueue::getTrack 1 Jun 07 14:37:06 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:37:06 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:37:06 test volumio[890]: info: CorePlayQueue::getTrack 1 Jun 07 14:37:06 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:37:06 test volumio[890]: info: ------------------------------ 103ms Jun 07 14:37:06 test volumio[890]: info: ------------------------------ 89ms Jun 07 14:37:06 test volumio[890]: info: [ASDebug] CurState: play PrevState: stop Jun 07 14:37:06 test volumio[890]: info: [ASDebug] Togle GPIO: ON Jun 07 14:37:06 test volumio[890]: info: [ASDebug] CurState: play PrevState: play Jun 07 14:37:06 test volumio[890]: info: [ASDebug] CurState: play PrevState: play Jun 07 14:37:06 test volumio[890]: info: [ASDebug] CurState: play PrevState: play Jun 07 14:37:06 test volumio[890]: info: [ASDebug] CurState: play PrevState: play Jun 07 14:37:06 test volumio[890]: info: [ASDebug] CurState: play PrevState: play Jun 07 14:37:10 test volumio[890]: info: CoreCommandRouter::volumioGetState Jun 07 14:37:10 test volumio[890]: info: CorePlayQueue::getTrack 1 Jun 07 14:37:16 test volumio[890]: info: CoreCommandRouter::volumioClearQueue Jun 07 14:37:16 test volumio[890]: info: CoreStateMachine::ClearQueue Jun 07 14:37:16 test volumio[890]: info: CoreStateMachine::stop Jun 07 14:37:16 test volumio[890]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 07 14:37:16 test volumio[890]: info: CoreStateMachine::stPlaybackTimer Jun 07 14:37:16 test volumio[890]: info: CoreStateMachine::updateTrackBlock Jun 07 14:37:16 test volumio[890]: info: CorePlayQueue::getTrackBlock Jun 07 14:37:16 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:37:16 test volumio[890]: info: CorePlayQueue::getTrack 1 Jun 07 14:37:16 test volumio[890]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 07 14:37:16 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:37:16 test volumio[890]: info: CoreStateMachine::serviceStop Jun 07 14:37:16 test volumio[890]: info: CorePlayQueue::getTrack 1 Jun 07 14:37:16 test volumio[890]: info: CoreCommandRouter::serviceStop Jun 07 14:37:16 test volumio[890]: info: ControllerMpd::stop Jun 07 14:37:16 test volumio[890]: verbose: ControllerMpd::sendMpdCommand stop Jun 07 14:37:16 test volumio[890]: info: CorePlayQueue::clearPlayQueue Jun 07 14:37:16 test volumio[890]: info: CorePlayQueue::saveQueue Jun 07 14:37:16 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:37:16 test volumio[890]: info: CoreCommandRouter::volumioPushQueue Jun 07 14:37:16 test volumio[890]: info: [ASDebug] CurState: stop PrevState: play Jun 07 14:37:16 test volumio[890]: info: [ASDebug] InitTimeout - Amp off in: 0 ms Jun 07 14:37:16 test volumio[890]: info: [ASDebug] CurState: stop PrevState: play Jun 07 14:37:16 test volumio[890]: info: [ASDebug] InitTimeout - Amp off in: 0 ms Jun 07 14:37:16 test volumio[890]: info: Jun 07 14:37:16 test volumio[890]: ---------------------------- MPD announces state update: player Jun 07 14:37:16 test volumio[890]: info: sendMpdCommand stop took 27 milliseconds Jun 07 14:37:16 test volumio[890]: info: ControllerMpd::getState Jun 07 14:37:16 test volumio[890]: verbose: ControllerMpd::sendMpdCommand status Jun 07 14:37:16 test volumio[890]: info: [ASDebug] Togle GPIO: OFF Jun 07 14:37:16 test volumio[890]: info: sendMpdCommand status took 1 milliseconds Jun 07 14:37:16 test volumio[890]: verbose: ControllerMpd::parseState Jun 07 14:37:16 test volumio[890]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 07 14:37:16 test volumio[890]: info: Jun 07 14:37:16 test volumio[890]: ---------------------------- MPD announces state update: player Jun 07 14:37:16 test volumio[890]: info: ControllerMpd::getState Jun 07 14:37:16 test volumio[890]: verbose: ControllerMpd::sendMpdCommand status Jun 07 14:37:16 test volumio[890]: info: sendMpdCommand playlistinfo took 2 milliseconds Jun 07 14:37:16 test volumio[890]: info: sendMpdCommand status took 2 milliseconds Jun 07 14:37:16 test volumio[890]: verbose: ControllerMpd::parseTrackInfo Jun 07 14:37:16 test volumio[890]: verbose: ControllerMpd::parseState Jun 07 14:37:16 test volumio[890]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 07 14:37:16 test volumio[890]: info: ControllerMpd::pushState Jun 07 14:37:16 test volumio[890]: info: CoreCommandRouter::servicePushState Jun 07 14:37:16 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:37:16 test volumio[890]: info: CorePlayQueue::getTrack 1 Jun 07 14:37:16 test volumio[890]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 07 14:37:16 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:37:16 test volumio[890]: info: CorePlayQueue::getTrack 1 Jun 07 14:37:16 test volumio[890]: 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":"Brothers Johnson","artist":"Streetwave","album":"Doin' It - Connoisseur Soul Collection Volume 4","uri":"USB/38C6FBC0C6FB7C86/Folder 1; complete tracks/06 Brothers Johnson.flac","trackType":"flac"} Jun 07 14:37:16 test volumio[890]: verbose: CURRENT POSITION 1 Jun 07 14:37:16 test volumio[890]: info: CoreStateMachine::syncState stateService stop Jun 07 14:37:16 test volumio[890]: info: CoreStateMachine::syncState currentStatus stop Jun 07 14:37:16 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:37:16 test volumio[890]: info: CorePlayQueue::getTrack 1 Jun 07 14:37:16 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:37:16 test volumio[890]: info: No code Jun 07 14:37:16 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:37:16 test volumio[890]: info: CorePlayQueue::getTrack 1 Jun 07 14:37:16 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:37:16 test volumio[890]: info: ------------------------------ 32ms Jun 07 14:37:16 test volumio[890]: info: sendMpdCommand playlistinfo took 27 milliseconds Jun 07 14:37:16 test volumio[890]: verbose: ControllerMpd::parseTrackInfo Jun 07 14:37:16 test volumio[890]: info: ControllerMpd::pushState Jun 07 14:37:16 test volumio[890]: info: CoreCommandRouter::servicePushState Jun 07 14:37:16 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:37:16 test volumio[890]: info: CorePlayQueue::getTrack 1 Jun 07 14:37:16 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:37:16 test volumio[890]: info: CorePlayQueue::getTrack 1 Jun 07 14:37:16 test volumio[890]: 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":"Brothers Johnson","artist":"Streetwave","album":"Doin' It - Connoisseur Soul Collection Volume 4","uri":"USB/38C6FBC0C6FB7C86/Folder 1; complete tracks/06 Brothers Johnson.flac","trackType":"flac"} Jun 07 14:37:16 test volumio[890]: verbose: CURRENT POSITION 1 Jun 07 14:37:16 test volumio[890]: info: CoreStateMachine::syncState stateService stop Jun 07 14:37:16 test volumio[890]: info: CoreStateMachine::syncState currentStatus stop Jun 07 14:37:16 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:37:16 test volumio[890]: info: CorePlayQueue::getTrack 1 Jun 07 14:37:16 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:37:16 test volumio[890]: info: No code Jun 07 14:37:16 test volumio[890]: info: CoreStateMachine::pushState Jun 07 14:37:16 test volumio[890]: info: CorePlayQueue::getTrack 1 Jun 07 14:37:16 test volumio[890]: info: CoreCommandRouter::volumioPushState Jun 07 14:37:16 test volumio[890]: info: ------------------------------ 58ms Jun 07 14:37:16 test volumio[890]: info: [ASDebug] CurState: stop PrevState: stop Jun 07 14:37:16 test volumio[890]: info: [ASDebug] CurState: stop PrevState: stop Jun 07 14:37:16 test volumio[890]: info: [ASDebug] CurState: stop PrevState: stop Jun 07 14:37:16 test volumio[890]: info: [ASDebug] CurState: stop PrevState: stop Jun 07 14:37:16 test volumio[890]: info: [ASDebug] CurState: stop PrevState: stop Jun 07 14:37:16 test volumio[890]: info: [ASDebug] CurState: stop PrevState: stop Jun 07 14:37:21 test volumio[890]: info: CoreCommandRouter::volumioGetState Jun 07 14:37:21 test volumio[890]: info: CorePlayQueue::getTrack 1 Jun 07 14:37:29 test volumio[890]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 07 14:37:29 test volumio[890]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jun 07 14:37:35 test volumio[890]: info: [ASDebug] Port: 9 Jun 07 14:37:35 test volumio[890]: info: [ASDebug] Inverted: true Jun 07 14:37:35 test volumio[890]: info: [ASDebug] Delay: 0 Jun 07 14:37:41 test volumio[890]: info: [ASDebug] Port: 9 Jun 07 14:37:41 test volumio[890]: info: [ASDebug] Inverted: true Jun 07 14:37:41 test volumio[890]: info: [ASDebug] Delay: 0 Jun 07 14:37:41 test volumio[890]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 07 14:37:41 test volumio[890]: Error: EBADF: bad file descriptor, close Jun 07 14:37:41 test volumio[890]: at Object.closeSync (fs.js:439:3) Jun 07 14:37:41 test volumio[890]: at Object.closeSync (/volumio/node_modules/graceful-fs/graceful-fs.js:74:20) Jun 07 14:37:41 test volumio[890]: at Object.closeSync (/data/plugins/system_controller/ampswitch/node_modules/graceful-fs/graceful-fs.js:51:27) Jun 07 14:37:41 test volumio[890]: at Gpio.unexport (/data/plugins/system_controller/ampswitch/node_modules/onoff/onoff.js:307:8) Jun 07 14:37:41 test volumio[890]: at AmpSwitchController.freeGPIO (/data/plugins/system_controller/ampswitch/index.js:242:19) Jun 07 14:37:41 test volumio[890]: at AmpSwitchController.onStop (/data/plugins/system_controller/ampswitch/index.js:90:10) Jun 07 14:37:41 test volumio[890]: at PluginManager.stopPlugin (/volumio/app/pluginmanager.js:460:30) Jun 07 14:37:41 test volumio[890]: at PluginManager.disableAndStopPlugin (/volumio/app/pluginmanager.js:1883:8) Jun 07 14:37:41 test volumio[890]: at CoreCommandRouter.disableAndStopPlugin (/volumio/app/index.js:1556:29) Jun 07 14:37:41 test volumio[890]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1401:47) Jun 07 14:37:41 test volumio[890]: at Socket.emit (events.js:315:20) Jun 07 14:37:41 test volumio[890]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Jun 07 14:37:41 test volumio[890]: at processTicksAndRejections (internal/process/task_queues.js:75:11) { Jun 07 14:37:41 test volumio[890]: errno: -9, Jun 07 14:37:41 test volumio[890]: syscall: 'close', Jun 07 14:37:41 test volumio[890]: code: 'EBADF' Jun 07 14:37:41 test volumio[890]: } Jun 07 14:37:41 test volumio[890]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 07 14:37:42 test sudo[3905]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-07 14:36 Jun 07 14:37:42 test sudo[3905]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="570c5791513f5bac7da274aba6690c1a961705de" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 13 May 2025 05:16:30 PM CEST" VOLUMIO_VERSION="3.812" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="3934ee440d5d3f0186049a23752ad680"