-- Logs begin at Thu 2019-02-14 12:11:59 EET, end at Fri 2025-10-17 12:11:46 EEST. -- Oct 17 12:10:10 volumio volumio[1130]: info: CoreCommandRouter::executeOnPlugin: radio_paradise , handleBrowseUri Oct 17 12:10:10 volumio volumio[1130]: info: Preload queue cleared Oct 17 12:10:17 volumio volumio[1130]: info: Preload queue cleared Oct 17 12:10:17 volumio volumio[1130]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 17 12:10:17 volumio volumio[1130]: info: CoreStateMachine::ClearQueue Oct 17 12:10:17 volumio volumio[1130]: info: CoreStateMachine::stop Oct 17 12:10:17 volumio volumio[1130]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 12:10:17 volumio volumio[1130]: info: CoreStateMachine::stPlaybackTimer Oct 17 12:10:17 volumio volumio[1130]: info: CoreStateMachine::updateTrackBlock Oct 17 12:10:17 volumio volumio[1130]: info: CorePlayQueue::getTrackBlock Oct 17 12:10:17 volumio volumio[1130]: info: CoreStateMachine::pushState Oct 17 12:10:17 volumio volumio[1130]: info: CorePlayQueue::getTrack 1 Oct 17 12:10:17 volumio volumio[1130]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 17 12:10:17 volumio volumio[1130]: info: CoreCommandRouter::volumioPushState Oct 17 12:10:17 volumio volumio[1130]: info: CoreStateMachine::serviceStop Oct 17 12:10:17 volumio volumio[1130]: info: CorePlayQueue::getTrack 1 Oct 17 12:10:17 volumio volumio[1130]: info: CoreCommandRouter::serviceStop Oct 17 12:10:17 volumio volumio[1130]: info: ControllerMpd::stop Oct 17 12:10:17 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand stop Oct 17 12:10:17 volumio volumio[1130]: info: CorePlayQueue::clearPlayQueue Oct 17 12:10:17 volumio volumio[1130]: info: CorePlayQueue::saveQueue Oct 17 12:10:17 volumio volumio[1130]: info: CoreCommandRouter::volumioPushQueue Oct 17 12:10:17 volumio volumio[1130]: info: CoreStateMachine::addQueueItems Oct 17 12:10:17 volumio volumio[1130]: info: CorePlayQueue::addQueueItems Oct 17 12:10:17 volumio volumio[1130]: info: Preload queue cleared Oct 17 12:10:17 volumio volumio[1130]: info: Adding Item to queue: webrp/2 Oct 17 12:10:17 volumio volumio[1130]: info: Exploding uri webrp/2 in service radio_paradise Oct 17 12:10:17 volumio volumio[1130]: info: CoreCommandRouter::volumioPushQueue Oct 17 12:10:17 volumio volumio[1130]: info: CorePlayQueue::saveQueue Oct 17 12:10:17 volumio volumio[1130]: info: CoreStateMachine::updateTrackBlock Oct 17 12:10:17 volumio volumio[1130]: info: CorePlayQueue::getTrackBlock Oct 17 12:10:17 volumio volumio[1130]: info: CoreCommandRouter::volumioPlay Oct 17 12:10:17 volumio volumio[1130]: info: CoreStateMachine::play index 0 Oct 17 12:10:17 volumio volumio[1130]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 12:10:17 volumio volumio[1130]: info: CoreStateMachine::stop Oct 17 12:10:17 volumio volumio[1130]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 12:10:17 volumio volumio[1130]: info: CoreStateMachine::play index undefined Oct 17 12:10:17 volumio volumio[1130]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 12:10:17 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:17 volumio volumio[1130]: info: CoreStateMachine::startPlaybackTimer Oct 17 12:10:17 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:17 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand stop Oct 17 12:10:17 volumio volumio[1130]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 17 12:10:17 volumio volumio[1130]: info: Oct 17 12:10:17 volumio volumio[1130]: ---------------------------- MPD announces state update: player Oct 17 12:10:17 volumio volumio[1130]: info: sendMpdCommand stop took 15 milliseconds Oct 17 12:10:17 volumio volumio[1130]: info: ControllerMpd::getState Oct 17 12:10:17 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand status Oct 17 12:10:17 volumio volumio[1130]: info: sendMpdCommand stop took 3 milliseconds Oct 17 12:10:17 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:10:17 volumio volumio[1130]: info: CoreStateMachine::pushState Oct 17 12:10:17 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:17 volumio volumio[1130]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 17 12:10:17 volumio volumio[1130]: info: CoreCommandRouter::volumioPushState Oct 17 12:10:17 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:17 volumio volumio[1130]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received 80s80s Oct 17 12:10:17 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand clear Oct 17 12:10:17 volumio volumio[1130]: info: Oct 17 12:10:17 volumio volumio[1130]: ---------------------------- MPD announces state update: player Oct 17 12:10:17 volumio volumio[1130]: info: ControllerMpd::getState Oct 17 12:10:17 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand status Oct 17 12:10:17 volumio volumio[1130]: info: Oct 17 12:10:17 volumio volumio[1130]: ---------------------------- MPD announces state update: player Oct 17 12:10:17 volumio volumio[1130]: info: ControllerMpd::getState Oct 17 12:10:17 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand status Oct 17 12:10:17 volumio volumio[1130]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 17 12:10:17 volumio volumio[1130]: info: Oct 17 12:10:17 volumio volumio[1130]: ---------------------------- MPD announces system playlist update Oct 17 12:10:17 volumio volumio[1130]: info: Ignoring MPD Status Update Oct 17 12:10:17 volumio volumio[1130]: info: sendMpdCommand status took 8 milliseconds Oct 17 12:10:17 volumio volumio[1130]: info: sendMpdCommand clear took 5 milliseconds Oct 17 12:10:17 volumio volumio[1130]: info: sendMpdCommand status took 3 milliseconds Oct 17 12:10:17 volumio volumio[1130]: info: sendMpdCommand status took 3 milliseconds Oct 17 12:10:17 volumio volumio[1130]: verbose: ControllerMpd::parseState Oct 17 12:10:17 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 12:10:17 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand consume 1 Oct 17 12:10:17 volumio volumio[1130]: verbose: ControllerMpd::parseState Oct 17 12:10:17 volumio volumio[1130]: verbose: ControllerMpd::parseState Oct 17 12:10:17 volumio volumio[1130]: info: ControllerMpd::pushState Oct 17 12:10:17 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:10:17 volumio volumio[1130]: info: CoreStateMachine::pushState Oct 17 12:10:17 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:17 volumio volumio[1130]: info: CoreCommandRouter::volumioPushState Oct 17 12:10:17 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:17 volumio volumio[1130]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 17 12:10:17 volumio volumio[1130]: info: ControllerMpd::pushState Oct 17 12:10:17 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:10:17 volumio volumio[1130]: info: CoreStateMachine::pushState Oct 17 12:10:17 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:17 volumio volumio[1130]: info: CoreCommandRouter::volumioPushState Oct 17 12:10:17 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:17 volumio volumio[1130]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 17 12:10:17 volumio volumio[1130]: info: ------------------------------ 10ms Oct 17 12:10:17 volumio volumio[1130]: info: ------------------------------ 9ms Oct 17 12:10:17 volumio volumio[1130]: info: Oct 17 12:10:17 volumio volumio[1130]: ---------------------------- MPD announces system playlist update Oct 17 12:10:17 volumio volumio[1130]: info: Ignoring MPD Status Update Oct 17 12:10:17 volumio volumio[1130]: info: Oct 17 12:10:17 volumio volumio[1130]: ---------------------------- MPD announces system playlist update Oct 17 12:10:17 volumio volumio[1130]: info: Ignoring MPD Status Update Oct 17 12:10:17 volumio volumio[1130]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 17 12:10:17 volumio volumio[1130]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 17 12:10:17 volumio volumio[1130]: error: updateQueue error: null Oct 17 12:10:17 volumio volumio[1130]: error: updateQueue error: null Oct 17 12:10:17 volumio volumio[1130]: error: updateQueue error: null Oct 17 12:10:17 volumio volumio[1130]: info: ------------------------------ 14ms Oct 17 12:10:17 volumio volumio[1130]: info: sendMpdCommand playlistinfo took 13 milliseconds Oct 17 12:10:17 volumio volumio[1130]: info: sendMpdCommand consume 1 took 12 milliseconds Oct 17 12:10:17 volumio volumio[1130]: info: ------------------------------ 6ms Oct 17 12:10:17 volumio volumio[1130]: info: ------------------------------ 6ms Oct 17 12:10:17 volumio volumio[1130]: verbose: ControllerMpd::parseTrackInfo Oct 17 12:10:17 volumio volumio[1130]: info: [1760692217102] [RadioParadise] set to consume mode, adding url: https://stream.radioparadise.com/rock-flac Oct 17 12:10:17 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand add "https://stream.radioparadise.com/rock-flac" Oct 17 12:10:17 volumio volumio[1130]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Oct 17 12:10:17 volumio volumio[1130]: info: ------------------------------ 22ms Oct 17 12:10:17 volumio volumio[1130]: info: Oct 17 12:10:17 volumio volumio[1130]: ---------------------------- MPD announces system playlist update Oct 17 12:10:17 volumio volumio[1130]: info: Ignoring MPD Status Update Oct 17 12:10:17 volumio volumio[1130]: info: sendMpdCommand add "https://stream.radioparadise.com/rock-flac" took 1 milliseconds Oct 17 12:10:17 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand play Oct 17 12:10:17 volumio volumio[1130]: info: Oct 17 12:10:17 volumio volumio[1130]: ---------------------------- MPD announces system playlist update Oct 17 12:10:17 volumio volumio[1130]: info: Ignoring MPD Status Update Oct 17 12:10:17 volumio volumio[1130]: info: Oct 17 12:10:17 volumio volumio[1130]: ---------------------------- MPD announces system playlist update Oct 17 12:10:17 volumio volumio[1130]: info: Ignoring MPD Status Update Oct 17 12:10:17 volumio volumio[1130]: info: ------------------------------ 4ms Oct 17 12:10:17 volumio volumio[1130]: info: sendMpdCommand play took 2 milliseconds Oct 17 12:10:17 volumio volumio[1130]: info: ------------------------------ 2ms Oct 17 12:10:17 volumio volumio[1130]: info: ------------------------------ 1ms Oct 17 12:10:17 volumio volumio[1130]: info: [1760692217107] [RadioParadise] getMetadata started with url https://api.radioparadise.com/api/now_playing?chan=2 Oct 17 12:10:17 volumio volumio[1130]: info: [1760692217730] [RadioParadise] received new metadata: {"time":51,"artist":"Talking Heads","title":"Crosseyed And Painless","album":"Remain In Light","year":"1980","cover":"https://img.radioparadise.com/covers/l/B000002KO3.jpg","cover_med":"https://img.radioparadise.com/covers/m/B000002KO3.jpg","cover_small":"https://img.radioparadise.com/covers/s/B000002KO3.jpg"} Oct 17 12:10:17 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:17 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:10:17 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:17 volumio volumio[1130]: verbose: STATE SERVICE {"status":"play","service":"radio_paradise","type":"webradio","trackType":"flac","radioType":"rparadise","albumart":"https://img.radioparadise.com/covers/l/B000002KO3.jpg","uri":"https://stream.radioparadise.com/rock-flac","name":"Crosseyed And Painless","title":"Crosseyed And Painless","artist":"Talking Heads","album":"Remain In Light","streaming":true,"disableUiControls":true,"duration":56,"seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Oct 17 12:10:17 volumio volumio[1130]: verbose: CURRENT POSITION 0 Oct 17 12:10:17 volumio volumio[1130]: info: CoreStateMachine::syncState stateService play Oct 17 12:10:17 volumio volumio[1130]: info: CoreStateMachine::syncState currentStatus stop Oct 17 12:10:17 volumio volumio[1130]: info: [1760692217731] [RadioParadise] setting new timer with duration of 56000 seconds. Oct 17 12:10:17 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:17 volumio volumio[1130]: info: CorePlayQueue::getTrack 1 Oct 17 12:10:18 volumio volumio[1130]: info: Oct 17 12:10:18 volumio volumio[1130]: ---------------------------- MPD announces state update: player Oct 17 12:10:18 volumio volumio[1130]: info: ControllerMpd::getState Oct 17 12:10:18 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand status Oct 17 12:10:18 volumio volumio[1130]: info: Oct 17 12:10:18 volumio volumio[1130]: ---------------------------- MPD announces state update: player Oct 17 12:10:18 volumio volumio[1130]: info: ControllerMpd::getState Oct 17 12:10:18 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand status Oct 17 12:10:18 volumio volumio[1130]: info: Oct 17 12:10:18 volumio volumio[1130]: ---------------------------- MPD announces state update: player Oct 17 12:10:18 volumio volumio[1130]: info: ControllerMpd::getState Oct 17 12:10:18 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand status Oct 17 12:10:18 volumio volumio[1130]: info: Oct 17 12:10:18 volumio volumio[1130]: ---------------------------- MPD announces state update: player Oct 17 12:10:18 volumio volumio[1130]: info: sendMpdCommand status took 14 milliseconds Oct 17 12:10:18 volumio volumio[1130]: info: sendMpdCommand status took 13 milliseconds Oct 17 12:10:18 volumio volumio[1130]: info: ControllerMpd::getState Oct 17 12:10:18 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand status Oct 17 12:10:18 volumio volumio[1130]: verbose: ControllerMpd::parseState Oct 17 12:10:18 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 12:10:18 volumio volumio[1130]: verbose: ControllerMpd::parseState Oct 17 12:10:18 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 12:10:18 volumio volumio[1130]: verbose: ControllerMpd::parseState Oct 17 12:10:18 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 12:10:18 volumio volumio[1130]: info: Oct 17 12:10:18 volumio volumio[1130]: ---------------------------- MPD announces state update: player Oct 17 12:10:18 volumio volumio[1130]: info: ControllerMpd::getState Oct 17 12:10:18 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand status Oct 17 12:10:18 volumio volumio[1130]: info: Oct 17 12:10:18 volumio volumio[1130]: ---------------------------- MPD announces state update: player Oct 17 12:10:18 volumio volumio[1130]: info: ControllerMpd::getState Oct 17 12:10:18 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand status Oct 17 12:10:18 volumio volumio[1130]: info: sendMpdCommand status took 6 milliseconds Oct 17 12:10:18 volumio volumio[1130]: info: sendMpdCommand playlistinfo took 6 milliseconds Oct 17 12:10:18 volumio volumio[1130]: info: sendMpdCommand playlistinfo took 5 milliseconds Oct 17 12:10:18 volumio volumio[1130]: info: sendMpdCommand status took 3 milliseconds Oct 17 12:10:18 volumio volumio[1130]: verbose: ControllerMpd::parseState Oct 17 12:10:18 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 12:10:18 volumio volumio[1130]: verbose: ControllerMpd::parseTrackInfo Oct 17 12:10:18 volumio volumio[1130]: verbose: ControllerMpd::parseState Oct 17 12:10:18 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 12:10:18 volumio volumio[1130]: verbose: ControllerMpd::parseState Oct 17 12:10:18 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 12:10:18 volumio volumio[1130]: info: ControllerMpd::pushState Oct 17 12:10:18 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:10:18 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:18 volumio volumio[1130]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 17 12:10:18 volumio volumio[1130]: info: ControllerMpd::pushState Oct 17 12:10:18 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:10:18 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:18 volumio volumio[1130]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 17 12:10:18 volumio volumio[1130]: info: ControllerMpd::pushState Oct 17 12:10:18 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:10:18 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:18 volumio volumio[1130]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 17 12:10:18 volumio volumio[1130]: info: ------------------------------ 25ms Oct 17 12:10:18 volumio volumio[1130]: info: ------------------------------ 24ms Oct 17 12:10:18 volumio volumio[1130]: info: ------------------------------ 23ms Oct 17 12:10:18 volumio volumio[1130]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 17 12:10:18 volumio volumio[1130]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 17 12:10:18 volumio volumio[1130]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 17 12:10:18 volumio volumio[1130]: verbose: ControllerMpd::parseTrackInfo Oct 17 12:10:18 volumio volumio[1130]: verbose: ControllerMpd::parseTrackInfo Oct 17 12:10:18 volumio volumio[1130]: verbose: ControllerMpd::parseTrackInfo Oct 17 12:10:18 volumio volumio[1130]: info: ControllerMpd::pushState Oct 17 12:10:18 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:10:18 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:18 volumio volumio[1130]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 17 12:10:18 volumio volumio[1130]: info: ControllerMpd::pushState Oct 17 12:10:18 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:10:18 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:18 volumio volumio[1130]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 17 12:10:18 volumio volumio[1130]: info: ControllerMpd::pushState Oct 17 12:10:18 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:10:18 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:18 volumio volumio[1130]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 17 12:10:18 volumio volumio[1130]: info: ------------------------------ 13ms Oct 17 12:10:18 volumio volumio[1130]: info: ------------------------------ 9ms Oct 17 12:10:18 volumio volumio[1130]: info: ------------------------------ 8ms Oct 17 12:10:18 volumio volumio[1130]: info: Oct 17 12:10:18 volumio volumio[1130]: ---------------------------- MPD announces system playlist update Oct 17 12:10:18 volumio volumio[1130]: info: Ignoring MPD Status Update Oct 17 12:10:18 volumio volumio[1130]: info: Oct 17 12:10:18 volumio volumio[1130]: ---------------------------- MPD announces state update: player Oct 17 12:10:18 volumio volumio[1130]: info: ControllerMpd::getState Oct 17 12:10:18 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand status Oct 17 12:10:18 volumio volumio[1130]: info: Oct 17 12:10:18 volumio volumio[1130]: ---------------------------- MPD announces system playlist update Oct 17 12:10:18 volumio volumio[1130]: info: Ignoring MPD Status Update Oct 17 12:10:18 volumio volumio[1130]: info: Oct 17 12:10:18 volumio volumio[1130]: ---------------------------- MPD announces state update: player Oct 17 12:10:18 volumio volumio[1130]: info: ControllerMpd::getState Oct 17 12:10:18 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand status Oct 17 12:10:18 volumio volumio[1130]: info: Oct 17 12:10:18 volumio volumio[1130]: ---------------------------- MPD announces system playlist update Oct 17 12:10:18 volumio volumio[1130]: info: Ignoring MPD Status Update Oct 17 12:10:18 volumio volumio[1130]: info: Oct 17 12:10:18 volumio volumio[1130]: ---------------------------- MPD announces state update: player Oct 17 12:10:18 volumio volumio[1130]: info: ControllerMpd::getState Oct 17 12:10:18 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand status Oct 17 12:10:18 volumio volumio[1130]: info: ------------------------------ 6ms Oct 17 12:10:18 volumio volumio[1130]: info: sendMpdCommand status took 4 milliseconds Oct 17 12:10:18 volumio volumio[1130]: info: ------------------------------ 3ms Oct 17 12:10:18 volumio volumio[1130]: info: sendMpdCommand status took 2 milliseconds Oct 17 12:10:18 volumio volumio[1130]: verbose: ControllerMpd::parseState Oct 17 12:10:18 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 12:10:18 volumio volumio[1130]: verbose: ControllerMpd::parseState Oct 17 12:10:18 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 12:10:18 volumio volumio[1130]: info: ------------------------------ 3ms Oct 17 12:10:18 volumio volumio[1130]: info: sendMpdCommand status took 3 milliseconds Oct 17 12:10:18 volumio volumio[1130]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 17 12:10:18 volumio volumio[1130]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 17 12:10:18 volumio volumio[1130]: verbose: ControllerMpd::parseState Oct 17 12:10:18 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 12:10:18 volumio volumio[1130]: verbose: ControllerMpd::parseTrackInfo Oct 17 12:10:18 volumio volumio[1130]: verbose: ControllerMpd::parseTrackInfo Oct 17 12:10:18 volumio volumio[1130]: info: ControllerMpd::pushState Oct 17 12:10:18 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:10:18 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:18 volumio volumio[1130]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 17 12:10:18 volumio volumio[1130]: info: ControllerMpd::pushState Oct 17 12:10:18 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:10:18 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:18 volumio volumio[1130]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 17 12:10:18 volumio volumio[1130]: info: ------------------------------ 10ms Oct 17 12:10:18 volumio volumio[1130]: info: ------------------------------ 9ms Oct 17 12:10:18 volumio volumio[1130]: info: sendMpdCommand playlistinfo took 5 milliseconds Oct 17 12:10:18 volumio volumio[1130]: verbose: ControllerMpd::parseTrackInfo Oct 17 12:10:18 volumio volumio[1130]: info: ControllerMpd::pushState Oct 17 12:10:18 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:10:18 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:18 volumio volumio[1130]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 17 12:10:18 volumio volumio[1130]: info: ------------------------------ 9ms Oct 17 12:10:48 volumio volumio[1130]: info: Preload queue cleared Oct 17 12:10:48 volumio volumio[1130]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 17 12:10:48 volumio volumio[1130]: info: CoreStateMachine::ClearQueue Oct 17 12:10:48 volumio volumio[1130]: info: CoreStateMachine::stop Oct 17 12:10:48 volumio volumio[1130]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 12:10:48 volumio volumio[1130]: info: CoreStateMachine::stPlaybackTimer Oct 17 12:10:48 volumio volumio[1130]: info: CoreStateMachine::updateTrackBlock Oct 17 12:10:48 volumio volumio[1130]: info: CorePlayQueue::getTrackBlock Oct 17 12:10:48 volumio volumio[1130]: info: CoreStateMachine::pushState Oct 17 12:10:48 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:48 volumio volumio[1130]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 17 12:10:48 volumio volumio[1130]: info: CoreCommandRouter::volumioPushState Oct 17 12:10:48 volumio volumio[1130]: info: CoreStateMachine::serviceStop Oct 17 12:10:48 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:48 volumio volumio[1130]: info: CoreCommandRouter::serviceStop Oct 17 12:10:48 volumio volumio[1130]: info: ControllerMpd::stop Oct 17 12:10:48 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand stop Oct 17 12:10:48 volumio volumio[1130]: info: CorePlayQueue::clearPlayQueue Oct 17 12:10:48 volumio volumio[1130]: info: CorePlayQueue::saveQueue Oct 17 12:10:48 volumio volumio[1130]: info: CoreCommandRouter::volumioPushQueue Oct 17 12:10:48 volumio volumio[1130]: info: CoreStateMachine::addQueueItems Oct 17 12:10:48 volumio volumio[1130]: info: CorePlayQueue::addQueueItems Oct 17 12:10:48 volumio volumio[1130]: info: Preload queue cleared Oct 17 12:10:48 volumio volumio[1130]: info: Adding Item to queue: webrp/1 Oct 17 12:10:48 volumio volumio[1130]: info: Exploding uri webrp/1 in service radio_paradise Oct 17 12:10:48 volumio volumio[1130]: info: CoreCommandRouter::volumioPushQueue Oct 17 12:10:48 volumio volumio[1130]: info: CorePlayQueue::saveQueue Oct 17 12:10:48 volumio volumio[1130]: info: CoreStateMachine::updateTrackBlock Oct 17 12:10:48 volumio volumio[1130]: info: CorePlayQueue::getTrackBlock Oct 17 12:10:48 volumio volumio[1130]: info: CoreCommandRouter::volumioPlay Oct 17 12:10:48 volumio volumio[1130]: info: CoreStateMachine::play index 0 Oct 17 12:10:48 volumio volumio[1130]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 12:10:48 volumio volumio[1130]: info: CoreStateMachine::stop Oct 17 12:10:48 volumio volumio[1130]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 12:10:48 volumio volumio[1130]: info: CoreStateMachine::play index undefined Oct 17 12:10:48 volumio volumio[1130]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 12:10:48 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:48 volumio volumio[1130]: info: CoreStateMachine::startPlaybackTimer Oct 17 12:10:48 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:48 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand stop Oct 17 12:10:48 volumio volumio[1130]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 17 12:10:48 volumio volumio[1130]: info: Oct 17 12:10:48 volumio volumio[1130]: ---------------------------- MPD announces state update: player Oct 17 12:10:48 volumio volumio[1130]: info: sendMpdCommand stop took 13 milliseconds Oct 17 12:10:48 volumio volumio[1130]: info: ControllerMpd::getState Oct 17 12:10:48 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand status Oct 17 12:10:48 volumio volumio[1130]: info: sendMpdCommand stop took 3 milliseconds Oct 17 12:10:48 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:10:48 volumio volumio[1130]: info: CoreStateMachine::pushState Oct 17 12:10:48 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:48 volumio volumio[1130]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 17 12:10:48 volumio volumio[1130]: info: CoreCommandRouter::volumioPushState Oct 17 12:10:48 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:48 volumio volumio[1130]: verbose: STATE SERVICE {"status":"stop","service":"radio_paradise","type":"webradio","trackType":"flac","radioType":"rparadise","albumart":"https://img.radioparadise.com/covers/l/B000002KO3.jpg","uri":"https://stream.radioparadise.com/rock-flac","name":"Crosseyed And Painless","title":"Crosseyed And Painless","artist":"Talking Heads","album":"Remain In Light","streaming":true,"disableUiControls":true,"duration":56,"seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Oct 17 12:10:48 volumio volumio[1130]: verbose: CURRENT POSITION 0 Oct 17 12:10:48 volumio volumio[1130]: info: CoreStateMachine::syncState stateService stop Oct 17 12:10:48 volumio volumio[1130]: info: CoreStateMachine::syncState currentStatus stop Oct 17 12:10:48 volumio volumio[1130]: info: CoreStateMachine::pushState Oct 17 12:10:48 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:48 volumio volumio[1130]: info: CoreCommandRouter::volumioPushState Oct 17 12:10:48 volumio volumio[1130]: info: No code Oct 17 12:10:48 volumio volumio[1130]: info: CoreStateMachine::pushState Oct 17 12:10:48 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:48 volumio volumio[1130]: info: CoreCommandRouter::volumioPushState Oct 17 12:10:48 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand clear Oct 17 12:10:48 volumio volumio[1130]: info: Oct 17 12:10:48 volumio volumio[1130]: ---------------------------- MPD announces state update: player Oct 17 12:10:48 volumio volumio[1130]: info: ControllerMpd::getState Oct 17 12:10:48 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand status Oct 17 12:10:48 volumio volumio[1130]: info: Oct 17 12:10:48 volumio volumio[1130]: ---------------------------- MPD announces state update: player Oct 17 12:10:48 volumio volumio[1130]: info: ControllerMpd::getState Oct 17 12:10:48 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand status Oct 17 12:10:48 volumio volumio[1130]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 17 12:10:48 volumio volumio[1130]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 17 12:10:48 volumio volumio[1130]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 17 12:10:48 volumio volumio[1130]: info: Oct 17 12:10:48 volumio volumio[1130]: ---------------------------- MPD announces system playlist update Oct 17 12:10:48 volumio volumio[1130]: info: Ignoring MPD Status Update Oct 17 12:10:48 volumio volumio[1130]: info: sendMpdCommand status took 25 milliseconds Oct 17 12:10:48 volumio volumio[1130]: info: sendMpdCommand clear took 13 milliseconds Oct 17 12:10:48 volumio volumio[1130]: info: sendMpdCommand status took 5 milliseconds Oct 17 12:10:48 volumio volumio[1130]: info: sendMpdCommand status took 5 milliseconds Oct 17 12:10:48 volumio volumio[1130]: verbose: ControllerMpd::parseState Oct 17 12:10:48 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 12:10:48 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand consume 1 Oct 17 12:10:48 volumio volumio[1130]: verbose: ControllerMpd::parseState Oct 17 12:10:48 volumio volumio[1130]: verbose: ControllerMpd::parseState Oct 17 12:10:48 volumio volumio[1130]: info: ControllerMpd::pushState Oct 17 12:10:48 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:10:48 volumio volumio[1130]: info: CoreStateMachine::pushState Oct 17 12:10:48 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:48 volumio volumio[1130]: info: CoreCommandRouter::volumioPushState Oct 17 12:10:48 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:48 volumio volumio[1130]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 17 12:10:48 volumio volumio[1130]: info: ControllerMpd::pushState Oct 17 12:10:48 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:10:48 volumio volumio[1130]: info: CoreStateMachine::pushState Oct 17 12:10:48 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:48 volumio volumio[1130]: info: CoreCommandRouter::volumioPushState Oct 17 12:10:48 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:48 volumio volumio[1130]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 17 12:10:48 volumio volumio[1130]: info: ------------------------------ 13ms Oct 17 12:10:48 volumio volumio[1130]: info: ------------------------------ 12ms Oct 17 12:10:48 volumio volumio[1130]: info: Oct 17 12:10:48 volumio volumio[1130]: ---------------------------- MPD announces system playlist update Oct 17 12:10:48 volumio volumio[1130]: info: Ignoring MPD Status Update Oct 17 12:10:48 volumio volumio[1130]: info: Oct 17 12:10:48 volumio volumio[1130]: ---------------------------- MPD announces system playlist update Oct 17 12:10:48 volumio volumio[1130]: info: Ignoring MPD Status Update Oct 17 12:10:48 volumio volumio[1130]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 17 12:10:48 volumio volumio[1130]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 17 12:10:48 volumio volumio[1130]: error: updateQueue error: null Oct 17 12:10:48 volumio volumio[1130]: error: updateQueue error: null Oct 17 12:10:48 volumio volumio[1130]: error: updateQueue error: null Oct 17 12:10:48 volumio volumio[1130]: info: ------------------------------ 12ms Oct 17 12:10:48 volumio volumio[1130]: info: sendMpdCommand playlistinfo took 11 milliseconds Oct 17 12:10:48 volumio volumio[1130]: info: sendMpdCommand consume 1 took 12 milliseconds Oct 17 12:10:48 volumio volumio[1130]: info: ------------------------------ 4ms Oct 17 12:10:48 volumio volumio[1130]: info: ------------------------------ 4ms Oct 17 12:10:48 volumio volumio[1130]: verbose: ControllerMpd::parseTrackInfo Oct 17 12:10:48 volumio volumio[1130]: info: [1760692248899] [RadioParadise] set to consume mode, adding url: https://stream.radioparadise.com/mellow-flac Oct 17 12:10:48 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand add "https://stream.radioparadise.com/mellow-flac" Oct 17 12:10:48 volumio volumio[1130]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Oct 17 12:10:48 volumio volumio[1130]: info: ------------------------------ 40ms Oct 17 12:10:48 volumio volumio[1130]: info: Oct 17 12:10:48 volumio volumio[1130]: ---------------------------- MPD announces system playlist update Oct 17 12:10:48 volumio volumio[1130]: info: Ignoring MPD Status Update Oct 17 12:10:48 volumio volumio[1130]: info: sendMpdCommand add "https://stream.radioparadise.com/mellow-flac" took 2 milliseconds Oct 17 12:10:48 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand play Oct 17 12:10:48 volumio volumio[1130]: info: Oct 17 12:10:48 volumio volumio[1130]: ---------------------------- MPD announces system playlist update Oct 17 12:10:48 volumio volumio[1130]: info: Ignoring MPD Status Update Oct 17 12:10:48 volumio volumio[1130]: info: Oct 17 12:10:48 volumio volumio[1130]: ---------------------------- MPD announces system playlist update Oct 17 12:10:48 volumio volumio[1130]: info: Ignoring MPD Status Update Oct 17 12:10:48 volumio volumio[1130]: info: ------------------------------ 4ms Oct 17 12:10:48 volumio volumio[1130]: info: sendMpdCommand play took 2 milliseconds Oct 17 12:10:48 volumio volumio[1130]: info: ------------------------------ 2ms Oct 17 12:10:48 volumio volumio[1130]: info: ------------------------------ 1ms Oct 17 12:10:48 volumio volumio[1130]: info: [1760692248905] [RadioParadise] getMetadata started with url https://api.radioparadise.com/api/now_playing?chan=1 Oct 17 12:10:49 volumio volumio[1130]: info: Oct 17 12:10:49 volumio volumio[1130]: ---------------------------- MPD announces state update: player Oct 17 12:10:49 volumio volumio[1130]: info: ControllerMpd::getState Oct 17 12:10:49 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand status Oct 17 12:10:49 volumio volumio[1130]: info: Oct 17 12:10:49 volumio volumio[1130]: ---------------------------- MPD announces state update: player Oct 17 12:10:49 volumio volumio[1130]: info: ControllerMpd::getState Oct 17 12:10:49 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand status Oct 17 12:10:49 volumio volumio[1130]: info: Oct 17 12:10:49 volumio volumio[1130]: ---------------------------- MPD announces state update: player Oct 17 12:10:49 volumio volumio[1130]: info: ControllerMpd::getState Oct 17 12:10:49 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand status Oct 17 12:10:49 volumio volumio[1130]: info: Oct 17 12:10:49 volumio volumio[1130]: ---------------------------- MPD announces state update: player Oct 17 12:10:49 volumio volumio[1130]: info: sendMpdCommand status took 14 milliseconds Oct 17 12:10:49 volumio volumio[1130]: info: sendMpdCommand status took 13 milliseconds Oct 17 12:10:49 volumio volumio[1130]: info: sendMpdCommand status took 12 milliseconds Oct 17 12:10:49 volumio volumio[1130]: info: ControllerMpd::getState Oct 17 12:10:49 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand status Oct 17 12:10:49 volumio volumio[1130]: verbose: ControllerMpd::parseState Oct 17 12:10:49 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 12:10:49 volumio volumio[1130]: verbose: ControllerMpd::parseState Oct 17 12:10:49 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 12:10:49 volumio volumio[1130]: verbose: ControllerMpd::parseState Oct 17 12:10:49 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 12:10:49 volumio volumio[1130]: info: sendMpdCommand status took 1 milliseconds Oct 17 12:10:49 volumio volumio[1130]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 17 12:10:49 volumio volumio[1130]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 17 12:10:49 volumio volumio[1130]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 17 12:10:49 volumio volumio[1130]: verbose: ControllerMpd::parseState Oct 17 12:10:49 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 12:10:49 volumio volumio[1130]: verbose: ControllerMpd::parseTrackInfo Oct 17 12:10:49 volumio volumio[1130]: verbose: ControllerMpd::parseTrackInfo Oct 17 12:10:49 volumio volumio[1130]: verbose: ControllerMpd::parseTrackInfo Oct 17 12:10:49 volumio volumio[1130]: info: ControllerMpd::pushState Oct 17 12:10:49 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:10:49 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:49 volumio volumio[1130]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 17 12:10:49 volumio volumio[1130]: info: ControllerMpd::pushState Oct 17 12:10:49 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:10:49 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:49 volumio volumio[1130]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 17 12:10:49 volumio volumio[1130]: info: ControllerMpd::pushState Oct 17 12:10:49 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:10:49 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:49 volumio volumio[1130]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 17 12:10:49 volumio volumio[1130]: info: ------------------------------ 20ms Oct 17 12:10:49 volumio volumio[1130]: info: ------------------------------ 19ms Oct 17 12:10:49 volumio volumio[1130]: info: ------------------------------ 18ms Oct 17 12:10:49 volumio volumio[1130]: info: Oct 17 12:10:49 volumio volumio[1130]: ---------------------------- MPD announces state update: player Oct 17 12:10:49 volumio volumio[1130]: info: ControllerMpd::getState Oct 17 12:10:49 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand status Oct 17 12:10:49 volumio volumio[1130]: info: Oct 17 12:10:49 volumio volumio[1130]: ---------------------------- MPD announces state update: player Oct 17 12:10:49 volumio volumio[1130]: info: ControllerMpd::getState Oct 17 12:10:49 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand status Oct 17 12:10:49 volumio volumio[1130]: info: sendMpdCommand playlistinfo took 6 milliseconds Oct 17 12:10:49 volumio volumio[1130]: info: sendMpdCommand status took 2 milliseconds Oct 17 12:10:49 volumio volumio[1130]: info: sendMpdCommand status took 1 milliseconds Oct 17 12:10:49 volumio volumio[1130]: verbose: ControllerMpd::parseTrackInfo Oct 17 12:10:49 volumio volumio[1130]: verbose: ControllerMpd::parseState Oct 17 12:10:49 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 12:10:49 volumio volumio[1130]: verbose: ControllerMpd::parseState Oct 17 12:10:49 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 12:10:49 volumio volumio[1130]: info: ControllerMpd::pushState Oct 17 12:10:49 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:10:49 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:49 volumio volumio[1130]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 17 12:10:49 volumio volumio[1130]: info: ------------------------------ 10ms Oct 17 12:10:49 volumio volumio[1130]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 17 12:10:49 volumio volumio[1130]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 17 12:10:49 volumio volumio[1130]: verbose: ControllerMpd::parseTrackInfo Oct 17 12:10:49 volumio volumio[1130]: verbose: ControllerMpd::parseTrackInfo Oct 17 12:10:49 volumio volumio[1130]: info: ControllerMpd::pushState Oct 17 12:10:49 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:10:49 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:49 volumio volumio[1130]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 17 12:10:49 volumio volumio[1130]: info: ControllerMpd::pushState Oct 17 12:10:49 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:10:49 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:49 volumio volumio[1130]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 17 12:10:49 volumio volumio[1130]: info: ------------------------------ 4ms Oct 17 12:10:49 volumio volumio[1130]: info: ------------------------------ 3ms Oct 17 12:10:49 volumio volumio[1130]: info: Oct 17 12:10:49 volumio volumio[1130]: ---------------------------- MPD announces system playlist update Oct 17 12:10:49 volumio volumio[1130]: info: Ignoring MPD Status Update Oct 17 12:10:49 volumio volumio[1130]: info: Oct 17 12:10:49 volumio volumio[1130]: ---------------------------- MPD announces state update: player Oct 17 12:10:49 volumio volumio[1130]: info: ControllerMpd::getState Oct 17 12:10:49 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand status Oct 17 12:10:49 volumio volumio[1130]: info: Oct 17 12:10:49 volumio volumio[1130]: ---------------------------- MPD announces system playlist update Oct 17 12:10:49 volumio volumio[1130]: info: Ignoring MPD Status Update Oct 17 12:10:49 volumio volumio[1130]: info: Oct 17 12:10:49 volumio volumio[1130]: ---------------------------- MPD announces state update: player Oct 17 12:10:49 volumio volumio[1130]: info: ControllerMpd::getState Oct 17 12:10:49 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand status Oct 17 12:10:49 volumio volumio[1130]: info: Oct 17 12:10:49 volumio volumio[1130]: ---------------------------- MPD announces system playlist update Oct 17 12:10:49 volumio volumio[1130]: info: Ignoring MPD Status Update Oct 17 12:10:49 volumio volumio[1130]: info: Oct 17 12:10:49 volumio volumio[1130]: ---------------------------- MPD announces state update: player Oct 17 12:10:49 volumio volumio[1130]: info: ControllerMpd::getState Oct 17 12:10:49 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand status Oct 17 12:10:49 volumio volumio[1130]: info: ------------------------------ 5ms Oct 17 12:10:49 volumio volumio[1130]: info: sendMpdCommand status took 4 milliseconds Oct 17 12:10:49 volumio volumio[1130]: info: ------------------------------ 3ms Oct 17 12:10:49 volumio volumio[1130]: info: sendMpdCommand status took 2 milliseconds Oct 17 12:10:49 volumio volumio[1130]: info: ------------------------------ 2ms Oct 17 12:10:49 volumio volumio[1130]: info: sendMpdCommand status took 1 milliseconds Oct 17 12:10:49 volumio volumio[1130]: verbose: ControllerMpd::parseState Oct 17 12:10:49 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 12:10:49 volumio volumio[1130]: verbose: ControllerMpd::parseState Oct 17 12:10:49 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 12:10:49 volumio volumio[1130]: verbose: ControllerMpd::parseState Oct 17 12:10:49 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 12:10:49 volumio volumio[1130]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 17 12:10:49 volumio volumio[1130]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 17 12:10:49 volumio volumio[1130]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 17 12:10:49 volumio volumio[1130]: verbose: ControllerMpd::parseTrackInfo Oct 17 12:10:49 volumio volumio[1130]: verbose: ControllerMpd::parseTrackInfo Oct 17 12:10:49 volumio volumio[1130]: verbose: ControllerMpd::parseTrackInfo Oct 17 12:10:49 volumio volumio[1130]: info: ControllerMpd::pushState Oct 17 12:10:49 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:10:49 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:49 volumio volumio[1130]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 17 12:10:49 volumio volumio[1130]: info: ControllerMpd::pushState Oct 17 12:10:49 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:10:49 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:49 volumio volumio[1130]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 17 12:10:49 volumio volumio[1130]: info: ControllerMpd::pushState Oct 17 12:10:49 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:10:49 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:49 volumio volumio[1130]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 17 12:10:49 volumio volumio[1130]: info: ------------------------------ 8ms Oct 17 12:10:49 volumio volumio[1130]: info: ------------------------------ 6ms Oct 17 12:10:49 volumio volumio[1130]: info: ------------------------------ 4ms Oct 17 12:10:49 volumio volumio[1130]: info: [1760692249411] [RadioParadise] received new metadata: {"time":175,"artist":"The Decemberists","title":"12-17-12","album":"What a Terrible World, What a Beautiful World","year":"2015","cover":"https://img.radioparadise.com/covers/l/B00P33GA7Q.jpg","cover_med":"https://img.radioparadise.com/covers/m/B00P33GA7Q.jpg","cover_small":"https://img.radioparadise.com/covers/s/B00P33GA7Q.jpg"} Oct 17 12:10:49 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:49 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:10:49 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:49 volumio volumio[1130]: verbose: STATE SERVICE {"status":"play","service":"radio_paradise","type":"webradio","trackType":"flac","radioType":"rparadise","albumart":"https://img.radioparadise.com/covers/l/B00P33GA7Q.jpg","uri":"https://stream.radioparadise.com/mellow-flac","name":"12-17-12","title":"12-17-12","artist":"The Decemberists","album":"What a Terrible World, What a Beautiful World","streaming":true,"disableUiControls":true,"duration":180,"seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Oct 17 12:10:49 volumio volumio[1130]: verbose: CURRENT POSITION 0 Oct 17 12:10:49 volumio volumio[1130]: info: CoreStateMachine::syncState stateService play Oct 17 12:10:49 volumio volumio[1130]: info: CoreStateMachine::syncState currentStatus stop Oct 17 12:10:49 volumio volumio[1130]: info: [1760692249411] [RadioParadise] setting new timer with duration of 180000 seconds. Oct 17 12:10:49 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:10:49 volumio volumio[1130]: info: CorePlayQueue::getTrack 1 Oct 17 12:11:01 volumio volumio[1130]: info: Preload queue cleared Oct 17 12:11:01 volumio volumio[1130]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 17 12:11:01 volumio volumio[1130]: info: CoreStateMachine::ClearQueue Oct 17 12:11:01 volumio volumio[1130]: info: CoreStateMachine::stop Oct 17 12:11:01 volumio volumio[1130]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 12:11:01 volumio volumio[1130]: info: CoreStateMachine::stPlaybackTimer Oct 17 12:11:01 volumio volumio[1130]: info: CoreStateMachine::updateTrackBlock Oct 17 12:11:01 volumio volumio[1130]: info: CorePlayQueue::getTrackBlock Oct 17 12:11:01 volumio volumio[1130]: info: CoreStateMachine::pushState Oct 17 12:11:01 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:11:01 volumio volumio[1130]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 17 12:11:01 volumio volumio[1130]: info: CoreCommandRouter::volumioPushState Oct 17 12:11:01 volumio volumio[1130]: info: CoreStateMachine::serviceStop Oct 17 12:11:01 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:11:01 volumio volumio[1130]: info: CoreCommandRouter::serviceStop Oct 17 12:11:01 volumio volumio[1130]: info: ControllerMpd::stop Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand stop Oct 17 12:11:01 volumio volumio[1130]: info: CorePlayQueue::clearPlayQueue Oct 17 12:11:01 volumio volumio[1130]: info: CorePlayQueue::saveQueue Oct 17 12:11:01 volumio volumio[1130]: info: CoreCommandRouter::volumioPushQueue Oct 17 12:11:01 volumio volumio[1130]: info: CoreStateMachine::addQueueItems Oct 17 12:11:01 volumio volumio[1130]: info: CorePlayQueue::addQueueItems Oct 17 12:11:01 volumio volumio[1130]: info: Preload queue cleared Oct 17 12:11:01 volumio volumio[1130]: info: Adding Item to queue: webrp/3 Oct 17 12:11:01 volumio volumio[1130]: info: Exploding uri webrp/3 in service radio_paradise Oct 17 12:11:01 volumio volumio[1130]: info: CoreCommandRouter::volumioPushQueue Oct 17 12:11:01 volumio volumio[1130]: info: CorePlayQueue::saveQueue Oct 17 12:11:01 volumio volumio[1130]: info: CoreStateMachine::updateTrackBlock Oct 17 12:11:01 volumio volumio[1130]: info: CorePlayQueue::getTrackBlock Oct 17 12:11:01 volumio volumio[1130]: info: CoreCommandRouter::volumioPlay Oct 17 12:11:01 volumio volumio[1130]: info: CoreStateMachine::play index 0 Oct 17 12:11:01 volumio volumio[1130]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 12:11:01 volumio volumio[1130]: info: CoreStateMachine::stop Oct 17 12:11:01 volumio volumio[1130]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 12:11:01 volumio volumio[1130]: info: CoreStateMachine::play index undefined Oct 17 12:11:01 volumio volumio[1130]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 12:11:01 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:11:01 volumio volumio[1130]: info: CoreStateMachine::startPlaybackTimer Oct 17 12:11:01 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand stop Oct 17 12:11:01 volumio volumio[1130]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 17 12:11:01 volumio volumio[1130]: info: Oct 17 12:11:01 volumio volumio[1130]: ---------------------------- MPD announces state update: player Oct 17 12:11:01 volumio volumio[1130]: info: sendMpdCommand stop took 13 milliseconds Oct 17 12:11:01 volumio volumio[1130]: info: ControllerMpd::getState Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand status Oct 17 12:11:01 volumio volumio[1130]: info: sendMpdCommand stop took 4 milliseconds Oct 17 12:11:01 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:11:01 volumio volumio[1130]: info: CoreStateMachine::pushState Oct 17 12:11:01 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:11:01 volumio volumio[1130]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 17 12:11:01 volumio volumio[1130]: info: CoreCommandRouter::volumioPushState Oct 17 12:11:01 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:11:01 volumio volumio[1130]: verbose: STATE SERVICE {"status":"stop","service":"radio_paradise","type":"webradio","trackType":"flac","radioType":"rparadise","albumart":"https://img.radioparadise.com/covers/l/B00P33GA7Q.jpg","uri":"https://stream.radioparadise.com/mellow-flac","name":"12-17-12","title":"12-17-12","artist":"The Decemberists","album":"What a Terrible World, What a Beautiful World","streaming":true,"disableUiControls":true,"duration":180,"seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Oct 17 12:11:01 volumio volumio[1130]: verbose: CURRENT POSITION 0 Oct 17 12:11:01 volumio volumio[1130]: info: CoreStateMachine::syncState stateService stop Oct 17 12:11:01 volumio volumio[1130]: info: CoreStateMachine::syncState currentStatus stop Oct 17 12:11:01 volumio volumio[1130]: info: CoreStateMachine::pushState Oct 17 12:11:01 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:11:01 volumio volumio[1130]: info: CoreCommandRouter::volumioPushState Oct 17 12:11:01 volumio volumio[1130]: info: No code Oct 17 12:11:01 volumio volumio[1130]: info: CoreStateMachine::pushState Oct 17 12:11:01 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:11:01 volumio volumio[1130]: info: CoreCommandRouter::volumioPushState Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand clear Oct 17 12:11:01 volumio volumio[1130]: info: Oct 17 12:11:01 volumio volumio[1130]: ---------------------------- MPD announces state update: player Oct 17 12:11:01 volumio volumio[1130]: info: ControllerMpd::getState Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand status Oct 17 12:11:01 volumio volumio[1130]: info: Oct 17 12:11:01 volumio volumio[1130]: ---------------------------- MPD announces state update: player Oct 17 12:11:01 volumio volumio[1130]: info: ControllerMpd::getState Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand status Oct 17 12:11:01 volumio volumio[1130]: info: Oct 17 12:11:01 volumio volumio[1130]: ---------------------------- MPD announces system playlist update Oct 17 12:11:01 volumio volumio[1130]: info: Ignoring MPD Status Update Oct 17 12:11:01 volumio volumio[1130]: info: sendMpdCommand status took 9 milliseconds Oct 17 12:11:01 volumio volumio[1130]: info: sendMpdCommand clear took 5 milliseconds Oct 17 12:11:01 volumio volumio[1130]: info: sendMpdCommand status took 2 milliseconds Oct 17 12:11:01 volumio volumio[1130]: info: sendMpdCommand status took 1 milliseconds Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::parseState Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand consume 1 Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::parseState Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::parseState Oct 17 12:11:01 volumio volumio[1130]: info: ControllerMpd::pushState Oct 17 12:11:01 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:11:01 volumio volumio[1130]: info: CoreStateMachine::pushState Oct 17 12:11:01 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:11:01 volumio volumio[1130]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 17 12:11:01 volumio volumio[1130]: info: CoreCommandRouter::volumioPushState Oct 17 12:11:01 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:11:01 volumio volumio[1130]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 17 12:11:01 volumio volumio[1130]: info: ControllerMpd::pushState Oct 17 12:11:01 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:11:01 volumio volumio[1130]: info: CoreStateMachine::pushState Oct 17 12:11:01 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:11:01 volumio volumio[1130]: info: CoreCommandRouter::volumioPushState Oct 17 12:11:01 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:11:01 volumio volumio[1130]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 17 12:11:01 volumio volumio[1130]: info: ------------------------------ 8ms Oct 17 12:11:01 volumio volumio[1130]: info: ------------------------------ 7ms Oct 17 12:11:01 volumio volumio[1130]: info: Oct 17 12:11:01 volumio volumio[1130]: ---------------------------- MPD announces system playlist update Oct 17 12:11:01 volumio volumio[1130]: info: Ignoring MPD Status Update Oct 17 12:11:01 volumio volumio[1130]: info: Oct 17 12:11:01 volumio volumio[1130]: ---------------------------- MPD announces system playlist update Oct 17 12:11:01 volumio volumio[1130]: info: Ignoring MPD Status Update Oct 17 12:11:01 volumio volumio[1130]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 17 12:11:01 volumio volumio[1130]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 17 12:11:01 volumio volumio[1130]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 17 12:11:01 volumio volumio[1130]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 17 12:11:01 volumio volumio[1130]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 17 12:11:01 volumio volumio[1130]: error: updateQueue error: null Oct 17 12:11:01 volumio volumio[1130]: error: updateQueue error: null Oct 17 12:11:01 volumio volumio[1130]: info: ------------------------------ 16ms Oct 17 12:11:01 volumio volumio[1130]: info: sendMpdCommand playlistinfo took 15 milliseconds Oct 17 12:11:01 volumio volumio[1130]: info: sendMpdCommand consume 1 took 15 milliseconds Oct 17 12:11:01 volumio volumio[1130]: info: ------------------------------ 9ms Oct 17 12:11:01 volumio volumio[1130]: info: ------------------------------ 9ms Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::parseTrackInfo Oct 17 12:11:01 volumio volumio[1130]: info: [1760692261138] [RadioParadise] set to consume mode, adding url: https://stream.radioparadise.com/world-etc-flac Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand add "https://stream.radioparadise.com/world-etc-flac" Oct 17 12:11:01 volumio volumio[1130]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Oct 17 12:11:01 volumio volumio[1130]: info: ------------------------------ 27ms Oct 17 12:11:01 volumio volumio[1130]: info: Oct 17 12:11:01 volumio volumio[1130]: ---------------------------- MPD announces system playlist update Oct 17 12:11:01 volumio volumio[1130]: info: Ignoring MPD Status Update Oct 17 12:11:01 volumio volumio[1130]: info: sendMpdCommand add "https://stream.radioparadise.com/world-etc-flac" took 1 milliseconds Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand play Oct 17 12:11:01 volumio volumio[1130]: info: Oct 17 12:11:01 volumio volumio[1130]: ---------------------------- MPD announces system playlist update Oct 17 12:11:01 volumio volumio[1130]: info: Ignoring MPD Status Update Oct 17 12:11:01 volumio volumio[1130]: info: Oct 17 12:11:01 volumio volumio[1130]: ---------------------------- MPD announces system playlist update Oct 17 12:11:01 volumio volumio[1130]: info: Ignoring MPD Status Update Oct 17 12:11:01 volumio volumio[1130]: info: ------------------------------ 5ms Oct 17 12:11:01 volumio volumio[1130]: info: sendMpdCommand play took 3 milliseconds Oct 17 12:11:01 volumio volumio[1130]: info: ------------------------------ 2ms Oct 17 12:11:01 volumio volumio[1130]: info: ------------------------------ 1ms Oct 17 12:11:01 volumio volumio[1130]: info: [1760692261144] [RadioParadise] getMetadata started with url https://api.radioparadise.com/api/now_playing?chan=3 Oct 17 12:11:01 volumio volumio[1130]: info: Oct 17 12:11:01 volumio volumio[1130]: ---------------------------- MPD announces state update: player Oct 17 12:11:01 volumio volumio[1130]: info: ControllerMpd::getState Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand status Oct 17 12:11:01 volumio volumio[1130]: info: Oct 17 12:11:01 volumio volumio[1130]: ---------------------------- MPD announces state update: player Oct 17 12:11:01 volumio volumio[1130]: info: ControllerMpd::getState Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand status Oct 17 12:11:01 volumio volumio[1130]: info: Oct 17 12:11:01 volumio volumio[1130]: ---------------------------- MPD announces state update: player Oct 17 12:11:01 volumio volumio[1130]: info: ControllerMpd::getState Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand status Oct 17 12:11:01 volumio volumio[1130]: info: Oct 17 12:11:01 volumio volumio[1130]: ---------------------------- MPD announces state update: player Oct 17 12:11:01 volumio volumio[1130]: info: sendMpdCommand status took 13 milliseconds Oct 17 12:11:01 volumio volumio[1130]: info: sendMpdCommand status took 13 milliseconds Oct 17 12:11:01 volumio volumio[1130]: info: ControllerMpd::getState Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand status Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::parseState Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::parseState Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 12:11:01 volumio volumio[1130]: info: sendMpdCommand status took 12 milliseconds Oct 17 12:11:01 volumio volumio[1130]: info: sendMpdCommand status took 1 milliseconds Oct 17 12:11:01 volumio volumio[1130]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 17 12:11:01 volumio volumio[1130]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::parseState Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::parseState Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::parseTrackInfo Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::parseTrackInfo Oct 17 12:11:01 volumio volumio[1130]: info: ControllerMpd::pushState Oct 17 12:11:01 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:11:01 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:11:01 volumio volumio[1130]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 17 12:11:01 volumio volumio[1130]: info: ControllerMpd::pushState Oct 17 12:11:01 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:11:01 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:11:01 volumio volumio[1130]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 17 12:11:01 volumio volumio[1130]: info: ------------------------------ 18ms Oct 17 12:11:01 volumio volumio[1130]: info: ------------------------------ 17ms Oct 17 12:11:01 volumio volumio[1130]: info: Oct 17 12:11:01 volumio volumio[1130]: ---------------------------- MPD announces state update: player Oct 17 12:11:01 volumio volumio[1130]: info: ControllerMpd::getState Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand status Oct 17 12:11:01 volumio volumio[1130]: info: Oct 17 12:11:01 volumio volumio[1130]: ---------------------------- MPD announces state update: player Oct 17 12:11:01 volumio volumio[1130]: info: ControllerMpd::getState Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand status Oct 17 12:11:01 volumio volumio[1130]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 17 12:11:01 volumio volumio[1130]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 17 12:11:01 volumio volumio[1130]: info: sendMpdCommand status took 2 milliseconds Oct 17 12:11:01 volumio volumio[1130]: info: sendMpdCommand status took 1 milliseconds Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::parseTrackInfo Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::parseTrackInfo Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::parseState Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::parseState Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 12:11:01 volumio volumio[1130]: info: ControllerMpd::pushState Oct 17 12:11:01 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:11:01 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:11:01 volumio volumio[1130]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 17 12:11:01 volumio volumio[1130]: info: ControllerMpd::pushState Oct 17 12:11:01 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:11:01 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:11:01 volumio volumio[1130]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 17 12:11:01 volumio volumio[1130]: info: ------------------------------ 17ms Oct 17 12:11:01 volumio volumio[1130]: info: ------------------------------ 7ms Oct 17 12:11:01 volumio volumio[1130]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 17 12:11:01 volumio volumio[1130]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::parseTrackInfo Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::parseTrackInfo Oct 17 12:11:01 volumio volumio[1130]: info: ControllerMpd::pushState Oct 17 12:11:01 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:11:01 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:11:01 volumio volumio[1130]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 17 12:11:01 volumio volumio[1130]: info: ControllerMpd::pushState Oct 17 12:11:01 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:11:01 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:11:01 volumio volumio[1130]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 17 12:11:01 volumio volumio[1130]: info: ------------------------------ 5ms Oct 17 12:11:01 volumio volumio[1130]: info: ------------------------------ 4ms Oct 17 12:11:01 volumio volumio[1130]: info: Oct 17 12:11:01 volumio volumio[1130]: ---------------------------- MPD announces system playlist update Oct 17 12:11:01 volumio volumio[1130]: info: Ignoring MPD Status Update Oct 17 12:11:01 volumio volumio[1130]: info: Oct 17 12:11:01 volumio volumio[1130]: ---------------------------- MPD announces state update: player Oct 17 12:11:01 volumio volumio[1130]: info: ControllerMpd::getState Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand status Oct 17 12:11:01 volumio volumio[1130]: info: Oct 17 12:11:01 volumio volumio[1130]: ---------------------------- MPD announces system playlist update Oct 17 12:11:01 volumio volumio[1130]: info: Ignoring MPD Status Update Oct 17 12:11:01 volumio volumio[1130]: info: Oct 17 12:11:01 volumio volumio[1130]: ---------------------------- MPD announces state update: player Oct 17 12:11:01 volumio volumio[1130]: info: ControllerMpd::getState Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand status Oct 17 12:11:01 volumio volumio[1130]: info: Oct 17 12:11:01 volumio volumio[1130]: ---------------------------- MPD announces system playlist update Oct 17 12:11:01 volumio volumio[1130]: info: Ignoring MPD Status Update Oct 17 12:11:01 volumio volumio[1130]: info: Oct 17 12:11:01 volumio volumio[1130]: ---------------------------- MPD announces state update: player Oct 17 12:11:01 volumio volumio[1130]: info: ControllerMpd::getState Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand status Oct 17 12:11:01 volumio volumio[1130]: info: ------------------------------ 3ms Oct 17 12:11:01 volumio volumio[1130]: info: sendMpdCommand status took 2 milliseconds Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::parseState Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 12:11:01 volumio volumio[1130]: info: ------------------------------ 4ms Oct 17 12:11:01 volumio volumio[1130]: info: sendMpdCommand status took 3 milliseconds Oct 17 12:11:01 volumio volumio[1130]: info: ------------------------------ 3ms Oct 17 12:11:01 volumio volumio[1130]: info: sendMpdCommand status took 3 milliseconds Oct 17 12:11:01 volumio volumio[1130]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::parseState Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::parseState Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::parseTrackInfo Oct 17 12:11:01 volumio volumio[1130]: info: ControllerMpd::pushState Oct 17 12:11:01 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:11:01 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:11:01 volumio volumio[1130]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 17 12:11:01 volumio volumio[1130]: info: ------------------------------ 8ms Oct 17 12:11:01 volumio volumio[1130]: info: sendMpdCommand playlistinfo took 4 milliseconds Oct 17 12:11:01 volumio volumio[1130]: info: sendMpdCommand playlistinfo took 4 milliseconds Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::parseTrackInfo Oct 17 12:11:01 volumio volumio[1130]: verbose: ControllerMpd::parseTrackInfo Oct 17 12:11:01 volumio volumio[1130]: info: ControllerMpd::pushState Oct 17 12:11:01 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:11:01 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:11:01 volumio volumio[1130]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 17 12:11:01 volumio volumio[1130]: info: ControllerMpd::pushState Oct 17 12:11:01 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:11:01 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:11:01 volumio volumio[1130]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 17 12:11:01 volumio volumio[1130]: info: ------------------------------ 10ms Oct 17 12:11:01 volumio volumio[1130]: info: ------------------------------ 9ms Oct 17 12:11:01 volumio volumio[1130]: info: [1760692261663] [RadioParadise] received new metadata: {"time":168,"artist":"Andy Palacio & The Garifuna Collective","title":"Weyu Lárigi Weyu","album":"Wátina","year":"0","cover":"https://img.radioparadise.com/covers/l/19655_cf2fd570-68cb-478d-b0bd-b031f0549320.jpg","cover_med":"https://img.radioparadise.com/covers/m/19655_cf2fd570-68cb-478d-b0bd-b031f0549320.jpg","cover_small":"https://img.radioparadise.com/covers/s/19655_cf2fd570-68cb-478d-b0bd-b031f0549320.jpg"} Oct 17 12:11:01 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:11:01 volumio volumio[1130]: info: CoreCommandRouter::servicePushState Oct 17 12:11:01 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:11:01 volumio volumio[1130]: verbose: STATE SERVICE {"status":"play","service":"radio_paradise","type":"webradio","trackType":"flac","radioType":"rparadise","albumart":"https://img.radioparadise.com/covers/l/19655_cf2fd570-68cb-478d-b0bd-b031f0549320.jpg","uri":"https://stream.radioparadise.com/world-etc-flac","name":"Weyu Lárigi Weyu","title":"Weyu Lárigi Weyu","artist":"Andy Palacio & The Garifuna Collective","album":"Wátina","streaming":true,"disableUiControls":true,"duration":173,"seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Oct 17 12:11:01 volumio volumio[1130]: verbose: CURRENT POSITION 0 Oct 17 12:11:01 volumio volumio[1130]: info: CoreStateMachine::syncState stateService play Oct 17 12:11:01 volumio volumio[1130]: info: CoreStateMachine::syncState currentStatus stop Oct 17 12:11:01 volumio volumio[1130]: info: [1760692261663] [RadioParadise] setting new timer with duration of 173000 seconds. Oct 17 12:11:01 volumio volumio[1130]: info: CorePlayQueue::getTrack 0 Oct 17 12:11:01 volumio volumio[1130]: info: CorePlayQueue::getTrack 1 Oct 17 12:11:30 volumio volumio[1130]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 17 12:11:30 volumio volumio[1130]: info: Preload queue cleared Oct 17 12:11:36 volumio volumio[1130]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 17 12:11:36 volumio volumio[1130]: info: Preload queue cleared Oct 17 12:11:43 volumio volumio[1130]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 17 12:11:43 volumio volumio[1130]: info: Preload queue cleared Oct 17 12:11:46 volumio volumio[1130]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 17 12:11:46 volumio volumio[1130]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 17 12:11:46 volumio volumio[1130]: TypeError: Cannot read property 'length' of undefined Oct 17 12:11:46 volumio volumio[1130]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Oct 17 12:11:46 volumio volumio[1130]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Oct 17 12:11:46 volumio volumio[1130]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Oct 17 12:11:46 volumio volumio[1130]: at Parser.emit (events.js:315:20) Oct 17 12:11:46 volumio volumio[1130]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Oct 17 12:11:46 volumio volumio[1130]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Oct 17 12:11:46 volumio volumio[1130]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Oct 17 12:11:46 volumio volumio[1130]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Oct 17 12:11:46 volumio volumio[1130]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Oct 17 12:11:46 volumio volumio[1130]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Oct 17 12:11:46 volumio volumio[1130]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Oct 17 12:11:46 volumio volumio[1130]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Oct 17 12:11:46 volumio volumio[1130]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Oct 17 12:11:46 volumio volumio[1130]: at IncomingMessage.emit (events.js:327:22) Oct 17 12:11:46 volumio volumio[1130]: at endReadableNT (internal/streams/readable.js:1327:12) Oct 17 12:11:46 volumio volumio[1130]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Oct 17 12:11:46 volumio volumio[1130]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 17 12:11:46 volumio sudo[3225]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-10-17 12:10 Oct 17 12:11:46 volumio sudo[3225]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="29866754e5f1d7e4d0f581c10d9f22852f6f21db" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 10:25:36 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="cf6e14681b2ecbbdc9a62186b0f3114c"