Jan 25 22:34:29 muzak go-librespot[13559]: time="2026-01-25T22:34:29+01:00" level=trace msg="sent dealer ping" Jan 25 22:34:29 muzak go-librespot[13559]: time="2026-01-25T22:34:29+01:00" level=trace msg="received dealer pong" Jan 25 22:34:56 muzak volumio[13296]: info: CorePlayQueue::getTrack 10 Jan 25 22:34:56 muzak volumio[13296]: info: CorePlayQueue::getTrack 11 Jan 25 22:34:58 muzak go-librespot[13559]: time="2026-01-25T22:34:58+01:00" level=trace msg="received accesspoint ping" Jan 25 22:34:58 muzak go-librespot[13559]: time="2026-01-25T22:34:58+01:00" level=trace msg="received accesspoint pong ack" Jan 25 22:34:59 muzak go-librespot[13559]: time="2026-01-25T22:34:59+01:00" level=trace msg="sent dealer ping" Jan 25 22:34:59 muzak go-librespot[13559]: time="2026-01-25T22:34:59+01:00" level=trace msg="received dealer pong" Jan 25 22:35:02 muzak volumio[13296]: info: Jan 25 22:35:02 muzak volumio[13296]: ---------------------------- MPD announces system playlist update Jan 25 22:35:02 muzak volumio[13296]: info: Ignoring MPD Status Update Jan 25 22:35:02 muzak volumio[13296]: info: Jan 25 22:35:02 muzak volumio[13296]: ---------------------------- MPD announces state update: player Jan 25 22:35:02 muzak volumio[13296]: info: ControllerMpd::getState Jan 25 22:35:02 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand status Jan 25 22:35:02 muzak volumio[13296]: info: Jan 25 22:35:02 muzak volumio[13296]: ---------------------------- MPD announces system playlist update Jan 25 22:35:02 muzak volumio[13296]: info: Ignoring MPD Status Update Jan 25 22:35:02 muzak volumio[13296]: info: Jan 25 22:35:02 muzak volumio[13296]: ---------------------------- MPD announces state update: player Jan 25 22:35:02 muzak volumio[13296]: info: ControllerMpd::getState Jan 25 22:35:02 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand status Jan 25 22:35:02 muzak volumio[13296]: info: Jan 25 22:35:02 muzak volumio[13296]: ---------------------------- MPD announces system playlist update Jan 25 22:35:02 muzak volumio[13296]: info: Ignoring MPD Status Update Jan 25 22:35:02 muzak volumio[13296]: info: Jan 25 22:35:02 muzak volumio[13296]: ---------------------------- MPD announces state update: player Jan 25 22:35:02 muzak volumio[13296]: error: updateQueue error: null Jan 25 22:35:02 muzak volumio[13296]: error: updateQueue error: null Jan 25 22:35:02 muzak volumio[13296]: info: ControllerMpd::getState Jan 25 22:35:02 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand status Jan 25 22:35:02 muzak volumio[13296]: info: ------------------------------ 3ms Jan 25 22:35:02 muzak volumio[13296]: info: sendMpdCommand status took 2 milliseconds Jan 25 22:35:02 muzak volumio[13296]: info: ------------------------------ 3ms Jan 25 22:35:02 muzak volumio[13296]: info: sendMpdCommand status took 2 milliseconds Jan 25 22:35:02 muzak volumio[13296]: verbose: ControllerMpd::parseState Jan 25 22:35:02 muzak volumio[13296]: verbose: ControllerMpd::parseState Jan 25 22:35:02 muzak volumio[13296]: info: ControllerMpd::pushState Jan 25 22:35:02 muzak volumio[13296]: info: CoreCommandRouter::servicePushState Jan 25 22:35:02 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:02 muzak volumio[13296]: info: CorePlayQueue::getTrack 10 Jan 25 22:35:02 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 22:35:02 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:02 muzak volumio[13296]: info: CorePlayQueue::getTrack 10 Jan 25 22:35:02 muzak volumio[13296]: 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} Jan 25 22:35:02 muzak volumio[13296]: verbose: CURRENT POSITION 10 Jan 25 22:35:02 muzak volumio[13296]: info: CoreStateMachine::syncState stateService stop Jan 25 22:35:02 muzak volumio[13296]: info: CoreStateMachine::syncState currentStatus play Jan 25 22:35:02 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:02 muzak volumio[13296]: info: CoreStateMachine::stPlaybackTimer Jan 25 22:35:02 muzak volumio[13296]: info: ControllerMpd::pushState Jan 25 22:35:02 muzak volumio[13296]: info: CoreCommandRouter::servicePushState Jan 25 22:35:02 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:02 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:02 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 22:35:02 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:02 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:02 muzak volumio[13296]: 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} Jan 25 22:35:02 muzak volumio[13296]: verbose: CURRENT POSITION 0 Jan 25 22:35:02 muzak volumio[13296]: info: CoreStateMachine::syncState stateService stop Jan 25 22:35:02 muzak volumio[13296]: info: CoreStateMachine::syncState currentStatus stop Jan 25 22:35:02 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:02 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:02 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:02 muzak volumio[13296]: info: No code Jan 25 22:35:02 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:02 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:02 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:02 muzak volumio[13296]: info: ------------------------------ 51ms Jan 25 22:35:02 muzak volumio[13296]: info: ------------------------------ 51ms Jan 25 22:35:02 muzak volumio[13296]: error: updateQueue error: null Jan 25 22:35:02 muzak volumio[13296]: info: ------------------------------ 52ms Jan 25 22:35:02 muzak volumio[13296]: info: sendMpdCommand status took 51 milliseconds Jan 25 22:35:02 muzak volumio[13296]: verbose: ControllerMpd::parseState Jan 25 22:35:02 muzak volumio[13296]: info: ControllerMpd::pushState Jan 25 22:35:02 muzak volumio[13296]: info: CoreCommandRouter::servicePushState Jan 25 22:35:02 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:02 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:02 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 22:35:02 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:02 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:02 muzak volumio[13296]: 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} Jan 25 22:35:02 muzak volumio[13296]: verbose: CURRENT POSITION 0 Jan 25 22:35:02 muzak volumio[13296]: info: CoreStateMachine::syncState stateService stop Jan 25 22:35:02 muzak volumio[13296]: info: CoreStateMachine::syncState currentStatus stop Jan 25 22:35:02 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:02 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:02 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:02 muzak volumio[13296]: info: No code Jan 25 22:35:02 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:02 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:02 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:02 muzak volumio[13296]: info: ------------------------------ 77ms Jan 25 22:35:07 muzak volumio[13296]: verbose: New Socket.io Connection to 192.168.178.33:3000 from 192.168.178.44 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Jan 25 22:35:07 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 25 22:35:07 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 25 22:35:07 muzak volumio[13296]: info: Discovery: Getting this device information Jan 25 22:35:07 muzak volumio[13296]: info: CoreCommandRouter::volumioGetState Jan 25 22:35:07 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:07 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 25 22:35:29 muzak go-librespot[13559]: time="2026-01-25T22:35:29+01:00" level=trace msg="sent dealer ping" Jan 25 22:35:29 muzak go-librespot[13559]: time="2026-01-25T22:35:29+01:00" level=trace msg="received dealer pong" Jan 25 22:35:29 muzak volumio[13296]: verbose: New Socket.io Connection to 192.168.178.33 from 192.168.178.44 UA: Mozilla/5.0 (Linux; Android 16; Pixel 8 Build/BP3A.251105.015; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/143.0.7499.192 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Jan 25 22:35:29 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 25 22:35:29 muzak volumio[13296]: info: CoreCommandRouter::volumioGetVisibleSources Jan 25 22:35:29 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 22:35:29 muzak volumio[13296]: info: CoreCommandRouter::volumioGetState Jan 25 22:35:29 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:29 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jan 25 22:35:29 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 25 22:35:29 muzak volumio[13296]: info: Received Get System Info Jan 25 22:35:29 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 25 22:35:29 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 25 22:35:29 muzak volumio[13296]: info: Discovery: Getting this device information Jan 25 22:35:29 muzak volumio[13296]: info: CoreCommandRouter::volumioGetState Jan 25 22:35:29 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:29 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 25 22:35:29 muzak volumio[13296]: info: CoreCommandRouter::volumioGetState Jan 25 22:35:29 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:29 muzak volumio[13296]: info: Listing playlists Jan 25 22:35:29 muzak volumio[13296]: info: CoreCommandRouter::volumioGetQueue Jan 25 22:35:29 muzak volumio[13296]: info: CoreStateMachine::getQueue Jan 25 22:35:29 muzak volumio[13296]: info: CorePlayQueue::getQueue Jan 25 22:35:30 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jan 25 22:35:32 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 25 22:35:32 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 25 22:35:32 muzak volumio[13296]: info: Discovery: Getting this device information Jan 25 22:35:32 muzak volumio[13296]: info: CoreCommandRouter::volumioGetState Jan 25 22:35:32 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:32 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 25 22:35:32 muzak volumio[13296]: verbose: New Socket.io Connection to 192.168.178.33:3000 from 192.168.178.44 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Jan 25 22:35:32 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 25 22:35:32 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 25 22:35:38 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: randomizer , handleBrowseUri Jan 25 22:35:38 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jan 25 22:35:38 muzak volumio[13296]: info: CURURI: albums:// Jan 25 22:35:38 muzak volumio[13296]: info: listAlbums - loading Albums from cache Jan 25 22:35:38 muzak volumio[13296]: info: CoreCommandRouter::volumioClearQueue Jan 25 22:35:38 muzak volumio[13296]: info: CoreStateMachine::ClearQueue Jan 25 22:35:38 muzak volumio[13296]: info: CoreStateMachine::stop Jan 25 22:35:38 muzak volumio[13296]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 25 22:35:38 muzak volumio[13296]: info: CorePlayQueue::clearPlayQueue Jan 25 22:35:38 muzak volumio[13296]: info: CorePlayQueue::saveQueue Jan 25 22:35:38 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:38 muzak volumio[13296]: info: CoreCommandRouter::volumioPushQueue Jan 25 22:35:38 muzak volumio[13296]: info: CoreCommandRouter::volumioAddQueueItems Jan 25 22:35:38 muzak volumio[13296]: info: CoreStateMachine::addQueueItems Jan 25 22:35:38 muzak volumio[13296]: info: CorePlayQueue::addQueueItems Jan 25 22:35:38 muzak volumio[13296]: info: Preload queue cleared Jan 25 22:35:38 muzak volumio[13296]: info: Adding Item to queue: albums://Calcutta/Mainstream Jan 25 22:35:38 muzak volumio[13296]: info: Exploding uri albums://Calcutta/Mainstream in service mpd Jan 25 22:35:38 muzak volumio[13296]: info: Preload queue cleared Jan 25 22:35:38 muzak volumio[13296]: info: CoreCommandRouter::volumioPushQueue Jan 25 22:35:38 muzak volumio[13296]: info: CorePlayQueue::saveQueue Jan 25 22:35:38 muzak volumio[13296]: info: CoreStateMachine::updateTrackBlock Jan 25 22:35:38 muzak volumio[13296]: info: CorePlayQueue::getTrackBlock Jan 25 22:35:38 muzak volumio[13296]: info: Preload queue cleared Jan 25 22:35:38 muzak volumio[13296]: info: CoreCommandRouter::volumioPlay Jan 25 22:35:38 muzak volumio[13296]: info: CoreStateMachine::play index 0 Jan 25 22:35:38 muzak volumio[13296]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 25 22:35:38 muzak volumio[13296]: info: CoreStateMachine::stop Jan 25 22:35:38 muzak volumio[13296]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 25 22:35:38 muzak volumio[13296]: info: CoreStateMachine::play index undefined Jan 25 22:35:38 muzak volumio[13296]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 25 22:35:38 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:38 muzak volumio[13296]: info: CoreStateMachine::startPlaybackTimer Jan 25 22:35:38 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:38 muzak volumio[13296]: verbose: ControllerMpd::clearAddPlayTracks USB/MuZaK/Calcutta/Mainstream/Calcutta - 01 - Gaetano.mp3 Jan 25 22:35:38 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand stop Jan 25 22:35:38 muzak volumio[13296]: info: sendMpdCommand stop took 2 milliseconds Jan 25 22:35:38 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand clear Jan 25 22:35:38 muzak volumio[13296]: info: Jan 25 22:35:38 muzak volumio[13296]: ---------------------------- MPD announces system playlist update Jan 25 22:35:38 muzak volumio[13296]: info: Ignoring MPD Status Update Jan 25 22:35:38 muzak volumio[13296]: info: sendMpdCommand clear took 3 milliseconds Jan 25 22:35:38 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand add "USB/MuZaK/Calcutta/Mainstream/Calcutta - 01 - Gaetano.mp3" Jan 25 22:35:38 muzak volumio[13296]: info: Jan 25 22:35:38 muzak volumio[13296]: ---------------------------- MPD announces system playlist update Jan 25 22:35:38 muzak volumio[13296]: info: Ignoring MPD Status Update Jan 25 22:35:38 muzak volumio[13296]: info: Jan 25 22:35:38 muzak volumio[13296]: ---------------------------- MPD announces system playlist update Jan 25 22:35:38 muzak volumio[13296]: info: Ignoring MPD Status Update Jan 25 22:35:38 muzak volumio[13296]: error: updateQueue error: null Jan 25 22:35:38 muzak volumio[13296]: info: Jan 25 22:35:38 muzak volumio[13296]: ---------------------------- MPD announces system playlist update Jan 25 22:35:38 muzak volumio[13296]: info: Ignoring MPD Status Update Jan 25 22:35:38 muzak volumio[13296]: info: ------------------------------ 4ms Jan 25 22:35:38 muzak volumio[13296]: info: sendMpdCommand add "USB/MuZaK/Calcutta/Mainstream/Calcutta - 01 - Gaetano.mp3" took 4 milliseconds Jan 25 22:35:38 muzak volumio[13296]: info: ------------------------------ 3ms Jan 25 22:35:38 muzak volumio[13296]: info: ------------------------------ 3ms Jan 25 22:35:38 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand play Jan 25 22:35:38 muzak volumio[13296]: info: Jan 25 22:35:38 muzak volumio[13296]: ---------------------------- MPD announces system playlist update Jan 25 22:35:38 muzak volumio[13296]: info: Ignoring MPD Status Update Jan 25 22:35:38 muzak volumio[13296]: info: Jan 25 22:35:38 muzak volumio[13296]: ---------------------------- MPD announces system playlist update Jan 25 22:35:38 muzak volumio[13296]: info: Ignoring MPD Status Update Jan 25 22:35:38 muzak volumio[13296]: info: ------------------------------ 5ms Jan 25 22:35:38 muzak volumio[13296]: info: sendMpdCommand play took 4 milliseconds Jan 25 22:35:38 muzak volumio[13296]: info: ------------------------------ 3ms Jan 25 22:35:38 muzak volumio[13296]: info: ------------------------------ 2ms Jan 25 22:35:38 muzak volumio[13296]: info: Jan 25 22:35:38 muzak volumio[13296]: ---------------------------- MPD announces state update: player Jan 25 22:35:38 muzak volumio[13296]: info: ControllerMpd::getState Jan 25 22:35:38 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand status Jan 25 22:35:38 muzak volumio[13296]: info: Jan 25 22:35:38 muzak volumio[13296]: ---------------------------- MPD announces state update: player Jan 25 22:35:38 muzak volumio[13296]: info: ControllerMpd::getState Jan 25 22:35:38 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand status Jan 25 22:35:38 muzak kernel: bcm2835-i2s fe203000.i2s: I2S SYNC error! Jan 25 22:35:38 muzak volumio[13296]: info: Jan 25 22:35:38 muzak volumio[13296]: ---------------------------- MPD announces state update: player Jan 25 22:35:38 muzak volumio[13296]: info: Jan 25 22:35:38 muzak volumio[13296]: ---------------------------- MPD announces state update: player Jan 25 22:35:38 muzak volumio[13296]: info: ControllerMpd::getState Jan 25 22:35:38 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand status Jan 25 22:35:38 muzak volumio[13296]: info: sendMpdCommand status took 9 milliseconds Jan 25 22:35:38 muzak volumio[13296]: info: ControllerMpd::getState Jan 25 22:35:38 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand status Jan 25 22:35:38 muzak volumio[13296]: verbose: ControllerMpd::parseState Jan 25 22:35:38 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 22:35:38 muzak volumio[13296]: info: Jan 25 22:35:38 muzak volumio[13296]: ---------------------------- MPD announces state update: player Jan 25 22:35:38 muzak volumio[13296]: info: ControllerMpd::getState Jan 25 22:35:38 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand status Jan 25 22:35:38 muzak volumio[13296]: info: Jan 25 22:35:38 muzak volumio[13296]: ---------------------------- MPD announces state update: player Jan 25 22:35:38 muzak volumio[13296]: info: ControllerMpd::getState Jan 25 22:35:38 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand status Jan 25 22:35:38 muzak volumio[13296]: info: sendMpdCommand status took 13 milliseconds Jan 25 22:35:38 muzak volumio[13296]: info: sendMpdCommand status took 5 milliseconds Jan 25 22:35:38 muzak volumio[13296]: info: sendMpdCommand status took 5 milliseconds Jan 25 22:35:38 muzak volumio[13296]: info: sendMpdCommand playlistinfo took 5 milliseconds Jan 25 22:35:38 muzak volumio[13296]: info: sendMpdCommand status took 4 milliseconds Jan 25 22:35:38 muzak volumio[13296]: info: sendMpdCommand status took 3 milliseconds Jan 25 22:35:38 muzak volumio[13296]: verbose: ControllerMpd::parseState Jan 25 22:35:38 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 22:35:38 muzak volumio[13296]: verbose: ControllerMpd::parseState Jan 25 22:35:38 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 22:35:38 muzak volumio[13296]: verbose: ControllerMpd::parseState Jan 25 22:35:38 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 22:35:38 muzak volumio[13296]: verbose: ControllerMpd::parseTrackInfo Jan 25 22:35:38 muzak volumio[13296]: verbose: ControllerMpd::parseState Jan 25 22:35:38 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 22:35:38 muzak volumio[13296]: verbose: ControllerMpd::parseState Jan 25 22:35:38 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 22:35:38 muzak volumio[13296]: info: ControllerMpd::pushState Jan 25 22:35:38 muzak volumio[13296]: info: CoreCommandRouter::servicePushState Jan 25 22:35:38 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:38 muzak volumio[13296]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":242,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Gaetano","artist":"Calcutta","album":"Mainstream","uri":"USB/MuZaK/Calcutta/Mainstream/Calcutta - 01 - Gaetano.mp3","trackType":"mp3"} Jan 25 22:35:38 muzak volumio[13296]: verbose: CURRENT POSITION 0 Jan 25 22:35:38 muzak volumio[13296]: info: CoreStateMachine::syncState stateService play Jan 25 22:35:38 muzak volumio[13296]: info: CoreStateMachine::syncState currentStatus stop Jan 25 22:35:38 muzak volumio[13296]: info: ------------------------------ 18ms Jan 25 22:35:38 muzak volumio[13296]: info: sendMpdCommand playlistinfo took 4 milliseconds Jan 25 22:35:38 muzak volumio[13296]: info: sendMpdCommand playlistinfo took 3 milliseconds Jan 25 22:35:38 muzak volumio[13296]: info: sendMpdCommand playlistinfo took 3 milliseconds Jan 25 22:35:38 muzak volumio[13296]: info: sendMpdCommand playlistinfo took 3 milliseconds Jan 25 22:35:38 muzak volumio[13296]: info: sendMpdCommand playlistinfo took 5 milliseconds Jan 25 22:35:38 muzak volumio[13296]: verbose: ControllerMpd::parseTrackInfo Jan 25 22:35:38 muzak volumio[13296]: verbose: ControllerMpd::parseTrackInfo Jan 25 22:35:38 muzak volumio[13296]: verbose: ControllerMpd::parseTrackInfo Jan 25 22:35:38 muzak volumio[13296]: verbose: ControllerMpd::parseTrackInfo Jan 25 22:35:38 muzak volumio[13296]: verbose: ControllerMpd::parseTrackInfo Jan 25 22:35:38 muzak volumio[13296]: info: ControllerMpd::pushState Jan 25 22:35:38 muzak volumio[13296]: info: CoreCommandRouter::servicePushState Jan 25 22:35:38 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:38 muzak volumio[13296]: verbose: STATE SERVICE {"status":"play","position":0,"seek":275,"duration":242,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Gaetano","artist":"Calcutta","album":"Mainstream","uri":"USB/MuZaK/Calcutta/Mainstream/Calcutta - 01 - Gaetano.mp3","trackType":"mp3"} Jan 25 22:35:38 muzak volumio[13296]: verbose: CURRENT POSITION 0 Jan 25 22:35:38 muzak volumio[13296]: info: CoreStateMachine::syncState stateService play Jan 25 22:35:38 muzak volumio[13296]: info: CoreStateMachine::syncState currentStatus play Jan 25 22:35:38 muzak volumio[13296]: info: Received an update from plugin. extracting info from payload Jan 25 22:35:38 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:38 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:38 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 22:35:38 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:38 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:38 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:38 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:38 muzak volumio[13296]: info: ControllerMpd::pushState Jan 25 22:35:38 muzak volumio[13296]: info: CoreCommandRouter::servicePushState Jan 25 22:35:38 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:38 muzak volumio[13296]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":242,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Gaetano","artist":"Calcutta","album":"Mainstream","uri":"USB/MuZaK/Calcutta/Mainstream/Calcutta - 01 - Gaetano.mp3","trackType":"mp3"} Jan 25 22:35:38 muzak volumio[13296]: verbose: CURRENT POSITION 0 Jan 25 22:35:38 muzak volumio[13296]: info: CoreStateMachine::syncState stateService play Jan 25 22:35:38 muzak volumio[13296]: info: CoreStateMachine::syncState currentStatus play Jan 25 22:35:38 muzak volumio[13296]: info: Received an update from plugin. extracting info from payload Jan 25 22:35:38 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:38 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:38 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 22:35:38 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:38 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:38 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:38 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:38 muzak volumio[13296]: info: ControllerMpd::pushState Jan 25 22:35:38 muzak volumio[13296]: info: CoreCommandRouter::servicePushState Jan 25 22:35:38 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:38 muzak volumio[13296]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":242,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Gaetano","artist":"Calcutta","album":"Mainstream","uri":"USB/MuZaK/Calcutta/Mainstream/Calcutta - 01 - Gaetano.mp3","trackType":"mp3"} Jan 25 22:35:38 muzak volumio[13296]: verbose: CURRENT POSITION 0 Jan 25 22:35:38 muzak volumio[13296]: info: CoreStateMachine::syncState stateService play Jan 25 22:35:38 muzak volumio[13296]: info: CoreStateMachine::syncState currentStatus play Jan 25 22:35:38 muzak volumio[13296]: info: Received an update from plugin. extracting info from payload Jan 25 22:35:38 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:38 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:38 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:38 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:38 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:38 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:38 muzak volumio[13296]: info: ControllerMpd::pushState Jan 25 22:35:38 muzak volumio[13296]: info: CoreCommandRouter::servicePushState Jan 25 22:35:38 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:38 muzak volumio[13296]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":242,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Gaetano","artist":"Calcutta","album":"Mainstream","uri":"USB/MuZaK/Calcutta/Mainstream/Calcutta - 01 - Gaetano.mp3","trackType":"mp3"} Jan 25 22:35:38 muzak volumio[13296]: verbose: CURRENT POSITION 0 Jan 25 22:35:38 muzak volumio[13296]: info: CoreStateMachine::syncState stateService play Jan 25 22:35:38 muzak volumio[13296]: info: CoreStateMachine::syncState currentStatus play Jan 25 22:35:38 muzak volumio[13296]: info: Received an update from plugin. extracting info from payload Jan 25 22:35:38 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:38 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:38 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:38 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:38 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:38 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:38 muzak volumio[13296]: info: ControllerMpd::pushState Jan 25 22:35:38 muzak volumio[13296]: info: CoreCommandRouter::servicePushState Jan 25 22:35:38 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:38 muzak volumio[13296]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":242,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Gaetano","artist":"Calcutta","album":"Mainstream","uri":"USB/MuZaK/Calcutta/Mainstream/Calcutta - 01 - Gaetano.mp3","trackType":"mp3"} Jan 25 22:35:38 muzak volumio[13296]: verbose: CURRENT POSITION 0 Jan 25 22:35:38 muzak volumio[13296]: info: CoreStateMachine::syncState stateService play Jan 25 22:35:38 muzak volumio[13296]: info: CoreStateMachine::syncState currentStatus play Jan 25 22:35:38 muzak volumio[13296]: info: Received an update from plugin. extracting info from payload Jan 25 22:35:38 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:38 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:38 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:38 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:38 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:38 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:38 muzak volumio[13296]: info: ------------------------------ 106ms Jan 25 22:35:38 muzak volumio[13296]: info: ------------------------------ 99ms Jan 25 22:35:38 muzak volumio[13296]: info: ------------------------------ 98ms Jan 25 22:35:38 muzak volumio[13296]: info: ------------------------------ 96ms Jan 25 22:35:38 muzak volumio[13296]: info: ------------------------------ 96ms Jan 25 22:35:38 muzak volumio[13296]: info: [LastFM] Current track has sufficient metadata: title (Gaetano) and artist (Calcutta) passed on explicitly Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: randomizer , handleBrowseUri Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jan 25 22:35:39 muzak volumio[13296]: info: CURURI: albums:// Jan 25 22:35:39 muzak volumio[13296]: info: listAlbums - loading Albums from cache Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::volumioClearQueue Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::ClearQueue Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::stop Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::stPlaybackTimer Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::updateTrackBlock Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::getTrackBlock Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::serviceStop Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::serviceStop Jan 25 22:35:39 muzak volumio[13296]: info: ControllerMpd::stop Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand stop Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::clearPlayQueue Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::saveQueue Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::volumioPushQueue Jan 25 22:35:39 muzak volumio[13296]: info: Preload queue cleared Jan 25 22:35:39 muzak volumio[13296]: info: Preload queue cleared Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::volumioAddQueueItems Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::addQueueItems Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::addQueueItems Jan 25 22:35:39 muzak volumio[13296]: info: Preload queue cleared Jan 25 22:35:39 muzak volumio[13296]: info: Adding Item to queue: albums://Godflesh/Pure Jan 25 22:35:39 muzak volumio[13296]: info: Exploding uri albums://Godflesh/Pure in service mpd Jan 25 22:35:39 muzak volumio[13296]: info: Jan 25 22:35:39 muzak volumio[13296]: ---------------------------- MPD announces state update: player Jan 25 22:35:39 muzak volumio[13296]: info: sendMpdCommand stop took 74 milliseconds Jan 25 22:35:39 muzak volumio[13296]: info: ControllerMpd::getState Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand status Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::volumioPushQueue Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::saveQueue Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::updateTrackBlock Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::getTrackBlock Jan 25 22:35:39 muzak volumio[13296]: info: Jan 25 22:35:39 muzak volumio[13296]: ---------------------------- MPD announces state update: player Jan 25 22:35:39 muzak volumio[13296]: info: ControllerMpd::getState Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand status Jan 25 22:35:39 muzak volumio[13296]: info: Jan 25 22:35:39 muzak volumio[13296]: ---------------------------- MPD announces state update: player Jan 25 22:35:39 muzak volumio[13296]: info: ControllerMpd::getState Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand status Jan 25 22:35:39 muzak volumio[13296]: info: sendMpdCommand status took 98 milliseconds Jan 25 22:35:39 muzak volumio[13296]: info: sendMpdCommand status took 40 milliseconds Jan 25 22:35:39 muzak volumio[13296]: info: sendMpdCommand status took 39 milliseconds Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::parseState Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::parseState Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::parseState Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 22:35:39 muzak volumio[13296]: info: sendMpdCommand playlistinfo took 4 milliseconds Jan 25 22:35:39 muzak volumio[13296]: info: sendMpdCommand playlistinfo took 5 milliseconds Jan 25 22:35:39 muzak volumio[13296]: info: sendMpdCommand playlistinfo took 5 milliseconds Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::parseTrackInfo Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::parseTrackInfo Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::parseTrackInfo Jan 25 22:35:39 muzak volumio[13296]: info: ControllerMpd::pushState Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::servicePushState Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:39 muzak volumio[13296]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Gaetano","artist":"Calcutta","album":"Mainstream","uri":"USB/MuZaK/Calcutta/Mainstream/Calcutta - 01 - Gaetano.mp3","trackType":"mp3"} Jan 25 22:35:39 muzak volumio[13296]: verbose: CURRENT POSITION 0 Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::syncState stateService stop Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::syncState currentStatus stop Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:39 muzak volumio[13296]: info: No code Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:39 muzak volumio[13296]: info: ControllerMpd::pushState Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::servicePushState Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:39 muzak volumio[13296]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Gaetano","artist":"Calcutta","album":"Mainstream","uri":"USB/MuZaK/Calcutta/Mainstream/Calcutta - 01 - Gaetano.mp3","trackType":"mp3"} Jan 25 22:35:39 muzak volumio[13296]: verbose: CURRENT POSITION 0 Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::syncState stateService stop Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::syncState currentStatus stop Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:39 muzak volumio[13296]: info: No code Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:39 muzak volumio[13296]: info: ControllerMpd::pushState Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::servicePushState Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:39 muzak volumio[13296]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Gaetano","artist":"Calcutta","album":"Mainstream","uri":"USB/MuZaK/Calcutta/Mainstream/Calcutta - 01 - Gaetano.mp3","trackType":"mp3"} Jan 25 22:35:39 muzak volumio[13296]: verbose: CURRENT POSITION 0 Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::syncState stateService stop Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::syncState currentStatus stop Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:39 muzak volumio[13296]: info: No code Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:39 muzak volumio[13296]: info: ------------------------------ 198ms Jan 25 22:35:39 muzak volumio[13296]: info: ------------------------------ 141ms Jan 25 22:35:39 muzak volumio[13296]: info: ------------------------------ 139ms Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::volumioPlay Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::play index 0 Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::stop Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::play index undefined Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::startPlaybackTimer Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::clearAddPlayTracks USB/MuZaK/Godflesh/Pure/01 Spite.flac Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand stop Jan 25 22:35:39 muzak volumio[13296]: info: sendMpdCommand stop took 1 milliseconds Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand clear Jan 25 22:35:39 muzak volumio[13296]: info: Jan 25 22:35:39 muzak volumio[13296]: ---------------------------- MPD announces system playlist update Jan 25 22:35:39 muzak volumio[13296]: info: Ignoring MPD Status Update Jan 25 22:35:39 muzak volumio[13296]: info: sendMpdCommand clear took 28 milliseconds Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand add "USB/MuZaK/Godflesh/Pure/01 Spite.flac" Jan 25 22:35:39 muzak volumio[13296]: info: Jan 25 22:35:39 muzak volumio[13296]: ---------------------------- MPD announces system playlist update Jan 25 22:35:39 muzak volumio[13296]: info: Ignoring MPD Status Update Jan 25 22:35:39 muzak volumio[13296]: info: Jan 25 22:35:39 muzak volumio[13296]: ---------------------------- MPD announces system playlist update Jan 25 22:35:39 muzak volumio[13296]: info: Ignoring MPD Status Update Jan 25 22:35:39 muzak volumio[13296]: error: updateQueue error: null Jan 25 22:35:39 muzak volumio[13296]: info: Jan 25 22:35:39 muzak volumio[13296]: ---------------------------- MPD announces system playlist update Jan 25 22:35:39 muzak volumio[13296]: info: Ignoring MPD Status Update Jan 25 22:35:39 muzak volumio[13296]: info: ------------------------------ 4ms Jan 25 22:35:39 muzak volumio[13296]: info: sendMpdCommand add "USB/MuZaK/Godflesh/Pure/01 Spite.flac" took 4 milliseconds Jan 25 22:35:39 muzak volumio[13296]: info: ------------------------------ 4ms Jan 25 22:35:39 muzak volumio[13296]: info: ------------------------------ 3ms Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand play Jan 25 22:35:39 muzak volumio[13296]: info: Jan 25 22:35:39 muzak volumio[13296]: ---------------------------- MPD announces system playlist update Jan 25 22:35:39 muzak volumio[13296]: info: Ignoring MPD Status Update Jan 25 22:35:39 muzak volumio[13296]: info: Jan 25 22:35:39 muzak volumio[13296]: ---------------------------- MPD announces system playlist update Jan 25 22:35:39 muzak volumio[13296]: info: Ignoring MPD Status Update Jan 25 22:35:39 muzak volumio[13296]: info: Jan 25 22:35:39 muzak volumio[13296]: ---------------------------- MPD announces state update: player Jan 25 22:35:39 muzak volumio[13296]: info: Jan 25 22:35:39 muzak volumio[13296]: ---------------------------- MPD announces state update: player Jan 25 22:35:39 muzak volumio[13296]: info: ------------------------------ 9ms Jan 25 22:35:39 muzak volumio[13296]: info: sendMpdCommand play took 8 milliseconds Jan 25 22:35:39 muzak volumio[13296]: info: ControllerMpd::getState Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand status Jan 25 22:35:39 muzak volumio[13296]: info: ------------------------------ 4ms Jan 25 22:35:39 muzak volumio[13296]: info: ControllerMpd::getState Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand status Jan 25 22:35:39 muzak volumio[13296]: info: Jan 25 22:35:39 muzak volumio[13296]: ---------------------------- MPD announces state update: player Jan 25 22:35:39 muzak volumio[13296]: info: ControllerMpd::getState Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand status Jan 25 22:35:39 muzak volumio[13296]: info: Jan 25 22:35:39 muzak volumio[13296]: ---------------------------- MPD announces state update: player Jan 25 22:35:39 muzak volumio[13296]: info: ControllerMpd::getState Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand status Jan 25 22:35:39 muzak volumio[13296]: info: ------------------------------ 8ms Jan 25 22:35:39 muzak volumio[13296]: info: sendMpdCommand status took 5 milliseconds Jan 25 22:35:39 muzak volumio[13296]: info: sendMpdCommand status took 5 milliseconds Jan 25 22:35:39 muzak volumio[13296]: info: sendMpdCommand status took 2 milliseconds Jan 25 22:35:39 muzak volumio[13296]: info: sendMpdCommand status took 2 milliseconds Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::parseState Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::parseState Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::parseState Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::parseState Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 22:35:39 muzak volumio[13296]: info: Jan 25 22:35:39 muzak volumio[13296]: ---------------------------- MPD announces state update: player Jan 25 22:35:39 muzak volumio[13296]: info: ControllerMpd::getState Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand status Jan 25 22:35:39 muzak volumio[13296]: info: Jan 25 22:35:39 muzak volumio[13296]: ---------------------------- MPD announces state update: player Jan 25 22:35:39 muzak volumio[13296]: info: ControllerMpd::getState Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand status Jan 25 22:35:39 muzak volumio[13296]: info: sendMpdCommand playlistinfo took 5 milliseconds Jan 25 22:35:39 muzak volumio[13296]: info: sendMpdCommand playlistinfo took 4 milliseconds Jan 25 22:35:39 muzak volumio[13296]: info: sendMpdCommand playlistinfo took 4 milliseconds Jan 25 22:35:39 muzak volumio[13296]: info: sendMpdCommand playlistinfo took 5 milliseconds Jan 25 22:35:39 muzak volumio[13296]: info: sendMpdCommand status took 3 milliseconds Jan 25 22:35:39 muzak volumio[13296]: info: sendMpdCommand status took 2 milliseconds Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::parseTrackInfo Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::parseTrackInfo Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::parseTrackInfo Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::parseTrackInfo Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::parseState Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::parseState Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 22:35:39 muzak volumio[13296]: info: ControllerMpd::pushState Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::servicePushState Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:39 muzak volumio[13296]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":271,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"891 Kbps","isStreaming":false,"title":"Spite","artist":"Godflesh","album":"Pure","uri":"USB/MuZaK/Godflesh/Pure/01 Spite.flac","trackType":"flac"} Jan 25 22:35:39 muzak volumio[13296]: verbose: CURRENT POSITION 0 Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::syncState stateService play Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::syncState currentStatus stop Jan 25 22:35:39 muzak volumio[13296]: info: ControllerMpd::pushState Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::servicePushState Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:39 muzak volumio[13296]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":271,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"891 Kbps","isStreaming":false,"title":"Spite","artist":"Godflesh","album":"Pure","uri":"USB/MuZaK/Godflesh/Pure/01 Spite.flac","trackType":"flac"} Jan 25 22:35:39 muzak volumio[13296]: verbose: CURRENT POSITION 0 Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::syncState stateService play Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::syncState currentStatus play Jan 25 22:35:39 muzak volumio[13296]: info: Received an update from plugin. extracting info from payload Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:39 muzak volumio[13296]: info: ControllerMpd::pushState Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::servicePushState Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:39 muzak volumio[13296]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":271,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"872 Kbps","isStreaming":false,"title":"Spite","artist":"Godflesh","album":"Pure","uri":"USB/MuZaK/Godflesh/Pure/01 Spite.flac","trackType":"flac"} Jan 25 22:35:39 muzak volumio[13296]: verbose: CURRENT POSITION 0 Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::syncState stateService play Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::syncState currentStatus play Jan 25 22:35:39 muzak volumio[13296]: info: Received an update from plugin. extracting info from payload Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:39 muzak volumio[13296]: info: ControllerMpd::pushState Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::servicePushState Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:39 muzak volumio[13296]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":271,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"872 Kbps","isStreaming":false,"title":"Spite","artist":"Godflesh","album":"Pure","uri":"USB/MuZaK/Godflesh/Pure/01 Spite.flac","trackType":"flac"} Jan 25 22:35:39 muzak volumio[13296]: verbose: CURRENT POSITION 0 Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::syncState stateService play Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::syncState currentStatus play Jan 25 22:35:39 muzak volumio[13296]: info: Received an update from plugin. extracting info from payload Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:39 muzak volumio[13296]: info: ------------------------------ 31ms Jan 25 22:35:39 muzak volumio[13296]: info: ------------------------------ 63ms Jan 25 22:35:39 muzak volumio[13296]: info: ------------------------------ 59ms Jan 25 22:35:39 muzak volumio[13296]: info: ------------------------------ 59ms Jan 25 22:35:39 muzak volumio[13296]: info: sendMpdCommand playlistinfo took 52 milliseconds Jan 25 22:35:39 muzak volumio[13296]: info: sendMpdCommand playlistinfo took 52 milliseconds Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::parseTrackInfo Jan 25 22:35:39 muzak volumio[13296]: verbose: ControllerMpd::parseTrackInfo Jan 25 22:35:39 muzak volumio[13296]: info: ControllerMpd::pushState Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::servicePushState Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:39 muzak volumio[13296]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":271,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"872 Kbps","isStreaming":false,"title":"Spite","artist":"Godflesh","album":"Pure","uri":"USB/MuZaK/Godflesh/Pure/01 Spite.flac","trackType":"flac"} Jan 25 22:35:39 muzak volumio[13296]: verbose: CURRENT POSITION 0 Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::syncState stateService play Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::syncState currentStatus play Jan 25 22:35:39 muzak volumio[13296]: info: Received an update from plugin. extracting info from payload Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:39 muzak volumio[13296]: info: ControllerMpd::pushState Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::servicePushState Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:39 muzak volumio[13296]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":271,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"872 Kbps","isStreaming":false,"title":"Spite","artist":"Godflesh","album":"Pure","uri":"USB/MuZaK/Godflesh/Pure/01 Spite.flac","trackType":"flac"} Jan 25 22:35:39 muzak volumio[13296]: verbose: CURRENT POSITION 0 Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::syncState stateService play Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::syncState currentStatus play Jan 25 22:35:39 muzak volumio[13296]: info: Received an update from plugin. extracting info from payload Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:39 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:39 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:39 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:39 muzak volumio[13296]: info: ------------------------------ 88ms Jan 25 22:35:39 muzak volumio[13296]: info: ------------------------------ 87ms Jan 25 22:35:39 muzak volumio[13296]: info: [LastFM] Current track has sufficient metadata: title (Spite) and artist (Godflesh) passed on explicitly Jan 25 22:35:40 muzak volumio[13296]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"Spite","mbid":"2d1b1a48-51d7-3af6-a0a0-2179415b49ce","url":"https://www.last.fm/music/Godflesh/_/Spite","duration":"272000","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"23813","playcount":"104423","artist":{"name":"Godflesh","mbid":"864aa861-e22a-4187-8baa-2ef0c215bc0a","url":"https://www.last.fm/music/Godflesh"},"album":{"artist":"Godflesh","title":"Pure","url":"https://www.last.fm/music/Godflesh/Pure","image":[{"#":"https://lastfm.freetls.fastly.net/i/u/34s/a2766f699bb80c4ac73f69d3b259c1fa.png","@":{"size":"small"}},{"#":"https://lastfm.freetls.fastly.net/i/u/64s/a2766f699bb80c4ac73f69d3b259c1fa.png","@":{"size":"medium"}},{"#":"https://lastfm.freetls.fastly.net/i/u/174s/a2766f699bb80c4ac73f69d3b259c1fa.png","@":{"size":"large"}},{"#":"https://lastfm.freetls.fastly.net/i/u/300x300/a2766f699bb80c4ac73f69d3b259c1fa.png","@":{"size":"extralarge"}}]},"userplaycount":"14","userloved":"0","toptags":""}} Jan 25 22:35:40 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: randomizer , handleBrowseUri Jan 25 22:35:40 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jan 25 22:35:40 muzak volumio[13296]: info: CURURI: albums:// Jan 25 22:35:40 muzak volumio[13296]: info: listAlbums - loading Albums from cache Jan 25 22:35:40 muzak volumio[13296]: info: CoreCommandRouter::volumioClearQueue Jan 25 22:35:40 muzak volumio[13296]: info: CoreStateMachine::ClearQueue Jan 25 22:35:40 muzak volumio[13296]: info: CoreStateMachine::stop Jan 25 22:35:40 muzak volumio[13296]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 25 22:35:40 muzak volumio[13296]: info: CoreStateMachine::stPlaybackTimer Jan 25 22:35:40 muzak volumio[13296]: info: CoreStateMachine::updateTrackBlock Jan 25 22:35:40 muzak volumio[13296]: info: CorePlayQueue::getTrackBlock Jan 25 22:35:40 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:40 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:40 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 22:35:40 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:40 muzak volumio[13296]: info: CoreStateMachine::serviceStop Jan 25 22:35:40 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:40 muzak volumio[13296]: info: CoreCommandRouter::serviceStop Jan 25 22:35:40 muzak volumio[13296]: info: ControllerMpd::stop Jan 25 22:35:40 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand stop Jan 25 22:35:40 muzak volumio[13296]: info: CorePlayQueue::clearPlayQueue Jan 25 22:35:40 muzak volumio[13296]: info: CorePlayQueue::saveQueue Jan 25 22:35:40 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:40 muzak volumio[13296]: info: CoreCommandRouter::volumioPushQueue Jan 25 22:35:40 muzak volumio[13296]: info: CoreCommandRouter::volumioAddQueueItems Jan 25 22:35:40 muzak volumio[13296]: info: CoreStateMachine::addQueueItems Jan 25 22:35:40 muzak volumio[13296]: info: CorePlayQueue::addQueueItems Jan 25 22:35:40 muzak volumio[13296]: info: Preload queue cleared Jan 25 22:35:40 muzak volumio[13296]: info: Adding Item to queue: albums://Antichrist Siege Machine/Purifying Blade Jan 25 22:35:40 muzak volumio[13296]: info: Exploding uri albums://Antichrist Siege Machine/Purifying Blade in service mpd Jan 25 22:35:40 muzak volumio[13296]: info: Jan 25 22:35:40 muzak volumio[13296]: ---------------------------- MPD announces state update: player Jan 25 22:35:40 muzak volumio[13296]: info: sendMpdCommand stop took 25 milliseconds Jan 25 22:35:40 muzak volumio[13296]: info: ControllerMpd::getState Jan 25 22:35:40 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand status Jan 25 22:35:40 muzak volumio[13296]: info: CoreCommandRouter::volumioPushQueue Jan 25 22:35:40 muzak volumio[13296]: info: CorePlayQueue::saveQueue Jan 25 22:35:40 muzak volumio[13296]: info: CoreStateMachine::updateTrackBlock Jan 25 22:35:40 muzak volumio[13296]: info: CorePlayQueue::getTrackBlock Jan 25 22:35:40 muzak volumio[13296]: info: Jan 25 22:35:40 muzak volumio[13296]: ---------------------------- MPD announces state update: player Jan 25 22:35:40 muzak volumio[13296]: info: ControllerMpd::getState Jan 25 22:35:40 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand status Jan 25 22:35:40 muzak volumio[13296]: info: Jan 25 22:35:40 muzak volumio[13296]: ---------------------------- MPD announces state update: player Jan 25 22:35:40 muzak volumio[13296]: info: ControllerMpd::getState Jan 25 22:35:40 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand status Jan 25 22:35:40 muzak volumio[13296]: info: Preload queue cleared Jan 25 22:35:40 muzak volumio[13296]: info: Preload queue cleared Jan 25 22:35:40 muzak volumio[13296]: info: sendMpdCommand status took 23 milliseconds Jan 25 22:35:40 muzak volumio[13296]: info: sendMpdCommand status took 9 milliseconds Jan 25 22:35:40 muzak volumio[13296]: info: sendMpdCommand status took 9 milliseconds Jan 25 22:35:40 muzak volumio[13296]: verbose: ControllerMpd::parseState Jan 25 22:35:40 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 22:35:40 muzak volumio[13296]: verbose: ControllerMpd::parseState Jan 25 22:35:40 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 22:35:40 muzak volumio[13296]: verbose: ControllerMpd::parseState Jan 25 22:35:40 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 22:35:40 muzak volumio[13296]: info: sendMpdCommand playlistinfo took 2 milliseconds Jan 25 22:35:41 muzak volumio[13296]: info: sendMpdCommand playlistinfo took 3 milliseconds Jan 25 22:35:41 muzak volumio[13296]: info: sendMpdCommand playlistinfo took 2 milliseconds Jan 25 22:35:41 muzak volumio[13296]: verbose: ControllerMpd::parseTrackInfo Jan 25 22:35:41 muzak volumio[13296]: verbose: ControllerMpd::parseTrackInfo Jan 25 22:35:41 muzak volumio[13296]: verbose: ControllerMpd::parseTrackInfo Jan 25 22:35:41 muzak volumio[13296]: info: ControllerMpd::pushState Jan 25 22:35:41 muzak volumio[13296]: info: CoreCommandRouter::servicePushState Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:41 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:41 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 22:35:41 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:41 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:41 muzak volumio[13296]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Spite","artist":"Godflesh","album":"Pure","uri":"USB/MuZaK/Godflesh/Pure/01 Spite.flac","trackType":"flac"} Jan 25 22:35:41 muzak volumio[13296]: verbose: CURRENT POSITION 0 Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::syncState stateService stop Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::syncState currentStatus stop Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:41 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:41 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:41 muzak volumio[13296]: info: No code Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:41 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:41 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:41 muzak volumio[13296]: info: ControllerMpd::pushState Jan 25 22:35:41 muzak volumio[13296]: info: CoreCommandRouter::servicePushState Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:41 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:41 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:41 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:41 muzak volumio[13296]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Spite","artist":"Godflesh","album":"Pure","uri":"USB/MuZaK/Godflesh/Pure/01 Spite.flac","trackType":"flac"} Jan 25 22:35:41 muzak volumio[13296]: verbose: CURRENT POSITION 0 Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::syncState stateService stop Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::syncState currentStatus stop Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:41 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:41 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:41 muzak volumio[13296]: info: No code Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:41 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:41 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:41 muzak volumio[13296]: info: ControllerMpd::pushState Jan 25 22:35:41 muzak volumio[13296]: info: CoreCommandRouter::servicePushState Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:41 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:41 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:41 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:41 muzak volumio[13296]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Spite","artist":"Godflesh","album":"Pure","uri":"USB/MuZaK/Godflesh/Pure/01 Spite.flac","trackType":"flac"} Jan 25 22:35:41 muzak volumio[13296]: verbose: CURRENT POSITION 0 Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::syncState stateService stop Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::syncState currentStatus stop Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:41 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:41 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:41 muzak volumio[13296]: info: No code Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:41 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:41 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:41 muzak volumio[13296]: info: ------------------------------ 104ms Jan 25 22:35:41 muzak volumio[13296]: info: ------------------------------ 90ms Jan 25 22:35:41 muzak volumio[13296]: info: ------------------------------ 89ms Jan 25 22:35:41 muzak volumio[13296]: info: CoreCommandRouter::volumioPlay Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::play index 0 Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::stop Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::play index undefined Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 25 22:35:41 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::startPlaybackTimer Jan 25 22:35:41 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:41 muzak volumio[13296]: verbose: ControllerMpd::clearAddPlayTracks USB/MuZaK/Antichrist Siege Machine - Purifying Blade/01 Intro - The Way of Cain.flac Jan 25 22:35:41 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand stop Jan 25 22:35:41 muzak volumio[13296]: info: sendMpdCommand stop took 1 milliseconds Jan 25 22:35:41 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand clear Jan 25 22:35:41 muzak volumio[13296]: info: Jan 25 22:35:41 muzak volumio[13296]: ---------------------------- MPD announces system playlist update Jan 25 22:35:41 muzak volumio[13296]: info: Ignoring MPD Status Update Jan 25 22:35:41 muzak volumio[13296]: info: sendMpdCommand clear took 30 milliseconds Jan 25 22:35:41 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand add "USB/MuZaK/Antichrist Siege Machine - Purifying Blade/01 Intro - The Way of Cain.flac" Jan 25 22:35:41 muzak volumio[13296]: info: Jan 25 22:35:41 muzak volumio[13296]: ---------------------------- MPD announces system playlist update Jan 25 22:35:41 muzak volumio[13296]: info: Ignoring MPD Status Update Jan 25 22:35:41 muzak volumio[13296]: info: Jan 25 22:35:41 muzak volumio[13296]: ---------------------------- MPD announces system playlist update Jan 25 22:35:41 muzak volumio[13296]: info: Ignoring MPD Status Update Jan 25 22:35:41 muzak volumio[13296]: error: updateQueue error: null Jan 25 22:35:41 muzak volumio[13296]: info: Jan 25 22:35:41 muzak volumio[13296]: ---------------------------- MPD announces system playlist update Jan 25 22:35:41 muzak volumio[13296]: info: Ignoring MPD Status Update Jan 25 22:35:41 muzak volumio[13296]: info: ------------------------------ 5ms Jan 25 22:35:41 muzak volumio[13296]: info: sendMpdCommand add "USB/MuZaK/Antichrist Siege Machine - Purifying Blade/01 Intro - The Way of Cain.flac" took 5 milliseconds Jan 25 22:35:41 muzak volumio[13296]: info: ------------------------------ 3ms Jan 25 22:35:41 muzak volumio[13296]: info: ------------------------------ 2ms Jan 25 22:35:41 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand play Jan 25 22:35:41 muzak volumio[13296]: info: Jan 25 22:35:41 muzak volumio[13296]: ---------------------------- MPD announces system playlist update Jan 25 22:35:41 muzak volumio[13296]: info: Ignoring MPD Status Update Jan 25 22:35:41 muzak volumio[13296]: info: Jan 25 22:35:41 muzak volumio[13296]: ---------------------------- MPD announces system playlist update Jan 25 22:35:41 muzak volumio[13296]: info: Ignoring MPD Status Update Jan 25 22:35:41 muzak volumio[13296]: info: Jan 25 22:35:41 muzak volumio[13296]: ---------------------------- MPD announces state update: player Jan 25 22:35:41 muzak volumio[13296]: info: ------------------------------ 8ms Jan 25 22:35:41 muzak volumio[13296]: info: sendMpdCommand play took 7 milliseconds Jan 25 22:35:41 muzak volumio[13296]: info: ControllerMpd::getState Jan 25 22:35:41 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand status Jan 25 22:35:41 muzak volumio[13296]: info: Jan 25 22:35:41 muzak volumio[13296]: ---------------------------- MPD announces state update: player Jan 25 22:35:41 muzak volumio[13296]: info: ControllerMpd::getState Jan 25 22:35:41 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand status Jan 25 22:35:41 muzak volumio[13296]: info: Jan 25 22:35:41 muzak volumio[13296]: ---------------------------- MPD announces state update: player Jan 25 22:35:41 muzak volumio[13296]: info: ------------------------------ 6ms Jan 25 22:35:41 muzak volumio[13296]: info: ------------------------------ 4ms Jan 25 22:35:41 muzak volumio[13296]: info: sendMpdCommand status took 4 milliseconds Jan 25 22:35:41 muzak volumio[13296]: info: ControllerMpd::getState Jan 25 22:35:41 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand status Jan 25 22:35:41 muzak volumio[13296]: info: sendMpdCommand status took 2 milliseconds Jan 25 22:35:41 muzak volumio[13296]: verbose: ControllerMpd::parseState Jan 25 22:35:41 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 22:35:41 muzak volumio[13296]: verbose: ControllerMpd::parseState Jan 25 22:35:41 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 22:35:41 muzak volumio[13296]: info: Jan 25 22:35:41 muzak volumio[13296]: ---------------------------- MPD announces state update: player Jan 25 22:35:41 muzak volumio[13296]: info: ControllerMpd::getState Jan 25 22:35:41 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand status Jan 25 22:35:41 muzak volumio[13296]: info: Jan 25 22:35:41 muzak volumio[13296]: ---------------------------- MPD announces state update: player Jan 25 22:35:41 muzak volumio[13296]: info: ControllerMpd::getState Jan 25 22:35:41 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand status Jan 25 22:35:41 muzak volumio[13296]: info: sendMpdCommand status took 4 milliseconds Jan 25 22:35:41 muzak volumio[13296]: info: sendMpdCommand playlistinfo took 5 milliseconds Jan 25 22:35:41 muzak volumio[13296]: info: sendMpdCommand playlistinfo took 4 milliseconds Jan 25 22:35:41 muzak volumio[13296]: info: sendMpdCommand status took 2 milliseconds Jan 25 22:35:41 muzak volumio[13296]: info: sendMpdCommand status took 1 milliseconds Jan 25 22:35:41 muzak volumio[13296]: verbose: ControllerMpd::parseState Jan 25 22:35:41 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 22:35:41 muzak volumio[13296]: verbose: ControllerMpd::parseTrackInfo Jan 25 22:35:41 muzak volumio[13296]: verbose: ControllerMpd::parseTrackInfo Jan 25 22:35:41 muzak volumio[13296]: verbose: ControllerMpd::parseState Jan 25 22:35:41 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 22:35:41 muzak volumio[13296]: verbose: ControllerMpd::parseState Jan 25 22:35:41 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 22:35:41 muzak volumio[13296]: info: ControllerMpd::pushState Jan 25 22:35:41 muzak volumio[13296]: info: CoreCommandRouter::servicePushState Jan 25 22:35:41 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:41 muzak volumio[13296]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":79,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Intro - The Way of Cain","artist":"Antichrist Siege Machine","album":"Purifying Blade","uri":"USB/MuZaK/Antichrist Siege Machine - Purifying Blade/01 Intro - The Way of Cain.flac","trackType":"flac"} Jan 25 22:35:41 muzak volumio[13296]: verbose: CURRENT POSITION 0 Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::syncState stateService play Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::syncState currentStatus stop Jan 25 22:35:41 muzak volumio[13296]: info: ControllerMpd::pushState Jan 25 22:35:41 muzak volumio[13296]: info: CoreCommandRouter::servicePushState Jan 25 22:35:41 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:41 muzak volumio[13296]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":79,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"350 Kbps","isStreaming":false,"title":"Intro - The Way of Cain","artist":"Antichrist Siege Machine","album":"Purifying Blade","uri":"USB/MuZaK/Antichrist Siege Machine - Purifying Blade/01 Intro - The Way of Cain.flac","trackType":"flac"} Jan 25 22:35:41 muzak volumio[13296]: verbose: CURRENT POSITION 0 Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::syncState stateService play Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::syncState currentStatus play Jan 25 22:35:41 muzak volumio[13296]: info: Received an update from plugin. extracting info from payload Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:41 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:41 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 22:35:41 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:41 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:41 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:41 muzak volumio[13296]: info: ------------------------------ 24ms Jan 25 22:35:41 muzak volumio[13296]: info: ------------------------------ 39ms Jan 25 22:35:41 muzak volumio[13296]: info: Jan 25 22:35:41 muzak volumio[13296]: ---------------------------- MPD announces state update: player Jan 25 22:35:41 muzak volumio[13296]: info: ControllerMpd::getState Jan 25 22:35:41 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand status Jan 25 22:35:41 muzak volumio[13296]: info: sendMpdCommand playlistinfo took 32 milliseconds Jan 25 22:35:41 muzak volumio[13296]: info: sendMpdCommand playlistinfo took 33 milliseconds Jan 25 22:35:41 muzak volumio[13296]: info: sendMpdCommand playlistinfo took 33 milliseconds Jan 25 22:35:41 muzak volumio[13296]: info: sendMpdCommand status took 2 milliseconds Jan 25 22:35:41 muzak volumio[13296]: verbose: ControllerMpd::parseTrackInfo Jan 25 22:35:41 muzak volumio[13296]: verbose: ControllerMpd::parseTrackInfo Jan 25 22:35:41 muzak volumio[13296]: verbose: ControllerMpd::parseTrackInfo Jan 25 22:35:41 muzak volumio[13296]: verbose: ControllerMpd::parseState Jan 25 22:35:41 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 22:35:41 muzak volumio[13296]: info: ControllerMpd::pushState Jan 25 22:35:41 muzak volumio[13296]: info: CoreCommandRouter::servicePushState Jan 25 22:35:41 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:41 muzak volumio[13296]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":79,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"408 Kbps","isStreaming":false,"title":"Intro - The Way of Cain","artist":"Antichrist Siege Machine","album":"Purifying Blade","uri":"USB/MuZaK/Antichrist Siege Machine - Purifying Blade/01 Intro - The Way of Cain.flac","trackType":"flac"} Jan 25 22:35:41 muzak volumio[13296]: verbose: CURRENT POSITION 0 Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::syncState stateService play Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::syncState currentStatus play Jan 25 22:35:41 muzak volumio[13296]: info: Received an update from plugin. extracting info from payload Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:41 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:41 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:41 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:41 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:41 muzak volumio[13296]: info: ControllerMpd::pushState Jan 25 22:35:41 muzak volumio[13296]: info: CoreCommandRouter::servicePushState Jan 25 22:35:41 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:41 muzak volumio[13296]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":79,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"418 Kbps","isStreaming":false,"title":"Intro - The Way of Cain","artist":"Antichrist Siege Machine","album":"Purifying Blade","uri":"USB/MuZaK/Antichrist Siege Machine - Purifying Blade/01 Intro - The Way of Cain.flac","trackType":"flac"} Jan 25 22:35:41 muzak volumio[13296]: verbose: CURRENT POSITION 0 Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::syncState stateService play Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::syncState currentStatus play Jan 25 22:35:41 muzak volumio[13296]: info: Received an update from plugin. extracting info from payload Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:41 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:41 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:41 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:41 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:41 muzak volumio[13296]: info: ControllerMpd::pushState Jan 25 22:35:41 muzak volumio[13296]: info: CoreCommandRouter::servicePushState Jan 25 22:35:41 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:41 muzak volumio[13296]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":79,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"418 Kbps","isStreaming":false,"title":"Intro - The Way of Cain","artist":"Antichrist Siege Machine","album":"Purifying Blade","uri":"USB/MuZaK/Antichrist Siege Machine - Purifying Blade/01 Intro - The Way of Cain.flac","trackType":"flac"} Jan 25 22:35:41 muzak volumio[13296]: verbose: CURRENT POSITION 0 Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::syncState stateService play Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::syncState currentStatus play Jan 25 22:35:41 muzak volumio[13296]: info: Received an update from plugin. extracting info from payload Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:41 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:41 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:41 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:41 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:41 muzak volumio[13296]: info: ------------------------------ 98ms Jan 25 22:35:41 muzak volumio[13296]: info: ------------------------------ 95ms Jan 25 22:35:41 muzak volumio[13296]: info: ------------------------------ 95ms Jan 25 22:35:41 muzak volumio[13296]: info: [LastFM] Current track has sufficient metadata: title (Intro - The Way of Cain) and artist (Antichrist Siege Machine) passed on explicitly Jan 25 22:35:41 muzak volumio[13296]: info: sendMpdCommand playlistinfo took 83 milliseconds Jan 25 22:35:41 muzak volumio[13296]: verbose: ControllerMpd::parseTrackInfo Jan 25 22:35:41 muzak volumio[13296]: info: ControllerMpd::pushState Jan 25 22:35:41 muzak volumio[13296]: info: CoreCommandRouter::servicePushState Jan 25 22:35:41 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:41 muzak volumio[13296]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":79,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"418 Kbps","isStreaming":false,"title":"Intro - The Way of Cain","artist":"Antichrist Siege Machine","album":"Purifying Blade","uri":"USB/MuZaK/Antichrist Siege Machine - Purifying Blade/01 Intro - The Way of Cain.flac","trackType":"flac"} Jan 25 22:35:41 muzak volumio[13296]: verbose: CURRENT POSITION 0 Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::syncState stateService play Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::syncState currentStatus play Jan 25 22:35:41 muzak volumio[13296]: info: Received an update from plugin. extracting info from payload Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:41 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:41 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:41 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:41 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:41 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:41 muzak volumio[13296]: info: ------------------------------ 103ms Jan 25 22:35:41 muzak volumio[13296]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"Intro - The Way Of Cain","mbid":"5f0c3e34-504c-4e9c-8cce-4da0708309bd","url":"https://www.last.fm/music/Antichrist+Siege+Machine/_/Intro+-+The+Way+Of+Cain","duration":"78000","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"7104","playcount":"24435","artist":{"name":"Antichrist Siege Machine","mbid":"57f2bfc7-7e85-4c27-b6f5-44746198b338","url":"https://www.last.fm/music/Antichrist+Siege+Machine"},"album":{"artist":"Antichrist Siege Machine","title":"Purifying Blade","url":"https://www.last.fm/music/Antichrist+Siege+Machine/Purifying+Blade","image":[{"#":"https://lastfm.freetls.fastly.net/i/u/34s/598500e8c239b415238b73d57577201d.png","@":{"size":"small"}},{"#":"https://lastfm.freetls.fastly.net/i/u/64s/598500e8c239b415238b73d57577201d.png","@":{"size":"medium"}},{"#":"https://lastfm.freetls.fastly.net/i/u/174s/598500e8c239b415238b73d57577201d.png","@":{"size":"large"}},{"#":"https://lastfm.freetls.fastly.net/i/u/300x300/598500e8c239b415238b73d57577201d.png","@":{"size":"extralarge"}}]},"userplaycount":"1","userloved":"0","toptags":""}} Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: randomizer , handleBrowseUri Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jan 25 22:35:42 muzak volumio[13296]: info: CURURI: albums:// Jan 25 22:35:42 muzak volumio[13296]: info: listAlbums - loading Albums from cache Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::volumioClearQueue Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::ClearQueue Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::stop Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::stPlaybackTimer Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::updateTrackBlock Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::getTrackBlock Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::serviceStop Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::serviceStop Jan 25 22:35:42 muzak volumio[13296]: info: ControllerMpd::stop Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand stop Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::clearPlayQueue Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::saveQueue Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::volumioPushQueue Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::volumioAddQueueItems Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::addQueueItems Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::addQueueItems Jan 25 22:35:42 muzak volumio[13296]: info: Preload queue cleared Jan 25 22:35:42 muzak volumio[13296]: info: Adding Item to queue: albums://Jesu/Jesu (The Released Picture Disc Mix) Jan 25 22:35:42 muzak volumio[13296]: info: Exploding uri albums://Jesu/Jesu (The Released Picture Disc Mix) in service mpd Jan 25 22:35:42 muzak volumio[13296]: info: Preload queue cleared Jan 25 22:35:42 muzak volumio[13296]: info: Jan 25 22:35:42 muzak volumio[13296]: ---------------------------- MPD announces state update: player Jan 25 22:35:42 muzak volumio[13296]: info: sendMpdCommand stop took 24 milliseconds Jan 25 22:35:42 muzak volumio[13296]: info: ControllerMpd::getState Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand status Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::volumioPushQueue Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::saveQueue Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::updateTrackBlock Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::getTrackBlock Jan 25 22:35:42 muzak volumio[13296]: info: Preload queue cleared Jan 25 22:35:42 muzak volumio[13296]: info: sendMpdCommand status took 16 milliseconds Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::parseState Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 22:35:42 muzak volumio[13296]: info: Jan 25 22:35:42 muzak volumio[13296]: ---------------------------- MPD announces state update: player Jan 25 22:35:42 muzak volumio[13296]: info: ControllerMpd::getState Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand status Jan 25 22:35:42 muzak volumio[13296]: info: Jan 25 22:35:42 muzak volumio[13296]: ---------------------------- MPD announces state update: player Jan 25 22:35:42 muzak volumio[13296]: info: ControllerMpd::getState Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand status Jan 25 22:35:42 muzak volumio[13296]: info: sendMpdCommand playlistinfo took 5 milliseconds Jan 25 22:35:42 muzak volumio[13296]: info: sendMpdCommand status took 4 milliseconds Jan 25 22:35:42 muzak volumio[13296]: info: sendMpdCommand status took 3 milliseconds Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::parseTrackInfo Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::parseState Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::parseState Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 22:35:42 muzak volumio[13296]: info: ControllerMpd::pushState Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::servicePushState Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:42 muzak volumio[13296]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Intro - The Way of Cain","artist":"Antichrist Siege Machine","album":"Purifying Blade","uri":"USB/MuZaK/Antichrist Siege Machine - Purifying Blade/01 Intro - The Way of Cain.flac","trackType":"flac"} Jan 25 22:35:42 muzak volumio[13296]: verbose: CURRENT POSITION 0 Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::syncState stateService stop Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::syncState currentStatus stop Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:42 muzak volumio[13296]: info: No code Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:42 muzak volumio[13296]: info: ------------------------------ 44ms Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::volumioPlay Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::play index 0 Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::stop Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::play index undefined Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::startPlaybackTimer Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::clearAddPlayTracks USB/MuZaK/Jesu/Jesu/01. Your Path To Divinity (Picture Disc Mix).flac Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand stop Jan 25 22:35:42 muzak volumio[13296]: info: sendMpdCommand playlistinfo took 25 milliseconds Jan 25 22:35:42 muzak volumio[13296]: info: sendMpdCommand playlistinfo took 25 milliseconds Jan 25 22:35:42 muzak volumio[13296]: info: sendMpdCommand stop took 2 milliseconds Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::parseTrackInfo Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::parseTrackInfo Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand clear Jan 25 22:35:42 muzak volumio[13296]: info: ControllerMpd::pushState Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::servicePushState Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:42 muzak volumio[13296]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Intro - The Way of Cain","artist":"Antichrist Siege Machine","album":"Purifying Blade","uri":"USB/MuZaK/Antichrist Siege Machine - Purifying Blade/01 Intro - The Way of Cain.flac","trackType":"flac"} Jan 25 22:35:42 muzak volumio[13296]: verbose: CURRENT POSITION 0 Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::syncState stateService stop Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::syncState currentStatus stop Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:42 muzak volumio[13296]: info: No code Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:42 muzak volumio[13296]: info: ControllerMpd::pushState Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::servicePushState Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:42 muzak volumio[13296]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Intro - The Way of Cain","artist":"Antichrist Siege Machine","album":"Purifying Blade","uri":"USB/MuZaK/Antichrist Siege Machine - Purifying Blade/01 Intro - The Way of Cain.flac","trackType":"flac"} Jan 25 22:35:42 muzak volumio[13296]: verbose: CURRENT POSITION 0 Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::syncState stateService stop Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::syncState currentStatus stop Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:42 muzak volumio[13296]: info: No code Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:42 muzak volumio[13296]: info: ------------------------------ 81ms Jan 25 22:35:42 muzak volumio[13296]: info: ------------------------------ 82ms Jan 25 22:35:42 muzak volumio[13296]: info: Jan 25 22:35:42 muzak volumio[13296]: ---------------------------- MPD announces system playlist update Jan 25 22:35:42 muzak volumio[13296]: info: Ignoring MPD Status Update Jan 25 22:35:42 muzak volumio[13296]: info: sendMpdCommand clear took 84 milliseconds Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand add "USB/MuZaK/Jesu/Jesu/01. Your Path To Divinity (Picture Disc Mix).flac" Jan 25 22:35:42 muzak volumio[13296]: info: Jan 25 22:35:42 muzak volumio[13296]: ---------------------------- MPD announces system playlist update Jan 25 22:35:42 muzak volumio[13296]: info: Ignoring MPD Status Update Jan 25 22:35:42 muzak volumio[13296]: info: Jan 25 22:35:42 muzak volumio[13296]: ---------------------------- MPD announces system playlist update Jan 25 22:35:42 muzak volumio[13296]: info: Ignoring MPD Status Update Jan 25 22:35:42 muzak volumio[13296]: error: updateQueue error: null Jan 25 22:35:42 muzak volumio[13296]: info: Jan 25 22:35:42 muzak volumio[13296]: ---------------------------- MPD announces system playlist update Jan 25 22:35:42 muzak volumio[13296]: info: Ignoring MPD Status Update Jan 25 22:35:42 muzak volumio[13296]: info: ------------------------------ 4ms Jan 25 22:35:42 muzak volumio[13296]: info: sendMpdCommand add "USB/MuZaK/Jesu/Jesu/01. Your Path To Divinity (Picture Disc Mix).flac" took 4 milliseconds Jan 25 22:35:42 muzak volumio[13296]: info: ------------------------------ 3ms Jan 25 22:35:42 muzak volumio[13296]: info: ------------------------------ 3ms Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand play Jan 25 22:35:42 muzak volumio[13296]: info: Jan 25 22:35:42 muzak volumio[13296]: ---------------------------- MPD announces system playlist update Jan 25 22:35:42 muzak volumio[13296]: info: Ignoring MPD Status Update Jan 25 22:35:42 muzak volumio[13296]: info: Jan 25 22:35:42 muzak volumio[13296]: ---------------------------- MPD announces system playlist update Jan 25 22:35:42 muzak volumio[13296]: info: Ignoring MPD Status Update Jan 25 22:35:42 muzak volumio[13296]: info: Jan 25 22:35:42 muzak volumio[13296]: ---------------------------- MPD announces state update: player Jan 25 22:35:42 muzak volumio[13296]: info: ------------------------------ 7ms Jan 25 22:35:42 muzak volumio[13296]: info: sendMpdCommand play took 6 milliseconds Jan 25 22:35:42 muzak volumio[13296]: info: ControllerMpd::getState Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand status Jan 25 22:35:42 muzak volumio[13296]: info: ------------------------------ 4ms Jan 25 22:35:42 muzak volumio[13296]: info: ------------------------------ 3ms Jan 25 22:35:42 muzak volumio[13296]: info: Jan 25 22:35:42 muzak volumio[13296]: ---------------------------- MPD announces state update: player Jan 25 22:35:42 muzak volumio[13296]: info: ControllerMpd::getState Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand status Jan 25 22:35:42 muzak volumio[13296]: info: Jan 25 22:35:42 muzak volumio[13296]: ---------------------------- MPD announces state update: player Jan 25 22:35:42 muzak volumio[13296]: info: ControllerMpd::getState Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand status Jan 25 22:35:42 muzak volumio[13296]: info: Jan 25 22:35:42 muzak volumio[13296]: ---------------------------- MPD announces state update: player Jan 25 22:35:42 muzak volumio[13296]: info: ControllerMpd::getState Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand status Jan 25 22:35:42 muzak volumio[13296]: info: sendMpdCommand status took 5 milliseconds Jan 25 22:35:42 muzak volumio[13296]: info: sendMpdCommand status took 2 milliseconds Jan 25 22:35:42 muzak volumio[13296]: info: sendMpdCommand status took 2 milliseconds Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::parseState Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::parseState Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::parseState Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 22:35:42 muzak volumio[13296]: info: Jan 25 22:35:42 muzak volumio[13296]: ---------------------------- MPD announces state update: player Jan 25 22:35:42 muzak volumio[13296]: info: ControllerMpd::getState Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand status Jan 25 22:35:42 muzak volumio[13296]: info: Jan 25 22:35:42 muzak volumio[13296]: ---------------------------- MPD announces state update: player Jan 25 22:35:42 muzak volumio[13296]: info: ControllerMpd::getState Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand status Jan 25 22:35:42 muzak volumio[13296]: info: sendMpdCommand status took 5 milliseconds Jan 25 22:35:42 muzak volumio[13296]: info: sendMpdCommand playlistinfo took 5 milliseconds Jan 25 22:35:42 muzak volumio[13296]: info: sendMpdCommand playlistinfo took 5 milliseconds Jan 25 22:35:42 muzak volumio[13296]: info: sendMpdCommand playlistinfo took 5 milliseconds Jan 25 22:35:42 muzak volumio[13296]: info: sendMpdCommand status took 3 milliseconds Jan 25 22:35:42 muzak volumio[13296]: info: sendMpdCommand status took 2 milliseconds Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::parseState Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::parseTrackInfo Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::parseTrackInfo Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::parseTrackInfo Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::parseState Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::parseState Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 22:35:42 muzak volumio[13296]: info: ControllerMpd::pushState Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::servicePushState Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:42 muzak volumio[13296]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":558,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Your Path To Divinity (Picture Disc Mix)","artist":"Jesu","album":"Jesu (The Released Picture Disc Mix)","uri":"USB/MuZaK/Jesu/Jesu/01. Your Path To Divinity (Picture Disc Mix).flac","trackType":"flac"} Jan 25 22:35:42 muzak volumio[13296]: verbose: CURRENT POSITION 0 Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::syncState stateService play Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::syncState currentStatus stop Jan 25 22:35:42 muzak volumio[13296]: info: ControllerMpd::pushState Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::servicePushState Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:42 muzak volumio[13296]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":558,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"694 Kbps","isStreaming":false,"title":"Your Path To Divinity (Picture Disc Mix)","artist":"Jesu","album":"Jesu (The Released Picture Disc Mix)","uri":"USB/MuZaK/Jesu/Jesu/01. Your Path To Divinity (Picture Disc Mix).flac","trackType":"flac"} Jan 25 22:35:42 muzak volumio[13296]: verbose: CURRENT POSITION 0 Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::syncState stateService play Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::syncState currentStatus play Jan 25 22:35:42 muzak volumio[13296]: info: Received an update from plugin. extracting info from payload Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:42 muzak volumio[13296]: info: ControllerMpd::pushState Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::servicePushState Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:42 muzak volumio[13296]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":558,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"694 Kbps","isStreaming":false,"title":"Your Path To Divinity (Picture Disc Mix)","artist":"Jesu","album":"Jesu (The Released Picture Disc Mix)","uri":"USB/MuZaK/Jesu/Jesu/01. Your Path To Divinity (Picture Disc Mix).flac","trackType":"flac"} Jan 25 22:35:42 muzak volumio[13296]: verbose: CURRENT POSITION 0 Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::syncState stateService play Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::syncState currentStatus play Jan 25 22:35:42 muzak volumio[13296]: info: Received an update from plugin. extracting info from payload Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:42 muzak volumio[13296]: info: ------------------------------ 25ms Jan 25 22:35:42 muzak volumio[13296]: info: ------------------------------ 42ms Jan 25 22:35:42 muzak volumio[13296]: info: ------------------------------ 42ms Jan 25 22:35:42 muzak volumio[13296]: info: sendMpdCommand playlistinfo took 34 milliseconds Jan 25 22:35:42 muzak volumio[13296]: info: sendMpdCommand playlistinfo took 35 milliseconds Jan 25 22:35:42 muzak volumio[13296]: info: sendMpdCommand playlistinfo took 34 milliseconds Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::parseTrackInfo Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::parseTrackInfo Jan 25 22:35:42 muzak volumio[13296]: verbose: ControllerMpd::parseTrackInfo Jan 25 22:35:42 muzak volumio[13296]: info: ControllerMpd::pushState Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::servicePushState Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:42 muzak volumio[13296]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":558,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"694 Kbps","isStreaming":false,"title":"Your Path To Divinity (Picture Disc Mix)","artist":"Jesu","album":"Jesu (The Released Picture Disc Mix)","uri":"USB/MuZaK/Jesu/Jesu/01. Your Path To Divinity (Picture Disc Mix).flac","trackType":"flac"} Jan 25 22:35:42 muzak volumio[13296]: verbose: CURRENT POSITION 0 Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::syncState stateService play Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::syncState currentStatus play Jan 25 22:35:42 muzak volumio[13296]: info: Received an update from plugin. extracting info from payload Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:42 muzak volumio[13296]: info: ControllerMpd::pushState Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::servicePushState Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:42 muzak volumio[13296]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":558,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"694 Kbps","isStreaming":false,"title":"Your Path To Divinity (Picture Disc Mix)","artist":"Jesu","album":"Jesu (The Released Picture Disc Mix)","uri":"USB/MuZaK/Jesu/Jesu/01. Your Path To Divinity (Picture Disc Mix).flac","trackType":"flac"} Jan 25 22:35:42 muzak volumio[13296]: verbose: CURRENT POSITION 0 Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::syncState stateService play Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::syncState currentStatus play Jan 25 22:35:42 muzak volumio[13296]: info: Received an update from plugin. extracting info from payload Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:42 muzak volumio[13296]: info: ControllerMpd::pushState Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::servicePushState Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:42 muzak volumio[13296]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":558,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"694 Kbps","isStreaming":false,"title":"Your Path To Divinity (Picture Disc Mix)","artist":"Jesu","album":"Jesu (The Released Picture Disc Mix)","uri":"USB/MuZaK/Jesu/Jesu/01. Your Path To Divinity (Picture Disc Mix).flac","trackType":"flac"} Jan 25 22:35:42 muzak volumio[13296]: verbose: CURRENT POSITION 0 Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::syncState stateService play Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::syncState currentStatus play Jan 25 22:35:42 muzak volumio[13296]: info: Received an update from plugin. extracting info from payload Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:42 muzak volumio[13296]: info: CoreStateMachine::pushState Jan 25 22:35:42 muzak volumio[13296]: info: CorePlayQueue::getTrack 0 Jan 25 22:35:42 muzak volumio[13296]: info: CoreCommandRouter::volumioPushState Jan 25 22:35:42 muzak volumio[13296]: info: ------------------------------ 82ms Jan 25 22:35:42 muzak volumio[13296]: info: ------------------------------ 78ms Jan 25 22:35:42 muzak volumio[13296]: info: ------------------------------ 78ms Jan 25 22:35:42 muzak volumio[13296]: info: [LastFM] Current track has sufficient metadata: title (Your Path To Divinity (Picture Disc Mix)) and artist (Jesu) passed on explicitly Jan 25 22:35:42 muzak volumio[13296]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"Your Path To Divinity (Picture Disc Mix)","url":"https://www.last.fm/music/Jesu/_/Your+Path+To+Divinity+(Picture+Disc+Mix)","duration":"555000","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"947","playcount":"2588","artist":{"name":"Jesu","mbid":"ae69d81f-552d-4013-8dfc-4778d8f38742","url":"https://www.last.fm/music/Jesu"},"album":{"artist":"Jesu","title":"Jesu (The Released Picture Disc Mix)","url":"https://www.last.fm/music/Jesu/Jesu+(The+Released+Picture+Disc+Mix)","image":[{"#":"https://lastfm.freetls.fastly.net/i/u/34s/e2a40d6229e88b63a20951fa15cdcf95.png","@":{"size":"small"}},{"#":"https://lastfm.freetls.fastly.net/i/u/64s/e2a40d6229e88b63a20951fa15cdcf95.png","@":{"size":"medium"}},{"#":"https://lastfm.freetls.fastly.net/i/u/174s/e2a40d6229e88b63a20951fa15cdcf95.png","@":{"size":"large"}},{"#":"https://lastfm.freetls.fastly.net/i/u/300x300/e2a40d6229e88b63a20951fa15cdcf95.png","@":{"size":"extralarge"}}]},"userplaycount":"4","userloved":"0","toptags":""}} Jan 25 22:35:43 muzak volumio[13296]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 25 22:35:43 muzak volumio[13296]: TypeError: Cannot read properties of null (reading '@') Jan 25 22:35:43 muzak volumio[13296]: at Object.callback (/data/plugins/user_interface/lastfm/node_modules/simple-lastfm/lib/index.js:342:14) Jan 25 22:35:43 muzak volumio[13296]: at /data/plugins/user_interface/lastfm/node_modules/simple-lastfm/lib/index.js:60:13 Jan 25 22:35:43 muzak volumio[13296]: at Parser. (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:318:18) Jan 25 22:35:43 muzak volumio[13296]: at Parser.emit (node:events:514:28) Jan 25 22:35:43 muzak volumio[13296]: at exports.Parser.Parser.parseString (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:328:16) Jan 25 22:35:43 muzak volumio[13296]: at Parser.parseString (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:5:59) Jan 25 22:35:43 muzak volumio[13296]: at IncomingMessage. (/data/plugins/user_interface/lastfm/node_modules/simple-lastfm/lib/index.js:58:14) Jan 25 22:35:43 muzak volumio[13296]: at IncomingMessage.emit (node:events:526:35) Jan 25 22:35:43 muzak volumio[13296]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 25 22:35:43 muzak volumio[13296]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) Jan 25 22:35:43 muzak volumio[13296]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 25 22:35:44 muzak sudo[16503]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-25 22:34' Jan 25 22:35:44 muzak sudo[16503]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"