Dec 05 09:14:00 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:14:00 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:00 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:14:00 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:14:00 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:14:02 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:14:02 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:02 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:14:02 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:14:02 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:14:03 volumio-test volumio[1167]: info: CoreCommandRouter::volumioReplaceandPlayItems Dec 05 09:14:03 volumio-test volumio[1167]: info: CoreStateMachine::ClearQueue Dec 05 09:14:03 volumio-test volumio[1167]: info: CoreStateMachine::stop Dec 05 09:14:03 volumio-test volumio[1167]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 05 09:14:03 volumio-test volumio[1167]: info: CorePlayQueue::clearPlayQueue Dec 05 09:14:03 volumio-test volumio[1167]: info: CorePlayQueue::saveQueue Dec 05 09:14:03 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushQueue Dec 05 09:14:03 volumio-test volumio[1167]: info: CoreStateMachine::addQueueItems Dec 05 09:14:03 volumio-test volumio[1167]: info: CorePlayQueue::addQueueItems Dec 05 09:14:03 volumio-test volumio[1167]: info: Preload queue cleared Dec 05 09:14:03 volumio-test volumio[1167]: info: Adding Item to queue: radio/tunein/local Dec 05 09:14:03 volumio-test volumio[1167]: info: Using cached record of: radio/tunein/local Dec 05 09:14:03 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushQueue Dec 05 09:14:03 volumio-test volumio[1167]: info: CorePlayQueue::saveQueue Dec 05 09:14:03 volumio-test volumio[1167]: info: CoreStateMachine::updateTrackBlock Dec 05 09:14:03 volumio-test volumio[1167]: info: CorePlayQueue::getTrackBlock Dec 05 09:14:03 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPlay Dec 05 09:14:03 volumio-test volumio[1167]: info: CoreStateMachine::play index 0 Dec 05 09:14:03 volumio-test volumio[1167]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 05 09:14:03 volumio-test volumio[1167]: info: CoreStateMachine::stop Dec 05 09:14:03 volumio-test volumio[1167]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 05 09:14:03 volumio-test volumio[1167]: info: CoreStateMachine::play index undefined Dec 05 09:14:03 volumio-test volumio[1167]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 05 09:14:03 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:03 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:14:03 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:04 volumio-test go-librespot[16922]: time="2025-12-05T09:14:04-07:00" level=trace msg="sent dealer ping" Dec 05 09:14:04 volumio-test go-librespot[16922]: time="2025-12-05T09:14:04-07:00" level=trace msg="received dealer pong" Dec 05 09:14:04 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:14:04 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:04 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:14:04 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:14:04 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:14:06 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:14:06 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:06 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:14:06 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:14:06 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:14:08 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:14:08 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:08 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:14:08 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:14:08 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:14:10 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:14:10 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:10 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:14:10 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:14:10 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:14:10 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:14:10 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:12 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:14:12 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:12 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:14:12 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:14:12 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:14:13 volumio-test volumio[1167]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Dec 05 09:14:13 volumio-test volumio[1167]: info: Preload queue cleared Dec 05 09:14:14 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:14:14 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:14 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:14:14 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:14:14 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:14:15 volumio-test volumio[1167]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Dec 05 09:14:16 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:14:16 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:16 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:14:16 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:14:16 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:14:18 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:14:18 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:18 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:14:18 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:14:18 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:14:20 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:14:20 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:20 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:14:20 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:14:20 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:14:22 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:14:22 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:22 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:14:22 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:14:22 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:14:24 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:14:24 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:24 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:14:24 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:14:24 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:14:26 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:14:26 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:26 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:14:26 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:14:26 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:14:28 volumio-test volumio[1167]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Dec 05 09:14:28 volumio-test volumio[1167]: info: TuneIn handleBrowseUri: tunein/local Dec 05 09:14:28 volumio-test volumio[1167]: info: Preload queue cleared Dec 05 09:14:28 volumio-test volumio[1167]: info: Preload queue cleared Dec 05 09:14:28 volumio-test volumio[1167]: info: Preload queue cleared Dec 05 09:14:28 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:14:28 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:28 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:14:28 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:14:28 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:14:29 volumio-test volumio[1167]: info: Preload queue cleared Dec 05 09:14:29 volumio-test volumio[1167]: info: CoreCommandRouter::volumioReplaceandPlayItems Dec 05 09:14:29 volumio-test volumio[1167]: info: CoreStateMachine::ClearQueue Dec 05 09:14:29 volumio-test volumio[1167]: info: CoreStateMachine::stop Dec 05 09:14:29 volumio-test volumio[1167]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 05 09:14:29 volumio-test volumio[1167]: info: CorePlayQueue::clearPlayQueue Dec 05 09:14:29 volumio-test volumio[1167]: info: CorePlayQueue::saveQueue Dec 05 09:14:29 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushQueue Dec 05 09:14:29 volumio-test volumio[1167]: info: CoreStateMachine::addQueueItems Dec 05 09:14:29 volumio-test volumio[1167]: info: CorePlayQueue::addQueueItems Dec 05 09:14:29 volumio-test volumio[1167]: info: Preload queue cleared Dec 05 09:14:29 volumio-test volumio[1167]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s34200 Dec 05 09:14:29 volumio-test volumio[1167]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Dec 05 09:14:30 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushQueue Dec 05 09:14:30 volumio-test volumio[1167]: info: CorePlayQueue::saveQueue Dec 05 09:14:30 volumio-test volumio[1167]: info: CoreStateMachine::updateTrackBlock Dec 05 09:14:30 volumio-test volumio[1167]: info: CorePlayQueue::getTrackBlock Dec 05 09:14:30 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPlay Dec 05 09:14:30 volumio-test volumio[1167]: info: CoreStateMachine::play index 0 Dec 05 09:14:30 volumio-test volumio[1167]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 05 09:14:30 volumio-test volumio[1167]: info: CoreStateMachine::stop Dec 05 09:14:30 volumio-test volumio[1167]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 05 09:14:30 volumio-test volumio[1167]: info: CoreStateMachine::play index undefined Dec 05 09:14:30 volumio-test volumio[1167]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 05 09:14:30 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:30 volumio-test volumio[1167]: info: CoreStateMachine::startPlaybackTimer Dec 05 09:14:30 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:30 volumio-test volumio[1167]: info: [1764951270092] ControllerWebradio::clearAddPlayTrack Dec 05 09:14:30 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand stop Dec 05 09:14:30 volumio-test volumio[1167]: info: sendMpdCommand stop took 6 milliseconds Dec 05 09:14:30 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand clear Dec 05 09:14:30 volumio-test volumio[1167]: info: Dec 05 09:14:30 volumio-test volumio[1167]: ---------------------------- MPD announces system playlist update Dec 05 09:14:30 volumio-test volumio[1167]: info: Ignoring MPD Status Update Dec 05 09:14:30 volumio-test volumio[1167]: info: sendMpdCommand clear took 2 milliseconds Dec 05 09:14:30 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand load "https://playerservices.streamtheworld.com/pls/KMXZFM.pls?DIST=TuneIn&TGT=TuneIn&maxServers=2&gdpr=0&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTc2NDk1MTI3MCwiaXNzIjoidGlzcnYifQ.1CD1v-l_v2A4TwKDDA_mQ-ZqHMHb4q2xxdtJeno80ww" Dec 05 09:14:30 volumio-test volumio[1167]: info: Dec 05 09:14:30 volumio-test volumio[1167]: ---------------------------- MPD announces system playlist update Dec 05 09:14:30 volumio-test volumio[1167]: info: Ignoring MPD Status Update Dec 05 09:14:30 volumio-test volumio[1167]: info: Dec 05 09:14:30 volumio-test volumio[1167]: ---------------------------- MPD announces system playlist update Dec 05 09:14:30 volumio-test volumio[1167]: info: Ignoring MPD Status Update Dec 05 09:14:30 volumio-test volumio[1167]: error: updateQueue error: null Dec 05 09:14:30 volumio-test volumio[1167]: info: ------------------------------ 4ms Dec 05 09:14:30 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:14:30 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:30 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:14:30 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:14:30 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:14:31 volumio-test volumio[1167]: info: sendMpdCommand load "https://playerservices.streamtheworld.com/pls/KMXZFM.pls?DIST=TuneIn&TGT=TuneIn&maxServers=2&gdpr=0&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTc2NDk1MTI3MCwiaXNzIjoidGlzcnYifQ.1CD1v-l_v2A4TwKDDA_mQ-ZqHMHb4q2xxdtJeno80ww" took 938 milliseconds Dec 05 09:14:31 volumio-test volumio[1167]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 05 09:14:31 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand play Dec 05 09:14:31 volumio-test volumio[1167]: info: Dec 05 09:14:31 volumio-test volumio[1167]: ---------------------------- MPD announces system playlist update Dec 05 09:14:31 volumio-test volumio[1167]: info: Ignoring MPD Status Update Dec 05 09:14:31 volumio-test volumio[1167]: info: ------------------------------ 940ms Dec 05 09:14:31 volumio-test volumio[1167]: info: ------------------------------ 939ms Dec 05 09:14:31 volumio-test volumio[1167]: info: Dec 05 09:14:31 volumio-test volumio[1167]: ---------------------------- MPD announces system playlist update Dec 05 09:14:31 volumio-test volumio[1167]: info: Ignoring MPD Status Update Dec 05 09:14:31 volumio-test volumio[1167]: info: Dec 05 09:14:31 volumio-test volumio[1167]: ---------------------------- MPD announces system playlist update Dec 05 09:14:31 volumio-test volumio[1167]: info: Ignoring MPD Status Update Dec 05 09:14:31 volumio-test volumio[1167]: info: sendMpdCommand play took 5 milliseconds Dec 05 09:14:31 volumio-test volumio[1167]: info: ------------------------------ 4ms Dec 05 09:14:31 volumio-test volumio[1167]: info: ------------------------------ 2ms Dec 05 09:14:31 volumio-test volumio[1167]: info: ------------------------------ 1ms Dec 05 09:14:32 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:14:32 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:14:32 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:14:32 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:14:32 volumio-test volumio[1167]: info: Dec 05 09:14:32 volumio-test volumio[1167]: ---------------------------- MPD announces state update: player Dec 05 09:14:32 volumio-test volumio[1167]: info: ControllerMpd::getState Dec 05 09:14:32 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 05 09:14:32 volumio-test volumio[1167]: info: Dec 05 09:14:32 volumio-test volumio[1167]: ---------------------------- MPD announces state update: player Dec 05 09:14:32 volumio-test volumio[1167]: info: ControllerMpd::getState Dec 05 09:14:32 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 05 09:14:32 volumio-test volumio[1167]: info: Dec 05 09:14:32 volumio-test volumio[1167]: ---------------------------- MPD announces state update: player Dec 05 09:14:32 volumio-test volumio[1167]: info: ControllerMpd::getState Dec 05 09:14:32 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 05 09:14:33 volumio-test volumio[1167]: info: sendMpdCommand status took 19 milliseconds Dec 05 09:14:33 volumio-test volumio[1167]: verbose: ControllerMpd::parseState Dec 05 09:14:33 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 05 09:14:33 volumio-test volumio[1167]: info: Dec 05 09:14:33 volumio-test volumio[1167]: ---------------------------- MPD announces state update: player Dec 05 09:14:33 volumio-test volumio[1167]: info: ControllerMpd::getState Dec 05 09:14:33 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 05 09:14:33 volumio-test volumio[1167]: info: Dec 05 09:14:33 volumio-test volumio[1167]: ---------------------------- MPD announces system playlist update Dec 05 09:14:33 volumio-test volumio[1167]: info: Ignoring MPD Status Update Dec 05 09:14:33 volumio-test volumio[1167]: info: Dec 05 09:14:33 volumio-test volumio[1167]: ---------------------------- MPD announces state update: player Dec 05 09:14:33 volumio-test volumio[1167]: info: ControllerMpd::getState Dec 05 09:14:33 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 05 09:14:33 volumio-test volumio[1167]: info: sendMpdCommand status took 22 milliseconds Dec 05 09:14:33 volumio-test volumio[1167]: info: sendMpdCommand status took 22 milliseconds Dec 05 09:14:33 volumio-test volumio[1167]: info: sendMpdCommand playlistinfo took 5 milliseconds Dec 05 09:14:33 volumio-test volumio[1167]: verbose: ControllerMpd::parseState Dec 05 09:14:33 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 05 09:14:33 volumio-test volumio[1167]: verbose: ControllerMpd::parseState Dec 05 09:14:33 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 05 09:14:33 volumio-test volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 05 09:14:33 volumio-test volumio[1167]: info: ControllerMpd::pushState Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreCommandRouter::servicePushState Dec 05 09:14:33 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:33 volumio-test volumio[1167]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"KMXZFM_SC?TGT=TuneIn&DIST=TuneIn&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTc2NDk1MTI3MCwiaXNzIjoidGlzcnYifQ.1CD1v-l_v2A4TwKDDA_mQ-ZqHMHb4q2xxdtJeno80ww&gdpr=0","artist":null,"album":null,"uri":"https://23023.live.streamtheworld.com:443/KMXZFM_SC?TGT=TuneIn&DIST=TuneIn&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTc2NDk1MTI3MCwiaXNzIjoidGlzcnYifQ.1CD1v-l_v2A4TwKDDA_mQ-ZqHMHb4q2xxdtJeno80ww&gdpr=0","trackType":""} Dec 05 09:14:33 volumio-test volumio[1167]: verbose: CURRENT POSITION 0 Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreStateMachine::syncState stateService play Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreStateMachine::syncState currentStatus stop Dec 05 09:14:33 volumio-test volumio[1167]: info: ------------------------------ 30ms Dec 05 09:14:33 volumio-test volumio[1167]: info: Dec 05 09:14:33 volumio-test volumio[1167]: ---------------------------- MPD announces system playlist update Dec 05 09:14:33 volumio-test volumio[1167]: info: Ignoring MPD Status Update Dec 05 09:14:33 volumio-test volumio[1167]: info: Dec 05 09:14:33 volumio-test volumio[1167]: ---------------------------- MPD announces system playlist update Dec 05 09:14:33 volumio-test volumio[1167]: info: Ignoring MPD Status Update Dec 05 09:14:33 volumio-test volumio[1167]: info: Dec 05 09:14:33 volumio-test volumio[1167]: ---------------------------- MPD announces state update: player Dec 05 09:14:33 volumio-test volumio[1167]: info: ControllerMpd::getState Dec 05 09:14:33 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 05 09:14:33 volumio-test volumio[1167]: info: sendMpdCommand status took 13 milliseconds Dec 05 09:14:33 volumio-test volumio[1167]: info: ------------------------------ 13ms Dec 05 09:14:33 volumio-test volumio[1167]: info: sendMpdCommand status took 12 milliseconds Dec 05 09:14:33 volumio-test volumio[1167]: info: sendMpdCommand playlistinfo took 10 milliseconds Dec 05 09:14:33 volumio-test volumio[1167]: info: sendMpdCommand playlistinfo took 9 milliseconds Dec 05 09:14:33 volumio-test volumio[1167]: info: ------------------------------ 7ms Dec 05 09:14:33 volumio-test volumio[1167]: info: ------------------------------ 5ms Dec 05 09:14:33 volumio-test volumio[1167]: info: sendMpdCommand status took 4 milliseconds Dec 05 09:14:33 volumio-test volumio[1167]: verbose: ControllerMpd::parseState Dec 05 09:14:33 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 05 09:14:33 volumio-test volumio[1167]: verbose: ControllerMpd::parseState Dec 05 09:14:33 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 05 09:14:33 volumio-test volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 05 09:14:33 volumio-test volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 05 09:14:33 volumio-test volumio[1167]: verbose: ControllerMpd::parseState Dec 05 09:14:33 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 05 09:14:33 volumio-test volumio[1167]: info: ControllerMpd::pushState Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreCommandRouter::servicePushState Dec 05 09:14:33 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:33 volumio-test volumio[1167]: verbose: STATE SERVICE {"status":"play","position":0,"seek":881,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"96 Kbps","isStreaming":false,"title":"KMXZFM_SC?TGT=TuneIn&DIST=TuneIn&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTc2NDk1MTI3MCwiaXNzIjoidGlzcnYifQ.1CD1v-l_v2A4TwKDDA_mQ-ZqHMHb4q2xxdtJeno80ww&gdpr=0","artist":null,"album":null,"uri":"https://23023.live.streamtheworld.com:443/KMXZFM_SC?TGT=TuneIn&DIST=TuneIn&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTc2NDk1MTI3MCwiaXNzIjoidGlzcnYifQ.1CD1v-l_v2A4TwKDDA_mQ-ZqHMHb4q2xxdtJeno80ww&gdpr=0","trackType":""} Dec 05 09:14:33 volumio-test volumio[1167]: verbose: CURRENT POSITION 0 Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreStateMachine::syncState stateService play Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreStateMachine::syncState currentStatus play Dec 05 09:14:33 volumio-test volumio[1167]: info: Received an update from plugin. extracting info from payload Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:33 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:33 volumio-test volumio[1167]: info: ControllerMpd::pushState Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreCommandRouter::servicePushState Dec 05 09:14:33 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:33 volumio-test volumio[1167]: verbose: STATE SERVICE {"status":"play","position":0,"seek":881,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"96 Kbps","isStreaming":false,"title":"KMXZFM_SC?TGT=TuneIn&DIST=TuneIn&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTc2NDk1MTI3MCwiaXNzIjoidGlzcnYifQ.1CD1v-l_v2A4TwKDDA_mQ-ZqHMHb4q2xxdtJeno80ww&gdpr=0","artist":null,"album":null,"uri":"https://23023.live.streamtheworld.com:443/KMXZFM_SC?TGT=TuneIn&DIST=TuneIn&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTc2NDk1MTI3MCwiaXNzIjoidGlzcnYifQ.1CD1v-l_v2A4TwKDDA_mQ-ZqHMHb4q2xxdtJeno80ww&gdpr=0","trackType":""} Dec 05 09:14:33 volumio-test volumio[1167]: verbose: CURRENT POSITION 0 Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreStateMachine::syncState stateService play Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreStateMachine::syncState currentStatus play Dec 05 09:14:33 volumio-test volumio[1167]: info: Received an update from plugin. extracting info from payload Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:33 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:33 volumio-test volumio[1167]: info: ------------------------------ 67ms Dec 05 09:14:33 volumio-test volumio[1167]: info: ------------------------------ 66ms Dec 05 09:14:33 volumio-test volumio[1167]: info: sendMpdCommand playlistinfo took 32 milliseconds Dec 05 09:14:33 volumio-test volumio[1167]: info: sendMpdCommand playlistinfo took 33 milliseconds Dec 05 09:14:33 volumio-test volumio[1167]: info: sendMpdCommand playlistinfo took 31 milliseconds Dec 05 09:14:33 volumio-test volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 05 09:14:33 volumio-test volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 05 09:14:33 volumio-test volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 05 09:14:33 volumio-test volumio[1167]: info: ControllerMpd::pushState Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreCommandRouter::servicePushState Dec 05 09:14:33 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:33 volumio-test volumio[1167]: verbose: STATE SERVICE {"status":"play","position":0,"seek":881,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"96 Kbps","isStreaming":false,"title":"KMXZFM_SC?TGT=TuneIn&DIST=TuneIn&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTc2NDk1MTI3MCwiaXNzIjoidGlzcnYifQ.1CD1v-l_v2A4TwKDDA_mQ-ZqHMHb4q2xxdtJeno80ww&gdpr=0","artist":null,"album":null,"uri":"https://23023.live.streamtheworld.com:443/KMXZFM_SC?TGT=TuneIn&DIST=TuneIn&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTc2NDk1MTI3MCwiaXNzIjoidGlzcnYifQ.1CD1v-l_v2A4TwKDDA_mQ-ZqHMHb4q2xxdtJeno80ww&gdpr=0","trackType":""} Dec 05 09:14:33 volumio-test volumio[1167]: verbose: CURRENT POSITION 0 Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreStateMachine::syncState stateService play Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreStateMachine::syncState currentStatus play Dec 05 09:14:33 volumio-test volumio[1167]: info: Received an update from plugin. extracting info from payload Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:33 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:33 volumio-test volumio[1167]: info: ControllerMpd::pushState Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreCommandRouter::servicePushState Dec 05 09:14:33 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:33 volumio-test volumio[1167]: verbose: STATE SERVICE {"status":"play","position":0,"seek":881,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"96 Kbps","isStreaming":false,"title":"KMXZFM_SC?TGT=TuneIn&DIST=TuneIn&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTc2NDk1MTI3MCwiaXNzIjoidGlzcnYifQ.1CD1v-l_v2A4TwKDDA_mQ-ZqHMHb4q2xxdtJeno80ww&gdpr=0","artist":null,"album":null,"uri":"https://23023.live.streamtheworld.com:443/KMXZFM_SC?TGT=TuneIn&DIST=TuneIn&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTc2NDk1MTI3MCwiaXNzIjoidGlzcnYifQ.1CD1v-l_v2A4TwKDDA_mQ-ZqHMHb4q2xxdtJeno80ww&gdpr=0","trackType":""} Dec 05 09:14:33 volumio-test volumio[1167]: verbose: CURRENT POSITION 0 Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreStateMachine::syncState stateService play Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreStateMachine::syncState currentStatus play Dec 05 09:14:33 volumio-test volumio[1167]: info: Received an update from plugin. extracting info from payload Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:33 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:33 volumio-test volumio[1167]: info: ControllerMpd::pushState Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreCommandRouter::servicePushState Dec 05 09:14:33 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:33 volumio-test volumio[1167]: verbose: STATE SERVICE {"status":"play","position":0,"seek":881,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"96 Kbps","isStreaming":false,"title":"KMXZFM_SC?TGT=TuneIn&DIST=TuneIn&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTc2NDk1MTI3MCwiaXNzIjoidGlzcnYifQ.1CD1v-l_v2A4TwKDDA_mQ-ZqHMHb4q2xxdtJeno80ww&gdpr=0","artist":null,"album":null,"uri":"https://23023.live.streamtheworld.com:443/KMXZFM_SC?TGT=TuneIn&DIST=TuneIn&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTc2NDk1MTI3MCwiaXNzIjoidGlzcnYifQ.1CD1v-l_v2A4TwKDDA_mQ-ZqHMHb4q2xxdtJeno80ww&gdpr=0","trackType":""} Dec 05 09:14:33 volumio-test volumio[1167]: verbose: CURRENT POSITION 0 Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreStateMachine::syncState stateService play Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreStateMachine::syncState currentStatus play Dec 05 09:14:33 volumio-test volumio[1167]: info: Received an update from plugin. extracting info from payload Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:33 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:33 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:33 volumio-test volumio[1167]: info: ------------------------------ 73ms Dec 05 09:14:33 volumio-test volumio[1167]: info: ------------------------------ 72ms Dec 05 09:14:33 volumio-test volumio[1167]: info: ------------------------------ 63ms Dec 05 09:14:33 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:33 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:33 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:33 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:33 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:33 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:33 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:33 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:33 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:33 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:33 volumio-test go-librespot[16922]: time="2025-12-05T09:14:33-07:00" level=trace msg="received accesspoint ping" Dec 05 09:14:33 volumio-test go-librespot[16922]: time="2025-12-05T09:14:33-07:00" level=trace msg="received accesspoint pong ack" Dec 05 09:14:34 volumio-test go-librespot[16922]: time="2025-12-05T09:14:34-07:00" level=trace msg="sent dealer ping" Dec 05 09:14:34 volumio-test go-librespot[16922]: time="2025-12-05T09:14:34-07:00" level=trace msg="received dealer pong" Dec 05 09:14:34 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:14:34 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:14:34 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:14:34 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:14:36 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:14:36 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:14:36 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:14:36 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:14:38 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:14:38 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:14:38 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:14:38 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:14:40 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:14:40 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:14:40 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:14:40 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:14:42 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:14:42 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:14:42 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:14:42 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:14:44 volumio-test volumio[1167]: info: Preload queue cleared Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreCommandRouter::volumioReplaceandPlayItems Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreStateMachine::ClearQueue Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreStateMachine::stop Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreStateMachine::stPlaybackTimer Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreStateMachine::updateTrackBlock Dec 05 09:14:44 volumio-test volumio[1167]: info: CorePlayQueue::getTrackBlock Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:44 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreStateMachine::serviceStop Dec 05 09:14:44 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreCommandRouter::serviceStop Dec 05 09:14:44 volumio-test volumio[1167]: info: [1764951284249] ControllerWebradio::stop Dec 05 09:14:44 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand stop Dec 05 09:14:44 volumio-test volumio[1167]: info: CorePlayQueue::clearPlayQueue Dec 05 09:14:44 volumio-test volumio[1167]: info: CorePlayQueue::saveQueue Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushQueue Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreStateMachine::addQueueItems Dec 05 09:14:44 volumio-test volumio[1167]: info: CorePlayQueue::addQueueItems Dec 05 09:14:44 volumio-test volumio[1167]: info: Preload queue cleared Dec 05 09:14:44 volumio-test volumio[1167]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s21022 Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Dec 05 09:14:44 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:44 volumio-test volumio[1167]: info: Dec 05 09:14:44 volumio-test volumio[1167]: ---------------------------- MPD announces state update: player Dec 05 09:14:44 volumio-test volumio[1167]: info: sendMpdCommand stop took 45 milliseconds Dec 05 09:14:44 volumio-test volumio[1167]: info: ControllerMpd::getState Dec 05 09:14:44 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 05 09:14:44 volumio-test volumio[1167]: info: Dec 05 09:14:44 volumio-test volumio[1167]: ---------------------------- MPD announces state update: player Dec 05 09:14:44 volumio-test volumio[1167]: info: ControllerMpd::getState Dec 05 09:14:44 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 05 09:14:44 volumio-test volumio[1167]: info: Dec 05 09:14:44 volumio-test volumio[1167]: ---------------------------- MPD announces state update: player Dec 05 09:14:44 volumio-test volumio[1167]: info: ControllerMpd::getState Dec 05 09:14:44 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 05 09:14:44 volumio-test volumio[1167]: info: sendMpdCommand status took 4 milliseconds Dec 05 09:14:44 volumio-test volumio[1167]: info: sendMpdCommand status took 3 milliseconds Dec 05 09:14:44 volumio-test volumio[1167]: info: sendMpdCommand status took 2 milliseconds Dec 05 09:14:44 volumio-test volumio[1167]: verbose: ControllerMpd::parseState Dec 05 09:14:44 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 05 09:14:44 volumio-test volumio[1167]: verbose: ControllerMpd::parseState Dec 05 09:14:44 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 05 09:14:44 volumio-test volumio[1167]: verbose: ControllerMpd::parseState Dec 05 09:14:44 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 05 09:14:44 volumio-test volumio[1167]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 05 09:14:44 volumio-test volumio[1167]: info: sendMpdCommand playlistinfo took 2 milliseconds Dec 05 09:14:44 volumio-test volumio[1167]: info: sendMpdCommand playlistinfo took 2 milliseconds Dec 05 09:14:44 volumio-test volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 05 09:14:44 volumio-test volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 05 09:14:44 volumio-test volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 05 09:14:44 volumio-test volumio[1167]: info: ControllerMpd::pushState Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreCommandRouter::servicePushState Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:44 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:44 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:44 volumio-test volumio[1167]: 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":"KMXZFM_SC?TGT=TuneIn&DIST=TuneIn&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTc2NDk1MTI3MCwiaXNzIjoidGlzcnYifQ.1CD1v-l_v2A4TwKDDA_mQ-ZqHMHb4q2xxdtJeno80ww&gdpr=0","artist":null,"album":null,"uri":"https://23023.live.streamtheworld.com:443/KMXZFM_SC?TGT=TuneIn&DIST=TuneIn&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTc2NDk1MTI3MCwiaXNzIjoidGlzcnYifQ.1CD1v-l_v2A4TwKDDA_mQ-ZqHMHb4q2xxdtJeno80ww&gdpr=0","trackType":""} Dec 05 09:14:44 volumio-test volumio[1167]: verbose: CURRENT POSITION 0 Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreStateMachine::syncState stateService stop Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreStateMachine::syncState currentStatus stop Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:44 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:44 volumio-test volumio[1167]: info: No code Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:44 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:44 volumio-test volumio[1167]: info: ControllerMpd::pushState Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreCommandRouter::servicePushState Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:44 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:44 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:44 volumio-test volumio[1167]: 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":"KMXZFM_SC?TGT=TuneIn&DIST=TuneIn&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTc2NDk1MTI3MCwiaXNzIjoidGlzcnYifQ.1CD1v-l_v2A4TwKDDA_mQ-ZqHMHb4q2xxdtJeno80ww&gdpr=0","artist":null,"album":null,"uri":"https://23023.live.streamtheworld.com:443/KMXZFM_SC?TGT=TuneIn&DIST=TuneIn&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTc2NDk1MTI3MCwiaXNzIjoidGlzcnYifQ.1CD1v-l_v2A4TwKDDA_mQ-ZqHMHb4q2xxdtJeno80ww&gdpr=0","trackType":""} Dec 05 09:14:44 volumio-test volumio[1167]: verbose: CURRENT POSITION 0 Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreStateMachine::syncState stateService stop Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreStateMachine::syncState currentStatus stop Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:44 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:44 volumio-test volumio[1167]: info: No code Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:44 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:44 volumio-test volumio[1167]: info: ControllerMpd::pushState Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreCommandRouter::servicePushState Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:44 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:44 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:44 volumio-test volumio[1167]: 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":"KMXZFM_SC?TGT=TuneIn&DIST=TuneIn&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTc2NDk1MTI3MCwiaXNzIjoidGlzcnYifQ.1CD1v-l_v2A4TwKDDA_mQ-ZqHMHb4q2xxdtJeno80ww&gdpr=0","artist":null,"album":null,"uri":"https://23023.live.streamtheworld.com:443/KMXZFM_SC?TGT=TuneIn&DIST=TuneIn&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTc2NDk1MTI3MCwiaXNzIjoidGlzcnYifQ.1CD1v-l_v2A4TwKDDA_mQ-ZqHMHb4q2xxdtJeno80ww&gdpr=0","trackType":""} Dec 05 09:14:44 volumio-test volumio[1167]: verbose: CURRENT POSITION 0 Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreStateMachine::syncState stateService stop Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreStateMachine::syncState currentStatus stop Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:44 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:44 volumio-test volumio[1167]: info: No code Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:44 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:44 volumio-test volumio[1167]: info: ------------------------------ 38ms Dec 05 09:14:44 volumio-test volumio[1167]: info: ------------------------------ 37ms Dec 05 09:14:44 volumio-test volumio[1167]: info: ------------------------------ 37ms Dec 05 09:14:44 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:44 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:44 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:44 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:44 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:44 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:44 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:44 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:44 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushQueue Dec 05 09:14:44 volumio-test volumio[1167]: info: CorePlayQueue::saveQueue Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreStateMachine::updateTrackBlock Dec 05 09:14:44 volumio-test volumio[1167]: info: CorePlayQueue::getTrackBlock Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPlay Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreStateMachine::play index 0 Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreStateMachine::stop Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreStateMachine::play index undefined Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 05 09:14:44 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreStateMachine::startPlaybackTimer Dec 05 09:14:44 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:44 volumio-test volumio[1167]: info: [1764951284461] ControllerWebradio::clearAddPlayTrack Dec 05 09:14:44 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand stop Dec 05 09:14:44 volumio-test volumio[1167]: info: sendMpdCommand stop took 2 milliseconds Dec 05 09:14:44 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand clear Dec 05 09:14:44 volumio-test volumio[1167]: info: Dec 05 09:14:44 volumio-test volumio[1167]: ---------------------------- MPD announces system playlist update Dec 05 09:14:44 volumio-test volumio[1167]: info: Ignoring MPD Status Update Dec 05 09:14:44 volumio-test volumio[1167]: info: sendMpdCommand clear took 1 milliseconds Dec 05 09:14:44 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand load "http://kjzz.streamguys1.com/kjzz_mp3_128" Dec 05 09:14:44 volumio-test volumio[1167]: info: Dec 05 09:14:44 volumio-test volumio[1167]: ---------------------------- MPD announces system playlist update Dec 05 09:14:44 volumio-test volumio[1167]: info: Ignoring MPD Status Update Dec 05 09:14:44 volumio-test volumio[1167]: info: Dec 05 09:14:44 volumio-test volumio[1167]: ---------------------------- MPD announces system playlist update Dec 05 09:14:44 volumio-test volumio[1167]: info: Ignoring MPD Status Update Dec 05 09:14:44 volumio-test volumio[1167]: error: updateQueue error: null Dec 05 09:14:44 volumio-test volumio[1167]: info: ------------------------------ 3ms Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:14:44 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:14:44 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:14:44 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:14:45 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand add "http://kjzz.streamguys1.com/kjzz_mp3_128" Dec 05 09:14:45 volumio-test volumio[1167]: error: updateQueue error: null Dec 05 09:14:45 volumio-test volumio[1167]: error: updateQueue error: null Dec 05 09:14:45 volumio-test volumio[1167]: info: ------------------------------ 938ms Dec 05 09:14:45 volumio-test volumio[1167]: info: ------------------------------ 937ms Dec 05 09:14:45 volumio-test volumio[1167]: info: sendMpdCommand add "http://kjzz.streamguys1.com/kjzz_mp3_128" took 1 milliseconds Dec 05 09:14:45 volumio-test volumio[1167]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 05 09:14:45 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand play Dec 05 09:14:45 volumio-test volumio[1167]: info: Dec 05 09:14:45 volumio-test volumio[1167]: ---------------------------- MPD announces system playlist update Dec 05 09:14:45 volumio-test volumio[1167]: info: Ignoring MPD Status Update Dec 05 09:14:45 volumio-test volumio[1167]: info: Dec 05 09:14:45 volumio-test volumio[1167]: ---------------------------- MPD announces system playlist update Dec 05 09:14:45 volumio-test volumio[1167]: info: Ignoring MPD Status Update Dec 05 09:14:45 volumio-test volumio[1167]: info: Dec 05 09:14:45 volumio-test volumio[1167]: ---------------------------- MPD announces system playlist update Dec 05 09:14:45 volumio-test volumio[1167]: info: Ignoring MPD Status Update Dec 05 09:14:45 volumio-test volumio[1167]: info: sendMpdCommand play took 4 milliseconds Dec 05 09:14:45 volumio-test volumio[1167]: info: ------------------------------ 3ms Dec 05 09:14:45 volumio-test volumio[1167]: info: ------------------------------ 2ms Dec 05 09:14:45 volumio-test volumio[1167]: info: ------------------------------ 1ms Dec 05 09:14:46 volumio-test volumio[1167]: info: Dec 05 09:14:46 volumio-test volumio[1167]: ---------------------------- MPD announces state update: player Dec 05 09:14:46 volumio-test volumio[1167]: info: ControllerMpd::getState Dec 05 09:14:46 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 05 09:14:46 volumio-test volumio[1167]: info: Dec 05 09:14:46 volumio-test volumio[1167]: ---------------------------- MPD announces state update: player Dec 05 09:14:46 volumio-test volumio[1167]: info: ControllerMpd::getState Dec 05 09:14:46 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 05 09:14:46 volumio-test volumio[1167]: info: Dec 05 09:14:46 volumio-test volumio[1167]: ---------------------------- MPD announces state update: player Dec 05 09:14:46 volumio-test volumio[1167]: info: ControllerMpd::getState Dec 05 09:14:46 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 05 09:14:46 volumio-test volumio[1167]: info: sendMpdCommand status took 12 milliseconds Dec 05 09:14:46 volumio-test volumio[1167]: verbose: ControllerMpd::parseState Dec 05 09:14:46 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 05 09:14:46 volumio-test volumio[1167]: info: Dec 05 09:14:46 volumio-test volumio[1167]: ---------------------------- MPD announces state update: player Dec 05 09:14:46 volumio-test volumio[1167]: info: ControllerMpd::getState Dec 05 09:14:46 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 05 09:14:46 volumio-test volumio[1167]: info: sendMpdCommand status took 14 milliseconds Dec 05 09:14:46 volumio-test volumio[1167]: info: sendMpdCommand status took 12 milliseconds Dec 05 09:14:46 volumio-test volumio[1167]: info: sendMpdCommand playlistinfo took 2 milliseconds Dec 05 09:14:46 volumio-test volumio[1167]: verbose: ControllerMpd::parseState Dec 05 09:14:46 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 05 09:14:46 volumio-test volumio[1167]: verbose: ControllerMpd::parseState Dec 05 09:14:46 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 05 09:14:46 volumio-test volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 05 09:14:46 volumio-test volumio[1167]: info: ControllerMpd::pushState Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreCommandRouter::servicePushState Dec 05 09:14:46 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:46 volumio-test volumio[1167]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"kjzz_mp3_128","artist":null,"album":null,"uri":"http://kjzz.streamguys1.com/kjzz_mp3_128","trackType":""} Dec 05 09:14:46 volumio-test volumio[1167]: verbose: CURRENT POSITION 0 Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreStateMachine::syncState stateService play Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreStateMachine::syncState currentStatus stop Dec 05 09:14:46 volumio-test volumio[1167]: info: ------------------------------ 20ms Dec 05 09:14:46 volumio-test volumio[1167]: info: Dec 05 09:14:46 volumio-test volumio[1167]: ---------------------------- MPD announces state update: player Dec 05 09:14:46 volumio-test volumio[1167]: info: ControllerMpd::getState Dec 05 09:14:46 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 05 09:14:46 volumio-test volumio[1167]: info: Dec 05 09:14:46 volumio-test volumio[1167]: ---------------------------- MPD announces state update: player Dec 05 09:14:46 volumio-test volumio[1167]: info: ControllerMpd::getState Dec 05 09:14:46 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 05 09:14:46 volumio-test volumio[1167]: info: sendMpdCommand status took 5 milliseconds Dec 05 09:14:46 volumio-test volumio[1167]: info: sendMpdCommand playlistinfo took 4 milliseconds Dec 05 09:14:46 volumio-test volumio[1167]: info: sendMpdCommand playlistinfo took 4 milliseconds Dec 05 09:14:46 volumio-test volumio[1167]: info: sendMpdCommand status took 2 milliseconds Dec 05 09:14:46 volumio-test volumio[1167]: info: sendMpdCommand status took 2 milliseconds Dec 05 09:14:46 volumio-test volumio[1167]: verbose: ControllerMpd::parseState Dec 05 09:14:46 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 05 09:14:46 volumio-test volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 05 09:14:46 volumio-test volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 05 09:14:46 volumio-test volumio[1167]: verbose: ControllerMpd::parseState Dec 05 09:14:46 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 05 09:14:46 volumio-test volumio[1167]: verbose: ControllerMpd::parseState Dec 05 09:14:46 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 05 09:14:46 volumio-test volumio[1167]: info: ControllerMpd::pushState Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreCommandRouter::servicePushState Dec 05 09:14:46 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:46 volumio-test volumio[1167]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"kjzz_mp3_128","artist":null,"album":null,"uri":"http://kjzz.streamguys1.com/kjzz_mp3_128","trackType":""} Dec 05 09:14:46 volumio-test volumio[1167]: verbose: CURRENT POSITION 0 Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreStateMachine::syncState stateService play Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreStateMachine::syncState currentStatus play Dec 05 09:14:46 volumio-test volumio[1167]: info: Received an update from plugin. extracting info from payload Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:46 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:46 volumio-test volumio[1167]: info: ControllerMpd::pushState Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreCommandRouter::servicePushState Dec 05 09:14:46 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:46 volumio-test volumio[1167]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"kjzz_mp3_128","artist":null,"album":null,"uri":"http://kjzz.streamguys1.com/kjzz_mp3_128","trackType":""} Dec 05 09:14:46 volumio-test volumio[1167]: verbose: CURRENT POSITION 0 Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreStateMachine::syncState stateService play Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreStateMachine::syncState currentStatus play Dec 05 09:14:46 volumio-test volumio[1167]: info: Received an update from plugin. extracting info from payload Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:46 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:46 volumio-test volumio[1167]: info: ------------------------------ 41ms Dec 05 09:14:46 volumio-test volumio[1167]: info: ------------------------------ 41ms Dec 05 09:14:46 volumio-test volumio[1167]: info: sendMpdCommand playlistinfo took 23 milliseconds Dec 05 09:14:46 volumio-test volumio[1167]: info: sendMpdCommand playlistinfo took 23 milliseconds Dec 05 09:14:46 volumio-test volumio[1167]: info: sendMpdCommand playlistinfo took 23 milliseconds Dec 05 09:14:46 volumio-test volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 05 09:14:46 volumio-test volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 05 09:14:46 volumio-test volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 05 09:14:46 volumio-test volumio[1167]: info: ControllerMpd::pushState Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreCommandRouter::servicePushState Dec 05 09:14:46 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:46 volumio-test volumio[1167]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"kjzz_mp3_128","artist":null,"album":null,"uri":"http://kjzz.streamguys1.com/kjzz_mp3_128","trackType":""} Dec 05 09:14:46 volumio-test volumio[1167]: verbose: CURRENT POSITION 0 Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreStateMachine::syncState stateService play Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreStateMachine::syncState currentStatus play Dec 05 09:14:46 volumio-test volumio[1167]: info: Received an update from plugin. extracting info from payload Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:46 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:46 volumio-test volumio[1167]: info: ControllerMpd::pushState Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreCommandRouter::servicePushState Dec 05 09:14:46 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:46 volumio-test volumio[1167]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"kjzz_mp3_128","artist":null,"album":null,"uri":"http://kjzz.streamguys1.com/kjzz_mp3_128","trackType":""} Dec 05 09:14:46 volumio-test volumio[1167]: verbose: CURRENT POSITION 0 Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreStateMachine::syncState stateService play Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreStateMachine::syncState currentStatus play Dec 05 09:14:46 volumio-test volumio[1167]: info: Received an update from plugin. extracting info from payload Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:46 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:46 volumio-test volumio[1167]: info: ControllerMpd::pushState Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreCommandRouter::servicePushState Dec 05 09:14:46 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:46 volumio-test volumio[1167]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"kjzz_mp3_128","artist":null,"album":null,"uri":"http://kjzz.streamguys1.com/kjzz_mp3_128","trackType":""} Dec 05 09:14:46 volumio-test volumio[1167]: verbose: CURRENT POSITION 0 Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreStateMachine::syncState stateService play Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreStateMachine::syncState currentStatus play Dec 05 09:14:46 volumio-test volumio[1167]: info: Received an update from plugin. extracting info from payload Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:46 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:46 volumio-test volumio[1167]: info: ------------------------------ 71ms Dec 05 09:14:46 volumio-test volumio[1167]: info: ------------------------------ 68ms Dec 05 09:14:46 volumio-test volumio[1167]: info: ------------------------------ 69ms Dec 05 09:14:46 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:46 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:46 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:46 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:46 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:46 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:46 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:46 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:46 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:46 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:14:46 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:14:46 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:14:48 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:14:48 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:14:48 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:14:48 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:14:50 volumio-test volumio[1167]: info: Preload queue cleared Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreCommandRouter::volumioReplaceandPlayItems Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreStateMachine::ClearQueue Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreStateMachine::stop Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreStateMachine::stPlaybackTimer Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreStateMachine::updateTrackBlock Dec 05 09:14:50 volumio-test volumio[1167]: info: CorePlayQueue::getTrackBlock Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:50 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreStateMachine::serviceStop Dec 05 09:14:50 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreCommandRouter::serviceStop Dec 05 09:14:50 volumio-test volumio[1167]: info: [1764951290266] ControllerWebradio::stop Dec 05 09:14:50 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand stop Dec 05 09:14:50 volumio-test volumio[1167]: info: CorePlayQueue::clearPlayQueue Dec 05 09:14:50 volumio-test volumio[1167]: info: CorePlayQueue::saveQueue Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushQueue Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreStateMachine::addQueueItems Dec 05 09:14:50 volumio-test volumio[1167]: info: CorePlayQueue::addQueueItems Dec 05 09:14:50 volumio-test volumio[1167]: info: Preload queue cleared Dec 05 09:14:50 volumio-test volumio[1167]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s257014 Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Dec 05 09:14:50 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:50 volumio-test volumio[1167]: info: Dec 05 09:14:50 volumio-test volumio[1167]: ---------------------------- MPD announces state update: player Dec 05 09:14:50 volumio-test volumio[1167]: info: sendMpdCommand stop took 40 milliseconds Dec 05 09:14:50 volumio-test volumio[1167]: info: ControllerMpd::getState Dec 05 09:14:50 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 05 09:14:50 volumio-test volumio[1167]: info: Dec 05 09:14:50 volumio-test volumio[1167]: ---------------------------- MPD announces state update: player Dec 05 09:14:50 volumio-test volumio[1167]: info: ControllerMpd::getState Dec 05 09:14:50 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 05 09:14:50 volumio-test volumio[1167]: info: Dec 05 09:14:50 volumio-test volumio[1167]: ---------------------------- MPD announces state update: player Dec 05 09:14:50 volumio-test volumio[1167]: info: ControllerMpd::getState Dec 05 09:14:50 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 05 09:14:50 volumio-test volumio[1167]: info: sendMpdCommand status took 5 milliseconds Dec 05 09:14:50 volumio-test volumio[1167]: info: sendMpdCommand status took 3 milliseconds Dec 05 09:14:50 volumio-test volumio[1167]: info: sendMpdCommand status took 3 milliseconds Dec 05 09:14:50 volumio-test volumio[1167]: verbose: ControllerMpd::parseState Dec 05 09:14:50 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 05 09:14:50 volumio-test volumio[1167]: verbose: ControllerMpd::parseState Dec 05 09:14:50 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 05 09:14:50 volumio-test volumio[1167]: verbose: ControllerMpd::parseState Dec 05 09:14:50 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 05 09:14:50 volumio-test volumio[1167]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 05 09:14:50 volumio-test volumio[1167]: info: sendMpdCommand playlistinfo took 2 milliseconds Dec 05 09:14:50 volumio-test volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 05 09:14:50 volumio-test volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 05 09:14:50 volumio-test volumio[1167]: info: ControllerMpd::pushState Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreCommandRouter::servicePushState Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:50 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:50 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:50 volumio-test volumio[1167]: 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":"kjzz_mp3_128","artist":null,"album":null,"uri":"http://kjzz.streamguys1.com/kjzz_mp3_128","trackType":""} Dec 05 09:14:50 volumio-test volumio[1167]: verbose: CURRENT POSITION 0 Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreStateMachine::syncState stateService stop Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreStateMachine::syncState currentStatus stop Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:50 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:50 volumio-test volumio[1167]: info: No code Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:50 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:50 volumio-test volumio[1167]: info: ControllerMpd::pushState Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreCommandRouter::servicePushState Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:50 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:50 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:50 volumio-test volumio[1167]: 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":"kjzz_mp3_128","artist":null,"album":null,"uri":"http://kjzz.streamguys1.com/kjzz_mp3_128","trackType":""} Dec 05 09:14:50 volumio-test volumio[1167]: verbose: CURRENT POSITION 0 Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreStateMachine::syncState stateService stop Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreStateMachine::syncState currentStatus stop Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:50 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:50 volumio-test volumio[1167]: info: No code Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:50 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:50 volumio-test volumio[1167]: info: ------------------------------ 30ms Dec 05 09:14:50 volumio-test volumio[1167]: info: ------------------------------ 29ms Dec 05 09:14:50 volumio-test volumio[1167]: info: sendMpdCommand playlistinfo took 27 milliseconds Dec 05 09:14:50 volumio-test volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 05 09:14:50 volumio-test volumio[1167]: info: ControllerMpd::pushState Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreCommandRouter::servicePushState Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:50 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:50 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:50 volumio-test volumio[1167]: 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":"kjzz_mp3_128","artist":null,"album":null,"uri":"http://kjzz.streamguys1.com/kjzz_mp3_128","trackType":""} Dec 05 09:14:50 volumio-test volumio[1167]: verbose: CURRENT POSITION 0 Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreStateMachine::syncState stateService stop Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreStateMachine::syncState currentStatus stop Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:50 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:50 volumio-test volumio[1167]: info: No code Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:50 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:50 volumio-test volumio[1167]: info: ------------------------------ 41ms Dec 05 09:14:50 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:50 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:50 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:50 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:50 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:50 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:50 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:50 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:50 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushQueue Dec 05 09:14:50 volumio-test volumio[1167]: info: CorePlayQueue::saveQueue Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreStateMachine::updateTrackBlock Dec 05 09:14:50 volumio-test volumio[1167]: info: CorePlayQueue::getTrackBlock Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPlay Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreStateMachine::play index 0 Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreStateMachine::stop Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreStateMachine::play index undefined Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 05 09:14:50 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreStateMachine::startPlaybackTimer Dec 05 09:14:50 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:50 volumio-test volumio[1167]: info: [1764951290521] ControllerWebradio::clearAddPlayTrack Dec 05 09:14:50 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand stop Dec 05 09:14:50 volumio-test volumio[1167]: info: sendMpdCommand stop took 2 milliseconds Dec 05 09:14:50 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand clear Dec 05 09:14:50 volumio-test volumio[1167]: info: Dec 05 09:14:50 volumio-test volumio[1167]: ---------------------------- MPD announces system playlist update Dec 05 09:14:50 volumio-test volumio[1167]: info: Ignoring MPD Status Update Dec 05 09:14:50 volumio-test volumio[1167]: info: sendMpdCommand clear took 1 milliseconds Dec 05 09:14:50 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand load "https://securestreams6.autopo.st:2110/" Dec 05 09:14:50 volumio-test volumio[1167]: info: Dec 05 09:14:50 volumio-test volumio[1167]: ---------------------------- MPD announces system playlist update Dec 05 09:14:50 volumio-test volumio[1167]: info: Ignoring MPD Status Update Dec 05 09:14:50 volumio-test volumio[1167]: info: Dec 05 09:14:50 volumio-test volumio[1167]: ---------------------------- MPD announces system playlist update Dec 05 09:14:50 volumio-test volumio[1167]: info: Ignoring MPD Status Update Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:14:50 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:14:50 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:14:50 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:14:51 volumio-test volumio[1167]: error: updateQueue error: null Dec 05 09:14:51 volumio-test volumio[1167]: info: ------------------------------ 1301ms Dec 05 09:14:51 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand add "https://securestreams6.autopo.st:2110/" Dec 05 09:14:51 volumio-test volumio[1167]: error: updateQueue error: null Dec 05 09:14:51 volumio-test volumio[1167]: error: updateQueue error: null Dec 05 09:14:51 volumio-test volumio[1167]: info: ------------------------------ 1301ms Dec 05 09:14:51 volumio-test volumio[1167]: info: ------------------------------ 1300ms Dec 05 09:14:51 volumio-test volumio[1167]: info: Dec 05 09:14:51 volumio-test volumio[1167]: ---------------------------- MPD announces system playlist update Dec 05 09:14:51 volumio-test volumio[1167]: info: Ignoring MPD Status Update Dec 05 09:14:51 volumio-test volumio[1167]: info: sendMpdCommand add "https://securestreams6.autopo.st:2110/" took 2 milliseconds Dec 05 09:14:51 volumio-test volumio[1167]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 05 09:14:51 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand play Dec 05 09:14:51 volumio-test volumio[1167]: info: Dec 05 09:14:51 volumio-test volumio[1167]: ---------------------------- MPD announces system playlist update Dec 05 09:14:51 volumio-test volumio[1167]: info: Ignoring MPD Status Update Dec 05 09:14:51 volumio-test volumio[1167]: info: Dec 05 09:14:51 volumio-test volumio[1167]: ---------------------------- MPD announces system playlist update Dec 05 09:14:51 volumio-test volumio[1167]: info: Ignoring MPD Status Update Dec 05 09:14:51 volumio-test volumio[1167]: info: ------------------------------ 3ms Dec 05 09:14:51 volumio-test volumio[1167]: info: sendMpdCommand play took 4 milliseconds Dec 05 09:14:51 volumio-test volumio[1167]: info: ------------------------------ 3ms Dec 05 09:14:51 volumio-test volumio[1167]: info: ------------------------------ 2ms Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:14:52 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:14:52 volumio-test volumio[1167]: info: Dec 05 09:14:52 volumio-test volumio[1167]: ---------------------------- MPD announces state update: player Dec 05 09:14:52 volumio-test volumio[1167]: info: ControllerMpd::getState Dec 05 09:14:52 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 05 09:14:52 volumio-test volumio[1167]: info: Dec 05 09:14:52 volumio-test volumio[1167]: ---------------------------- MPD announces state update: player Dec 05 09:14:52 volumio-test volumio[1167]: info: ControllerMpd::getState Dec 05 09:14:52 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 05 09:14:52 volumio-test volumio[1167]: info: Dec 05 09:14:52 volumio-test volumio[1167]: ---------------------------- MPD announces state update: player Dec 05 09:14:52 volumio-test volumio[1167]: info: ControllerMpd::getState Dec 05 09:14:52 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 05 09:14:52 volumio-test volumio[1167]: info: Dec 05 09:14:52 volumio-test volumio[1167]: ---------------------------- MPD announces state update: player Dec 05 09:14:52 volumio-test volumio[1167]: info: sendMpdCommand status took 15 milliseconds Dec 05 09:14:52 volumio-test volumio[1167]: info: ControllerMpd::getState Dec 05 09:14:52 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 05 09:14:52 volumio-test volumio[1167]: verbose: ControllerMpd::parseState Dec 05 09:14:52 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 05 09:14:52 volumio-test volumio[1167]: info: Dec 05 09:14:52 volumio-test volumio[1167]: ---------------------------- MPD announces state update: player Dec 05 09:14:52 volumio-test volumio[1167]: info: ControllerMpd::getState Dec 05 09:14:52 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 05 09:14:52 volumio-test volumio[1167]: info: sendMpdCommand status took 16 milliseconds Dec 05 09:14:52 volumio-test volumio[1167]: info: sendMpdCommand status took 16 milliseconds Dec 05 09:14:52 volumio-test volumio[1167]: verbose: ControllerMpd::parseState Dec 05 09:14:52 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 05 09:14:52 volumio-test volumio[1167]: verbose: ControllerMpd::parseState Dec 05 09:14:52 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 05 09:14:52 volumio-test volumio[1167]: info: Dec 05 09:14:52 volumio-test volumio[1167]: ---------------------------- MPD announces state update: player Dec 05 09:14:52 volumio-test volumio[1167]: info: ControllerMpd::getState Dec 05 09:14:52 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 05 09:14:52 volumio-test volumio[1167]: info: sendMpdCommand status took 6 milliseconds Dec 05 09:14:52 volumio-test volumio[1167]: info: sendMpdCommand playlistinfo took 5 milliseconds Dec 05 09:14:52 volumio-test volumio[1167]: info: sendMpdCommand status took 4 milliseconds Dec 05 09:14:52 volumio-test volumio[1167]: info: sendMpdCommand playlistinfo took 3 milliseconds Dec 05 09:14:52 volumio-test volumio[1167]: info: sendMpdCommand playlistinfo took 3 milliseconds Dec 05 09:14:52 volumio-test volumio[1167]: info: sendMpdCommand status took 2 milliseconds Dec 05 09:14:52 volumio-test volumio[1167]: verbose: ControllerMpd::parseState Dec 05 09:14:52 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 05 09:14:52 volumio-test volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 05 09:14:52 volumio-test volumio[1167]: verbose: ControllerMpd::parseState Dec 05 09:14:52 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 05 09:14:52 volumio-test volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 05 09:14:52 volumio-test volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 05 09:14:52 volumio-test volumio[1167]: verbose: ControllerMpd::parseState Dec 05 09:14:52 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 05 09:14:52 volumio-test volumio[1167]: info: ControllerMpd::pushState Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreCommandRouter::servicePushState Dec 05 09:14:52 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:52 volumio-test volumio[1167]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"","artist":null,"album":null,"uri":"https://securestreams6.autopo.st:2110/","trackType":"st:2110/"} Dec 05 09:14:52 volumio-test volumio[1167]: verbose: CURRENT POSITION 0 Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreStateMachine::syncState stateService play Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreStateMachine::syncState currentStatus stop Dec 05 09:14:52 volumio-test volumio[1167]: info: ControllerMpd::pushState Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreCommandRouter::servicePushState Dec 05 09:14:52 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:52 volumio-test volumio[1167]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"","artist":null,"album":null,"uri":"https://securestreams6.autopo.st:2110/","trackType":"st:2110/"} Dec 05 09:14:52 volumio-test volumio[1167]: verbose: CURRENT POSITION 0 Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreStateMachine::syncState stateService play Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreStateMachine::syncState currentStatus play Dec 05 09:14:52 volumio-test volumio[1167]: info: Received an update from plugin. extracting info from payload Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:52 volumio-test volumio[1167]: info: ControllerMpd::pushState Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreCommandRouter::servicePushState Dec 05 09:14:52 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:52 volumio-test volumio[1167]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"","artist":null,"album":null,"uri":"https://securestreams6.autopo.st:2110/","trackType":"st:2110/"} Dec 05 09:14:52 volumio-test volumio[1167]: verbose: CURRENT POSITION 0 Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreStateMachine::syncState stateService play Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreStateMachine::syncState currentStatus play Dec 05 09:14:52 volumio-test volumio[1167]: info: Received an update from plugin. extracting info from payload Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:52 volumio-test volumio[1167]: info: ------------------------------ 35ms Dec 05 09:14:52 volumio-test volumio[1167]: info: ------------------------------ 38ms Dec 05 09:14:52 volumio-test volumio[1167]: info: ------------------------------ 39ms Dec 05 09:14:52 volumio-test volumio[1167]: info: sendMpdCommand playlistinfo took 19 milliseconds Dec 05 09:14:52 volumio-test volumio[1167]: info: sendMpdCommand playlistinfo took 19 milliseconds Dec 05 09:14:52 volumio-test volumio[1167]: info: sendMpdCommand playlistinfo took 18 milliseconds Dec 05 09:14:52 volumio-test volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 05 09:14:52 volumio-test volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 05 09:14:52 volumio-test volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 05 09:14:52 volumio-test volumio[1167]: info: ControllerMpd::pushState Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreCommandRouter::servicePushState Dec 05 09:14:52 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:52 volumio-test volumio[1167]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"","artist":null,"album":null,"uri":"https://securestreams6.autopo.st:2110/","trackType":"st:2110/"} Dec 05 09:14:52 volumio-test volumio[1167]: verbose: CURRENT POSITION 0 Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreStateMachine::syncState stateService play Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreStateMachine::syncState currentStatus play Dec 05 09:14:52 volumio-test volumio[1167]: info: Received an update from plugin. extracting info from payload Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:52 volumio-test volumio[1167]: info: ControllerMpd::pushState Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreCommandRouter::servicePushState Dec 05 09:14:52 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:52 volumio-test volumio[1167]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"","artist":null,"album":null,"uri":"https://securestreams6.autopo.st:2110/","trackType":"st:2110/"} Dec 05 09:14:52 volumio-test volumio[1167]: verbose: CURRENT POSITION 0 Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreStateMachine::syncState stateService play Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreStateMachine::syncState currentStatus play Dec 05 09:14:52 volumio-test volumio[1167]: info: Received an update from plugin. extracting info from payload Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:52 volumio-test volumio[1167]: info: ControllerMpd::pushState Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreCommandRouter::servicePushState Dec 05 09:14:52 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:52 volumio-test volumio[1167]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"","artist":null,"album":null,"uri":"https://securestreams6.autopo.st:2110/","trackType":"st:2110/"} Dec 05 09:14:52 volumio-test volumio[1167]: verbose: CURRENT POSITION 0 Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreStateMachine::syncState stateService play Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreStateMachine::syncState currentStatus play Dec 05 09:14:52 volumio-test volumio[1167]: info: Received an update from plugin. extracting info from payload Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:52 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:53 volumio-test volumio[1167]: info: ------------------------------ 45ms Dec 05 09:14:53 volumio-test volumio[1167]: info: ------------------------------ 45ms Dec 05 09:14:53 volumio-test volumio[1167]: info: ------------------------------ 42ms Dec 05 09:14:53 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:53 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:53 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:53 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:53 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:53 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:53 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:53 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:53 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:53 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:53 volumio-test volumio[1167]: info: Dec 05 09:14:53 volumio-test volumio[1167]: ---------------------------- MPD announces system playlist update Dec 05 09:14:53 volumio-test volumio[1167]: info: Ignoring MPD Status Update Dec 05 09:14:53 volumio-test volumio[1167]: info: Dec 05 09:14:53 volumio-test volumio[1167]: ---------------------------- MPD announces state update: player Dec 05 09:14:53 volumio-test volumio[1167]: info: ControllerMpd::getState Dec 05 09:14:53 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 05 09:14:53 volumio-test volumio[1167]: info: Dec 05 09:14:53 volumio-test volumio[1167]: ---------------------------- MPD announces system playlist update Dec 05 09:14:53 volumio-test volumio[1167]: info: Ignoring MPD Status Update Dec 05 09:14:53 volumio-test volumio[1167]: info: Dec 05 09:14:53 volumio-test volumio[1167]: ---------------------------- MPD announces state update: player Dec 05 09:14:53 volumio-test volumio[1167]: info: ControllerMpd::getState Dec 05 09:14:53 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 05 09:14:53 volumio-test volumio[1167]: info: Dec 05 09:14:53 volumio-test volumio[1167]: ---------------------------- MPD announces system playlist update Dec 05 09:14:53 volumio-test volumio[1167]: info: Ignoring MPD Status Update Dec 05 09:14:53 volumio-test volumio[1167]: info: Dec 05 09:14:53 volumio-test volumio[1167]: ---------------------------- MPD announces state update: player Dec 05 09:14:53 volumio-test volumio[1167]: info: ControllerMpd::getState Dec 05 09:14:53 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 05 09:14:53 volumio-test volumio[1167]: info: ------------------------------ 4ms Dec 05 09:14:53 volumio-test volumio[1167]: info: sendMpdCommand status took 4 milliseconds Dec 05 09:14:53 volumio-test volumio[1167]: verbose: ControllerMpd::parseState Dec 05 09:14:53 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 05 09:14:53 volumio-test volumio[1167]: info: ------------------------------ 5ms Dec 05 09:14:53 volumio-test volumio[1167]: info: sendMpdCommand status took 4 milliseconds Dec 05 09:14:53 volumio-test volumio[1167]: info: ------------------------------ 4ms Dec 05 09:14:53 volumio-test volumio[1167]: info: sendMpdCommand status took 4 milliseconds Dec 05 09:14:53 volumio-test volumio[1167]: info: sendMpdCommand playlistinfo took 2 milliseconds Dec 05 09:14:53 volumio-test volumio[1167]: verbose: ControllerMpd::parseState Dec 05 09:14:53 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 05 09:14:53 volumio-test volumio[1167]: verbose: ControllerMpd::parseState Dec 05 09:14:53 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 05 09:14:53 volumio-test volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 05 09:14:53 volumio-test volumio[1167]: info: ControllerMpd::pushState Dec 05 09:14:53 volumio-test volumio[1167]: info: CoreCommandRouter::servicePushState Dec 05 09:14:53 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:53 volumio-test volumio[1167]: verbose: STATE SERVICE {"status":"play","position":0,"seek":881,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"","artist":"Downtown Radio Tucson","album":null,"uri":"https://securestreams6.autopo.st:2110/","trackType":"st:2110/"} Dec 05 09:14:53 volumio-test volumio[1167]: verbose: CURRENT POSITION 0 Dec 05 09:14:53 volumio-test volumio[1167]: info: CoreStateMachine::syncState stateService play Dec 05 09:14:53 volumio-test volumio[1167]: info: CoreStateMachine::syncState currentStatus play Dec 05 09:14:53 volumio-test volumio[1167]: info: Received an update from plugin. extracting info from payload Dec 05 09:14:53 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:53 volumio-test volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 05 09:14:53 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:53 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:53 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:53 volumio-test volumio[1167]: info: ------------------------------ 17ms Dec 05 09:14:53 volumio-test volumio[1167]: info: sendMpdCommand playlistinfo took 11 milliseconds Dec 05 09:14:53 volumio-test volumio[1167]: info: sendMpdCommand playlistinfo took 11 milliseconds Dec 05 09:14:53 volumio-test volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 05 09:14:53 volumio-test volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 05 09:14:53 volumio-test volumio[1167]: info: ControllerMpd::pushState Dec 05 09:14:53 volumio-test volumio[1167]: info: CoreCommandRouter::servicePushState Dec 05 09:14:53 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:53 volumio-test volumio[1167]: verbose: STATE SERVICE {"status":"play","position":0,"seek":881,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"","artist":"Downtown Radio Tucson","album":null,"uri":"https://securestreams6.autopo.st:2110/","trackType":"st:2110/"} Dec 05 09:14:53 volumio-test volumio[1167]: verbose: CURRENT POSITION 0 Dec 05 09:14:53 volumio-test volumio[1167]: info: CoreStateMachine::syncState stateService play Dec 05 09:14:53 volumio-test volumio[1167]: info: CoreStateMachine::syncState currentStatus play Dec 05 09:14:53 volumio-test volumio[1167]: info: Received an update from plugin. extracting info from payload Dec 05 09:14:53 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:53 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:53 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:53 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:53 volumio-test volumio[1167]: info: ControllerMpd::pushState Dec 05 09:14:53 volumio-test volumio[1167]: info: CoreCommandRouter::servicePushState Dec 05 09:14:53 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:14:53 volumio-test volumio[1167]: verbose: STATE SERVICE {"status":"play","position":0,"seek":881,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"","artist":"Downtown Radio Tucson","album":null,"uri":"https://securestreams6.autopo.st:2110/","trackType":"st:2110/"} Dec 05 09:14:53 volumio-test volumio[1167]: verbose: CURRENT POSITION 0 Dec 05 09:14:53 volumio-test volumio[1167]: info: CoreStateMachine::syncState stateService play Dec 05 09:14:53 volumio-test volumio[1167]: info: CoreStateMachine::syncState currentStatus play Dec 05 09:14:53 volumio-test volumio[1167]: info: Received an update from plugin. extracting info from payload Dec 05 09:14:53 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:53 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:53 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:14:53 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:14:53 volumio-test volumio[1167]: info: ------------------------------ 31ms Dec 05 09:14:53 volumio-test volumio[1167]: info: ------------------------------ 31ms Dec 05 09:14:53 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:53 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:53 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:53 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:53 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:53 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:14:54 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:14:54 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:14:54 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:14:54 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:14:56 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:14:56 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:14:56 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:14:56 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:14:58 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:14:58 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:14:58 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:14:58 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:15:00 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:15:00 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:15:00 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:15:00 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:15:02 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:15:02 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:15:02 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:15:02 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:15:04 volumio-test go-librespot[16922]: time="2025-12-05T09:15:04-07:00" level=trace msg="sent dealer ping" Dec 05 09:15:04 volumio-test go-librespot[16922]: time="2025-12-05T09:15:04-07:00" level=trace msg="received dealer pong" Dec 05 09:15:04 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:15:04 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:15:04 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:15:04 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:15:06 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:15:06 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:15:06 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:15:06 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:15:08 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:15:08 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:15:08 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:15:08 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:15:10 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:15:10 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:15:10 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:15:10 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:15:12 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:15:12 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:15:12 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:15:12 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:15:14 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:15:14 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:15:14 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:15:14 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:15:16 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:15:16 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:15:16 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:15:16 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:15:18 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:15:18 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:15:18 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:15:18 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:15:20 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:15:20 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:15:20 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:15:20 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:15:22 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:15:22 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:15:22 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:15:22 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:15:24 volumio-test volumio[1167]: info: Dec 05 09:15:24 volumio-test volumio[1167]: ---------------------------- Client requests Volumio toggle Dec 05 09:15:24 volumio-test volumio[1167]: info: CoreCommandRouter::volumioToggle Dec 05 09:15:24 volumio-test volumio[1167]: info: CoreStateMachine::stop Dec 05 09:15:24 volumio-test volumio[1167]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 05 09:15:24 volumio-test volumio[1167]: info: CoreStateMachine::stPlaybackTimer Dec 05 09:15:24 volumio-test volumio[1167]: info: CoreStateMachine::updateTrackBlock Dec 05 09:15:24 volumio-test volumio[1167]: info: CorePlayQueue::getTrackBlock Dec 05 09:15:24 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:15:24 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:15:24 volumio-test volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 05 09:15:24 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:15:24 volumio-test volumio[1167]: info: CoreStateMachine::serviceStop Dec 05 09:15:24 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:15:24 volumio-test volumio[1167]: info: CoreCommandRouter::serviceStop Dec 05 09:15:24 volumio-test volumio[1167]: info: [1764951324333] ControllerWebradio::stop Dec 05 09:15:24 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand stop Dec 05 09:15:24 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:15:24 volumio-test volumio[1167]: info: Dec 05 09:15:24 volumio-test volumio[1167]: ---------------------------- MPD announces state update: player Dec 05 09:15:24 volumio-test volumio[1167]: info: sendMpdCommand stop took 22 milliseconds Dec 05 09:15:24 volumio-test volumio[1167]: info: ControllerMpd::getState Dec 05 09:15:24 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 05 09:15:24 volumio-test volumio[1167]: info: sendMpdCommand status took 2 milliseconds Dec 05 09:15:24 volumio-test volumio[1167]: verbose: ControllerMpd::parseState Dec 05 09:15:24 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 05 09:15:24 volumio-test volumio[1167]: info: Dec 05 09:15:24 volumio-test volumio[1167]: ---------------------------- MPD announces state update: player Dec 05 09:15:24 volumio-test volumio[1167]: info: ControllerMpd::getState Dec 05 09:15:24 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 05 09:15:24 volumio-test volumio[1167]: info: Dec 05 09:15:24 volumio-test volumio[1167]: ---------------------------- MPD announces state update: player Dec 05 09:15:24 volumio-test volumio[1167]: info: ControllerMpd::getState Dec 05 09:15:24 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 05 09:15:24 volumio-test volumio[1167]: info: sendMpdCommand playlistinfo took 2 milliseconds Dec 05 09:15:24 volumio-test volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 05 09:15:24 volumio-test volumio[1167]: info: ControllerMpd::pushState Dec 05 09:15:24 volumio-test volumio[1167]: info: CoreCommandRouter::servicePushState Dec 05 09:15:24 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:15:24 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:15:24 volumio-test volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 05 09:15:24 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:15:24 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:15:24 volumio-test volumio[1167]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Dec 05 09:15:24 volumio-test volumio[1167]: info: ------------------------------ 14ms Dec 05 09:15:24 volumio-test volumio[1167]: info: sendMpdCommand status took 9 milliseconds Dec 05 09:15:24 volumio-test volumio[1167]: info: sendMpdCommand status took 10 milliseconds Dec 05 09:15:24 volumio-test volumio[1167]: verbose: ControllerMpd::parseState Dec 05 09:15:24 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 05 09:15:24 volumio-test volumio[1167]: verbose: ControllerMpd::parseState Dec 05 09:15:24 volumio-test volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 05 09:15:24 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:15:24 volumio-test volumio[1167]: info: sendMpdCommand playlistinfo took 7 milliseconds Dec 05 09:15:24 volumio-test volumio[1167]: info: sendMpdCommand playlistinfo took 6 milliseconds Dec 05 09:15:24 volumio-test volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 05 09:15:24 volumio-test volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 05 09:15:24 volumio-test volumio[1167]: info: ControllerMpd::pushState Dec 05 09:15:24 volumio-test volumio[1167]: info: CoreCommandRouter::servicePushState Dec 05 09:15:24 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:15:24 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:15:24 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:15:24 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:15:24 volumio-test volumio[1167]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Dec 05 09:15:24 volumio-test volumio[1167]: info: ControllerMpd::pushState Dec 05 09:15:24 volumio-test volumio[1167]: info: CoreCommandRouter::servicePushState Dec 05 09:15:24 volumio-test volumio[1167]: info: CoreStateMachine::pushState Dec 05 09:15:24 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:15:24 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:15:24 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:15:24 volumio-test volumio[1167]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Dec 05 09:15:24 volumio-test volumio[1167]: info: ------------------------------ 31ms Dec 05 09:15:24 volumio-test volumio[1167]: info: ------------------------------ 31ms Dec 05 09:15:24 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:15:24 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:15:24 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:15:24 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:15:24 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:15:24 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:15:24 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:15:24 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:15:24 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:15:26 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:15:26 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:15:26 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetQueue Dec 05 09:15:26 volumio-test volumio[1167]: info: CoreStateMachine::getQueue Dec 05 09:15:26 volumio-test volumio[1167]: info: CorePlayQueue::getQueue Dec 05 09:15:27 volumio-test volumio[1167]: info: Dec 05 09:15:27 volumio-test volumio[1167]: ---------------------------- Client requests Volumio Clear Queue Dec 05 09:15:27 volumio-test volumio[1167]: info: CoreCommandRouter::volumioClearQueue Dec 05 09:15:27 volumio-test volumio[1167]: info: CoreStateMachine::ClearQueue Dec 05 09:15:27 volumio-test volumio[1167]: info: CoreStateMachine::stop Dec 05 09:15:27 volumio-test volumio[1167]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 05 09:15:27 volumio-test volumio[1167]: info: CorePlayQueue::clearPlayQueue Dec 05 09:15:27 volumio-test volumio[1167]: info: CorePlayQueue::saveQueue Dec 05 09:15:27 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 05 09:15:27 volumio-test volumio[1167]: info: CoreCommandRouter::volumioPushQueue Dec 05 09:15:27 volumio-test volumio[1167]: error: API:pushError: TypeError: callback.apply is not a function Dec 05 09:15:27 volumio-test volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Dec 05 09:15:27 volumio-test volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 05 09:15:27 volumio-test volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 05 09:15:28 volumio-test volumio[1167]: info: READ Dec 05 09:15:28 volumio-test volumio[1167]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 05 09:15:28 volumio-test volumio[1167]: Error Dec 05 09:15:28 volumio-test volumio[1167]: at /volumio/app/plugins/music_service/webradio/index.js:286:31 Dec 05 09:15:28 volumio-test volumio[1167]: at Request.handleRequestResponse [as _callback] (/volumio/node_modules/unirest/index.js:444:15) Dec 05 09:15:28 volumio-test volumio[1167]: at self.callback (/volumio/node_modules/request/request.js:185:22) Dec 05 09:15:28 volumio-test volumio[1167]: at Request.emit (node:events:514:28) Dec 05 09:15:28 volumio-test volumio[1167]: at Request.onRequestError (/volumio/node_modules/request/request.js:877:8) Dec 05 09:15:28 volumio-test volumio[1167]: at ClientRequest.emit (node:events:514:28) Dec 05 09:15:28 volumio-test volumio[1167]: at Socket.socketErrorListener (node:_http_client:495:9) Dec 05 09:15:28 volumio-test volumio[1167]: at Socket.emit (node:events:514:28) Dec 05 09:15:28 volumio-test volumio[1167]: at emitErrorNT (node:internal/streams/destroy:151:8) Dec 05 09:15:28 volumio-test volumio[1167]: at emitErrorCloseNT (node:internal/streams/destroy:116:3) Dec 05 09:15:28 volumio-test volumio[1167]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 05 09:15:28 volumio-test sudo[24053]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-05 09:14' Dec 05 09:15:28 volumio-test sudo[24053]: 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="3a3cfe435f8bb2bc94a920662e91a4ef35bc8e7c" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="8bcc10c3dbcbcb349e9887dc0527d54876b32688" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Dec 2 11:51:19 UTC 2025" VOLUMIO_VERSION="4.072" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="e5001581b220b096097cf8f46a54d4f1"