Jun 14 06:07:00 volumio volumio[6477]: info: Jun 14 06:07:00 volumio volumio[6477]: ---------------------------- MPD announces state update: player Jun 14 06:07:00 volumio volumio[6477]: info: ControllerMpd::getState Jun 14 06:07:00 volumio volumio[6477]: verbose: ControllerMpd::sendMpdCommand status Jun 14 06:07:00 volumio volumio[6477]: info: Jun 14 06:07:00 volumio volumio[6477]: ---------------------------- MPD announces state update: player Jun 14 06:07:00 volumio volumio[6477]: info: ControllerMpd::getState Jun 14 06:07:00 volumio volumio[6477]: verbose: ControllerMpd::sendMpdCommand status Jun 14 06:07:00 volumio volumio[6477]: info: Jun 14 06:07:00 volumio volumio[6477]: ---------------------------- MPD announces state update: player Jun 14 06:07:00 volumio volumio[6477]: info: ControllerMpd::getState Jun 14 06:07:00 volumio volumio[6477]: verbose: ControllerMpd::sendMpdCommand status Jun 14 06:07:00 volumio volumio[6477]: info: Jun 14 06:07:00 volumio volumio[6477]: ---------------------------- MPD announces state update: player Jun 14 06:07:00 volumio volumio[6477]: info: sendMpdCommand status took 21 milliseconds Jun 14 06:07:00 volumio volumio[6477]: info: sendMpdCommand status took 21 milliseconds Jun 14 06:07:00 volumio volumio[6477]: info: ControllerMpd::getState Jun 14 06:07:00 volumio volumio[6477]: verbose: ControllerMpd::sendMpdCommand status Jun 14 06:07:00 volumio volumio[6477]: verbose: ControllerMpd::parseState Jun 14 06:07:00 volumio volumio[6477]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 14 06:07:00 volumio volumio[6477]: verbose: ControllerMpd::parseState Jun 14 06:07:00 volumio volumio[6477]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 14 06:07:00 volumio volumio[6477]: info: Jun 14 06:07:00 volumio volumio[6477]: ---------------------------- MPD announces state update: player Jun 14 06:07:00 volumio volumio[6477]: info: ControllerMpd::getState Jun 14 06:07:00 volumio volumio[6477]: verbose: ControllerMpd::sendMpdCommand status Jun 14 06:07:00 volumio volumio[6477]: info: Jun 14 06:07:00 volumio volumio[6477]: ---------------------------- MPD announces state update: player Jun 14 06:07:00 volumio volumio[6477]: info: ControllerMpd::getState Jun 14 06:07:00 volumio volumio[6477]: verbose: ControllerMpd::sendMpdCommand status Jun 14 06:07:00 volumio volumio[6477]: info: sendMpdCommand status took 23 milliseconds Jun 14 06:07:00 volumio volumio[6477]: info: sendMpdCommand status took 2 milliseconds Jun 14 06:07:00 volumio volumio[6477]: info: sendMpdCommand playlistinfo took 1 milliseconds Jun 14 06:07:00 volumio volumio[6477]: info: sendMpdCommand playlistinfo took 1 milliseconds Jun 14 06:07:00 volumio volumio[6477]: info: sendMpdCommand status took 1 milliseconds Jun 14 06:07:00 volumio volumio[6477]: info: sendMpdCommand status took 0 milliseconds Jun 14 06:07:00 volumio volumio[6477]: verbose: ControllerMpd::parseState Jun 14 06:07:00 volumio volumio[6477]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 14 06:07:00 volumio volumio[6477]: verbose: ControllerMpd::parseState Jun 14 06:07:00 volumio volumio[6477]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 14 06:07:00 volumio volumio[6477]: verbose: ControllerMpd::parseTrackInfo Jun 14 06:07:00 volumio volumio[6477]: verbose: ControllerMpd::parseTrackInfo Jun 14 06:07:00 volumio volumio[6477]: verbose: ControllerMpd::parseState Jun 14 06:07:00 volumio volumio[6477]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 14 06:07:00 volumio volumio[6477]: verbose: ControllerMpd::parseState Jun 14 06:07:00 volumio volumio[6477]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 14 06:07:00 volumio volumio[6477]: info: ControllerMpd::pushState Jun 14 06:07:00 volumio volumio[6477]: info: CoreCommandRouter::servicePushState Jun 14 06:07:00 volumio volumio[6477]: info: CorePlayQueue::getTrack 0 Jun 14 06:07:00 volumio volumio[6477]: 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":"Radio Gra Wrocław","artist":null,"album":null,"uri":"http://www.rmfon.pl/tunein/tunein.php?host=rs202-krk-cyfronet.rmfstream.pl&mount=radio_gra_wroc&secure=0","trackType":""} Jun 14 06:07:00 volumio volumio[6477]: verbose: CURRENT POSITION 0 Jun 14 06:07:00 volumio volumio[6477]: info: CoreStateMachine::syncState stateService play Jun 14 06:07:00 volumio volumio[6477]: info: CoreStateMachine::syncState currentStatus stop Jun 14 06:07:00 volumio volumio[6477]: info: ControllerMpd::pushState Jun 14 06:07:00 volumio volumio[6477]: info: CoreCommandRouter::servicePushState Jun 14 06:07:00 volumio volumio[6477]: info: CorePlayQueue::getTrack 0 Jun 14 06:07:00 volumio volumio[6477]: 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":"Radio Gra Wrocław","artist":null,"album":null,"uri":"http://www.rmfon.pl/tunein/tunein.php?host=rs202-krk-cyfronet.rmfstream.pl&mount=radio_gra_wroc&secure=0","trackType":""} Jun 14 06:07:00 volumio volumio[6477]: verbose: CURRENT POSITION 0 Jun 14 06:07:00 volumio volumio[6477]: info: CoreStateMachine::syncState stateService play Jun 14 06:07:00 volumio volumio[6477]: info: CoreStateMachine::syncState currentStatus play Jun 14 06:07:00 volumio volumio[6477]: info: Received an update from plugin. extracting info from payload Jun 14 06:07:00 volumio volumio[6477]: info: CoreStateMachine::pushState Jun 14 06:07:00 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 14 06:07:00 volumio volumio[6477]: info: CoreCommandRouter::volumioPushState Jun 14 06:07:00 volumio volumio[6477]: info: CoreStateMachine::pushState Jun 14 06:07:00 volumio volumio[6477]: info: CoreCommandRouter::volumioPushState Jun 14 06:07:00 volumio volumio[6477]: info: ------------------------------ 31ms Jun 14 06:07:00 volumio volumio[6477]: info: ------------------------------ 32ms Jun 14 06:07:00 volumio volumio[6477]: info: sendMpdCommand playlistinfo took 8 milliseconds Jun 14 06:07:00 volumio volumio[6477]: info: sendMpdCommand playlistinfo took 9 milliseconds Jun 14 06:07:00 volumio volumio[6477]: info: sendMpdCommand playlistinfo took 9 milliseconds Jun 14 06:07:00 volumio volumio[6477]: info: sendMpdCommand playlistinfo took 8 milliseconds Jun 14 06:07:00 volumio volumio[6477]: verbose: ControllerMpd::parseTrackInfo Jun 14 06:07:00 volumio volumio[6477]: verbose: ControllerMpd::parseTrackInfo Jun 14 06:07:00 volumio volumio[6477]: verbose: ControllerMpd::parseTrackInfo Jun 14 06:07:00 volumio volumio[6477]: verbose: ControllerMpd::parseTrackInfo Jun 14 06:07:00 volumio volumio[6477]: info: ControllerMpd::pushState Jun 14 06:07:00 volumio volumio[6477]: info: CoreCommandRouter::servicePushState Jun 14 06:07:00 volumio volumio[6477]: info: CorePlayQueue::getTrack 0 Jun 14 06:07:00 volumio volumio[6477]: 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":"Radio Gra Wrocław","artist":null,"album":null,"uri":"http://www.rmfon.pl/tunein/tunein.php?host=rs202-krk-cyfronet.rmfstream.pl&mount=radio_gra_wroc&secure=0","trackType":""} Jun 14 06:07:00 volumio volumio[6477]: verbose: CURRENT POSITION 0 Jun 14 06:07:00 volumio volumio[6477]: info: CoreStateMachine::syncState stateService play Jun 14 06:07:00 volumio volumio[6477]: info: CoreStateMachine::syncState currentStatus play Jun 14 06:07:00 volumio volumio[6477]: info: Received an update from plugin. extracting info from payload Jun 14 06:07:00 volumio volumio[6477]: info: CoreStateMachine::pushState Jun 14 06:07:00 volumio volumio[6477]: info: CoreCommandRouter::volumioPushState Jun 14 06:07:00 volumio volumio[6477]: info: CoreStateMachine::pushState Jun 14 06:07:00 volumio volumio[6477]: info: CoreCommandRouter::volumioPushState Jun 14 06:07:00 volumio volumio[6477]: info: ControllerMpd::pushState Jun 14 06:07:00 volumio volumio[6477]: info: CoreCommandRouter::servicePushState Jun 14 06:07:00 volumio volumio[6477]: info: CorePlayQueue::getTrack 0 Jun 14 06:07:00 volumio volumio[6477]: 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":"Radio Gra Wrocław","artist":null,"album":null,"uri":"http://www.rmfon.pl/tunein/tunein.php?host=rs202-krk-cyfronet.rmfstream.pl&mount=radio_gra_wroc&secure=0","trackType":""} Jun 14 06:07:00 volumio volumio[6477]: verbose: CURRENT POSITION 0 Jun 14 06:07:00 volumio volumio[6477]: info: CoreStateMachine::syncState stateService play Jun 14 06:07:00 volumio volumio[6477]: info: CoreStateMachine::syncState currentStatus play Jun 14 06:07:00 volumio volumio[6477]: info: Received an update from plugin. extracting info from payload Jun 14 06:07:00 volumio volumio[6477]: info: CoreStateMachine::pushState Jun 14 06:07:00 volumio volumio[6477]: info: CoreCommandRouter::volumioPushState Jun 14 06:07:00 volumio volumio[6477]: info: CoreStateMachine::pushState Jun 14 06:07:00 volumio volumio[6477]: info: CoreCommandRouter::volumioPushState Jun 14 06:07:00 volumio volumio[6477]: info: ControllerMpd::pushState Jun 14 06:07:00 volumio volumio[6477]: info: CoreCommandRouter::servicePushState Jun 14 06:07:00 volumio volumio[6477]: info: CorePlayQueue::getTrack 0 Jun 14 06:07:00 volumio volumio[6477]: 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":"Radio Gra Wrocław","artist":null,"album":null,"uri":"http://www.rmfon.pl/tunein/tunein.php?host=rs202-krk-cyfronet.rmfstream.pl&mount=radio_gra_wroc&secure=0","trackType":""} Jun 14 06:07:00 volumio volumio[6477]: verbose: CURRENT POSITION 0 Jun 14 06:07:00 volumio volumio[6477]: info: CoreStateMachine::syncState stateService play Jun 14 06:07:00 volumio volumio[6477]: info: CoreStateMachine::syncState currentStatus play Jun 14 06:07:00 volumio volumio[6477]: info: Received an update from plugin. extracting info from payload Jun 14 06:07:00 volumio volumio[6477]: info: CoreStateMachine::pushState Jun 14 06:07:00 volumio volumio[6477]: info: CoreCommandRouter::volumioPushState Jun 14 06:07:00 volumio volumio[6477]: info: CoreStateMachine::pushState Jun 14 06:07:00 volumio volumio[6477]: info: CoreCommandRouter::volumioPushState Jun 14 06:07:00 volumio volumio[6477]: info: ControllerMpd::pushState Jun 14 06:07:00 volumio volumio[6477]: info: CoreCommandRouter::servicePushState Jun 14 06:07:00 volumio volumio[6477]: info: CorePlayQueue::getTrack 0 Jun 14 06:07:00 volumio volumio[6477]: 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":"Radio Gra Wrocław","artist":null,"album":null,"uri":"http://www.rmfon.pl/tunein/tunein.php?host=rs202-krk-cyfronet.rmfstream.pl&mount=radio_gra_wroc&secure=0","trackType":""} Jun 14 06:07:00 volumio volumio[6477]: verbose: CURRENT POSITION 0 Jun 14 06:07:00 volumio volumio[6477]: info: CoreStateMachine::syncState stateService play Jun 14 06:07:00 volumio volumio[6477]: info: CoreStateMachine::syncState currentStatus play Jun 14 06:07:00 volumio volumio[6477]: info: Received an update from plugin. extracting info from payload Jun 14 06:07:00 volumio volumio[6477]: info: CoreStateMachine::pushState Jun 14 06:07:00 volumio volumio[6477]: info: CoreCommandRouter::volumioPushState Jun 14 06:07:00 volumio volumio[6477]: info: CoreStateMachine::pushState Jun 14 06:07:00 volumio volumio[6477]: info: CoreCommandRouter::volumioPushState Jun 14 06:07:00 volumio volumio[6477]: info: ------------------------------ 61ms Jun 14 06:07:00 volumio volumio[6477]: info: ------------------------------ 42ms Jun 14 06:07:00 volumio volumio[6477]: info: ------------------------------ 40ms Jun 14 06:07:00 volumio volumio[6477]: info: ------------------------------ 40ms Jun 14 06:07:00 volumio volumio[6477]: info: Jun 14 06:07:00 volumio volumio[6477]: ---------------------------- MPD announces system playlist update Jun 14 06:07:00 volumio volumio[6477]: info: Ignoring MPD Status Update Jun 14 06:07:00 volumio volumio[6477]: info: Jun 14 06:07:00 volumio volumio[6477]: ---------------------------- MPD announces state update: player Jun 14 06:07:00 volumio volumio[6477]: info: ControllerMpd::getState Jun 14 06:07:00 volumio volumio[6477]: verbose: ControllerMpd::sendMpdCommand status Jun 14 06:07:00 volumio volumio[6477]: info: Jun 14 06:07:00 volumio volumio[6477]: ---------------------------- MPD announces system playlist update Jun 14 06:07:00 volumio volumio[6477]: info: Ignoring MPD Status Update Jun 14 06:07:00 volumio volumio[6477]: info: Jun 14 06:07:00 volumio volumio[6477]: ---------------------------- MPD announces state update: player Jun 14 06:07:00 volumio volumio[6477]: info: ControllerMpd::getState Jun 14 06:07:00 volumio volumio[6477]: verbose: ControllerMpd::sendMpdCommand status Jun 14 06:07:00 volumio volumio[6477]: info: Jun 14 06:07:00 volumio volumio[6477]: ---------------------------- MPD announces system playlist update Jun 14 06:07:00 volumio volumio[6477]: info: Ignoring MPD Status Update Jun 14 06:07:00 volumio volumio[6477]: info: Jun 14 06:07:00 volumio volumio[6477]: ---------------------------- MPD announces state update: player Jun 14 06:07:00 volumio volumio[6477]: info: ControllerMpd::getState Jun 14 06:07:00 volumio volumio[6477]: verbose: ControllerMpd::sendMpdCommand status Jun 14 06:07:00 volumio volumio[6477]: info: ------------------------------ 6ms Jun 14 06:07:00 volumio volumio[6477]: info: sendMpdCommand status took 5 milliseconds Jun 14 06:07:00 volumio volumio[6477]: verbose: ControllerMpd::parseState Jun 14 06:07:00 volumio volumio[6477]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 14 06:07:00 volumio volumio[6477]: info: ------------------------------ 4ms Jun 14 06:07:00 volumio volumio[6477]: info: sendMpdCommand status took 5 milliseconds Jun 14 06:07:00 volumio volumio[6477]: info: ------------------------------ 4ms Jun 14 06:07:00 volumio volumio[6477]: info: sendMpdCommand status took 4 milliseconds Jun 14 06:07:00 volumio volumio[6477]: info: sendMpdCommand playlistinfo took 3 milliseconds Jun 14 06:07:00 volumio volumio[6477]: verbose: ControllerMpd::parseState Jun 14 06:07:00 volumio volumio[6477]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 14 06:07:00 volumio volumio[6477]: verbose: ControllerMpd::parseState Jun 14 06:07:00 volumio volumio[6477]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 14 06:07:00 volumio volumio[6477]: verbose: ControllerMpd::parseTrackInfo Jun 14 06:07:00 volumio volumio[6477]: info: ControllerMpd::pushState Jun 14 06:07:00 volumio volumio[6477]: info: CoreCommandRouter::servicePushState Jun 14 06:07:00 volumio volumio[6477]: info: CorePlayQueue::getTrack 0 Jun 14 06:07:00 volumio volumio[6477]: verbose: STATE SERVICE {"status":"play","position":0,"seek":980,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"tunein.php?host=rs202-krk-cyfronet.rmfstream.pl&mount=radio_gra_wroc&secure=0","artist":"Gra Wroclaw","album":null,"uri":"http://www.rmfon.pl/tunein/tunein.php?host=rs202-krk-cyfronet.rmfstream.pl&mount=radio_gra_wroc&secure=0","trackType":""} Jun 14 06:07:00 volumio volumio[6477]: verbose: CURRENT POSITION 0 Jun 14 06:07:00 volumio volumio[6477]: info: CoreStateMachine::syncState stateService play Jun 14 06:07:00 volumio volumio[6477]: info: CoreStateMachine::syncState currentStatus play Jun 14 06:07:00 volumio volumio[6477]: info: Received an update from plugin. extracting info from payload Jun 14 06:07:00 volumio volumio[6477]: info: CoreStateMachine::pushState Jun 14 06:07:00 volumio volumio[6477]: info: CorePlayQueue::getTrack 0 Jun 14 06:07:00 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 14 06:07:00 volumio volumio[6477]: info: CoreCommandRouter::volumioPushState Jun 14 06:07:00 volumio volumio[6477]: info: CoreStateMachine::pushState Jun 14 06:07:00 volumio volumio[6477]: info: CoreCommandRouter::volumioPushState Jun 14 06:07:00 volumio volumio[6477]: info: ------------------------------ 20ms Jun 14 06:07:00 volumio volumio[6477]: info: sendMpdCommand playlistinfo took 11 milliseconds Jun 14 06:07:00 volumio volumio[6477]: info: sendMpdCommand playlistinfo took 11 milliseconds Jun 14 06:07:00 volumio volumio[6477]: verbose: ControllerMpd::parseTrackInfo Jun 14 06:07:00 volumio volumio[6477]: verbose: ControllerMpd::parseTrackInfo Jun 14 06:07:00 volumio volumio[6477]: info: ControllerMpd::pushState Jun 14 06:07:00 volumio volumio[6477]: info: CoreCommandRouter::servicePushState Jun 14 06:07:00 volumio volumio[6477]: info: CorePlayQueue::getTrack 0 Jun 14 06:07:00 volumio volumio[6477]: verbose: STATE SERVICE {"status":"play","position":0,"seek":980,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"tunein.php?host=rs202-krk-cyfronet.rmfstream.pl&mount=radio_gra_wroc&secure=0","artist":"Gra Wroclaw","album":null,"uri":"http://www.rmfon.pl/tunein/tunein.php?host=rs202-krk-cyfronet.rmfstream.pl&mount=radio_gra_wroc&secure=0","trackType":""} Jun 14 06:07:00 volumio volumio[6477]: verbose: CURRENT POSITION 0 Jun 14 06:07:00 volumio volumio[6477]: info: CoreStateMachine::syncState stateService play Jun 14 06:07:00 volumio volumio[6477]: info: CoreStateMachine::syncState currentStatus play Jun 14 06:07:00 volumio volumio[6477]: info: Received an update from plugin. extracting info from payload Jun 14 06:07:00 volumio volumio[6477]: info: CoreStateMachine::pushState Jun 14 06:07:00 volumio volumio[6477]: info: CorePlayQueue::getTrack 0 Jun 14 06:07:00 volumio volumio[6477]: info: CoreCommandRouter::volumioPushState Jun 14 06:07:00 volumio volumio[6477]: info: CoreStateMachine::pushState Jun 14 06:07:00 volumio volumio[6477]: info: CoreCommandRouter::volumioPushState Jun 14 06:07:00 volumio volumio[6477]: info: ControllerMpd::pushState Jun 14 06:07:00 volumio volumio[6477]: info: CoreCommandRouter::servicePushState Jun 14 06:07:00 volumio volumio[6477]: info: CorePlayQueue::getTrack 0 Jun 14 06:07:00 volumio volumio[6477]: verbose: STATE SERVICE {"status":"play","position":0,"seek":980,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"tunein.php?host=rs202-krk-cyfronet.rmfstream.pl&mount=radio_gra_wroc&secure=0","artist":"Gra Wroclaw","album":null,"uri":"http://www.rmfon.pl/tunein/tunein.php?host=rs202-krk-cyfronet.rmfstream.pl&mount=radio_gra_wroc&secure=0","trackType":""} Jun 14 06:07:00 volumio volumio[6477]: verbose: CURRENT POSITION 0 Jun 14 06:07:00 volumio volumio[6477]: info: CoreStateMachine::syncState stateService play Jun 14 06:07:00 volumio volumio[6477]: info: CoreStateMachine::syncState currentStatus play Jun 14 06:07:00 volumio volumio[6477]: info: Received an update from plugin. extracting info from payload Jun 14 06:07:00 volumio volumio[6477]: info: CoreStateMachine::pushState Jun 14 06:07:00 volumio volumio[6477]: info: CorePlayQueue::getTrack 0 Jun 14 06:07:00 volumio volumio[6477]: info: CoreCommandRouter::volumioPushState Jun 14 06:07:00 volumio volumio[6477]: info: CoreStateMachine::pushState Jun 14 06:07:00 volumio volumio[6477]: info: CoreCommandRouter::volumioPushState Jun 14 06:07:00 volumio volumio[6477]: info: ------------------------------ 33ms Jun 14 06:07:00 volumio volumio[6477]: info: ------------------------------ 32ms Jun 14 06:07:05 volumio volumio[6477]: info: VolumeController::SetAlsaVolume78 Jun 14 06:07:05 volumio volumio[6477]: info: CoreStateMachine::pushState Jun 14 06:07:05 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 14 06:07:05 volumio volumio[6477]: info: CoreCommandRouter::volumioPushState Jun 14 06:07:09 volumio volumio[6477]: info: CoreCommandRouter::volumioGetState Jun 14 06:07:18 volumio volumio[6477]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 14 06:07:18 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jun 14 06:07:18 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jun 14 06:07:18 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jun 14 06:07:18 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableUIs Jun 14 06:07:18 volumio volumio[6477]: info: Received Get System Version Jun 14 06:07:18 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 14 06:07:21 volumio systemd[1]: systemd-timedated.service: Deactivated successfully. Jun 14 06:07:27 volumio volumio[6477]: info: Jun 14 06:07:27 volumio volumio[6477]: ---------------------------- MPD announces system playlist update Jun 14 06:07:27 volumio volumio[6477]: info: Ignoring MPD Status Update Jun 14 06:07:27 volumio volumio[6477]: info: Jun 14 06:07:27 volumio volumio[6477]: ---------------------------- MPD announces state update: player Jun 14 06:07:27 volumio volumio[6477]: info: ControllerMpd::getState Jun 14 06:07:27 volumio volumio[6477]: verbose: ControllerMpd::sendMpdCommand status Jun 14 06:07:27 volumio volumio[6477]: info: Jun 14 06:07:27 volumio volumio[6477]: ---------------------------- MPD announces system playlist update Jun 14 06:07:27 volumio volumio[6477]: info: Ignoring MPD Status Update Jun 14 06:07:27 volumio volumio[6477]: info: Jun 14 06:07:27 volumio volumio[6477]: ---------------------------- MPD announces state update: player Jun 14 06:07:27 volumio volumio[6477]: info: ControllerMpd::getState Jun 14 06:07:27 volumio volumio[6477]: verbose: ControllerMpd::sendMpdCommand status Jun 14 06:07:27 volumio volumio[6477]: info: Jun 14 06:07:27 volumio volumio[6477]: ---------------------------- MPD announces system playlist update Jun 14 06:07:27 volumio volumio[6477]: info: Ignoring MPD Status Update Jun 14 06:07:27 volumio volumio[6477]: info: Jun 14 06:07:27 volumio volumio[6477]: ---------------------------- MPD announces state update: player Jun 14 06:07:27 volumio volumio[6477]: info: ControllerMpd::getState Jun 14 06:07:27 volumio volumio[6477]: verbose: ControllerMpd::sendMpdCommand status Jun 14 06:07:27 volumio volumio[6477]: info: ------------------------------ 1ms Jun 14 06:07:27 volumio volumio[6477]: info: sendMpdCommand status took 1 milliseconds Jun 14 06:07:27 volumio volumio[6477]: info: ------------------------------ 1ms Jun 14 06:07:27 volumio volumio[6477]: verbose: ControllerMpd::parseState Jun 14 06:07:27 volumio volumio[6477]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 14 06:07:27 volumio volumio[6477]: info: sendMpdCommand status took 1 milliseconds Jun 14 06:07:27 volumio volumio[6477]: info: ------------------------------ 1ms Jun 14 06:07:27 volumio volumio[6477]: info: sendMpdCommand status took 2 milliseconds Jun 14 06:07:27 volumio volumio[6477]: info: sendMpdCommand playlistinfo took 1 milliseconds Jun 14 06:07:27 volumio volumio[6477]: verbose: ControllerMpd::parseState Jun 14 06:07:27 volumio volumio[6477]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 14 06:07:27 volumio volumio[6477]: verbose: ControllerMpd::parseState Jun 14 06:07:27 volumio volumio[6477]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 14 06:07:27 volumio volumio[6477]: verbose: ControllerMpd::parseTrackInfo Jun 14 06:07:27 volumio volumio[6477]: info: ControllerMpd::pushState Jun 14 06:07:27 volumio volumio[6477]: info: CoreCommandRouter::servicePushState Jun 14 06:07:27 volumio volumio[6477]: info: CorePlayQueue::getTrack 0 Jun 14 06:07:27 volumio volumio[6477]: verbose: STATE SERVICE {"status":"play","position":0,"seek":27853,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"RADIO GRA WROCLAW - RADIO GRA WROCLAW","artist":"Gra Wroclaw","album":null,"uri":"http://www.rmfon.pl/tunein/tunein.php?host=rs202-krk-cyfronet.rmfstream.pl&mount=radio_gra_wroc&secure=0","trackType":""} Jun 14 06:07:27 volumio volumio[6477]: verbose: CURRENT POSITION 0 Jun 14 06:07:27 volumio volumio[6477]: info: CoreStateMachine::syncState stateService play Jun 14 06:07:27 volumio volumio[6477]: info: CoreStateMachine::syncState currentStatus play Jun 14 06:07:27 volumio volumio[6477]: info: Received an update from plugin. extracting info from payload Jun 14 06:07:27 volumio volumio[6477]: info: CoreStateMachine::pushState Jun 14 06:07:27 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 14 06:07:27 volumio volumio[6477]: info: CoreCommandRouter::volumioPushState Jun 14 06:07:27 volumio volumio[6477]: info: CoreStateMachine::pushState Jun 14 06:07:27 volumio volumio[6477]: info: CoreCommandRouter::volumioPushState Jun 14 06:07:27 volumio volumio[6477]: info: ------------------------------ 8ms Jun 14 06:07:27 volumio volumio[6477]: info: sendMpdCommand playlistinfo took 5 milliseconds Jun 14 06:07:27 volumio volumio[6477]: info: sendMpdCommand playlistinfo took 5 milliseconds Jun 14 06:07:27 volumio volumio[6477]: verbose: ControllerMpd::parseTrackInfo Jun 14 06:07:27 volumio volumio[6477]: verbose: ControllerMpd::parseTrackInfo Jun 14 06:07:27 volumio volumio[6477]: info: ControllerMpd::pushState Jun 14 06:07:27 volumio volumio[6477]: info: CoreCommandRouter::servicePushState Jun 14 06:07:27 volumio volumio[6477]: info: CorePlayQueue::getTrack 0 Jun 14 06:07:27 volumio volumio[6477]: verbose: STATE SERVICE {"status":"play","position":0,"seek":27853,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"RADIO GRA WROCLAW - RADIO GRA WROCLAW","artist":"Gra Wroclaw","album":null,"uri":"http://www.rmfon.pl/tunein/tunein.php?host=rs202-krk-cyfronet.rmfstream.pl&mount=radio_gra_wroc&secure=0","trackType":""} Jun 14 06:07:27 volumio volumio[6477]: verbose: CURRENT POSITION 0 Jun 14 06:07:27 volumio volumio[6477]: info: CoreStateMachine::syncState stateService play Jun 14 06:07:27 volumio volumio[6477]: info: CoreStateMachine::syncState currentStatus play Jun 14 06:07:27 volumio volumio[6477]: info: Received an update from plugin. extracting info from payload Jun 14 06:07:27 volumio volumio[6477]: info: CoreStateMachine::pushState Jun 14 06:07:27 volumio volumio[6477]: info: CoreCommandRouter::volumioPushState Jun 14 06:07:27 volumio volumio[6477]: info: CoreStateMachine::pushState Jun 14 06:07:27 volumio volumio[6477]: info: CoreCommandRouter::volumioPushState Jun 14 06:07:27 volumio volumio[6477]: info: ControllerMpd::pushState Jun 14 06:07:27 volumio volumio[6477]: info: CoreCommandRouter::servicePushState Jun 14 06:07:27 volumio volumio[6477]: info: CorePlayQueue::getTrack 0 Jun 14 06:07:27 volumio volumio[6477]: verbose: STATE SERVICE {"status":"play","position":0,"seek":27853,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"RADIO GRA WROCLAW - RADIO GRA WROCLAW","artist":"Gra Wroclaw","album":null,"uri":"http://www.rmfon.pl/tunein/tunein.php?host=rs202-krk-cyfronet.rmfstream.pl&mount=radio_gra_wroc&secure=0","trackType":""} Jun 14 06:07:27 volumio volumio[6477]: verbose: CURRENT POSITION 0 Jun 14 06:07:27 volumio volumio[6477]: info: CoreStateMachine::syncState stateService play Jun 14 06:07:27 volumio volumio[6477]: info: CoreStateMachine::syncState currentStatus play Jun 14 06:07:27 volumio volumio[6477]: info: Received an update from plugin. extracting info from payload Jun 14 06:07:27 volumio volumio[6477]: info: CoreStateMachine::pushState Jun 14 06:07:27 volumio volumio[6477]: info: CoreCommandRouter::volumioPushState Jun 14 06:07:27 volumio volumio[6477]: info: CoreStateMachine::pushState Jun 14 06:07:27 volumio volumio[6477]: info: CoreCommandRouter::volumioPushState Jun 14 06:07:27 volumio volumio[6477]: info: ------------------------------ 23ms Jun 14 06:07:27 volumio volumio[6477]: info: ------------------------------ 23ms Jun 14 06:07:27 volumio volumio[6477]: info: CALLMETHOD: miscellanea appearance setVolumio3UI [object Object] Jun 14 06:07:27 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: appearance , setVolumio3UI Jun 14 06:07:27 volumio volumio[6477]: info: Setting active UI to: {"uiPrettyName":"Contemporary","uiName":"contemporary","uiPath":"/volumio/http/www3"} Jun 14 06:07:28 volumio volumio[6477]: info: CoreCommandRouter::Reload Ui Jun 14 06:07:29 volumio volumio[6477]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Jun 14 06:07:29 volumio volumio[6477]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 14 06:07:29 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jun 14 06:07:29 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 14 06:07:29 volumio volumio[6477]: info: CoreCommandRouter::volumioGetState Jun 14 06:07:29 volumio volumio[6477]: info: CoreCommandRouter::volumioGetVisibleSources Jun 14 06:07:29 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 14 06:07:29 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jun 14 06:07:29 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jun 14 06:07:29 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jun 14 06:07:29 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 14 06:07:29 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jun 14 06:07:29 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jun 14 06:07:29 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableUIs Jun 14 06:07:30 volumio volumio[6477]: info: Received Get System Version Jun 14 06:07:30 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 14 06:07:30 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: appearance , getBackgrounds Jun 14 06:07:31 volumio volumio[6477]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Jun 14 06:07:32 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 14 06:07:32 volumio volumio[6477]: info: CoreCommandRouter::volumioGetState Jun 14 06:07:32 volumio volumio[6477]: info: CoreCommandRouter::volumioGetVisibleSources Jun 14 06:07:32 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 14 06:07:32 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 14 06:07:32 volumio volumio[6477]: info: Received Get System Info Jun 14 06:07:32 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 14 06:07:32 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 14 06:07:32 volumio volumio[6477]: info: Discovery: Getting this device information Jun 14 06:07:32 volumio volumio[6477]: info: CoreCommandRouter::volumioGetState Jun 14 06:07:32 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 14 06:07:47 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 14 06:07:47 volumio volumio[6477]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Jun 14 06:07:47 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Jun 14 06:07:47 volumio volumio[6477]: info: Received Get System Version Jun 14 06:07:47 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 14 06:07:47 volumio volumio[6477]: info: Received Get System Info Jun 14 06:07:47 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 14 06:07:47 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 14 06:07:47 volumio volumio[6477]: info: Discovery: Getting this device information Jun 14 06:07:47 volumio volumio[6477]: info: CoreCommandRouter::volumioGetState Jun 14 06:07:47 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 14 06:07:59 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Jun 14 06:07:59 volumio volumio[6477]: info: MyVolumio login type: Token Jun 14 06:08:00 volumio volumio[6477]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jun 14 06:08:00 volumio volumio[6477]: info: MyVolumio token set successfully Jun 14 06:08:00 volumio volumio[6477]: info: MYVOLUMIO: Adding device Jun 14 06:08:00 volumio volumio[6477]: info: MYVOLUMIO: Evaluating Server Jun 14 06:08:01 volumio volumio[6477]: info: MyVolumio Plan changed: premium Jun 14 06:08:01 volumio volumio[6477]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Jun 14 06:08:01 volumio volumio[6477]: info: Removing browser output: myVolumio user plan is not superstar Jun 14 06:08:01 volumio volumio[6477]: info: Removing audio output: Jun 14 06:08:01 volumio volumio[6477]: info: MYVOLUMIO: Adding device Jun 14 06:08:01 volumio volumio[6477]: info: MYVOLUMIO: Evaluating Server Jun 14 06:08:01 volumio volumio[6477]: info: Remote config written successfully Jun 14 06:08:01 volumio volumio[6477]: info: Starting Tunnel 1 Jun 14 06:08:01 volumio volumio[6477]: info: Starting Tunnel Connection Checker Jun 14 06:08:01 volumio volumio[6477]: info: MYVolumio Device disabled Jun 14 06:08:01 volumio volumio[6477]: info: MyVolumio status changed Jun 14 06:08:01 volumio volumio[6477]: info: Streaming services startup Jun 14 06:08:01 volumio volumio[6477]: info: Starting Streaming Daemon Jun 14 06:08:01 volumio sudo[7313]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jun 14 06:08:01 volumio sudo[7313]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 14 06:08:01 volumio systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... Jun 14 06:08:01 volumio sudo[7313]: pam_unix(sudo:session): session closed for user root Jun 14 06:08:01 volumio volumio[6477]: error: Cannot start Volumio Streaming Daemon Jun 14 06:08:01 volumio volumio[6477]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jun 14 06:08:01 volumio volumio[6477]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jun 14 06:08:01 volumio dbus-daemon[826]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.96' (uid=0 pid=7316 comm="timedatectl show --property=NTPSynchronized --valu") Jun 14 06:08:01 volumio systemd[1]: Starting systemd-timedated.service - Time & Date Service... Jun 14 06:08:01 volumio dbus-daemon[826]: [system] Successfully activated service 'org.freedesktop.timedate1' Jun 14 06:08:01 volumio systemd[1]: Started systemd-timedated.service - Time & Date Service. Jun 14 06:08:01 volumio setdatetime-helper.sh[7315]: Time is not synchronized. Attempting to sync... Jun 14 06:08:01 volumio volumio[6477]: info: Setting Geolocation for MyVolumio to eu4 Jun 14 06:08:01 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 14 06:08:01 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 14 06:08:01 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 14 06:08:01 volumio volumio[6477]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 14 06:08:01 volumio sudo[7324]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/date -s 'Sat, 14 Jun 2025 04:08:01 GMT#015' Jun 14 06:08:01 volumio sudo[7324]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jun 14 06:08:01 volumio setdatetime-helper.sh[7325]: Sat Jun 14 06:08:01 CEST 2025 Jun 14 06:08:01 volumio systemd-journald[507]: Time jumped backwards, rotating. Jun 14 06:08:01 volumio setdatetime-helper.sh[7315]: Time synchronized successfully. Jun 14 06:08:01 volumio sudo[7324]: pam_unix(sudo:session): session closed for user root Jun 14 06:08:01 volumio systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. Jun 14 06:08:01 volumio volumio[6477]: error: Failed to ping endpoint as1.myvolumio.org : unknown error Jun 14 06:08:01 volumio systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. Jun 14 06:08:01 volumio volumio[6477]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 14 06:08:01 volumio volumio[6477]: Error: Unable to resolve or reject the same promise twice Jun 14 06:08:01 volumio volumio[6477]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Jun 14 06:08:01 volumio volumio[6477]: at Socket. (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:32371) Jun 14 06:08:01 volumio volumio[6477]: at Socket.emit (node:events:514:28) Jun 14 06:08:01 volumio volumio[6477]: at addChunk (node:internal/streams/readable:343:12) Jun 14 06:08:01 volumio volumio[6477]: at readableAddChunk (node:internal/streams/readable:316:9) Jun 14 06:08:01 volumio volumio[6477]: at Readable.push (node:internal/streams/readable:253:10) Jun 14 06:08:01 volumio volumio[6477]: at Pipe.onStreamRead (node:internal/stream_base_commons:190:23) Jun 14 06:08:01 volumio volumio[6477]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 14 06:08:01 volumio systemd[1]: Starting apt-daily-upgrade.service - Daily apt upgrade and clean activities... Jun 14 06:08:01 volumio sudo[7345]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-06-14 06:07' Jun 14 06:08:01 volumio sudo[7345]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="9c17cc34697ef689c9c9b64ea62ec0a8e386d7ce" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat Jun 7 03:41:32 UTC 2025" VOLUMIO_VERSION="4.011" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="3d7d070df9925b1237bac9fe8beec51e"