Feb 25 09:52:04 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Feb 25 09:52:09 volumio volumio[1234]: info: Preload queue cleared Feb 25 09:52:09 volumio volumio[1234]: info: Preloading song: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@d451a256a4c78050a275 Feb 25 09:52:09 volumio volumio[1234]: info: Preloading song: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@222809d9d264680b6533 Feb 25 09:52:09 volumio volumio[1234]: info: Preloading song: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@f2ebb7f3710900f01fc6 Feb 25 09:52:09 volumio volumio[1234]: info: Preloading song: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@450d86739fa72cef1148 Feb 25 09:52:09 volumio volumio[1234]: info: Preloading song: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@4649ef2b368db5a0afc9 Feb 25 09:52:09 volumio volumio[1234]: info: Preloading song: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@f431b329fa82dc493939 Feb 25 09:52:09 volumio volumio[1234]: info: Preloading song: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@46edc73177eaf999fb81 Feb 25 09:52:09 volumio volumio[1234]: info: Preloading song: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@9fb67d37edfb20e013a7 Feb 25 09:52:09 volumio volumio[1234]: info: Preloading song: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@c4dd98c90b720ae081f4 Feb 25 09:52:09 volumio volumio[1234]: info: Preloading song: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@e114cfe58f1920404762 Feb 25 09:52:09 volumio volumio[1234]: info: Preloading song: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@13945081c377a9bc27ba Feb 25 09:52:09 volumio volumio[1234]: info: Exploding uri upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@d451a256a4c78050a275 in service upnp_browser Feb 25 09:52:09 volumio volumio[1234]: info: Exploding uri upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@222809d9d264680b6533 in service upnp_browser Feb 25 09:52:09 volumio volumio[1234]: info: Exploding uri upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@f2ebb7f3710900f01fc6 in service upnp_browser Feb 25 09:52:09 volumio volumio[1234]: info: Exploding uri upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@450d86739fa72cef1148 in service upnp_browser Feb 25 09:52:09 volumio volumio[1234]: info: Exploding uri upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@4649ef2b368db5a0afc9 in service upnp_browser Feb 25 09:52:09 volumio volumio[1234]: info: Exploding uri upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@f431b329fa82dc493939 in service upnp_browser Feb 25 09:52:09 volumio volumio[1234]: info: Exploding uri upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@46edc73177eaf999fb81 in service upnp_browser Feb 25 09:52:09 volumio volumio[1234]: info: Exploding uri upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@9fb67d37edfb20e013a7 in service upnp_browser Feb 25 09:52:09 volumio volumio[1234]: info: Exploding uri upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@c4dd98c90b720ae081f4 in service upnp_browser Feb 25 09:52:09 volumio volumio[1234]: info: Exploding uri upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@e114cfe58f1920404762 in service upnp_browser Feb 25 09:52:09 volumio volumio[1234]: info: Exploding uri upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@13945081c377a9bc27ba in service upnp_browser Feb 25 09:52:11 volumio volumio[1234]: info: No valid Plugin REST Endpoint Feb 25 09:52:26 volumio volumio[1234]: info: Preload queue cleared Feb 25 09:52:26 volumio volumio[1234]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 25 09:52:26 volumio volumio[1234]: info: CoreStateMachine::ClearQueue Feb 25 09:52:26 volumio volumio[1234]: info: CoreStateMachine::stop Feb 25 09:52:26 volumio volumio[1234]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 25 09:52:26 volumio volumio[1234]: info: CoreStateMachine::stPlaybackTimer Feb 25 09:52:26 volumio volumio[1234]: info: CoreStateMachine::updateTrackBlock Feb 25 09:52:26 volumio volumio[1234]: info: CorePlayQueue::getTrackBlock Feb 25 09:52:26 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:26 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Feb 25 09:52:26 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 25 09:52:26 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:26 volumio volumio[1234]: info: CoreStateMachine::serviceStop Feb 25 09:52:26 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Feb 25 09:52:26 volumio volumio[1234]: info: CoreCommandRouter::serviceStop Feb 25 09:52:26 volumio volumio[1234]: info: [1772009546779] ControllerWebradio::stop Feb 25 09:52:26 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand stop Feb 25 09:52:26 volumio volumio[1234]: info: CorePlayQueue::clearPlayQueue Feb 25 09:52:26 volumio volumio[1234]: info: CorePlayQueue::saveQueue Feb 25 09:52:26 volumio volumio[1234]: info: CoreCommandRouter::volumioPushQueue Feb 25 09:52:26 volumio volumio[1234]: info: CoreStateMachine::addQueueItems Feb 25 09:52:26 volumio volumio[1234]: info: CorePlayQueue::addQueueItems Feb 25 09:52:26 volumio volumio[1234]: info: Preload queue cleared Feb 25 09:52:26 volumio volumio[1234]: info: Adding Item to queue: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@d451a256a4c78050a275 Feb 25 09:52:26 volumio volumio[1234]: info: Using cached record of: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@d451a256a4c78050a275 Feb 25 09:52:26 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:26.829+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_STOPPED positionMs=0 volume=100 Feb 25 09:52:26 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:26.830+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id="http://stream.antenne.de/coffee/stream/mp3?aw_0_1st.playerid=tunein.com" title="ANTENNE BAYERN Coffee Music" Feb 25 09:52:26 volumio volumio[1234]: info: CoreCommandRouter::volumioPushQueue Feb 25 09:52:26 volumio volumio[1234]: info: CorePlayQueue::saveQueue Feb 25 09:52:26 volumio volumio[1234]: info: CoreStateMachine::updateTrackBlock Feb 25 09:52:26 volumio volumio[1234]: info: CorePlayQueue::getTrackBlock Feb 25 09:52:26 volumio volumio[1234]: info: CoreCommandRouter::volumioPlay Feb 25 09:52:26 volumio volumio[1234]: info: CoreStateMachine::play index 0 Feb 25 09:52:26 volumio volumio[1234]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 25 09:52:26 volumio volumio[1234]: info: CoreStateMachine::addQueueItems Feb 25 09:52:26 volumio volumio[1234]: info: CorePlayQueue::addQueueItems Feb 25 09:52:26 volumio volumio[1234]: info: Preload queue cleared Feb 25 09:52:26 volumio volumio[1234]: info: Adding Item to queue: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@222809d9d264680b6533 Feb 25 09:52:26 volumio volumio[1234]: info: Using cached record of: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@222809d9d264680b6533 Feb 25 09:52:26 volumio volumio[1234]: info: Adding Item to queue: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@f2ebb7f3710900f01fc6 Feb 25 09:52:26 volumio volumio[1234]: info: Using cached record of: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@f2ebb7f3710900f01fc6 Feb 25 09:52:26 volumio volumio[1234]: info: Adding Item to queue: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@450d86739fa72cef1148 Feb 25 09:52:26 volumio volumio[1234]: info: Using cached record of: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@450d86739fa72cef1148 Feb 25 09:52:26 volumio volumio[1234]: info: Adding Item to queue: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@4649ef2b368db5a0afc9 Feb 25 09:52:26 volumio volumio[1234]: info: Using cached record of: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@4649ef2b368db5a0afc9 Feb 25 09:52:26 volumio volumio[1234]: info: Adding Item to queue: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@f431b329fa82dc493939 Feb 25 09:52:26 volumio volumio[1234]: info: Using cached record of: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@f431b329fa82dc493939 Feb 25 09:52:26 volumio volumio[1234]: info: Adding Item to queue: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@46edc73177eaf999fb81 Feb 25 09:52:26 volumio volumio[1234]: info: Using cached record of: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@46edc73177eaf999fb81 Feb 25 09:52:26 volumio volumio[1234]: info: Adding Item to queue: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@9fb67d37edfb20e013a7 Feb 25 09:52:26 volumio volumio[1234]: info: Using cached record of: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@9fb67d37edfb20e013a7 Feb 25 09:52:26 volumio volumio[1234]: info: Adding Item to queue: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@c4dd98c90b720ae081f4 Feb 25 09:52:26 volumio volumio[1234]: info: Using cached record of: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@c4dd98c90b720ae081f4 Feb 25 09:52:26 volumio volumio[1234]: info: Adding Item to queue: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@e114cfe58f1920404762 Feb 25 09:52:26 volumio volumio[1234]: info: Using cached record of: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@e114cfe58f1920404762 Feb 25 09:52:26 volumio volumio[1234]: info: Adding Item to queue: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@13945081c377a9bc27ba Feb 25 09:52:26 volumio volumio[1234]: info: Using cached record of: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@13945081c377a9bc27ba Feb 25 09:52:26 volumio volumio[1234]: info: CoreStateMachine::stop Feb 25 09:52:26 volumio volumio[1234]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 25 09:52:26 volumio volumio[1234]: info: CoreCommandRouter::volumioPushQueue Feb 25 09:52:26 volumio volumio[1234]: info: CorePlayQueue::saveQueue Feb 25 09:52:26 volumio volumio[1234]: info: CoreStateMachine::play index undefined Feb 25 09:52:26 volumio volumio[1234]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 25 09:52:26 volumio volumio[1234]: info: CoreStateMachine::updateTrackBlock Feb 25 09:52:26 volumio volumio[1234]: info: CorePlayQueue::getTrackBlock Feb 25 09:52:26 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Feb 25 09:52:26 volumio volumio[1234]: info: CoreStateMachine::startPlaybackTimer Feb 25 09:52:26 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Feb 25 09:52:26 volumio volumio[1234]: info: [1772009546983] ControllerUPNPBrowser::clearAddPlayTrack Feb 25 09:52:26 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand stop Feb 25 09:52:27 volumio volumio[1234]: info: Feb 25 09:52:27 volumio volumio[1234]: ---------------------------- MPD announces state update: player Feb 25 09:52:27 volumio volumio[1234]: info: sendMpdCommand stop took 266 milliseconds Feb 25 09:52:27 volumio volumio[1234]: info: ControllerMpd::getState Feb 25 09:52:27 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Feb 25 09:52:27 volumio volumio[1234]: info: sendMpdCommand stop took 63 milliseconds Feb 25 09:52:27 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand clear Feb 25 09:52:27 volumio volumio[1234]: info: Feb 25 09:52:27 volumio volumio[1234]: ---------------------------- MPD announces state update: player Feb 25 09:52:27 volumio volumio[1234]: info: ControllerMpd::getState Feb 25 09:52:27 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Feb 25 09:52:27 volumio volumio[1234]: info: Feb 25 09:52:27 volumio volumio[1234]: ---------------------------- MPD announces state update: player Feb 25 09:52:27 volumio volumio[1234]: info: ControllerMpd::getState Feb 25 09:52:27 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Feb 25 09:52:27 volumio volumio[1234]: info: Feb 25 09:52:27 volumio volumio[1234]: ---------------------------- MPD announces system playlist update Feb 25 09:52:27 volumio volumio[1234]: info: Ignoring MPD Status Update Feb 25 09:52:27 volumio volumio[1234]: info: sendMpdCommand status took 83 milliseconds Feb 25 09:52:27 volumio volumio[1234]: info: sendMpdCommand clear took 29 milliseconds Feb 25 09:52:27 volumio volumio[1234]: info: sendMpdCommand status took 21 milliseconds Feb 25 09:52:27 volumio volumio[1234]: info: sendMpdCommand status took 20 milliseconds Feb 25 09:52:27 volumio volumio[1234]: verbose: ControllerMpd::parseState Feb 25 09:52:27 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 25 09:52:27 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.188.21:32469/object/d451a256a4c78050a275/file.flac" Feb 25 09:52:27 volumio volumio[1234]: verbose: ControllerMpd::parseState Feb 25 09:52:27 volumio volumio[1234]: verbose: ControllerMpd::parseState Feb 25 09:52:27 volumio volumio[1234]: info: ControllerMpd::pushState Feb 25 09:52:27 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Feb 25 09:52:27 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:27 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Feb 25 09:52:27 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 25 09:52:27 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:27 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Feb 25 09:52:27 volumio volumio[1234]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Feb 25 09:52:27 volumio volumio[1234]: verbose: CURRENT POSITION 0 Feb 25 09:52:27 volumio volumio[1234]: info: CoreStateMachine::syncState stateService stop Feb 25 09:52:27 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus stop Feb 25 09:52:27 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:27 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Feb 25 09:52:27 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:27 volumio volumio[1234]: info: No code Feb 25 09:52:27 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:27 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Feb 25 09:52:27 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:27 volumio volumio[1234]: info: ControllerMpd::pushState Feb 25 09:52:27 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Feb 25 09:52:27 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:27 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Feb 25 09:52:27 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:27 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Feb 25 09:52:27 volumio volumio[1234]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Feb 25 09:52:27 volumio volumio[1234]: verbose: CURRENT POSITION 0 Feb 25 09:52:27 volumio volumio[1234]: info: CoreStateMachine::syncState stateService stop Feb 25 09:52:27 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus stop Feb 25 09:52:27 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:27 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Feb 25 09:52:27 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:27 volumio volumio[1234]: info: No code Feb 25 09:52:27 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:27 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Feb 25 09:52:27 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:27 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:27.308+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_STOPPED positionMs=57 volume=100 Feb 25 09:52:27 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:27.308+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/d451a256a4c78050a275/file.flac title=Hello Feb 25 09:52:27 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:27.312+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_STOPPED positionMs=57 volume=100 Feb 25 09:52:27 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:27.312+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/d451a256a4c78050a275/file.flac title=Hello Feb 25 09:52:27 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:27.313+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_STOPPED positionMs=57 volume=100 Feb 25 09:52:27 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:27.313+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/d451a256a4c78050a275/file.flac title=Hello Feb 25 09:52:27 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:27.333+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_STOPPED positionMs=57 volume=100 Feb 25 09:52:27 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:27.333+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/d451a256a4c78050a275/file.flac title=Hello Feb 25 09:52:27 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:27.335+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_STOPPED positionMs=57 volume=100 Feb 25 09:52:27 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:27.335+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/d451a256a4c78050a275/file.flac title=Hello Feb 25 09:52:27 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:27.340+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_STOPPED positionMs=57 volume=100 Feb 25 09:52:27 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:27.341+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/d451a256a4c78050a275/file.flac title=Hello Feb 25 09:52:27 volumio volumio[1234]: info: ------------------------------ 334ms Feb 25 09:52:27 volumio volumio[1234]: info: ------------------------------ 337ms Feb 25 09:52:27 volumio volumio[1234]: info: Feb 25 09:52:27 volumio volumio[1234]: ---------------------------- MPD announces system playlist update Feb 25 09:52:27 volumio volumio[1234]: info: Ignoring MPD Status Update Feb 25 09:52:27 volumio volumio[1234]: info: Feb 25 09:52:27 volumio volumio[1234]: ---------------------------- MPD announces system playlist update Feb 25 09:52:27 volumio volumio[1234]: info: Ignoring MPD Status Update Feb 25 09:52:27 volumio volumio[1234]: error: updateQueue error: null Feb 25 09:52:27 volumio volumio[1234]: error: updateQueue error: null Feb 25 09:52:27 volumio volumio[1234]: error: updateQueue error: null Feb 25 09:52:27 volumio volumio[1234]: info: ------------------------------ 774ms Feb 25 09:52:27 volumio volumio[1234]: info: sendMpdCommand playlistinfo took 777 milliseconds Feb 25 09:52:27 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.188.21:32469/object/d451a256a4c78050a275/file.flac" Feb 25 09:52:27 volumio volumio[1234]: info: ------------------------------ 459ms Feb 25 09:52:27 volumio volumio[1234]: info: ------------------------------ 459ms Feb 25 09:52:27 volumio volumio[1234]: verbose: ControllerMpd::parseTrackInfo Feb 25 09:52:27 volumio volumio[1234]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Feb 25 09:52:27 volumio volumio[1234]: info: ------------------------------ 874ms Feb 25 09:52:27 volumio volumio[1234]: info: Feb 25 09:52:27 volumio volumio[1234]: ---------------------------- MPD announces system playlist update Feb 25 09:52:27 volumio volumio[1234]: info: Ignoring MPD Status Update Feb 25 09:52:27 volumio volumio[1234]: info: sendMpdCommand add "http://192.168.188.21:32469/object/d451a256a4c78050a275/file.flac" took 10 milliseconds Feb 25 09:52:27 volumio volumio[1234]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 25 09:52:27 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand play Feb 25 09:52:27 volumio volumio[1234]: info: Feb 25 09:52:27 volumio volumio[1234]: ---------------------------- MPD announces system playlist update Feb 25 09:52:27 volumio volumio[1234]: info: Ignoring MPD Status Update Feb 25 09:52:27 volumio volumio[1234]: info: Feb 25 09:52:27 volumio volumio[1234]: ---------------------------- MPD announces system playlist update Feb 25 09:52:27 volumio volumio[1234]: info: Ignoring MPD Status Update Feb 25 09:52:27 volumio volumio[1234]: info: Feb 25 09:52:27 volumio volumio[1234]: ---------------------------- MPD announces state update: player Feb 25 09:52:27 volumio volumio[1234]: info: Feb 25 09:52:27 volumio volumio[1234]: ---------------------------- MPD announces state update: player Feb 25 09:52:28 volumio volumio[1234]: info: ------------------------------ 83ms Feb 25 09:52:28 volumio volumio[1234]: info: sendMpdCommand play took 82 milliseconds Feb 25 09:52:28 volumio volumio[1234]: info: ------------------------------ 29ms Feb 25 09:52:28 volumio volumio[1234]: info: ControllerMpd::getState Feb 25 09:52:28 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Feb 25 09:52:28 volumio volumio[1234]: info: ------------------------------ 28ms Feb 25 09:52:28 volumio volumio[1234]: info: ControllerMpd::getState Feb 25 09:52:28 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Feb 25 09:52:28 volumio volumio[1234]: info: Feb 25 09:52:28 volumio volumio[1234]: ---------------------------- MPD announces state update: player Feb 25 09:52:28 volumio volumio[1234]: info: ControllerMpd::getState Feb 25 09:52:28 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Feb 25 09:52:28 volumio volumio[1234]: info: Feb 25 09:52:28 volumio volumio[1234]: ---------------------------- MPD announces state update: player Feb 25 09:52:28 volumio volumio[1234]: info: ControllerMpd::getState Feb 25 09:52:28 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Feb 25 09:52:28 volumio volumio[1234]: info: sendMpdCommand status took 40 milliseconds Feb 25 09:52:28 volumio volumio[1234]: info: sendMpdCommand status took 40 milliseconds Feb 25 09:52:28 volumio volumio[1234]: info: sendMpdCommand status took 2 milliseconds Feb 25 09:52:28 volumio volumio[1234]: info: sendMpdCommand status took 2 milliseconds Feb 25 09:52:28 volumio volumio[1234]: verbose: ControllerMpd::parseState Feb 25 09:52:28 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 25 09:52:28 volumio volumio[1234]: verbose: ControllerMpd::parseState Feb 25 09:52:28 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 25 09:52:28 volumio volumio[1234]: verbose: ControllerMpd::parseState Feb 25 09:52:28 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 25 09:52:28 volumio volumio[1234]: verbose: ControllerMpd::parseState Feb 25 09:52:28 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 25 09:52:28 volumio volumio[1234]: info: Feb 25 09:52:28 volumio volumio[1234]: ---------------------------- MPD announces state update: player Feb 25 09:52:28 volumio volumio[1234]: info: ControllerMpd::getState Feb 25 09:52:28 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Feb 25 09:52:28 volumio volumio[1234]: info: Feb 25 09:52:28 volumio volumio[1234]: ---------------------------- MPD announces state update: player Feb 25 09:52:28 volumio volumio[1234]: info: ControllerMpd::getState Feb 25 09:52:28 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Feb 25 09:52:28 volumio volumio[1234]: info: sendMpdCommand playlistinfo took 26 milliseconds Feb 25 09:52:28 volumio volumio[1234]: info: sendMpdCommand playlistinfo took 25 milliseconds Feb 25 09:52:28 volumio volumio[1234]: info: sendMpdCommand playlistinfo took 27 milliseconds Feb 25 09:52:28 volumio volumio[1234]: info: sendMpdCommand playlistinfo took 24 milliseconds Feb 25 09:52:28 volumio volumio[1234]: info: sendMpdCommand status took 18 milliseconds Feb 25 09:52:28 volumio volumio[1234]: info: sendMpdCommand status took 17 milliseconds Feb 25 09:52:28 volumio volumio[1234]: verbose: ControllerMpd::parseTrackInfo Feb 25 09:52:28 volumio volumio[1234]: verbose: ControllerMpd::parseTrackInfo Feb 25 09:52:28 volumio volumio[1234]: verbose: ControllerMpd::parseTrackInfo Feb 25 09:52:28 volumio volumio[1234]: verbose: ControllerMpd::parseTrackInfo Feb 25 09:52:28 volumio volumio[1234]: verbose: ControllerMpd::parseState Feb 25 09:52:28 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 25 09:52:28 volumio volumio[1234]: verbose: ControllerMpd::parseState Feb 25 09:52:28 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 25 09:52:28 volumio volumio[1234]: info: ControllerMpd::pushState Feb 25 09:52:28 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Feb 25 09:52:28 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Feb 25 09:52:28 volumio volumio[1234]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":295,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file.flac","artist":null,"album":null,"uri":"http://192.168.188.21:32469/object/d451a256a4c78050a275/file.flac","trackType":"flac"} Feb 25 09:52:28 volumio volumio[1234]: verbose: CURRENT POSITION 0 Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::syncState stateService play Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus stop Feb 25 09:52:28 volumio volumio[1234]: info: ControllerMpd::pushState Feb 25 09:52:28 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Feb 25 09:52:28 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Feb 25 09:52:28 volumio volumio[1234]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":295,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file.flac","artist":null,"album":null,"uri":"http://192.168.188.21:32469/object/d451a256a4c78050a275/file.flac","trackType":"flac"} Feb 25 09:52:28 volumio volumio[1234]: verbose: CURRENT POSITION 0 Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::syncState stateService play Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus play Feb 25 09:52:28 volumio volumio[1234]: info: Received an update from plugin. extracting info from payload Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:28 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 25 09:52:28 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:28 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:28 volumio volumio[1234]: info: ControllerMpd::pushState Feb 25 09:52:28 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Feb 25 09:52:28 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Feb 25 09:52:28 volumio volumio[1234]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":295,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file.flac","artist":null,"album":null,"uri":"http://192.168.188.21:32469/object/d451a256a4c78050a275/file.flac","trackType":"flac"} Feb 25 09:52:28 volumio volumio[1234]: verbose: CURRENT POSITION 0 Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::syncState stateService play Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus play Feb 25 09:52:28 volumio volumio[1234]: info: Received an update from plugin. extracting info from payload Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:28 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:28 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:28 volumio volumio[1234]: info: ControllerMpd::pushState Feb 25 09:52:28 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Feb 25 09:52:28 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Feb 25 09:52:28 volumio volumio[1234]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":295,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file.flac","artist":null,"album":null,"uri":"http://192.168.188.21:32469/object/d451a256a4c78050a275/file.flac","trackType":"flac"} Feb 25 09:52:28 volumio volumio[1234]: verbose: CURRENT POSITION 0 Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::syncState stateService play Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus play Feb 25 09:52:28 volumio volumio[1234]: info: Received an update from plugin. extracting info from payload Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:28 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:28 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:28 volumio volumio[1234]: info: ------------------------------ 243ms Feb 25 09:52:28 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:28.251+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=0 volume=100 Feb 25 09:52:28 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:28.252+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/d451a256a4c78050a275/file.flac title=file.flac Feb 25 09:52:28 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:28.256+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=0 volume=100 Feb 25 09:52:28 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:28.256+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/d451a256a4c78050a275/file.flac title=file.flac Feb 25 09:52:28 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:28.259+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=0 volume=100 Feb 25 09:52:28 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:28.259+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/d451a256a4c78050a275/file.flac title=file.flac Feb 25 09:52:28 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:28.261+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=0 volume=100 Feb 25 09:52:28 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:28.261+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/d451a256a4c78050a275/file.flac title=file.flac Feb 25 09:52:28 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:28.264+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=0 volume=100 Feb 25 09:52:28 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:28.265+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/d451a256a4c78050a275/file.flac title=file.flac Feb 25 09:52:28 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:28.267+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=0 volume=100 Feb 25 09:52:28 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:28.267+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/d451a256a4c78050a275/file.flac title=file.flac Feb 25 09:52:28 volumio volumio[1234]: info: ------------------------------ 292ms Feb 25 09:52:28 volumio volumio[1234]: info: ------------------------------ 253ms Feb 25 09:52:28 volumio volumio[1234]: info: ------------------------------ 253ms Feb 25 09:52:28 volumio volumio[1234]: info: Feb 25 09:52:28 volumio volumio[1234]: ---------------------------- MPD announces system playlist update Feb 25 09:52:28 volumio volumio[1234]: info: Ignoring MPD Status Update Feb 25 09:52:28 volumio volumio[1234]: info: Feb 25 09:52:28 volumio volumio[1234]: ---------------------------- MPD announces state update: player Feb 25 09:52:28 volumio volumio[1234]: info: ControllerMpd::getState Feb 25 09:52:28 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Feb 25 09:52:28 volumio volumio[1234]: info: sendMpdCommand playlistinfo took 156 milliseconds Feb 25 09:52:28 volumio volumio[1234]: info: sendMpdCommand playlistinfo took 157 milliseconds Feb 25 09:52:28 volumio volumio[1234]: verbose: ControllerMpd::parseTrackInfo Feb 25 09:52:28 volumio volumio[1234]: verbose: ControllerMpd::parseTrackInfo Feb 25 09:52:28 volumio volumio[1234]: info: ControllerMpd::pushState Feb 25 09:52:28 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Feb 25 09:52:28 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Feb 25 09:52:28 volumio volumio[1234]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":295,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Hello","artist":"Adele","album":"25","uri":"http://192.168.188.21:32469/object/d451a256a4c78050a275/file.flac","trackType":"flac"} Feb 25 09:52:28 volumio volumio[1234]: verbose: CURRENT POSITION 0 Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::syncState stateService play Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus play Feb 25 09:52:28 volumio volumio[1234]: info: Received an update from plugin. extracting info from payload Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:28 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 25 09:52:28 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:28 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:28 volumio volumio[1234]: info: ControllerMpd::pushState Feb 25 09:52:28 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Feb 25 09:52:28 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Feb 25 09:52:28 volumio volumio[1234]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":295,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Hello","artist":"Adele","album":"25","uri":"http://192.168.188.21:32469/object/d451a256a4c78050a275/file.flac","trackType":"flac"} Feb 25 09:52:28 volumio volumio[1234]: verbose: CURRENT POSITION 0 Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::syncState stateService play Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus play Feb 25 09:52:28 volumio volumio[1234]: info: Received an update from plugin. extracting info from payload Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:28 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:28 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:28 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:28.397+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=297 volume=100 Feb 25 09:52:28 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:28.397+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/d451a256a4c78050a275/file.flac title=Hello Feb 25 09:52:28 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:28.420+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=297 volume=100 Feb 25 09:52:28 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:28.421+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/d451a256a4c78050a275/file.flac title=Hello Feb 25 09:52:28 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:28.422+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=297 volume=100 Feb 25 09:52:28 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:28.425+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/d451a256a4c78050a275/file.flac title=Hello Feb 25 09:52:28 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:28.432+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=297 volume=100 Feb 25 09:52:28 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:28.433+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/d451a256a4c78050a275/file.flac title=Hello Feb 25 09:52:28 volumio volumio[1234]: info: ------------------------------ 477ms Feb 25 09:52:28 volumio volumio[1234]: info: ------------------------------ 475ms Feb 25 09:52:28 volumio volumio[1234]: info: CoreCommandRouter::volumioGetQueue Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::getQueue Feb 25 09:52:28 volumio volumio[1234]: info: CorePlayQueue::getQueue Feb 25 09:52:28 volumio volumio[1234]: info: CoreCommandRouter::volumioGetQueue Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::getQueue Feb 25 09:52:28 volumio volumio[1234]: info: CorePlayQueue::getQueue Feb 25 09:52:28 volumio volumio[1234]: info: CoreCommandRouter::volumioGetQueue Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::getQueue Feb 25 09:52:28 volumio volumio[1234]: info: CorePlayQueue::getQueue Feb 25 09:52:28 volumio volumio[1234]: info: CoreCommandRouter::volumioGetQueue Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::getQueue Feb 25 09:52:28 volumio volumio[1234]: info: CorePlayQueue::getQueue Feb 25 09:52:28 volumio volumio[1234]: info: Feb 25 09:52:28 volumio volumio[1234]: ---------------------------- MPD announces system playlist update Feb 25 09:52:28 volumio volumio[1234]: info: Ignoring MPD Status Update Feb 25 09:52:28 volumio volumio[1234]: info: Feb 25 09:52:28 volumio volumio[1234]: ---------------------------- MPD announces state update: player Feb 25 09:52:28 volumio volumio[1234]: info: ControllerMpd::getState Feb 25 09:52:28 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Feb 25 09:52:28 volumio volumio[1234]: info: Feb 25 09:52:28 volumio volumio[1234]: ---------------------------- MPD announces system playlist update Feb 25 09:52:28 volumio volumio[1234]: info: Ignoring MPD Status Update Feb 25 09:52:28 volumio volumio[1234]: info: Feb 25 09:52:28 volumio volumio[1234]: ---------------------------- MPD announces state update: player Feb 25 09:52:28 volumio volumio[1234]: info: ControllerMpd::getState Feb 25 09:52:28 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Feb 25 09:52:28 volumio volumio[1234]: info: ------------------------------ 428ms Feb 25 09:52:28 volumio volumio[1234]: info: sendMpdCommand status took 429 milliseconds Feb 25 09:52:28 volumio volumio[1234]: info: ------------------------------ 61ms Feb 25 09:52:28 volumio volumio[1234]: info: sendMpdCommand status took 58 milliseconds Feb 25 09:52:28 volumio volumio[1234]: info: ------------------------------ 59ms Feb 25 09:52:28 volumio volumio[1234]: info: sendMpdCommand status took 49 milliseconds Feb 25 09:52:28 volumio volumio[1234]: verbose: ControllerMpd::parseState Feb 25 09:52:28 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 25 09:52:28 volumio volumio[1234]: verbose: ControllerMpd::parseState Feb 25 09:52:28 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 25 09:52:28 volumio volumio[1234]: verbose: ControllerMpd::parseState Feb 25 09:52:28 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 25 09:52:28 volumio volumio[1234]: info: sendMpdCommand playlistinfo took 19 milliseconds Feb 25 09:52:28 volumio volumio[1234]: info: sendMpdCommand playlistinfo took 36 milliseconds Feb 25 09:52:28 volumio volumio[1234]: info: sendMpdCommand playlistinfo took 36 milliseconds Feb 25 09:52:28 volumio volumio[1234]: verbose: ControllerMpd::parseTrackInfo Feb 25 09:52:28 volumio volumio[1234]: verbose: ControllerMpd::parseTrackInfo Feb 25 09:52:28 volumio volumio[1234]: verbose: ControllerMpd::parseTrackInfo Feb 25 09:52:28 volumio volumio[1234]: info: ControllerMpd::pushState Feb 25 09:52:28 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Feb 25 09:52:28 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Feb 25 09:52:28 volumio volumio[1234]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":295,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"369 Kbps","isStreaming":false,"title":"Hello","artist":"Adele","album":"25","uri":"http://192.168.188.21:32469/object/d451a256a4c78050a275/file.flac","trackType":"flac"} Feb 25 09:52:28 volumio volumio[1234]: verbose: CURRENT POSITION 0 Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::syncState stateService play Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus play Feb 25 09:52:28 volumio volumio[1234]: info: Received an update from plugin. extracting info from payload Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:28 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 25 09:52:28 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:28 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:28 volumio volumio[1234]: info: ControllerMpd::pushState Feb 25 09:52:28 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Feb 25 09:52:28 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Feb 25 09:52:28 volumio volumio[1234]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1260,"duration":295,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"353 Kbps","isStreaming":false,"title":"Hello","artist":"Adele","album":"25","uri":"http://192.168.188.21:32469/object/d451a256a4c78050a275/file.flac","trackType":"flac"} Feb 25 09:52:28 volumio volumio[1234]: verbose: CURRENT POSITION 0 Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::syncState stateService play Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus play Feb 25 09:52:28 volumio volumio[1234]: info: Received an update from plugin. extracting info from payload Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:28 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 25 09:52:28 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:28 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:28 volumio volumio[1234]: info: ControllerMpd::pushState Feb 25 09:52:28 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Feb 25 09:52:28 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Feb 25 09:52:28 volumio volumio[1234]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1260,"duration":295,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"353 Kbps","isStreaming":false,"title":"Hello","artist":"Adele","album":"25","uri":"http://192.168.188.21:32469/object/d451a256a4c78050a275/file.flac","trackType":"flac"} Feb 25 09:52:28 volumio volumio[1234]: verbose: CURRENT POSITION 0 Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::syncState stateService play Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus play Feb 25 09:52:28 volumio volumio[1234]: info: Received an update from plugin. extracting info from payload Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:28 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:28 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:28 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:28 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:28.888+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=725 volume=100 Feb 25 09:52:28 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:28.888+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=725 volume=100 Feb 25 09:52:28 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:28.889+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/d451a256a4c78050a275/file.flac title=Hello Feb 25 09:52:28 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:28.889+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/d451a256a4c78050a275/file.flac title=Hello Feb 25 09:52:28 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:28.895+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=725 volume=100 Feb 25 09:52:28 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:28.895+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/d451a256a4c78050a275/file.flac title=Hello Feb 25 09:52:28 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:28.897+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=725 volume=100 Feb 25 09:52:28 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:28.897+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/d451a256a4c78050a275/file.flac title=Hello Feb 25 09:52:28 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:28.906+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=725 volume=100 Feb 25 09:52:28 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:28.906+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/d451a256a4c78050a275/file.flac title=Hello Feb 25 09:52:28 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:28.909+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=725 volume=100 Feb 25 09:52:28 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:28.909+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/d451a256a4c78050a275/file.flac title=Hello Feb 25 09:52:29 volumio volumio[1234]: info: ------------------------------ 704ms Feb 25 09:52:29 volumio volumio[1234]: info: ------------------------------ 335ms Feb 25 09:52:29 volumio volumio[1234]: info: ------------------------------ 344ms Feb 25 09:52:29 volumio volumio[1234]: info: CoreCommandRouter::volumioGetQueue Feb 25 09:52:29 volumio volumio[1234]: info: CoreStateMachine::getQueue Feb 25 09:52:29 volumio volumio[1234]: info: CorePlayQueue::getQueue Feb 25 09:52:29 volumio volumio[1234]: info: CoreCommandRouter::volumioGetQueue Feb 25 09:52:29 volumio volumio[1234]: info: CoreStateMachine::getQueue Feb 25 09:52:29 volumio volumio[1234]: info: CorePlayQueue::getQueue Feb 25 09:52:29 volumio volumio[1234]: info: CoreCommandRouter::volumioGetQueue Feb 25 09:52:29 volumio volumio[1234]: info: CoreStateMachine::getQueue Feb 25 09:52:29 volumio volumio[1234]: info: CorePlayQueue::getQueue Feb 25 09:52:29 volumio volumio[1234]: info: CoreCommandRouter::volumioGetQueue Feb 25 09:52:29 volumio volumio[1234]: info: CoreStateMachine::getQueue Feb 25 09:52:29 volumio volumio[1234]: info: CorePlayQueue::getQueue Feb 25 09:52:29 volumio volumio[1234]: info: CoreCommandRouter::volumioGetQueue Feb 25 09:52:29 volumio volumio[1234]: info: CoreStateMachine::getQueue Feb 25 09:52:29 volumio volumio[1234]: info: CorePlayQueue::getQueue Feb 25 09:52:29 volumio volumio[1234]: info: CoreCommandRouter::volumioGetQueue Feb 25 09:52:29 volumio volumio[1234]: info: CoreStateMachine::getQueue Feb 25 09:52:29 volumio volumio[1234]: info: CorePlayQueue::getQueue Feb 25 09:52:31 volumio wpa_supplicant[1196]: wlan0: WPA: Group rekeying completed with 34:31:c4:30:3f:66 [GTK=TKIP] Feb 25 09:52:42 volumio volumio[1234]: info: Preload queue cleared Feb 25 09:52:42 volumio volumio[1234]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 25 09:52:42 volumio volumio[1234]: info: CoreStateMachine::ClearQueue Feb 25 09:52:42 volumio volumio[1234]: info: CoreStateMachine::stop Feb 25 09:52:42 volumio volumio[1234]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 25 09:52:42 volumio volumio[1234]: info: CoreStateMachine::stPlaybackTimer Feb 25 09:52:42 volumio volumio[1234]: info: CoreStateMachine::updateTrackBlock Feb 25 09:52:42 volumio volumio[1234]: info: CorePlayQueue::getTrackBlock Feb 25 09:52:42 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:42 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Feb 25 09:52:42 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 25 09:52:42 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:42 volumio volumio[1234]: info: CoreStateMachine::serviceStop Feb 25 09:52:42 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Feb 25 09:52:42 volumio volumio[1234]: info: CoreCommandRouter::serviceStop Feb 25 09:52:42 volumio volumio[1234]: info: [1772009562893] ControllerUPNPBrowser::stop Feb 25 09:52:42 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand stop Feb 25 09:52:42 volumio volumio[1234]: info: CorePlayQueue::clearPlayQueue Feb 25 09:52:42 volumio volumio[1234]: info: CorePlayQueue::saveQueue Feb 25 09:52:42 volumio volumio[1234]: info: CoreCommandRouter::volumioPushQueue Feb 25 09:52:42 volumio volumio[1234]: info: CoreStateMachine::addQueueItems Feb 25 09:52:42 volumio volumio[1234]: info: CorePlayQueue::addQueueItems Feb 25 09:52:42 volumio volumio[1234]: info: Preload queue cleared Feb 25 09:52:42 volumio volumio[1234]: info: Adding Item to queue: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@d451a256a4c78050a275 Feb 25 09:52:42 volumio volumio[1234]: info: Using cached record of: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@d451a256a4c78050a275 Feb 25 09:52:42 volumio volumio[1234]: info: Adding Item to queue: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@222809d9d264680b6533 Feb 25 09:52:42 volumio volumio[1234]: info: Using cached record of: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@222809d9d264680b6533 Feb 25 09:52:42 volumio volumio[1234]: info: Adding Item to queue: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@f2ebb7f3710900f01fc6 Feb 25 09:52:42 volumio volumio[1234]: info: Using cached record of: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@f2ebb7f3710900f01fc6 Feb 25 09:52:42 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:42.917+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_STOPPED positionMs=0 volume=100 Feb 25 09:52:42 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:42.918+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/d451a256a4c78050a275/file.flac title=Hello Feb 25 09:52:43 volumio volumio[1234]: info: CoreCommandRouter::volumioPushQueue Feb 25 09:52:43 volumio volumio[1234]: info: CorePlayQueue::saveQueue Feb 25 09:52:43 volumio volumio[1234]: info: CoreStateMachine::updateTrackBlock Feb 25 09:52:43 volumio volumio[1234]: info: CorePlayQueue::getTrackBlock Feb 25 09:52:43 volumio volumio[1234]: info: CoreCommandRouter::volumioPlay Feb 25 09:52:43 volumio volumio[1234]: info: CoreStateMachine::play index 2 Feb 25 09:52:43 volumio volumio[1234]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 25 09:52:43 volumio volumio[1234]: info: CoreStateMachine::addQueueItems Feb 25 09:52:43 volumio volumio[1234]: info: CorePlayQueue::addQueueItems Feb 25 09:52:43 volumio volumio[1234]: info: Preload queue cleared Feb 25 09:52:43 volumio volumio[1234]: info: Adding Item to queue: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@450d86739fa72cef1148 Feb 25 09:52:43 volumio volumio[1234]: info: Using cached record of: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@450d86739fa72cef1148 Feb 25 09:52:43 volumio volumio[1234]: info: Adding Item to queue: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@4649ef2b368db5a0afc9 Feb 25 09:52:43 volumio volumio[1234]: info: Using cached record of: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@4649ef2b368db5a0afc9 Feb 25 09:52:43 volumio volumio[1234]: info: Adding Item to queue: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@f431b329fa82dc493939 Feb 25 09:52:43 volumio volumio[1234]: info: Using cached record of: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@f431b329fa82dc493939 Feb 25 09:52:43 volumio volumio[1234]: info: Adding Item to queue: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@46edc73177eaf999fb81 Feb 25 09:52:43 volumio volumio[1234]: info: Using cached record of: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@46edc73177eaf999fb81 Feb 25 09:52:43 volumio volumio[1234]: info: Adding Item to queue: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@9fb67d37edfb20e013a7 Feb 25 09:52:43 volumio volumio[1234]: info: Using cached record of: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@9fb67d37edfb20e013a7 Feb 25 09:52:43 volumio volumio[1234]: info: Adding Item to queue: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@c4dd98c90b720ae081f4 Feb 25 09:52:43 volumio volumio[1234]: info: Using cached record of: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@c4dd98c90b720ae081f4 Feb 25 09:52:43 volumio volumio[1234]: info: Adding Item to queue: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@e114cfe58f1920404762 Feb 25 09:52:43 volumio volumio[1234]: info: Using cached record of: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@e114cfe58f1920404762 Feb 25 09:52:43 volumio volumio[1234]: info: Adding Item to queue: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@13945081c377a9bc27ba Feb 25 09:52:43 volumio volumio[1234]: info: Using cached record of: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@13945081c377a9bc27ba Feb 25 09:52:43 volumio volumio[1234]: info: CoreStateMachine::stop Feb 25 09:52:43 volumio volumio[1234]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 25 09:52:43 volumio volumio[1234]: info: CoreCommandRouter::volumioPushQueue Feb 25 09:52:43 volumio volumio[1234]: info: CorePlayQueue::saveQueue Feb 25 09:52:43 volumio volumio[1234]: info: CoreStateMachine::play index undefined Feb 25 09:52:43 volumio volumio[1234]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 25 09:52:43 volumio volumio[1234]: info: CoreStateMachine::updateTrackBlock Feb 25 09:52:43 volumio volumio[1234]: info: CorePlayQueue::getTrackBlock Feb 25 09:52:43 volumio volumio[1234]: info: CorePlayQueue::getTrack 2 Feb 25 09:52:43 volumio volumio[1234]: info: CoreStateMachine::startPlaybackTimer Feb 25 09:52:43 volumio volumio[1234]: info: CorePlayQueue::getTrack 2 Feb 25 09:52:43 volumio volumio[1234]: info: [1772009563252] ControllerUPNPBrowser::clearAddPlayTrack Feb 25 09:52:43 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand stop Feb 25 09:52:43 volumio volumio[1234]: info: Feb 25 09:52:43 volumio volumio[1234]: ---------------------------- MPD announces state update: player Feb 25 09:52:43 volumio volumio[1234]: info: sendMpdCommand stop took 450 milliseconds Feb 25 09:52:43 volumio volumio[1234]: info: ControllerMpd::getState Feb 25 09:52:43 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Feb 25 09:52:43 volumio volumio[1234]: info: sendMpdCommand stop took 91 milliseconds Feb 25 09:52:43 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand clear Feb 25 09:52:43 volumio volumio[1234]: info: Feb 25 09:52:43 volumio volumio[1234]: ---------------------------- MPD announces state update: player Feb 25 09:52:43 volumio volumio[1234]: info: ControllerMpd::getState Feb 25 09:52:43 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Feb 25 09:52:43 volumio volumio[1234]: info: Feb 25 09:52:43 volumio volumio[1234]: ---------------------------- MPD announces state update: player Feb 25 09:52:43 volumio volumio[1234]: info: ControllerMpd::getState Feb 25 09:52:43 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Feb 25 09:52:43 volumio volumio[1234]: info: Feb 25 09:52:43 volumio volumio[1234]: ---------------------------- MPD announces system playlist update Feb 25 09:52:43 volumio volumio[1234]: info: Ignoring MPD Status Update Feb 25 09:52:43 volumio volumio[1234]: info: sendMpdCommand status took 59 milliseconds Feb 25 09:52:43 volumio volumio[1234]: info: sendMpdCommand clear took 58 milliseconds Feb 25 09:52:43 volumio volumio[1234]: info: sendMpdCommand status took 59 milliseconds Feb 25 09:52:43 volumio volumio[1234]: info: sendMpdCommand status took 28 milliseconds Feb 25 09:52:43 volumio volumio[1234]: verbose: ControllerMpd::parseState Feb 25 09:52:43 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 25 09:52:43 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.188.21:32469/object/f2ebb7f3710900f01fc6/file.flac" Feb 25 09:52:43 volumio volumio[1234]: verbose: ControllerMpd::parseState Feb 25 09:52:43 volumio volumio[1234]: verbose: ControllerMpd::parseState Feb 25 09:52:43 volumio volumio[1234]: info: ControllerMpd::pushState Feb 25 09:52:43 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Feb 25 09:52:43 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:43 volumio volumio[1234]: info: CorePlayQueue::getTrack 2 Feb 25 09:52:43 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 25 09:52:43 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:43 volumio volumio[1234]: info: CorePlayQueue::getTrack 2 Feb 25 09:52:43 volumio volumio[1234]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Feb 25 09:52:43 volumio volumio[1234]: verbose: CURRENT POSITION 2 Feb 25 09:52:43 volumio volumio[1234]: info: CoreStateMachine::syncState stateService stop Feb 25 09:52:43 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus stop Feb 25 09:52:43 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:43 volumio volumio[1234]: info: CorePlayQueue::getTrack 2 Feb 25 09:52:43 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:43 volumio volumio[1234]: info: No code Feb 25 09:52:43 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:43 volumio volumio[1234]: info: CorePlayQueue::getTrack 2 Feb 25 09:52:43 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:43 volumio volumio[1234]: info: ControllerMpd::pushState Feb 25 09:52:43 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Feb 25 09:52:43 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:43 volumio volumio[1234]: info: CorePlayQueue::getTrack 2 Feb 25 09:52:43 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:43 volumio volumio[1234]: info: CorePlayQueue::getTrack 2 Feb 25 09:52:43 volumio volumio[1234]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Feb 25 09:52:43 volumio volumio[1234]: verbose: CURRENT POSITION 2 Feb 25 09:52:43 volumio volumio[1234]: info: CoreStateMachine::syncState stateService stop Feb 25 09:52:43 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus stop Feb 25 09:52:43 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:43 volumio volumio[1234]: info: CorePlayQueue::getTrack 2 Feb 25 09:52:43 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:43 volumio volumio[1234]: info: No code Feb 25 09:52:43 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:43 volumio volumio[1234]: info: CorePlayQueue::getTrack 2 Feb 25 09:52:43 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:43 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:43.559+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_STOPPED positionMs=1 volume=100 Feb 25 09:52:43 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:43.559+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ebb7f3710900f01fc6/file.flac title="I Miss You" Feb 25 09:52:43 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:43.574+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_STOPPED positionMs=1 volume=100 Feb 25 09:52:43 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:43.575+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ebb7f3710900f01fc6/file.flac title="I Miss You" Feb 25 09:52:43 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:43.586+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_STOPPED positionMs=1 volume=100 Feb 25 09:52:43 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:43.586+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ebb7f3710900f01fc6/file.flac title="I Miss You" Feb 25 09:52:43 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:43.591+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_STOPPED positionMs=1 volume=100 Feb 25 09:52:43 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:43.591+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ebb7f3710900f01fc6/file.flac title="I Miss You" Feb 25 09:52:43 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:43.614+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_STOPPED positionMs=1 volume=100 Feb 25 09:52:43 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:43.614+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ebb7f3710900f01fc6/file.flac title="I Miss You" Feb 25 09:52:43 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:43.619+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_STOPPED positionMs=1 volume=100 Feb 25 09:52:43 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:43.619+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ebb7f3710900f01fc6/file.flac title="I Miss You" Feb 25 09:52:43 volumio volumio[1234]: info: ------------------------------ 379ms Feb 25 09:52:43 volumio volumio[1234]: info: ------------------------------ 378ms Feb 25 09:52:43 volumio volumio[1234]: info: Feb 25 09:52:43 volumio volumio[1234]: ---------------------------- MPD announces system playlist update Feb 25 09:52:43 volumio volumio[1234]: info: Ignoring MPD Status Update Feb 25 09:52:43 volumio volumio[1234]: info: Feb 25 09:52:43 volumio volumio[1234]: ---------------------------- MPD announces system playlist update Feb 25 09:52:43 volumio volumio[1234]: info: Ignoring MPD Status Update Feb 25 09:52:43 volumio volumio[1234]: error: updateQueue error: null Feb 25 09:52:43 volumio volumio[1234]: info: ------------------------------ 332ms Feb 25 09:52:43 volumio volumio[1234]: info: sendMpdCommand playlistinfo took 323 milliseconds Feb 25 09:52:43 volumio volumio[1234]: verbose: ControllerMpd::parseTrackInfo Feb 25 09:52:43 volumio volumio[1234]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Feb 25 09:52:43 volumio volumio[1234]: info: ------------------------------ 385ms Feb 25 09:52:44 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.188.21:32469/object/f2ebb7f3710900f01fc6/file.flac" Feb 25 09:52:44 volumio volumio[1234]: error: updateQueue error: null Feb 25 09:52:44 volumio volumio[1234]: error: updateQueue error: null Feb 25 09:52:44 volumio volumio[1234]: info: Feb 25 09:52:44 volumio volumio[1234]: ---------------------------- MPD announces system playlist update Feb 25 09:52:44 volumio volumio[1234]: info: Ignoring MPD Status Update Feb 25 09:52:44 volumio volumio[1234]: info: ------------------------------ 382ms Feb 25 09:52:44 volumio volumio[1234]: info: ------------------------------ 382ms Feb 25 09:52:44 volumio volumio[1234]: info: sendMpdCommand add "http://192.168.188.21:32469/object/f2ebb7f3710900f01fc6/file.flac" took 2 milliseconds Feb 25 09:52:44 volumio volumio[1234]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 25 09:52:44 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand play Feb 25 09:52:44 volumio volumio[1234]: info: ------------------------------ 13ms Feb 25 09:52:44 volumio volumio[1234]: info: sendMpdCommand play took 12 milliseconds Feb 25 09:52:44 volumio volumio[1234]: info: Feb 25 09:52:44 volumio volumio[1234]: ---------------------------- MPD announces system playlist update Feb 25 09:52:44 volumio volumio[1234]: info: Ignoring MPD Status Update Feb 25 09:52:44 volumio volumio[1234]: info: Feb 25 09:52:44 volumio volumio[1234]: ---------------------------- MPD announces system playlist update Feb 25 09:52:44 volumio volumio[1234]: info: Ignoring MPD Status Update Feb 25 09:52:44 volumio volumio[1234]: info: ------------------------------ 2ms Feb 25 09:52:44 volumio volumio[1234]: info: ------------------------------ 1ms Feb 25 09:52:44 volumio volumio[1234]: info: Feb 25 09:52:44 volumio volumio[1234]: ---------------------------- MPD announces state update: player Feb 25 09:52:44 volumio volumio[1234]: info: ControllerMpd::getState Feb 25 09:52:44 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Feb 25 09:52:44 volumio volumio[1234]: info: Feb 25 09:52:44 volumio volumio[1234]: ---------------------------- MPD announces state update: player Feb 25 09:52:44 volumio volumio[1234]: info: ControllerMpd::getState Feb 25 09:52:44 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Feb 25 09:52:44 volumio volumio[1234]: info: Feb 25 09:52:44 volumio volumio[1234]: ---------------------------- MPD announces state update: player Feb 25 09:52:44 volumio volumio[1234]: info: Feb 25 09:52:44 volumio volumio[1234]: ---------------------------- MPD announces state update: player Feb 25 09:52:44 volumio volumio[1234]: info: ControllerMpd::getState Feb 25 09:52:44 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Feb 25 09:52:44 volumio volumio[1234]: info: sendMpdCommand status took 33 milliseconds Feb 25 09:52:44 volumio volumio[1234]: info: ControllerMpd::getState Feb 25 09:52:44 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Feb 25 09:52:44 volumio volumio[1234]: info: sendMpdCommand status took 29 milliseconds Feb 25 09:52:44 volumio volumio[1234]: verbose: ControllerMpd::parseState Feb 25 09:52:44 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 25 09:52:44 volumio volumio[1234]: verbose: ControllerMpd::parseState Feb 25 09:52:44 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 25 09:52:44 volumio volumio[1234]: info: Feb 25 09:52:44 volumio volumio[1234]: ---------------------------- MPD announces state update: player Feb 25 09:52:44 volumio volumio[1234]: info: ControllerMpd::getState Feb 25 09:52:44 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Feb 25 09:52:44 volumio volumio[1234]: info: Feb 25 09:52:44 volumio volumio[1234]: ---------------------------- MPD announces state update: player Feb 25 09:52:44 volumio volumio[1234]: info: ControllerMpd::getState Feb 25 09:52:44 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Feb 25 09:52:44 volumio volumio[1234]: info: sendMpdCommand status took 48 milliseconds Feb 25 09:52:44 volumio volumio[1234]: info: sendMpdCommand status took 42 milliseconds Feb 25 09:52:44 volumio volumio[1234]: info: sendMpdCommand playlistinfo took 32 milliseconds Feb 25 09:52:44 volumio volumio[1234]: info: sendMpdCommand playlistinfo took 29 milliseconds Feb 25 09:52:44 volumio volumio[1234]: info: sendMpdCommand status took 10 milliseconds Feb 25 09:52:44 volumio volumio[1234]: info: sendMpdCommand status took 5 milliseconds Feb 25 09:52:44 volumio volumio[1234]: verbose: ControllerMpd::parseState Feb 25 09:52:44 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 25 09:52:44 volumio volumio[1234]: verbose: ControllerMpd::parseState Feb 25 09:52:44 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 25 09:52:44 volumio volumio[1234]: verbose: ControllerMpd::parseTrackInfo Feb 25 09:52:44 volumio volumio[1234]: verbose: ControllerMpd::parseTrackInfo Feb 25 09:52:44 volumio volumio[1234]: verbose: ControllerMpd::parseState Feb 25 09:52:44 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 25 09:52:44 volumio volumio[1234]: verbose: ControllerMpd::parseState Feb 25 09:52:44 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 25 09:52:44 volumio volumio[1234]: info: ControllerMpd::pushState Feb 25 09:52:44 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Feb 25 09:52:44 volumio volumio[1234]: info: CorePlayQueue::getTrack 2 Feb 25 09:52:44 volumio volumio[1234]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":349,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file.flac","artist":null,"album":null,"uri":"http://192.168.188.21:32469/object/f2ebb7f3710900f01fc6/file.flac","trackType":"flac"} Feb 25 09:52:44 volumio volumio[1234]: verbose: CURRENT POSITION 2 Feb 25 09:52:44 volumio volumio[1234]: info: CoreStateMachine::syncState stateService play Feb 25 09:52:44 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus stop Feb 25 09:52:44 volumio volumio[1234]: info: ControllerMpd::pushState Feb 25 09:52:44 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Feb 25 09:52:44 volumio volumio[1234]: info: CorePlayQueue::getTrack 2 Feb 25 09:52:44 volumio volumio[1234]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":349,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file.flac","artist":null,"album":null,"uri":"http://192.168.188.21:32469/object/f2ebb7f3710900f01fc6/file.flac","trackType":"flac"} Feb 25 09:52:44 volumio volumio[1234]: verbose: CURRENT POSITION 2 Feb 25 09:52:44 volumio volumio[1234]: info: CoreStateMachine::syncState stateService play Feb 25 09:52:44 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus play Feb 25 09:52:44 volumio volumio[1234]: info: Received an update from plugin. extracting info from payload Feb 25 09:52:44 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:44 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 25 09:52:44 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:44 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:44 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:44 volumio volumio[1234]: info: ------------------------------ 232ms Feb 25 09:52:44 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:44.444+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=0 volume=100 Feb 25 09:52:44 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:44.444+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ebb7f3710900f01fc6/file.flac title=file.flac Feb 25 09:52:44 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:44.472+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=0 volume=100 Feb 25 09:52:44 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:44.472+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ebb7f3710900f01fc6/file.flac title=file.flac Feb 25 09:52:44 volumio volumio[1234]: info: ------------------------------ 282ms Feb 25 09:52:44 volumio volumio[1234]: info: sendMpdCommand playlistinfo took 202 milliseconds Feb 25 09:52:44 volumio volumio[1234]: info: sendMpdCommand playlistinfo took 203 milliseconds Feb 25 09:52:44 volumio volumio[1234]: info: sendMpdCommand playlistinfo took 203 milliseconds Feb 25 09:52:44 volumio volumio[1234]: info: sendMpdCommand playlistinfo took 202 milliseconds Feb 25 09:52:44 volumio volumio[1234]: verbose: ControllerMpd::parseTrackInfo Feb 25 09:52:44 volumio volumio[1234]: verbose: ControllerMpd::parseTrackInfo Feb 25 09:52:44 volumio volumio[1234]: verbose: ControllerMpd::parseTrackInfo Feb 25 09:52:44 volumio volumio[1234]: verbose: ControllerMpd::parseTrackInfo Feb 25 09:52:44 volumio volumio[1234]: info: ControllerMpd::pushState Feb 25 09:52:44 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Feb 25 09:52:44 volumio volumio[1234]: info: CorePlayQueue::getTrack 2 Feb 25 09:52:44 volumio volumio[1234]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":349,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file.flac","artist":null,"album":null,"uri":"http://192.168.188.21:32469/object/f2ebb7f3710900f01fc6/file.flac","trackType":"flac"} Feb 25 09:52:44 volumio volumio[1234]: verbose: CURRENT POSITION 2 Feb 25 09:52:44 volumio volumio[1234]: info: CoreStateMachine::syncState stateService play Feb 25 09:52:44 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus play Feb 25 09:52:44 volumio volumio[1234]: info: Received an update from plugin. extracting info from payload Feb 25 09:52:44 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:44 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:44 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:44 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:44 volumio volumio[1234]: info: ControllerMpd::pushState Feb 25 09:52:44 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Feb 25 09:52:44 volumio volumio[1234]: info: CorePlayQueue::getTrack 2 Feb 25 09:52:44 volumio volumio[1234]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":349,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file.flac","artist":null,"album":null,"uri":"http://192.168.188.21:32469/object/f2ebb7f3710900f01fc6/file.flac","trackType":"flac"} Feb 25 09:52:44 volumio volumio[1234]: verbose: CURRENT POSITION 2 Feb 25 09:52:44 volumio volumio[1234]: info: CoreStateMachine::syncState stateService play Feb 25 09:52:44 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus play Feb 25 09:52:44 volumio volumio[1234]: info: Received an update from plugin. extracting info from payload Feb 25 09:52:44 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:44 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:44 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:44 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:44 volumio volumio[1234]: info: ControllerMpd::pushState Feb 25 09:52:44 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Feb 25 09:52:44 volumio volumio[1234]: info: CorePlayQueue::getTrack 2 Feb 25 09:52:44 volumio volumio[1234]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":349,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file.flac","artist":null,"album":null,"uri":"http://192.168.188.21:32469/object/f2ebb7f3710900f01fc6/file.flac","trackType":"flac"} Feb 25 09:52:44 volumio volumio[1234]: verbose: CURRENT POSITION 2 Feb 25 09:52:44 volumio volumio[1234]: info: CoreStateMachine::syncState stateService play Feb 25 09:52:44 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus play Feb 25 09:52:44 volumio volumio[1234]: info: Received an update from plugin. extracting info from payload Feb 25 09:52:44 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:44 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:44 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:44 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:44 volumio volumio[1234]: info: ControllerMpd::pushState Feb 25 09:52:44 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Feb 25 09:52:44 volumio volumio[1234]: info: CorePlayQueue::getTrack 2 Feb 25 09:52:44 volumio volumio[1234]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":349,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file.flac","artist":null,"album":null,"uri":"http://192.168.188.21:32469/object/f2ebb7f3710900f01fc6/file.flac","trackType":"flac"} Feb 25 09:52:44 volumio volumio[1234]: verbose: CURRENT POSITION 2 Feb 25 09:52:44 volumio volumio[1234]: info: CoreStateMachine::syncState stateService play Feb 25 09:52:44 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus play Feb 25 09:52:44 volumio volumio[1234]: info: Received an update from plugin. extracting info from payload Feb 25 09:52:44 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:44 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:44 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:44 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:44 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:44.839+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=0 volume=100 Feb 25 09:52:44 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:44.840+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ebb7f3710900f01fc6/file.flac title=file.flac Feb 25 09:52:44 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:44.844+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=0 volume=100 Feb 25 09:52:44 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:44.844+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ebb7f3710900f01fc6/file.flac title=file.flac Feb 25 09:52:44 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:44.848+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=0 volume=100 Feb 25 09:52:44 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:44.849+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ebb7f3710900f01fc6/file.flac title=file.flac Feb 25 09:52:44 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:44.852+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=0 volume=100 Feb 25 09:52:44 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:44.852+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ebb7f3710900f01fc6/file.flac title=file.flac Feb 25 09:52:44 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:44.856+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=0 volume=100 Feb 25 09:52:44 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:44.856+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ebb7f3710900f01fc6/file.flac title=file.flac Feb 25 09:52:44 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:44.861+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=0 volume=100 Feb 25 09:52:44 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:44.861+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ebb7f3710900f01fc6/file.flac title=file.flac Feb 25 09:52:44 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:44.864+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=0 volume=100 Feb 25 09:52:44 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:44.865+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ebb7f3710900f01fc6/file.flac title=file.flac Feb 25 09:52:44 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:44.870+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=0 volume=100 Feb 25 09:52:44 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:44.870+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ebb7f3710900f01fc6/file.flac title=file.flac Feb 25 09:52:44 volumio volumio[1234]: info: ------------------------------ 709ms Feb 25 09:52:44 volumio volumio[1234]: info: ------------------------------ 709ms Feb 25 09:52:44 volumio volumio[1234]: info: ------------------------------ 681ms Feb 25 09:52:44 volumio volumio[1234]: info: ------------------------------ 667ms Feb 25 09:52:45 volumio volumio[1234]: info: Feb 25 09:52:45 volumio volumio[1234]: ---------------------------- MPD announces system playlist update Feb 25 09:52:45 volumio volumio[1234]: info: Ignoring MPD Status Update Feb 25 09:52:45 volumio volumio[1234]: info: Feb 25 09:52:45 volumio volumio[1234]: ---------------------------- MPD announces state update: player Feb 25 09:52:45 volumio volumio[1234]: info: ControllerMpd::getState Feb 25 09:52:45 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Feb 25 09:52:45 volumio volumio[1234]: info: Feb 25 09:52:45 volumio volumio[1234]: ---------------------------- MPD announces system playlist update Feb 25 09:52:45 volumio volumio[1234]: info: Ignoring MPD Status Update Feb 25 09:52:45 volumio volumio[1234]: info: Feb 25 09:52:45 volumio volumio[1234]: ---------------------------- MPD announces state update: player Feb 25 09:52:45 volumio volumio[1234]: info: ControllerMpd::getState Feb 25 09:52:45 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Feb 25 09:52:45 volumio volumio[1234]: info: Feb 25 09:52:45 volumio volumio[1234]: ---------------------------- MPD announces system playlist update Feb 25 09:52:45 volumio volumio[1234]: info: Ignoring MPD Status Update Feb 25 09:52:45 volumio volumio[1234]: info: Feb 25 09:52:45 volumio volumio[1234]: ---------------------------- MPD announces state update: player Feb 25 09:52:45 volumio volumio[1234]: info: ControllerMpd::getState Feb 25 09:52:45 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Feb 25 09:52:45 volumio volumio[1234]: info: ------------------------------ 32ms Feb 25 09:52:45 volumio volumio[1234]: info: sendMpdCommand status took 32 milliseconds Feb 25 09:52:45 volumio volumio[1234]: info: ------------------------------ 31ms Feb 25 09:52:45 volumio volumio[1234]: info: sendMpdCommand status took 3 milliseconds Feb 25 09:52:45 volumio volumio[1234]: info: ------------------------------ 3ms Feb 25 09:52:45 volumio volumio[1234]: info: sendMpdCommand status took 2 milliseconds Feb 25 09:52:45 volumio volumio[1234]: verbose: ControllerMpd::parseState Feb 25 09:52:45 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 25 09:52:45 volumio volumio[1234]: verbose: ControllerMpd::parseState Feb 25 09:52:45 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 25 09:52:45 volumio volumio[1234]: verbose: ControllerMpd::parseState Feb 25 09:52:45 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 25 09:52:45 volumio volumio[1234]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 25 09:52:45 volumio volumio[1234]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 25 09:52:45 volumio volumio[1234]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 25 09:52:45 volumio volumio[1234]: verbose: ControllerMpd::parseTrackInfo Feb 25 09:52:45 volumio volumio[1234]: verbose: ControllerMpd::parseTrackInfo Feb 25 09:52:45 volumio volumio[1234]: verbose: ControllerMpd::parseTrackInfo Feb 25 09:52:45 volumio volumio[1234]: info: ControllerMpd::pushState Feb 25 09:52:45 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Feb 25 09:52:45 volumio volumio[1234]: info: CorePlayQueue::getTrack 2 Feb 25 09:52:45 volumio volumio[1234]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1467,"duration":349,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"419 Kbps","isStreaming":false,"title":"I Miss You","artist":"Adele","album":"25","uri":"http://192.168.188.21:32469/object/f2ebb7f3710900f01fc6/file.flac","trackType":"flac"} Feb 25 09:52:45 volumio volumio[1234]: verbose: CURRENT POSITION 2 Feb 25 09:52:45 volumio volumio[1234]: info: CoreStateMachine::syncState stateService play Feb 25 09:52:45 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus play Feb 25 09:52:45 volumio volumio[1234]: info: Received an update from plugin. extracting info from payload Feb 25 09:52:45 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:45 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 25 09:52:45 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:45 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:45 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:45 volumio volumio[1234]: info: ControllerMpd::pushState Feb 25 09:52:45 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Feb 25 09:52:45 volumio volumio[1234]: info: CorePlayQueue::getTrack 2 Feb 25 09:52:45 volumio volumio[1234]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1467,"duration":349,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"419 Kbps","isStreaming":false,"title":"I Miss You","artist":"Adele","album":"25","uri":"http://192.168.188.21:32469/object/f2ebb7f3710900f01fc6/file.flac","trackType":"flac"} Feb 25 09:52:45 volumio volumio[1234]: verbose: CURRENT POSITION 2 Feb 25 09:52:45 volumio volumio[1234]: info: CoreStateMachine::syncState stateService play Feb 25 09:52:45 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus play Feb 25 09:52:45 volumio volumio[1234]: info: Received an update from plugin. extracting info from payload Feb 25 09:52:45 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:45 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:45 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:45 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:45 volumio volumio[1234]: info: ControllerMpd::pushState Feb 25 09:52:45 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Feb 25 09:52:45 volumio volumio[1234]: info: CorePlayQueue::getTrack 2 Feb 25 09:52:45 volumio volumio[1234]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1467,"duration":349,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"419 Kbps","isStreaming":false,"title":"I Miss You","artist":"Adele","album":"25","uri":"http://192.168.188.21:32469/object/f2ebb7f3710900f01fc6/file.flac","trackType":"flac"} Feb 25 09:52:45 volumio volumio[1234]: verbose: CURRENT POSITION 2 Feb 25 09:52:45 volumio volumio[1234]: info: CoreStateMachine::syncState stateService play Feb 25 09:52:45 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus play Feb 25 09:52:45 volumio volumio[1234]: info: Received an update from plugin. extracting info from payload Feb 25 09:52:45 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:45 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:45 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:52:45 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:52:45 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:45.293+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=863 volume=100 Feb 25 09:52:45 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:45.294+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ebb7f3710900f01fc6/file.flac title="I Miss You" Feb 25 09:52:45 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:45.294+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=863 volume=100 Feb 25 09:52:45 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:45.294+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ebb7f3710900f01fc6/file.flac title="I Miss You" Feb 25 09:52:45 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:45.294+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=863 volume=100 Feb 25 09:52:45 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:45.294+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ebb7f3710900f01fc6/file.flac title="I Miss You" Feb 25 09:52:45 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:45.295+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=863 volume=100 Feb 25 09:52:45 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:45.295+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ebb7f3710900f01fc6/file.flac title="I Miss You" Feb 25 09:52:45 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:45.295+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=863 volume=100 Feb 25 09:52:45 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:45.295+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ebb7f3710900f01fc6/file.flac title="I Miss You" Feb 25 09:52:45 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:45.295+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=863 volume=100 Feb 25 09:52:45 volumio volumio5-onboarding[1545]: time=2026-02-25T09:52:45.295+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ebb7f3710900f01fc6/file.flac title="I Miss You" Feb 25 09:52:45 volumio volumio[1234]: info: ------------------------------ 272ms Feb 25 09:52:45 volumio volumio[1234]: info: ------------------------------ 271ms Feb 25 09:52:45 volumio volumio[1234]: info: ------------------------------ 244ms Feb 25 09:52:45 volumio volumio[1234]: info: CoreCommandRouter::volumioGetQueue Feb 25 09:52:45 volumio volumio[1234]: info: CoreStateMachine::getQueue Feb 25 09:52:45 volumio volumio[1234]: info: CorePlayQueue::getQueue Feb 25 09:52:45 volumio volumio[1234]: info: CoreCommandRouter::volumioGetQueue Feb 25 09:52:45 volumio volumio[1234]: info: CoreStateMachine::getQueue Feb 25 09:52:45 volumio volumio[1234]: info: CorePlayQueue::getQueue Feb 25 09:52:45 volumio volumio[1234]: info: CoreCommandRouter::volumioGetQueue Feb 25 09:52:45 volumio volumio[1234]: info: CoreStateMachine::getQueue Feb 25 09:52:45 volumio volumio[1234]: info: CorePlayQueue::getQueue Feb 25 09:52:45 volumio volumio[1234]: info: CoreCommandRouter::volumioGetQueue Feb 25 09:52:45 volumio volumio[1234]: info: CoreStateMachine::getQueue Feb 25 09:52:45 volumio volumio[1234]: info: CorePlayQueue::getQueue Feb 25 09:52:45 volumio volumio[1234]: info: CoreCommandRouter::volumioGetQueue Feb 25 09:52:45 volumio volumio[1234]: info: CoreStateMachine::getQueue Feb 25 09:52:45 volumio volumio[1234]: info: CorePlayQueue::getQueue Feb 25 09:52:45 volumio volumio[1234]: info: CoreCommandRouter::volumioGetQueue Feb 25 09:52:45 volumio volumio[1234]: info: CoreStateMachine::getQueue Feb 25 09:52:45 volumio volumio[1234]: info: CorePlayQueue::getQueue Feb 25 09:53:01 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Feb 25 09:53:07 volumio volumio[1234]: info: Preload queue cleared Feb 25 09:53:07 volumio volumio[1234]: info: Preloading song: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@60c1babc814e13889f9a Feb 25 09:53:07 volumio volumio[1234]: info: Preloading song: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@81dfb1717385367e7e23 Feb 25 09:53:07 volumio volumio[1234]: info: Preloading song: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@6284cb03615f0cd36dce Feb 25 09:53:07 volumio volumio[1234]: info: Preloading song: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@f2ef3ce84976702d2eaa Feb 25 09:53:07 volumio volumio[1234]: info: Preloading song: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@89b21936fa239a404988 Feb 25 09:53:07 volumio volumio[1234]: info: Preloading song: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@0fb30366957ee6943136 Feb 25 09:53:07 volumio volumio[1234]: info: Preloading song: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@b49d7fbd2aaee2c41881 Feb 25 09:53:07 volumio volumio[1234]: info: Preloading song: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@5736df801024da0fedd3 Feb 25 09:53:07 volumio volumio[1234]: info: Preloading song: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@d95849036ab4e91266f4 Feb 25 09:53:07 volumio volumio[1234]: info: Preloading song: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@56c151d9478358140f4d Feb 25 09:53:07 volumio volumio[1234]: info: Preloading song: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@2bf9069ff88a3e1649bf Feb 25 09:53:07 volumio volumio[1234]: info: Exploding uri upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@60c1babc814e13889f9a in service upnp_browser Feb 25 09:53:07 volumio volumio[1234]: info: Exploding uri upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@81dfb1717385367e7e23 in service upnp_browser Feb 25 09:53:07 volumio volumio[1234]: info: Exploding uri upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@6284cb03615f0cd36dce in service upnp_browser Feb 25 09:53:07 volumio volumio[1234]: info: Exploding uri upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@f2ef3ce84976702d2eaa in service upnp_browser Feb 25 09:53:07 volumio volumio[1234]: info: Exploding uri upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@89b21936fa239a404988 in service upnp_browser Feb 25 09:53:07 volumio volumio[1234]: info: Exploding uri upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@0fb30366957ee6943136 in service upnp_browser Feb 25 09:53:07 volumio volumio[1234]: info: Exploding uri upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@b49d7fbd2aaee2c41881 in service upnp_browser Feb 25 09:53:08 volumio volumio[1234]: info: Exploding uri upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@5736df801024da0fedd3 in service upnp_browser Feb 25 09:53:08 volumio volumio[1234]: info: Exploding uri upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@d95849036ab4e91266f4 in service upnp_browser Feb 25 09:53:08 volumio volumio[1234]: info: Exploding uri upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@56c151d9478358140f4d in service upnp_browser Feb 25 09:53:08 volumio volumio[1234]: info: Exploding uri upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@2bf9069ff88a3e1649bf in service upnp_browser Feb 25 09:53:14 volumio volumio[1234]: info: No valid Plugin REST Endpoint Feb 25 09:53:17 volumio volumio[1234]: info: Preload queue cleared Feb 25 09:53:17 volumio volumio[1234]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 25 09:53:17 volumio volumio[1234]: info: CoreStateMachine::ClearQueue Feb 25 09:53:17 volumio volumio[1234]: info: CoreStateMachine::stop Feb 25 09:53:17 volumio volumio[1234]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 25 09:53:17 volumio volumio[1234]: info: CoreStateMachine::stPlaybackTimer Feb 25 09:53:17 volumio volumio[1234]: info: CoreStateMachine::updateTrackBlock Feb 25 09:53:17 volumio volumio[1234]: info: CorePlayQueue::getTrackBlock Feb 25 09:53:17 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:53:17 volumio volumio[1234]: info: CorePlayQueue::getTrack 2 Feb 25 09:53:17 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 25 09:53:17 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:53:17 volumio volumio[1234]: info: CoreStateMachine::serviceStop Feb 25 09:53:17 volumio volumio[1234]: info: CorePlayQueue::getTrack 2 Feb 25 09:53:17 volumio volumio[1234]: info: CoreCommandRouter::serviceStop Feb 25 09:53:17 volumio volumio[1234]: info: [1772009597623] ControllerUPNPBrowser::stop Feb 25 09:53:17 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand stop Feb 25 09:53:17 volumio volumio[1234]: info: CorePlayQueue::clearPlayQueue Feb 25 09:53:17 volumio volumio[1234]: info: CorePlayQueue::saveQueue Feb 25 09:53:17 volumio volumio[1234]: info: CoreCommandRouter::volumioPushQueue Feb 25 09:53:17 volumio volumio[1234]: info: CoreStateMachine::addQueueItems Feb 25 09:53:17 volumio volumio[1234]: info: CorePlayQueue::addQueueItems Feb 25 09:53:17 volumio volumio[1234]: info: Preload queue cleared Feb 25 09:53:17 volumio volumio[1234]: info: Adding Item to queue: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@60c1babc814e13889f9a Feb 25 09:53:17 volumio volumio[1234]: info: Using cached record of: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@60c1babc814e13889f9a Feb 25 09:53:17 volumio volumio[1234]: info: Adding Item to queue: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@81dfb1717385367e7e23 Feb 25 09:53:17 volumio volumio[1234]: info: Using cached record of: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@81dfb1717385367e7e23 Feb 25 09:53:17 volumio volumio[1234]: info: Adding Item to queue: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@6284cb03615f0cd36dce Feb 25 09:53:17 volumio volumio[1234]: info: Using cached record of: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@6284cb03615f0cd36dce Feb 25 09:53:17 volumio volumio[1234]: info: Adding Item to queue: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@f2ef3ce84976702d2eaa Feb 25 09:53:17 volumio volumio[1234]: info: Using cached record of: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@f2ef3ce84976702d2eaa Feb 25 09:53:17 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:17.627+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_STOPPED positionMs=0 volume=100 Feb 25 09:53:17 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:17.627+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ebb7f3710900f01fc6/file.flac title="I Miss You" Feb 25 09:53:17 volumio volumio[1234]: info: CoreCommandRouter::volumioPushQueue Feb 25 09:53:17 volumio volumio[1234]: info: CorePlayQueue::saveQueue Feb 25 09:53:17 volumio volumio[1234]: info: CoreStateMachine::updateTrackBlock Feb 25 09:53:17 volumio volumio[1234]: info: CorePlayQueue::getTrackBlock Feb 25 09:53:17 volumio volumio[1234]: info: CoreCommandRouter::volumioPlay Feb 25 09:53:17 volumio volumio[1234]: info: CoreStateMachine::play index 3 Feb 25 09:53:17 volumio volumio[1234]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 25 09:53:17 volumio volumio[1234]: info: CoreStateMachine::addQueueItems Feb 25 09:53:17 volumio volumio[1234]: info: CorePlayQueue::addQueueItems Feb 25 09:53:17 volumio volumio[1234]: info: Preload queue cleared Feb 25 09:53:17 volumio volumio[1234]: info: Adding Item to queue: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@89b21936fa239a404988 Feb 25 09:53:17 volumio volumio[1234]: info: Using cached record of: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@89b21936fa239a404988 Feb 25 09:53:17 volumio volumio[1234]: info: Adding Item to queue: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@0fb30366957ee6943136 Feb 25 09:53:17 volumio volumio[1234]: info: Using cached record of: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@0fb30366957ee6943136 Feb 25 09:53:17 volumio volumio[1234]: info: Adding Item to queue: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@b49d7fbd2aaee2c41881 Feb 25 09:53:17 volumio volumio[1234]: info: Using cached record of: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@b49d7fbd2aaee2c41881 Feb 25 09:53:17 volumio volumio[1234]: info: Adding Item to queue: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@5736df801024da0fedd3 Feb 25 09:53:17 volumio volumio[1234]: info: Using cached record of: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@5736df801024da0fedd3 Feb 25 09:53:17 volumio volumio[1234]: info: Adding Item to queue: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@d95849036ab4e91266f4 Feb 25 09:53:17 volumio volumio[1234]: info: Using cached record of: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@d95849036ab4e91266f4 Feb 25 09:53:17 volumio volumio[1234]: info: Adding Item to queue: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@56c151d9478358140f4d Feb 25 09:53:17 volumio volumio[1234]: info: Using cached record of: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@56c151d9478358140f4d Feb 25 09:53:17 volumio volumio[1234]: info: Adding Item to queue: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@2bf9069ff88a3e1649bf Feb 25 09:53:17 volumio volumio[1234]: info: Using cached record of: upnp/http://192.168.188.21:32469/ContentDirectory/06ef1e56-8584-0ec7-9992-54676a49a89e/control.xml@2bf9069ff88a3e1649bf Feb 25 09:53:17 volumio volumio[1234]: info: CoreStateMachine::stop Feb 25 09:53:17 volumio volumio[1234]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 25 09:53:17 volumio volumio[1234]: info: CoreCommandRouter::volumioPushQueue Feb 25 09:53:17 volumio volumio[1234]: info: CorePlayQueue::saveQueue Feb 25 09:53:17 volumio volumio[1234]: info: CoreStateMachine::play index undefined Feb 25 09:53:17 volumio volumio[1234]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 25 09:53:17 volumio volumio[1234]: info: CoreStateMachine::updateTrackBlock Feb 25 09:53:17 volumio volumio[1234]: info: CorePlayQueue::getTrackBlock Feb 25 09:53:17 volumio volumio[1234]: info: CorePlayQueue::getTrack 3 Feb 25 09:53:17 volumio volumio[1234]: info: CoreStateMachine::startPlaybackTimer Feb 25 09:53:17 volumio volumio[1234]: info: CorePlayQueue::getTrack 3 Feb 25 09:53:17 volumio volumio[1234]: info: [1772009597643] ControllerUPNPBrowser::clearAddPlayTrack Feb 25 09:53:17 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand stop Feb 25 09:53:17 volumio volumio[1234]: info: Feb 25 09:53:17 volumio volumio[1234]: ---------------------------- MPD announces state update: player Feb 25 09:53:17 volumio volumio[1234]: info: sendMpdCommand stop took 26 milliseconds Feb 25 09:53:17 volumio volumio[1234]: info: ControllerMpd::getState Feb 25 09:53:17 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Feb 25 09:53:17 volumio volumio[1234]: info: sendMpdCommand stop took 6 milliseconds Feb 25 09:53:17 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand clear Feb 25 09:53:17 volumio volumio[1234]: info: Feb 25 09:53:17 volumio volumio[1234]: ---------------------------- MPD announces state update: player Feb 25 09:53:17 volumio volumio[1234]: info: ControllerMpd::getState Feb 25 09:53:17 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Feb 25 09:53:17 volumio volumio[1234]: info: Feb 25 09:53:17 volumio volumio[1234]: ---------------------------- MPD announces state update: player Feb 25 09:53:17 volumio volumio[1234]: info: ControllerMpd::getState Feb 25 09:53:17 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Feb 25 09:53:17 volumio volumio[1234]: info: Feb 25 09:53:17 volumio volumio[1234]: ---------------------------- MPD announces system playlist update Feb 25 09:53:17 volumio volumio[1234]: info: Ignoring MPD Status Update Feb 25 09:53:17 volumio volumio[1234]: info: sendMpdCommand status took 4 milliseconds Feb 25 09:53:17 volumio volumio[1234]: info: sendMpdCommand clear took 3 milliseconds Feb 25 09:53:17 volumio volumio[1234]: info: sendMpdCommand status took 4 milliseconds Feb 25 09:53:17 volumio volumio[1234]: info: sendMpdCommand status took 3 milliseconds Feb 25 09:53:17 volumio volumio[1234]: verbose: ControllerMpd::parseState Feb 25 09:53:17 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 25 09:53:17 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.188.21:32469/object/f2ef3ce84976702d2eaa/file.flac" Feb 25 09:53:17 volumio volumio[1234]: verbose: ControllerMpd::parseState Feb 25 09:53:17 volumio volumio[1234]: verbose: ControllerMpd::parseState Feb 25 09:53:17 volumio volumio[1234]: info: ControllerMpd::pushState Feb 25 09:53:17 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Feb 25 09:53:17 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:53:17 volumio volumio[1234]: info: CorePlayQueue::getTrack 3 Feb 25 09:53:17 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 25 09:53:17 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:53:17 volumio volumio[1234]: info: CorePlayQueue::getTrack 3 Feb 25 09:53:17 volumio volumio[1234]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Feb 25 09:53:17 volumio volumio[1234]: verbose: CURRENT POSITION 3 Feb 25 09:53:17 volumio volumio[1234]: info: CoreStateMachine::syncState stateService stop Feb 25 09:53:17 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus stop Feb 25 09:53:17 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:53:17 volumio volumio[1234]: info: CorePlayQueue::getTrack 3 Feb 25 09:53:17 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:53:17 volumio volumio[1234]: info: No code Feb 25 09:53:17 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:53:17 volumio volumio[1234]: info: CorePlayQueue::getTrack 3 Feb 25 09:53:17 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:53:17 volumio volumio[1234]: info: ControllerMpd::pushState Feb 25 09:53:17 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Feb 25 09:53:17 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:53:17 volumio volumio[1234]: info: CorePlayQueue::getTrack 3 Feb 25 09:53:17 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:53:17 volumio volumio[1234]: info: CorePlayQueue::getTrack 3 Feb 25 09:53:17 volumio volumio[1234]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Feb 25 09:53:17 volumio volumio[1234]: verbose: CURRENT POSITION 3 Feb 25 09:53:17 volumio volumio[1234]: info: CoreStateMachine::syncState stateService stop Feb 25 09:53:17 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus stop Feb 25 09:53:17 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:53:17 volumio volumio[1234]: info: CorePlayQueue::getTrack 3 Feb 25 09:53:17 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:53:17 volumio volumio[1234]: info: No code Feb 25 09:53:17 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:53:17 volumio volumio[1234]: info: CorePlayQueue::getTrack 3 Feb 25 09:53:17 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:53:17 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:17.678+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_STOPPED positionMs=0 volume=100 Feb 25 09:53:17 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:17.679+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ef3ce84976702d2eaa/file.flac title="Don’t You Remember" Feb 25 09:53:17 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:17.685+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_STOPPED positionMs=0 volume=100 Feb 25 09:53:17 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:17.686+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ef3ce84976702d2eaa/file.flac title="Don’t You Remember" Feb 25 09:53:17 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:17.687+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_STOPPED positionMs=0 volume=100 Feb 25 09:53:17 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:17.687+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ef3ce84976702d2eaa/file.flac title="Don’t You Remember" Feb 25 09:53:17 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:17.689+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_STOPPED positionMs=0 volume=100 Feb 25 09:53:17 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:17.690+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ef3ce84976702d2eaa/file.flac title="Don’t You Remember" Feb 25 09:53:17 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:17.692+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_STOPPED positionMs=0 volume=100 Feb 25 09:53:17 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:17.692+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ef3ce84976702d2eaa/file.flac title="Don’t You Remember" Feb 25 09:53:17 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:17.693+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_STOPPED positionMs=0 volume=100 Feb 25 09:53:17 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:17.693+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ef3ce84976702d2eaa/file.flac title="Don’t You Remember" Feb 25 09:53:17 volumio volumio[1234]: info: ------------------------------ 58ms Feb 25 09:53:17 volumio volumio[1234]: info: ------------------------------ 58ms Feb 25 09:53:17 volumio volumio[1234]: info: Feb 25 09:53:17 volumio volumio[1234]: ---------------------------- MPD announces system playlist update Feb 25 09:53:17 volumio volumio[1234]: info: Ignoring MPD Status Update Feb 25 09:53:17 volumio volumio[1234]: info: Feb 25 09:53:17 volumio volumio[1234]: ---------------------------- MPD announces system playlist update Feb 25 09:53:17 volumio volumio[1234]: info: Ignoring MPD Status Update Feb 25 09:53:17 volumio volumio[1234]: error: updateQueue error: null Feb 25 09:53:17 volumio volumio[1234]: info: ------------------------------ 61ms Feb 25 09:53:17 volumio volumio[1234]: info: sendMpdCommand playlistinfo took 59 milliseconds Feb 25 09:53:17 volumio volumio[1234]: verbose: ControllerMpd::parseTrackInfo Feb 25 09:53:17 volumio volumio[1234]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Feb 25 09:53:17 volumio volumio[1234]: info: ------------------------------ 65ms Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.188.21:32469/object/f2ef3ce84976702d2eaa/file.flac" Feb 25 09:53:18 volumio volumio[1234]: error: updateQueue error: null Feb 25 09:53:18 volumio volumio[1234]: error: updateQueue error: null Feb 25 09:53:18 volumio volumio[1234]: info: Feb 25 09:53:18 volumio volumio[1234]: ---------------------------- MPD announces system playlist update Feb 25 09:53:18 volumio volumio[1234]: info: Ignoring MPD Status Update Feb 25 09:53:18 volumio volumio[1234]: info: ------------------------------ 580ms Feb 25 09:53:18 volumio volumio[1234]: info: ------------------------------ 580ms Feb 25 09:53:18 volumio volumio[1234]: info: sendMpdCommand add "http://192.168.188.21:32469/object/f2ef3ce84976702d2eaa/file.flac" took 2 milliseconds Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand play Feb 25 09:53:18 volumio volumio[1234]: info: ------------------------------ 2ms Feb 25 09:53:18 volumio volumio[1234]: info: Feb 25 09:53:18 volumio volumio[1234]: ---------------------------- MPD announces system playlist update Feb 25 09:53:18 volumio volumio[1234]: info: Ignoring MPD Status Update Feb 25 09:53:18 volumio volumio[1234]: info: Feb 25 09:53:18 volumio volumio[1234]: ---------------------------- MPD announces system playlist update Feb 25 09:53:18 volumio volumio[1234]: info: Ignoring MPD Status Update Feb 25 09:53:18 volumio volumio[1234]: info: sendMpdCommand play took 2 milliseconds Feb 25 09:53:18 volumio volumio[1234]: info: ------------------------------ 2ms Feb 25 09:53:18 volumio volumio[1234]: info: ------------------------------ 1ms Feb 25 09:53:18 volumio volumio[1234]: info: Feb 25 09:53:18 volumio volumio[1234]: ---------------------------- MPD announces state update: player Feb 25 09:53:18 volumio volumio[1234]: info: ControllerMpd::getState Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Feb 25 09:53:18 volumio volumio[1234]: info: Feb 25 09:53:18 volumio volumio[1234]: ---------------------------- MPD announces state update: player Feb 25 09:53:18 volumio volumio[1234]: info: ControllerMpd::getState Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Feb 25 09:53:18 volumio volumio[1234]: info: Feb 25 09:53:18 volumio volumio[1234]: ---------------------------- MPD announces state update: player Feb 25 09:53:18 volumio volumio[1234]: info: ControllerMpd::getState Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Feb 25 09:53:18 volumio volumio[1234]: info: sendMpdCommand status took 11 milliseconds Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::parseState Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 25 09:53:18 volumio volumio[1234]: info: Feb 25 09:53:18 volumio volumio[1234]: ---------------------------- MPD announces state update: player Feb 25 09:53:18 volumio volumio[1234]: info: ControllerMpd::getState Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Feb 25 09:53:18 volumio volumio[1234]: info: Feb 25 09:53:18 volumio volumio[1234]: ---------------------------- MPD announces state update: player Feb 25 09:53:18 volumio volumio[1234]: info: ControllerMpd::getState Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Feb 25 09:53:18 volumio volumio[1234]: info: sendMpdCommand status took 13 milliseconds Feb 25 09:53:18 volumio volumio[1234]: info: sendMpdCommand status took 12 milliseconds Feb 25 09:53:18 volumio volumio[1234]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 25 09:53:18 volumio volumio[1234]: info: sendMpdCommand status took 2 milliseconds Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::parseState Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::parseState Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::parseTrackInfo Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::parseState Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 25 09:53:18 volumio volumio[1234]: info: ControllerMpd::pushState Feb 25 09:53:18 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Feb 25 09:53:18 volumio volumio[1234]: info: CorePlayQueue::getTrack 3 Feb 25 09:53:18 volumio volumio[1234]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":242,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file.flac","artist":null,"album":null,"uri":"http://192.168.188.21:32469/object/f2ef3ce84976702d2eaa/file.flac","trackType":"flac"} Feb 25 09:53:18 volumio volumio[1234]: verbose: CURRENT POSITION 3 Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::syncState stateService play Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus stop Feb 25 09:53:18 volumio volumio[1234]: info: ------------------------------ 17ms Feb 25 09:53:18 volumio volumio[1234]: info: Feb 25 09:53:18 volumio volumio[1234]: ---------------------------- MPD announces state update: player Feb 25 09:53:18 volumio volumio[1234]: info: ControllerMpd::getState Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Feb 25 09:53:18 volumio volumio[1234]: info: sendMpdCommand status took 5 milliseconds Feb 25 09:53:18 volumio volumio[1234]: info: sendMpdCommand playlistinfo took 4 milliseconds Feb 25 09:53:18 volumio volumio[1234]: info: sendMpdCommand playlistinfo took 4 milliseconds Feb 25 09:53:18 volumio volumio[1234]: info: sendMpdCommand playlistinfo took 5 milliseconds Feb 25 09:53:18 volumio volumio[1234]: info: sendMpdCommand status took 2 milliseconds Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::parseState Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::parseTrackInfo Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::parseTrackInfo Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::parseTrackInfo Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::parseState Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 25 09:53:18 volumio volumio[1234]: info: ControllerMpd::pushState Feb 25 09:53:18 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Feb 25 09:53:18 volumio volumio[1234]: info: CorePlayQueue::getTrack 3 Feb 25 09:53:18 volumio volumio[1234]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":242,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file.flac","artist":null,"album":null,"uri":"http://192.168.188.21:32469/object/f2ef3ce84976702d2eaa/file.flac","trackType":"flac"} Feb 25 09:53:18 volumio volumio[1234]: verbose: CURRENT POSITION 3 Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::syncState stateService play Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus play Feb 25 09:53:18 volumio volumio[1234]: info: Received an update from plugin. extracting info from payload Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:53:18 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 25 09:53:18 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:53:18 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:53:18 volumio volumio[1234]: info: ControllerMpd::pushState Feb 25 09:53:18 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Feb 25 09:53:18 volumio volumio[1234]: info: CorePlayQueue::getTrack 3 Feb 25 09:53:18 volumio volumio[1234]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":242,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file.flac","artist":null,"album":null,"uri":"http://192.168.188.21:32469/object/f2ef3ce84976702d2eaa/file.flac","trackType":"flac"} Feb 25 09:53:18 volumio volumio[1234]: verbose: CURRENT POSITION 3 Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::syncState stateService play Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus play Feb 25 09:53:18 volumio volumio[1234]: info: Received an update from plugin. extracting info from payload Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:53:18 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:53:18 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:53:18 volumio volumio[1234]: info: ControllerMpd::pushState Feb 25 09:53:18 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Feb 25 09:53:18 volumio volumio[1234]: info: CorePlayQueue::getTrack 3 Feb 25 09:53:18 volumio volumio[1234]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":242,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file.flac","artist":null,"album":null,"uri":"http://192.168.188.21:32469/object/f2ef3ce84976702d2eaa/file.flac","trackType":"flac"} Feb 25 09:53:18 volumio volumio[1234]: verbose: CURRENT POSITION 3 Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::syncState stateService play Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus play Feb 25 09:53:18 volumio volumio[1234]: info: Received an update from plugin. extracting info from payload Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:53:18 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:53:18 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:53:18 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:18.521+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=0 volume=100 Feb 25 09:53:18 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:18.522+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ef3ce84976702d2eaa/file.flac title=file.flac Feb 25 09:53:18 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:18.523+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=0 volume=100 Feb 25 09:53:18 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:18.523+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ef3ce84976702d2eaa/file.flac title=file.flac Feb 25 09:53:18 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:18.524+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=0 volume=100 Feb 25 09:53:18 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:18.525+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ef3ce84976702d2eaa/file.flac title=file.flac Feb 25 09:53:18 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:18.526+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=0 volume=100 Feb 25 09:53:18 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:18.526+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ef3ce84976702d2eaa/file.flac title=file.flac Feb 25 09:53:18 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:18.527+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=0 volume=100 Feb 25 09:53:18 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:18.528+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ef3ce84976702d2eaa/file.flac title=file.flac Feb 25 09:53:18 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:18.528+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=0 volume=100 Feb 25 09:53:18 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:18.529+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ef3ce84976702d2eaa/file.flac title=file.flac Feb 25 09:53:18 volumio volumio[1234]: info: ------------------------------ 63ms Feb 25 09:53:18 volumio volumio[1234]: info: ------------------------------ 63ms Feb 25 09:53:18 volumio volumio[1234]: info: ------------------------------ 53ms Feb 25 09:53:18 volumio volumio[1234]: info: sendMpdCommand playlistinfo took 47 milliseconds Feb 25 09:53:18 volumio volumio[1234]: info: sendMpdCommand playlistinfo took 46 milliseconds Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::parseTrackInfo Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::parseTrackInfo Feb 25 09:53:18 volumio volumio[1234]: info: ControllerMpd::pushState Feb 25 09:53:18 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Feb 25 09:53:18 volumio volumio[1234]: info: CorePlayQueue::getTrack 3 Feb 25 09:53:18 volumio volumio[1234]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":242,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file.flac","artist":null,"album":null,"uri":"http://192.168.188.21:32469/object/f2ef3ce84976702d2eaa/file.flac","trackType":"flac"} Feb 25 09:53:18 volumio volumio[1234]: verbose: CURRENT POSITION 3 Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::syncState stateService play Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus play Feb 25 09:53:18 volumio volumio[1234]: info: Received an update from plugin. extracting info from payload Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:53:18 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 25 09:53:18 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:53:18 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:53:18 volumio volumio[1234]: info: ControllerMpd::pushState Feb 25 09:53:18 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Feb 25 09:53:18 volumio volumio[1234]: info: CorePlayQueue::getTrack 3 Feb 25 09:53:18 volumio volumio[1234]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":242,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file.flac","artist":null,"album":null,"uri":"http://192.168.188.21:32469/object/f2ef3ce84976702d2eaa/file.flac","trackType":"flac"} Feb 25 09:53:18 volumio volumio[1234]: verbose: CURRENT POSITION 3 Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::syncState stateService play Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus play Feb 25 09:53:18 volumio volumio[1234]: info: Received an update from plugin. extracting info from payload Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:53:18 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:53:18 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:53:18 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:18.563+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=153 volume=100 Feb 25 09:53:18 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:18.563+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ef3ce84976702d2eaa/file.flac title=file.flac Feb 25 09:53:18 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:18.563+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=153 volume=100 Feb 25 09:53:18 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:18.564+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ef3ce84976702d2eaa/file.flac title=file.flac Feb 25 09:53:18 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:18.565+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=153 volume=100 Feb 25 09:53:18 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:18.565+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ef3ce84976702d2eaa/file.flac title=file.flac Feb 25 09:53:18 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:18.566+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=153 volume=100 Feb 25 09:53:18 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:18.566+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ef3ce84976702d2eaa/file.flac title=file.flac Feb 25 09:53:18 volumio volumio[1234]: info: ------------------------------ 79ms Feb 25 09:53:18 volumio volumio[1234]: info: ------------------------------ 77ms Feb 25 09:53:18 volumio volumio[1234]: info: Feb 25 09:53:18 volumio volumio[1234]: ---------------------------- MPD announces system playlist update Feb 25 09:53:18 volumio volumio[1234]: info: Ignoring MPD Status Update Feb 25 09:53:18 volumio volumio[1234]: info: Feb 25 09:53:18 volumio volumio[1234]: ---------------------------- MPD announces state update: player Feb 25 09:53:18 volumio volumio[1234]: info: ControllerMpd::getState Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Feb 25 09:53:18 volumio volumio[1234]: info: Feb 25 09:53:18 volumio volumio[1234]: ---------------------------- MPD announces system playlist update Feb 25 09:53:18 volumio volumio[1234]: info: Ignoring MPD Status Update Feb 25 09:53:18 volumio volumio[1234]: info: Feb 25 09:53:18 volumio volumio[1234]: ---------------------------- MPD announces state update: player Feb 25 09:53:18 volumio volumio[1234]: info: ControllerMpd::getState Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Feb 25 09:53:18 volumio volumio[1234]: info: Feb 25 09:53:18 volumio volumio[1234]: ---------------------------- MPD announces system playlist update Feb 25 09:53:18 volumio volumio[1234]: info: Ignoring MPD Status Update Feb 25 09:53:18 volumio volumio[1234]: info: Feb 25 09:53:18 volumio volumio[1234]: ---------------------------- MPD announces state update: player Feb 25 09:53:18 volumio volumio[1234]: info: ControllerMpd::getState Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Feb 25 09:53:18 volumio volumio[1234]: info: ------------------------------ 3ms Feb 25 09:53:18 volumio volumio[1234]: info: sendMpdCommand status took 4 milliseconds Feb 25 09:53:18 volumio volumio[1234]: info: ------------------------------ 4ms Feb 25 09:53:18 volumio volumio[1234]: info: sendMpdCommand status took 3 milliseconds Feb 25 09:53:18 volumio volumio[1234]: info: ------------------------------ 3ms Feb 25 09:53:18 volumio volumio[1234]: info: sendMpdCommand status took 2 milliseconds Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::parseState Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::parseState Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::parseState Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 25 09:53:18 volumio volumio[1234]: info: sendMpdCommand playlistinfo took 2 milliseconds Feb 25 09:53:18 volumio volumio[1234]: info: sendMpdCommand playlistinfo took 2 milliseconds Feb 25 09:53:18 volumio volumio[1234]: info: sendMpdCommand playlistinfo took 2 milliseconds Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::parseTrackInfo Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::parseTrackInfo Feb 25 09:53:18 volumio volumio[1234]: verbose: ControllerMpd::parseTrackInfo Feb 25 09:53:18 volumio volumio[1234]: info: ControllerMpd::pushState Feb 25 09:53:18 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Feb 25 09:53:18 volumio volumio[1234]: info: CorePlayQueue::getTrack 3 Feb 25 09:53:18 volumio volumio[1234]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":242,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"490 Kbps","isStreaming":false,"title":"Don't You Remember","artist":"Adele","album":"21","uri":"http://192.168.188.21:32469/object/f2ef3ce84976702d2eaa/file.flac","trackType":"flac"} Feb 25 09:53:18 volumio volumio[1234]: verbose: CURRENT POSITION 3 Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::syncState stateService play Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus play Feb 25 09:53:18 volumio volumio[1234]: info: Received an update from plugin. extracting info from payload Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:53:18 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 25 09:53:18 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:53:18 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:53:18 volumio volumio[1234]: info: ControllerMpd::pushState Feb 25 09:53:18 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Feb 25 09:53:18 volumio volumio[1234]: info: CorePlayQueue::getTrack 3 Feb 25 09:53:18 volumio volumio[1234]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":242,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"490 Kbps","isStreaming":false,"title":"Don't You Remember","artist":"Adele","album":"21","uri":"http://192.168.188.21:32469/object/f2ef3ce84976702d2eaa/file.flac","trackType":"flac"} Feb 25 09:53:18 volumio volumio[1234]: verbose: CURRENT POSITION 3 Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::syncState stateService play Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus play Feb 25 09:53:18 volumio volumio[1234]: info: Received an update from plugin. extracting info from payload Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:53:18 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:53:18 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:53:18 volumio volumio[1234]: info: ControllerMpd::pushState Feb 25 09:53:18 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Feb 25 09:53:18 volumio volumio[1234]: info: CorePlayQueue::getTrack 3 Feb 25 09:53:18 volumio volumio[1234]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":242,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"725 Kbps","isStreaming":false,"title":"Don't You Remember","artist":"Adele","album":"21","uri":"http://192.168.188.21:32469/object/f2ef3ce84976702d2eaa/file.flac","trackType":"flac"} Feb 25 09:53:18 volumio volumio[1234]: verbose: CURRENT POSITION 3 Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::syncState stateService play Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus play Feb 25 09:53:18 volumio volumio[1234]: info: Received an update from plugin. extracting info from payload Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:53:18 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 25 09:53:18 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::pushState Feb 25 09:53:18 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Feb 25 09:53:18 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:18.851+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=404 volume=100 Feb 25 09:53:18 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:18.852+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=404 volume=100 Feb 25 09:53:18 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:18.852+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ef3ce84976702d2eaa/file.flac title="Don't You Remember" Feb 25 09:53:18 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:18.852+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ef3ce84976702d2eaa/file.flac title="Don't You Remember" Feb 25 09:53:18 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:18.853+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=404 volume=100 Feb 25 09:53:18 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:18.854+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ef3ce84976702d2eaa/file.flac title="Don't You Remember" Feb 25 09:53:18 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:18.855+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=404 volume=100 Feb 25 09:53:18 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:18.856+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ef3ce84976702d2eaa/file.flac title="Don't You Remember" Feb 25 09:53:18 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:18.857+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=404 volume=100 Feb 25 09:53:18 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:18.857+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ef3ce84976702d2eaa/file.flac title="Don't You Remember" Feb 25 09:53:18 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:18.858+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" state=STATUS_PLAYING positionMs=404 volume=100 Feb 25 09:53:18 volumio volumio5-onboarding[1545]: time=2026-02-25T09:53:18.859+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.188.28:54711 @ 0x2001200" id=http://192.168.188.21:32469/object/f2ef3ce84976702d2eaa/file.flac title="Don't You Remember" Feb 25 09:53:18 volumio volumio[1234]: info: ------------------------------ 44ms Feb 25 09:53:18 volumio volumio[1234]: info: ------------------------------ 43ms Feb 25 09:53:18 volumio volumio[1234]: info: ------------------------------ 43ms Feb 25 09:53:18 volumio volumio[1234]: info: CoreCommandRouter::volumioGetQueue Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::getQueue Feb 25 09:53:18 volumio volumio[1234]: info: CorePlayQueue::getQueue Feb 25 09:53:18 volumio volumio[1234]: info: CoreCommandRouter::volumioGetQueue Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::getQueue Feb 25 09:53:18 volumio volumio[1234]: info: CorePlayQueue::getQueue Feb 25 09:53:18 volumio volumio[1234]: info: CoreCommandRouter::volumioGetQueue Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::getQueue Feb 25 09:53:18 volumio volumio[1234]: info: CorePlayQueue::getQueue Feb 25 09:53:18 volumio volumio[1234]: info: CoreCommandRouter::volumioGetQueue Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::getQueue Feb 25 09:53:18 volumio volumio[1234]: info: CorePlayQueue::getQueue Feb 25 09:53:18 volumio volumio[1234]: info: CoreCommandRouter::volumioGetQueue Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::getQueue Feb 25 09:53:18 volumio volumio[1234]: info: CorePlayQueue::getQueue Feb 25 09:53:18 volumio volumio[1234]: info: CoreCommandRouter::volumioGetQueue Feb 25 09:53:18 volumio volumio[1234]: info: CoreStateMachine::getQueue Feb 25 09:53:18 volumio volumio[1234]: info: CorePlayQueue::getQueue Feb 25 09:53:37 volumio volumio[1234]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 25 09:53:37 volumio volumio[1234]: TypeError: Cannot read properties of null (reading 'slice') Feb 25 09:53:37 volumio volumio[1234]: at download (/volumio/app/plugins/miscellanea/albumart/albumart.js:718:41) Feb 25 09:53:37 volumio volumio[1234]: at ClientRequest. (/volumio/app/plugins/miscellanea/albumart/albumart.js:728:7) Feb 25 09:53:37 volumio volumio[1234]: at Object.onceWrapper (node:events:629:26) Feb 25 09:53:37 volumio volumio[1234]: at ClientRequest.emit (node:events:514:28) Feb 25 09:53:37 volumio volumio[1234]: at HTTPParser.parserOnIncomingClient [as onIncoming] (node:_http_client:693:27) Feb 25 09:53:37 volumio volumio[1234]: at HTTPParser.parserOnHeadersComplete (node:_http_common:119:17) Feb 25 09:53:37 volumio volumio[1234]: at TLSSocket.socketOnData (node:_http_client:535:22) Feb 25 09:53:37 volumio volumio[1234]: at TLSSocket.emit (node:events:514:28) Feb 25 09:53:37 volumio volumio[1234]: at addChunk (node:internal/streams/readable:343:12) Feb 25 09:53:37 volumio volumio[1234]: at readableAddChunk (node:internal/streams/readable:316:9) Feb 25 09:53:37 volumio volumio[1234]: at Readable.push (node:internal/streams/readable:253:10) Feb 25 09:53:37 volumio volumio[1234]: at TLSWrap.onStreamRead (node:internal/stream_base_commons:190:23) Feb 25 09:53:37 volumio volumio[1234]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 25 09:53:38 volumio sudo[2776]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-25 09:52' Feb 25 09:53:38 volumio sudo[2776]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="a78d359cf1dc63ac74e9d151015afd30d31a709a" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Feb 5 14:07:07 UTC 2026" VOLUMIO_VERSION="4.096" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5e37060f9823263a753eb5e84030104f"