Aug 25 17:20:02 kitchen volumio[1437]: info: AutoStart - Check #10/60 - VOLUMIO_SYSTEM_STATUS = starting Aug 25 17:20:05 kitchen volumio[1437]: info: BOOT COMPLETED Aug 25 17:20:07 kitchen volumio[1437]: info: AutoStart - Check #11/60 - VOLUMIO_SYSTEM_STATUS = ready Aug 25 17:20:07 kitchen volumio[1437]: info: AutoStart - System ready state CONFIRMED after 11 checks Aug 25 17:20:07 kitchen volumio[1437]: info: AutoStart - Applying additional delay of 5000ms before playback Aug 25 17:20:12 kitchen volumio[1437]: info: AutoStart - startPlayback called Aug 25 17:20:12 kitchen volumio[1437]: info: CoreCommandRouter::volumioGetQueue Aug 25 17:20:12 kitchen volumio[1437]: info: CoreStateMachine::getQueue Aug 25 17:20:12 kitchen volumio[1437]: info: CorePlayQueue::getQueue Aug 25 17:20:12 kitchen volumio[1437]: info: AutoStart - Queue has 1 items Aug 25 17:20:12 kitchen volumio[1437]: info: AutoStart - Playing from position 0 Aug 25 17:20:12 kitchen volumio[1437]: info: CoreCommandRouter::volumioGetState Aug 25 17:20:12 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:20:12 kitchen volumio[1437]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Aug 25 17:20:12 kitchen volumio[1437]: info: CoreCommandRouter::volumioPlay Aug 25 17:20:12 kitchen volumio[1437]: info: CoreStateMachine::play index 0 Aug 25 17:20:12 kitchen volumio[1437]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 25 17:20:12 kitchen volumio[1437]: info: CoreStateMachine::stop Aug 25 17:20:12 kitchen volumio[1437]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 25 17:20:12 kitchen volumio[1437]: info: CoreStateMachine::play index undefined Aug 25 17:20:12 kitchen volumio[1437]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 25 17:20:12 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:20:12 kitchen volumio[1437]: info: CoreStateMachine::startPlaybackTimer Aug 25 17:20:12 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:20:12 kitchen volumio[1437]: info: CoreCommandRouter::volumioGetVisibleSources Aug 25 17:20:12 kitchen volumio[1437]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 25 17:20:12 kitchen volumio[1437]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Aug 25 17:20:12 kitchen volumio[1437]: info: [RadioParadise] Matched station: Radio Paradise Mellow Mix (FLAC), chan=1 Aug 25 17:20:12 kitchen volumio[1437]: verbose: ControllerMpd::sendMpdCommand stop Aug 25 17:20:12 kitchen volumio[1437]: info: sendMpdCommand stop took 33 milliseconds Aug 25 17:20:12 kitchen volumio[1437]: verbose: ControllerMpd::sendMpdCommand clear Aug 25 17:20:12 kitchen volumio[1437]: info: Aug 25 17:20:12 kitchen volumio[1437]: ---------------------------- MPD announces system playlist update Aug 25 17:20:12 kitchen volumio[1437]: info: Ignoring MPD Status Update Aug 25 17:20:12 kitchen volumio[1437]: info: sendMpdCommand clear took 8 milliseconds Aug 25 17:20:12 kitchen volumio[1437]: verbose: ControllerMpd::sendMpdCommand consume 1 Aug 25 17:20:12 kitchen volumio[1437]: error: updateQueue error: null Aug 25 17:20:12 kitchen volumio[1437]: info: Aug 25 17:20:12 kitchen volumio[1437]: ---------------------------- MPD announces state update: options Aug 25 17:20:12 kitchen volumio[1437]: info: ------------------------------ 22ms Aug 25 17:20:12 kitchen volumio[1437]: info: sendMpdCommand consume 1 took 15 milliseconds Aug 25 17:20:12 kitchen volumio[1437]: info: ControllerMpd::getState Aug 25 17:20:12 kitchen volumio[1437]: verbose: ControllerMpd::sendMpdCommand status Aug 25 17:20:12 kitchen volumio[1437]: info: [1787692812143] [RadioParadise] set to consume mode, adding url: https://stream.radioparadise.com/mellow-flacm Aug 25 17:20:12 kitchen volumio[1437]: verbose: ControllerMpd::sendMpdCommand add "https://stream.radioparadise.com/mellow-flacm" Aug 25 17:20:12 kitchen volumio[1437]: info: sendMpdCommand status took 10 milliseconds Aug 25 17:20:12 kitchen volumio[1437]: verbose: ControllerMpd::parseState Aug 25 17:20:12 kitchen volumio[1437]: info: ControllerMpd::pushState Aug 25 17:20:12 kitchen volumio[1437]: info: CoreCommandRouter::servicePushState Aug 25 17:20:12 kitchen volumio[1437]: info: CoreStateMachine::pushState Aug 25 17:20:12 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:20:12 kitchen volumio[1437]: info: CoreCommandRouter::volumioPushState Aug 25 17:20:12 kitchen volumio[1437]: info: MRS: Pushing multiroomSync output update for this device Aug 25 17:20:12 kitchen volumio[1437]: info: MRS: Pushing multiroomSync output Aug 25 17:20:12 kitchen volumio[1437]: info: CoreCommandRouter::volumioGetState Aug 25 17:20:12 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:20:12 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:20:12 kitchen volumio[1437]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Aug 25 17:20:12 kitchen volumio[1437]: info: ------------------------------ 149ms Aug 25 17:20:12 kitchen volumio[1437]: info: Aug 25 17:20:12 kitchen volumio[1437]: ---------------------------- MPD announces system playlist update Aug 25 17:20:12 kitchen volumio[1437]: info: Ignoring MPD Status Update Aug 25 17:20:12 kitchen volumio[1437]: info: sendMpdCommand add "https://stream.radioparadise.com/mellow-flacm" took 136 milliseconds Aug 25 17:20:12 kitchen volumio[1437]: verbose: ControllerMpd::sendMpdCommand play Aug 25 17:20:12 kitchen volumio[1437]: info: ------------------------------ 132ms Aug 25 17:20:12 kitchen volumio[1437]: info: sendMpdCommand play took 102 milliseconds Aug 25 17:20:12 kitchen volumio[1437]: info: [RadioParadise] Using metadata URL: https://api.radioparadise.com/api/now_playing?chan=1 Aug 25 17:20:12 kitchen volumio[1437]: info: [1787692812412] [RadioParadise] getMetadata started with url https://api.radioparadise.com/api/now_playing?chan=1 Aug 25 17:20:12 kitchen volumio[1437]: info: Aug 25 17:20:12 kitchen volumio[1437]: ---------------------------- MPD announces state update: player Aug 25 17:20:12 kitchen volumio[1437]: info: ControllerMpd::getState Aug 25 17:20:12 kitchen volumio[1437]: verbose: ControllerMpd::sendMpdCommand status Aug 25 17:20:13 kitchen volumio[1437]: info: Aug 25 17:20:13 kitchen volumio[1437]: ---------------------------- MPD announces state update: player Aug 25 17:20:13 kitchen volumio[1437]: info: sendMpdCommand status took 159 milliseconds Aug 25 17:20:13 kitchen volumio[1437]: info: ControllerMpd::getState Aug 25 17:20:13 kitchen volumio[1437]: verbose: ControllerMpd::sendMpdCommand status Aug 25 17:20:13 kitchen volumio[1437]: verbose: ControllerMpd::parseState Aug 25 17:20:13 kitchen volumio[1437]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 25 17:20:13 kitchen volumio[1437]: info: Aug 25 17:20:13 kitchen volumio[1437]: ---------------------------- MPD announces system playlist update Aug 25 17:20:13 kitchen volumio[1437]: info: Ignoring MPD Status Update Aug 25 17:20:13 kitchen volumio[1437]: info: Aug 25 17:20:13 kitchen volumio[1437]: ---------------------------- MPD announces state update: player Aug 25 17:20:13 kitchen volumio[1437]: info: ControllerMpd::getState Aug 25 17:20:13 kitchen volumio[1437]: verbose: ControllerMpd::sendMpdCommand status Aug 25 17:20:13 kitchen volumio[1437]: info: sendMpdCommand status took 2 milliseconds Aug 25 17:20:13 kitchen volumio[1437]: info: sendMpdCommand playlistinfo took 2 milliseconds Aug 25 17:20:13 kitchen volumio[1437]: verbose: ControllerMpd::parseState Aug 25 17:20:13 kitchen volumio[1437]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 25 17:20:13 kitchen volumio[1437]: verbose: ControllerMpd::parseTrackInfo Aug 25 17:20:13 kitchen volumio[1437]: info: ControllerMpd::pushState Aug 25 17:20:13 kitchen volumio[1437]: info: CoreCommandRouter::servicePushState Aug 25 17:20:13 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:20:13 kitchen volumio[1437]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Aug 25 17:20:13 kitchen volumio[1437]: info: ------------------------------ 248ms Aug 25 17:20:13 kitchen volumio[1437]: info: ------------------------------ 107ms Aug 25 17:20:13 kitchen volumio[1437]: info: sendMpdCommand status took 107 milliseconds Aug 25 17:20:13 kitchen volumio[1437]: info: sendMpdCommand playlistinfo took 66 milliseconds Aug 25 17:20:13 kitchen volumio[1437]: verbose: ControllerMpd::parseState Aug 25 17:20:13 kitchen volumio[1437]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 25 17:20:13 kitchen volumio[1437]: verbose: ControllerMpd::parseTrackInfo Aug 25 17:20:13 kitchen volumio[1437]: info: ControllerMpd::pushState Aug 25 17:20:13 kitchen volumio[1437]: info: CoreCommandRouter::servicePushState Aug 25 17:20:13 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:20:13 kitchen volumio[1437]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Aug 25 17:20:13 kitchen volumio[1437]: info: ------------------------------ 200ms Aug 25 17:20:13 kitchen volumio[1437]: info: [1787692813299] [RadioParadise] received new metadata: {"time":37,"artist":"Rod Stewart","title":"Mandolin Wind","album":"Gasoline Alley","year":"1970","cover":"https://img.radioparadise.com/covers/l/12338.jpg","cover_med":"https://img.radioparadise.com/covers/m/12338.jpg","cover_small":"https://img.radioparadise.com/covers/s/12338.jpg"} Aug 25 17:20:13 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:20:13 kitchen volumio[1437]: info: CoreCommandRouter::servicePushState Aug 25 17:20:13 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:20:13 kitchen volumio[1437]: verbose: STATE SERVICE {"status":"play","service":"radio_paradise","type":"webradio","trackType":"flac","radioType":"","albumart":"https://img.radioparadise.com/covers/l/12338.jpg","uri":"https://stream.radioparadise.com/mellow-flacm","name":"Mandolin Wind","title":"Mandolin Wind","artist":"Rod Stewart","album":"Gasoline Alley","streaming":true,"disableUiControls":true,"duration":42,"seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Aug 25 17:20:13 kitchen volumio[1437]: verbose: CURRENT POSITION 0 Aug 25 17:20:13 kitchen volumio[1437]: info: CoreStateMachine::syncState stateService play Aug 25 17:20:13 kitchen volumio[1437]: info: CoreStateMachine::syncState currentStatus stop Aug 25 17:20:13 kitchen volumio[1437]: info: [1787692813301] [RadioParadise] setting new timer with duration of 42000 seconds. Aug 25 17:20:13 kitchen volumio[1437]: info: sendMpdCommand playlistinfo took 94 milliseconds Aug 25 17:20:13 kitchen volumio[1437]: verbose: ControllerMpd::parseTrackInfo Aug 25 17:20:13 kitchen volumio[1437]: info: ControllerMpd::pushState Aug 25 17:20:13 kitchen volumio[1437]: info: CoreCommandRouter::servicePushState Aug 25 17:20:13 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:20:13 kitchen volumio[1437]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Aug 25 17:20:13 kitchen volumio[1437]: info: ------------------------------ 204ms Aug 25 17:20:15 kitchen volumio[1437]: info: Aug 25 17:20:15 kitchen volumio[1437]: ---------------------------- MPD announces system playlist update Aug 25 17:20:15 kitchen volumio[1437]: info: Ignoring MPD Status Update Aug 25 17:20:15 kitchen volumio[1437]: info: Aug 25 17:20:15 kitchen volumio[1437]: ---------------------------- MPD announces state update: player Aug 25 17:20:15 kitchen volumio[1437]: info: ControllerMpd::getState Aug 25 17:20:15 kitchen volumio[1437]: verbose: ControllerMpd::sendMpdCommand status Aug 25 17:20:15 kitchen volumio[1437]: info: ------------------------------ 2ms Aug 25 17:20:15 kitchen volumio[1437]: info: sendMpdCommand status took 6 milliseconds Aug 25 17:20:15 kitchen volumio[1437]: verbose: ControllerMpd::parseState Aug 25 17:20:15 kitchen volumio[1437]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 25 17:20:15 kitchen volumio[1437]: info: sendMpdCommand playlistinfo took 14 milliseconds Aug 25 17:20:15 kitchen volumio[1437]: verbose: ControllerMpd::parseTrackInfo Aug 25 17:20:15 kitchen volumio[1437]: info: ControllerMpd::pushState Aug 25 17:20:15 kitchen volumio[1437]: info: CoreCommandRouter::servicePushState Aug 25 17:20:15 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:20:15 kitchen volumio[1437]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Aug 25 17:20:15 kitchen volumio[1437]: info: ------------------------------ 33ms Aug 25 17:20:18 kitchen volumio[1437]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 25 17:20:18 kitchen volumio[1437]: info: CoreCommandRouter::Close All Modals sent Aug 25 17:20:42 kitchen kernel: logitech-hidpp-device 0003:046D:4055.0003: HID++ 4.5 device connected. Aug 25 17:20:44 kitchen volumio[1437]: info: CoreCommandRouter::volumioGetQueue Aug 25 17:20:44 kitchen volumio[1437]: info: CoreStateMachine::getQueue Aug 25 17:20:44 kitchen volumio[1437]: info: CorePlayQueue::getQueue Aug 25 17:20:48 kitchen volumio[1437]: info: Preload queue cleared Aug 25 17:20:48 kitchen volumio[1437]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 25 17:20:48 kitchen volumio[1437]: info: CoreStateMachine::ClearQueue Aug 25 17:20:48 kitchen volumio[1437]: info: CoreStateMachine::stop Aug 25 17:20:48 kitchen volumio[1437]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 25 17:20:48 kitchen volumio[1437]: info: CoreStateMachine::stPlaybackTimer Aug 25 17:20:48 kitchen volumio[1437]: info: CoreStateMachine::updateTrackBlock Aug 25 17:20:48 kitchen volumio[1437]: info: CorePlayQueue::getTrackBlock Aug 25 17:20:48 kitchen volumio[1437]: info: CoreStateMachine::pushState Aug 25 17:20:48 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:20:48 kitchen volumio[1437]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 25 17:20:48 kitchen volumio[1437]: info: CoreCommandRouter::volumioPushState Aug 25 17:20:48 kitchen volumio[1437]: info: MRS: Pushing multiroomSync output update for this device Aug 25 17:20:48 kitchen volumio[1437]: info: MRS: Pushing multiroomSync output Aug 25 17:20:48 kitchen volumio[1437]: info: CoreCommandRouter::volumioGetState Aug 25 17:20:48 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:20:48 kitchen volumio[1437]: info: CoreStateMachine::serviceStop Aug 25 17:20:48 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:20:48 kitchen volumio[1437]: info: CoreCommandRouter::serviceStop Aug 25 17:20:48 kitchen volumio[1437]: info: ControllerMpd::stop Aug 25 17:20:48 kitchen volumio[1437]: verbose: ControllerMpd::sendMpdCommand stop Aug 25 17:20:48 kitchen volumio[1437]: info: CorePlayQueue::clearPlayQueue Aug 25 17:20:48 kitchen volumio[1437]: info: CorePlayQueue::saveQueue Aug 25 17:20:48 kitchen volumio[1437]: info: CoreCommandRouter::volumioPushQueue Aug 25 17:20:48 kitchen volumio[1437]: info: CoreStateMachine::addQueueItems Aug 25 17:20:48 kitchen volumio[1437]: info: CorePlayQueue::addQueueItems Aug 25 17:20:48 kitchen volumio[1437]: info: Preload queue cleared Aug 25 17:20:48 kitchen volumio[1437]: info: Adding Item to queue: webrp/1 Aug 25 17:20:48 kitchen volumio[1437]: info: Exploding uri webrp/1 in service radio_paradise Aug 25 17:20:49 kitchen volumio[1437]: info: CoreCommandRouter::volumioPushQueue Aug 25 17:20:49 kitchen volumio[1437]: info: CorePlayQueue::saveQueue Aug 25 17:20:49 kitchen volumio[1437]: info: CoreStateMachine::updateTrackBlock Aug 25 17:20:49 kitchen volumio[1437]: info: CorePlayQueue::getTrackBlock Aug 25 17:20:49 kitchen volumio[1437]: info: CoreCommandRouter::volumioGetState Aug 25 17:20:49 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:20:49 kitchen volumio[1437]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Aug 25 17:20:49 kitchen volumio[1437]: info: CoreCommandRouter::volumioPlay Aug 25 17:20:49 kitchen volumio[1437]: info: CoreStateMachine::play index 0 Aug 25 17:20:49 kitchen volumio[1437]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 25 17:20:49 kitchen volumio[1437]: info: CoreStateMachine::stop Aug 25 17:20:49 kitchen volumio[1437]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 25 17:20:49 kitchen volumio[1437]: info: CoreStateMachine::play index undefined Aug 25 17:20:49 kitchen volumio[1437]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 25 17:20:49 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:20:49 kitchen volumio[1437]: info: CoreStateMachine::startPlaybackTimer Aug 25 17:20:49 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:20:49 kitchen volumio[1437]: info: CoreCommandRouter::volumioGetVisibleSources Aug 25 17:20:49 kitchen volumio[1437]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 25 17:20:49 kitchen volumio[1437]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Aug 25 17:20:49 kitchen volumio[1437]: info: [RadioParadise] Matched station: Radio Paradise Mellow Mix (FLAC), chan=1 Aug 25 17:20:49 kitchen volumio[1437]: verbose: ControllerMpd::sendMpdCommand stop Aug 25 17:20:49 kitchen volumio[1437]: info: Aug 25 17:20:49 kitchen volumio[1437]: ---------------------------- MPD announces state update: player Aug 25 17:20:49 kitchen volumio[1437]: info: sendMpdCommand stop took 333 milliseconds Aug 25 17:20:49 kitchen volumio[1437]: info: ControllerMpd::getState Aug 25 17:20:49 kitchen volumio[1437]: verbose: ControllerMpd::sendMpdCommand status Aug 25 17:20:49 kitchen volumio[1437]: info: sendMpdCommand stop took 128 milliseconds Aug 25 17:20:49 kitchen volumio[1437]: info: CoreCommandRouter::servicePushState Aug 25 17:20:49 kitchen volumio[1437]: info: CoreStateMachine::pushState Aug 25 17:20:49 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:20:49 kitchen volumio[1437]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 25 17:20:49 kitchen volumio[1437]: info: CoreCommandRouter::volumioPushState Aug 25 17:20:49 kitchen volumio[1437]: info: MRS: Pushing multiroomSync output update for this device Aug 25 17:20:49 kitchen volumio[1437]: info: MRS: Pushing multiroomSync output Aug 25 17:20:49 kitchen volumio[1437]: info: CoreCommandRouter::volumioGetState Aug 25 17:20:49 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:20:49 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:20:49 kitchen volumio[1437]: verbose: STATE SERVICE {"status":"stop","service":"radio_paradise","type":"webradio","trackType":"flac","radioType":"","albumart":"https://img.radioparadise.com/covers/l/12338.jpg","uri":"https://stream.radioparadise.com/mellow-flacm","name":"Mandolin Wind","title":"Mandolin Wind","artist":"Rod Stewart","album":"Gasoline Alley","streaming":true,"disableUiControls":true,"duration":42,"seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Aug 25 17:20:49 kitchen volumio[1437]: verbose: CURRENT POSITION 0 Aug 25 17:20:49 kitchen volumio[1437]: info: CoreStateMachine::syncState stateService stop Aug 25 17:20:49 kitchen volumio[1437]: info: CoreStateMachine::syncState currentStatus stop Aug 25 17:20:49 kitchen volumio[1437]: info: CoreStateMachine::pushState Aug 25 17:20:49 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:20:49 kitchen volumio[1437]: info: CoreCommandRouter::volumioPushState Aug 25 17:20:49 kitchen volumio[1437]: info: MRS: Pushing multiroomSync output update for this device Aug 25 17:20:49 kitchen volumio[1437]: info: MRS: Pushing multiroomSync output Aug 25 17:20:49 kitchen volumio[1437]: info: CoreCommandRouter::volumioGetState Aug 25 17:20:49 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:20:49 kitchen volumio[1437]: info: No code Aug 25 17:20:49 kitchen volumio[1437]: info: CoreStateMachine::pushState Aug 25 17:20:49 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:20:49 kitchen volumio[1437]: info: CoreCommandRouter::volumioPushState Aug 25 17:20:49 kitchen volumio[1437]: info: MRS: Pushing multiroomSync output update for this device Aug 25 17:20:49 kitchen volumio[1437]: info: MRS: Pushing multiroomSync output Aug 25 17:20:49 kitchen volumio[1437]: info: CoreCommandRouter::volumioGetState Aug 25 17:20:49 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:20:49 kitchen volumio[1437]: verbose: ControllerMpd::sendMpdCommand clear Aug 25 17:20:49 kitchen volumio[1437]: info: Aug 25 17:20:49 kitchen volumio[1437]: ---------------------------- MPD announces system playlist update Aug 25 17:20:49 kitchen volumio[1437]: info: Ignoring MPD Status Update Aug 25 17:20:49 kitchen volumio[1437]: info: sendMpdCommand status took 568 milliseconds Aug 25 17:20:49 kitchen volumio[1437]: info: sendMpdCommand clear took 432 milliseconds Aug 25 17:20:49 kitchen volumio[1437]: verbose: ControllerMpd::parseState Aug 25 17:20:49 kitchen volumio[1437]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 25 17:20:49 kitchen volumio[1437]: verbose: ControllerMpd::sendMpdCommand consume 1 Aug 25 17:20:50 kitchen volumio[1437]: error: updateQueue error: null Aug 25 17:20:50 kitchen volumio[1437]: info: ------------------------------ 290ms Aug 25 17:20:50 kitchen volumio[1437]: info: sendMpdCommand playlistinfo took 288 milliseconds Aug 25 17:20:50 kitchen volumio[1437]: info: sendMpdCommand consume 1 took 288 milliseconds Aug 25 17:20:50 kitchen volumio[1437]: verbose: ControllerMpd::parseTrackInfo Aug 25 17:20:50 kitchen volumio[1437]: info: [1787692850079] [RadioParadise] set to consume mode, adding url: https://stream.radioparadise.com/mellow-flacm Aug 25 17:20:50 kitchen volumio[1437]: verbose: ControllerMpd::sendMpdCommand add "https://stream.radioparadise.com/mellow-flacm" Aug 25 17:20:50 kitchen volumio[1437]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Aug 25 17:20:50 kitchen volumio[1437]: info: ------------------------------ 860ms Aug 25 17:20:50 kitchen volumio[1437]: info: Aug 25 17:20:50 kitchen volumio[1437]: ---------------------------- MPD announces system playlist update Aug 25 17:20:50 kitchen volumio[1437]: info: Ignoring MPD Status Update Aug 25 17:20:50 kitchen volumio[1437]: info: sendMpdCommand add "https://stream.radioparadise.com/mellow-flacm" took 9 milliseconds Aug 25 17:20:50 kitchen volumio[1437]: verbose: ControllerMpd::sendMpdCommand play Aug 25 17:20:50 kitchen volumio[1437]: info: ------------------------------ 50ms Aug 25 17:20:50 kitchen volumio[1437]: info: sendMpdCommand play took 22 milliseconds Aug 25 17:20:50 kitchen volumio[1437]: info: [RadioParadise] Using metadata URL: https://api.radioparadise.com/api/now_playing?chan=1 Aug 25 17:20:50 kitchen volumio[1437]: info: [1787692850137] [RadioParadise] getMetadata started with url https://api.radioparadise.com/api/now_playing?chan=1 Aug 25 17:20:50 kitchen volumio[1437]: info: [1787692850837] [RadioParadise] received new metadata: {"time":269,"artist":"Sade","title":"By Your Side","album":"Lovers Rock","year":"1999","cover":"https://img.radioparadise.com/covers/l/17607.jpg","cover_med":"https://img.radioparadise.com/covers/m/17607.jpg","cover_small":"https://img.radioparadise.com/covers/s/17607.jpg"} Aug 25 17:20:50 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:20:50 kitchen volumio[1437]: info: CoreCommandRouter::servicePushState Aug 25 17:20:50 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:20:50 kitchen volumio[1437]: verbose: STATE SERVICE {"status":"play","service":"radio_paradise","type":"webradio","trackType":"flac","radioType":"","albumart":"https://img.radioparadise.com/covers/l/17607.jpg","uri":"https://stream.radioparadise.com/mellow-flacm","name":"By Your Side","title":"By Your Side","artist":"Sade","album":"Lovers Rock","streaming":true,"disableUiControls":true,"duration":274,"seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Aug 25 17:20:50 kitchen volumio[1437]: verbose: CURRENT POSITION 0 Aug 25 17:20:50 kitchen volumio[1437]: info: CoreStateMachine::syncState stateService play Aug 25 17:20:50 kitchen volumio[1437]: info: CoreStateMachine::syncState currentStatus stop Aug 25 17:20:50 kitchen volumio[1437]: info: [1787692850838] [RadioParadise] setting new timer with duration of 274000 seconds. Aug 25 17:20:50 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:20:50 kitchen volumio[1437]: info: CorePlayQueue::getTrack 1 Aug 25 17:20:50 kitchen volumio[1437]: info: Aug 25 17:20:50 kitchen volumio[1437]: ---------------------------- MPD announces state update: player Aug 25 17:20:50 kitchen volumio[1437]: info: ControllerMpd::getState Aug 25 17:20:50 kitchen volumio[1437]: verbose: ControllerMpd::sendMpdCommand status Aug 25 17:20:50 kitchen volumio[1437]: info: Aug 25 17:20:50 kitchen volumio[1437]: ---------------------------- MPD announces state update: player Aug 25 17:20:50 kitchen volumio[1437]: info: sendMpdCommand status took 40 milliseconds Aug 25 17:20:50 kitchen volumio[1437]: info: ControllerMpd::getState Aug 25 17:20:50 kitchen volumio[1437]: verbose: ControllerMpd::sendMpdCommand status Aug 25 17:20:50 kitchen volumio[1437]: verbose: ControllerMpd::parseState Aug 25 17:20:50 kitchen volumio[1437]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 25 17:20:50 kitchen volumio[1437]: info: sendMpdCommand status took 1 milliseconds Aug 25 17:20:50 kitchen volumio[1437]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 25 17:20:50 kitchen volumio[1437]: verbose: ControllerMpd::parseState Aug 25 17:20:50 kitchen volumio[1437]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 25 17:20:50 kitchen volumio[1437]: verbose: ControllerMpd::parseTrackInfo Aug 25 17:20:50 kitchen volumio[1437]: info: ControllerMpd::pushState Aug 25 17:20:50 kitchen volumio[1437]: info: CoreCommandRouter::servicePushState Aug 25 17:20:50 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:20:50 kitchen volumio[1437]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Aug 25 17:20:50 kitchen volumio[1437]: info: ------------------------------ 43ms Aug 25 17:20:50 kitchen volumio[1437]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 25 17:20:50 kitchen volumio[1437]: verbose: ControllerMpd::parseTrackInfo Aug 25 17:20:50 kitchen volumio[1437]: info: ControllerMpd::pushState Aug 25 17:20:50 kitchen volumio[1437]: info: CoreCommandRouter::servicePushState Aug 25 17:20:50 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:20:50 kitchen volumio[1437]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Aug 25 17:20:50 kitchen volumio[1437]: info: ------------------------------ 5ms Aug 25 17:20:51 kitchen volumio[1437]: info: Aug 25 17:20:51 kitchen volumio[1437]: ---------------------------- MPD announces system playlist update Aug 25 17:20:51 kitchen volumio[1437]: info: Ignoring MPD Status Update Aug 25 17:20:51 kitchen volumio[1437]: info: Aug 25 17:20:51 kitchen volumio[1437]: ---------------------------- MPD announces state update: player Aug 25 17:20:51 kitchen volumio[1437]: info: ControllerMpd::getState Aug 25 17:20:51 kitchen volumio[1437]: verbose: ControllerMpd::sendMpdCommand status Aug 25 17:20:51 kitchen volumio[1437]: info: ------------------------------ 2ms Aug 25 17:20:51 kitchen volumio[1437]: info: sendMpdCommand status took 1 milliseconds Aug 25 17:20:51 kitchen volumio[1437]: verbose: ControllerMpd::parseState Aug 25 17:20:51 kitchen volumio[1437]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 25 17:20:51 kitchen volumio[1437]: info: sendMpdCommand playlistinfo took 0 milliseconds Aug 25 17:20:51 kitchen volumio[1437]: verbose: ControllerMpd::parseTrackInfo Aug 25 17:20:51 kitchen volumio[1437]: info: ControllerMpd::pushState Aug 25 17:20:51 kitchen volumio[1437]: info: CoreCommandRouter::servicePushState Aug 25 17:20:51 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:20:51 kitchen volumio[1437]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Aug 25 17:20:51 kitchen volumio[1437]: info: ------------------------------ 16ms Aug 25 17:20:53 kitchen volumio[1437]: info: Aug 25 17:20:53 kitchen volumio[1437]: ---------------------------- MPD announces system playlist update Aug 25 17:20:53 kitchen volumio[1437]: info: Ignoring MPD Status Update Aug 25 17:20:53 kitchen volumio[1437]: info: Aug 25 17:20:53 kitchen volumio[1437]: ---------------------------- MPD announces state update: player Aug 25 17:20:53 kitchen volumio[1437]: info: ControllerMpd::getState Aug 25 17:20:53 kitchen volumio[1437]: verbose: ControllerMpd::sendMpdCommand status Aug 25 17:20:53 kitchen volumio[1437]: info: ------------------------------ 3ms Aug 25 17:20:53 kitchen volumio[1437]: info: sendMpdCommand status took 2 milliseconds Aug 25 17:20:53 kitchen volumio[1437]: verbose: ControllerMpd::parseState Aug 25 17:20:53 kitchen volumio[1437]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 25 17:20:53 kitchen volumio[1437]: info: sendMpdCommand playlistinfo took 0 milliseconds Aug 25 17:20:53 kitchen volumio[1437]: verbose: ControllerMpd::parseTrackInfo Aug 25 17:20:53 kitchen volumio[1437]: info: ControllerMpd::pushState Aug 25 17:20:53 kitchen volumio[1437]: info: CoreCommandRouter::servicePushState Aug 25 17:20:53 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:20:53 kitchen volumio[1437]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Aug 25 17:20:53 kitchen volumio[1437]: info: ------------------------------ 5ms Aug 25 17:20:56 kitchen volumio[1437]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 25 17:20:56 kitchen volumio[1437]: info: CoreCommandRouter::Close All Modals sent Aug 25 17:21:23 kitchen volumio[1437]: info: Aug 25 17:21:23 kitchen volumio[1437]: ---------------------------- MPD announces system playlist update Aug 25 17:21:23 kitchen volumio[1437]: info: Ignoring MPD Status Update Aug 25 17:21:23 kitchen volumio[1437]: info: Aug 25 17:21:23 kitchen volumio[1437]: ---------------------------- MPD announces state update: player Aug 25 17:21:23 kitchen volumio[1437]: info: ControllerMpd::getState Aug 25 17:21:23 kitchen volumio[1437]: verbose: ControllerMpd::sendMpdCommand status Aug 25 17:21:23 kitchen volumio[1437]: info: ------------------------------ 14ms Aug 25 17:21:23 kitchen volumio[1437]: info: sendMpdCommand status took 13 milliseconds Aug 25 17:21:23 kitchen volumio[1437]: verbose: ControllerMpd::parseState Aug 25 17:21:23 kitchen volumio[1437]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 25 17:21:23 kitchen volumio[1437]: info: sendMpdCommand playlistinfo took 0 milliseconds Aug 25 17:21:23 kitchen volumio[1437]: verbose: ControllerMpd::parseTrackInfo Aug 25 17:21:23 kitchen volumio[1437]: info: ControllerMpd::pushState Aug 25 17:21:23 kitchen volumio[1437]: info: CoreCommandRouter::servicePushState Aug 25 17:21:23 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:21:23 kitchen volumio[1437]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Aug 25 17:21:23 kitchen volumio[1437]: info: ------------------------------ 26ms Aug 25 17:21:32 kitchen volumio[1437]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 25 17:21:32 kitchen volumio[1437]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Aug 25 17:21:39 kitchen volumio[1437]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 25 17:21:50 kitchen volumio[1437]: info: CALLMETHOD: music_service spotify-connect saveSettings [object Object] Aug 25 17:21:50 kitchen volumio[1437]: info: CoreCommandRouter::executeOnPlugin: spotify-connect , saveSettings Aug 25 17:21:50 kitchen volumio[1437]: warn: [SpotifyConnect] event stream closed, retrying… Aug 25 17:21:50 kitchen volumio[1437]: warn: [SpotifyConnect] daemon exited (0) Aug 25 17:21:51 kitchen volumio[1437]: info: [go-librespot] time="2026-08-25T17:21:51-04:00" level=info msg="running go-librespot 0.9.0" Aug 25 17:21:51 kitchen volumio[1437]: info: [go-librespot] time="2026-08-25T17:21:51-04:00" level=info msg="api server listening on 127.0.0.1:9878" Aug 25 17:21:51 kitchen volumio[1437]: info: [go-librespot] time="2026-08-25T17:21:51-04:00" level=info msg="zeroconf server listening on port 33073" Aug 25 17:21:51 kitchen volumio[1437]: info: [go-librespot] time="2026-08-25T17:21:51-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 25 17:21:51 kitchen volumio[1437]: info: [go-librespot] time="2026-08-25T17:21:51-04:00" level=info msg="loading previously persisted zeroconf credentials" username="jo****n1" Aug 25 17:21:52 kitchen volumio[1437]: info: [SpotifyConnect] event stream CONNECTED (ws://localhost:9878/events) Aug 25 17:21:52 kitchen volumio[1437]: info: [go-librespot] time="2026-08-25T17:21:52-04:00" level=info msg="authenticated AP" username="jo****n1" Aug 25 17:21:52 kitchen volumio[1437]: info: [go-librespot] time="2026-08-25T17:21:52-04:00" level=info msg="authenticated Login5" username="jo****n1" Aug 25 17:21:52 kitchen volumio[1437]: info: CoreCommandRouter::servicePushState Aug 25 17:21:52 kitchen volumio[1437]: info: CoreStateMachine::pushState Aug 25 17:21:52 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:21:52 kitchen volumio[1437]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 25 17:21:52 kitchen volumio[1437]: info: CoreCommandRouter::volumioPushState Aug 25 17:21:52 kitchen volumio[1437]: info: MRS: Pushing multiroomSync output update for this device Aug 25 17:21:52 kitchen volumio[1437]: info: MRS: Pushing multiroomSync output Aug 25 17:21:52 kitchen volumio[1437]: info: CoreCommandRouter::volumioGetState Aug 25 17:21:52 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:21:52 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:21:52 kitchen volumio[1437]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received spotify-connect Aug 25 17:21:52 kitchen volumio[1437]: info: CoreCommandRouter::volumioGetQueue Aug 25 17:21:52 kitchen volumio[1437]: info: CoreStateMachine::getQueue Aug 25 17:21:52 kitchen volumio[1437]: info: CorePlayQueue::getQueue Aug 25 17:21:53 kitchen volumio[1437]: info: [SpotifyConnect] event: playback_ready Aug 25 17:21:53 kitchen volumio[1437]: info: [SpotifyConnect] event stream CONNECTED (ws://localhost:9878/events) Aug 25 17:21:53 kitchen volumio[1437]: info: CoreCommandRouter::servicePushState Aug 25 17:21:53 kitchen volumio[1437]: info: CoreStateMachine::pushState Aug 25 17:21:53 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:21:53 kitchen volumio[1437]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 25 17:21:53 kitchen volumio[1437]: info: CoreCommandRouter::volumioPushState Aug 25 17:21:53 kitchen volumio[1437]: info: MRS: Pushing multiroomSync output update for this device Aug 25 17:21:53 kitchen volumio[1437]: info: MRS: Pushing multiroomSync output Aug 25 17:21:53 kitchen volumio[1437]: info: CoreCommandRouter::volumioGetState Aug 25 17:21:53 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:21:53 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:21:53 kitchen volumio[1437]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received spotify-connect Aug 25 17:21:53 kitchen volumio[1437]: info: [SpotifyConnect] event: volume Aug 25 17:21:53 kitchen volumio[1437]: info: VolumeController::SetAlsaVolume77 Aug 25 17:21:53 kitchen volumio[1437]: info: CoreStateMachine::pushState Aug 25 17:21:53 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:21:53 kitchen volumio[1437]: info: CoreCommandRouter::volumioPushState Aug 25 17:21:53 kitchen volumio[1437]: info: MRS: Pushing multiroomSync output update for this device Aug 25 17:21:53 kitchen volumio[1437]: info: MRS: Pushing multiroomSync output Aug 25 17:21:53 kitchen volumio[1437]: info: CoreCommandRouter::volumioGetState Aug 25 17:21:53 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:21:53 kitchen volumio[1437]: info: [SpotifyConnect] event: volume Aug 25 17:21:53 kitchen volumio[1437]: info: VolumeController::SetAlsaVolume77 Aug 25 17:21:53 kitchen volumio[1437]: info: CoreStateMachine::pushState Aug 25 17:21:53 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:21:53 kitchen volumio[1437]: info: CoreCommandRouter::volumioPushState Aug 25 17:21:53 kitchen volumio[1437]: info: MRS: Pushing multiroomSync output update for this device Aug 25 17:21:53 kitchen volumio[1437]: info: MRS: Pushing multiroomSync output Aug 25 17:21:53 kitchen volumio[1437]: info: CoreCommandRouter::volumioGetState Aug 25 17:21:53 kitchen volumio[1437]: info: CorePlayQueue::getTrack 0 Aug 25 17:21:53 kitchen volumio[1437]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 25 17:21:53 kitchen volumio[1437]: Error: Unable to resolve or reject the same promise twice Aug 25 17:21:53 kitchen volumio[1437]: at Promise.resolve (/data/plugins/music_service/spotify-connect/node_modules/kew/kew.js:140:43) Aug 25 17:21:53 kitchen volumio[1437]: at Timeout._onTimeout (/data/plugins/music_service/spotify-connect/index.js:162:13) Aug 25 17:21:53 kitchen volumio[1437]: at listOnTimeout (node:internal/timers:573:17) Aug 25 17:21:53 kitchen volumio[1437]: at process.processTimers (node:internal/timers:514:7) Aug 25 17:21:53 kitchen volumio[1437]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 25 17:21:57 kitchen sudo[2799]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-25 17:20' Aug 25 17:21:57 kitchen sudo[2799]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"