Aug 31 22:10:00 volumio volumio[1250]: info: Aug 31 22:10:00 volumio volumio[1250]: ---------------------------- MPD announces state update: player Aug 31 22:10:00 volumio volumio[1250]: info: sendMpdCommand stop took 53 milliseconds Aug 31 22:10:00 volumio volumio[1250]: info: ControllerMpd::getState Aug 31 22:10:00 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand status Aug 31 22:10:00 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand clear Aug 31 22:10:00 volumio volumio[1250]: info: Aug 31 22:10:00 volumio volumio[1250]: ---------------------------- MPD announces state update: player Aug 31 22:10:00 volumio volumio[1250]: info: ControllerMpd::getState Aug 31 22:10:00 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand status Aug 31 22:10:00 volumio volumio[1250]: info: Aug 31 22:10:00 volumio volumio[1250]: ---------------------------- MPD announces state update: player Aug 31 22:10:00 volumio volumio[1250]: info: ControllerMpd::getState Aug 31 22:10:00 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand status Aug 31 22:10:00 volumio volumio[1250]: info: Aug 31 22:10:00 volumio volumio[1250]: ---------------------------- MPD announces system playlist update Aug 31 22:10:00 volumio volumio[1250]: info: Ignoring MPD Status Update Aug 31 22:10:00 volumio volumio[1250]: info: sendMpdCommand status took 26 milliseconds Aug 31 22:10:00 volumio volumio[1250]: info: sendMpdCommand clear took 26 milliseconds Aug 31 22:10:00 volumio volumio[1250]: info: sendMpdCommand status took 4 milliseconds Aug 31 22:10:00 volumio volumio[1250]: info: sendMpdCommand status took 56 milliseconds Aug 31 22:10:00 volumio volumio[1250]: verbose: ControllerMpd::parseState Aug 31 22:10:00 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 22:10:00 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand load "http://streams.radiobob.de/blues/mp3-192/tunein/" Aug 31 22:10:00 volumio volumio[1250]: verbose: ControllerMpd::parseState Aug 31 22:10:00 volumio volumio[1250]: verbose: ControllerMpd::parseState Aug 31 22:10:00 volumio volumio[1250]: info: ControllerMpd::pushState Aug 31 22:10:00 volumio volumio[1250]: info: CoreCommandRouter::servicePushState Aug 31 22:10:00 volumio volumio[1250]: info: CoreStateMachine::pushState Aug 31 22:10:00 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:10:00 volumio volumio[1250]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 22:10:00 volumio volumio[1250]: info: CoreCommandRouter::volumioPushState Aug 31 22:10:00 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:10:00 volumio volumio[1250]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Aug 31 22:10:00 volumio volumio[1250]: info: ControllerMpd::pushState Aug 31 22:10:00 volumio volumio[1250]: info: CoreCommandRouter::servicePushState Aug 31 22:10:00 volumio volumio[1250]: info: CoreStateMachine::pushState Aug 31 22:10:00 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:10:00 volumio volumio[1250]: info: CoreCommandRouter::volumioPushState Aug 31 22:10:00 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:10:00 volumio volumio[1250]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Aug 31 22:10:00 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:00.295+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" state=STATUS_STOPPED positionMs=50 volume=100 Aug 31 22:10:00 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:00.295+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" id=http://streams.radiobob.de/blues/mp3-192/tunein/ title="RADIO BOB! Blues" Aug 31 22:10:00 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:00.296+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" state=STATUS_STOPPED positionMs=50 volume=100 Aug 31 22:10:00 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:00.296+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" id=http://streams.radiobob.de/blues/mp3-192/tunein/ title="RADIO BOB! Blues" Aug 31 22:10:00 volumio volumio[1250]: info: ------------------------------ 353ms Aug 31 22:10:00 volumio volumio[1250]: info: ------------------------------ 329ms Aug 31 22:10:00 volumio volumio[1250]: info: Aug 31 22:10:00 volumio volumio[1250]: ---------------------------- MPD announces system playlist update Aug 31 22:10:00 volumio volumio[1250]: info: Ignoring MPD Status Update Aug 31 22:10:00 volumio volumio[1250]: info: Aug 31 22:10:00 volumio volumio[1250]: ---------------------------- MPD announces system playlist update Aug 31 22:10:00 volumio volumio[1250]: info: Ignoring MPD Status Update Aug 31 22:10:00 volumio volumio[1250]: error: updateQueue error: null Aug 31 22:10:00 volumio volumio[1250]: info: ------------------------------ 331ms Aug 31 22:10:00 volumio volumio[1250]: info: sendMpdCommand playlistinfo took 275 milliseconds Aug 31 22:10:00 volumio volumio[1250]: verbose: ControllerMpd::parseTrackInfo Aug 31 22:10:00 volumio volumio[1250]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Aug 31 22:10:00 volumio volumio[1250]: info: ------------------------------ 393ms Aug 31 22:10:00 volumio volumio[1250]: error: updateQueue error: null Aug 31 22:10:00 volumio volumio[1250]: error: updateQueue error: null Aug 31 22:10:00 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand add "http://streams.radiobob.de/blues/mp3-192/tunein/" Aug 31 22:10:00 volumio volumio[1250]: info: ------------------------------ 108ms Aug 31 22:10:00 volumio volumio[1250]: info: ------------------------------ 108ms Aug 31 22:10:00 volumio volumio[1250]: info: Aug 31 22:10:00 volumio volumio[1250]: ---------------------------- MPD announces system playlist update Aug 31 22:10:00 volumio volumio[1250]: info: Ignoring MPD Status Update Aug 31 22:10:00 volumio volumio[1250]: info: sendMpdCommand add "http://streams.radiobob.de/blues/mp3-192/tunein/" took 2 milliseconds Aug 31 22:10:00 volumio volumio[1250]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 31 22:10:00 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand play Aug 31 22:10:00 volumio volumio[1250]: info: Aug 31 22:10:00 volumio volumio[1250]: ---------------------------- MPD announces system playlist update Aug 31 22:10:00 volumio volumio[1250]: info: Ignoring MPD Status Update Aug 31 22:10:00 volumio volumio[1250]: info: Aug 31 22:10:00 volumio volumio[1250]: ---------------------------- MPD announces system playlist update Aug 31 22:10:00 volumio volumio[1250]: info: Ignoring MPD Status Update Aug 31 22:10:00 volumio volumio[1250]: info: ------------------------------ 34ms Aug 31 22:10:00 volumio volumio[1250]: info: sendMpdCommand play took 33 milliseconds Aug 31 22:10:00 volumio volumio[1250]: info: ------------------------------ 3ms Aug 31 22:10:00 volumio volumio[1250]: info: ------------------------------ 3ms Aug 31 22:10:00 volumio volumio[1250]: info: Preload queue cleared Aug 31 22:10:00 volumio volumio[1250]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 31 22:10:00 volumio volumio[1250]: info: CoreStateMachine::ClearQueue Aug 31 22:10:00 volumio volumio[1250]: info: CoreStateMachine::stop Aug 31 22:10:00 volumio volumio[1250]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 22:10:00 volumio volumio[1250]: info: CorePlayQueue::clearPlayQueue Aug 31 22:10:00 volumio volumio[1250]: info: CorePlayQueue::saveQueue Aug 31 22:10:00 volumio volumio[1250]: info: CoreCommandRouter::volumioPushQueue Aug 31 22:10:00 volumio kernel: bcm2835-i2s fe203000.i2s: I2S SYNC error! Aug 31 22:10:00 volumio volumio[1250]: info: CoreStateMachine::addQueueItems Aug 31 22:10:00 volumio volumio[1250]: info: CorePlayQueue::addQueueItems Aug 31 22:10:00 volumio volumio[1250]: info: Preload queue cleared Aug 31 22:10:00 volumio volumio[1250]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s309660 Aug 31 22:10:00 volumio volumio[1250]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Aug 31 22:10:00 volumio volumio[1250]: info: CoreCommandRouter::volumioPushQueue Aug 31 22:10:00 volumio volumio[1250]: info: CorePlayQueue::saveQueue Aug 31 22:10:00 volumio volumio[1250]: info: CoreStateMachine::updateTrackBlock Aug 31 22:10:00 volumio volumio[1250]: info: CorePlayQueue::getTrackBlock Aug 31 22:10:00 volumio volumio[1250]: info: CoreCommandRouter::volumioPlay Aug 31 22:10:00 volumio volumio[1250]: info: CoreStateMachine::play index 0 Aug 31 22:10:00 volumio volumio[1250]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 22:10:00 volumio volumio[1250]: info: CoreStateMachine::stop Aug 31 22:10:00 volumio volumio[1250]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 22:10:00 volumio volumio[1250]: info: CoreStateMachine::play index undefined Aug 31 22:10:00 volumio volumio[1250]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 22:10:00 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:10:00 volumio volumio[1250]: info: CoreStateMachine::startPlaybackTimer Aug 31 22:10:00 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:10:00 volumio volumio[1250]: info: [1788207000813] ControllerWebradio::clearAddPlayTrack Aug 31 22:10:00 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand stop Aug 31 22:10:00 volumio volumio[1250]: info: Aug 31 22:10:00 volumio volumio[1250]: ---------------------------- MPD announces state update: player Aug 31 22:10:00 volumio volumio[1250]: info: ControllerMpd::getState Aug 31 22:10:00 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand status Aug 31 22:10:00 volumio volumio[1250]: info: Aug 31 22:10:00 volumio volumio[1250]: ---------------------------- MPD announces state update: player Aug 31 22:10:00 volumio volumio[1250]: info: ControllerMpd::getState Aug 31 22:10:00 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand status Aug 31 22:10:00 volumio volumio[1250]: info: Aug 31 22:10:00 volumio volumio[1250]: ---------------------------- MPD announces state update: player Aug 31 22:10:00 volumio volumio[1250]: info: Aug 31 22:10:00 volumio volumio[1250]: ---------------------------- MPD announces system playlist update Aug 31 22:10:00 volumio volumio[1250]: info: Ignoring MPD Status Update Aug 31 22:10:00 volumio volumio[1250]: info: Aug 31 22:10:00 volumio volumio[1250]: ---------------------------- MPD announces state update: player Aug 31 22:10:00 volumio volumio[1250]: info: Aug 31 22:10:00 volumio volumio[1250]: ---------------------------- MPD announces state update: player Aug 31 22:10:00 volumio volumio[1250]: info: ControllerMpd::getState Aug 31 22:10:00 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand status Aug 31 22:10:00 volumio volumio[1250]: info: sendMpdCommand stop took 25 milliseconds Aug 31 22:10:00 volumio volumio[1250]: info: ControllerMpd::getState Aug 31 22:10:00 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand status Aug 31 22:10:00 volumio volumio[1250]: info: sendMpdCommand status took 3 milliseconds Aug 31 22:10:00 volumio volumio[1250]: info: ControllerMpd::getState Aug 31 22:10:00 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand status Aug 31 22:10:00 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand clear Aug 31 22:10:00 volumio volumio[1250]: verbose: ControllerMpd::parseState Aug 31 22:10:00 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 22:10:00 volumio volumio[1250]: info: Aug 31 22:10:00 volumio volumio[1250]: ---------------------------- MPD announces system playlist update Aug 31 22:10:00 volumio volumio[1250]: info: Ignoring MPD Status Update Aug 31 22:10:00 volumio volumio[1250]: info: Aug 31 22:10:00 volumio volumio[1250]: ---------------------------- MPD announces state update: player Aug 31 22:10:00 volumio volumio[1250]: info: ControllerMpd::getState Aug 31 22:10:00 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand status Aug 31 22:10:00 volumio volumio[1250]: info: Aug 31 22:10:00 volumio volumio[1250]: ---------------------------- MPD announces system playlist update Aug 31 22:10:00 volumio volumio[1250]: info: Ignoring MPD Status Update Aug 31 22:10:00 volumio volumio[1250]: info: Aug 31 22:10:00 volumio volumio[1250]: ---------------------------- MPD announces state update: player Aug 31 22:10:00 volumio volumio[1250]: info: ControllerMpd::getState Aug 31 22:10:00 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand status Aug 31 22:10:00 volumio volumio[1250]: info: Aug 31 22:10:00 volumio volumio[1250]: ---------------------------- MPD announces system playlist update Aug 31 22:10:00 volumio volumio[1250]: info: Ignoring MPD Status Update Aug 31 22:10:00 volumio volumio[1250]: error: updateQueue error: null Aug 31 22:10:00 volumio volumio[1250]: error: updateQueue error: null Aug 31 22:10:00 volumio volumio[1250]: info: sendMpdCommand status took 128 milliseconds Aug 31 22:10:00 volumio volumio[1250]: info: sendMpdCommand status took 127 milliseconds Aug 31 22:10:00 volumio volumio[1250]: info: ------------------------------ 128ms Aug 31 22:10:00 volumio volumio[1250]: info: sendMpdCommand status took 127 milliseconds Aug 31 22:10:01 volumio volumio[1250]: info: sendMpdCommand status took 154 milliseconds Aug 31 22:10:01 volumio volumio[1250]: info: sendMpdCommand clear took 153 milliseconds Aug 31 22:10:01 volumio volumio[1250]: info: sendMpdCommand playlistinfo took 128 milliseconds Aug 31 22:10:01 volumio volumio[1250]: info: ------------------------------ 64ms Aug 31 22:10:01 volumio volumio[1250]: info: sendMpdCommand status took 64 milliseconds Aug 31 22:10:01 volumio volumio[1250]: info: ------------------------------ 30ms Aug 31 22:10:01 volumio volumio[1250]: info: sendMpdCommand status took 29 milliseconds Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::parseState Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::parseState Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::parseState Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::parseState Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand load "http://streams.radiobob.de/blues/mp3-192/tunein/" Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::parseTrackInfo Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::parseState Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::parseState Aug 31 22:10:01 volumio volumio[1250]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Aug 31 22:10:01 volumio volumio[1250]: info: ControllerMpd::pushState Aug 31 22:10:01 volumio volumio[1250]: info: CoreCommandRouter::servicePushState Aug 31 22:10:01 volumio volumio[1250]: info: CoreStateMachine::pushState Aug 31 22:10:01 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:10:01 volumio volumio[1250]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 22:10:01 volumio volumio[1250]: info: CoreCommandRouter::volumioPushState Aug 31 22:10:01 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:10:01 volumio volumio[1250]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Aug 31 22:10:01 volumio volumio[1250]: info: ControllerMpd::pushState Aug 31 22:10:01 volumio volumio[1250]: info: CoreCommandRouter::servicePushState Aug 31 22:10:01 volumio volumio[1250]: info: CoreStateMachine::pushState Aug 31 22:10:01 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:10:01 volumio volumio[1250]: info: CoreCommandRouter::volumioPushState Aug 31 22:10:01 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:10:01 volumio volumio[1250]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Aug 31 22:10:01 volumio volumio[1250]: info: ------------------------------ 299ms Aug 31 22:10:01 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:01.166+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" state=STATUS_STOPPED positionMs=1 volume=100 Aug 31 22:10:01 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:01.166+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" id=http://streams.radiobob.de/blues/mp3-192/tunein/ title="RADIO BOB! Blues" Aug 31 22:10:01 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:01.167+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" state=STATUS_STOPPED positionMs=1 volume=100 Aug 31 22:10:01 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:01.167+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" id=http://streams.radiobob.de/blues/mp3-192/tunein/ title="RADIO BOB! Blues" Aug 31 22:10:01 volumio volumio[1250]: info: ------------------------------ 320ms Aug 31 22:10:01 volumio volumio[1250]: info: ------------------------------ 286ms Aug 31 22:10:01 volumio volumio[1250]: info: Aug 31 22:10:01 volumio volumio[1250]: ---------------------------- MPD announces system playlist update Aug 31 22:10:01 volumio volumio[1250]: info: Ignoring MPD Status Update Aug 31 22:10:01 volumio volumio[1250]: info: Aug 31 22:10:01 volumio volumio[1250]: ---------------------------- MPD announces system playlist update Aug 31 22:10:01 volumio volumio[1250]: info: Ignoring MPD Status Update Aug 31 22:10:01 volumio volumio[1250]: error: updateQueue error: null Aug 31 22:10:01 volumio volumio[1250]: error: updateQueue error: null Aug 31 22:10:01 volumio volumio[1250]: error: updateQueue error: null Aug 31 22:10:01 volumio volumio[1250]: info: ------------------------------ 315ms Aug 31 22:10:01 volumio volumio[1250]: info: sendMpdCommand playlistinfo took 286 milliseconds Aug 31 22:10:01 volumio volumio[1250]: info: sendMpdCommand playlistinfo took 286 milliseconds Aug 31 22:10:01 volumio volumio[1250]: info: sendMpdCommand playlistinfo took 286 milliseconds Aug 31 22:10:01 volumio volumio[1250]: info: sendMpdCommand playlistinfo took 286 milliseconds Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand add "http://streams.radiobob.de/blues/mp3-192/tunein/" Aug 31 22:10:01 volumio volumio[1250]: info: ------------------------------ 31ms Aug 31 22:10:01 volumio volumio[1250]: info: ------------------------------ 30ms Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::parseTrackInfo Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::parseTrackInfo Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::parseTrackInfo Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::parseTrackInfo Aug 31 22:10:01 volumio volumio[1250]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Aug 31 22:10:01 volumio volumio[1250]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Aug 31 22:10:01 volumio volumio[1250]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Aug 31 22:10:01 volumio volumio[1250]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Aug 31 22:10:01 volumio volumio[1250]: info: ------------------------------ 471ms Aug 31 22:10:01 volumio volumio[1250]: info: ------------------------------ 470ms Aug 31 22:10:01 volumio volumio[1250]: info: ------------------------------ 471ms Aug 31 22:10:01 volumio volumio[1250]: info: ------------------------------ 471ms Aug 31 22:10:01 volumio volumio[1250]: info: Aug 31 22:10:01 volumio volumio[1250]: ---------------------------- MPD announces system playlist update Aug 31 22:10:01 volumio volumio[1250]: info: Ignoring MPD Status Update Aug 31 22:10:01 volumio volumio[1250]: info: Aug 31 22:10:01 volumio volumio[1250]: ---------------------------- MPD announces system playlist update Aug 31 22:10:01 volumio volumio[1250]: info: Ignoring MPD Status Update Aug 31 22:10:01 volumio volumio[1250]: info: Aug 31 22:10:01 volumio volumio[1250]: ---------------------------- MPD announces system playlist update Aug 31 22:10:01 volumio volumio[1250]: info: Ignoring MPD Status Update Aug 31 22:10:01 volumio volumio[1250]: info: sendMpdCommand add "http://streams.radiobob.de/blues/mp3-192/tunein/" took 139 milliseconds Aug 31 22:10:01 volumio volumio[1250]: info: ------------------------------ 73ms Aug 31 22:10:01 volumio volumio[1250]: info: ------------------------------ 72ms Aug 31 22:10:01 volumio volumio[1250]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand play Aug 31 22:10:01 volumio volumio[1250]: info: ------------------------------ 74ms Aug 31 22:10:01 volumio volumio[1250]: info: sendMpdCommand play took 1 milliseconds Aug 31 22:10:01 volumio volumio[1250]: info: Aug 31 22:10:01 volumio volumio[1250]: ---------------------------- MPD announces state update: player Aug 31 22:10:01 volumio volumio[1250]: info: ControllerMpd::getState Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand status Aug 31 22:10:01 volumio volumio[1250]: info: Aug 31 22:10:01 volumio volumio[1250]: ---------------------------- MPD announces state update: player Aug 31 22:10:01 volumio volumio[1250]: info: ControllerMpd::getState Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand status Aug 31 22:10:01 volumio volumio[1250]: info: Aug 31 22:10:01 volumio volumio[1250]: ---------------------------- MPD announces state update: player Aug 31 22:10:01 volumio volumio[1250]: info: Aug 31 22:10:01 volumio volumio[1250]: ---------------------------- MPD announces state update: player Aug 31 22:10:01 volumio volumio[1250]: info: ControllerMpd::getState Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand status Aug 31 22:10:01 volumio volumio[1250]: info: sendMpdCommand status took 3 milliseconds Aug 31 22:10:01 volumio volumio[1250]: info: ControllerMpd::getState Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand status Aug 31 22:10:01 volumio volumio[1250]: info: sendMpdCommand status took 1 milliseconds Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::parseState Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::parseState Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 22:10:01 volumio volumio[1250]: info: Aug 31 22:10:01 volumio volumio[1250]: ---------------------------- MPD announces state update: player Aug 31 22:10:01 volumio volumio[1250]: info: ControllerMpd::getState Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand status Aug 31 22:10:01 volumio volumio[1250]: info: Aug 31 22:10:01 volumio volumio[1250]: ---------------------------- MPD announces state update: player Aug 31 22:10:01 volumio volumio[1250]: info: ControllerMpd::getState Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand status Aug 31 22:10:01 volumio volumio[1250]: info: Aug 31 22:10:01 volumio volumio[1250]: ---------------------------- MPD announces system playlist update Aug 31 22:10:01 volumio volumio[1250]: info: Ignoring MPD Status Update Aug 31 22:10:01 volumio volumio[1250]: info: Aug 31 22:10:01 volumio volumio[1250]: ---------------------------- MPD announces state update: player Aug 31 22:10:01 volumio volumio[1250]: info: sendMpdCommand status took 29 milliseconds Aug 31 22:10:01 volumio volumio[1250]: info: sendMpdCommand status took 29 milliseconds Aug 31 22:10:01 volumio volumio[1250]: info: sendMpdCommand playlistinfo took 28 milliseconds Aug 31 22:10:01 volumio volumio[1250]: info: sendMpdCommand playlistinfo took 15 milliseconds Aug 31 22:10:01 volumio volumio[1250]: info: ControllerMpd::getState Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand status Aug 31 22:10:01 volumio volumio[1250]: info: sendMpdCommand status took 4 milliseconds Aug 31 22:10:01 volumio volumio[1250]: info: sendMpdCommand status took 3 milliseconds Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::parseState Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::parseState Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::parseTrackInfo Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::parseTrackInfo Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::parseState Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::parseState Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 22:10:01 volumio volumio[1250]: info: ControllerMpd::pushState Aug 31 22:10:01 volumio volumio[1250]: info: CoreCommandRouter::servicePushState Aug 31 22:10:01 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:10:01 volumio volumio[1250]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"","artist":null,"album":null,"uri":"http://streams.radiobob.de/blues/mp3-192/tunein/","trackType":""} Aug 31 22:10:01 volumio volumio[1250]: verbose: CURRENT POSITION 0 Aug 31 22:10:01 volumio volumio[1250]: info: CoreStateMachine::syncState stateService play Aug 31 22:10:01 volumio volumio[1250]: info: CoreStateMachine::syncState currentStatus stop Aug 31 22:10:01 volumio volumio[1250]: info: ControllerMpd::pushState Aug 31 22:10:01 volumio volumio[1250]: info: CoreCommandRouter::servicePushState Aug 31 22:10:01 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:10:01 volumio volumio[1250]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"","artist":null,"album":null,"uri":"http://streams.radiobob.de/blues/mp3-192/tunein/","trackType":""} Aug 31 22:10:01 volumio volumio[1250]: verbose: CURRENT POSITION 0 Aug 31 22:10:01 volumio volumio[1250]: info: CoreStateMachine::syncState stateService play Aug 31 22:10:01 volumio volumio[1250]: info: CoreStateMachine::syncState currentStatus play Aug 31 22:10:01 volumio volumio[1250]: info: Received an update from plugin. extracting info from payload Aug 31 22:10:01 volumio volumio[1250]: info: CoreStateMachine::pushState Aug 31 22:10:01 volumio volumio[1250]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 22:10:01 volumio volumio[1250]: info: CoreCommandRouter::volumioPushState Aug 31 22:10:01 volumio volumio[1250]: info: CoreStateMachine::pushState Aug 31 22:10:01 volumio volumio[1250]: info: CoreCommandRouter::volumioPushState Aug 31 22:10:01 volumio volumio[1250]: info: ------------------------------ 224ms Aug 31 22:10:01 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:01.726+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" state=STATUS_PLAYING positionMs=0 volume=100 Aug 31 22:10:01 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:01.726+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" id=http://streams.radiobob.de/blues/mp3-192/tunein/ title= Aug 31 22:10:01 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:01.783+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" state=STATUS_PLAYING positionMs=0 volume=100 Aug 31 22:10:01 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:01.783+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" id=http://streams.radiobob.de/blues/mp3-192/tunein/ title= Aug 31 22:10:01 volumio volumio[1250]: info: ------------------------------ 345ms Aug 31 22:10:01 volumio volumio[1250]: info: Aug 31 22:10:01 volumio volumio[1250]: ---------------------------- MPD announces system playlist update Aug 31 22:10:01 volumio volumio[1250]: info: Ignoring MPD Status Update Aug 31 22:10:01 volumio volumio[1250]: info: Aug 31 22:10:01 volumio volumio[1250]: ---------------------------- MPD announces state update: player Aug 31 22:10:01 volumio volumio[1250]: info: ControllerMpd::getState Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand status Aug 31 22:10:01 volumio volumio[1250]: info: Aug 31 22:10:01 volumio volumio[1250]: ---------------------------- MPD announces system playlist update Aug 31 22:10:01 volumio volumio[1250]: info: Ignoring MPD Status Update Aug 31 22:10:01 volumio volumio[1250]: info: Aug 31 22:10:01 volumio volumio[1250]: ---------------------------- MPD announces state update: player Aug 31 22:10:01 volumio volumio[1250]: info: ControllerMpd::getState Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand status Aug 31 22:10:01 volumio volumio[1250]: info: ------------------------------ 397ms Aug 31 22:10:01 volumio volumio[1250]: info: sendMpdCommand status took 397 milliseconds Aug 31 22:10:01 volumio volumio[1250]: info: sendMpdCommand playlistinfo took 396 milliseconds Aug 31 22:10:01 volumio volumio[1250]: info: sendMpdCommand playlistinfo took 396 milliseconds Aug 31 22:10:01 volumio volumio[1250]: info: sendMpdCommand playlistinfo took 364 milliseconds Aug 31 22:10:01 volumio volumio[1250]: info: sendMpdCommand playlistinfo took 364 milliseconds Aug 31 22:10:01 volumio volumio[1250]: info: ------------------------------ 82ms Aug 31 22:10:01 volumio volumio[1250]: info: sendMpdCommand status took 32 milliseconds Aug 31 22:10:01 volumio volumio[1250]: info: ------------------------------ 25ms Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::parseState Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::parseTrackInfo Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::parseTrackInfo Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::parseTrackInfo Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::parseTrackInfo Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::parseState Aug 31 22:10:01 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 22:10:01 volumio volumio[1250]: info: ControllerMpd::pushState Aug 31 22:10:01 volumio volumio[1250]: info: CoreCommandRouter::servicePushState Aug 31 22:10:01 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:10:01 volumio volumio[1250]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"RADIO BOB - Blues","artist":"RADIO BOB - Blues","album":null,"uri":"http://streams.radiobob.de/blues/mp3-192/tunein/","trackType":""} Aug 31 22:10:01 volumio volumio[1250]: verbose: CURRENT POSITION 0 Aug 31 22:10:01 volumio volumio[1250]: info: CoreStateMachine::syncState stateService play Aug 31 22:10:01 volumio volumio[1250]: info: CoreStateMachine::syncState currentStatus play Aug 31 22:10:01 volumio volumio[1250]: info: Received an update from plugin. extracting info from payload Aug 31 22:10:01 volumio volumio[1250]: info: CoreStateMachine::pushState Aug 31 22:10:01 volumio volumio[1250]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 22:10:01 volumio volumio[1250]: info: CoreCommandRouter::volumioPushState Aug 31 22:10:02 volumio volumio[1250]: info: CoreStateMachine::pushState Aug 31 22:10:02 volumio volumio[1250]: info: CoreCommandRouter::volumioPushState Aug 31 22:10:02 volumio volumio[1250]: info: ControllerMpd::pushState Aug 31 22:10:02 volumio volumio[1250]: info: CoreCommandRouter::servicePushState Aug 31 22:10:02 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:10:02 volumio volumio[1250]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"RADIO BOB - Blues","artist":"RADIO BOB - Blues","album":null,"uri":"http://streams.radiobob.de/blues/mp3-192/tunein/","trackType":""} Aug 31 22:10:02 volumio volumio[1250]: verbose: CURRENT POSITION 0 Aug 31 22:10:02 volumio volumio[1250]: info: CoreStateMachine::syncState stateService play Aug 31 22:10:02 volumio volumio[1250]: info: CoreStateMachine::syncState currentStatus play Aug 31 22:10:02 volumio volumio[1250]: info: Received an update from plugin. extracting info from payload Aug 31 22:10:02 volumio volumio[1250]: info: CoreStateMachine::pushState Aug 31 22:10:02 volumio volumio[1250]: info: CoreCommandRouter::volumioPushState Aug 31 22:10:02 volumio volumio[1250]: info: CoreStateMachine::pushState Aug 31 22:10:02 volumio volumio[1250]: info: CoreCommandRouter::volumioPushState Aug 31 22:10:02 volumio volumio[1250]: info: ControllerMpd::pushState Aug 31 22:10:02 volumio volumio[1250]: info: CoreCommandRouter::servicePushState Aug 31 22:10:02 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:10:02 volumio volumio[1250]: verbose: STATE SERVICE {"status":"play","position":0,"seek":884,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"RADIO BOB - Blues","artist":"RADIO BOB - Blues","album":null,"uri":"http://streams.radiobob.de/blues/mp3-192/tunein/","trackType":""} Aug 31 22:10:02 volumio volumio[1250]: verbose: CURRENT POSITION 0 Aug 31 22:10:02 volumio volumio[1250]: info: CoreStateMachine::syncState stateService play Aug 31 22:10:02 volumio volumio[1250]: info: CoreStateMachine::syncState currentStatus play Aug 31 22:10:02 volumio volumio[1250]: info: Received an update from plugin. extracting info from payload Aug 31 22:10:02 volumio volumio[1250]: info: CoreStateMachine::pushState Aug 31 22:10:02 volumio volumio[1250]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 22:10:02 volumio volumio[1250]: info: CoreCommandRouter::volumioPushState Aug 31 22:10:02 volumio volumio[1250]: info: CoreStateMachine::pushState Aug 31 22:10:02 volumio volumio[1250]: info: CoreCommandRouter::volumioPushState Aug 31 22:10:02 volumio volumio[1250]: info: ControllerMpd::pushState Aug 31 22:10:02 volumio volumio[1250]: info: CoreCommandRouter::servicePushState Aug 31 22:10:02 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:10:02 volumio volumio[1250]: verbose: STATE SERVICE {"status":"play","position":0,"seek":884,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"RADIO BOB - Blues","artist":"RADIO BOB - Blues","album":null,"uri":"http://streams.radiobob.de/blues/mp3-192/tunein/","trackType":""} Aug 31 22:10:02 volumio volumio[1250]: verbose: CURRENT POSITION 0 Aug 31 22:10:02 volumio volumio[1250]: info: CoreStateMachine::syncState stateService play Aug 31 22:10:02 volumio volumio[1250]: info: CoreStateMachine::syncState currentStatus play Aug 31 22:10:02 volumio volumio[1250]: info: Received an update from plugin. extracting info from payload Aug 31 22:10:02 volumio volumio[1250]: info: CoreStateMachine::pushState Aug 31 22:10:02 volumio volumio[1250]: info: CoreCommandRouter::volumioPushState Aug 31 22:10:02 volumio volumio[1250]: info: CoreStateMachine::pushState Aug 31 22:10:02 volumio volumio[1250]: info: CoreCommandRouter::volumioPushState Aug 31 22:10:02 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:02.342+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" state=STATUS_PLAYING positionMs=328 volume=100 Aug 31 22:10:02 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:02.342+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" id=http://streams.radiobob.de/blues/mp3-192/tunein/ title="RADIO BOB - Blues" Aug 31 22:10:02 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:02.370+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" state=STATUS_PLAYING positionMs=328 volume=100 Aug 31 22:10:02 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:02.370+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" id=http://streams.radiobob.de/blues/mp3-192/tunein/ title="RADIO BOB - Blues" Aug 31 22:10:02 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:02.371+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" state=STATUS_PLAYING positionMs=328 volume=100 Aug 31 22:10:02 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:02.371+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" id=http://streams.radiobob.de/blues/mp3-192/tunein/ title="RADIO BOB - Blues" Aug 31 22:10:02 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:02.390+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" state=STATUS_PLAYING positionMs=328 volume=100 Aug 31 22:10:02 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:02.390+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" id=http://streams.radiobob.de/blues/mp3-192/tunein/ title="RADIO BOB - Blues" Aug 31 22:10:02 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:02.391+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" state=STATUS_PLAYING positionMs=328 volume=100 Aug 31 22:10:02 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:02.392+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" id=http://streams.radiobob.de/blues/mp3-192/tunein/ title="RADIO BOB - Blues" Aug 31 22:10:02 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:02.419+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" state=STATUS_PLAYING positionMs=328 volume=100 Aug 31 22:10:02 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:02.419+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" id=http://streams.radiobob.de/blues/mp3-192/tunein/ title="RADIO BOB - Blues" Aug 31 22:10:02 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:02.421+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" state=STATUS_PLAYING positionMs=328 volume=100 Aug 31 22:10:02 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:02.421+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" id=http://streams.radiobob.de/blues/mp3-192/tunein/ title="RADIO BOB - Blues" Aug 31 22:10:02 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:02.442+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" state=STATUS_PLAYING positionMs=328 volume=100 Aug 31 22:10:02 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:02.443+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" id=http://streams.radiobob.de/blues/mp3-192/tunein/ title="RADIO BOB - Blues" Aug 31 22:10:02 volumio volumio[1250]: info: ------------------------------ 1169ms Aug 31 22:10:02 volumio volumio[1250]: info: ------------------------------ 1195ms Aug 31 22:10:02 volumio volumio[1250]: info: ------------------------------ 1180ms Aug 31 22:10:02 volumio volumio[1250]: info: ------------------------------ 1168ms Aug 31 22:10:02 volumio volumio[1250]: info: sendMpdCommand status took 1012 milliseconds Aug 31 22:10:02 volumio volumio[1250]: info: sendMpdCommand playlistinfo took 1003 milliseconds Aug 31 22:10:02 volumio volumio[1250]: info: sendMpdCommand playlistinfo took 980 milliseconds Aug 31 22:10:02 volumio volumio[1250]: verbose: ControllerMpd::parseState Aug 31 22:10:02 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 22:10:02 volumio volumio[1250]: verbose: ControllerMpd::parseTrackInfo Aug 31 22:10:02 volumio volumio[1250]: verbose: ControllerMpd::parseTrackInfo Aug 31 22:10:02 volumio volumio[1250]: info: ControllerMpd::pushState Aug 31 22:10:02 volumio volumio[1250]: info: CoreCommandRouter::servicePushState Aug 31 22:10:02 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:10:02 volumio volumio[1250]: verbose: STATE SERVICE {"status":"play","position":0,"seek":884,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"RADIO BOB - Blues","artist":"RADIO BOB - Blues","album":null,"uri":"http://streams.radiobob.de/blues/mp3-192/tunein/","trackType":""} Aug 31 22:10:02 volumio volumio[1250]: verbose: CURRENT POSITION 0 Aug 31 22:10:02 volumio volumio[1250]: info: CoreStateMachine::syncState stateService play Aug 31 22:10:02 volumio volumio[1250]: info: CoreStateMachine::syncState currentStatus play Aug 31 22:10:02 volumio volumio[1250]: info: Received an update from plugin. extracting info from payload Aug 31 22:10:02 volumio volumio[1250]: info: CoreStateMachine::pushState Aug 31 22:10:02 volumio volumio[1250]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 22:10:02 volumio volumio[1250]: info: CoreCommandRouter::volumioPushState Aug 31 22:10:02 volumio volumio[1250]: info: CoreStateMachine::pushState Aug 31 22:10:02 volumio volumio[1250]: info: CoreCommandRouter::volumioPushState Aug 31 22:10:02 volumio volumio[1250]: info: ControllerMpd::pushState Aug 31 22:10:02 volumio volumio[1250]: info: CoreCommandRouter::servicePushState Aug 31 22:10:02 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:10:02 volumio volumio[1250]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1182,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"RADIO BOB - Blues","artist":"RADIO BOB - Blues","album":null,"uri":"http://streams.radiobob.de/blues/mp3-192/tunein/","trackType":""} Aug 31 22:10:02 volumio volumio[1250]: verbose: CURRENT POSITION 0 Aug 31 22:10:02 volumio volumio[1250]: info: CoreStateMachine::syncState stateService play Aug 31 22:10:02 volumio volumio[1250]: info: CoreStateMachine::syncState currentStatus play Aug 31 22:10:02 volumio volumio[1250]: info: Received an update from plugin. extracting info from payload Aug 31 22:10:02 volumio volumio[1250]: info: CoreStateMachine::pushState Aug 31 22:10:03 volumio volumio[1250]: info: CoreCommandRouter::volumioPushState Aug 31 22:10:03 volumio volumio[1250]: info: CoreStateMachine::pushState Aug 31 22:10:03 volumio volumio[1250]: info: CoreCommandRouter::volumioPushState Aug 31 22:10:03 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:03.045+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" state=STATUS_PLAYING positionMs=1399 volume=100 Aug 31 22:10:03 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:03.045+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" id=http://streams.radiobob.de/blues/mp3-192/tunein/ title="RADIO BOB - Blues" Aug 31 22:10:03 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:03.071+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" state=STATUS_PLAYING positionMs=1399 volume=100 Aug 31 22:10:03 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:03.072+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" id=http://streams.radiobob.de/blues/mp3-192/tunein/ title="RADIO BOB - Blues" Aug 31 22:10:03 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:03.073+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" state=STATUS_PLAYING positionMs=1399 volume=100 Aug 31 22:10:03 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:03.073+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" id=http://streams.radiobob.de/blues/mp3-192/tunein/ title="RADIO BOB - Blues" Aug 31 22:10:03 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:03.092+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" state=STATUS_PLAYING positionMs=1399 volume=100 Aug 31 22:10:03 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:03.092+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" id=http://streams.radiobob.de/blues/mp3-192/tunein/ title="RADIO BOB - Blues" Aug 31 22:10:03 volumio volumio[1250]: info: ------------------------------ 1674ms Aug 31 22:10:03 volumio volumio[1250]: info: ------------------------------ 1376ms Aug 31 22:10:03 volumio volumio[1250]: info: [ytmusic] Innertube support service: result: {"status":"started","server":{"address":"127.0.0.1","port":34295}} Aug 31 22:10:03 volumio volumio[1250]: info: [ytmusic] Innertube support service running at http://127.0.0.1:34295 Aug 31 22:10:03 volumio volumio[1250]: info: sendMpdCommand playlistinfo took 408 milliseconds Aug 31 22:10:03 volumio volumio[1250]: verbose: ControllerMpd::parseTrackInfo Aug 31 22:10:03 volumio volumio[1250]: info: ControllerMpd::pushState Aug 31 22:10:03 volumio volumio[1250]: info: CoreCommandRouter::servicePushState Aug 31 22:10:03 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:10:03 volumio volumio[1250]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1285,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"RADIO BOB - Blues","artist":"RADIO BOB - Blues","album":null,"uri":"http://streams.radiobob.de/blues/mp3-192/tunein/","trackType":""} Aug 31 22:10:03 volumio volumio[1250]: verbose: CURRENT POSITION 0 Aug 31 22:10:03 volumio volumio[1250]: info: CoreStateMachine::syncState stateService play Aug 31 22:10:03 volumio volumio[1250]: info: CoreStateMachine::syncState currentStatus play Aug 31 22:10:03 volumio volumio[1250]: info: Received an update from plugin. extracting info from payload Aug 31 22:10:03 volumio volumio[1250]: info: CoreStateMachine::pushState Aug 31 22:10:03 volumio volumio[1250]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 22:10:03 volumio volumio[1250]: info: CoreCommandRouter::volumioPushState Aug 31 22:10:03 volumio volumio[1250]: info: CoreStateMachine::pushState Aug 31 22:10:03 volumio volumio[1250]: info: CoreCommandRouter::volumioPushState Aug 31 22:10:03 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:03.422+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" state=STATUS_PLAYING positionMs=1823 volume=100 Aug 31 22:10:03 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:03.423+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" state=STATUS_PLAYING positionMs=1823 volume=100 Aug 31 22:10:03 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:03.424+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" id=http://streams.radiobob.de/blues/mp3-192/tunein/ title="RADIO BOB - Blues" Aug 31 22:10:03 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:03.424+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" id=http://streams.radiobob.de/blues/mp3-192/tunein/ title="RADIO BOB - Blues" Aug 31 22:10:03 volumio volumio[1250]: info: ------------------------------ 1579ms Aug 31 22:10:07 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 10. Aug 31 22:10:07 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 31 22:10:07 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 31 22:10:07 volumio volumio[1250]: info: CoreCommandRouter::executeOnPlugin: ytmusic , handleBrowseUri Aug 31 22:10:07 volumio volumio[1250]: info: [ytmusic-browse] browseUri: ytmusic Aug 31 22:10:07 volumio upmpdcli[2324]: Could not open config: /tmp/upmpdcli.conf Aug 31 22:10:07 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Aug 31 22:10:07 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Aug 31 22:10:07 volumio volumio[1250]: info: Preload queue cleared Aug 31 22:10:07 volumio volumio[1250]: info: Aug 31 22:10:07 volumio volumio[1250]: ---------------------------- MPD announces system playlist update Aug 31 22:10:07 volumio volumio[1250]: info: Ignoring MPD Status Update Aug 31 22:10:07 volumio volumio[1250]: info: Aug 31 22:10:07 volumio volumio[1250]: ---------------------------- MPD announces state update: player Aug 31 22:10:07 volumio volumio[1250]: info: ControllerMpd::getState Aug 31 22:10:07 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand status Aug 31 22:10:07 volumio volumio[1250]: info: Aug 31 22:10:07 volumio volumio[1250]: ---------------------------- MPD announces system playlist update Aug 31 22:10:07 volumio volumio[1250]: info: Ignoring MPD Status Update Aug 31 22:10:07 volumio volumio[1250]: info: Aug 31 22:10:07 volumio volumio[1250]: ---------------------------- MPD announces state update: player Aug 31 22:10:07 volumio volumio[1250]: info: ControllerMpd::getState Aug 31 22:10:07 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand status Aug 31 22:10:07 volumio volumio[1250]: info: Aug 31 22:10:07 volumio volumio[1250]: ---------------------------- MPD announces system playlist update Aug 31 22:10:07 volumio volumio[1250]: info: Ignoring MPD Status Update Aug 31 22:10:07 volumio volumio[1250]: info: Aug 31 22:10:07 volumio volumio[1250]: ---------------------------- MPD announces state update: player Aug 31 22:10:07 volumio volumio[1250]: info: ControllerMpd::getState Aug 31 22:10:07 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand status Aug 31 22:10:07 volumio volumio[1250]: info: ------------------------------ 34ms Aug 31 22:10:07 volumio volumio[1250]: info: sendMpdCommand status took 33 milliseconds Aug 31 22:10:07 volumio volumio[1250]: info: ------------------------------ 32ms Aug 31 22:10:07 volumio volumio[1250]: info: sendMpdCommand status took 32 milliseconds Aug 31 22:10:07 volumio volumio[1250]: verbose: ControllerMpd::parseState Aug 31 22:10:07 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 22:10:07 volumio volumio[1250]: verbose: ControllerMpd::parseState Aug 31 22:10:07 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 22:10:07 volumio volumio[1250]: info: ------------------------------ 93ms Aug 31 22:10:07 volumio volumio[1250]: info: sendMpdCommand status took 64 milliseconds Aug 31 22:10:07 volumio volumio[1250]: info: sendMpdCommand playlistinfo took 61 milliseconds Aug 31 22:10:07 volumio volumio[1250]: info: sendMpdCommand playlistinfo took 61 milliseconds Aug 31 22:10:07 volumio volumio[1250]: verbose: ControllerMpd::parseState Aug 31 22:10:07 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 22:10:07 volumio volumio[1250]: verbose: ControllerMpd::parseTrackInfo Aug 31 22:10:07 volumio volumio[1250]: verbose: ControllerMpd::parseTrackInfo Aug 31 22:10:07 volumio volumio[1250]: info: ControllerMpd::pushState Aug 31 22:10:07 volumio volumio[1250]: info: CoreCommandRouter::servicePushState Aug 31 22:10:07 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:10:07 volumio volumio[1250]: verbose: STATE SERVICE {"status":"play","position":0,"seek":7080,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Stevie Ray Vaughan & Double Trouble - Texas Flood","artist":"RADIO BOB - Blues","album":null,"uri":"http://streams.radiobob.de/blues/mp3-192/tunein/","trackType":""} Aug 31 22:10:07 volumio volumio[1250]: verbose: CURRENT POSITION 0 Aug 31 22:10:07 volumio volumio[1250]: info: CoreStateMachine::syncState stateService play Aug 31 22:10:07 volumio volumio[1250]: info: CoreStateMachine::syncState currentStatus play Aug 31 22:10:07 volumio volumio[1250]: info: Received an update from plugin. extracting info from payload Aug 31 22:10:07 volumio volumio[1250]: info: CoreStateMachine::pushState Aug 31 22:10:07 volumio volumio[1250]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 22:10:07 volumio volumio[1250]: info: CoreCommandRouter::volumioPushState Aug 31 22:10:07 volumio volumio[1250]: info: CoreStateMachine::pushState Aug 31 22:10:07 volumio volumio[1250]: info: CoreCommandRouter::volumioPushState Aug 31 22:10:07 volumio volumio[1250]: info: ControllerMpd::pushState Aug 31 22:10:07 volumio volumio[1250]: info: CoreCommandRouter::servicePushState Aug 31 22:10:07 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:10:07 volumio volumio[1250]: verbose: STATE SERVICE {"status":"play","position":0,"seek":7080,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Stevie Ray Vaughan & Double Trouble - Texas Flood","artist":"RADIO BOB - Blues","album":null,"uri":"http://streams.radiobob.de/blues/mp3-192/tunein/","trackType":""} Aug 31 22:10:07 volumio volumio[1250]: verbose: CURRENT POSITION 0 Aug 31 22:10:07 volumio volumio[1250]: info: CoreStateMachine::syncState stateService play Aug 31 22:10:07 volumio volumio[1250]: info: CoreStateMachine::syncState currentStatus play Aug 31 22:10:07 volumio volumio[1250]: info: Received an update from plugin. extracting info from payload Aug 31 22:10:07 volumio volumio[1250]: info: CoreStateMachine::pushState Aug 31 22:10:07 volumio volumio[1250]: info: CoreCommandRouter::volumioPushState Aug 31 22:10:07 volumio volumio[1250]: info: CoreStateMachine::pushState Aug 31 22:10:07 volumio volumio[1250]: info: CoreCommandRouter::volumioPushState Aug 31 22:10:08 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:08.063+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" state=STATUS_PLAYING positionMs=6045 volume=100 Aug 31 22:10:08 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:08.064+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" id=http://streams.radiobob.de/blues/mp3-192/tunein/ title="Stevie Ray Vaughan & Double Trouble - Texas Flood" Aug 31 22:10:08 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:08.101+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" state=STATUS_PLAYING positionMs=6045 volume=100 Aug 31 22:10:08 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:08.101+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" state=STATUS_PLAYING positionMs=6045 volume=100 Aug 31 22:10:08 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:08.101+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" id=http://streams.radiobob.de/blues/mp3-192/tunein/ title="Stevie Ray Vaughan & Double Trouble - Texas Flood" Aug 31 22:10:08 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:08.101+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" id=http://streams.radiobob.de/blues/mp3-192/tunein/ title="Stevie Ray Vaughan & Double Trouble - Texas Flood" Aug 31 22:10:08 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:08.102+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" state=STATUS_PLAYING positionMs=6045 volume=100 Aug 31 22:10:08 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:08.102+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" id=http://streams.radiobob.de/blues/mp3-192/tunein/ title="Stevie Ray Vaughan & Double Trouble - Texas Flood" Aug 31 22:10:08 volumio volumio[1250]: info: ------------------------------ 417ms Aug 31 22:10:08 volumio volumio[1250]: info: ------------------------------ 416ms Aug 31 22:10:08 volumio volumio[1250]: info: sendMpdCommand playlistinfo took 322 milliseconds Aug 31 22:10:08 volumio volumio[1250]: verbose: ControllerMpd::parseTrackInfo Aug 31 22:10:08 volumio volumio[1250]: info: ControllerMpd::pushState Aug 31 22:10:08 volumio volumio[1250]: info: CoreCommandRouter::servicePushState Aug 31 22:10:08 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:10:08 volumio volumio[1250]: verbose: STATE SERVICE {"status":"play","position":0,"seek":7080,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Stevie Ray Vaughan & Double Trouble - Texas Flood","artist":"RADIO BOB - Blues","album":null,"uri":"http://streams.radiobob.de/blues/mp3-192/tunein/","trackType":""} Aug 31 22:10:08 volumio volumio[1250]: verbose: CURRENT POSITION 0 Aug 31 22:10:08 volumio volumio[1250]: info: CoreStateMachine::syncState stateService play Aug 31 22:10:08 volumio volumio[1250]: info: CoreStateMachine::syncState currentStatus play Aug 31 22:10:08 volumio volumio[1250]: info: Received an update from plugin. extracting info from payload Aug 31 22:10:08 volumio volumio[1250]: info: CoreStateMachine::pushState Aug 31 22:10:08 volumio volumio[1250]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 22:10:08 volumio volumio[1250]: info: CoreCommandRouter::volumioPushState Aug 31 22:10:08 volumio volumio[1250]: info: CoreStateMachine::pushState Aug 31 22:10:08 volumio volumio[1250]: info: CoreCommandRouter::volumioPushState Aug 31 22:10:08 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:08.335+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" state=STATUS_PLAYING positionMs=6653 volume=100 Aug 31 22:10:08 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:08.335+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" id=http://streams.radiobob.de/blues/mp3-192/tunein/ title="Stevie Ray Vaughan & Double Trouble - Texas Flood" Aug 31 22:10:08 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:08.336+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" state=STATUS_PLAYING positionMs=6653 volume=100 Aug 31 22:10:08 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:08.337+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" id=http://streams.radiobob.de/blues/mp3-192/tunein/ title="Stevie Ray Vaughan & Double Trouble - Texas Flood" Aug 31 22:10:08 volumio volumio[1250]: info: ------------------------------ 643ms Aug 31 22:10:13 volumio volumio[1250]: Searching plugin music_service/ytmusic Aug 31 22:10:13 volumio volumio[1250]: info: CoreCommandRouter::executeOnPlugin: ytmusic , search Aug 31 22:10:18 volumio volumio[1250]: Searching plugin music_service/ytmusic Aug 31 22:10:18 volumio volumio[1250]: info: CoreCommandRouter::executeOnPlugin: ytmusic , search Aug 31 22:10:20 volumio volumio[1250]: Searching plugin music_service/ytmusic Aug 31 22:10:20 volumio volumio[1250]: info: CoreCommandRouter::executeOnPlugin: ytmusic , search Aug 31 22:10:22 volumio volumio[1250]: Searching plugin music_service/ytmusic Aug 31 22:10:22 volumio volumio[1250]: info: CoreCommandRouter::executeOnPlugin: ytmusic , search Aug 31 22:10:22 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 11. Aug 31 22:10:22 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 31 22:10:22 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 31 22:10:22 volumio upmpdcli[2355]: Could not open config: /tmp/upmpdcli.conf Aug 31 22:10:22 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Aug 31 22:10:22 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Aug 31 22:10:23 volumio volumio[1250]: Searching plugin music_service/ytmusic Aug 31 22:10:23 volumio volumio[1250]: info: CoreCommandRouter::executeOnPlugin: ytmusic , search Aug 31 22:10:24 volumio volumio[1250]: Searching plugin music_service/ytmusic Aug 31 22:10:24 volumio volumio[1250]: info: CoreCommandRouter::executeOnPlugin: ytmusic , search Aug 31 22:10:37 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 12. Aug 31 22:10:37 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 31 22:10:37 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 31 22:10:37 volumio upmpdcli[2370]: Could not open config: /tmp/upmpdcli.conf Aug 31 22:10:37 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Aug 31 22:10:37 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Aug 31 22:10:39 volumio volumio[1250]: info: CoreCommandRouter::executeOnPlugin: ytmusic , handleBrowseUri Aug 31 22:10:39 volumio volumio[1250]: info: [ytmusic-browse] browseUri: ytmusic Aug 31 22:10:39 volumio volumio[1250]: info: Preload queue cleared Aug 31 22:10:43 volumio volumio[1250]: info: CoreCommandRouter::executeOnPlugin: ytmusic , handleBrowseUri Aug 31 22:10:43 volumio volumio[1250]: info: [ytmusic-browse] browseUri: ytmusic/generic@endpoint:o=%7B%22type%22%3A%22browse%22%2C%22payload%22%3A%7B%22browseId%22%3A%22FEmusic_history%22%7D%7D Aug 31 22:10:43 volumio volumio[1250]: error: VM operation timed out Error: VM operation timed out Aug 31 22:10:43 volumio volumio[1250]: at InnertubeWrapper.generatePoToken (/data/plugins/music_service/ytmusic/node_modules/volumio-yt-support/dist/lib/innertube/Wrapper.js:145:15) Aug 31 22:10:43 volumio volumio[1250]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Aug 31 22:10:43 volumio volumio[1250]: at async #generateSessionPoToken (/data/plugins/music_service/ytmusic/node_modules/volumio-yt-support/dist/lib/innertube/Wrapper.js:169:35) Aug 31 22:10:43 volumio volumio[1250]: at async #doGetSessionPoToken (/data/plugins/music_service/ytmusic/node_modules/volumio-yt-support/dist/lib/innertube/Wrapper.js:113:25) Aug 31 22:10:43 volumio volumio[1250]: at async #init (/data/plugins/music_service/ytmusic/node_modules/volumio-yt-support/dist/lib/innertube/Wrapper.js:97:9) Aug 31 22:10:43 volumio volumio[1250]: at async InnertubeWrapper.create (/data/plugins/music_service/ytmusic/node_modules/volumio-yt-support/dist/lib/innertube/Wrapper.js:57:9) Aug 31 22:10:43 volumio volumio[1250]: error: Failed to execute browseSource: Error: VM operation timed out Aug 31 22:10:53 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 13. Aug 31 22:10:53 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 31 22:10:53 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 31 22:10:53 volumio upmpdcli[2400]: Could not open config: /tmp/upmpdcli.conf Aug 31 22:10:53 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Aug 31 22:10:53 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Aug 31 22:10:54 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:54.764+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.42.147:43450 @ 0x1800a50" latency=-1.801877082s timeout=10s Aug 31 22:10:54 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:54.982+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.42.147:43450 @ 0x1800a50" latency=-1.801877082s timeout=10s endpoint=http://pushupdates.volumio.org duration=215.56629ms Aug 31 22:10:55 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:55.002+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.42.147:43450 @ 0x1800a50" latency=-1.801877082s timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=237.558863ms Aug 31 22:10:55 volumio volumio[1250]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 22:10:55 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:55.092+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.42.147:43450 @ 0x1800a50" latency=-1.801877082s timeout=10s endpoint=https://securetoken.googleapis.com duration=325.813393ms Aug 31 22:10:55 volumio volumio[1250]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 22:10:55 volumio volumio[1250]: info: Discovery: Getting this device information Aug 31 22:10:55 volumio volumio[1250]: info: CoreCommandRouter::volumioGetState Aug 31 22:10:55 volumio volumio[1250]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 22:10:55 volumio volumio[1250]: verbose: New Socket.io Connection to 192.168.42.153:3000 from 192.168.42.147 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Aug 31 22:10:55 volumio volumio[1250]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 31 22:10:55 volumio volumio[1250]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 31 22:10:55 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:55.182+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.42.147:43450 @ 0x1800a50" latency=-1.801877082s timeout=10s endpoint=https://www.googleapis.com duration=416.145502ms Aug 31 22:10:55 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:55.255+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.42.147:43450 @ 0x1800a50" latency=-1.801877082s timeout=10s endpoint=http://cddb.volumio.org duration=489.835785ms Aug 31 22:10:55 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:55.262+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.42.147:43450 @ 0x1800a50" latency=-1.801877082s timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=495.780695ms Aug 31 22:10:55 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:55.281+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.42.147:43450 @ 0x1800a50" latency=-1.801877082s timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=514.32864ms Aug 31 22:10:55 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:55.324+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.42.147:43450 @ 0x1800a50" latency=-1.801877082s timeout=10s endpoint=https://functions.volumio.cloud duration=557.846158ms Aug 31 22:10:55 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:55.327+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.42.147:43450 @ 0x1800a50" latency=-1.801877082s timeout=10s endpoint=https://functions.volumio.cloud duration=560.124478ms Aug 31 22:10:55 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:55.393+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.42.147:43450 @ 0x1800a50" latency=-1.801877082s timeout=10s endpoint=https://myvolumio.firebaseio.com duration=627.643576ms Aug 31 22:10:55 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:55.460+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.42.147:43450 @ 0x1800a50" latency=-1.801877082s timeout=10s endpoint=http://plugins.volumio.org duration=693.165427ms Aug 31 22:10:55 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:55.492+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.42.147:43450 @ 0x1800a50" latency=-1.801877082s timeout=10s endpoint=https://database.volumio.cloud duration=725.071717ms Aug 31 22:10:55 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:55.702+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.42.147:43450 @ 0x1800a50" latency=-1.801877082s timeout=10s endpoint=https://google.com duration=936.617865ms Aug 31 22:10:58 volumio volumio[1250]: info: Preload queue cleared Aug 31 22:10:58 volumio volumio[1250]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 31 22:10:58 volumio volumio[1250]: info: CoreStateMachine::ClearQueue Aug 31 22:10:58 volumio volumio[1250]: info: CoreStateMachine::stop Aug 31 22:10:58 volumio volumio[1250]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 22:10:58 volumio volumio[1250]: info: CoreStateMachine::stPlaybackTimer Aug 31 22:10:58 volumio volumio[1250]: info: CoreStateMachine::updateTrackBlock Aug 31 22:10:58 volumio volumio[1250]: info: CorePlayQueue::getTrackBlock Aug 31 22:10:58 volumio volumio[1250]: info: CoreStateMachine::pushState Aug 31 22:10:58 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:10:58 volumio volumio[1250]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 22:10:58 volumio volumio[1250]: info: CoreCommandRouter::volumioPushState Aug 31 22:10:58 volumio volumio[1250]: info: CoreStateMachine::serviceStop Aug 31 22:10:58 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:10:58 volumio volumio[1250]: info: CoreCommandRouter::serviceStop Aug 31 22:10:58 volumio volumio[1250]: info: [1788207058802] ControllerWebradio::stop Aug 31 22:10:58 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand stop Aug 31 22:10:58 volumio volumio[1250]: info: CorePlayQueue::clearPlayQueue Aug 31 22:10:58 volumio volumio[1250]: info: CorePlayQueue::saveQueue Aug 31 22:10:58 volumio volumio[1250]: info: CoreCommandRouter::volumioPushQueue Aug 31 22:10:58 volumio volumio[1250]: info: CoreStateMachine::addQueueItems Aug 31 22:10:58 volumio volumio[1250]: info: CorePlayQueue::addQueueItems Aug 31 22:10:58 volumio volumio[1250]: info: Preload queue cleared Aug 31 22:10:58 volumio volumio[1250]: info: Adding Item to queue: ytmusic/generic@endpoint:o=%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22dp2gxBEvg4A%22%2C%22playlistId%22%3A%22RDAOLTrlEx0f0CSmDVDWe9qDMA%22%2C%22params%22%3A%22wAEB8gECGAE%253D%22%7D%7D Aug 31 22:10:58 volumio volumio[1250]: info: Exploding uri ytmusic/generic@endpoint:o=%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22dp2gxBEvg4A%22%2C%22playlistId%22%3A%22RDAOLTrlEx0f0CSmDVDWe9qDMA%22%2C%22params%22%3A%22wAEB8gECGAE%253D%22%7D%7D in service ytmusic Aug 31 22:10:58 volumio volumio[1250]: info: [ytmusic-browse] explodeUri: ytmusic/generic@endpoint:o=%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22dp2gxBEvg4A%22%2C%22playlistId%22%3A%22RDAOLTrlEx0f0CSmDVDWe9qDMA%22%2C%22params%22%3A%22wAEB8gECGAE%253D%22%7D%7D Aug 31 22:10:58 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:58.808+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" state=STATUS_STOPPED positionMs=0 volume=100 Aug 31 22:10:58 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:58.809+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" id=http://streams.radiobob.de/blues/mp3-192/tunein/ title="RADIO BOB! Blues" Aug 31 22:10:58 volumio volumio[1250]: error: VM operation timed out Error: VM operation timed out Aug 31 22:10:58 volumio volumio[1250]: at InnertubeWrapper.generatePoToken (/data/plugins/music_service/ytmusic/node_modules/volumio-yt-support/dist/lib/innertube/Wrapper.js:145:15) Aug 31 22:10:58 volumio volumio[1250]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Aug 31 22:10:58 volumio volumio[1250]: at async #generateSessionPoToken (/data/plugins/music_service/ytmusic/node_modules/volumio-yt-support/dist/lib/innertube/Wrapper.js:169:35) Aug 31 22:10:58 volumio volumio[1250]: at async #doGetSessionPoToken (/data/plugins/music_service/ytmusic/node_modules/volumio-yt-support/dist/lib/innertube/Wrapper.js:113:25) Aug 31 22:10:58 volumio volumio[1250]: at async #init (/data/plugins/music_service/ytmusic/node_modules/volumio-yt-support/dist/lib/innertube/Wrapper.js:97:9) Aug 31 22:10:58 volumio volumio[1250]: at async InnertubeWrapper.create (/data/plugins/music_service/ytmusic/node_modules/volumio-yt-support/dist/lib/innertube/Wrapper.js:57:9) Aug 31 22:10:58 volumio volumio[1250]: error: Commandrouter: Cannot explode uri ytmusic/generic@endpoint:o=%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22dp2gxBEvg4A%22%2C%22playlistId%22%3A%22RDAOLTrlEx0f0CSmDVDWe9qDMA%22%2C%22params%22%3A%22wAEB8gECGAE%253D%22%7D%7D from service ytmusic: Error: VM operation timed out Aug 31 22:10:58 volumio volumio[1250]: info: CoreCommandRouter::volumioPushQueue Aug 31 22:10:58 volumio volumio[1250]: info: CorePlayQueue::saveQueue Aug 31 22:10:58 volumio volumio[1250]: info: CoreStateMachine::updateTrackBlock Aug 31 22:10:58 volumio volumio[1250]: info: CorePlayQueue::getTrackBlock Aug 31 22:10:58 volumio volumio[1250]: info: CoreCommandRouter::volumioPlay Aug 31 22:10:58 volumio volumio[1250]: info: CoreStateMachine::play index 0 Aug 31 22:10:58 volumio volumio[1250]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 22:10:58 volumio volumio[1250]: info: CoreStateMachine::stop Aug 31 22:10:58 volumio volumio[1250]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 22:10:58 volumio volumio[1250]: info: CoreStateMachine::play index undefined Aug 31 22:10:58 volumio volumio[1250]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 22:10:58 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:10:59 volumio volumio[1250]: info: Aug 31 22:10:59 volumio volumio[1250]: ---------------------------- MPD announces state update: player Aug 31 22:10:59 volumio volumio[1250]: info: sendMpdCommand stop took 251 milliseconds Aug 31 22:10:59 volumio volumio[1250]: info: ControllerMpd::getState Aug 31 22:10:59 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand status Aug 31 22:10:59 volumio volumio[1250]: info: Aug 31 22:10:59 volumio volumio[1250]: ---------------------------- MPD announces state update: player Aug 31 22:10:59 volumio volumio[1250]: info: ControllerMpd::getState Aug 31 22:10:59 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand status Aug 31 22:10:59 volumio volumio[1250]: info: Aug 31 22:10:59 volumio volumio[1250]: ---------------------------- MPD announces state update: player Aug 31 22:10:59 volumio volumio[1250]: info: ControllerMpd::getState Aug 31 22:10:59 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand status Aug 31 22:10:59 volumio volumio[1250]: info: sendMpdCommand status took 3 milliseconds Aug 31 22:10:59 volumio volumio[1250]: info: sendMpdCommand status took 2 milliseconds Aug 31 22:10:59 volumio volumio[1250]: info: sendMpdCommand status took 2 milliseconds Aug 31 22:10:59 volumio volumio[1250]: verbose: ControllerMpd::parseState Aug 31 22:10:59 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 22:10:59 volumio volumio[1250]: verbose: ControllerMpd::parseState Aug 31 22:10:59 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 22:10:59 volumio volumio[1250]: verbose: ControllerMpd::parseState Aug 31 22:10:59 volumio volumio[1250]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 22:10:59 volumio volumio[1250]: info: sendMpdCommand playlistinfo took 70 milliseconds Aug 31 22:10:59 volumio volumio[1250]: info: sendMpdCommand playlistinfo took 70 milliseconds Aug 31 22:10:59 volumio volumio[1250]: info: sendMpdCommand playlistinfo took 69 milliseconds Aug 31 22:10:59 volumio volumio[1250]: verbose: ControllerMpd::parseTrackInfo Aug 31 22:10:59 volumio volumio[1250]: verbose: ControllerMpd::parseTrackInfo Aug 31 22:10:59 volumio volumio[1250]: verbose: ControllerMpd::parseTrackInfo Aug 31 22:10:59 volumio volumio[1250]: info: ControllerMpd::pushState Aug 31 22:10:59 volumio volumio[1250]: info: CoreCommandRouter::servicePushState Aug 31 22:10:59 volumio volumio[1250]: info: CoreStateMachine::pushState Aug 31 22:10:59 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:10:59 volumio volumio[1250]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 22:10:59 volumio volumio[1250]: info: CoreCommandRouter::volumioPushState Aug 31 22:10:59 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:10:59 volumio volumio[1250]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Stevie Ray Vaughan & Double Trouble - Texas Flood","artist":"RADIO BOB - Blues","album":null,"uri":"http://streams.radiobob.de/blues/mp3-192/tunein/","trackType":""} Aug 31 22:10:59 volumio volumio[1250]: verbose: CURRENT POSITION 0 Aug 31 22:10:59 volumio volumio[1250]: info: CoreStateMachine::syncState stateService stop Aug 31 22:10:59 volumio volumio[1250]: info: CoreStateMachine::syncState currentStatus stop Aug 31 22:10:59 volumio volumio[1250]: info: CoreStateMachine::pushState Aug 31 22:10:59 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:10:59 volumio volumio[1250]: info: CoreCommandRouter::volumioPushState Aug 31 22:10:59 volumio volumio[1250]: info: No code Aug 31 22:10:59 volumio volumio[1250]: info: CoreStateMachine::pushState Aug 31 22:10:59 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:10:59 volumio volumio[1250]: info: CoreCommandRouter::volumioPushState Aug 31 22:10:59 volumio volumio[1250]: info: ControllerMpd::pushState Aug 31 22:10:59 volumio volumio[1250]: info: CoreCommandRouter::servicePushState Aug 31 22:10:59 volumio volumio[1250]: info: CoreStateMachine::pushState Aug 31 22:10:59 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:10:59 volumio volumio[1250]: info: CoreCommandRouter::volumioPushState Aug 31 22:10:59 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:10:59 volumio volumio[1250]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Stevie Ray Vaughan & Double Trouble - Texas Flood","artist":"RADIO BOB - Blues","album":null,"uri":"http://streams.radiobob.de/blues/mp3-192/tunein/","trackType":""} Aug 31 22:10:59 volumio volumio[1250]: verbose: CURRENT POSITION 0 Aug 31 22:10:59 volumio volumio[1250]: info: CoreStateMachine::syncState stateService stop Aug 31 22:10:59 volumio volumio[1250]: info: CoreStateMachine::syncState currentStatus stop Aug 31 22:10:59 volumio volumio[1250]: info: CoreStateMachine::pushState Aug 31 22:10:59 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:10:59 volumio volumio[1250]: info: CoreCommandRouter::volumioPushState Aug 31 22:10:59 volumio volumio[1250]: info: No code Aug 31 22:10:59 volumio volumio[1250]: info: CoreStateMachine::pushState Aug 31 22:10:59 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:10:59 volumio volumio[1250]: info: CoreCommandRouter::volumioPushState Aug 31 22:10:59 volumio volumio[1250]: info: ControllerMpd::pushState Aug 31 22:10:59 volumio volumio[1250]: info: CoreCommandRouter::servicePushState Aug 31 22:10:59 volumio volumio[1250]: info: CoreStateMachine::pushState Aug 31 22:10:59 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:10:59 volumio volumio[1250]: info: CoreCommandRouter::volumioPushState Aug 31 22:10:59 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:10:59 volumio volumio[1250]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Stevie Ray Vaughan & Double Trouble - Texas Flood","artist":"RADIO BOB - Blues","album":null,"uri":"http://streams.radiobob.de/blues/mp3-192/tunein/","trackType":""} Aug 31 22:10:59 volumio volumio[1250]: verbose: CURRENT POSITION 0 Aug 31 22:10:59 volumio volumio[1250]: info: CoreStateMachine::syncState stateService stop Aug 31 22:10:59 volumio volumio[1250]: info: CoreStateMachine::syncState currentStatus stop Aug 31 22:10:59 volumio volumio[1250]: info: CoreStateMachine::pushState Aug 31 22:10:59 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:10:59 volumio volumio[1250]: info: CoreCommandRouter::volumioPushState Aug 31 22:10:59 volumio volumio[1250]: info: No code Aug 31 22:10:59 volumio volumio[1250]: info: CoreStateMachine::pushState Aug 31 22:10:59 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:10:59 volumio volumio[1250]: info: CoreCommandRouter::volumioPushState Aug 31 22:10:59 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:59.336+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" state=STATUS_STOPPED positionMs=0 volume=100 Aug 31 22:10:59 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:59.336+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" id= title= Aug 31 22:10:59 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:59.373+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" state=STATUS_STOPPED positionMs=0 volume=100 Aug 31 22:10:59 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:59.373+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" id= title= Aug 31 22:10:59 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:59.374+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" state=STATUS_STOPPED positionMs=0 volume=100 Aug 31 22:10:59 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:59.375+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" id= title= Aug 31 22:10:59 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:59.393+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" state=STATUS_STOPPED positionMs=0 volume=100 Aug 31 22:10:59 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:59.393+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" id= title= Aug 31 22:10:59 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:59.395+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" state=STATUS_STOPPED positionMs=0 volume=100 Aug 31 22:10:59 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:59.395+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" id= title= Aug 31 22:10:59 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:59.396+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" state=STATUS_STOPPED positionMs=0 volume=100 Aug 31 22:10:59 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:59.397+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" id= title= Aug 31 22:10:59 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:59.398+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" state=STATUS_STOPPED positionMs=0 volume=100 Aug 31 22:10:59 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:59.398+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" id= title= Aug 31 22:10:59 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:59.399+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" state=STATUS_STOPPED positionMs=0 volume=100 Aug 31 22:10:59 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:59.400+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" id= title= Aug 31 22:10:59 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:59.443+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" state=STATUS_STOPPED positionMs=0 volume=100 Aug 31 22:10:59 volumio volumio5-onboarding[1552]: time=2026-08-31T22:10:59.443+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.42.147:43450 @ 0x1800a50" id= title= Aug 31 22:10:59 volumio volumio[1250]: info: ------------------------------ 614ms Aug 31 22:10:59 volumio volumio[1250]: info: ------------------------------ 604ms Aug 31 22:10:59 volumio volumio[1250]: info: ------------------------------ 604ms Aug 31 22:10:59 volumio volumio[1250]: info: touch_display: Setting screensaver timeout to 0 seconds. Aug 31 22:11:06 volumio volumio5-onboarding[1552]: time=2026-08-31T22:11:06.069+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.42.147:43450 @ 0x1800a50" latency=-1.925814297s timeout=10s Aug 31 22:11:06 volumio volumio5-onboarding[1552]: time=2026-08-31T22:11:06.084+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.42.147:43450 @ 0x1800a50" latency=-1.925814297s timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=14.957096ms Aug 31 22:11:06 volumio volumio5-onboarding[1552]: time=2026-08-31T22:11:06.091+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.42.147:43450 @ 0x1800a50" latency=-1.925814297s timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=21.368336ms Aug 31 22:11:06 volumio volumio5-onboarding[1552]: time=2026-08-31T22:11:06.102+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.42.147:43450 @ 0x1800a50" latency=-1.925814297s timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=33.126803ms Aug 31 22:11:06 volumio volumio[1250]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 22:11:06 volumio volumio[1250]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 22:11:06 volumio volumio[1250]: info: Discovery: Getting this device information Aug 31 22:11:06 volumio volumio[1250]: info: CoreCommandRouter::volumioGetState Aug 31 22:11:06 volumio volumio[1250]: info: CorePlayQueue::getTrack 0 Aug 31 22:11:06 volumio volumio[1250]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 22:11:06 volumio volumio5-onboarding[1552]: time=2026-08-31T22:11:06.104+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.42.147:43450 @ 0x1800a50" latency=-1.925814297s timeout=10s endpoint=http://pushupdates.volumio.org duration=34.750644ms Aug 31 22:11:06 volumio volumio[1250]: verbose: New Socket.io Connection to 192.168.42.153:3000 from 192.168.42.147 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Aug 31 22:11:06 volumio volumio[1250]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 31 22:11:06 volumio volumio[1250]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 31 22:11:06 volumio volumio5-onboarding[1552]: time=2026-08-31T22:11:06.177+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.42.147:43450 @ 0x1800a50" latency=-1.925814297s timeout=10s endpoint=https://www.googleapis.com duration=107.972672ms Aug 31 22:11:06 volumio volumio5-onboarding[1552]: time=2026-08-31T22:11:06.197+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.42.147:43450 @ 0x1800a50" latency=-1.925814297s timeout=10s endpoint=https://myvolumio.firebaseio.com duration=127.972516ms Aug 31 22:11:06 volumio volumio5-onboarding[1552]: time=2026-08-31T22:11:06.211+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.42.147:43450 @ 0x1800a50" latency=-1.925814297s timeout=10s endpoint=https://functions.volumio.cloud duration=141.673878ms Aug 31 22:11:06 volumio volumio5-onboarding[1552]: time=2026-08-31T22:11:06.212+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.42.147:43450 @ 0x1800a50" latency=-1.925814297s timeout=10s endpoint=https://functions.volumio.cloud duration=143.289776ms Aug 31 22:11:06 volumio volumio5-onboarding[1552]: time=2026-08-31T22:11:06.220+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.42.147:43450 @ 0x1800a50" latency=-1.925814297s timeout=10s endpoint=https://securetoken.googleapis.com duration=151.303247ms Aug 31 22:11:06 volumio volumio5-onboarding[1552]: time=2026-08-31T22:11:06.226+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.42.147:43450 @ 0x1800a50" latency=-1.925814297s timeout=10s endpoint=https://database.volumio.cloud duration=157.081323ms Aug 31 22:11:06 volumio volumio5-onboarding[1552]: time=2026-08-31T22:11:06.263+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.42.147:43450 @ 0x1800a50" latency=-1.925814297s timeout=10s endpoint=http://cddb.volumio.org duration=194.070215ms Aug 31 22:11:06 volumio volumio5-onboarding[1552]: time=2026-08-31T22:11:06.388+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.42.147:43450 @ 0x1800a50" latency=-1.925814297s timeout=10s endpoint=http://plugins.volumio.org duration=318.729434ms Aug 31 22:11:06 volumio volumio5-onboarding[1552]: time=2026-08-31T22:11:06.744+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.42.147:43450 @ 0x1800a50" latency=-1.925814297s timeout=10s endpoint=https://google.com duration=674.84985ms Aug 31 22:11:08 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 14. Aug 31 22:11:08 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 31 22:11:08 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 31 22:11:08 volumio upmpdcli[2430]: Could not open config: /tmp/upmpdcli.conf Aug 31 22:11:08 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Aug 31 22:11:08 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Aug 31 22:11:15 volumio volumio[1250]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 31 22:11:15 volumio volumio[1250]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Aug 31 22:11:23 volumio volumio[1250]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 31 22:11:23 volumio volumio[1250]: error: [ytmusic] Error getting i18n options: VM operation timed out Error: VM operation timed out Aug 31 22:11:23 volumio volumio[1250]: at InnertubeWrapper.generatePoToken (/data/plugins/music_service/ytmusic/node_modules/volumio-yt-support/dist/lib/innertube/Wrapper.js:145:15) Aug 31 22:11:23 volumio volumio[1250]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Aug 31 22:11:23 volumio volumio[1250]: at async #generateSessionPoToken (/data/plugins/music_service/ytmusic/node_modules/volumio-yt-support/dist/lib/innertube/Wrapper.js:169:35) Aug 31 22:11:23 volumio volumio[1250]: at async #doGetSessionPoToken (/data/plugins/music_service/ytmusic/node_modules/volumio-yt-support/dist/lib/innertube/Wrapper.js:113:25) Aug 31 22:11:23 volumio volumio[1250]: at async #init (/data/plugins/music_service/ytmusic/node_modules/volumio-yt-support/dist/lib/innertube/Wrapper.js:97:9) Aug 31 22:11:23 volumio volumio[1250]: at async InnertubeWrapper.create (/data/plugins/music_service/ytmusic/node_modules/volumio-yt-support/dist/lib/innertube/Wrapper.js:57:9) Aug 31 22:11:23 volumio volumio[1250]: warn: [ytmusic] Failed to get account config: VM operation timed out Error: VM operation timed out Aug 31 22:11:23 volumio volumio[1250]: at InnertubeWrapper.generatePoToken (/data/plugins/music_service/ytmusic/node_modules/volumio-yt-support/dist/lib/innertube/Wrapper.js:145:15) Aug 31 22:11:23 volumio volumio[1250]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Aug 31 22:11:23 volumio volumio[1250]: at async #generateSessionPoToken (/data/plugins/music_service/ytmusic/node_modules/volumio-yt-support/dist/lib/innertube/Wrapper.js:169:35) Aug 31 22:11:23 volumio volumio[1250]: at async #doGetSessionPoToken (/data/plugins/music_service/ytmusic/node_modules/volumio-yt-support/dist/lib/innertube/Wrapper.js:113:25) Aug 31 22:11:23 volumio volumio[1250]: at async #init (/data/plugins/music_service/ytmusic/node_modules/volumio-yt-support/dist/lib/innertube/Wrapper.js:97:9) Aug 31 22:11:23 volumio volumio[1250]: at async InnertubeWrapper.create (/data/plugins/music_service/ytmusic/node_modules/volumio-yt-support/dist/lib/innertube/Wrapper.js:57:9) Aug 31 22:11:23 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 15. Aug 31 22:11:23 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 31 22:11:23 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 31 22:11:23 volumio upmpdcli[2462]: Could not open config: /tmp/upmpdcli.conf Aug 31 22:11:23 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Aug 31 22:11:23 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Aug 31 22:11:33 volumio volumio[1250]: info: CALLMETHOD: music_service ytmusic configSaveI18n [object Object] Aug 31 22:11:33 volumio volumio[1250]: info: CoreCommandRouter::executeOnPlugin: ytmusic , configSaveI18n Aug 31 22:11:33 volumio volumio[1250]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 22:11:33 volumio volumio[1250]: Error: VM operation timed out Aug 31 22:11:33 volumio volumio[1250]: at InnertubeWrapper.generatePoToken (/data/plugins/music_service/ytmusic/node_modules/volumio-yt-support/dist/lib/innertube/Wrapper.js:145:15) Aug 31 22:11:33 volumio volumio[1250]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Aug 31 22:11:33 volumio volumio[1250]: at async #generateSessionPoToken (/data/plugins/music_service/ytmusic/node_modules/volumio-yt-support/dist/lib/innertube/Wrapper.js:169:35) Aug 31 22:11:33 volumio volumio[1250]: at async #doGetSessionPoToken (/data/plugins/music_service/ytmusic/node_modules/volumio-yt-support/dist/lib/innertube/Wrapper.js:113:25) Aug 31 22:11:33 volumio volumio[1250]: at async #init (/data/plugins/music_service/ytmusic/node_modules/volumio-yt-support/dist/lib/innertube/Wrapper.js:97:9) Aug 31 22:11:33 volumio volumio[1250]: at async InnertubeWrapper.create (/data/plugins/music_service/ytmusic/node_modules/volumio-yt-support/dist/lib/innertube/Wrapper.js:57:9) Aug 31 22:11:33 volumio volumio[1250]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 22:11:36 volumio sudo[2492]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-31 22:10' Aug 31 22:11:36 volumio sudo[2492]: 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"