Feb 26 21:44:21 volumio-salon volumio[1198]: info: CoreCommandRouter::volumioGetState Feb 26 21:44:21 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:21 volumio-salon volumio[1198]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Feb 26 21:44:21 volumio-salon volumio[1198]: info: CoreCommandRouter::volumioPlay Feb 26 21:44:21 volumio-salon volumio[1198]: info: CoreStateMachine::play index undefined Feb 26 21:44:21 volumio-salon volumio[1198]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 21:44:21 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:21 volumio-salon volumio[1198]: info: CoreStateMachine::startPlaybackTimer Feb 26 21:44:21 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:21 volumio-salon volumio[1198]: info: CoreCommandRouter::volumioGetVisibleSources Feb 26 21:44:21 volumio-salon volumio[1198]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 26 21:44:21 volumio-salon volumio[1198]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Feb 26 21:44:21 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand play Feb 26 21:44:21 volumio-salon kernel: bcm2835-i2s 3f203000.i2s: I2S SYNC error! Feb 26 21:44:21 volumio-salon volumio[1198]: info: Feb 26 21:44:21 volumio-salon volumio[1198]: ---------------------------- MPD announces state update: player Feb 26 21:44:21 volumio-salon volumio[1198]: info: sendMpdCommand play took 6 milliseconds Feb 26 21:44:21 volumio-salon volumio[1198]: info: ControllerMpd::getState Feb 26 21:44:21 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand status Feb 26 21:44:21 volumio-salon volumio[1198]: info: CoreCommandRouter::servicePushState Feb 26 21:44:21 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:21 volumio-salon volumio[1198]: verbose: STATE SERVICE {"status":"play","service":"radio_paradise","type":"webradio","trackType":"flac","radioType":"","albumart":"https://img.radioparadise.com/covers/l/18626.jpg","uri":"https://stream.radioparadise.com/flacm","name":"Black Mambo","title":"Black Mambo","artist":"Glass Animals","album":"ZABA","streaming":true,"disableUiControls":true,"duration":230,"seek":228842,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Feb 26 21:44:21 volumio-salon volumio[1198]: verbose: CURRENT POSITION 0 Feb 26 21:44:21 volumio-salon volumio[1198]: info: CoreStateMachine::syncState stateService play Feb 26 21:44:21 volumio-salon volumio[1198]: info: CoreStateMachine::syncState currentStatus pause Feb 26 21:44:21 volumio-salon volumio[1198]: info: CoreStateMachine::pushState Feb 26 21:44:21 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:21 volumio-salon volumio[1198]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 21:44:21 volumio-salon volumio[1198]: info: CoreCommandRouter::volumioPushState Feb 26 21:44:21 volumio-salon volumio[1198]: info: MRS: Pushing multiroomSync output update for this device Feb 26 21:44:21 volumio-salon volumio[1198]: info: MRS: Pushing multiroomSync output Feb 26 21:44:21 volumio-salon volumio[1198]: info: [1772138661296] [RadioParadise] getMetadata started with url https://api.radioparadise.com/api/now_playing?chan=0 Feb 26 21:44:21 volumio-salon volumio5-onboarding[1482]: time=2026-02-26T21:44:21.306+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.37:51254 @ 0x22ce0c0" state=STATUS_PLAYING positionMs=229344 volume=100 Feb 26 21:44:21 volumio-salon volumio5-onboarding[1482]: time=2026-02-26T21:44:21.307+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.37:51254 @ 0x22ce0c0" id=https://stream.radioparadise.com/flacm title="Black Mambo" Feb 26 21:44:21 volumio-salon volumio[1198]: info: Feb 26 21:44:21 volumio-salon volumio[1198]: ---------------------------- MPD announces state update: player Feb 26 21:44:21 volumio-salon volumio[1198]: info: ControllerMpd::getState Feb 26 21:44:21 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand status Feb 26 21:44:21 volumio-salon volumio[1198]: info: sendMpdCommand status took 22 milliseconds Feb 26 21:44:21 volumio-salon volumio[1198]: info: sendMpdCommand status took 1 milliseconds Feb 26 21:44:21 volumio-salon volumio[1198]: verbose: ControllerMpd::parseState Feb 26 21:44:21 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 21:44:21 volumio-salon volumio[1198]: verbose: ControllerMpd::parseState Feb 26 21:44:21 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 21:44:21 volumio-salon volumio[1198]: info: sendMpdCommand playlistinfo took 7 milliseconds Feb 26 21:44:21 volumio-salon volumio[1198]: info: sendMpdCommand playlistinfo took 8 milliseconds Feb 26 21:44:21 volumio-salon volumio[1198]: verbose: ControllerMpd::parseTrackInfo Feb 26 21:44:21 volumio-salon volumio[1198]: verbose: ControllerMpd::parseTrackInfo Feb 26 21:44:21 volumio-salon volumio[1198]: info: ControllerMpd::pushState Feb 26 21:44:21 volumio-salon volumio[1198]: info: CoreCommandRouter::servicePushState Feb 26 21:44:21 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:21 volumio-salon volumio[1198]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Feb 26 21:44:21 volumio-salon volumio[1198]: info: ControllerMpd::pushState Feb 26 21:44:21 volumio-salon volumio[1198]: info: CoreCommandRouter::servicePushState Feb 26 21:44:21 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:21 volumio-salon volumio[1198]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Feb 26 21:44:21 volumio-salon volumio[1198]: info: ------------------------------ 33ms Feb 26 21:44:21 volumio-salon volumio[1198]: info: ------------------------------ 12ms Feb 26 21:44:21 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:21 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 1 Feb 26 21:44:21 volumio-salon volumio[1198]: info: [1772138661846] [RadioParadise] received new metadata: {"time":37,"artist":"The The","title":"Where Do We Go When We Die?","album":"Ensoulment","year":"2024","cover":"https://img.radioparadise.com/covers/l/26434.jpg","cover_med":"https://img.radioparadise.com/covers/m/26434.jpg","cover_small":"https://img.radioparadise.com/covers/s/26434.jpg"} Feb 26 21:44:21 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:21 volumio-salon volumio[1198]: info: CoreCommandRouter::servicePushState Feb 26 21:44:21 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:21 volumio-salon volumio[1198]: verbose: STATE SERVICE {"status":"play","service":"radio_paradise","type":"webradio","trackType":"flac","radioType":"","albumart":"https://img.radioparadise.com/covers/l/26434.jpg","uri":"https://stream.radioparadise.com/flacm","name":"Where Do We Go When We Die?","title":"Where Do We Go When We Die?","artist":"The The","album":"Ensoulment","streaming":true,"disableUiControls":true,"duration":42,"seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Feb 26 21:44:21 volumio-salon volumio[1198]: verbose: CURRENT POSITION 0 Feb 26 21:44:21 volumio-salon volumio[1198]: info: CoreStateMachine::syncState stateService play Feb 26 21:44:21 volumio-salon volumio[1198]: info: CoreStateMachine::syncState currentStatus play Feb 26 21:44:21 volumio-salon volumio[1198]: info: Received an update from plugin. extracting info from payload Feb 26 21:44:21 volumio-salon volumio[1198]: info: CoreStateMachine::pushState Feb 26 21:44:21 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:21 volumio-salon volumio[1198]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 21:44:21 volumio-salon volumio[1198]: info: CoreCommandRouter::volumioPushState Feb 26 21:44:21 volumio-salon volumio[1198]: info: MRS: Pushing multiroomSync output update for this device Feb 26 21:44:21 volumio-salon volumio[1198]: info: MRS: Pushing multiroomSync output Feb 26 21:44:21 volumio-salon volumio[1198]: info: CoreStateMachine::pushState Feb 26 21:44:21 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:21 volumio-salon volumio[1198]: info: CoreCommandRouter::volumioPushState Feb 26 21:44:21 volumio-salon volumio[1198]: info: MRS: Pushing multiroomSync output update for this device Feb 26 21:44:21 volumio-salon volumio[1198]: info: MRS: Pushing multiroomSync output Feb 26 21:44:21 volumio-salon volumio5-onboarding[1482]: time=2026-02-26T21:44:21.857+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.37:51254 @ 0x22ce0c0" state=STATUS_PLAYING positionMs=0 volume=100 Feb 26 21:44:21 volumio-salon volumio5-onboarding[1482]: time=2026-02-26T21:44:21.858+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.37:51254 @ 0x22ce0c0" state=STATUS_PLAYING positionMs=0 volume=100 Feb 26 21:44:21 volumio-salon volumio5-onboarding[1482]: time=2026-02-26T21:44:21.858+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.37:51254 @ 0x22ce0c0" id=https://stream.radioparadise.com/flacm title="Where Do We Go When We Die?" Feb 26 21:44:21 volumio-salon volumio5-onboarding[1482]: time=2026-02-26T21:44:21.858+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.37:51254 @ 0x22ce0c0" id=https://stream.radioparadise.com/flacm title="Where Do We Go When We Die?" Feb 26 21:44:21 volumio-salon volumio[1198]: info: [1772138661863] [RadioParadise] setting new timer with duration of 42000 seconds. Feb 26 21:44:27 volumio-salon volumio[1198]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 26 21:44:27 volumio-salon volumio[1198]: info: CoreCommandRouter::Close All Modals sent Feb 26 21:44:33 volumio-salon volumio[1198]: info: Preload queue cleared Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreStateMachine::ClearQueue Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreStateMachine::stop Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreStateMachine::stPlaybackTimer Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreStateMachine::updateTrackBlock Feb 26 21:44:33 volumio-salon volumio[1198]: info: CorePlayQueue::getTrackBlock Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreStateMachine::pushState Feb 26 21:44:33 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreCommandRouter::volumioPushState Feb 26 21:44:33 volumio-salon volumio[1198]: info: MRS: Pushing multiroomSync output update for this device Feb 26 21:44:33 volumio-salon volumio[1198]: info: MRS: Pushing multiroomSync output Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreStateMachine::serviceStop Feb 26 21:44:33 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreCommandRouter::serviceStop Feb 26 21:44:33 volumio-salon volumio[1198]: info: ControllerMpd::stop Feb 26 21:44:33 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand stop Feb 26 21:44:33 volumio-salon volumio[1198]: info: CorePlayQueue::clearPlayQueue Feb 26 21:44:33 volumio-salon volumio[1198]: info: CorePlayQueue::saveQueue Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreCommandRouter::volumioPushQueue Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreStateMachine::addQueueItems Feb 26 21:44:33 volumio-salon volumio[1198]: info: CorePlayQueue::addQueueItems Feb 26 21:44:33 volumio-salon volumio[1198]: info: Preload queue cleared Feb 26 21:44:33 volumio-salon volumio[1198]: info: Adding Item to queue: webrp/1 Feb 26 21:44:33 volumio-salon volumio[1198]: info: Exploding uri webrp/1 in service radio_paradise Feb 26 21:44:33 volumio-salon volumio5-onboarding[1482]: time=2026-02-26T21:44:33.727+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.37:51254 @ 0x22ce0c0" state=STATUS_STOPPED positionMs=0 volume=100 Feb 26 21:44:33 volumio-salon volumio5-onboarding[1482]: time=2026-02-26T21:44:33.727+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.37:51254 @ 0x22ce0c0" id=https://stream.radioparadise.com/flacm title="Where Do We Go When We Die?" Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreCommandRouter::volumioPushQueue Feb 26 21:44:33 volumio-salon volumio[1198]: info: CorePlayQueue::saveQueue Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreStateMachine::updateTrackBlock Feb 26 21:44:33 volumio-salon volumio[1198]: info: CorePlayQueue::getTrackBlock Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreCommandRouter::volumioGetState Feb 26 21:44:33 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreCommandRouter::volumioPlay Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreStateMachine::play index 0 Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreStateMachine::stop Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreStateMachine::play index undefined Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 21:44:33 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreStateMachine::startPlaybackTimer Feb 26 21:44:33 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreCommandRouter::volumioGetVisibleSources Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Feb 26 21:44:33 volumio-salon volumio[1198]: info: [RadioParadise] Matched station: Radio Paradise Mellow Mix (FLAC), chan=1 Feb 26 21:44:33 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand stop Feb 26 21:44:33 volumio-salon volumio[1198]: info: Feb 26 21:44:33 volumio-salon volumio[1198]: ---------------------------- MPD announces state update: player Feb 26 21:44:33 volumio-salon volumio[1198]: info: sendMpdCommand stop took 23 milliseconds Feb 26 21:44:33 volumio-salon volumio[1198]: info: ControllerMpd::getState Feb 26 21:44:33 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand status Feb 26 21:44:33 volumio-salon volumio[1198]: info: sendMpdCommand stop took 10 milliseconds Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreCommandRouter::servicePushState Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreStateMachine::pushState Feb 26 21:44:33 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreCommandRouter::volumioPushState Feb 26 21:44:33 volumio-salon volumio[1198]: info: MRS: Pushing multiroomSync output update for this device Feb 26 21:44:33 volumio-salon volumio[1198]: info: MRS: Pushing multiroomSync output Feb 26 21:44:33 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:33 volumio-salon volumio[1198]: verbose: STATE SERVICE {"status":"stop","service":"radio_paradise","type":"webradio","trackType":"flac","radioType":"","albumart":"https://img.radioparadise.com/covers/l/26434.jpg","uri":"https://stream.radioparadise.com/flacm","name":"Where Do We Go When We Die?","title":"Where Do We Go When We Die?","artist":"The The","album":"Ensoulment","streaming":true,"disableUiControls":true,"duration":42,"seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Feb 26 21:44:33 volumio-salon volumio[1198]: verbose: CURRENT POSITION 0 Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreStateMachine::syncState stateService stop Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreStateMachine::syncState currentStatus stop Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreStateMachine::pushState Feb 26 21:44:33 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreCommandRouter::volumioPushState Feb 26 21:44:33 volumio-salon volumio[1198]: info: MRS: Pushing multiroomSync output update for this device Feb 26 21:44:33 volumio-salon volumio[1198]: info: MRS: Pushing multiroomSync output Feb 26 21:44:33 volumio-salon volumio[1198]: info: No code Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreStateMachine::pushState Feb 26 21:44:33 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreCommandRouter::volumioPushState Feb 26 21:44:33 volumio-salon volumio[1198]: info: MRS: Pushing multiroomSync output update for this device Feb 26 21:44:33 volumio-salon volumio[1198]: info: MRS: Pushing multiroomSync output Feb 26 21:44:33 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand clear Feb 26 21:44:33 volumio-salon volumio5-onboarding[1482]: time=2026-02-26T21:44:33.763+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.37:51254 @ 0x22ce0c0" state=STATUS_STOPPED positionMs=0 volume=100 Feb 26 21:44:33 volumio-salon volumio5-onboarding[1482]: time=2026-02-26T21:44:33.764+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.37:51254 @ 0x22ce0c0" state=STATUS_STOPPED positionMs=0 volume=100 Feb 26 21:44:33 volumio-salon volumio5-onboarding[1482]: time=2026-02-26T21:44:33.764+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.37:51254 @ 0x22ce0c0" id=https://stream.radioparadise.com/mellow-flacm title="Radio Paradise Mellow Mix (FLAC)" Feb 26 21:44:33 volumio-salon volumio5-onboarding[1482]: time=2026-02-26T21:44:33.764+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.37:51254 @ 0x22ce0c0" state=STATUS_STOPPED positionMs=0 volume=100 Feb 26 21:44:33 volumio-salon volumio5-onboarding[1482]: time=2026-02-26T21:44:33.764+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.37:51254 @ 0x22ce0c0" id=https://stream.radioparadise.com/mellow-flacm title="Radio Paradise Mellow Mix (FLAC)" Feb 26 21:44:33 volumio-salon volumio5-onboarding[1482]: time=2026-02-26T21:44:33.765+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.37:51254 @ 0x22ce0c0" id=https://stream.radioparadise.com/mellow-flacm title="Radio Paradise Mellow Mix (FLAC)" Feb 26 21:44:33 volumio-salon volumio[1198]: info: Feb 26 21:44:33 volumio-salon volumio[1198]: ---------------------------- MPD announces state update: player Feb 26 21:44:33 volumio-salon volumio[1198]: info: ControllerMpd::getState Feb 26 21:44:33 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand status Feb 26 21:44:33 volumio-salon volumio[1198]: info: Feb 26 21:44:33 volumio-salon volumio[1198]: ---------------------------- MPD announces system playlist update Feb 26 21:44:33 volumio-salon volumio[1198]: info: Ignoring MPD Status Update Feb 26 21:44:33 volumio-salon volumio[1198]: info: sendMpdCommand status took 43 milliseconds Feb 26 21:44:33 volumio-salon volumio[1198]: info: sendMpdCommand clear took 29 milliseconds Feb 26 21:44:33 volumio-salon volumio[1198]: info: sendMpdCommand status took 17 milliseconds Feb 26 21:44:33 volumio-salon volumio[1198]: verbose: ControllerMpd::parseState Feb 26 21:44:33 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 21:44:33 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand consume 1 Feb 26 21:44:33 volumio-salon volumio[1198]: verbose: ControllerMpd::parseState Feb 26 21:44:33 volumio-salon volumio[1198]: info: ControllerMpd::pushState Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreCommandRouter::servicePushState Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreStateMachine::pushState Feb 26 21:44:33 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:33 volumio-salon volumio[1198]: info: CoreCommandRouter::volumioPushState Feb 26 21:44:33 volumio-salon volumio[1198]: info: MRS: Pushing multiroomSync output update for this device Feb 26 21:44:33 volumio-salon volumio[1198]: info: MRS: Pushing multiroomSync output Feb 26 21:44:33 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:33 volumio-salon volumio[1198]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Feb 26 21:44:33 volumio-salon volumio5-onboarding[1482]: time=2026-02-26T21:44:33.798+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.37:51254 @ 0x22ce0c0" state=STATUS_STOPPED positionMs=0 volume=100 Feb 26 21:44:33 volumio-salon volumio5-onboarding[1482]: time=2026-02-26T21:44:33.798+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.37:51254 @ 0x22ce0c0" id=https://stream.radioparadise.com/mellow-flacm title="Radio Paradise Mellow Mix (FLAC)" Feb 26 21:44:33 volumio-salon volumio[1198]: info: ------------------------------ 27ms Feb 26 21:44:33 volumio-salon volumio[1198]: info: Feb 26 21:44:33 volumio-salon volumio[1198]: ---------------------------- MPD announces system playlist update Feb 26 21:44:33 volumio-salon volumio[1198]: info: Ignoring MPD Status Update Feb 26 21:44:33 volumio-salon volumio[1198]: error: updateQueue error: null Feb 26 21:44:33 volumio-salon volumio[1198]: error: updateQueue error: null Feb 26 21:44:33 volumio-salon volumio[1198]: info: ------------------------------ 19ms Feb 26 21:44:33 volumio-salon volumio[1198]: info: sendMpdCommand playlistinfo took 18 milliseconds Feb 26 21:44:33 volumio-salon volumio[1198]: info: sendMpdCommand consume 1 took 18 milliseconds Feb 26 21:44:33 volumio-salon volumio[1198]: info: ------------------------------ 8ms Feb 26 21:44:33 volumio-salon volumio[1198]: verbose: ControllerMpd::parseTrackInfo Feb 26 21:44:33 volumio-salon volumio[1198]: info: [1772138673810] [RadioParadise] set to consume mode, adding url: https://stream.radioparadise.com/mellow-flacm Feb 26 21:44:33 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand add "https://stream.radioparadise.com/mellow-flacm" Feb 26 21:44:33 volumio-salon volumio[1198]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Feb 26 21:44:33 volumio-salon volumio[1198]: info: ------------------------------ 64ms Feb 26 21:44:33 volumio-salon volumio[1198]: info: Feb 26 21:44:33 volumio-salon volumio[1198]: ---------------------------- MPD announces system playlist update Feb 26 21:44:33 volumio-salon volumio[1198]: info: Ignoring MPD Status Update Feb 26 21:44:33 volumio-salon volumio[1198]: info: sendMpdCommand add "https://stream.radioparadise.com/mellow-flacm" took 3 milliseconds Feb 26 21:44:33 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand play Feb 26 21:44:33 volumio-salon volumio[1198]: info: Feb 26 21:44:33 volumio-salon volumio[1198]: ---------------------------- MPD announces system playlist update Feb 26 21:44:33 volumio-salon volumio[1198]: info: Ignoring MPD Status Update Feb 26 21:44:33 volumio-salon volumio[1198]: info: ------------------------------ 7ms Feb 26 21:44:33 volumio-salon volumio[1198]: info: sendMpdCommand play took 4 milliseconds Feb 26 21:44:33 volumio-salon volumio[1198]: info: ------------------------------ 4ms Feb 26 21:44:33 volumio-salon volumio[1198]: info: [RadioParadise] Using metadata URL: https://api.radioparadise.com/api/now_playing?chan=1 Feb 26 21:44:33 volumio-salon volumio[1198]: info: [1772138673819] [RadioParadise] getMetadata started with url https://api.radioparadise.com/api/now_playing?chan=1 Feb 26 21:44:34 volumio-salon volumio[1198]: info: [1772138674353] [RadioParadise] received new metadata: {"time":12,"artist":"Ayla Nereo","title":"Lead With Your Bones","album":"Sovereign Kin – Book I: The Spark","year":"2023","cover":"https://img.radioparadise.com/covers/l/19917.jpg","cover_med":"https://img.radioparadise.com/covers/m/19917.jpg","cover_small":"https://img.radioparadise.com/covers/s/19917.jpg"} Feb 26 21:44:34 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:34 volumio-salon volumio[1198]: info: CoreCommandRouter::servicePushState Feb 26 21:44:34 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:34 volumio-salon volumio[1198]: verbose: STATE SERVICE {"status":"play","service":"radio_paradise","type":"webradio","trackType":"flac","radioType":"","albumart":"https://img.radioparadise.com/covers/l/19917.jpg","uri":"https://stream.radioparadise.com/mellow-flacm","name":"Lead With Your Bones","title":"Lead With Your Bones","artist":"Ayla Nereo","album":"Sovereign Kin – Book I: The Spark","streaming":true,"disableUiControls":true,"duration":17,"seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Feb 26 21:44:34 volumio-salon volumio[1198]: verbose: CURRENT POSITION 0 Feb 26 21:44:34 volumio-salon volumio[1198]: info: CoreStateMachine::syncState stateService play Feb 26 21:44:34 volumio-salon volumio[1198]: info: CoreStateMachine::syncState currentStatus stop Feb 26 21:44:34 volumio-salon volumio[1198]: info: [1772138674354] [RadioParadise] setting new timer with duration of 17000 seconds. Feb 26 21:44:34 volumio-salon volumio[1198]: info: Feb 26 21:44:34 volumio-salon volumio[1198]: ---------------------------- MPD announces state update: player Feb 26 21:44:34 volumio-salon volumio[1198]: info: ControllerMpd::getState Feb 26 21:44:34 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand status Feb 26 21:44:34 volumio-salon volumio[1198]: info: Feb 26 21:44:34 volumio-salon volumio[1198]: ---------------------------- MPD announces state update: player Feb 26 21:44:34 volumio-salon volumio[1198]: info: ControllerMpd::getState Feb 26 21:44:34 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand status Feb 26 21:44:34 volumio-salon volumio[1198]: info: Feb 26 21:44:34 volumio-salon volumio[1198]: ---------------------------- MPD announces state update: player Feb 26 21:44:34 volumio-salon volumio[1198]: info: sendMpdCommand status took 4 milliseconds Feb 26 21:44:34 volumio-salon volumio[1198]: info: ControllerMpd::getState Feb 26 21:44:34 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand status Feb 26 21:44:34 volumio-salon volumio[1198]: verbose: ControllerMpd::parseState Feb 26 21:44:34 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 21:44:34 volumio-salon volumio[1198]: info: Feb 26 21:44:34 volumio-salon volumio[1198]: ---------------------------- MPD announces state update: player Feb 26 21:44:34 volumio-salon volumio[1198]: info: ControllerMpd::getState Feb 26 21:44:34 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand status Feb 26 21:44:34 volumio-salon volumio[1198]: info: sendMpdCommand status took 5 milliseconds Feb 26 21:44:34 volumio-salon volumio[1198]: info: sendMpdCommand status took 3 milliseconds Feb 26 21:44:34 volumio-salon volumio[1198]: info: sendMpdCommand playlistinfo took 3 milliseconds Feb 26 21:44:34 volumio-salon volumio[1198]: verbose: ControllerMpd::parseState Feb 26 21:44:34 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 21:44:34 volumio-salon volumio[1198]: verbose: ControllerMpd::parseState Feb 26 21:44:34 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 21:44:34 volumio-salon volumio[1198]: verbose: ControllerMpd::parseTrackInfo Feb 26 21:44:34 volumio-salon volumio[1198]: info: ControllerMpd::pushState Feb 26 21:44:34 volumio-salon volumio[1198]: info: CoreCommandRouter::servicePushState Feb 26 21:44:34 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:34 volumio-salon volumio[1198]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Feb 26 21:44:34 volumio-salon volumio[1198]: info: ------------------------------ 10ms Feb 26 21:44:34 volumio-salon volumio[1198]: info: sendMpdCommand status took 3 milliseconds Feb 26 21:44:34 volumio-salon volumio[1198]: info: sendMpdCommand playlistinfo took 3 milliseconds Feb 26 21:44:34 volumio-salon volumio[1198]: info: sendMpdCommand playlistinfo took 2 milliseconds Feb 26 21:44:34 volumio-salon volumio[1198]: verbose: ControllerMpd::parseState Feb 26 21:44:34 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 21:44:34 volumio-salon volumio[1198]: verbose: ControllerMpd::parseTrackInfo Feb 26 21:44:34 volumio-salon volumio[1198]: verbose: ControllerMpd::parseTrackInfo Feb 26 21:44:34 volumio-salon volumio[1198]: info: ControllerMpd::pushState Feb 26 21:44:34 volumio-salon volumio[1198]: info: CoreCommandRouter::servicePushState Feb 26 21:44:34 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:34 volumio-salon volumio[1198]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Feb 26 21:44:34 volumio-salon volumio[1198]: info: ControllerMpd::pushState Feb 26 21:44:34 volumio-salon volumio[1198]: info: CoreCommandRouter::servicePushState Feb 26 21:44:34 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:34 volumio-salon volumio[1198]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Feb 26 21:44:34 volumio-salon volumio[1198]: info: ------------------------------ 10ms Feb 26 21:44:34 volumio-salon volumio[1198]: info: ------------------------------ 8ms Feb 26 21:44:34 volumio-salon volumio[1198]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 26 21:44:34 volumio-salon volumio[1198]: verbose: ControllerMpd::parseTrackInfo Feb 26 21:44:34 volumio-salon volumio[1198]: info: ControllerMpd::pushState Feb 26 21:44:34 volumio-salon volumio[1198]: info: CoreCommandRouter::servicePushState Feb 26 21:44:34 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:34 volumio-salon volumio[1198]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Feb 26 21:44:34 volumio-salon volumio[1198]: info: ------------------------------ 7ms Feb 26 21:44:34 volumio-salon volumio[1198]: info: Feb 26 21:44:34 volumio-salon volumio[1198]: ---------------------------- MPD announces system playlist update Feb 26 21:44:34 volumio-salon volumio[1198]: info: Ignoring MPD Status Update Feb 26 21:44:34 volumio-salon volumio[1198]: info: Feb 26 21:44:34 volumio-salon volumio[1198]: ---------------------------- MPD announces state update: player Feb 26 21:44:34 volumio-salon volumio[1198]: info: ControllerMpd::getState Feb 26 21:44:34 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand status Feb 26 21:44:34 volumio-salon volumio[1198]: info: Feb 26 21:44:34 volumio-salon volumio[1198]: ---------------------------- MPD announces system playlist update Feb 26 21:44:34 volumio-salon volumio[1198]: info: Ignoring MPD Status Update Feb 26 21:44:34 volumio-salon volumio[1198]: info: Feb 26 21:44:34 volumio-salon volumio[1198]: ---------------------------- MPD announces state update: player Feb 26 21:44:34 volumio-salon volumio[1198]: info: ControllerMpd::getState Feb 26 21:44:34 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand status Feb 26 21:44:34 volumio-salon volumio[1198]: info: ------------------------------ 2ms Feb 26 21:44:34 volumio-salon volumio[1198]: info: sendMpdCommand status took 3 milliseconds Feb 26 21:44:34 volumio-salon volumio[1198]: info: ------------------------------ 2ms Feb 26 21:44:34 volumio-salon volumio[1198]: info: sendMpdCommand status took 2 milliseconds Feb 26 21:44:34 volumio-salon volumio[1198]: verbose: ControllerMpd::parseState Feb 26 21:44:34 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 21:44:34 volumio-salon volumio[1198]: verbose: ControllerMpd::parseState Feb 26 21:44:34 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 21:44:34 volumio-salon volumio[1198]: info: sendMpdCommand playlistinfo took 2 milliseconds Feb 26 21:44:34 volumio-salon volumio[1198]: info: sendMpdCommand playlistinfo took 2 milliseconds Feb 26 21:44:34 volumio-salon volumio[1198]: verbose: ControllerMpd::parseTrackInfo Feb 26 21:44:34 volumio-salon volumio[1198]: verbose: ControllerMpd::parseTrackInfo Feb 26 21:44:34 volumio-salon volumio[1198]: info: ControllerMpd::pushState Feb 26 21:44:34 volumio-salon volumio[1198]: info: CoreCommandRouter::servicePushState Feb 26 21:44:34 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:34 volumio-salon volumio[1198]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Feb 26 21:44:34 volumio-salon volumio[1198]: info: ControllerMpd::pushState Feb 26 21:44:34 volumio-salon volumio[1198]: info: CoreCommandRouter::servicePushState Feb 26 21:44:34 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:34 volumio-salon volumio[1198]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Feb 26 21:44:34 volumio-salon volumio[1198]: info: ------------------------------ 6ms Feb 26 21:44:34 volumio-salon volumio[1198]: info: ------------------------------ 5ms Feb 26 21:44:39 volumio-salon volumio[1198]: info: Feb 26 21:44:39 volumio-salon volumio[1198]: ---------------------------- MPD announces system playlist update Feb 26 21:44:39 volumio-salon volumio[1198]: info: Ignoring MPD Status Update Feb 26 21:44:39 volumio-salon volumio[1198]: info: Feb 26 21:44:39 volumio-salon volumio[1198]: ---------------------------- MPD announces state update: player Feb 26 21:44:39 volumio-salon volumio[1198]: info: ControllerMpd::getState Feb 26 21:44:39 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand status Feb 26 21:44:39 volumio-salon volumio[1198]: info: Feb 26 21:44:39 volumio-salon volumio[1198]: ---------------------------- MPD announces system playlist update Feb 26 21:44:39 volumio-salon volumio[1198]: info: Ignoring MPD Status Update Feb 26 21:44:39 volumio-salon volumio[1198]: info: Feb 26 21:44:39 volumio-salon volumio[1198]: ---------------------------- MPD announces state update: player Feb 26 21:44:39 volumio-salon volumio[1198]: info: ControllerMpd::getState Feb 26 21:44:39 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand status Feb 26 21:44:39 volumio-salon volumio[1198]: info: ------------------------------ 3ms Feb 26 21:44:39 volumio-salon volumio[1198]: info: sendMpdCommand status took 3 milliseconds Feb 26 21:44:39 volumio-salon volumio[1198]: verbose: ControllerMpd::parseState Feb 26 21:44:39 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 21:44:39 volumio-salon volumio[1198]: info: ------------------------------ 4ms Feb 26 21:44:39 volumio-salon volumio[1198]: info: sendMpdCommand status took 3 milliseconds Feb 26 21:44:39 volumio-salon volumio[1198]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 26 21:44:39 volumio-salon volumio[1198]: verbose: ControllerMpd::parseState Feb 26 21:44:39 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 21:44:39 volumio-salon volumio[1198]: verbose: ControllerMpd::parseTrackInfo Feb 26 21:44:39 volumio-salon volumio[1198]: info: ControllerMpd::pushState Feb 26 21:44:39 volumio-salon volumio[1198]: info: CoreCommandRouter::servicePushState Feb 26 21:44:39 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:39 volumio-salon volumio[1198]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Feb 26 21:44:39 volumio-salon volumio[1198]: info: ------------------------------ 7ms Feb 26 21:44:39 volumio-salon volumio[1198]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 26 21:44:39 volumio-salon volumio[1198]: verbose: ControllerMpd::parseTrackInfo Feb 26 21:44:39 volumio-salon volumio[1198]: info: ControllerMpd::pushState Feb 26 21:44:39 volumio-salon volumio[1198]: info: CoreCommandRouter::servicePushState Feb 26 21:44:39 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:39 volumio-salon volumio[1198]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Feb 26 21:44:39 volumio-salon volumio[1198]: info: ------------------------------ 6ms Feb 26 21:44:39 volumio-salon volumio[1198]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 26 21:44:39 volumio-salon volumio[1198]: info: CoreCommandRouter::Close All Modals sent Feb 26 21:44:51 volumio-salon volumio[1198]: info: [1772138691354] [RadioParadise] getMetadata started with url https://api.radioparadise.com/api/now_playing?chan=1 Feb 26 21:44:51 volumio-salon volumio[1198]: info: [1772138691893] [RadioParadise] received new metadata: {"time":154,"artist":"Johnny Nash","title":"I Can See Clearly Now","album":"I Can See Clearly Now","year":"1972","cover":"https://img.radioparadise.com/covers/l/10582.jpg","cover_med":"https://img.radioparadise.com/covers/m/10582.jpg","cover_small":"https://img.radioparadise.com/covers/s/10582.jpg"} Feb 26 21:44:51 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:51 volumio-salon volumio[1198]: info: CoreCommandRouter::servicePushState Feb 26 21:44:51 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:51 volumio-salon volumio[1198]: verbose: STATE SERVICE {"status":"play","service":"radio_paradise","type":"webradio","trackType":"flac","radioType":"","albumart":"https://img.radioparadise.com/covers/l/10582.jpg","uri":"https://stream.radioparadise.com/mellow-flacm","name":"I Can See Clearly Now","title":"I Can See Clearly Now","artist":"Johnny Nash","album":"I Can See Clearly Now","streaming":true,"disableUiControls":true,"duration":159,"seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Feb 26 21:44:51 volumio-salon volumio[1198]: verbose: CURRENT POSITION 0 Feb 26 21:44:51 volumio-salon volumio[1198]: info: CoreStateMachine::syncState stateService play Feb 26 21:44:51 volumio-salon volumio[1198]: info: CoreStateMachine::syncState currentStatus play Feb 26 21:44:51 volumio-salon volumio[1198]: info: Received an update from plugin. extracting info from payload Feb 26 21:44:51 volumio-salon volumio[1198]: info: CoreStateMachine::pushState Feb 26 21:44:51 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:51 volumio-salon volumio[1198]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 21:44:51 volumio-salon volumio[1198]: info: CoreCommandRouter::volumioPushState Feb 26 21:44:51 volumio-salon volumio[1198]: info: MRS: Pushing multiroomSync output update for this device Feb 26 21:44:51 volumio-salon volumio[1198]: info: MRS: Pushing multiroomSync output Feb 26 21:44:51 volumio-salon volumio[1198]: info: CoreStateMachine::pushState Feb 26 21:44:51 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:51 volumio-salon volumio[1198]: info: CoreCommandRouter::volumioPushState Feb 26 21:44:51 volumio-salon volumio[1198]: info: MRS: Pushing multiroomSync output update for this device Feb 26 21:44:51 volumio-salon volumio[1198]: info: MRS: Pushing multiroomSync output Feb 26 21:44:51 volumio-salon volumio5-onboarding[1482]: time=2026-02-26T21:44:51.905+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.37:51254 @ 0x22ce0c0" state=STATUS_PLAYING positionMs=0 volume=100 Feb 26 21:44:51 volumio-salon volumio5-onboarding[1482]: time=2026-02-26T21:44:51.906+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.37:51254 @ 0x22ce0c0" id=https://stream.radioparadise.com/mellow-flacm title="I Can See Clearly Now" Feb 26 21:44:51 volumio-salon volumio5-onboarding[1482]: time=2026-02-26T21:44:51.908+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.37:51254 @ 0x22ce0c0" state=STATUS_PLAYING positionMs=0 volume=100 Feb 26 21:44:51 volumio-salon volumio5-onboarding[1482]: time=2026-02-26T21:44:51.909+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.37:51254 @ 0x22ce0c0" id=https://stream.radioparadise.com/mellow-flacm title="I Can See Clearly Now" Feb 26 21:44:51 volumio-salon volumio[1198]: info: [1772138691911] [RadioParadise] setting new timer with duration of 159000 seconds. Feb 26 21:44:51 volumio-salon volumio[1198]: info: CoreCommandRouter::volumioGetQueue Feb 26 21:44:51 volumio-salon volumio[1198]: info: CoreStateMachine::getQueue Feb 26 21:44:51 volumio-salon volumio[1198]: info: CorePlayQueue::getQueue Feb 26 21:44:52 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:52 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 1 Feb 26 21:44:57 volumio-salon volumio[1198]: info: Feb 26 21:44:57 volumio-salon volumio[1198]: ---------------------------- MPD announces system playlist update Feb 26 21:44:57 volumio-salon volumio[1198]: info: Ignoring MPD Status Update Feb 26 21:44:57 volumio-salon volumio[1198]: info: Feb 26 21:44:57 volumio-salon volumio[1198]: ---------------------------- MPD announces state update: player Feb 26 21:44:57 volumio-salon volumio[1198]: info: ControllerMpd::getState Feb 26 21:44:57 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand status Feb 26 21:44:57 volumio-salon volumio[1198]: info: Feb 26 21:44:57 volumio-salon volumio[1198]: ---------------------------- MPD announces system playlist update Feb 26 21:44:57 volumio-salon volumio[1198]: info: Ignoring MPD Status Update Feb 26 21:44:57 volumio-salon volumio[1198]: info: Feb 26 21:44:57 volumio-salon volumio[1198]: ---------------------------- MPD announces state update: player Feb 26 21:44:57 volumio-salon volumio[1198]: info: ControllerMpd::getState Feb 26 21:44:57 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand status Feb 26 21:44:57 volumio-salon volumio[1198]: info: ------------------------------ 3ms Feb 26 21:44:57 volumio-salon volumio[1198]: info: sendMpdCommand status took 2 milliseconds Feb 26 21:44:57 volumio-salon volumio[1198]: verbose: ControllerMpd::parseState Feb 26 21:44:57 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 21:44:57 volumio-salon volumio[1198]: info: ------------------------------ 3ms Feb 26 21:44:57 volumio-salon volumio[1198]: info: sendMpdCommand status took 2 milliseconds Feb 26 21:44:57 volumio-salon volumio[1198]: info: sendMpdCommand playlistinfo took 2 milliseconds Feb 26 21:44:57 volumio-salon volumio[1198]: verbose: ControllerMpd::parseState Feb 26 21:44:57 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 21:44:57 volumio-salon volumio[1198]: verbose: ControllerMpd::parseTrackInfo Feb 26 21:44:57 volumio-salon volumio[1198]: info: ControllerMpd::pushState Feb 26 21:44:57 volumio-salon volumio[1198]: info: CoreCommandRouter::servicePushState Feb 26 21:44:57 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:57 volumio-salon volumio[1198]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Feb 26 21:44:57 volumio-salon volumio[1198]: info: ------------------------------ 7ms Feb 26 21:44:57 volumio-salon volumio[1198]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 26 21:44:57 volumio-salon volumio[1198]: verbose: ControllerMpd::parseTrackInfo Feb 26 21:44:57 volumio-salon volumio[1198]: info: ControllerMpd::pushState Feb 26 21:44:57 volumio-salon volumio[1198]: info: CoreCommandRouter::servicePushState Feb 26 21:44:57 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:44:57 volumio-salon volumio[1198]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Feb 26 21:44:57 volumio-salon volumio[1198]: info: ------------------------------ 6ms Feb 26 21:44:57 volumio-salon volumio[1198]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 26 21:44:57 volumio-salon volumio[1198]: info: CoreCommandRouter::Close All Modals sent Feb 26 21:45:09 volumio-salon volumio[1198]: info: CoreCommandRouter::volumioPause Feb 26 21:45:09 volumio-salon volumio[1198]: info: CoreStateMachine::pause Feb 26 21:45:09 volumio-salon volumio[1198]: info: CoreStateMachine::stPlaybackTimer Feb 26 21:45:09 volumio-salon volumio[1198]: info: CoreStateMachine::servicePause Feb 26 21:45:09 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:45:09 volumio-salon volumio[1198]: info: CoreCommandRouter::servicePause Feb 26 21:45:09 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand pause Feb 26 21:45:09 volumio-salon volumio[1198]: info: sendMpdCommand pause took 3 milliseconds Feb 26 21:45:09 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:45:09 volumio-salon volumio[1198]: info: CoreCommandRouter::servicePushState Feb 26 21:45:09 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:45:09 volumio-salon volumio[1198]: verbose: STATE SERVICE {"status":"pause","service":"radio_paradise","type":"webradio","trackType":"flac","radioType":"","albumart":"https://img.radioparadise.com/covers/l/10582.jpg","uri":"https://stream.radioparadise.com/mellow-flacm","name":"I Can See Clearly Now","title":"I Can See Clearly Now","artist":"Johnny Nash","album":"I Can See Clearly Now","streaming":true,"disableUiControls":true,"duration":159,"seek":17431,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Feb 26 21:45:09 volumio-salon volumio[1198]: verbose: CURRENT POSITION 0 Feb 26 21:45:09 volumio-salon volumio[1198]: info: CoreStateMachine::syncState stateService pause Feb 26 21:45:09 volumio-salon volumio[1198]: info: CoreStateMachine::syncState currentStatus pause Feb 26 21:45:09 volumio-salon volumio[1198]: info: CoreStateMachine::pushState Feb 26 21:45:09 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:45:09 volumio-salon volumio[1198]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 21:45:09 volumio-salon volumio[1198]: info: CoreCommandRouter::volumioPushState Feb 26 21:45:09 volumio-salon volumio[1198]: info: MRS: Pushing multiroomSync output update for this device Feb 26 21:45:09 volumio-salon volumio[1198]: info: MRS: Pushing multiroomSync output Feb 26 21:45:09 volumio-salon volumio[1198]: info: CoreStateMachine::stPlaybackTimer Feb 26 21:45:09 volumio-salon volumio5-onboarding[1482]: time=2026-02-26T21:45:09.352+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.37:51254 @ 0x22ce0c0" state=STATUS_PAUSED positionMs=17431 volume=100 Feb 26 21:45:09 volumio-salon volumio5-onboarding[1482]: time=2026-02-26T21:45:09.353+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.37:51254 @ 0x22ce0c0" id=https://stream.radioparadise.com/mellow-flacm title="I Can See Clearly Now" Feb 26 21:45:09 volumio-salon volumio[1198]: info: Feb 26 21:45:09 volumio-salon volumio[1198]: ---------------------------- MPD announces state update: player Feb 26 21:45:09 volumio-salon volumio[1198]: info: ControllerMpd::getState Feb 26 21:45:09 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand status Feb 26 21:45:09 volumio-salon volumio[1198]: info: Feb 26 21:45:09 volumio-salon volumio[1198]: ---------------------------- MPD announces state update: player Feb 26 21:45:09 volumio-salon volumio[1198]: info: ControllerMpd::getState Feb 26 21:45:09 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand status Feb 26 21:45:09 volumio-salon volumio[1198]: info: sendMpdCommand status took 9 milliseconds Feb 26 21:45:09 volumio-salon volumio[1198]: info: sendMpdCommand status took 8 milliseconds Feb 26 21:45:09 volumio-salon volumio[1198]: verbose: ControllerMpd::parseState Feb 26 21:45:09 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 21:45:09 volumio-salon volumio[1198]: verbose: ControllerMpd::parseState Feb 26 21:45:09 volumio-salon volumio[1198]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 21:45:09 volumio-salon volumio[1198]: info: sendMpdCommand playlistinfo took 2 milliseconds Feb 26 21:45:09 volumio-salon volumio[1198]: info: sendMpdCommand playlistinfo took 2 milliseconds Feb 26 21:45:09 volumio-salon volumio[1198]: verbose: ControllerMpd::parseTrackInfo Feb 26 21:45:09 volumio-salon volumio[1198]: verbose: ControllerMpd::parseTrackInfo Feb 26 21:45:09 volumio-salon volumio[1198]: info: ControllerMpd::pushState Feb 26 21:45:09 volumio-salon volumio[1198]: info: CoreCommandRouter::servicePushState Feb 26 21:45:09 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:45:09 volumio-salon volumio[1198]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Feb 26 21:45:09 volumio-salon volumio[1198]: info: ControllerMpd::pushState Feb 26 21:45:09 volumio-salon volumio[1198]: info: CoreCommandRouter::servicePushState Feb 26 21:45:09 volumio-salon volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 21:45:09 volumio-salon volumio[1198]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Feb 26 21:45:09 volumio-salon volumio[1198]: info: ------------------------------ 13ms Feb 26 21:45:09 volumio-salon volumio[1198]: info: ------------------------------ 12ms Feb 26 21:45:25 volumio-salon volumio[1198]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 26 21:45:25 volumio-salon volumio[1198]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Feb 26 21:45:25 volumio-salon volumio[1198]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 21:45:25 volumio-salon volumio[1198]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 26 21:45:25 volumio-salon volumio[1198]: info: Getting Alsa Cards List without I2S DAC Feb 26 21:45:25 volumio-salon volumio[1198]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Feb 26 21:45:25 volumio-salon volumio[1198]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 21:45:26 volumio-salon volumio[1198]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 26 21:45:26 volumio-salon volumio[1198]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 26 21:45:26 volumio-salon volumio[1198]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 26 21:45:26 volumio-salon volumio[1198]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 26 21:45:26 volumio-salon volumio[1198]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 26 21:45:26 volumio-salon volumio[1198]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 26 21:45:26 volumio-salon volumio[1198]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 26 21:45:26 volumio-salon volumio[1198]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Feb 26 21:45:26 volumio-salon volumio[1198]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Feb 26 21:45:36 volumio-salon volumio[1198]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 26 21:45:36 volumio-salon volumio[1198]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 26 21:45:36 volumio-salon volumio[1198]: info: Retrieving Cloud Streaming UI Feb 26 21:45:36 volumio-salon volumio[1198]: info: Getting Tidal Cloud Configuration Feb 26 21:45:36 volumio-salon volumio[1198]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 26 21:45:36 volumio-salon volumio[1198]: info: Getting Qobuz Cloud Configuration Feb 26 21:45:36 volumio-salon volumio[1198]: info: Asking plugin for UI Config Feb 26 21:45:36 volumio-salon volumio[1198]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 26 21:45:36 volumio-salon volumio[1198]: info: Getting Spotify Cloud Configuration Feb 26 21:45:36 volumio-salon volumio[1198]: info: Asking plugin for UI Config Feb 26 21:45:36 volumio-salon volumio[1198]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 26 21:45:36 volumio-salon volumio[1198]: info: Saving Spotify Acccount Feb 26 21:45:36 volumio-salon volumio[1198]: info: Got it Feb 26 21:45:36 volumio-salon volumio[1198]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Feb 26 21:45:36 volumio-salon volumio[1198]: info: Got Tidal Cloud Configuration Feb 26 21:45:36 volumio-salon volumio[1198]: info: Got it Feb 26 21:45:36 volumio-salon volumio[1198]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 26 21:45:36 volumio-salon volumio[1198]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Feb 26 21:45:36 volumio-salon volumio[1198]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Feb 26 21:45:36 volumio-salon volumio[1198]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Feb 26 21:45:36 volumio-salon volumio[1198]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Feb 26 21:45:36 volumio-salon volumio[1198]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 26 21:45:36 volumio-salon volumio[1198]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 26 21:45:36 volumio-salon volumio[1198]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 26 21:45:36 volumio-salon volumio[1198]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 26 21:45:36 volumio-salon volumio[1198]: info: CoreCommandRouter::volumioGetBrowseSources Feb 26 21:45:36 volumio-salon volumio[1198]: info: CoreCommandRouter::volumioGetBrowseSources Feb 26 21:45:36 volumio-salon volumio[1198]: info: CoreCommandRouter::volumioGetBrowseSources Feb 26 21:45:37 volumio-salon volumio[1198]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 26 21:45:37 volumio-salon volumio[1198]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Feb 26 21:45:39 volumio-salon volumio[1198]: info: Disabling MyMusic plugin upnp Feb 26 21:45:39 volumio-salon sudo[31131]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Feb 26 21:45:39 volumio-salon sudo[31131]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 21:45:39 volumio-salon systemd[1]: Stopping upmpdcli.service - UPnP Renderer front-end to MPD... Feb 26 21:45:40 volumio-salon volumio[1198]: info: Enabling MyMusic plugin upnp Feb 26 21:45:40 volumio-salon volumio[1198]: info: Enabling plugin upnp Feb 26 21:45:40 volumio-salon volumio[1198]: info: Loading plugin "upnp"... Feb 26 21:45:40 volumio-salon volumio[1198]: info: [1772138740544] Starting Upmpd Daemon Feb 26 21:45:40 volumio-salon volumio[1198]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 26 21:45:40 volumio-salon volumio[1198]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 26 21:45:40 volumio-salon volumio[1198]: Error: listen EADDRINUSE: address already in use :::6599 Feb 26 21:45:40 volumio-salon volumio[1198]: at Server.setupListenHandle [as _listen2] (node:net:1872:16) Feb 26 21:45:40 volumio-salon volumio[1198]: at listenInCluster (node:net:1920:12) Feb 26 21:45:40 volumio-salon volumio[1198]: at Server.listen (node:net:2008:7) Feb 26 21:45:40 volumio-salon volumio[1198]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Feb 26 21:45:40 volumio-salon volumio[1198]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Feb 26 21:45:40 volumio-salon volumio[1198]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Feb 26 21:45:40 volumio-salon volumio[1198]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Feb 26 21:45:40 volumio-salon volumio[1198]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) { Feb 26 21:45:40 volumio-salon volumio[1198]: code: 'EADDRINUSE', Feb 26 21:45:40 volumio-salon volumio[1198]: errno: -98, Feb 26 21:45:40 volumio-salon volumio[1198]: syscall: 'listen', Feb 26 21:45:40 volumio-salon volumio[1198]: address: '::', Feb 26 21:45:40 volumio-salon volumio[1198]: port: 6599 Feb 26 21:45:40 volumio-salon volumio[1198]: } Feb 26 21:45:40 volumio-salon volumio[1198]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 26 21:45:41 volumio-salon sudo[31161]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-26 21:44' Feb 26 21:45:41 volumio-salon sudo[31161]: 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="a78d359cf1dc63ac74e9d151015afd30d31a709a" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Feb 5 14:07:07 UTC 2026" VOLUMIO_VERSION="4.096" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5e37060f9823263a753eb5e84030104f"