-- Logs begin at Tue 2024-04-16 13:12:20 -03, end at Tue 2024-04-16 14:04:21 -03. -- Apr 16 14:03:04 primo volumio[5322]: info: Preload queue cleared Apr 16 14:03:04 primo volumio[5322]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 16 14:03:04 primo volumio[5322]: info: CoreStateMachine::ClearQueue Apr 16 14:03:04 primo volumio[5322]: info: CoreStateMachine::stop Apr 16 14:03:04 primo volumio[5322]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 16 14:03:04 primo volumio[5322]: info: CorePlayQueue::clearPlayQueue Apr 16 14:03:04 primo volumio[5322]: info: CorePlayQueue::saveQueue Apr 16 14:03:04 primo volumio[5322]: info: CoreCommandRouter::volumioPushQueue Apr 16 14:03:04 primo volumio[5322]: info: CoreStateMachine::addQueueItems Apr 16 14:03:04 primo volumio[5322]: info: CorePlayQueue::addQueueItems Apr 16 14:03:04 primo volumio[5322]: info: Preload queue cleared Apr 16 14:03:04 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/Babylon by Bus/Babylon by Bus-01.flac Apr 16 14:03:04 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/Babylon by Bus/Babylon by Bus-01.flac Apr 16 14:03:04 primo volumio[5322]: info: CoreCommandRouter::volumioPushQueue Apr 16 14:03:04 primo volumio[5322]: info: CorePlayQueue::saveQueue Apr 16 14:03:04 primo volumio[5322]: info: CoreStateMachine::updateTrackBlock Apr 16 14:03:04 primo volumio[5322]: info: CorePlayQueue::getTrackBlock Apr 16 14:03:04 primo volumio[5322]: info: CoreCommandRouter::volumioPlay Apr 16 14:03:04 primo volumio[5322]: info: CoreStateMachine::play index 0 Apr 16 14:03:04 primo volumio[5322]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 16 14:03:04 primo volumio[5322]: info: CoreStateMachine::stop Apr 16 14:03:04 primo volumio[5322]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 16 14:03:04 primo volumio[5322]: info: CoreStateMachine::play index undefined Apr 16 14:03:04 primo volumio[5322]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 16 14:03:04 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:04 primo volumio[5322]: info: CoreStateMachine::startPlaybackTimer Apr 16 14:03:04 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:04 primo volumio[5322]: info: CoreCommandRouter::volumioGetVisibleSources Apr 16 14:03:04 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 16 14:03:04 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 16 14:03:04 primo volumio[5322]: info: METAVOLUMIO: Retrieving similar tracks from metavolumio Apr 16 14:03:04 primo volumio[5322]: verbose: ControllerMpd::clearAddPlayTracks USB/SSDSumsung/LossLessMusic/Babylon by Bus/Babylon by Bus-01.flac Apr 16 14:03:04 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand stop Apr 16 14:03:04 primo volumio[5322]: info: Apr 16 14:03:04 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:03:04 primo volumio[5322]: info: sendMpdCommand stop took 17 milliseconds Apr 16 14:03:04 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:03:04 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:03:04 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand clear Apr 16 14:03:04 primo volumio[5322]: info: Apr 16 14:03:04 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:03:04 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:03:04 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:03:04 primo volumio[5322]: info: Apr 16 14:03:04 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:03:04 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:03:04 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:03:04 primo volumio[5322]: info: Apr 16 14:03:04 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:03:04 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:03:04 primo volumio[5322]: info: sendMpdCommand status took 7 milliseconds Apr 16 14:03:04 primo volumio[5322]: info: sendMpdCommand clear took 6 milliseconds Apr 16 14:03:04 primo volumio[5322]: info: sendMpdCommand status took 5 milliseconds Apr 16 14:03:04 primo volumio[5322]: info: sendMpdCommand status took 4 milliseconds Apr 16 14:03:04 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:03:04 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 14:03:04 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand add "USB/SSDSumsung/LossLessMusic/Babylon by Bus/Babylon by Bus-01.flac" Apr 16 14:03:04 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:03:04 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:03:04 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:03:04 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:03:04 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:04 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:04 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 16 14:03:04 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:04 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:04 primo volumio[5322]: 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} Apr 16 14:03:04 primo volumio[5322]: verbose: CURRENT POSITION 0 Apr 16 14:03:04 primo volumio[5322]: info: CoreStateMachine::syncState stateService stop Apr 16 14:03:04 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus stop Apr 16 14:03:04 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:04 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:04 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:04 primo volumio[5322]: info: No code Apr 16 14:03:04 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:04 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:04 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:04 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:03:04 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:03:04 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:04 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:04 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:04 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:04 primo volumio[5322]: 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} Apr 16 14:03:04 primo volumio[5322]: verbose: CURRENT POSITION 0 Apr 16 14:03:04 primo volumio[5322]: info: CoreStateMachine::syncState stateService stop Apr 16 14:03:04 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus stop Apr 16 14:03:04 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:04 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:04 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:04 primo volumio[5322]: info: No code Apr 16 14:03:04 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:04 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:04 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:04 primo volumio[5322]: info: ------------------------------ 46ms Apr 16 14:03:04 primo volumio[5322]: info: ------------------------------ 45ms Apr 16 14:03:04 primo volumio[5322]: info: Apr 16 14:03:04 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:03:04 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:03:04 primo volumio[5322]: info: Apr 16 14:03:04 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:03:04 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:03:04 primo volumio[5322]: error: updateQueue error: null Apr 16 14:03:04 primo volumio[5322]: info: Apr 16 14:03:04 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:03:04 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:03:04 primo volumio[5322]: info: ------------------------------ 54ms Apr 16 14:03:04 primo volumio[5322]: info: sendMpdCommand playlistinfo took 52 milliseconds Apr 16 14:03:04 primo volumio[5322]: info: sendMpdCommand add "USB/SSDSumsung/LossLessMusic/Babylon by Bus/Babylon by Bus-01.flac" took 52 milliseconds Apr 16 14:03:04 primo volumio[5322]: info: ------------------------------ 10ms Apr 16 14:03:04 primo volumio[5322]: info: ------------------------------ 5ms Apr 16 14:03:04 primo volumio[5322]: verbose: ControllerMpd::parseTrackInfo Apr 16 14:03:04 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand play Apr 16 14:03:04 primo volumio[5322]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 16 14:03:04 primo volumio[5322]: info: ------------------------------ 64ms Apr 16 14:03:04 primo volumio[5322]: info: Apr 16 14:03:04 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:03:04 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:03:04 primo volumio[5322]: info: Apr 16 14:03:04 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:03:04 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:03:04 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:04 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:04 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:04 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:04 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:04 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:04 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:04 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:04 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:04 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:04 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:04 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:04 primo volumio[5322]: info: ------------------------------ 40ms Apr 16 14:03:04 primo volumio[5322]: info: sendMpdCommand play took 37 milliseconds Apr 16 14:03:04 primo volumio[5322]: info: ------------------------------ 36ms Apr 16 14:03:04 primo volumio[5322]: info: ------------------------------ 34ms Apr 16 14:03:12 primo volumio[5322]: info: CoreCommandRouter::volumioPlay Apr 16 14:03:12 primo volumio[5322]: info: CoreStateMachine::play index undefined Apr 16 14:03:12 primo volumio[5322]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 16 14:03:12 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:12 primo volumio[5322]: info: CoreStateMachine::startPlaybackTimer Apr 16 14:03:12 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:12 primo volumio[5322]: info: CoreCommandRouter::volumioGetVisibleSources Apr 16 14:03:12 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 16 14:03:12 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 16 14:03:12 primo volumio[5322]: info: METAVOLUMIO: Retrieving similar tracks from metavolumio Apr 16 14:03:12 primo volumio[5322]: verbose: ControllerMpd::clearAddPlayTracks USB/SSDSumsung/LossLessMusic/Babylon by Bus/Babylon by Bus-01.flac Apr 16 14:03:12 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand stop Apr 16 14:03:12 primo volumio[5322]: info: Apr 16 14:03:12 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:03:12 primo volumio[5322]: info: sendMpdCommand stop took 8 milliseconds Apr 16 14:03:12 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:03:12 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:03:12 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand clear Apr 16 14:03:12 primo volumio[5322]: info: Apr 16 14:03:12 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:03:12 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:03:12 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:03:12 primo volumio[5322]: info: Apr 16 14:03:12 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:03:12 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:03:12 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:03:12 primo volumio[5322]: info: Apr 16 14:03:12 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:03:12 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:03:12 primo volumio[5322]: info: sendMpdCommand status took 9 milliseconds Apr 16 14:03:12 primo volumio[5322]: info: sendMpdCommand clear took 8 milliseconds Apr 16 14:03:12 primo volumio[5322]: info: sendMpdCommand status took 6 milliseconds Apr 16 14:03:12 primo volumio[5322]: info: sendMpdCommand status took 4 milliseconds Apr 16 14:03:12 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:03:12 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 14:03:12 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand add "USB/SSDSumsung/LossLessMusic/Babylon by Bus/Babylon by Bus-01.flac" Apr 16 14:03:12 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:03:12 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:03:12 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:03:12 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:03:12 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:12 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:12 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 16 14:03:12 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:12 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:12 primo volumio[5322]: 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} Apr 16 14:03:12 primo volumio[5322]: verbose: CURRENT POSITION 0 Apr 16 14:03:12 primo volumio[5322]: info: CoreStateMachine::syncState stateService stop Apr 16 14:03:12 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus stop Apr 16 14:03:12 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:12 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:12 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:12 primo volumio[5322]: info: No code Apr 16 14:03:12 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:12 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:12 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:12 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:03:12 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:03:12 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:12 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:12 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:12 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:12 primo volumio[5322]: 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} Apr 16 14:03:12 primo volumio[5322]: verbose: CURRENT POSITION 0 Apr 16 14:03:12 primo volumio[5322]: info: CoreStateMachine::syncState stateService stop Apr 16 14:03:12 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus stop Apr 16 14:03:12 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:12 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:12 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:12 primo volumio[5322]: info: No code Apr 16 14:03:12 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:12 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:12 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:12 primo volumio[5322]: info: ------------------------------ 50ms Apr 16 14:03:12 primo volumio[5322]: info: ------------------------------ 49ms Apr 16 14:03:12 primo volumio[5322]: info: Apr 16 14:03:12 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:03:12 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:03:12 primo volumio[5322]: info: Apr 16 14:03:12 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:03:12 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:03:12 primo volumio[5322]: error: updateQueue error: null Apr 16 14:03:12 primo volumio[5322]: info: Apr 16 14:03:12 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:03:12 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:03:12 primo volumio[5322]: info: ------------------------------ 54ms Apr 16 14:03:12 primo volumio[5322]: info: sendMpdCommand playlistinfo took 51 milliseconds Apr 16 14:03:12 primo volumio[5322]: info: sendMpdCommand add "USB/SSDSumsung/LossLessMusic/Babylon by Bus/Babylon by Bus-01.flac" took 51 milliseconds Apr 16 14:03:12 primo volumio[5322]: info: ------------------------------ 6ms Apr 16 14:03:12 primo volumio[5322]: info: ------------------------------ 4ms Apr 16 14:03:12 primo volumio[5322]: verbose: ControllerMpd::parseTrackInfo Apr 16 14:03:12 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand play Apr 16 14:03:12 primo volumio[5322]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 16 14:03:12 primo volumio[5322]: info: ------------------------------ 66ms Apr 16 14:03:12 primo volumio[5322]: info: Apr 16 14:03:12 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:03:12 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:03:12 primo volumio[5322]: info: Apr 16 14:03:12 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:03:12 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:03:12 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:12 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:12 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:12 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:12 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:12 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:12 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:12 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:12 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:12 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:12 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:12 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:12 primo volumio[5322]: info: ------------------------------ 45ms Apr 16 14:03:12 primo volumio[5322]: info: sendMpdCommand play took 41 milliseconds Apr 16 14:03:12 primo volumio[5322]: info: ------------------------------ 40ms Apr 16 14:03:12 primo volumio[5322]: info: ------------------------------ 39ms Apr 16 14:03:16 primo volumio[5322]: info: Preload queue cleared Apr 16 14:03:16 primo volumio[5322]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 16 14:03:16 primo volumio[5322]: info: CoreStateMachine::ClearQueue Apr 16 14:03:16 primo volumio[5322]: info: CoreStateMachine::stop Apr 16 14:03:16 primo volumio[5322]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 16 14:03:16 primo volumio[5322]: info: CorePlayQueue::clearPlayQueue Apr 16 14:03:16 primo volumio[5322]: info: CorePlayQueue::saveQueue Apr 16 14:03:16 primo volumio[5322]: info: CoreCommandRouter::volumioPushQueue Apr 16 14:03:16 primo volumio[5322]: info: CoreStateMachine::addQueueItems Apr 16 14:03:16 primo volumio[5322]: info: CorePlayQueue::addQueueItems Apr 16 14:03:16 primo volumio[5322]: info: Preload queue cleared Apr 16 14:03:16 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/Babylon by Bus/Babylon by Bus-01.flac Apr 16 14:03:16 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/Babylon by Bus/Babylon by Bus-01.flac Apr 16 14:03:16 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/Babylon by Bus/Babylon by Bus-02.flac Apr 16 14:03:16 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/Babylon by Bus/Babylon by Bus-02.flac Apr 16 14:03:16 primo volumio[5322]: info: CoreCommandRouter::volumioPushQueue Apr 16 14:03:16 primo volumio[5322]: info: CorePlayQueue::saveQueue Apr 16 14:03:16 primo volumio[5322]: info: CoreStateMachine::updateTrackBlock Apr 16 14:03:16 primo volumio[5322]: info: CorePlayQueue::getTrackBlock Apr 16 14:03:16 primo volumio[5322]: info: CoreCommandRouter::volumioPlay Apr 16 14:03:16 primo volumio[5322]: info: CoreStateMachine::play index 0 Apr 16 14:03:16 primo volumio[5322]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 16 14:03:16 primo volumio[5322]: info: CoreStateMachine::stop Apr 16 14:03:16 primo volumio[5322]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 16 14:03:16 primo volumio[5322]: info: CoreStateMachine::play index undefined Apr 16 14:03:16 primo volumio[5322]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 16 14:03:16 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:16 primo volumio[5322]: info: CoreStateMachine::startPlaybackTimer Apr 16 14:03:16 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:16 primo volumio[5322]: verbose: ControllerMpd::clearAddPlayTracks USB/SSDSumsung/LossLessMusic/Babylon by Bus/Babylon by Bus-01.flac Apr 16 14:03:16 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand stop Apr 16 14:03:16 primo volumio[5322]: info: Apr 16 14:03:16 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:03:16 primo volumio[5322]: info: sendMpdCommand stop took 15 milliseconds Apr 16 14:03:16 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:03:16 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:03:16 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand clear Apr 16 14:03:16 primo volumio[5322]: info: Apr 16 14:03:16 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:03:16 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:03:16 primo volumio[5322]: info: sendMpdCommand status took 2 milliseconds Apr 16 14:03:16 primo volumio[5322]: info: sendMpdCommand clear took 2 milliseconds Apr 16 14:03:16 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:03:16 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 14:03:16 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand add "USB/SSDSumsung/LossLessMusic/Babylon by Bus/Babylon by Bus-01.flac" Apr 16 14:03:16 primo volumio[5322]: info: Apr 16 14:03:16 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:03:16 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:03:16 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:03:16 primo volumio[5322]: info: Apr 16 14:03:16 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:03:16 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:03:16 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:03:16 primo volumio[5322]: error: updateQueue error: null Apr 16 14:03:16 primo volumio[5322]: info: Apr 16 14:03:16 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:03:16 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:03:16 primo volumio[5322]: info: ------------------------------ 9ms Apr 16 14:03:16 primo volumio[5322]: info: sendMpdCommand playlistinfo took 7 milliseconds Apr 16 14:03:16 primo volumio[5322]: info: sendMpdCommand add "USB/SSDSumsung/LossLessMusic/Babylon by Bus/Babylon by Bus-01.flac" took 8 milliseconds Apr 16 14:03:16 primo volumio[5322]: info: sendMpdCommand status took 6 milliseconds Apr 16 14:03:16 primo volumio[5322]: info: sendMpdCommand status took 4 milliseconds Apr 16 14:03:16 primo volumio[5322]: verbose: ControllerMpd::parseTrackInfo Apr 16 14:03:16 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand play Apr 16 14:03:16 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:03:16 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:03:16 primo volumio[5322]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 16 14:03:16 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:03:16 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:03:16 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:16 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:16 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 16 14:03:16 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:16 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:16 primo volumio[5322]: 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} Apr 16 14:03:16 primo volumio[5322]: verbose: CURRENT POSITION 0 Apr 16 14:03:16 primo volumio[5322]: info: CoreStateMachine::syncState stateService stop Apr 16 14:03:16 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus stop Apr 16 14:03:16 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:16 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:16 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:16 primo volumio[5322]: info: No code Apr 16 14:03:16 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:16 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:16 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:16 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:03:16 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:03:16 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:16 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:16 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:16 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:16 primo volumio[5322]: 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} Apr 16 14:03:16 primo volumio[5322]: verbose: CURRENT POSITION 0 Apr 16 14:03:16 primo volumio[5322]: info: CoreStateMachine::syncState stateService stop Apr 16 14:03:16 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus stop Apr 16 14:03:16 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:16 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:16 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:16 primo volumio[5322]: info: No code Apr 16 14:03:16 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:16 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:16 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:16 primo volumio[5322]: info: ------------------------------ 39ms Apr 16 14:03:16 primo volumio[5322]: info: ------------------------------ 51ms Apr 16 14:03:16 primo volumio[5322]: info: ------------------------------ 50ms Apr 16 14:03:16 primo volumio[5322]: info: Apr 16 14:03:16 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:03:16 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:03:16 primo volumio[5322]: info: Apr 16 14:03:16 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:03:16 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:03:16 primo volumio[5322]: info: ------------------------------ 54ms Apr 16 14:03:16 primo volumio[5322]: info: sendMpdCommand play took 51 milliseconds Apr 16 14:03:16 primo volumio[5322]: info: ------------------------------ 6ms Apr 16 14:03:16 primo volumio[5322]: info: ------------------------------ 4ms Apr 16 14:03:16 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:16 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:16 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:16 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:16 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:16 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:16 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:16 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:16 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:16 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:16 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:16 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:21 primo volumio[5322]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 16 14:03:21 primo volumio[5322]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 16 14:03:21 primo volumio[5322]: info: Retrieving Cloud Streaming UI Apr 16 14:03:21 primo volumio[5322]: info: Getting Tidal Cloud Configuration Apr 16 14:03:21 primo volumio[5322]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 16 14:03:21 primo volumio[5322]: info: Getting Qobuz Cloud Configuration Apr 16 14:03:21 primo volumio[5322]: info: Asking plugin for UI Config Apr 16 14:03:21 primo volumio[5322]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 16 14:03:21 primo volumio[5322]: info: Getting Spotify Cloud Configuration Apr 16 14:03:21 primo volumio[5322]: info: Asking plugin for UI Config Apr 16 14:03:21 primo volumio[5322]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 16 14:03:21 primo volumio[5322]: info: Saving Spotify Acccount Apr 16 14:03:21 primo volumio[5322]: info: Got it Apr 16 14:03:21 primo volumio[5322]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Apr 16 14:03:21 primo volumio[5322]: info: Got Tidal Cloud Configuration Apr 16 14:03:21 primo volumio[5322]: info: Got it Apr 16 14:03:21 primo volumio[5322]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 16 14:03:21 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 16 14:03:21 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Apr 16 14:03:21 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Apr 16 14:03:21 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Apr 16 14:03:21 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 16 14:03:21 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 16 14:03:21 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 16 14:03:21 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 16 14:03:21 primo volumio[5322]: info: CoreCommandRouter::volumioGetBrowseSources Apr 16 14:03:21 primo volumio[5322]: info: CoreCommandRouter::volumioGetBrowseSources Apr 16 14:03:21 primo volumio[5322]: info: CoreCommandRouter::volumioGetBrowseSources Apr 16 14:03:22 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 16 14:03:22 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Apr 16 14:03:24 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: mpd , rescanDb Apr 16 14:03:24 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand rescan Apr 16 14:03:24 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:03:24 primo volumio[5322]: info: Apr 16 14:03:24 primo volumio[5322]: ---------------------------- MPD announces state update: update Apr 16 14:03:24 primo volumio[5322]: info: sendMpdCommand rescan took 7 milliseconds Apr 16 14:03:24 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:03:24 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:03:24 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:03:24 primo volumio[5322]: info: Apr 16 14:03:24 primo volumio[5322]: ---------------------------- MPD announces state update: update Apr 16 14:03:24 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:03:24 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:03:24 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:03:24 primo volumio[5322]: info: Apr 16 14:03:24 primo volumio[5322]: ---------------------------- MPD announces state update: update Apr 16 14:03:24 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:03:24 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:03:24 primo volumio[5322]: info: sendMpdCommand status took 12 milliseconds Apr 16 14:03:24 primo volumio[5322]: info: sendMpdCommand status took 9 milliseconds Apr 16 14:03:24 primo volumio[5322]: info: sendMpdCommand status took 7 milliseconds Apr 16 14:03:24 primo volumio[5322]: info: sendMpdCommand status took 6 milliseconds Apr 16 14:03:24 primo volumio[5322]: info: sendMpdCommand status took 6 milliseconds Apr 16 14:03:24 primo volumio[5322]: info: sendMpdCommand status took 4 milliseconds Apr 16 14:03:24 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:03:24 primo volumio[5322]: info: Command Router : Notfying DB Updatetrue Apr 16 14:03:24 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:03:24 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 14:03:24 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:03:24 primo volumio[5322]: info: Command Router : Notfying DB Updatetrue Apr 16 14:03:24 primo volumio[5322]: info: CoreCommandRouter::Close All Modals sent Apr 16 14:03:24 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:03:24 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 14:03:24 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:03:24 primo volumio[5322]: info: Command Router : Notfying DB Updatetrue Apr 16 14:03:24 primo volumio[5322]: info: CoreCommandRouter::Close All Modals sent Apr 16 14:03:24 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:03:24 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 14:03:24 primo volumio[5322]: info: sendMpdCommand playlistinfo took 109 milliseconds Apr 16 14:03:24 primo volumio[5322]: info: sendMpdCommand playlistinfo took 65 milliseconds Apr 16 14:03:24 primo volumio[5322]: info: sendMpdCommand playlistinfo took 17 milliseconds Apr 16 14:03:24 primo volumio[5322]: verbose: ControllerMpd::parseTrackInfo Apr 16 14:03:24 primo volumio[5322]: verbose: ControllerMpd::parseTrackInfo Apr 16 14:03:24 primo volumio[5322]: verbose: ControllerMpd::parseTrackInfo Apr 16 14:03:24 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:03:24 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:03:24 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:24 primo volumio[5322]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Babylon by Bus-01.flac","artist":null,"album":null,"uri":"USB/SSDSumsung/LossLessMusic/Babylon by Bus/Babylon by Bus-01.flac","trackType":"flac"} Apr 16 14:03:24 primo volumio[5322]: verbose: CURRENT POSITION 0 Apr 16 14:03:24 primo volumio[5322]: info: CoreStateMachine::syncState stateService play Apr 16 14:03:24 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus stop Apr 16 14:03:24 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:03:24 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:03:24 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:24 primo volumio[5322]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Babylon by Bus-01.flac","artist":null,"album":null,"uri":"USB/SSDSumsung/LossLessMusic/Babylon by Bus/Babylon by Bus-01.flac","trackType":"flac"} Apr 16 14:03:24 primo volumio[5322]: verbose: CURRENT POSITION 0 Apr 16 14:03:24 primo volumio[5322]: info: CoreStateMachine::syncState stateService play Apr 16 14:03:24 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus play Apr 16 14:03:24 primo volumio[5322]: info: Received an update from plugin. extracting info from payload Apr 16 14:03:24 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:24 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:24 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 16 14:03:24 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:24 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:24 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:24 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:24 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:03:24 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:03:24 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:24 primo volumio[5322]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Babylon by Bus-01.flac","artist":null,"album":null,"uri":"USB/SSDSumsung/LossLessMusic/Babylon by Bus/Babylon by Bus-01.flac","trackType":"flac"} Apr 16 14:03:24 primo volumio[5322]: verbose: CURRENT POSITION 0 Apr 16 14:03:24 primo volumio[5322]: info: CoreStateMachine::syncState stateService play Apr 16 14:03:24 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus play Apr 16 14:03:24 primo volumio[5322]: info: Received an update from plugin. extracting info from payload Apr 16 14:03:24 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:24 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:24 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:24 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:24 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:24 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:24 primo volumio[5322]: info: ------------------------------ 213ms Apr 16 14:03:24 primo volumio[5322]: info: ------------------------------ 222ms Apr 16 14:03:24 primo volumio[5322]: info: ------------------------------ 220ms Apr 16 14:03:24 primo volumio[5322]: info: Signalling Playback active due to playback status change Apr 16 14:03:24 primo volumio[5322]: info: Signalling Playback active due to playback status change Apr 16 14:03:24 primo volumio[5322]: info: Signalling Playback active due to playback status change Apr 16 14:03:24 primo volumio[5322]: info: Signalling Playback active due to playback status change Apr 16 14:03:24 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:24 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:24 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:24 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:24 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:24 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:24 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:24 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:24 primo volumio[5322]: info: MCU Signalled Playback Active Apr 16 14:03:26 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 16 14:03:28 primo volumio[5322]: info: Apr 16 14:03:28 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:03:28 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:03:28 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:03:28 primo volumio[5322]: info: Apr 16 14:03:28 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:03:28 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:03:28 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:03:28 primo volumio[5322]: info: Apr 16 14:03:28 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:03:28 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:03:28 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:03:28 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand clearerror Apr 16 14:03:28 primo volumio[5322]: info: sendMpdCommand status took 12 milliseconds Apr 16 14:03:28 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand clearerror Apr 16 14:03:28 primo volumio[5322]: info: sendMpdCommand status took 12 milliseconds Apr 16 14:03:28 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:03:28 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 14:03:28 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:03:28 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 14:03:28 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand clearerror Apr 16 14:03:28 primo volumio[5322]: info: sendMpdCommand status took 26 milliseconds Apr 16 14:03:28 primo volumio[5322]: info: sendMpdCommand clearerror took 19 milliseconds Apr 16 14:03:28 primo volumio[5322]: info: sendMpdCommand clearerror took 17 milliseconds Apr 16 14:03:28 primo volumio[5322]: info: sendMpdCommand playlistinfo took 14 milliseconds Apr 16 14:03:28 primo volumio[5322]: info: sendMpdCommand playlistinfo took 13 milliseconds Apr 16 14:03:28 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:03:28 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 14:03:28 primo volumio[5322]: verbose: ControllerMpd::parseTrackInfo Apr 16 14:03:28 primo volumio[5322]: verbose: ControllerMpd::parseTrackInfo Apr 16 14:03:28 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:03:28 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:03:28 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:28 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:28 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 16 14:03:28 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:28 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:03:28 primo volumio[5322]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Babylon by Bus-01.flac","artist":null,"album":null,"uri":"USB/SSDSumsung/LossLessMusic/Babylon by Bus/Babylon by Bus-01.flac","trackType":"flac"} Apr 16 14:03:28 primo volumio[5322]: verbose: CURRENT POSITION 0 Apr 16 14:03:28 primo volumio[5322]: info: CoreStateMachine::syncState stateService stop Apr 16 14:03:28 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus play Apr 16 14:03:28 primo volumio[5322]: info: CoreStateMachine::play index undefined Apr 16 14:03:28 primo volumio[5322]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 16 14:03:28 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:28 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:28 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 16 14:03:28 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:28 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:03:28 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:03:28 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:28 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:28 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:28 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:28 primo volumio[5322]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Babylon by Bus-01.flac","artist":null,"album":null,"uri":"USB/SSDSumsung/LossLessMusic/Babylon by Bus/Babylon by Bus-01.flac","trackType":"flac"} Apr 16 14:03:28 primo volumio[5322]: verbose: CURRENT POSITION 1 Apr 16 14:03:28 primo volumio[5322]: info: CoreStateMachine::syncState stateService stop Apr 16 14:03:28 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus stop Apr 16 14:03:28 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:28 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:28 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:28 primo volumio[5322]: info: No code Apr 16 14:03:28 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:28 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:28 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:28 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:28 primo volumio[5322]: info: CoreStateMachine::startPlaybackTimer Apr 16 14:03:28 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:28 primo volumio[5322]: info: CoreCommandRouter::volumioGetVisibleSources Apr 16 14:03:28 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 16 14:03:28 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 16 14:03:28 primo volumio[5322]: info: METAVOLUMIO: Retrieving similar tracks from metavolumio Apr 16 14:03:28 primo volumio[5322]: verbose: ControllerMpd::clearAddPlayTracks USB/SSDSumsung/LossLessMusic/Babylon by Bus/Babylon by Bus-02.flac Apr 16 14:03:28 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand stop Apr 16 14:03:28 primo volumio[5322]: info: ------------------------------ 94ms Apr 16 14:03:28 primo volumio[5322]: info: ------------------------------ 90ms Apr 16 14:03:28 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:28 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:28 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 16 14:03:28 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:28 primo volumio[5322]: info: Signalling Playback active due to playback status change Apr 16 14:03:28 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:28 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:28 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:28 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:28 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:28 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:28 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:28 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:28 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:28 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:28 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:28 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:28 primo volumio[5322]: info: sendMpdCommand clearerror took 124 milliseconds Apr 16 14:03:28 primo volumio[5322]: info: sendMpdCommand playlistinfo took 121 milliseconds Apr 16 14:03:28 primo volumio[5322]: info: sendMpdCommand stop took 66 milliseconds Apr 16 14:03:28 primo volumio[5322]: verbose: ControllerMpd::parseTrackInfo Apr 16 14:03:28 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand clear Apr 16 14:03:28 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:03:28 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:03:28 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:28 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:28 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 16 14:03:28 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:28 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:28 primo volumio[5322]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Babylon by Bus-01.flac","artist":null,"album":null,"uri":"USB/SSDSumsung/LossLessMusic/Babylon by Bus/Babylon by Bus-01.flac","trackType":"flac"} Apr 16 14:03:28 primo volumio[5322]: verbose: CURRENT POSITION 1 Apr 16 14:03:28 primo volumio[5322]: info: CoreStateMachine::syncState stateService stop Apr 16 14:03:28 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus stop Apr 16 14:03:28 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:28 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:28 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:28 primo volumio[5322]: info: No code Apr 16 14:03:28 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:28 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:28 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:28 primo volumio[5322]: info: ------------------------------ 178ms Apr 16 14:03:28 primo volumio[5322]: info: Apr 16 14:03:28 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:03:28 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:03:28 primo volumio[5322]: info: sendMpdCommand clear took 28 milliseconds Apr 16 14:03:28 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand add "USB/SSDSumsung/LossLessMusic/Babylon by Bus/Babylon by Bus-02.flac" Apr 16 14:03:28 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:28 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:28 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:28 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:28 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:28 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:28 primo volumio[5322]: info: Apr 16 14:03:28 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:03:28 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:03:28 primo volumio[5322]: info: Apr 16 14:03:28 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:03:28 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:03:28 primo volumio[5322]: error: updateQueue error: null Apr 16 14:03:28 primo volumio[5322]: info: Apr 16 14:03:28 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:03:28 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:03:28 primo volumio[5322]: info: ------------------------------ 32ms Apr 16 14:03:28 primo volumio[5322]: info: sendMpdCommand add "USB/SSDSumsung/LossLessMusic/Babylon by Bus/Babylon by Bus-02.flac" took 31 milliseconds Apr 16 14:03:28 primo volumio[5322]: info: ------------------------------ 6ms Apr 16 14:03:28 primo volumio[5322]: info: ------------------------------ 5ms Apr 16 14:03:28 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand play Apr 16 14:03:28 primo volumio[5322]: info: Apr 16 14:03:28 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:03:28 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:03:28 primo volumio[5322]: info: Apr 16 14:03:28 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:03:28 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:03:28 primo volumio[5322]: info: MCU Signalled Playback Inactive Apr 16 14:03:28 primo volumio[5322]: info: ------------------------------ 11ms Apr 16 14:03:28 primo volumio[5322]: info: sendMpdCommand play took 8 milliseconds Apr 16 14:03:28 primo volumio[5322]: info: ------------------------------ 7ms Apr 16 14:03:28 primo volumio[5322]: info: ------------------------------ 5ms Apr 16 14:03:32 primo volumio[5322]: info: CoreCommandRouter::volumioPlay Apr 16 14:03:32 primo volumio[5322]: info: CoreStateMachine::play index 1 Apr 16 14:03:32 primo volumio[5322]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 16 14:03:32 primo volumio[5322]: info: CoreStateMachine::stop Apr 16 14:03:32 primo volumio[5322]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 16 14:03:32 primo volumio[5322]: info: CoreStateMachine::play index undefined Apr 16 14:03:32 primo volumio[5322]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 16 14:03:32 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:32 primo volumio[5322]: info: CoreStateMachine::startPlaybackTimer Apr 16 14:03:32 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:32 primo volumio[5322]: info: CoreCommandRouter::volumioGetVisibleSources Apr 16 14:03:32 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 16 14:03:32 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 16 14:03:32 primo volumio[5322]: info: METAVOLUMIO: Retrieving similar tracks from metavolumio Apr 16 14:03:32 primo volumio[5322]: verbose: ControllerMpd::clearAddPlayTracks USB/SSDSumsung/LossLessMusic/Babylon by Bus/Babylon by Bus-02.flac Apr 16 14:03:32 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand stop Apr 16 14:03:32 primo volumio[5322]: info: sendMpdCommand stop took 31 milliseconds Apr 16 14:03:32 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand clear Apr 16 14:03:32 primo volumio[5322]: info: Apr 16 14:03:32 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:03:32 primo volumio[5322]: info: Apr 16 14:03:32 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:03:32 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:03:32 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:03:32 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:03:32 primo volumio[5322]: info: sendMpdCommand clear took 3 milliseconds Apr 16 14:03:32 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand add "USB/SSDSumsung/LossLessMusic/Babylon by Bus/Babylon by Bus-02.flac" Apr 16 14:03:32 primo volumio[5322]: info: Apr 16 14:03:32 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:03:32 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:03:32 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:03:32 primo volumio[5322]: info: Apr 16 14:03:32 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:03:32 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:03:32 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:03:32 primo volumio[5322]: error: updateQueue error: null Apr 16 14:03:32 primo volumio[5322]: info: Apr 16 14:03:32 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:03:32 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:03:32 primo volumio[5322]: info: sendMpdCommand status took 8 milliseconds Apr 16 14:03:32 primo volumio[5322]: info: ------------------------------ 10ms Apr 16 14:03:32 primo volumio[5322]: info: sendMpdCommand add "USB/SSDSumsung/LossLessMusic/Babylon by Bus/Babylon by Bus-02.flac" took 8 milliseconds Apr 16 14:03:32 primo volumio[5322]: info: sendMpdCommand status took 6 milliseconds Apr 16 14:03:32 primo volumio[5322]: info: sendMpdCommand status took 5 milliseconds Apr 16 14:03:32 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:03:32 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand play Apr 16 14:03:32 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:03:32 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:03:32 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:03:32 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:03:32 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:32 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:32 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 16 14:03:32 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:32 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:32 primo volumio[5322]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 16 14:03:32 primo volumio[5322]: verbose: CURRENT POSITION 1 Apr 16 14:03:32 primo volumio[5322]: info: CoreStateMachine::syncState stateService stop Apr 16 14:03:32 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus stop Apr 16 14:03:32 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:32 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:32 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:32 primo volumio[5322]: info: No code Apr 16 14:03:32 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:32 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:32 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:32 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:03:32 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:03:32 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:32 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:32 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:32 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:32 primo volumio[5322]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 16 14:03:32 primo volumio[5322]: verbose: CURRENT POSITION 1 Apr 16 14:03:32 primo volumio[5322]: info: CoreStateMachine::syncState stateService stop Apr 16 14:03:32 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus stop Apr 16 14:03:32 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:32 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:32 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:32 primo volumio[5322]: info: No code Apr 16 14:03:32 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:32 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:32 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:32 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:03:32 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:03:32 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:32 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:32 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:32 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:32 primo volumio[5322]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 16 14:03:32 primo volumio[5322]: verbose: CURRENT POSITION 1 Apr 16 14:03:32 primo volumio[5322]: info: CoreStateMachine::syncState stateService stop Apr 16 14:03:32 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus stop Apr 16 14:03:32 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:32 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:32 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:32 primo volumio[5322]: info: No code Apr 16 14:03:32 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:32 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:32 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:32 primo volumio[5322]: info: ------------------------------ 77ms Apr 16 14:03:32 primo volumio[5322]: info: ------------------------------ 74ms Apr 16 14:03:32 primo volumio[5322]: info: ------------------------------ 73ms Apr 16 14:03:32 primo volumio[5322]: info: Apr 16 14:03:32 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:03:32 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:03:32 primo volumio[5322]: info: Apr 16 14:03:32 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:03:32 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:03:32 primo volumio[5322]: info: ------------------------------ 82ms Apr 16 14:03:32 primo volumio[5322]: info: sendMpdCommand play took 78 milliseconds Apr 16 14:03:32 primo volumio[5322]: info: ------------------------------ 9ms Apr 16 14:03:32 primo volumio[5322]: info: ------------------------------ 4ms Apr 16 14:03:33 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:33 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:33 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:33 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:33 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:33 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:33 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:33 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:33 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:33 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:33 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:33 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:33 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:33 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:33 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:33 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:33 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:33 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:37 primo volumio[5322]: info: Preload queue cleared Apr 16 14:03:37 primo volumio[5322]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 16 14:03:37 primo volumio[5322]: info: CoreStateMachine::ClearQueue Apr 16 14:03:37 primo volumio[5322]: info: CoreStateMachine::stop Apr 16 14:03:37 primo volumio[5322]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 16 14:03:37 primo volumio[5322]: info: CorePlayQueue::clearPlayQueue Apr 16 14:03:37 primo volumio[5322]: info: CorePlayQueue::saveQueue Apr 16 14:03:37 primo volumio[5322]: info: CoreCommandRouter::volumioPushQueue Apr 16 14:03:37 primo volumio[5322]: info: CoreStateMachine::addQueueItems Apr 16 14:03:37 primo volumio[5322]: info: CorePlayQueue::addQueueItems Apr 16 14:03:37 primo volumio[5322]: info: Preload queue cleared Apr 16 14:03:37 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/Babylon by Bus/Babylon by Bus-01.flac Apr 16 14:03:37 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/Babylon by Bus/Babylon by Bus-01.flac Apr 16 14:03:37 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/Babylon by Bus/Babylon by Bus-02.flac Apr 16 14:03:37 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/Babylon by Bus/Babylon by Bus-02.flac Apr 16 14:03:37 primo volumio[5322]: info: CoreCommandRouter::volumioPushQueue Apr 16 14:03:37 primo volumio[5322]: info: CorePlayQueue::saveQueue Apr 16 14:03:37 primo volumio[5322]: info: CoreStateMachine::updateTrackBlock Apr 16 14:03:37 primo volumio[5322]: info: CorePlayQueue::getTrackBlock Apr 16 14:03:37 primo volumio[5322]: info: CoreCommandRouter::volumioPlay Apr 16 14:03:37 primo volumio[5322]: info: CoreStateMachine::play index 1 Apr 16 14:03:37 primo volumio[5322]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 16 14:03:37 primo volumio[5322]: info: CoreStateMachine::stop Apr 16 14:03:37 primo volumio[5322]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 16 14:03:37 primo volumio[5322]: info: CoreStateMachine::play index undefined Apr 16 14:03:37 primo volumio[5322]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 16 14:03:37 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:37 primo volumio[5322]: info: CoreStateMachine::startPlaybackTimer Apr 16 14:03:37 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:37 primo volumio[5322]: info: CoreCommandRouter::volumioGetVisibleSources Apr 16 14:03:37 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 16 14:03:37 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 16 14:03:37 primo volumio[5322]: info: METAVOLUMIO: Retrieving similar tracks from metavolumio Apr 16 14:03:37 primo volumio[5322]: verbose: ControllerMpd::clearAddPlayTracks USB/SSDSumsung/LossLessMusic/Babylon by Bus/Babylon by Bus-02.flac Apr 16 14:03:37 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand stop Apr 16 14:03:37 primo volumio[5322]: info: Apr 16 14:03:37 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:03:37 primo volumio[5322]: info: sendMpdCommand stop took 12 milliseconds Apr 16 14:03:37 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:03:37 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:03:37 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand clear Apr 16 14:03:37 primo volumio[5322]: info: Apr 16 14:03:37 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:03:37 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:03:37 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:03:37 primo volumio[5322]: info: Apr 16 14:03:37 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:03:37 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:03:37 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:03:37 primo volumio[5322]: info: Apr 16 14:03:37 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:03:37 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:03:37 primo volumio[5322]: info: sendMpdCommand status took 10 milliseconds Apr 16 14:03:37 primo volumio[5322]: info: sendMpdCommand clear took 10 milliseconds Apr 16 14:03:37 primo volumio[5322]: info: sendMpdCommand status took 8 milliseconds Apr 16 14:03:37 primo volumio[5322]: info: sendMpdCommand status took 7 milliseconds Apr 16 14:03:37 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:03:37 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 14:03:37 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand add "USB/SSDSumsung/LossLessMusic/Babylon by Bus/Babylon by Bus-02.flac" Apr 16 14:03:37 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:03:37 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:03:37 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:03:37 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:03:37 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:37 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:37 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 16 14:03:37 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:37 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:37 primo volumio[5322]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 16 14:03:37 primo volumio[5322]: verbose: CURRENT POSITION 1 Apr 16 14:03:37 primo volumio[5322]: info: CoreStateMachine::syncState stateService stop Apr 16 14:03:37 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus stop Apr 16 14:03:37 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:37 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:37 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:37 primo volumio[5322]: info: No code Apr 16 14:03:37 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:37 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:37 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:37 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:03:37 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:03:37 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:37 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:37 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:37 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:37 primo volumio[5322]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 16 14:03:37 primo volumio[5322]: verbose: CURRENT POSITION 1 Apr 16 14:03:37 primo volumio[5322]: info: CoreStateMachine::syncState stateService stop Apr 16 14:03:37 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus stop Apr 16 14:03:37 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:37 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:37 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:37 primo volumio[5322]: info: No code Apr 16 14:03:37 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:37 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:37 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:37 primo volumio[5322]: info: ------------------------------ 51ms Apr 16 14:03:37 primo volumio[5322]: info: ------------------------------ 50ms Apr 16 14:03:37 primo volumio[5322]: info: Apr 16 14:03:37 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:03:37 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:03:37 primo volumio[5322]: info: Apr 16 14:03:37 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:03:37 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:03:37 primo volumio[5322]: error: updateQueue error: null Apr 16 14:03:37 primo volumio[5322]: info: Apr 16 14:03:37 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:03:37 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:03:37 primo volumio[5322]: info: ------------------------------ 61ms Apr 16 14:03:37 primo volumio[5322]: info: sendMpdCommand playlistinfo took 58 milliseconds Apr 16 14:03:37 primo volumio[5322]: info: sendMpdCommand add "USB/SSDSumsung/LossLessMusic/Babylon by Bus/Babylon by Bus-02.flac" took 58 milliseconds Apr 16 14:03:37 primo volumio[5322]: info: ------------------------------ 12ms Apr 16 14:03:37 primo volumio[5322]: info: ------------------------------ 11ms Apr 16 14:03:37 primo volumio[5322]: verbose: ControllerMpd::parseTrackInfo Apr 16 14:03:37 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand play Apr 16 14:03:37 primo volumio[5322]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 16 14:03:37 primo volumio[5322]: info: ------------------------------ 80ms Apr 16 14:03:37 primo volumio[5322]: info: Apr 16 14:03:37 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:03:37 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:03:37 primo volumio[5322]: info: Apr 16 14:03:37 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:03:37 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:03:37 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:37 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:37 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:37 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:37 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:37 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:37 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:37 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:37 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:37 primo volumio[5322]: info: ------------------------------ 57ms Apr 16 14:03:37 primo volumio[5322]: info: sendMpdCommand play took 53 milliseconds Apr 16 14:03:37 primo volumio[5322]: info: ------------------------------ 51ms Apr 16 14:03:37 primo volumio[5322]: info: ------------------------------ 46ms Apr 16 14:03:41 primo ntpd[5562]: Soliciting pool server 2606:4700:f1::123 Apr 16 14:03:44 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 16 14:03:44 primo volumio[5322]: info: CURURI: music-library/USB/SSDSumsung/LossLessMusic/No Doubt Apr 16 14:03:44 primo volumio[5322]: info: Preload queue cleared Apr 16 14:03:46 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 16 14:03:46 primo volumio[5322]: info: CURURI: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/No Doubt - 1996 - Tragic Kingdom (LP, Red Vinyl, US, 92580-1) [24-192] Apr 16 14:03:47 primo volumio[5322]: info: Preload queue cleared Apr 16 14:03:47 primo volumio[5322]: info: Preloading song: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/No Doubt - 1996 - Tragic Kingdom (LP, Red Vinyl, US, 92580-1) [24-192]/No Doubt - Tragic Kingdom.m3u Apr 16 14:03:47 primo volumio[5322]: info: Exploding uri music-library/USB/SSDSumsung/LossLessMusic/No Doubt/No Doubt - 1996 - Tragic Kingdom (LP, Red Vinyl, US, 92580-1) [24-192]/No Doubt - Tragic Kingdom.m3u in service mpd Apr 16 14:03:49 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 16 14:03:49 primo volumio[5322]: info: CURURI: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip] Apr 16 14:03:50 primo volumio[5322]: info: Preload queue cleared Apr 16 14:03:50 primo volumio[5322]: info: Preloading song: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/A1. Ex-Girlfriend.flac Apr 16 14:03:50 primo volumio[5322]: info: Preloading song: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/A2. Simple Kind of Life.flac Apr 16 14:03:50 primo volumio[5322]: info: Preloading song: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/A3. Bathwater.flac Apr 16 14:03:50 primo volumio[5322]: info: Preloading song: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/A4. Six Feet Under.flac Apr 16 14:03:50 primo volumio[5322]: info: Preloading song: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/B1. Magic's in the Makeup.flac Apr 16 14:03:50 primo volumio[5322]: info: Preloading song: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/B2. Artificial Sweetener.flac Apr 16 14:03:50 primo volumio[5322]: info: Preloading song: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/B3. Marry Me.flac Apr 16 14:03:50 primo volumio[5322]: info: Preloading song: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/C1. New.flac Apr 16 14:03:50 primo volumio[5322]: info: Preloading song: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/C2. Too Late.flac Apr 16 14:03:50 primo volumio[5322]: info: Preloading song: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/C3. Comforting Lie.flac Apr 16 14:03:50 primo volumio[5322]: info: Preloading song: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/C4. Suspension Without Suspense.flac Apr 16 14:03:50 primo volumio[5322]: info: Preloading song: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/D1. Staring Problem.flac Apr 16 14:03:50 primo volumio[5322]: info: Preloading song: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/D2. Home Now.flac Apr 16 14:03:50 primo volumio[5322]: info: Preloading song: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/D3. Dark Blue.flac Apr 16 14:03:50 primo volumio[5322]: info: Exploding uri music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/A1. Ex-Girlfriend.flac in service mpd Apr 16 14:03:50 primo volumio[5322]: info: ALBUMART /albumart?cacheid=615&web=No%20Doubt/Return%20Of%20Saturn/extralarge&path=%2Fmnt%2FUSB%2FSSDSumsung%2FLossLessMusic%2FNo%20Doubt%2F2000%20-%20No%20Doubt%20-%20Return%20Of%20Saturn%20%5BVinyl%20Rip%5D%2FA1.%20Ex-Girlfriend.flac&metadata=false Apr 16 14:03:50 primo volumio[5322]: info: URI /mnt/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/A1. Ex-Girlfriend.flac Apr 16 14:03:50 primo volumio[5322]: info: Exploding uri music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/A2. Simple Kind of Life.flac in service mpd Apr 16 14:03:50 primo volumio[5322]: info: ALBUMART /albumart?cacheid=615&web=No%20Doubt/Return%20Of%20Saturn/extralarge&path=%2Fmnt%2FUSB%2FSSDSumsung%2FLossLessMusic%2FNo%20Doubt%2F2000%20-%20No%20Doubt%20-%20Return%20Of%20Saturn%20%5BVinyl%20Rip%5D%2FA2.%20Simple%20Kind%20of%20Life.flac&metadata=false Apr 16 14:03:50 primo volumio[5322]: info: URI /mnt/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/A2. Simple Kind of Life.flac Apr 16 14:03:50 primo volumio[5322]: info: Exploding uri music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/A3. Bathwater.flac in service mpd Apr 16 14:03:50 primo volumio[5322]: info: ALBUMART /albumart?cacheid=615&web=No%20Doubt/Return%20Of%20Saturn/extralarge&path=%2Fmnt%2FUSB%2FSSDSumsung%2FLossLessMusic%2FNo%20Doubt%2F2000%20-%20No%20Doubt%20-%20Return%20Of%20Saturn%20%5BVinyl%20Rip%5D%2FA3.%20Bathwater.flac&metadata=false Apr 16 14:03:50 primo volumio[5322]: info: URI /mnt/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/A3. Bathwater.flac Apr 16 14:03:50 primo volumio[5322]: info: Exploding uri music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/A4. Six Feet Under.flac in service mpd Apr 16 14:03:50 primo volumio[5322]: info: ALBUMART /albumart?cacheid=615&web=No%20Doubt/Return%20Of%20Saturn/extralarge&path=%2Fmnt%2FUSB%2FSSDSumsung%2FLossLessMusic%2FNo%20Doubt%2F2000%20-%20No%20Doubt%20-%20Return%20Of%20Saturn%20%5BVinyl%20Rip%5D%2FA4.%20Six%20Feet%20Under.flac&metadata=false Apr 16 14:03:50 primo volumio[5322]: info: URI /mnt/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/A4. Six Feet Under.flac Apr 16 14:03:50 primo volumio[5322]: info: Exploding uri music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/B1. Magic's in the Makeup.flac in service mpd Apr 16 14:03:50 primo volumio[5322]: info: ALBUMART /albumart?cacheid=615&web=No%20Doubt/Return%20Of%20Saturn/extralarge&path=%2Fmnt%2FUSB%2FSSDSumsung%2FLossLessMusic%2FNo%20Doubt%2F2000%20-%20No%20Doubt%20-%20Return%20Of%20Saturn%20%5BVinyl%20Rip%5D%2FB1.%20Magic's%20in%20the%20Makeup.flac&metadata=false Apr 16 14:03:50 primo volumio[5322]: info: URI /mnt/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/B1. Magic's in the Makeup.flac Apr 16 14:03:50 primo volumio[5322]: info: Exploding uri music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/B2. Artificial Sweetener.flac in service mpd Apr 16 14:03:50 primo volumio[5322]: info: ALBUMART /albumart?cacheid=615&web=No%20Doubt/Return%20Of%20Saturn/extralarge&path=%2Fmnt%2FUSB%2FSSDSumsung%2FLossLessMusic%2FNo%20Doubt%2F2000%20-%20No%20Doubt%20-%20Return%20Of%20Saturn%20%5BVinyl%20Rip%5D%2FB2.%20Artificial%20Sweetener.flac&metadata=false Apr 16 14:03:50 primo volumio[5322]: info: URI /mnt/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/B2. Artificial Sweetener.flac Apr 16 14:03:50 primo volumio[5322]: info: Exploding uri music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/B3. Marry Me.flac in service mpd Apr 16 14:03:50 primo volumio[5322]: info: ALBUMART /albumart?cacheid=615&web=No%20Doubt/Return%20Of%20Saturn/extralarge&path=%2Fmnt%2FUSB%2FSSDSumsung%2FLossLessMusic%2FNo%20Doubt%2F2000%20-%20No%20Doubt%20-%20Return%20Of%20Saturn%20%5BVinyl%20Rip%5D%2FB3.%20Marry%20Me.flac&metadata=false Apr 16 14:03:50 primo volumio[5322]: info: URI /mnt/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/B3. Marry Me.flac Apr 16 14:03:50 primo volumio[5322]: info: Exploding uri music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/C1. New.flac in service mpd Apr 16 14:03:50 primo volumio[5322]: info: ALBUMART /albumart?cacheid=615&web=No%20Doubt/Return%20Of%20Saturn/extralarge&path=%2Fmnt%2FUSB%2FSSDSumsung%2FLossLessMusic%2FNo%20Doubt%2F2000%20-%20No%20Doubt%20-%20Return%20Of%20Saturn%20%5BVinyl%20Rip%5D%2FC1.%20New.flac&metadata=false Apr 16 14:03:50 primo volumio[5322]: info: URI /mnt/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/C1. New.flac Apr 16 14:03:50 primo volumio[5322]: info: Exploding uri music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/C2. Too Late.flac in service mpd Apr 16 14:03:50 primo volumio[5322]: info: ALBUMART /albumart?cacheid=615&web=No%20Doubt/Return%20Of%20Saturn/extralarge&path=%2Fmnt%2FUSB%2FSSDSumsung%2FLossLessMusic%2FNo%20Doubt%2F2000%20-%20No%20Doubt%20-%20Return%20Of%20Saturn%20%5BVinyl%20Rip%5D%2FC2.%20Too%20Late.flac&metadata=false Apr 16 14:03:50 primo volumio[5322]: info: URI /mnt/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/C2. Too Late.flac Apr 16 14:03:50 primo volumio[5322]: info: Exploding uri music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/C3. Comforting Lie.flac in service mpd Apr 16 14:03:50 primo volumio[5322]: info: ALBUMART /albumart?cacheid=615&web=No%20Doubt/Return%20Of%20Saturn/extralarge&path=%2Fmnt%2FUSB%2FSSDSumsung%2FLossLessMusic%2FNo%20Doubt%2F2000%20-%20No%20Doubt%20-%20Return%20Of%20Saturn%20%5BVinyl%20Rip%5D%2FC3.%20Comforting%20Lie.flac&metadata=false Apr 16 14:03:50 primo volumio[5322]: info: URI /mnt/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/C3. Comforting Lie.flac Apr 16 14:03:50 primo volumio[5322]: info: Exploding uri music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/C4. Suspension Without Suspense.flac in service mpd Apr 16 14:03:50 primo volumio[5322]: info: ALBUMART /albumart?cacheid=615&web=No%20Doubt/Return%20Of%20Saturn/extralarge&path=%2Fmnt%2FUSB%2FSSDSumsung%2FLossLessMusic%2FNo%20Doubt%2F2000%20-%20No%20Doubt%20-%20Return%20Of%20Saturn%20%5BVinyl%20Rip%5D%2FC4.%20Suspension%20Without%20Suspense.flac&metadata=false Apr 16 14:03:50 primo volumio[5322]: info: URI /mnt/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/C4. Suspension Without Suspense.flac Apr 16 14:03:50 primo volumio[5322]: info: Exploding uri music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/D1. Staring Problem.flac in service mpd Apr 16 14:03:50 primo volumio[5322]: info: ALBUMART /albumart?cacheid=615&web=No%20Doubt/Return%20Of%20Saturn/extralarge&path=%2Fmnt%2FUSB%2FSSDSumsung%2FLossLessMusic%2FNo%20Doubt%2F2000%20-%20No%20Doubt%20-%20Return%20Of%20Saturn%20%5BVinyl%20Rip%5D%2FD1.%20Staring%20Problem.flac&metadata=false Apr 16 14:03:50 primo volumio[5322]: info: URI /mnt/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/D1. Staring Problem.flac Apr 16 14:03:50 primo volumio[5322]: info: Exploding uri music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/D2. Home Now.flac in service mpd Apr 16 14:03:50 primo volumio[5322]: info: ALBUMART /albumart?cacheid=615&web=No%20Doubt/Return%20Of%20Saturn/extralarge&path=%2Fmnt%2FUSB%2FSSDSumsung%2FLossLessMusic%2FNo%20Doubt%2F2000%20-%20No%20Doubt%20-%20Return%20Of%20Saturn%20%5BVinyl%20Rip%5D%2FD2.%20Home%20Now.flac&metadata=false Apr 16 14:03:50 primo volumio[5322]: info: URI /mnt/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/D2. Home Now.flac Apr 16 14:03:50 primo volumio[5322]: info: Exploding uri music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/D3. Dark Blue.flac in service mpd Apr 16 14:03:50 primo volumio[5322]: info: ALBUMART /albumart?cacheid=615&web=No%20Doubt/Return%20Of%20Saturn/extralarge&path=%2Fmnt%2FUSB%2FSSDSumsung%2FLossLessMusic%2FNo%20Doubt%2F2000%20-%20No%20Doubt%20-%20Return%20Of%20Saturn%20%5BVinyl%20Rip%5D%2FD3.%20Dark%20Blue.flac&metadata=false Apr 16 14:03:50 primo volumio[5322]: info: URI /mnt/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/D3. Dark Blue.flac Apr 16 14:03:57 primo volumio[5322]: info: Apr 16 14:03:57 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:03:57 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:03:57 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:03:57 primo volumio[5322]: info: Apr 16 14:03:57 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:03:57 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:03:57 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:03:57 primo volumio[5322]: info: Apr 16 14:03:57 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:03:57 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:03:57 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:03:57 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand clearerror Apr 16 14:03:57 primo volumio[5322]: info: sendMpdCommand status took 38 milliseconds Apr 16 14:03:57 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand clearerror Apr 16 14:03:57 primo volumio[5322]: info: sendMpdCommand status took 22 milliseconds Apr 16 14:03:57 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand clearerror Apr 16 14:03:57 primo volumio[5322]: info: sendMpdCommand status took 22 milliseconds Apr 16 14:03:57 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:03:57 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 14:03:57 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:03:57 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 14:03:57 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:03:57 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 14:03:57 primo volumio[5322]: info: sendMpdCommand clearerror took 14 milliseconds Apr 16 14:03:57 primo volumio[5322]: info: sendMpdCommand clearerror took 14 milliseconds Apr 16 14:03:57 primo volumio[5322]: info: sendMpdCommand clearerror took 12 milliseconds Apr 16 14:03:57 primo volumio[5322]: info: sendMpdCommand playlistinfo took 6 milliseconds Apr 16 14:03:57 primo volumio[5322]: info: sendMpdCommand playlistinfo took 6 milliseconds Apr 16 14:03:57 primo volumio[5322]: info: sendMpdCommand playlistinfo took 5 milliseconds Apr 16 14:03:57 primo volumio[5322]: verbose: ControllerMpd::parseTrackInfo Apr 16 14:03:57 primo volumio[5322]: verbose: ControllerMpd::parseTrackInfo Apr 16 14:03:57 primo volumio[5322]: verbose: ControllerMpd::parseTrackInfo Apr 16 14:03:57 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:03:57 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:03:57 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:57 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:57 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 16 14:03:57 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:57 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:57 primo volumio[5322]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Babylon by Bus-02.flac","artist":null,"album":null,"uri":"USB/SSDSumsung/LossLessMusic/Babylon by Bus/Babylon by Bus-02.flac","trackType":"flac"} Apr 16 14:03:57 primo volumio[5322]: verbose: CURRENT POSITION 1 Apr 16 14:03:57 primo volumio[5322]: info: CoreStateMachine::syncState stateService stop Apr 16 14:03:57 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus stop Apr 16 14:03:57 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:57 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:57 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:57 primo volumio[5322]: info: No code Apr 16 14:03:57 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:57 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:57 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:57 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:03:57 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:03:57 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:57 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:57 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:57 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:57 primo volumio[5322]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Babylon by Bus-02.flac","artist":null,"album":null,"uri":"USB/SSDSumsung/LossLessMusic/Babylon by Bus/Babylon by Bus-02.flac","trackType":"flac"} Apr 16 14:03:57 primo volumio[5322]: verbose: CURRENT POSITION 1 Apr 16 14:03:57 primo volumio[5322]: info: CoreStateMachine::syncState stateService stop Apr 16 14:03:57 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus stop Apr 16 14:03:57 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:57 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:57 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:57 primo volumio[5322]: info: No code Apr 16 14:03:57 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:57 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:57 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:57 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:03:57 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:03:57 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:57 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:57 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:57 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:57 primo volumio[5322]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Babylon by Bus-02.flac","artist":null,"album":null,"uri":"USB/SSDSumsung/LossLessMusic/Babylon by Bus/Babylon by Bus-02.flac","trackType":"flac"} Apr 16 14:03:57 primo volumio[5322]: verbose: CURRENT POSITION 1 Apr 16 14:03:57 primo volumio[5322]: info: CoreStateMachine::syncState stateService stop Apr 16 14:03:57 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus stop Apr 16 14:03:57 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:57 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:57 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:57 primo volumio[5322]: info: No code Apr 16 14:03:57 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:03:57 primo volumio[5322]: info: CorePlayQueue::getTrack 1 Apr 16 14:03:57 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:03:57 primo volumio[5322]: info: ------------------------------ 226ms Apr 16 14:03:57 primo volumio[5322]: info: ------------------------------ 211ms Apr 16 14:03:57 primo volumio[5322]: info: ------------------------------ 209ms Apr 16 14:03:58 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:58 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:58 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:58 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:58 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:58 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:58 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:58 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:58 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:03:58 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:58 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:58 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:58 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:58 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:58 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:58 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:58 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:58 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:03:58 primo ntpd[5562]: Soliciting pool server 162.159.200.1 Apr 16 14:04:00 primo volumio[5322]: info: Preload queue cleared Apr 16 14:04:00 primo volumio[5322]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 16 14:04:00 primo volumio[5322]: info: CoreStateMachine::ClearQueue Apr 16 14:04:00 primo volumio[5322]: info: CoreStateMachine::stop Apr 16 14:04:00 primo volumio[5322]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 16 14:04:00 primo volumio[5322]: info: CorePlayQueue::clearPlayQueue Apr 16 14:04:00 primo volumio[5322]: info: CorePlayQueue::saveQueue Apr 16 14:04:00 primo volumio[5322]: info: CoreCommandRouter::volumioPushQueue Apr 16 14:04:00 primo volumio[5322]: info: CoreStateMachine::addQueueItems Apr 16 14:04:00 primo volumio[5322]: info: CorePlayQueue::addQueueItems Apr 16 14:04:00 primo volumio[5322]: info: Preload queue cleared Apr 16 14:04:00 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/A1. Ex-Girlfriend.flac Apr 16 14:04:00 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/A1. Ex-Girlfriend.flac Apr 16 14:04:00 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/A2. Simple Kind of Life.flac Apr 16 14:04:00 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/A2. Simple Kind of Life.flac Apr 16 14:04:00 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/A3. Bathwater.flac Apr 16 14:04:00 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/A3. Bathwater.flac Apr 16 14:04:00 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/A4. Six Feet Under.flac Apr 16 14:04:00 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/A4. Six Feet Under.flac Apr 16 14:04:00 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/B1. Magic's in the Makeup.flac Apr 16 14:04:00 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/B1. Magic's in the Makeup.flac Apr 16 14:04:00 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/B2. Artificial Sweetener.flac Apr 16 14:04:00 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/B2. Artificial Sweetener.flac Apr 16 14:04:00 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/B3. Marry Me.flac Apr 16 14:04:00 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/B3. Marry Me.flac Apr 16 14:04:00 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/C1. New.flac Apr 16 14:04:00 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/C1. New.flac Apr 16 14:04:00 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/C2. Too Late.flac Apr 16 14:04:00 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/C2. Too Late.flac Apr 16 14:04:00 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/C3. Comforting Lie.flac Apr 16 14:04:00 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/C3. Comforting Lie.flac Apr 16 14:04:00 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/C4. Suspension Without Suspense.flac Apr 16 14:04:00 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/C4. Suspension Without Suspense.flac Apr 16 14:04:00 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/D1. Staring Problem.flac Apr 16 14:04:00 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/D1. Staring Problem.flac Apr 16 14:04:00 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/D2. Home Now.flac Apr 16 14:04:00 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/D2. Home Now.flac Apr 16 14:04:00 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/D3. Dark Blue.flac Apr 16 14:04:00 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/D3. Dark Blue.flac Apr 16 14:04:00 primo volumio[5322]: info: CoreCommandRouter::volumioPushQueue Apr 16 14:04:00 primo volumio[5322]: info: CorePlayQueue::saveQueue Apr 16 14:04:00 primo volumio[5322]: info: CoreStateMachine::updateTrackBlock Apr 16 14:04:00 primo volumio[5322]: info: CorePlayQueue::getTrackBlock Apr 16 14:04:00 primo volumio[5322]: info: CoreCommandRouter::volumioPlay Apr 16 14:04:00 primo volumio[5322]: info: CoreStateMachine::play index 0 Apr 16 14:04:00 primo volumio[5322]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 16 14:04:00 primo volumio[5322]: info: CoreStateMachine::stop Apr 16 14:04:00 primo volumio[5322]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 16 14:04:00 primo volumio[5322]: info: CoreStateMachine::play index undefined Apr 16 14:04:00 primo volumio[5322]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 16 14:04:00 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:00 primo volumio[5322]: info: CoreStateMachine::startPlaybackTimer Apr 16 14:04:00 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:00 primo volumio[5322]: verbose: ControllerMpd::clearAddPlayTracks USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/A1. Ex-Girlfriend.flac Apr 16 14:04:00 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand stop Apr 16 14:04:00 primo volumio[5322]: info: sendMpdCommand stop took 6 milliseconds Apr 16 14:04:00 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand clear Apr 16 14:04:00 primo volumio[5322]: info: Apr 16 14:04:00 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:04:00 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:04:00 primo volumio[5322]: info: sendMpdCommand clear took 4 milliseconds Apr 16 14:04:00 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand add "USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/A1. Ex-Girlfriend.flac" Apr 16 14:04:00 primo volumio[5322]: info: Apr 16 14:04:00 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:04:00 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:04:00 primo volumio[5322]: info: Apr 16 14:04:00 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:04:00 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:04:00 primo volumio[5322]: error: updateQueue error: null Apr 16 14:04:00 primo volumio[5322]: info: Apr 16 14:04:00 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:04:00 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:04:00 primo volumio[5322]: info: ------------------------------ 7ms Apr 16 14:04:00 primo volumio[5322]: info: sendMpdCommand add "USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/A1. Ex-Girlfriend.flac" took 6 milliseconds Apr 16 14:04:00 primo volumio[5322]: info: ------------------------------ 6ms Apr 16 14:04:00 primo volumio[5322]: info: ------------------------------ 4ms Apr 16 14:04:00 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand play Apr 16 14:04:00 primo volumio[5322]: info: Apr 16 14:04:00 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:04:00 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:04:00 primo volumio[5322]: info: Apr 16 14:04:00 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:04:00 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:04:00 primo kernel: aml_tdm_open Apr 16 14:04:00 primo kernel: Not init audio effects Apr 16 14:04:00 primo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:tdm@1 Apr 16 14:04:00 primo volumio[5322]: info: Apr 16 14:04:00 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:04:00 primo volumio[5322]: info: ------------------------------ 13ms Apr 16 14:04:00 primo volumio[5322]: info: sendMpdCommand play took 11 milliseconds Apr 16 14:04:00 primo volumio[5322]: info: ------------------------------ 11ms Apr 16 14:04:00 primo volumio[5322]: info: ------------------------------ 9ms Apr 16 14:04:00 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:04:00 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:04:00 primo volumio[5322]: info: Apr 16 14:04:00 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:04:00 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:04:00 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:04:00 primo volumio[5322]: info: Apr 16 14:04:00 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:04:00 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:04:00 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:04:01 primo kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk Apr 16 14:04:01 primo kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk Apr 16 14:04:01 primo kernel: set mclk:49152000, mpll:98304000, get mclk:49151901, mpll:98303801 Apr 16 14:04:01 primo kernel: asoc aml_dai_set_tdm_fmt, 0x4001, ffffffc050950018, id(1), clksel(1) Apr 16 14:04:01 primo kernel: aml_dai_set_tdm_fmt(), fmt not change Apr 16 14:04:01 primo kernel: dump_pcm_setting(ffffffc050950018) Apr 16 14:04:01 primo kernel: pcm_mode(1) Apr 16 14:04:01 primo kernel: sysclk(49152000) Apr 16 14:04:01 primo kernel: sysclk_bclk_ratio(4) Apr 16 14:04:01 primo kernel: bclk(12288000) Apr 16 14:04:01 primo kernel: bclk_lrclk_ratio(64) Apr 16 14:04:01 primo kernel: lrclk(192000) Apr 16 14:04:01 primo kernel: tx_mask(0x3) Apr 16 14:04:01 primo kernel: rx_mask(0x3) Apr 16 14:04:01 primo kernel: slots(2) Apr 16 14:04:01 primo kernel: slot_width(32) Apr 16 14:04:01 primo kernel: lane_mask_in(0x2) Apr 16 14:04:01 primo kernel: lane_mask_out(0x1) Apr 16 14:04:01 primo kernel: lane_oe_mask_in(0x0) Apr 16 14:04:01 primo kernel: lane_oe_mask_out(0x0) Apr 16 14:04:01 primo kernel: lane_lb_mask_in(0x0) Apr 16 14:04:01 primo kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk Apr 16 14:04:01 primo kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk Apr 16 14:04:01 primo kernel: set mclk:49152000, mpll:98304000, get mclk:49151901, mpll:98303801 Apr 16 14:04:01 primo kernel: aml_dai_set_clkdiv, div 4, clksel(1) Apr 16 14:04:01 primo kernel: aml_dai_set_bclk_ratio, select I2S mode Apr 16 14:04:01 primo kernel: aml_dai_tdm_hw_params(), enable mclk for TDM-B Apr 16 14:04:01 primo kernel: aml_tdm_prepare(), reset fddr Apr 16 14:04:01 primo kernel: spdif_a fifo ctrl, frddr:0 type:3, 32 bits, chmask 0x3, swap 0x10 Apr 16 14:04:01 primo kernel: spdif_info: rate: 192000, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0xe00, ch1_r:0xe00 Apr 16 14:04:01 primo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 Apr 16 14:04:01 primo kernel: tdm playback mute: 0, lane_cnt = 8 Apr 16 14:04:01 primo volumio[5322]: info: Apr 16 14:04:01 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:04:01 primo volumio[5322]: info: sendMpdCommand status took 505 milliseconds Apr 16 14:04:01 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:04:01 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:04:01 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:04:01 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 14:04:01 primo volumio[5322]: info: Apr 16 14:04:01 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:04:01 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:04:01 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:04:01 primo volumio[5322]: info: Apr 16 14:04:01 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:04:01 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:04:01 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:04:01 primo volumio[5322]: info: sendMpdCommand status took 524 milliseconds Apr 16 14:04:01 primo volumio[5322]: info: sendMpdCommand status took 522 milliseconds Apr 16 14:04:01 primo volumio[5322]: info: sendMpdCommand status took 21 milliseconds Apr 16 14:04:01 primo volumio[5322]: info: sendMpdCommand playlistinfo took 21 milliseconds Apr 16 14:04:01 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:04:01 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 14:04:01 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:04:01 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 14:04:01 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:04:01 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 14:04:01 primo volumio[5322]: verbose: ControllerMpd::parseTrackInfo Apr 16 14:04:01 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:04:01 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:04:01 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:01 primo volumio[5322]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":212,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Ex-Girlfriend","artist":"No Doubt","album":"Return Of Saturn","uri":"USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/A1. Ex-Girlfriend.flac","trackType":"flac"} Apr 16 14:04:01 primo volumio[5322]: verbose: CURRENT POSITION 0 Apr 16 14:04:01 primo volumio[5322]: info: CoreStateMachine::syncState stateService play Apr 16 14:04:01 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus stop Apr 16 14:04:01 primo volumio[5322]: info: ------------------------------ 536ms Apr 16 14:04:01 primo volumio[5322]: info: sendMpdCommand status took 12 milliseconds Apr 16 14:04:01 primo volumio[5322]: info: sendMpdCommand status took 10 milliseconds Apr 16 14:04:01 primo volumio[5322]: info: sendMpdCommand playlistinfo took 7 milliseconds Apr 16 14:04:01 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:04:01 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 14:04:01 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:04:01 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 14:04:01 primo volumio[5322]: verbose: ControllerMpd::parseTrackInfo Apr 16 14:04:01 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:04:01 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:04:01 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:01 primo volumio[5322]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":212,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Ex-Girlfriend","artist":"No Doubt","album":"Return Of Saturn","uri":"USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/A1. Ex-Girlfriend.flac","trackType":"flac"} Apr 16 14:04:01 primo volumio[5322]: verbose: CURRENT POSITION 0 Apr 16 14:04:01 primo volumio[5322]: info: CoreStateMachine::syncState stateService play Apr 16 14:04:01 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus play Apr 16 14:04:01 primo volumio[5322]: info: Received an update from plugin. extracting info from payload Apr 16 14:04:01 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:01 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:01 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 16 14:04:01 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:01 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:01 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:01 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:01 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:04:01 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:04:01 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:01 primo volumio[5322]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":212,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Ex-Girlfriend","artist":"No Doubt","album":"Return Of Saturn","uri":"USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/A1. Ex-Girlfriend.flac","trackType":"flac"} Apr 16 14:04:01 primo volumio[5322]: verbose: CURRENT POSITION 0 Apr 16 14:04:01 primo volumio[5322]: info: CoreStateMachine::syncState stateService play Apr 16 14:04:01 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus play Apr 16 14:04:01 primo volumio[5322]: info: Received an update from plugin. extracting info from payload Apr 16 14:04:01 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:01 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:01 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:01 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:01 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:01 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:01 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:04:01 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:04:01 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:01 primo volumio[5322]: verbose: STATE SERVICE {"status":"play","position":0,"seek":5,"duration":212,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"2813 Kbps","isStreaming":false,"title":"Ex-Girlfriend","artist":"No Doubt","album":"Return Of Saturn","uri":"USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/A1. Ex-Girlfriend.flac","trackType":"flac"} Apr 16 14:04:01 primo volumio[5322]: verbose: CURRENT POSITION 0 Apr 16 14:04:01 primo volumio[5322]: info: CoreStateMachine::syncState stateService play Apr 16 14:04:01 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus play Apr 16 14:04:01 primo volumio[5322]: info: Received an update from plugin. extracting info from payload Apr 16 14:04:01 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:01 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:01 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 16 14:04:01 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:01 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:01 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:01 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:01 primo volumio[5322]: info: ------------------------------ 597ms Apr 16 14:04:01 primo volumio[5322]: info: ------------------------------ 601ms Apr 16 14:04:01 primo volumio[5322]: info: ------------------------------ 102ms Apr 16 14:04:01 primo volumio[5322]: info: sendMpdCommand playlistinfo took 70 milliseconds Apr 16 14:04:01 primo volumio[5322]: info: sendMpdCommand playlistinfo took 70 milliseconds Apr 16 14:04:01 primo volumio[5322]: verbose: ControllerMpd::parseTrackInfo Apr 16 14:04:01 primo volumio[5322]: verbose: ControllerMpd::parseTrackInfo Apr 16 14:04:01 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:04:01 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:04:01 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:01 primo volumio[5322]: verbose: STATE SERVICE {"status":"play","position":0,"seek":5,"duration":212,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"2813 Kbps","isStreaming":false,"title":"Ex-Girlfriend","artist":"No Doubt","album":"Return Of Saturn","uri":"USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/A1. Ex-Girlfriend.flac","trackType":"flac"} Apr 16 14:04:01 primo volumio[5322]: verbose: CURRENT POSITION 0 Apr 16 14:04:01 primo volumio[5322]: info: CoreStateMachine::syncState stateService play Apr 16 14:04:01 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus play Apr 16 14:04:01 primo volumio[5322]: info: Received an update from plugin. extracting info from payload Apr 16 14:04:01 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:01 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:01 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:01 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:01 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:01 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:01 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:04:01 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:04:01 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:01 primo volumio[5322]: verbose: STATE SERVICE {"status":"play","position":0,"seek":5,"duration":212,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"2813 Kbps","isStreaming":false,"title":"Ex-Girlfriend","artist":"No Doubt","album":"Return Of Saturn","uri":"USB/SSDSumsung/LossLessMusic/No Doubt/2000 - No Doubt - Return Of Saturn [Vinyl Rip]/A1. Ex-Girlfriend.flac","trackType":"flac"} Apr 16 14:04:01 primo volumio[5322]: verbose: CURRENT POSITION 0 Apr 16 14:04:01 primo volumio[5322]: info: CoreStateMachine::syncState stateService play Apr 16 14:04:01 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus play Apr 16 14:04:01 primo volumio[5322]: info: Received an update from plugin. extracting info from payload Apr 16 14:04:01 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:01 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:01 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:01 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:01 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:01 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:01 primo volumio[5322]: info: ------------------------------ 118ms Apr 16 14:04:01 primo volumio[5322]: info: ------------------------------ 118ms Apr 16 14:04:01 primo volumio[5322]: info: Signalling Playback active due to playback status change Apr 16 14:04:01 primo volumio[5322]: info: Signalling Playback active due to playback status change Apr 16 14:04:01 primo volumio[5322]: info: Signalling Playback active due to playback status change Apr 16 14:04:01 primo volumio[5322]: info: Signalling Playback active due to playback status change Apr 16 14:04:01 primo volumio[5322]: info: Signalling Playback active due to playback status change Apr 16 14:04:01 primo volumio[5322]: info: Signalling Playback active due to playback status change Apr 16 14:04:01 primo volumio[5322]: info: Signalling Playback active due to playback status change Apr 16 14:04:01 primo kernel: asoc-aml-card auge_sound: tdm playback enable Apr 16 14:04:01 primo kernel: spdif_a is set to enable Apr 16 14:04:01 primo volumio[5322]: info: Signalling Playback active due to playback status change Apr 16 14:04:01 primo volumio[5322]: info: Signalling Playback active due to playback status change Apr 16 14:04:01 primo volumio[5322]: info: Signalling Playback active due to playback status change Apr 16 14:04:01 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:04:01 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:04:01 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:04:01 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:04:01 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:04:01 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:04:01 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:04:01 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:04:01 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:04:01 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:04:01 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:04:01 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:04:01 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:04:01 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:04:01 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:04:01 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:04:01 primo volumio[5322]: info: MCU Signalled Playback Active Apr 16 14:04:07 primo ntpd[5562]: Soliciting pool server 162.159.200.123 Apr 16 14:04:07 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 16 14:04:07 primo volumio[5322]: info: CURURI: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip] Apr 16 14:04:08 primo volumio[5322]: info: Preload queue cleared Apr 16 14:04:08 primo volumio[5322]: info: Preloading song: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A1. Intro.flac Apr 16 14:04:08 primo volumio[5322]: info: Preloading song: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A2. Hella Good.flac Apr 16 14:04:08 primo volumio[5322]: info: Preloading song: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A3. Hey Baby.flac Apr 16 14:04:08 primo volumio[5322]: info: Preloading song: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A4. Making Out.flac Apr 16 14:04:08 primo volumio[5322]: info: Preloading song: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/B1. Underneath It All.flac Apr 16 14:04:08 primo volumio[5322]: info: Preloading song: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/B2. Detective.flac Apr 16 14:04:08 primo volumio[5322]: info: Preloading song: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/B3. Don't Let Me Down.flac Apr 16 14:04:08 primo volumio[5322]: info: Preloading song: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/C1. Start the Fire.flac Apr 16 14:04:08 primo volumio[5322]: info: Preloading song: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/C2. Running.flac Apr 16 14:04:08 primo volumio[5322]: info: Preloading song: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/C3. In My Head.flac Apr 16 14:04:08 primo volumio[5322]: info: Preloading song: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/D1. Platinum Blonde Life.flac Apr 16 14:04:08 primo volumio[5322]: info: Preloading song: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/D2. Waiting Room.flac Apr 16 14:04:08 primo volumio[5322]: info: Preloading song: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/D3. Rock Steady.flac Apr 16 14:04:08 primo volumio[5322]: info: Exploding uri music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A1. Intro.flac in service mpd Apr 16 14:04:08 primo volumio[5322]: info: ALBUMART /albumart?cacheid=615&web=No%20Doubt/Rock%20Steady/extralarge&path=%2Fmnt%2FUSB%2FSSDSumsung%2FLossLessMusic%2FNo%20Doubt%2F2001%20-%20Rock%20Steady%20%5BVinyl%20Rip%5D%2FA1.%20Intro.flac&metadata=false Apr 16 14:04:08 primo volumio[5322]: info: URI /mnt/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A1. Intro.flac Apr 16 14:04:08 primo volumio[5322]: info: Exploding uri music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A2. Hella Good.flac in service mpd Apr 16 14:04:08 primo volumio[5322]: info: ALBUMART /albumart?cacheid=615&web=No%20Doubt/Rock%20Steady/extralarge&path=%2Fmnt%2FUSB%2FSSDSumsung%2FLossLessMusic%2FNo%20Doubt%2F2001%20-%20Rock%20Steady%20%5BVinyl%20Rip%5D%2FA2.%20Hella%20Good.flac&metadata=false Apr 16 14:04:08 primo volumio[5322]: info: URI /mnt/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A2. Hella Good.flac Apr 16 14:04:08 primo volumio[5322]: info: Exploding uri music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A3. Hey Baby.flac in service mpd Apr 16 14:04:08 primo volumio[5322]: info: ALBUMART /albumart?cacheid=615&web=No%20Doubt/Rock%20Steady/extralarge&path=%2Fmnt%2FUSB%2FSSDSumsung%2FLossLessMusic%2FNo%20Doubt%2F2001%20-%20Rock%20Steady%20%5BVinyl%20Rip%5D%2FA3.%20Hey%20Baby.flac&metadata=false Apr 16 14:04:08 primo volumio[5322]: info: URI /mnt/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A3. Hey Baby.flac Apr 16 14:04:08 primo volumio[5322]: info: Exploding uri music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A4. Making Out.flac in service mpd Apr 16 14:04:08 primo volumio[5322]: info: ALBUMART /albumart?cacheid=615&web=No%20Doubt/Rock%20Steady/extralarge&path=%2Fmnt%2FUSB%2FSSDSumsung%2FLossLessMusic%2FNo%20Doubt%2F2001%20-%20Rock%20Steady%20%5BVinyl%20Rip%5D%2FA4.%20Making%20Out.flac&metadata=false Apr 16 14:04:08 primo volumio[5322]: info: URI /mnt/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A4. Making Out.flac Apr 16 14:04:08 primo volumio[5322]: info: Exploding uri music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/B1. Underneath It All.flac in service mpd Apr 16 14:04:08 primo volumio[5322]: info: ALBUMART /albumart?cacheid=615&web=No%20Doubt/Rock%20Steady/extralarge&path=%2Fmnt%2FUSB%2FSSDSumsung%2FLossLessMusic%2FNo%20Doubt%2F2001%20-%20Rock%20Steady%20%5BVinyl%20Rip%5D%2FB1.%20Underneath%20It%20All.flac&metadata=false Apr 16 14:04:08 primo volumio[5322]: info: URI /mnt/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/B1. Underneath It All.flac Apr 16 14:04:08 primo volumio[5322]: info: Exploding uri music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/B2. Detective.flac in service mpd Apr 16 14:04:08 primo volumio[5322]: info: ALBUMART /albumart?cacheid=615&web=No%20Doubt/Rock%20Steady/extralarge&path=%2Fmnt%2FUSB%2FSSDSumsung%2FLossLessMusic%2FNo%20Doubt%2F2001%20-%20Rock%20Steady%20%5BVinyl%20Rip%5D%2FB2.%20Detective.flac&metadata=false Apr 16 14:04:08 primo volumio[5322]: info: URI /mnt/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/B2. Detective.flac Apr 16 14:04:08 primo volumio[5322]: info: Exploding uri music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/B3. Don't Let Me Down.flac in service mpd Apr 16 14:04:08 primo volumio[5322]: info: ALBUMART /albumart?cacheid=615&web=No%20Doubt/Rock%20Steady/extralarge&path=%2Fmnt%2FUSB%2FSSDSumsung%2FLossLessMusic%2FNo%20Doubt%2F2001%20-%20Rock%20Steady%20%5BVinyl%20Rip%5D%2FB3.%20Don't%20Let%20Me%20Down.flac&metadata=false Apr 16 14:04:08 primo volumio[5322]: info: URI /mnt/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/B3. Don't Let Me Down.flac Apr 16 14:04:08 primo volumio[5322]: info: Exploding uri music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/C1. Start the Fire.flac in service mpd Apr 16 14:04:08 primo volumio[5322]: info: ALBUMART /albumart?cacheid=615&web=No%20Doubt/Rock%20Steady/extralarge&path=%2Fmnt%2FUSB%2FSSDSumsung%2FLossLessMusic%2FNo%20Doubt%2F2001%20-%20Rock%20Steady%20%5BVinyl%20Rip%5D%2FC1.%20Start%20the%20Fire.flac&metadata=false Apr 16 14:04:08 primo volumio[5322]: info: URI /mnt/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/C1. Start the Fire.flac Apr 16 14:04:08 primo volumio[5322]: info: Exploding uri music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/C2. Running.flac in service mpd Apr 16 14:04:08 primo volumio[5322]: info: ALBUMART /albumart?cacheid=615&web=No%20Doubt/Rock%20Steady/extralarge&path=%2Fmnt%2FUSB%2FSSDSumsung%2FLossLessMusic%2FNo%20Doubt%2F2001%20-%20Rock%20Steady%20%5BVinyl%20Rip%5D%2FC2.%20Running.flac&metadata=false Apr 16 14:04:08 primo volumio[5322]: info: URI /mnt/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/C2. Running.flac Apr 16 14:04:08 primo volumio[5322]: info: Exploding uri music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/C3. In My Head.flac in service mpd Apr 16 14:04:08 primo volumio[5322]: info: ALBUMART /albumart?cacheid=615&web=No%20Doubt/Rock%20Steady/extralarge&path=%2Fmnt%2FUSB%2FSSDSumsung%2FLossLessMusic%2FNo%20Doubt%2F2001%20-%20Rock%20Steady%20%5BVinyl%20Rip%5D%2FC3.%20In%20My%20Head.flac&metadata=false Apr 16 14:04:08 primo volumio[5322]: info: URI /mnt/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/C3. In My Head.flac Apr 16 14:04:08 primo volumio[5322]: info: Exploding uri music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/D1. Platinum Blonde Life.flac in service mpd Apr 16 14:04:08 primo volumio[5322]: info: ALBUMART /albumart?cacheid=615&web=No%20Doubt/Rock%20Steady/extralarge&path=%2Fmnt%2FUSB%2FSSDSumsung%2FLossLessMusic%2FNo%20Doubt%2F2001%20-%20Rock%20Steady%20%5BVinyl%20Rip%5D%2FD1.%20Platinum%20Blonde%20Life.flac&metadata=false Apr 16 14:04:08 primo volumio[5322]: info: URI /mnt/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/D1. Platinum Blonde Life.flac Apr 16 14:04:08 primo volumio[5322]: info: Exploding uri music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/D2. Waiting Room.flac in service mpd Apr 16 14:04:08 primo volumio[5322]: info: ALBUMART /albumart?cacheid=615&web=No%20Doubt/Rock%20Steady/extralarge&path=%2Fmnt%2FUSB%2FSSDSumsung%2FLossLessMusic%2FNo%20Doubt%2F2001%20-%20Rock%20Steady%20%5BVinyl%20Rip%5D%2FD2.%20Waiting%20Room.flac&metadata=false Apr 16 14:04:08 primo volumio[5322]: info: URI /mnt/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/D2. Waiting Room.flac Apr 16 14:04:08 primo volumio[5322]: info: Exploding uri music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/D3. Rock Steady.flac in service mpd Apr 16 14:04:08 primo volumio[5322]: info: ALBUMART /albumart?cacheid=615&web=No%20Doubt/Rock%20Steady/extralarge&path=%2Fmnt%2FUSB%2FSSDSumsung%2FLossLessMusic%2FNo%20Doubt%2F2001%20-%20Rock%20Steady%20%5BVinyl%20Rip%5D%2FD3.%20Rock%20Steady.flac&metadata=false Apr 16 14:04:08 primo volumio[5322]: info: URI /mnt/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/D3. Rock Steady.flac Apr 16 14:04:10 primo volumio[5322]: info: Preload queue cleared Apr 16 14:04:10 primo volumio[5322]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 16 14:04:10 primo volumio[5322]: info: CoreStateMachine::ClearQueue Apr 16 14:04:10 primo volumio[5322]: info: CoreStateMachine::stop Apr 16 14:04:10 primo volumio[5322]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 16 14:04:10 primo volumio[5322]: info: CoreStateMachine::stPlaybackTimer Apr 16 14:04:10 primo volumio[5322]: info: CoreStateMachine::updateTrackBlock Apr 16 14:04:10 primo volumio[5322]: info: CorePlayQueue::getTrackBlock Apr 16 14:04:10 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:10 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:10 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 16 14:04:10 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:10 primo volumio[5322]: info: CoreStateMachine::serviceStop Apr 16 14:04:10 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:10 primo volumio[5322]: info: CoreCommandRouter::serviceStop Apr 16 14:04:10 primo volumio[5322]: info: ControllerMpd::stop Apr 16 14:04:10 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand stop Apr 16 14:04:10 primo volumio[5322]: info: CorePlayQueue::clearPlayQueue Apr 16 14:04:10 primo volumio[5322]: info: CorePlayQueue::saveQueue Apr 16 14:04:10 primo volumio[5322]: info: CoreCommandRouter::volumioPushQueue Apr 16 14:04:10 primo volumio[5322]: info: CoreStateMachine::addQueueItems Apr 16 14:04:10 primo volumio[5322]: info: CorePlayQueue::addQueueItems Apr 16 14:04:10 primo volumio[5322]: info: Preload queue cleared Apr 16 14:04:10 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A1. Intro.flac Apr 16 14:04:10 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A1. Intro.flac Apr 16 14:04:10 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A2. Hella Good.flac Apr 16 14:04:10 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A2. Hella Good.flac Apr 16 14:04:10 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A3. Hey Baby.flac Apr 16 14:04:10 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A3. Hey Baby.flac Apr 16 14:04:10 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A4. Making Out.flac Apr 16 14:04:10 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A4. Making Out.flac Apr 16 14:04:10 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/B1. Underneath It All.flac Apr 16 14:04:10 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/B1. Underneath It All.flac Apr 16 14:04:10 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/B2. Detective.flac Apr 16 14:04:10 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/B2. Detective.flac Apr 16 14:04:10 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/B3. Don't Let Me Down.flac Apr 16 14:04:10 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/B3. Don't Let Me Down.flac Apr 16 14:04:10 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/C1. Start the Fire.flac Apr 16 14:04:10 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/C1. Start the Fire.flac Apr 16 14:04:10 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/C2. Running.flac Apr 16 14:04:10 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/C2. Running.flac Apr 16 14:04:10 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/C3. In My Head.flac Apr 16 14:04:10 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/C3. In My Head.flac Apr 16 14:04:10 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/D1. Platinum Blonde Life.flac Apr 16 14:04:10 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/D1. Platinum Blonde Life.flac Apr 16 14:04:10 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/D2. Waiting Room.flac Apr 16 14:04:10 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/D2. Waiting Room.flac Apr 16 14:04:10 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/D3. Rock Steady.flac Apr 16 14:04:10 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/D3. Rock Steady.flac Apr 16 14:04:10 primo volumio[5322]: info: CoreCommandRouter::volumioPushQueue Apr 16 14:04:10 primo volumio[5322]: info: CorePlayQueue::saveQueue Apr 16 14:04:10 primo volumio[5322]: info: CoreStateMachine::updateTrackBlock Apr 16 14:04:10 primo volumio[5322]: info: CorePlayQueue::getTrackBlock Apr 16 14:04:10 primo volumio[5322]: info: CoreCommandRouter::volumioPlay Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::play index 0 Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::stop Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::play index undefined Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 16 14:04:11 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::startPlaybackTimer Apr 16 14:04:11 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:11 primo volumio[5322]: verbose: ControllerMpd::clearAddPlayTracks USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A1. Intro.flac Apr 16 14:04:11 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand stop Apr 16 14:04:11 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:04:11 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:04:11 primo kernel: asoc-aml-card auge_sound: tdm playback stop Apr 16 14:04:11 primo kernel: spdif_a is set to disable Apr 16 14:04:11 primo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 Apr 16 14:04:11 primo kernel: aml_dai_tdm_hw_free(), disable mclk for TDM-B Apr 16 14:04:11 primo kernel: tdm playback mute: 1, lane_cnt = 8 Apr 16 14:04:11 primo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:tdm@1 Apr 16 14:04:11 primo volumio[5322]: info: Apr 16 14:04:11 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:04:11 primo volumio[5322]: info: sendMpdCommand stop took 67 milliseconds Apr 16 14:04:11 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:04:11 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:04:11 primo volumio[5322]: info: sendMpdCommand stop took 33 milliseconds Apr 16 14:04:11 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand clear Apr 16 14:04:11 primo volumio[5322]: info: Apr 16 14:04:11 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:04:11 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:04:11 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:04:11 primo volumio[5322]: info: Apr 16 14:04:11 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:04:11 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:04:11 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:04:11 primo volumio[5322]: info: Apr 16 14:04:11 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:04:11 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:04:11 primo volumio[5322]: info: sendMpdCommand status took 10 milliseconds Apr 16 14:04:11 primo volumio[5322]: info: sendMpdCommand clear took 8 milliseconds Apr 16 14:04:11 primo volumio[5322]: info: sendMpdCommand status took 7 milliseconds Apr 16 14:04:11 primo volumio[5322]: info: sendMpdCommand status took 6 milliseconds Apr 16 14:04:11 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:04:11 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 14:04:11 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand add "USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A1. Intro.flac" Apr 16 14:04:11 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:04:11 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:04:11 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:04:11 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:11 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:11 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 16 14:04:11 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:11 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:11 primo volumio[5322]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 16 14:04:11 primo volumio[5322]: verbose: CURRENT POSITION 0 Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::syncState stateService stop Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus stop Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:11 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:11 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:11 primo volumio[5322]: info: No code Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:11 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:11 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:11 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:04:11 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:11 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:11 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:11 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:11 primo volumio[5322]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 16 14:04:11 primo volumio[5322]: verbose: CURRENT POSITION 0 Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::syncState stateService stop Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus stop Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:11 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:11 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:11 primo volumio[5322]: info: No code Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:11 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:11 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:11 primo volumio[5322]: info: ------------------------------ 53ms Apr 16 14:04:11 primo volumio[5322]: info: ------------------------------ 52ms Apr 16 14:04:11 primo volumio[5322]: info: Apr 16 14:04:11 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:04:11 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:04:11 primo volumio[5322]: info: Apr 16 14:04:11 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:04:11 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:04:11 primo volumio[5322]: error: updateQueue error: null Apr 16 14:04:11 primo volumio[5322]: info: Apr 16 14:04:11 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:04:11 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:04:11 primo volumio[5322]: info: ------------------------------ 55ms Apr 16 14:04:11 primo volumio[5322]: info: sendMpdCommand playlistinfo took 53 milliseconds Apr 16 14:04:11 primo volumio[5322]: info: sendMpdCommand add "USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A1. Intro.flac" took 53 milliseconds Apr 16 14:04:11 primo volumio[5322]: info: ------------------------------ 7ms Apr 16 14:04:11 primo volumio[5322]: info: ------------------------------ 6ms Apr 16 14:04:11 primo volumio[5322]: verbose: ControllerMpd::parseTrackInfo Apr 16 14:04:11 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand play Apr 16 14:04:11 primo volumio[5322]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 16 14:04:11 primo volumio[5322]: info: ------------------------------ 72ms Apr 16 14:04:11 primo volumio[5322]: info: Apr 16 14:04:11 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:04:11 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:04:11 primo volumio[5322]: info: Apr 16 14:04:11 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:04:11 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:04:11 primo kernel: aml_tdm_open Apr 16 14:04:11 primo kernel: Not init audio effects Apr 16 14:04:11 primo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:tdm@1 Apr 16 14:04:11 primo kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk Apr 16 14:04:11 primo kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk Apr 16 14:04:11 primo kernel: set mclk:49152000, mpll:98304000, get mclk:49151901, mpll:98303801 Apr 16 14:04:11 primo kernel: asoc aml_dai_set_tdm_fmt, 0x4001, ffffffc050950018, id(1), clksel(1) Apr 16 14:04:11 primo kernel: aml_dai_set_tdm_fmt(), fmt not change Apr 16 14:04:11 primo kernel: dump_pcm_setting(ffffffc050950018) Apr 16 14:04:11 primo kernel: pcm_mode(1) Apr 16 14:04:11 primo kernel: sysclk(49152000) Apr 16 14:04:11 primo kernel: sysclk_bclk_ratio(4) Apr 16 14:04:11 primo kernel: bclk(12288000) Apr 16 14:04:11 primo kernel: bclk_lrclk_ratio(64) Apr 16 14:04:11 primo kernel: lrclk(192000) Apr 16 14:04:11 primo kernel: tx_mask(0x3) Apr 16 14:04:11 primo kernel: rx_mask(0x3) Apr 16 14:04:11 primo kernel: slots(2) Apr 16 14:04:11 primo kernel: slot_width(32) Apr 16 14:04:11 primo kernel: lane_mask_in(0x2) Apr 16 14:04:11 primo kernel: lane_mask_out(0x1) Apr 16 14:04:11 primo kernel: lane_oe_mask_in(0x0) Apr 16 14:04:11 primo kernel: lane_oe_mask_out(0x0) Apr 16 14:04:11 primo kernel: lane_lb_mask_in(0x0) Apr 16 14:04:11 primo kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk Apr 16 14:04:11 primo kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk Apr 16 14:04:11 primo kernel: set mclk:49152000, mpll:98304000, get mclk:49151901, mpll:98303801 Apr 16 14:04:11 primo kernel: aml_dai_set_clkdiv, div 4, clksel(1) Apr 16 14:04:11 primo kernel: aml_dai_set_bclk_ratio, select I2S mode Apr 16 14:04:11 primo kernel: aml_dai_tdm_hw_params(), enable mclk for TDM-B Apr 16 14:04:11 primo kernel: aml_tdm_prepare(), reset fddr Apr 16 14:04:11 primo kernel: spdif_a fifo ctrl, frddr:0 type:3, 32 bits, chmask 0x3, swap 0x10 Apr 16 14:04:11 primo kernel: spdif_info: rate: 192000, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0xe00, ch1_r:0xe00 Apr 16 14:04:11 primo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 Apr 16 14:04:11 primo kernel: tdm playback mute: 0, lane_cnt = 8 Apr 16 14:04:11 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:04:11 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:04:11 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:04:11 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:04:11 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:04:11 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:04:11 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:04:11 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:04:11 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:04:11 primo volumio[5322]: info: MCU Signalled Playback Inactive Apr 16 14:04:11 primo volumio[5322]: info: Apr 16 14:04:11 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:04:11 primo volumio[5322]: info: ------------------------------ 75ms Apr 16 14:04:11 primo volumio[5322]: info: sendMpdCommand play took 69 milliseconds Apr 16 14:04:11 primo volumio[5322]: info: ------------------------------ 68ms Apr 16 14:04:11 primo volumio[5322]: info: ------------------------------ 66ms Apr 16 14:04:11 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:04:11 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:04:11 primo volumio[5322]: info: Apr 16 14:04:11 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:04:11 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:04:11 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:04:11 primo volumio[5322]: info: Apr 16 14:04:11 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:04:11 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:04:11 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:04:11 primo volumio[5322]: info: Apr 16 14:04:11 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:04:11 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:04:11 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:04:11 primo volumio[5322]: info: sendMpdCommand status took 16 milliseconds Apr 16 14:04:11 primo volumio[5322]: info: sendMpdCommand status took 15 milliseconds Apr 16 14:04:11 primo volumio[5322]: info: sendMpdCommand status took 13 milliseconds Apr 16 14:04:11 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:04:11 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 14:04:11 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:04:11 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 14:04:11 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:04:11 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 14:04:11 primo volumio[5322]: info: Apr 16 14:04:11 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:04:11 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:04:11 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:04:11 primo volumio[5322]: info: Apr 16 14:04:11 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:04:11 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:04:11 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:04:11 primo volumio[5322]: info: sendMpdCommand status took 14 milliseconds Apr 16 14:04:11 primo volumio[5322]: info: sendMpdCommand playlistinfo took 13 milliseconds Apr 16 14:04:11 primo volumio[5322]: info: sendMpdCommand playlistinfo took 13 milliseconds Apr 16 14:04:11 primo volumio[5322]: info: sendMpdCommand playlistinfo took 13 milliseconds Apr 16 14:04:11 primo volumio[5322]: info: sendMpdCommand status took 11 milliseconds Apr 16 14:04:11 primo volumio[5322]: info: sendMpdCommand status took 6 milliseconds Apr 16 14:04:11 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:04:11 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 14:04:11 primo volumio[5322]: verbose: ControllerMpd::parseTrackInfo Apr 16 14:04:11 primo volumio[5322]: verbose: ControllerMpd::parseTrackInfo Apr 16 14:04:11 primo volumio[5322]: verbose: ControllerMpd::parseTrackInfo Apr 16 14:04:11 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:04:11 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 14:04:11 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:04:11 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 14:04:11 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:04:11 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:04:11 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:11 primo volumio[5322]: verbose: STATE SERVICE {"status":"play","position":0,"seek":52,"duration":26,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"2612 Kbps","isStreaming":false,"title":"Intro","artist":"No Doubt","album":"Rock Steady","uri":"USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A1. Intro.flac","trackType":"flac"} Apr 16 14:04:11 primo volumio[5322]: verbose: CURRENT POSITION 0 Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::syncState stateService play Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus stop Apr 16 14:04:11 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:04:11 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:04:11 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:11 primo volumio[5322]: verbose: STATE SERVICE {"status":"play","position":0,"seek":52,"duration":26,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"2612 Kbps","isStreaming":false,"title":"Intro","artist":"No Doubt","album":"Rock Steady","uri":"USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A1. Intro.flac","trackType":"flac"} Apr 16 14:04:11 primo volumio[5322]: verbose: CURRENT POSITION 0 Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::syncState stateService play Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus play Apr 16 14:04:11 primo volumio[5322]: info: Received an update from plugin. extracting info from payload Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:11 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:11 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 16 14:04:11 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:11 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:11 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:11 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:04:11 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:04:11 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:11 primo volumio[5322]: verbose: STATE SERVICE {"status":"play","position":0,"seek":57,"duration":26,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"2612 Kbps","isStreaming":false,"title":"Intro","artist":"No Doubt","album":"Rock Steady","uri":"USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A1. Intro.flac","trackType":"flac"} Apr 16 14:04:11 primo volumio[5322]: verbose: CURRENT POSITION 0 Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::syncState stateService play Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus play Apr 16 14:04:11 primo volumio[5322]: info: Received an update from plugin. extracting info from payload Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:11 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:11 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 16 14:04:11 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:11 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:11 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:11 primo volumio[5322]: info: ------------------------------ 75ms Apr 16 14:04:11 primo volumio[5322]: info: ------------------------------ 90ms Apr 16 14:04:11 primo volumio[5322]: info: ------------------------------ 89ms Apr 16 14:04:11 primo volumio[5322]: info: sendMpdCommand playlistinfo took 67 milliseconds Apr 16 14:04:11 primo volumio[5322]: info: sendMpdCommand playlistinfo took 65 milliseconds Apr 16 14:04:11 primo volumio[5322]: info: sendMpdCommand playlistinfo took 63 milliseconds Apr 16 14:04:11 primo volumio[5322]: verbose: ControllerMpd::parseTrackInfo Apr 16 14:04:11 primo volumio[5322]: verbose: ControllerMpd::parseTrackInfo Apr 16 14:04:11 primo volumio[5322]: verbose: ControllerMpd::parseTrackInfo Apr 16 14:04:11 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:04:11 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:04:11 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:11 primo volumio[5322]: verbose: STATE SERVICE {"status":"play","position":0,"seek":68,"duration":26,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"2612 Kbps","isStreaming":false,"title":"Intro","artist":"No Doubt","album":"Rock Steady","uri":"USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A1. Intro.flac","trackType":"flac"} Apr 16 14:04:11 primo volumio[5322]: verbose: CURRENT POSITION 0 Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::syncState stateService play Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus play Apr 16 14:04:11 primo volumio[5322]: info: Received an update from plugin. extracting info from payload Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:11 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:11 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 16 14:04:11 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:11 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:11 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:11 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:04:11 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:04:11 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:11 primo volumio[5322]: verbose: STATE SERVICE {"status":"play","position":0,"seek":73,"duration":26,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"2612 Kbps","isStreaming":false,"title":"Intro","artist":"No Doubt","album":"Rock Steady","uri":"USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A1. Intro.flac","trackType":"flac"} Apr 16 14:04:11 primo volumio[5322]: verbose: CURRENT POSITION 0 Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::syncState stateService play Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus play Apr 16 14:04:11 primo volumio[5322]: info: Received an update from plugin. extracting info from payload Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:11 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:11 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 16 14:04:11 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:11 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:11 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:11 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:04:11 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:04:11 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:11 primo volumio[5322]: verbose: STATE SERVICE {"status":"play","position":0,"seek":78,"duration":26,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"2612 Kbps","isStreaming":false,"title":"Intro","artist":"No Doubt","album":"Rock Steady","uri":"USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A1. Intro.flac","trackType":"flac"} Apr 16 14:04:11 primo volumio[5322]: verbose: CURRENT POSITION 0 Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::syncState stateService play Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus play Apr 16 14:04:11 primo volumio[5322]: info: Received an update from plugin. extracting info from payload Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:11 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:11 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 16 14:04:11 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:11 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:11 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:11 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:11 primo kernel: asoc-aml-card auge_sound: tdm playback enable Apr 16 14:04:11 primo kernel: spdif_a is set to enable Apr 16 14:04:11 primo volumio[5322]: info: ------------------------------ 146ms Apr 16 14:04:11 primo volumio[5322]: info: ------------------------------ 140ms Apr 16 14:04:11 primo volumio[5322]: info: ------------------------------ 138ms Apr 16 14:04:11 primo volumio[5322]: info: Signalling Playback active due to playback status change Apr 16 14:04:11 primo volumio[5322]: info: Signalling Playback active due to playback status change Apr 16 14:04:11 primo volumio[5322]: info: Signalling Playback active due to playback status change Apr 16 14:04:11 primo volumio[5322]: info: Signalling Playback active due to playback status change Apr 16 14:04:11 primo volumio[5322]: info: Signalling Playback active due to playback status change Apr 16 14:04:11 primo volumio[5322]: info: Signalling Playback active due to playback status change Apr 16 14:04:11 primo volumio[5322]: info: Signalling Playback active due to playback status change Apr 16 14:04:11 primo volumio[5322]: info: Signalling Playback active due to playback status change Apr 16 14:04:11 primo volumio[5322]: info: Signalling Playback active due to playback status change Apr 16 14:04:11 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:04:11 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:04:11 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:04:11 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:04:11 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:04:11 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:04:11 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:04:11 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:04:11 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:04:11 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:04:11 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:04:11 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:04:11 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:04:11 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:04:11 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:04:11 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:04:11 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:04:11 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:04:11 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:04:11 primo volumio[5322]: info: MCU Signalled Playback Active Apr 16 14:04:12 primo volumio[5322]: info: Preload queue cleared Apr 16 14:04:12 primo volumio[5322]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 16 14:04:12 primo volumio[5322]: info: CoreStateMachine::ClearQueue Apr 16 14:04:12 primo volumio[5322]: info: CoreStateMachine::stop Apr 16 14:04:12 primo volumio[5322]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 16 14:04:12 primo volumio[5322]: info: CoreStateMachine::stPlaybackTimer Apr 16 14:04:12 primo volumio[5322]: info: CoreStateMachine::updateTrackBlock Apr 16 14:04:12 primo volumio[5322]: info: CorePlayQueue::getTrackBlock Apr 16 14:04:12 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:12 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:12 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 16 14:04:12 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:12 primo volumio[5322]: info: CoreStateMachine::serviceStop Apr 16 14:04:12 primo volumio[5322]: info: CorePlayQueue::getTrack 0 Apr 16 14:04:12 primo volumio[5322]: info: CoreCommandRouter::serviceStop Apr 16 14:04:12 primo volumio[5322]: info: ControllerMpd::stop Apr 16 14:04:12 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand stop Apr 16 14:04:12 primo volumio[5322]: info: CorePlayQueue::clearPlayQueue Apr 16 14:04:12 primo volumio[5322]: info: CorePlayQueue::saveQueue Apr 16 14:04:12 primo volumio[5322]: info: CoreCommandRouter::volumioPushQueue Apr 16 14:04:12 primo volumio[5322]: info: CoreStateMachine::addQueueItems Apr 16 14:04:12 primo volumio[5322]: info: CorePlayQueue::addQueueItems Apr 16 14:04:12 primo volumio[5322]: info: Preload queue cleared Apr 16 14:04:12 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A1. Intro.flac Apr 16 14:04:12 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A1. Intro.flac Apr 16 14:04:12 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A2. Hella Good.flac Apr 16 14:04:12 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A2. Hella Good.flac Apr 16 14:04:12 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A3. Hey Baby.flac Apr 16 14:04:12 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A3. Hey Baby.flac Apr 16 14:04:12 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A4. Making Out.flac Apr 16 14:04:12 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A4. Making Out.flac Apr 16 14:04:12 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/B1. Underneath It All.flac Apr 16 14:04:12 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/B1. Underneath It All.flac Apr 16 14:04:12 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/B2. Detective.flac Apr 16 14:04:12 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/B2. Detective.flac Apr 16 14:04:12 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/B3. Don't Let Me Down.flac Apr 16 14:04:12 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/B3. Don't Let Me Down.flac Apr 16 14:04:12 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/C1. Start the Fire.flac Apr 16 14:04:12 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/C1. Start the Fire.flac Apr 16 14:04:12 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/C2. Running.flac Apr 16 14:04:12 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/C2. Running.flac Apr 16 14:04:12 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/C3. In My Head.flac Apr 16 14:04:12 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/C3. In My Head.flac Apr 16 14:04:12 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/D1. Platinum Blonde Life.flac Apr 16 14:04:12 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/D1. Platinum Blonde Life.flac Apr 16 14:04:12 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/D2. Waiting Room.flac Apr 16 14:04:12 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/D2. Waiting Room.flac Apr 16 14:04:12 primo volumio[5322]: info: Adding Item to queue: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/D3. Rock Steady.flac Apr 16 14:04:12 primo volumio[5322]: info: Using cached record of: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/D3. Rock Steady.flac Apr 16 14:04:12 primo volumio[5322]: info: CoreCommandRouter::volumioPushQueue Apr 16 14:04:12 primo volumio[5322]: info: CorePlayQueue::saveQueue Apr 16 14:04:12 primo volumio[5322]: info: CoreStateMachine::updateTrackBlock Apr 16 14:04:12 primo volumio[5322]: info: CorePlayQueue::getTrackBlock Apr 16 14:04:12 primo volumio[5322]: info: CoreCommandRouter::volumioPlay Apr 16 14:04:12 primo volumio[5322]: info: CoreStateMachine::play index 2 Apr 16 14:04:12 primo volumio[5322]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 16 14:04:12 primo volumio[5322]: info: CoreStateMachine::stop Apr 16 14:04:12 primo volumio[5322]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 16 14:04:12 primo volumio[5322]: info: CoreStateMachine::play index undefined Apr 16 14:04:12 primo volumio[5322]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 16 14:04:12 primo kernel: asoc-aml-card auge_sound: tdm playback stop Apr 16 14:04:12 primo kernel: spdif_a is set to disable Apr 16 14:04:12 primo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 Apr 16 14:04:12 primo kernel: aml_dai_tdm_hw_free(), disable mclk for TDM-B Apr 16 14:04:12 primo kernel: tdm playback mute: 1, lane_cnt = 8 Apr 16 14:04:12 primo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:tdm@1 Apr 16 14:04:12 primo volumio[5322]: info: CorePlayQueue::getTrack 2 Apr 16 14:04:12 primo volumio[5322]: info: CoreStateMachine::startPlaybackTimer Apr 16 14:04:12 primo volumio[5322]: info: CorePlayQueue::getTrack 2 Apr 16 14:04:12 primo volumio[5322]: verbose: ControllerMpd::clearAddPlayTracks USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A3. Hey Baby.flac Apr 16 14:04:12 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand stop Apr 16 14:04:12 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:04:12 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:04:12 primo volumio[5322]: info: Apr 16 14:04:12 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:04:12 primo volumio[5322]: info: sendMpdCommand stop took 54 milliseconds Apr 16 14:04:12 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:04:12 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:04:12 primo volumio[5322]: info: sendMpdCommand stop took 14 milliseconds Apr 16 14:04:12 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand clear Apr 16 14:04:12 primo volumio[5322]: info: Apr 16 14:04:12 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:04:12 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:04:12 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:04:12 primo volumio[5322]: info: Apr 16 14:04:12 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:04:12 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:04:12 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:04:12 primo volumio[5322]: info: Apr 16 14:04:12 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:04:12 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:04:12 primo volumio[5322]: info: sendMpdCommand status took 10 milliseconds Apr 16 14:04:12 primo volumio[5322]: info: sendMpdCommand clear took 9 milliseconds Apr 16 14:04:12 primo volumio[5322]: info: sendMpdCommand status took 9 milliseconds Apr 16 14:04:12 primo volumio[5322]: info: sendMpdCommand status took 7 milliseconds Apr 16 14:04:12 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:04:12 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 14:04:12 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand add "USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A3. Hey Baby.flac" Apr 16 14:04:12 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:04:12 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:04:12 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:04:12 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:04:12 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:12 primo volumio[5322]: info: CorePlayQueue::getTrack 2 Apr 16 14:04:12 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 16 14:04:12 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:12 primo volumio[5322]: info: CorePlayQueue::getTrack 2 Apr 16 14:04:12 primo volumio[5322]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 16 14:04:12 primo volumio[5322]: verbose: CURRENT POSITION 2 Apr 16 14:04:12 primo volumio[5322]: info: CoreStateMachine::syncState stateService stop Apr 16 14:04:12 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus stop Apr 16 14:04:12 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:12 primo volumio[5322]: info: CorePlayQueue::getTrack 2 Apr 16 14:04:12 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:12 primo volumio[5322]: info: No code Apr 16 14:04:12 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:12 primo volumio[5322]: info: CorePlayQueue::getTrack 2 Apr 16 14:04:12 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:12 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:04:12 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:04:12 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:12 primo volumio[5322]: info: CorePlayQueue::getTrack 2 Apr 16 14:04:12 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:12 primo volumio[5322]: info: CorePlayQueue::getTrack 2 Apr 16 14:04:12 primo volumio[5322]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 16 14:04:12 primo volumio[5322]: verbose: CURRENT POSITION 2 Apr 16 14:04:12 primo volumio[5322]: info: CoreStateMachine::syncState stateService stop Apr 16 14:04:12 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus stop Apr 16 14:04:12 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:12 primo volumio[5322]: info: CorePlayQueue::getTrack 2 Apr 16 14:04:12 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:12 primo volumio[5322]: info: No code Apr 16 14:04:12 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:12 primo volumio[5322]: info: CorePlayQueue::getTrack 2 Apr 16 14:04:12 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:12 primo volumio[5322]: info: ------------------------------ 69ms Apr 16 14:04:12 primo volumio[5322]: info: ------------------------------ 68ms Apr 16 14:04:12 primo volumio[5322]: info: Apr 16 14:04:12 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:04:12 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:04:12 primo volumio[5322]: info: Apr 16 14:04:12 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:04:12 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:04:12 primo volumio[5322]: error: updateQueue error: null Apr 16 14:04:12 primo volumio[5322]: info: Apr 16 14:04:12 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:04:12 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:04:12 primo volumio[5322]: info: ------------------------------ 92ms Apr 16 14:04:12 primo volumio[5322]: info: sendMpdCommand playlistinfo took 89 milliseconds Apr 16 14:04:12 primo volumio[5322]: info: sendMpdCommand add "USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A3. Hey Baby.flac" took 89 milliseconds Apr 16 14:04:12 primo volumio[5322]: info: ------------------------------ 28ms Apr 16 14:04:12 primo volumio[5322]: verbose: ControllerMpd::parseTrackInfo Apr 16 14:04:12 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand play Apr 16 14:04:12 primo volumio[5322]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 16 14:04:12 primo volumio[5322]: info: ------------------------------ 106ms Apr 16 14:04:12 primo volumio[5322]: info: Apr 16 14:04:12 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:04:12 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:04:12 primo volumio[5322]: info: Apr 16 14:04:12 primo volumio[5322]: ---------------------------- MPD announces system playlist update Apr 16 14:04:12 primo volumio[5322]: info: Ignoring MPD Status Update Apr 16 14:04:12 primo kernel: aml_tdm_open Apr 16 14:04:12 primo kernel: Not init audio effects Apr 16 14:04:12 primo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:tdm@1 Apr 16 14:04:12 primo kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk Apr 16 14:04:12 primo kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk Apr 16 14:04:12 primo kernel: set mclk:49152000, mpll:98304000, get mclk:49151901, mpll:98303801 Apr 16 14:04:12 primo kernel: asoc aml_dai_set_tdm_fmt, 0x4001, ffffffc050950018, id(1), clksel(1) Apr 16 14:04:12 primo kernel: aml_dai_set_tdm_fmt(), fmt not change Apr 16 14:04:12 primo kernel: dump_pcm_setting(ffffffc050950018) Apr 16 14:04:12 primo kernel: pcm_mode(1) Apr 16 14:04:12 primo kernel: sysclk(49152000) Apr 16 14:04:12 primo kernel: sysclk_bclk_ratio(4) Apr 16 14:04:12 primo kernel: bclk(12288000) Apr 16 14:04:12 primo kernel: bclk_lrclk_ratio(64) Apr 16 14:04:12 primo kernel: lrclk(192000) Apr 16 14:04:12 primo kernel: tx_mask(0x3) Apr 16 14:04:12 primo kernel: rx_mask(0x3) Apr 16 14:04:12 primo kernel: slots(2) Apr 16 14:04:12 primo kernel: slot_width(32) Apr 16 14:04:12 primo kernel: lane_mask_in(0x2) Apr 16 14:04:12 primo kernel: lane_mask_out(0x1) Apr 16 14:04:12 primo kernel: lane_oe_mask_in(0x0) Apr 16 14:04:12 primo kernel: lane_oe_mask_out(0x0) Apr 16 14:04:12 primo kernel: lane_lb_mask_in(0x0) Apr 16 14:04:12 primo kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk Apr 16 14:04:12 primo kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk Apr 16 14:04:12 primo kernel: set mclk:49152000, mpll:98304000, get mclk:49151901, mpll:98303801 Apr 16 14:04:12 primo kernel: aml_dai_set_clkdiv, div 4, clksel(1) Apr 16 14:04:12 primo kernel: aml_dai_set_bclk_ratio, select I2S mode Apr 16 14:04:12 primo kernel: aml_dai_tdm_hw_params(), enable mclk for TDM-B Apr 16 14:04:12 primo kernel: aml_tdm_prepare(), reset fddr Apr 16 14:04:12 primo kernel: spdif_a fifo ctrl, frddr:0 type:3, 32 bits, chmask 0x3, swap 0x10 Apr 16 14:04:12 primo kernel: spdif_info: rate: 192000, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0xe00, ch1_r:0xe00 Apr 16 14:04:12 primo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 Apr 16 14:04:12 primo kernel: tdm playback mute: 0, lane_cnt = 8 Apr 16 14:04:12 primo volumio[5322]: info: MCU Signalled Playback Inactive Apr 16 14:04:12 primo volumio[5322]: info: Apr 16 14:04:12 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:04:12 primo volumio[5322]: info: Apr 16 14:04:12 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:04:12 primo volumio[5322]: info: ------------------------------ 32ms Apr 16 14:04:12 primo volumio[5322]: info: sendMpdCommand play took 29 milliseconds Apr 16 14:04:12 primo volumio[5322]: info: ------------------------------ 27ms Apr 16 14:04:12 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:04:12 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:04:12 primo volumio[5322]: info: ------------------------------ 27ms Apr 16 14:04:12 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:04:12 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:04:12 primo volumio[5322]: info: Apr 16 14:04:12 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:04:12 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:04:12 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:04:12 primo volumio[5322]: info: Apr 16 14:04:12 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:04:12 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:04:12 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:04:12 primo volumio[5322]: info: sendMpdCommand status took 48 milliseconds Apr 16 14:04:12 primo volumio[5322]: info: sendMpdCommand status took 47 milliseconds Apr 16 14:04:12 primo volumio[5322]: info: sendMpdCommand status took 46 milliseconds Apr 16 14:04:12 primo volumio[5322]: info: sendMpdCommand status took 44 milliseconds Apr 16 14:04:12 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:04:12 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 14:04:12 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:04:12 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 14:04:12 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:04:12 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 14:04:12 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:04:12 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 14:04:12 primo volumio[5322]: info: Apr 16 14:04:12 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:04:12 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:04:12 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:04:12 primo volumio[5322]: info: Apr 16 14:04:12 primo volumio[5322]: ---------------------------- MPD announces state update: player Apr 16 14:04:12 primo volumio[5322]: info: ControllerMpd::getState Apr 16 14:04:12 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand status Apr 16 14:04:13 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:04:13 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:04:13 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:04:13 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:04:13 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:04:13 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:04:13 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:04:13 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:04:13 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:04:13 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:04:13 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:04:13 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:04:13 primo volumio[5322]: info: sendMpdCommand playlistinfo took 69 milliseconds Apr 16 14:04:13 primo volumio[5322]: info: sendMpdCommand playlistinfo took 70 milliseconds Apr 16 14:04:13 primo volumio[5322]: info: sendMpdCommand playlistinfo took 69 milliseconds Apr 16 14:04:13 primo volumio[5322]: info: sendMpdCommand playlistinfo took 69 milliseconds Apr 16 14:04:13 primo volumio[5322]: info: sendMpdCommand status took 67 milliseconds Apr 16 14:04:13 primo volumio[5322]: info: sendMpdCommand status took 64 milliseconds Apr 16 14:04:13 primo volumio[5322]: verbose: ControllerMpd::parseTrackInfo Apr 16 14:04:13 primo volumio[5322]: verbose: ControllerMpd::parseTrackInfo Apr 16 14:04:13 primo volumio[5322]: verbose: ControllerMpd::parseTrackInfo Apr 16 14:04:13 primo volumio[5322]: verbose: ControllerMpd::parseTrackInfo Apr 16 14:04:13 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:04:13 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 14:04:13 primo volumio[5322]: verbose: ControllerMpd::parseState Apr 16 14:04:13 primo volumio[5322]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 14:04:13 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:04:13 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:04:13 primo volumio[5322]: info: CorePlayQueue::getTrack 2 Apr 16 14:04:13 primo volumio[5322]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":204,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Hey Baby","artist":"No Doubt","album":"Rock Steady","uri":"USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A3. Hey Baby.flac","trackType":"flac"} Apr 16 14:04:13 primo volumio[5322]: verbose: CURRENT POSITION 2 Apr 16 14:04:13 primo volumio[5322]: info: CoreStateMachine::syncState stateService play Apr 16 14:04:13 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus stop Apr 16 14:04:13 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:04:13 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:04:13 primo volumio[5322]: info: CorePlayQueue::getTrack 2 Apr 16 14:04:13 primo volumio[5322]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":204,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Hey Baby","artist":"No Doubt","album":"Rock Steady","uri":"USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A3. Hey Baby.flac","trackType":"flac"} Apr 16 14:04:13 primo volumio[5322]: verbose: CURRENT POSITION 2 Apr 16 14:04:13 primo volumio[5322]: info: CoreStateMachine::syncState stateService play Apr 16 14:04:13 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus play Apr 16 14:04:13 primo volumio[5322]: info: Received an update from plugin. extracting info from payload Apr 16 14:04:13 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:13 primo volumio[5322]: info: CorePlayQueue::getTrack 2 Apr 16 14:04:13 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 16 14:04:13 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:13 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:13 primo volumio[5322]: info: CorePlayQueue::getTrack 2 Apr 16 14:04:13 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:13 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:04:13 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:04:13 primo volumio[5322]: info: CorePlayQueue::getTrack 2 Apr 16 14:04:13 primo volumio[5322]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":204,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Hey Baby","artist":"No Doubt","album":"Rock Steady","uri":"USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A3. Hey Baby.flac","trackType":"flac"} Apr 16 14:04:13 primo volumio[5322]: verbose: CURRENT POSITION 2 Apr 16 14:04:13 primo volumio[5322]: info: CoreStateMachine::syncState stateService play Apr 16 14:04:13 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus play Apr 16 14:04:13 primo volumio[5322]: info: Received an update from plugin. extracting info from payload Apr 16 14:04:13 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:13 primo volumio[5322]: info: CorePlayQueue::getTrack 2 Apr 16 14:04:13 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:13 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:13 primo volumio[5322]: info: CorePlayQueue::getTrack 2 Apr 16 14:04:13 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:13 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:04:13 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:04:13 primo volumio[5322]: info: CorePlayQueue::getTrack 2 Apr 16 14:04:13 primo volumio[5322]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":204,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Hey Baby","artist":"No Doubt","album":"Rock Steady","uri":"USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A3. Hey Baby.flac","trackType":"flac"} Apr 16 14:04:13 primo volumio[5322]: verbose: CURRENT POSITION 2 Apr 16 14:04:13 primo volumio[5322]: info: CoreStateMachine::syncState stateService play Apr 16 14:04:13 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus play Apr 16 14:04:13 primo volumio[5322]: info: Received an update from plugin. extracting info from payload Apr 16 14:04:13 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:13 primo volumio[5322]: info: CorePlayQueue::getTrack 2 Apr 16 14:04:13 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:13 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:13 primo volumio[5322]: info: CorePlayQueue::getTrack 2 Apr 16 14:04:13 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:13 primo volumio[5322]: info: ------------------------------ 152ms Apr 16 14:04:13 primo volumio[5322]: info: ------------------------------ 171ms Apr 16 14:04:13 primo volumio[5322]: info: ------------------------------ 168ms Apr 16 14:04:13 primo volumio[5322]: info: ------------------------------ 167ms Apr 16 14:04:13 primo kernel: asoc-aml-card auge_sound: tdm playback enable Apr 16 14:04:13 primo kernel: spdif_a is set to enable Apr 16 14:04:13 primo volumio[5322]: info: sendMpdCommand playlistinfo took 49 milliseconds Apr 16 14:04:13 primo volumio[5322]: info: sendMpdCommand playlistinfo took 48 milliseconds Apr 16 14:04:13 primo volumio[5322]: verbose: ControllerMpd::parseTrackInfo Apr 16 14:04:13 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:04:13 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:04:13 primo volumio[5322]: info: CorePlayQueue::getTrack 2 Apr 16 14:04:13 primo volumio[5322]: verbose: STATE SERVICE {"status":"play","position":0,"seek":41,"duration":204,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"2587 Kbps","isStreaming":false,"title":"Hey Baby","artist":"No Doubt","album":"Rock Steady","uri":"USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A3. Hey Baby.flac","trackType":"flac"} Apr 16 14:04:13 primo volumio[5322]: verbose: CURRENT POSITION 2 Apr 16 14:04:13 primo volumio[5322]: info: CoreStateMachine::syncState stateService play Apr 16 14:04:13 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus play Apr 16 14:04:13 primo volumio[5322]: info: Received an update from plugin. extracting info from payload Apr 16 14:04:13 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:13 primo volumio[5322]: info: CorePlayQueue::getTrack 2 Apr 16 14:04:13 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 16 14:04:13 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:13 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:13 primo volumio[5322]: info: CorePlayQueue::getTrack 2 Apr 16 14:04:13 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:13 primo volumio[5322]: info: ControllerMpd::pushState Apr 16 14:04:13 primo volumio[5322]: info: CoreCommandRouter::servicePushState Apr 16 14:04:13 primo volumio[5322]: info: CorePlayQueue::getTrack 2 Apr 16 14:04:13 primo volumio[5322]: verbose: STATE SERVICE {"status":"play","position":0,"seek":47,"duration":204,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"2587 Kbps","isStreaming":false,"title":"Hey Baby","artist":"No Doubt","album":"Rock Steady","uri":"USB/SSDSumsung/LossLessMusic/No Doubt/2001 - Rock Steady [Vinyl Rip]/A3. Hey Baby.flac","trackType":"flac"} Apr 16 14:04:13 primo volumio[5322]: verbose: CURRENT POSITION 2 Apr 16 14:04:13 primo volumio[5322]: info: CoreStateMachine::syncState stateService play Apr 16 14:04:13 primo volumio[5322]: info: CoreStateMachine::syncState currentStatus play Apr 16 14:04:13 primo volumio[5322]: info: Received an update from plugin. extracting info from payload Apr 16 14:04:13 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:13 primo volumio[5322]: info: CorePlayQueue::getTrack 2 Apr 16 14:04:13 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 16 14:04:13 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:13 primo volumio[5322]: info: CoreStateMachine::pushState Apr 16 14:04:13 primo volumio[5322]: info: CorePlayQueue::getTrack 2 Apr 16 14:04:13 primo volumio[5322]: info: CoreCommandRouter::volumioPushState Apr 16 14:04:13 primo volumio[5322]: info: ------------------------------ 170ms Apr 16 14:04:13 primo volumio[5322]: info: ------------------------------ 168ms Apr 16 14:04:13 primo volumio[5322]: info: Signalling Playback active due to playback status change Apr 16 14:04:13 primo volumio[5322]: info: Signalling Playback active due to playback status change Apr 16 14:04:13 primo volumio[5322]: info: Signalling Playback active due to playback status change Apr 16 14:04:13 primo volumio[5322]: info: Signalling Playback active due to playback status change Apr 16 14:04:13 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:04:13 primo volumio[5322]: info: Updating RAAT Signal Path Apr 16 14:04:13 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:04:13 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:04:13 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:04:13 primo volumio[5322]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 16 14:04:13 primo volumio[5322]: info: MCU Signalled Playback Active Apr 16 14:04:19 primo volumio[5322]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 16 14:04:19 primo volumio[5322]: info: CURURI: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/No Doubt - Rock Steady (2001)[FLAC] Apr 16 14:04:19 primo volumio[5322]: info: Preload queue cleared Apr 16 14:04:19 primo volumio[5322]: info: Preloading song: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/No Doubt - Rock Steady (2001)[FLAC]/10 - In My Head.flac Apr 16 14:04:19 primo volumio[5322]: info: Preloading song: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/No Doubt - Rock Steady (2001)[FLAC]/Rock Steady [Cue_NonCompliant_FLAC].CUE Apr 16 14:04:19 primo volumio[5322]: info: Preloading song: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/No Doubt - Rock Steady (2001)[FLAC]/Rock Steady [Cue_NonCompliant_WAV].CUE Apr 16 14:04:19 primo volumio[5322]: info: Preloading song: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/No Doubt - Rock Steady (2001)[FLAC]/Rock Steady [Cue_SingleFile_FLAC].CUE Apr 16 14:04:19 primo volumio[5322]: info: Preloading song: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/No Doubt - Rock Steady (2001)[FLAC]/Rock Steady [Cue_SingleFile_WAV].CUE Apr 16 14:04:19 primo volumio[5322]: info: Preloading song: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/No Doubt - Rock Steady (2001)[FLAC]/Rock Steady [Playlist_FLAC].m3u Apr 16 14:04:19 primo volumio[5322]: info: Preloading song: music-library/USB/SSDSumsung/LossLessMusic/No Doubt/No Doubt - Rock Steady (2001)[FLAC]/Rock Steady [Playlist_WAV].m3u Apr 16 14:04:19 primo volumio[5322]: info: Exploding uri music-library/USB/SSDSumsung/LossLessMusic/No Doubt/No Doubt - Rock Steady (2001)[FLAC]/10 - In My Head.flac in service mpd Apr 16 14:04:19 primo volumio[5322]: info: ALBUMART /albumart?cacheid=615&web=No%20Doubt/Rock%20Steady/extralarge&path=%2Fmnt%2FUSB%2FSSDSumsung%2FLossLessMusic%2FNo%20Doubt%2FNo%20Doubt%20-%20Rock%20Steady%20(2001)%5BFLAC%5D%2F10%20-%20In%20My%20Head.flac&metadata=false Apr 16 14:04:19 primo volumio[5322]: info: URI /mnt/USB/SSDSumsung/LossLessMusic/No Doubt/No Doubt - Rock Steady (2001)[FLAC]/10 - In My Head.flac Apr 16 14:04:19 primo volumio[5322]: info: Exploding uri music-library/USB/SSDSumsung/LossLessMusic/No Doubt/No Doubt - Rock Steady (2001)[FLAC]/Rock Steady [Cue_NonCompliant_FLAC].CUE in service mpd Apr 16 14:04:19 primo volumio[5322]: info: ALBUMART /albumart?cacheid=615&web=No%20Doubt/Rock%20Steady/extralarge&path=%2Fmnt%2FUSB%2FSSDSumsung%2FLossLessMusic%2FNo%20Doubt%2FNo%20Doubt%20-%20Rock%20Steady%20(2001)%5BFLAC%5D%2FRock%20Steady%20%5BCue_NonCompliant_FLAC%5D.CUE&metadata=false Apr 16 14:04:19 primo volumio[5322]: info: URI /mnt/USB/SSDSumsung/LossLessMusic/No Doubt/No Doubt - Rock Steady (2001)[FLAC]/Rock Steady [Cue_NonCompliant_FLAC].CUE Apr 16 14:04:19 primo volumio[5322]: info: ALBUMART /albumart?cacheid=615&web=No%20Doubt/Rock%20Steady/extralarge&path=%2Fmnt%2FUSB%2FSSDSumsung%2FLossLessMusic%2FNo%20Doubt%2FNo%20Doubt%20-%20Rock%20Steady%20(2001)%5BFLAC%5D%2FRock%20Steady%20%5BCue_NonCompliant_FLAC%5D.CUE&metadata=false Apr 16 14:04:19 primo volumio[5322]: info: URI /mnt/USB/SSDSumsung/LossLessMusic/No Doubt/No Doubt - Rock Steady (2001)[FLAC]/Rock Steady [Cue_NonCompliant_FLAC].CUE Apr 16 14:04:19 primo volumio[5322]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 16 14:04:19 primo volumio[5322]: Error: Unable to resolve or reject the same promise twice Apr 16 14:04:19 primo volumio[5322]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Apr 16 14:04:19 primo volumio[5322]: at /volumio/app/plugins/music_service/mpd/index.js:2568:21 Apr 16 14:04:19 primo volumio[5322]: at MpdClient.handleMessage (/volumio/app/plugins/music_service/mpd/lib/mpd.js:77:3) Apr 16 14:04:19 primo volumio[5322]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:68:12) Apr 16 14:04:19 primo volumio[5322]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12) Apr 16 14:04:19 primo volumio[5322]: at Socket.emit (events.js:400:28) Apr 16 14:04:19 primo volumio[5322]: at addChunk (internal/streams/readable.js:293:12) Apr 16 14:04:19 primo volumio[5322]: at readableAddChunk (internal/streams/readable.js:263:11) Apr 16 14:04:19 primo volumio[5322]: at Socket.Readable.push (internal/streams/readable.js:206:10) Apr 16 14:04:19 primo volumio[5322]: at Pipe.onStreamRead (internal/stream_base_commons.js:188:23) Apr 16 14:04:19 primo volumio[5322]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 16 14:04:21 primo sudo[9455]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-16 14:03 Apr 16 14:04:21 primo sudo[9455]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="7f9f1bf001add7a8b19a4516e3c74ef598b2730d" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="e831866afe2db61aee9333a8f5ba9d9fd36609c7" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="primo2rev2" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sun 18 Feb 2024 12:01:04 PM CET" VOLUMIO_VERSION="3.629" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Primo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Primo" VOLUMIO_HASH="728189e850980f21ef569472434ec23d"