Apr 15 20:59:03 volumio volumio[3697]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 15 20:59:03 volumio volumio[3697]: info: CURURI: music-library Apr 15 20:59:03 volumio volumio[3697]: error: Failed LSINFO: null Apr 15 20:59:03 volumio volumio[3697]: info: Preload queue cleared Apr 15 20:59:09 volumio volumio[3697]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 15 20:59:09 volumio volumio[3697]: info: CURURI: albums:// Apr 15 20:59:09 volumio volumio[3697]: info: listAlbums - loading Albums from cache Apr 15 20:59:09 volumio volumio[3697]: info: Preload queue cleared Apr 15 20:59:15 volumio volumio[3697]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Apr 15 20:59:15 volumio volumio[3697]: info: Preload queue cleared Apr 15 20:59:17 volumio volumio[3697]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Apr 15 20:59:17 volumio volumio[3697]: info: Preload queue cleared Apr 15 20:59:21 volumio volumio[3697]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Apr 15 20:59:21 volumio volumio[3697]: info: Preload queue cleared Apr 15 20:59:24 volumio volumio[3697]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Apr 15 20:59:24 volumio volumio[3697]: info: Preload queue cleared Apr 15 20:59:41 volumio volumio[3697]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Apr 15 20:59:41 volumio volumio[3697]: info: Preload queue cleared Apr 15 20:59:41 volumio volumio[3697]: info: Preloading song: upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$0 Apr 15 20:59:41 volumio volumio[3697]: info: Preloading song: upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$1 Apr 15 20:59:41 volumio volumio[3697]: info: Preloading song: upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$2 Apr 15 20:59:41 volumio volumio[3697]: info: Preloading song: upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$3 Apr 15 20:59:41 volumio volumio[3697]: info: Preloading song: upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$4 Apr 15 20:59:41 volumio volumio[3697]: info: Preloading song: upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$5 Apr 15 20:59:41 volumio volumio[3697]: info: Preloading song: upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$6 Apr 15 20:59:41 volumio volumio[3697]: info: Preloading song: upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$7 Apr 15 20:59:41 volumio volumio[3697]: info: Preloading song: upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$8 Apr 15 20:59:41 volumio volumio[3697]: info: Preloading song: upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$9 Apr 15 20:59:41 volumio volumio[3697]: info: Preloading song: upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$A Apr 15 20:59:41 volumio volumio[3697]: info: Preloading song: upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$B Apr 15 20:59:42 volumio volumio[3697]: info: Exploding uri upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$0 in service upnp_browser Apr 15 20:59:42 volumio volumio[3697]: info: Exploding uri upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$1 in service upnp_browser Apr 15 20:59:42 volumio volumio[3697]: info: Exploding uri upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$2 in service upnp_browser Apr 15 20:59:42 volumio volumio[3697]: info: Exploding uri upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$3 in service upnp_browser Apr 15 20:59:42 volumio volumio[3697]: info: Exploding uri upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$4 in service upnp_browser Apr 15 20:59:42 volumio volumio[3697]: info: Exploding uri upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$5 in service upnp_browser Apr 15 20:59:42 volumio volumio[3697]: info: Exploding uri upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$6 in service upnp_browser Apr 15 20:59:42 volumio volumio[3697]: info: Exploding uri upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$7 in service upnp_browser Apr 15 20:59:42 volumio volumio[3697]: info: Exploding uri upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$8 in service upnp_browser Apr 15 20:59:42 volumio volumio[3697]: info: Exploding uri upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$9 in service upnp_browser Apr 15 20:59:42 volumio volumio[3697]: info: Exploding uri upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$A in service upnp_browser Apr 15 20:59:42 volumio volumio[3697]: info: Exploding uri upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$B in service upnp_browser Apr 15 20:59:45 volumio volumio[3697]: info: Preload queue cleared Apr 15 20:59:45 volumio volumio[3697]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::ClearQueue Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::stop Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::stPlaybackTimer Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::updateTrackBlock Apr 15 20:59:45 volumio volumio[3697]: info: CorePlayQueue::getTrackBlock Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::pushState Apr 15 20:59:45 volumio volumio[3697]: info: CorePlayQueue::getTrack 0 Apr 15 20:59:45 volumio volumio[3697]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 20:59:45 volumio volumio[3697]: info: CoreCommandRouter::volumioPushState Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::serviceStop Apr 15 20:59:45 volumio volumio[3697]: info: CorePlayQueue::getTrack 0 Apr 15 20:59:45 volumio volumio[3697]: info: CoreCommandRouter::serviceStop Apr 15 20:59:45 volumio volumio[3697]: info: [1776257985206] ControllerUPNPBrowser::stop Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand stop Apr 15 20:59:45 volumio volumio[3697]: info: CorePlayQueue::clearPlayQueue Apr 15 20:59:45 volumio volumio[3697]: info: CorePlayQueue::saveQueue Apr 15 20:59:45 volumio volumio[3697]: info: CoreCommandRouter::volumioPushQueue Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::addQueueItems Apr 15 20:59:45 volumio volumio[3697]: info: CorePlayQueue::addQueueItems Apr 15 20:59:45 volumio volumio[3697]: info: Preload queue cleared Apr 15 20:59:45 volumio volumio[3697]: info: Adding Item to queue: upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$0 Apr 15 20:59:45 volumio volumio[3697]: info: Using cached record of: upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$0 Apr 15 20:59:45 volumio volumio5-onboarding[2083]: time=2026-04-15T20:59:45.228+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_STOPPED positionMs=0 volume=97 Apr 15 20:59:45 volumio volumio5-onboarding[2083]: time=2026-04-15T20:59:45.229+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/501.flac title=Amani Apr 15 20:59:45 volumio volumio[3697]: info: CoreCommandRouter::volumioPushQueue Apr 15 20:59:45 volumio volumio[3697]: info: CorePlayQueue::saveQueue Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::updateTrackBlock Apr 15 20:59:45 volumio volumio[3697]: info: CorePlayQueue::getTrackBlock Apr 15 20:59:45 volumio volumio[3697]: info: CoreCommandRouter::volumioPlay Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::play index 0 Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::addQueueItems Apr 15 20:59:45 volumio volumio[3697]: info: CorePlayQueue::addQueueItems Apr 15 20:59:45 volumio volumio[3697]: info: Preload queue cleared Apr 15 20:59:45 volumio volumio[3697]: info: Adding Item to queue: upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$1 Apr 15 20:59:45 volumio volumio[3697]: info: Using cached record of: upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$1 Apr 15 20:59:45 volumio volumio[3697]: info: Adding Item to queue: upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$2 Apr 15 20:59:45 volumio volumio[3697]: info: Using cached record of: upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$2 Apr 15 20:59:45 volumio volumio[3697]: info: Adding Item to queue: upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$3 Apr 15 20:59:45 volumio volumio[3697]: info: Using cached record of: upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$3 Apr 15 20:59:45 volumio volumio[3697]: info: Adding Item to queue: upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$4 Apr 15 20:59:45 volumio volumio[3697]: info: Using cached record of: upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$4 Apr 15 20:59:45 volumio volumio[3697]: info: Adding Item to queue: upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$5 Apr 15 20:59:45 volumio volumio[3697]: info: Using cached record of: upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$5 Apr 15 20:59:45 volumio volumio[3697]: info: Adding Item to queue: upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$6 Apr 15 20:59:45 volumio volumio[3697]: info: Using cached record of: upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$6 Apr 15 20:59:45 volumio volumio[3697]: info: Adding Item to queue: upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$7 Apr 15 20:59:45 volumio volumio[3697]: info: Using cached record of: upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$7 Apr 15 20:59:45 volumio volumio[3697]: info: Adding Item to queue: upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$8 Apr 15 20:59:45 volumio volumio[3697]: info: Using cached record of: upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$8 Apr 15 20:59:45 volumio volumio[3697]: info: Adding Item to queue: upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$9 Apr 15 20:59:45 volumio volumio[3697]: info: Using cached record of: upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$9 Apr 15 20:59:45 volumio volumio[3697]: info: Adding Item to queue: upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$A Apr 15 20:59:45 volumio volumio[3697]: info: Using cached record of: upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$A Apr 15 20:59:45 volumio volumio[3697]: info: Adding Item to queue: upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$B Apr 15 20:59:45 volumio volumio[3697]: info: Using cached record of: upnp/http://10.0.0.9:8200/ctl/ContentDir@64$1$12$B Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::stop Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 15 20:59:45 volumio volumio[3697]: info: CoreCommandRouter::volumioPushQueue Apr 15 20:59:45 volumio volumio[3697]: info: CorePlayQueue::saveQueue Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::play index undefined Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::updateTrackBlock Apr 15 20:59:45 volumio volumio[3697]: info: CorePlayQueue::getTrackBlock Apr 15 20:59:45 volumio volumio[3697]: info: CorePlayQueue::getTrack 0 Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::startPlaybackTimer Apr 15 20:59:45 volumio volumio[3697]: info: CorePlayQueue::getTrack 0 Apr 15 20:59:45 volumio volumio[3697]: info: [1776257985267] ControllerUPNPBrowser::clearAddPlayTrack Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand stop Apr 15 20:59:45 volumio volumio[3697]: info: Apr 15 20:59:45 volumio volumio[3697]: ---------------------------- MPD announces state update: player Apr 15 20:59:45 volumio volumio[3697]: info: sendMpdCommand stop took 74 milliseconds Apr 15 20:59:45 volumio volumio[3697]: info: ControllerMpd::getState Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand status Apr 15 20:59:45 volumio volumio[3697]: info: sendMpdCommand stop took 14 milliseconds Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand clear Apr 15 20:59:45 volumio volumio[3697]: info: Apr 15 20:59:45 volumio volumio[3697]: ---------------------------- MPD announces state update: player Apr 15 20:59:45 volumio volumio[3697]: info: ControllerMpd::getState Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand status Apr 15 20:59:45 volumio volumio[3697]: info: Apr 15 20:59:45 volumio volumio[3697]: ---------------------------- MPD announces state update: player Apr 15 20:59:45 volumio volumio[3697]: info: ControllerMpd::getState Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand status Apr 15 20:59:45 volumio volumio[3697]: info: Apr 15 20:59:45 volumio volumio[3697]: ---------------------------- MPD announces system playlist update Apr 15 20:59:45 volumio volumio[3697]: info: Ignoring MPD Status Update Apr 15 20:59:45 volumio volumio[3697]: info: sendMpdCommand status took 10 milliseconds Apr 15 20:59:45 volumio volumio[3697]: info: sendMpdCommand clear took 8 milliseconds Apr 15 20:59:45 volumio volumio[3697]: info: sendMpdCommand status took 7 milliseconds Apr 15 20:59:45 volumio volumio[3697]: info: sendMpdCommand status took 9 milliseconds Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::parseState Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand load "http://10.0.0.9:8200/MediaItems/1041.wav" Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::parseState Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::parseState Apr 15 20:59:45 volumio volumio[3697]: info: ControllerMpd::pushState Apr 15 20:59:45 volumio volumio[3697]: info: CoreCommandRouter::servicePushState Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::pushState Apr 15 20:59:45 volumio volumio[3697]: info: CorePlayQueue::getTrack 0 Apr 15 20:59:45 volumio volumio[3697]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 20:59:45 volumio volumio[3697]: info: CoreCommandRouter::volumioPushState Apr 15 20:59:45 volumio volumio[3697]: info: CorePlayQueue::getTrack 0 Apr 15 20:59:45 volumio volumio[3697]: 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} Apr 15 20:59:45 volumio volumio[3697]: verbose: CURRENT POSITION 0 Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::syncState stateService stop Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::syncState currentStatus stop Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::pushState Apr 15 20:59:45 volumio volumio[3697]: info: CorePlayQueue::getTrack 0 Apr 15 20:59:45 volumio volumio[3697]: info: CoreCommandRouter::volumioPushState Apr 15 20:59:45 volumio volumio[3697]: info: No code Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::pushState Apr 15 20:59:45 volumio volumio[3697]: info: CorePlayQueue::getTrack 0 Apr 15 20:59:45 volumio volumio[3697]: info: CoreCommandRouter::volumioPushState Apr 15 20:59:45 volumio volumio[3697]: info: ControllerMpd::pushState Apr 15 20:59:45 volumio volumio[3697]: info: CoreCommandRouter::servicePushState Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::pushState Apr 15 20:59:45 volumio volumio[3697]: info: CorePlayQueue::getTrack 0 Apr 15 20:59:45 volumio volumio[3697]: info: CoreCommandRouter::volumioPushState Apr 15 20:59:45 volumio volumio[3697]: info: CorePlayQueue::getTrack 0 Apr 15 20:59:45 volumio volumio[3697]: 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} Apr 15 20:59:45 volumio volumio[3697]: verbose: CURRENT POSITION 0 Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::syncState stateService stop Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::syncState currentStatus stop Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::pushState Apr 15 20:59:45 volumio volumio[3697]: info: CorePlayQueue::getTrack 0 Apr 15 20:59:45 volumio volumio[3697]: info: CoreCommandRouter::volumioPushState Apr 15 20:59:45 volumio volumio[3697]: info: No code Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::pushState Apr 15 20:59:45 volumio volumio[3697]: info: CorePlayQueue::getTrack 0 Apr 15 20:59:45 volumio volumio[3697]: info: CoreCommandRouter::volumioPushState Apr 15 20:59:45 volumio volumio5-onboarding[2083]: time=2026-04-15T20:59:45.369+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_STOPPED positionMs=0 volume=97 Apr 15 20:59:45 volumio volumio5-onboarding[2083]: time=2026-04-15T20:59:45.369+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/1041.wav title=01.被爱伤过是人 Apr 15 20:59:45 volumio volumio5-onboarding[2083]: time=2026-04-15T20:59:45.372+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_STOPPED positionMs=0 volume=97 Apr 15 20:59:45 volumio volumio5-onboarding[2083]: time=2026-04-15T20:59:45.373+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/1041.wav title=01.被爱伤过是人 Apr 15 20:59:45 volumio volumio5-onboarding[2083]: time=2026-04-15T20:59:45.376+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_STOPPED positionMs=0 volume=97 Apr 15 20:59:45 volumio volumio5-onboarding[2083]: time=2026-04-15T20:59:45.376+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/1041.wav title=01.被爱伤过是人 Apr 15 20:59:45 volumio volumio5-onboarding[2083]: time=2026-04-15T20:59:45.380+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_STOPPED positionMs=0 volume=97 Apr 15 20:59:45 volumio volumio5-onboarding[2083]: time=2026-04-15T20:59:45.380+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/1041.wav title=01.被爱伤过是人 Apr 15 20:59:45 volumio volumio5-onboarding[2083]: time=2026-04-15T20:59:45.383+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_STOPPED positionMs=0 volume=97 Apr 15 20:59:45 volumio volumio5-onboarding[2083]: time=2026-04-15T20:59:45.383+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/1041.wav title=01.被爱伤过是人 Apr 15 20:59:45 volumio volumio5-onboarding[2083]: time=2026-04-15T20:59:45.387+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_STOPPED positionMs=0 volume=97 Apr 15 20:59:45 volumio volumio5-onboarding[2083]: time=2026-04-15T20:59:45.387+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/1041.wav title=01.被爱伤过是人 Apr 15 20:59:45 volumio volumio[3697]: info: ------------------------------ 113ms Apr 15 20:59:45 volumio volumio[3697]: info: ------------------------------ 111ms Apr 15 20:59:45 volumio volumio[3697]: info: Apr 15 20:59:45 volumio volumio[3697]: ---------------------------- MPD announces system playlist update Apr 15 20:59:45 volumio volumio[3697]: info: Ignoring MPD Status Update Apr 15 20:59:45 volumio volumio[3697]: info: Apr 15 20:59:45 volumio volumio[3697]: ---------------------------- MPD announces system playlist update Apr 15 20:59:45 volumio volumio[3697]: info: Ignoring MPD Status Update Apr 15 20:59:45 volumio volumio[3697]: error: updateQueue error: null Apr 15 20:59:45 volumio volumio[3697]: error: updateQueue error: null Apr 15 20:59:45 volumio volumio[3697]: error: updateQueue error: null Apr 15 20:59:45 volumio volumio[3697]: info: ------------------------------ 240ms Apr 15 20:59:45 volumio volumio[3697]: info: sendMpdCommand playlistinfo took 232 milliseconds Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand add "http://10.0.0.9:8200/MediaItems/1041.wav" Apr 15 20:59:45 volumio volumio[3697]: info: ------------------------------ 132ms Apr 15 20:59:45 volumio volumio[3697]: info: ------------------------------ 130ms Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::parseTrackInfo Apr 15 20:59:45 volumio volumio[3697]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Apr 15 20:59:45 volumio volumio[3697]: info: ------------------------------ 253ms Apr 15 20:59:45 volumio volumio[3697]: info: sendMpdCommand add "http://10.0.0.9:8200/MediaItems/1041.wav" took 4 milliseconds Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand play Apr 15 20:59:45 volumio volumio[3697]: info: Apr 15 20:59:45 volumio volumio[3697]: ---------------------------- MPD announces system playlist update Apr 15 20:59:45 volumio volumio[3697]: info: Ignoring MPD Status Update Apr 15 20:59:45 volumio volumio[3697]: info: Apr 15 20:59:45 volumio volumio[3697]: ---------------------------- MPD announces system playlist update Apr 15 20:59:45 volumio volumio[3697]: info: Ignoring MPD Status Update Apr 15 20:59:45 volumio volumio[3697]: info: Apr 15 20:59:45 volumio volumio[3697]: ---------------------------- MPD announces system playlist update Apr 15 20:59:45 volumio volumio[3697]: info: Ignoring MPD Status Update Apr 15 20:59:45 volumio volumio[3697]: info: sendMpdCommand play took 5 milliseconds Apr 15 20:59:45 volumio volumio[3697]: info: ------------------------------ 6ms Apr 15 20:59:45 volumio volumio[3697]: info: ------------------------------ 4ms Apr 15 20:59:45 volumio volumio[3697]: info: ------------------------------ 3ms Apr 15 20:59:45 volumio volumio[3697]: info: Apr 15 20:59:45 volumio volumio[3697]: ---------------------------- MPD announces state update: player Apr 15 20:59:45 volumio volumio[3697]: info: ControllerMpd::getState Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand status Apr 15 20:59:45 volumio volumio[3697]: info: Apr 15 20:59:45 volumio volumio[3697]: ---------------------------- MPD announces state update: player Apr 15 20:59:45 volumio volumio[3697]: info: ControllerMpd::getState Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand status Apr 15 20:59:45 volumio volumio[3697]: info: Apr 15 20:59:45 volumio volumio[3697]: ---------------------------- MPD announces state update: player Apr 15 20:59:45 volumio volumio[3697]: info: ControllerMpd::getState Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand status Apr 15 20:59:45 volumio volumio[3697]: info: sendMpdCommand status took 9 milliseconds Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::parseState Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 15 20:59:45 volumio volumio[3697]: info: Apr 15 20:59:45 volumio volumio[3697]: ---------------------------- MPD announces state update: player Apr 15 20:59:45 volumio volumio[3697]: info: ControllerMpd::getState Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand status Apr 15 20:59:45 volumio volumio[3697]: info: Apr 15 20:59:45 volumio volumio[3697]: ---------------------------- MPD announces state update: player Apr 15 20:59:45 volumio volumio[3697]: info: ControllerMpd::getState Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand status Apr 15 20:59:45 volumio volumio[3697]: info: sendMpdCommand status took 10 milliseconds Apr 15 20:59:45 volumio volumio[3697]: info: sendMpdCommand status took 9 milliseconds Apr 15 20:59:45 volumio volumio[3697]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 15 20:59:45 volumio volumio[3697]: info: sendMpdCommand status took 2 milliseconds Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::parseState Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::parseState Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::parseTrackInfo Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::parseState Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 15 20:59:45 volumio volumio[3697]: info: ControllerMpd::pushState Apr 15 20:59:45 volumio volumio[3697]: info: CoreCommandRouter::servicePushState Apr 15 20:59:45 volumio volumio[3697]: info: CorePlayQueue::getTrack 0 Apr 15 20:59:45 volumio volumio[3697]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":277,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"1041.wav","artist":null,"album":null,"uri":"http://10.0.0.9:8200/MediaItems/1041.wav","trackType":"wav"} Apr 15 20:59:45 volumio volumio[3697]: verbose: CURRENT POSITION 0 Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::syncState stateService play Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::syncState currentStatus stop Apr 15 20:59:45 volumio volumio[3697]: info: ------------------------------ 22ms Apr 15 20:59:45 volumio volumio[3697]: info: Apr 15 20:59:45 volumio volumio[3697]: ---------------------------- MPD announces state update: player Apr 15 20:59:45 volumio volumio[3697]: info: ControllerMpd::getState Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand status Apr 15 20:59:45 volumio volumio[3697]: info: sendMpdCommand status took 10 milliseconds Apr 15 20:59:45 volumio volumio[3697]: info: sendMpdCommand playlistinfo took 7 milliseconds Apr 15 20:59:45 volumio volumio[3697]: info: sendMpdCommand playlistinfo took 7 milliseconds Apr 15 20:59:45 volumio volumio[3697]: info: sendMpdCommand playlistinfo took 7 milliseconds Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::parseState Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::parseTrackInfo Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::parseTrackInfo Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::parseTrackInfo Apr 15 20:59:45 volumio volumio[3697]: info: ControllerMpd::pushState Apr 15 20:59:45 volumio volumio[3697]: info: CoreCommandRouter::servicePushState Apr 15 20:59:45 volumio volumio[3697]: info: CorePlayQueue::getTrack 0 Apr 15 20:59:45 volumio volumio[3697]: verbose: STATE SERVICE {"status":"play","position":0,"seek":45,"duration":277,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1411 Kbps","isStreaming":false,"title":"1041.wav","artist":null,"album":null,"uri":"http://10.0.0.9:8200/MediaItems/1041.wav","trackType":"wav"} Apr 15 20:59:45 volumio volumio[3697]: verbose: CURRENT POSITION 0 Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::syncState stateService play Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::syncState currentStatus play Apr 15 20:59:45 volumio volumio[3697]: info: Received an update from plugin. extracting info from payload Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::pushState Apr 15 20:59:45 volumio volumio[3697]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 20:59:45 volumio volumio[3697]: info: CoreCommandRouter::volumioPushState Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::pushState Apr 15 20:59:45 volumio volumio[3697]: info: CoreCommandRouter::volumioPushState Apr 15 20:59:45 volumio volumio[3697]: info: ControllerMpd::pushState Apr 15 20:59:45 volumio volumio[3697]: info: CoreCommandRouter::servicePushState Apr 15 20:59:45 volumio volumio[3697]: info: CorePlayQueue::getTrack 0 Apr 15 20:59:45 volumio volumio[3697]: verbose: STATE SERVICE {"status":"play","position":0,"seek":90,"duration":277,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1411 Kbps","isStreaming":false,"title":"1041.wav","artist":null,"album":null,"uri":"http://10.0.0.9:8200/MediaItems/1041.wav","trackType":"wav"} Apr 15 20:59:45 volumio volumio[3697]: verbose: CURRENT POSITION 0 Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::syncState stateService play Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::syncState currentStatus play Apr 15 20:59:45 volumio volumio[3697]: info: Received an update from plugin. extracting info from payload Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::pushState Apr 15 20:59:45 volumio volumio[3697]: info: CoreCommandRouter::volumioPushState Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::pushState Apr 15 20:59:45 volumio volumio[3697]: info: CoreCommandRouter::volumioPushState Apr 15 20:59:45 volumio volumio[3697]: info: ControllerMpd::pushState Apr 15 20:59:45 volumio volumio[3697]: info: CoreCommandRouter::servicePushState Apr 15 20:59:45 volumio volumio[3697]: info: CorePlayQueue::getTrack 0 Apr 15 20:59:45 volumio volumio[3697]: verbose: STATE SERVICE {"status":"play","position":0,"seek":844,"duration":277,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1411 Kbps","isStreaming":false,"title":"1041.wav","artist":null,"album":null,"uri":"http://10.0.0.9:8200/MediaItems/1041.wav","trackType":"wav"} Apr 15 20:59:45 volumio volumio[3697]: verbose: CURRENT POSITION 0 Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::syncState stateService play Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::syncState currentStatus play Apr 15 20:59:45 volumio volumio[3697]: info: Received an update from plugin. extracting info from payload Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::pushState Apr 15 20:59:45 volumio volumio[3697]: info: CoreCommandRouter::volumioPushState Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::pushState Apr 15 20:59:45 volumio volumio[3697]: info: CoreCommandRouter::volumioPushState Apr 15 20:59:45 volumio volumio5-onboarding[2083]: time=2026-04-15T20:59:45.693+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_PLAYING positionMs=0 volume=97 Apr 15 20:59:45 volumio volumio5-onboarding[2083]: time=2026-04-15T20:59:45.694+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/1041.wav title=1041.wav Apr 15 20:59:45 volumio volumio5-onboarding[2083]: time=2026-04-15T20:59:45.695+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_PLAYING positionMs=0 volume=97 Apr 15 20:59:45 volumio volumio5-onboarding[2083]: time=2026-04-15T20:59:45.695+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/1041.wav title=1041.wav Apr 15 20:59:45 volumio volumio5-onboarding[2083]: time=2026-04-15T20:59:45.696+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_PLAYING positionMs=0 volume=97 Apr 15 20:59:45 volumio volumio5-onboarding[2083]: time=2026-04-15T20:59:45.696+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/1041.wav title=1041.wav Apr 15 20:59:45 volumio volumio5-onboarding[2083]: time=2026-04-15T20:59:45.697+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_PLAYING positionMs=0 volume=97 Apr 15 20:59:45 volumio volumio5-onboarding[2083]: time=2026-04-15T20:59:45.698+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/1041.wav title=1041.wav Apr 15 20:59:45 volumio volumio5-onboarding[2083]: time=2026-04-15T20:59:45.699+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_PLAYING positionMs=0 volume=97 Apr 15 20:59:45 volumio volumio5-onboarding[2083]: time=2026-04-15T20:59:45.702+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/1041.wav title=1041.wav Apr 15 20:59:45 volumio volumio5-onboarding[2083]: time=2026-04-15T20:59:45.707+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_PLAYING positionMs=0 volume=97 Apr 15 20:59:45 volumio volumio5-onboarding[2083]: time=2026-04-15T20:59:45.707+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/1041.wav title=1041.wav Apr 15 20:59:45 volumio volumio[3697]: info: ------------------------------ 108ms Apr 15 20:59:45 volumio volumio[3697]: info: ------------------------------ 108ms Apr 15 20:59:45 volumio volumio[3697]: info: ------------------------------ 102ms Apr 15 20:59:45 volumio volumio[3697]: info: sendMpdCommand status took 100 milliseconds Apr 15 20:59:45 volumio volumio[3697]: info: sendMpdCommand playlistinfo took 98 milliseconds Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::parseState Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::parseTrackInfo Apr 15 20:59:45 volumio volumio[3697]: info: ControllerMpd::pushState Apr 15 20:59:45 volumio volumio[3697]: info: CoreCommandRouter::servicePushState Apr 15 20:59:45 volumio volumio[3697]: info: CorePlayQueue::getTrack 0 Apr 15 20:59:45 volumio volumio[3697]: verbose: STATE SERVICE {"status":"play","position":0,"seek":844,"duration":277,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1411 Kbps","isStreaming":false,"title":"1041.wav","artist":null,"album":null,"uri":"http://10.0.0.9:8200/MediaItems/1041.wav","trackType":"wav"} Apr 15 20:59:45 volumio volumio[3697]: verbose: CURRENT POSITION 0 Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::syncState stateService play Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::syncState currentStatus play Apr 15 20:59:45 volumio volumio[3697]: info: Received an update from plugin. extracting info from payload Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::pushState Apr 15 20:59:45 volumio volumio[3697]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 20:59:45 volumio volumio[3697]: info: CoreCommandRouter::volumioPushState Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::pushState Apr 15 20:59:45 volumio volumio[3697]: info: CoreCommandRouter::volumioPushState Apr 15 20:59:45 volumio volumio5-onboarding[2083]: time=2026-04-15T20:59:45.751+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_PLAYING positionMs=199 volume=97 Apr 15 20:59:45 volumio volumio5-onboarding[2083]: time=2026-04-15T20:59:45.751+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/1041.wav title=1041.wav Apr 15 20:59:45 volumio volumio5-onboarding[2083]: time=2026-04-15T20:59:45.752+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_PLAYING positionMs=199 volume=97 Apr 15 20:59:45 volumio volumio[3697]: info: ------------------------------ 145ms Apr 15 20:59:45 volumio volumio5-onboarding[2083]: time=2026-04-15T20:59:45.756+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/1041.wav title=1041.wav Apr 15 20:59:45 volumio volumio[3697]: info: sendMpdCommand playlistinfo took 68 milliseconds Apr 15 20:59:45 volumio volumio[3697]: verbose: ControllerMpd::parseTrackInfo Apr 15 20:59:45 volumio volumio[3697]: info: ControllerMpd::pushState Apr 15 20:59:45 volumio volumio[3697]: info: CoreCommandRouter::servicePushState Apr 15 20:59:45 volumio volumio[3697]: info: CorePlayQueue::getTrack 0 Apr 15 20:59:45 volumio volumio[3697]: verbose: STATE SERVICE {"status":"play","position":0,"seek":844,"duration":277,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1411 Kbps","isStreaming":false,"title":"1041.wav","artist":null,"album":null,"uri":"http://10.0.0.9:8200/MediaItems/1041.wav","trackType":"wav"} Apr 15 20:59:45 volumio volumio[3697]: verbose: CURRENT POSITION 0 Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::syncState stateService play Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::syncState currentStatus play Apr 15 20:59:45 volumio volumio[3697]: info: Received an update from plugin. extracting info from payload Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::pushState Apr 15 20:59:45 volumio volumio[3697]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 20:59:45 volumio volumio[3697]: info: CoreCommandRouter::volumioPushState Apr 15 20:59:45 volumio volumio[3697]: info: CoreStateMachine::pushState Apr 15 20:59:45 volumio volumio[3697]: info: CoreCommandRouter::volumioPushState Apr 15 20:59:45 volumio volumio5-onboarding[2083]: time=2026-04-15T20:59:45.815+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_PLAYING positionMs=271 volume=97 Apr 15 20:59:45 volumio volumio5-onboarding[2083]: time=2026-04-15T20:59:45.817+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_PLAYING positionMs=271 volume=97 Apr 15 20:59:45 volumio volumio5-onboarding[2083]: time=2026-04-15T20:59:45.817+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/1041.wav title=1041.wav Apr 15 20:59:45 volumio volumio5-onboarding[2083]: time=2026-04-15T20:59:45.817+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/1041.wav title=1041.wav Apr 15 20:59:45 volumio volumio[3697]: info: ------------------------------ 201ms Apr 15 21:00:09 volumio volumio[3697]: info: CoreCommandRouter::volumioNext Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::next Apr 15 21:00:09 volumio volumio[3697]: info: ControllerMpd::next Apr 15 21:00:09 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand next Apr 15 21:00:09 volumio volumio[3697]: info: sendMpdCommand next took 7 milliseconds Apr 15 21:00:09 volumio volumio[3697]: info: Apr 15 21:00:09 volumio volumio[3697]: ---------------------------- MPD announces state update: player Apr 15 21:00:09 volumio volumio[3697]: info: ControllerMpd::getState Apr 15 21:00:09 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand status Apr 15 21:00:09 volumio volumio[3697]: info: Apr 15 21:00:09 volumio volumio[3697]: ---------------------------- MPD announces state update: player Apr 15 21:00:09 volumio volumio[3697]: info: ControllerMpd::getState Apr 15 21:00:09 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand status Apr 15 21:00:09 volumio volumio[3697]: info: Apr 15 21:00:09 volumio volumio[3697]: ---------------------------- MPD announces state update: player Apr 15 21:00:09 volumio volumio[3697]: info: ControllerMpd::getState Apr 15 21:00:09 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand status Apr 15 21:00:09 volumio volumio[3697]: info: sendMpdCommand status took 7 milliseconds Apr 15 21:00:09 volumio volumio[3697]: info: sendMpdCommand status took 4 milliseconds Apr 15 21:00:09 volumio volumio[3697]: verbose: ControllerMpd::parseState Apr 15 21:00:09 volumio volumio[3697]: verbose: ControllerMpd::parseState Apr 15 21:00:09 volumio volumio[3697]: info: ControllerMpd::pushState Apr 15 21:00:09 volumio volumio[3697]: info: CoreCommandRouter::servicePushState Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::pushState Apr 15 21:00:09 volumio volumio[3697]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 21:00:09 volumio volumio[3697]: info: CoreCommandRouter::volumioPushState Apr 15 21:00:09 volumio volumio[3697]: info: CorePlayQueue::getTrack 0 Apr 15 21:00:09 volumio volumio[3697]: 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} Apr 15 21:00:09 volumio volumio[3697]: verbose: CURRENT POSITION 0 Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::syncState stateService stop Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::syncState currentStatus play Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::play index undefined Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::pushState Apr 15 21:00:09 volumio volumio[3697]: info: CorePlayQueue::getTrack 1 Apr 15 21:00:09 volumio volumio[3697]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 21:00:09 volumio volumio[3697]: info: CoreCommandRouter::volumioPushState Apr 15 21:00:09 volumio volumio[3697]: info: ControllerMpd::pushState Apr 15 21:00:09 volumio volumio[3697]: info: CoreCommandRouter::servicePushState Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::pushState Apr 15 21:00:09 volumio volumio[3697]: info: CorePlayQueue::getTrack 1 Apr 15 21:00:09 volumio volumio[3697]: info: CoreCommandRouter::volumioPushState Apr 15 21:00:09 volumio volumio[3697]: info: CorePlayQueue::getTrack 1 Apr 15 21:00:09 volumio volumio[3697]: 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} Apr 15 21:00:09 volumio volumio[3697]: verbose: CURRENT POSITION 1 Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::syncState stateService stop Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::syncState currentStatus stop Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::pushState Apr 15 21:00:09 volumio volumio[3697]: info: CorePlayQueue::getTrack 1 Apr 15 21:00:09 volumio volumio[3697]: info: CoreCommandRouter::volumioPushState Apr 15 21:00:09 volumio volumio[3697]: info: No code Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::pushState Apr 15 21:00:09 volumio volumio[3697]: info: CorePlayQueue::getTrack 1 Apr 15 21:00:09 volumio volumio[3697]: info: CoreCommandRouter::volumioPushState Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.466+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_PLAYING positionMs=23843 volume=97 Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.466+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/1041.wav title=1041.wav Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.469+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_STOPPED positionMs= volume=97 Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.470+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_STOPPED positionMs= volume=97 Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.470+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/1042.wav title=02.我是真的爱你 Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.471+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_STOPPED positionMs= volume=97 Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.472+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/1042.wav title=02.我是真的爱你 Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.473+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_STOPPED positionMs= volume=97 Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.473+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/1042.wav title=02.我是真的爱你 Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.473+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/1042.wav title=02.我是真的爱你 Apr 15 21:00:09 volumio volumio[3697]: info: CorePlayQueue::getTrack 1 Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::startPlaybackTimer Apr 15 21:00:09 volumio volumio[3697]: info: CorePlayQueue::getTrack 1 Apr 15 21:00:09 volumio volumio[3697]: info: [1776258009483] ControllerUPNPBrowser::clearAddPlayTrack Apr 15 21:00:09 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand stop Apr 15 21:00:09 volumio volumio[3697]: info: ------------------------------ 114ms Apr 15 21:00:09 volumio volumio[3697]: info: ------------------------------ 112ms Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::pushState Apr 15 21:00:09 volumio volumio[3697]: info: CorePlayQueue::getTrack 1 Apr 15 21:00:09 volumio volumio[3697]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 21:00:09 volumio volumio[3697]: info: CoreCommandRouter::volumioPushState Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.500+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_STOPPED positionMs=0 volume=97 Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.500+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/1042.wav title=02.我是真的爱你 Apr 15 21:00:09 volumio volumio[3697]: info: sendMpdCommand status took 123 milliseconds Apr 15 21:00:09 volumio volumio[3697]: info: sendMpdCommand stop took 18 milliseconds Apr 15 21:00:09 volumio volumio[3697]: verbose: ControllerMpd::parseState Apr 15 21:00:09 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand clear Apr 15 21:00:09 volumio volumio[3697]: info: ControllerMpd::pushState Apr 15 21:00:09 volumio volumio[3697]: info: CoreCommandRouter::servicePushState Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::pushState Apr 15 21:00:09 volumio volumio[3697]: info: CorePlayQueue::getTrack 1 Apr 15 21:00:09 volumio volumio[3697]: info: CoreCommandRouter::volumioPushState Apr 15 21:00:09 volumio volumio[3697]: info: CorePlayQueue::getTrack 1 Apr 15 21:00:09 volumio volumio[3697]: 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} Apr 15 21:00:09 volumio volumio[3697]: verbose: CURRENT POSITION 1 Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::syncState stateService stop Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::syncState currentStatus stop Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::pushState Apr 15 21:00:09 volumio volumio[3697]: info: CorePlayQueue::getTrack 1 Apr 15 21:00:09 volumio volumio[3697]: info: CoreCommandRouter::volumioPushState Apr 15 21:00:09 volumio volumio[3697]: info: No code Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::pushState Apr 15 21:00:09 volumio volumio[3697]: info: CorePlayQueue::getTrack 1 Apr 15 21:00:09 volumio volumio[3697]: info: CoreCommandRouter::volumioPushState Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.529+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_STOPPED positionMs=0 volume=97 Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.530+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/1042.wav title=02.我是真的爱你 Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.531+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_STOPPED positionMs=0 volume=97 Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.531+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/1042.wav title=02.我是真的爱你 Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.532+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_STOPPED positionMs=0 volume=97 Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.533+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/1042.wav title=02.我是真的爱你 Apr 15 21:00:09 volumio volumio[3697]: info: ------------------------------ 160ms Apr 15 21:00:09 volumio volumio[3697]: info: Apr 15 21:00:09 volumio volumio[3697]: ---------------------------- MPD announces system playlist update Apr 15 21:00:09 volumio volumio[3697]: info: Ignoring MPD Status Update Apr 15 21:00:09 volumio volumio[3697]: info: sendMpdCommand clear took 62 milliseconds Apr 15 21:00:09 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand load "http://10.0.0.9:8200/MediaItems/1042.wav" Apr 15 21:00:09 volumio volumio[3697]: info: Apr 15 21:00:09 volumio volumio[3697]: ---------------------------- MPD announces system playlist update Apr 15 21:00:09 volumio volumio[3697]: info: Ignoring MPD Status Update Apr 15 21:00:09 volumio volumio[3697]: info: Apr 15 21:00:09 volumio volumio[3697]: ---------------------------- MPD announces system playlist update Apr 15 21:00:09 volumio volumio[3697]: info: Ignoring MPD Status Update Apr 15 21:00:09 volumio volumio[3697]: error: updateQueue error: null Apr 15 21:00:09 volumio volumio[3697]: info: ------------------------------ 9ms Apr 15 21:00:09 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand add "http://10.0.0.9:8200/MediaItems/1042.wav" Apr 15 21:00:09 volumio volumio[3697]: error: updateQueue error: null Apr 15 21:00:09 volumio volumio[3697]: error: updateQueue error: null Apr 15 21:00:09 volumio volumio[3697]: info: Apr 15 21:00:09 volumio volumio[3697]: ---------------------------- MPD announces system playlist update Apr 15 21:00:09 volumio volumio[3697]: info: Ignoring MPD Status Update Apr 15 21:00:09 volumio volumio[3697]: info: ------------------------------ 8ms Apr 15 21:00:09 volumio volumio[3697]: info: ------------------------------ 7ms Apr 15 21:00:09 volumio volumio[3697]: info: sendMpdCommand add "http://10.0.0.9:8200/MediaItems/1042.wav" took 2 milliseconds Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 15 21:00:09 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand play Apr 15 21:00:09 volumio volumio[3697]: info: Apr 15 21:00:09 volumio volumio[3697]: ---------------------------- MPD announces system playlist update Apr 15 21:00:09 volumio volumio[3697]: info: Ignoring MPD Status Update Apr 15 21:00:09 volumio volumio[3697]: info: Apr 15 21:00:09 volumio volumio[3697]: ---------------------------- MPD announces system playlist update Apr 15 21:00:09 volumio volumio[3697]: info: Ignoring MPD Status Update Apr 15 21:00:09 volumio volumio[3697]: info: ------------------------------ 20ms Apr 15 21:00:09 volumio volumio[3697]: info: sendMpdCommand play took 18 milliseconds Apr 15 21:00:09 volumio volumio[3697]: info: ------------------------------ 6ms Apr 15 21:00:09 volumio volumio[3697]: info: ------------------------------ 3ms Apr 15 21:00:09 volumio volumio[3697]: info: Apr 15 21:00:09 volumio volumio[3697]: ---------------------------- MPD announces state update: player Apr 15 21:00:09 volumio volumio[3697]: info: ControllerMpd::getState Apr 15 21:00:09 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand status Apr 15 21:00:09 volumio volumio[3697]: info: Apr 15 21:00:09 volumio volumio[3697]: ---------------------------- MPD announces state update: player Apr 15 21:00:09 volumio volumio[3697]: info: ControllerMpd::getState Apr 15 21:00:09 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand status Apr 15 21:00:09 volumio volumio[3697]: info: Apr 15 21:00:09 volumio volumio[3697]: ---------------------------- MPD announces state update: player Apr 15 21:00:09 volumio volumio[3697]: info: ControllerMpd::getState Apr 15 21:00:09 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand status Apr 15 21:00:09 volumio volumio[3697]: info: Apr 15 21:00:09 volumio volumio[3697]: ---------------------------- MPD announces state update: player Apr 15 21:00:09 volumio volumio[3697]: info: ControllerMpd::getState Apr 15 21:00:09 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand status Apr 15 21:00:09 volumio volumio[3697]: info: Apr 15 21:00:09 volumio volumio[3697]: ---------------------------- MPD announces state update: player Apr 15 21:00:09 volumio volumio[3697]: info: sendMpdCommand status took 7 milliseconds Apr 15 21:00:09 volumio volumio[3697]: info: ControllerMpd::getState Apr 15 21:00:09 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand status Apr 15 21:00:09 volumio volumio[3697]: info: sendMpdCommand status took 5 milliseconds Apr 15 21:00:09 volumio volumio[3697]: info: sendMpdCommand status took 4 milliseconds Apr 15 21:00:09 volumio volumio[3697]: verbose: ControllerMpd::parseState Apr 15 21:00:09 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 15 21:00:09 volumio volumio[3697]: verbose: ControllerMpd::parseState Apr 15 21:00:09 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 15 21:00:09 volumio volumio[3697]: verbose: ControllerMpd::parseState Apr 15 21:00:09 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 15 21:00:09 volumio volumio[3697]: info: sendMpdCommand status took 5 milliseconds Apr 15 21:00:09 volumio volumio[3697]: info: sendMpdCommand status took 4 milliseconds Apr 15 21:00:09 volumio volumio[3697]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 15 21:00:09 volumio volumio[3697]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 15 21:00:09 volumio volumio[3697]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 15 21:00:09 volumio volumio[3697]: verbose: ControllerMpd::parseState Apr 15 21:00:09 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 15 21:00:09 volumio volumio[3697]: verbose: ControllerMpd::parseState Apr 15 21:00:09 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 15 21:00:09 volumio volumio[3697]: verbose: ControllerMpd::parseTrackInfo Apr 15 21:00:09 volumio volumio[3697]: verbose: ControllerMpd::parseTrackInfo Apr 15 21:00:09 volumio volumio[3697]: verbose: ControllerMpd::parseTrackInfo Apr 15 21:00:09 volumio volumio[3697]: info: ControllerMpd::pushState Apr 15 21:00:09 volumio volumio[3697]: info: CoreCommandRouter::servicePushState Apr 15 21:00:09 volumio volumio[3697]: info: CorePlayQueue::getTrack 1 Apr 15 21:00:09 volumio volumio[3697]: verbose: STATE SERVICE {"status":"play","position":0,"seek":113,"duration":283,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1411 Kbps","isStreaming":false,"title":"1042.wav","artist":null,"album":null,"uri":"http://10.0.0.9:8200/MediaItems/1042.wav","trackType":"wav"} Apr 15 21:00:09 volumio volumio[3697]: verbose: CURRENT POSITION 1 Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::syncState stateService play Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::syncState currentStatus stop Apr 15 21:00:09 volumio volumio[3697]: info: ControllerMpd::pushState Apr 15 21:00:09 volumio volumio[3697]: info: CoreCommandRouter::servicePushState Apr 15 21:00:09 volumio volumio[3697]: info: CorePlayQueue::getTrack 1 Apr 15 21:00:09 volumio volumio[3697]: verbose: STATE SERVICE {"status":"play","position":0,"seek":844,"duration":283,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1411 Kbps","isStreaming":false,"title":"1042.wav","artist":null,"album":null,"uri":"http://10.0.0.9:8200/MediaItems/1042.wav","trackType":"wav"} Apr 15 21:00:09 volumio volumio[3697]: verbose: CURRENT POSITION 1 Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::syncState stateService play Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::syncState currentStatus play Apr 15 21:00:09 volumio volumio[3697]: info: Received an update from plugin. extracting info from payload Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::pushState Apr 15 21:00:09 volumio volumio[3697]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 21:00:09 volumio volumio[3697]: info: CoreCommandRouter::volumioPushState Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::pushState Apr 15 21:00:09 volumio volumio[3697]: info: CoreCommandRouter::volumioPushState Apr 15 21:00:09 volumio volumio[3697]: info: ControllerMpd::pushState Apr 15 21:00:09 volumio volumio[3697]: info: CoreCommandRouter::servicePushState Apr 15 21:00:09 volumio volumio[3697]: info: CorePlayQueue::getTrack 1 Apr 15 21:00:09 volumio volumio[3697]: verbose: STATE SERVICE {"status":"play","position":0,"seek":844,"duration":283,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1411 Kbps","isStreaming":false,"title":"1042.wav","artist":null,"album":null,"uri":"http://10.0.0.9:8200/MediaItems/1042.wav","trackType":"wav"} Apr 15 21:00:09 volumio volumio[3697]: verbose: CURRENT POSITION 1 Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::syncState stateService play Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::syncState currentStatus play Apr 15 21:00:09 volumio volumio[3697]: info: Received an update from plugin. extracting info from payload Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::pushState Apr 15 21:00:09 volumio volumio[3697]: info: CoreCommandRouter::volumioPushState Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::pushState Apr 15 21:00:09 volumio volumio[3697]: info: CoreCommandRouter::volumioPushState Apr 15 21:00:09 volumio volumio[3697]: info: ------------------------------ 53ms Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.715+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_PLAYING positionMs=113 volume=97 Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.716+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_PLAYING positionMs=113 volume=97 Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.717+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/1042.wav title=1042.wav Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.717+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_PLAYING positionMs=113 volume=97 Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.718+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/1042.wav title=1042.wav Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.716+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/1042.wav title=1042.wav Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.720+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_PLAYING positionMs=113 volume=97 Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.721+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/1042.wav title=1042.wav Apr 15 21:00:09 volumio volumio[3697]: info: ------------------------------ 92ms Apr 15 21:00:09 volumio volumio[3697]: info: ------------------------------ 91ms Apr 15 21:00:09 volumio volumio[3697]: info: Apr 15 21:00:09 volumio volumio[3697]: ---------------------------- MPD announces state update: player Apr 15 21:00:09 volumio volumio[3697]: info: ControllerMpd::getState Apr 15 21:00:09 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand status Apr 15 21:00:09 volumio volumio[3697]: info: sendMpdCommand playlistinfo took 87 milliseconds Apr 15 21:00:09 volumio volumio[3697]: info: sendMpdCommand playlistinfo took 87 milliseconds Apr 15 21:00:09 volumio volumio[3697]: verbose: ControllerMpd::parseTrackInfo Apr 15 21:00:09 volumio volumio[3697]: verbose: ControllerMpd::parseTrackInfo Apr 15 21:00:09 volumio volumio[3697]: info: ControllerMpd::pushState Apr 15 21:00:09 volumio volumio[3697]: info: CoreCommandRouter::servicePushState Apr 15 21:00:09 volumio volumio[3697]: info: CorePlayQueue::getTrack 1 Apr 15 21:00:09 volumio volumio[3697]: verbose: STATE SERVICE {"status":"play","position":0,"seek":844,"duration":283,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1411 Kbps","isStreaming":false,"title":"1042.wav","artist":null,"album":null,"uri":"http://10.0.0.9:8200/MediaItems/1042.wav","trackType":"wav"} Apr 15 21:00:09 volumio volumio[3697]: verbose: CURRENT POSITION 1 Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::syncState stateService play Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::syncState currentStatus play Apr 15 21:00:09 volumio volumio[3697]: info: Received an update from plugin. extracting info from payload Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::pushState Apr 15 21:00:09 volumio volumio[3697]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 21:00:09 volumio volumio[3697]: info: CoreCommandRouter::volumioPushState Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::pushState Apr 15 21:00:09 volumio volumio[3697]: info: CoreCommandRouter::volumioPushState Apr 15 21:00:09 volumio volumio[3697]: info: ControllerMpd::pushState Apr 15 21:00:09 volumio volumio[3697]: info: CoreCommandRouter::servicePushState Apr 15 21:00:09 volumio volumio[3697]: info: CorePlayQueue::getTrack 1 Apr 15 21:00:09 volumio volumio[3697]: verbose: STATE SERVICE {"status":"play","position":0,"seek":844,"duration":283,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1411 Kbps","isStreaming":false,"title":"1042.wav","artist":null,"album":null,"uri":"http://10.0.0.9:8200/MediaItems/1042.wav","trackType":"wav"} Apr 15 21:00:09 volumio volumio[3697]: verbose: CURRENT POSITION 1 Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::syncState stateService play Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::syncState currentStatus play Apr 15 21:00:09 volumio volumio[3697]: info: Received an update from plugin. extracting info from payload Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::pushState Apr 15 21:00:09 volumio volumio[3697]: info: CoreCommandRouter::volumioPushState Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::pushState Apr 15 21:00:09 volumio volumio[3697]: info: CoreCommandRouter::volumioPushState Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.787+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_PLAYING positionMs=235 volume=97 Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.791+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_PLAYING positionMs=235 volume=97 Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.796+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_PLAYING positionMs=235 volume=97 Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.797+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_PLAYING positionMs=235 volume=97 Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.797+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/1042.wav title=1042.wav Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.798+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/1042.wav title=1042.wav Apr 15 21:00:09 volumio volumio[3697]: info: ------------------------------ 156ms Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.799+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/1042.wav title=1042.wav Apr 15 21:00:09 volumio volumio[3697]: info: ------------------------------ 156ms Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.801+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/1042.wav title=1042.wav Apr 15 21:00:09 volumio volumio[3697]: info: sendMpdCommand status took 95 milliseconds Apr 15 21:00:09 volumio volumio[3697]: verbose: ControllerMpd::parseState Apr 15 21:00:09 volumio volumio[3697]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 15 21:00:09 volumio volumio[3697]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 15 21:00:09 volumio volumio[3697]: verbose: ControllerMpd::parseTrackInfo Apr 15 21:00:09 volumio volumio[3697]: info: ControllerMpd::pushState Apr 15 21:00:09 volumio volumio[3697]: info: CoreCommandRouter::servicePushState Apr 15 21:00:09 volumio volumio[3697]: info: CorePlayQueue::getTrack 1 Apr 15 21:00:09 volumio volumio[3697]: verbose: STATE SERVICE {"status":"play","position":0,"seek":844,"duration":283,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1411 Kbps","isStreaming":false,"title":"1042.wav","artist":null,"album":null,"uri":"http://10.0.0.9:8200/MediaItems/1042.wav","trackType":"wav"} Apr 15 21:00:09 volumio volumio[3697]: verbose: CURRENT POSITION 1 Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::syncState stateService play Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::syncState currentStatus play Apr 15 21:00:09 volumio volumio[3697]: info: Received an update from plugin. extracting info from payload Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::pushState Apr 15 21:00:09 volumio volumio[3697]: info: CoreCommandRouter::volumioPushState Apr 15 21:00:09 volumio volumio[3697]: info: CoreStateMachine::pushState Apr 15 21:00:09 volumio volumio[3697]: info: CoreCommandRouter::volumioPushState Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.862+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_PLAYING positionMs=235 volume=97 Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.863+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/1042.wav title=1042.wav Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.864+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_PLAYING positionMs=235 volume=97 Apr 15 21:00:09 volumio volumio5-onboarding[2083]: time=2026-04-15T21:00:09.865+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/1042.wav title=1042.wav Apr 15 21:00:09 volumio volumio[3697]: info: ------------------------------ 133ms Apr 15 21:00:13 volumio volumio[3697]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 15 21:00:13 volumio volumio[3697]: Error: connect ETIMEDOUT 31.13.69.169:443 Apr 15 21:00:13 volumio volumio[3697]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Apr 15 21:00:13 volumio volumio[3697]: errno: -110, Apr 15 21:00:13 volumio volumio[3697]: code: 'ETIMEDOUT', Apr 15 21:00:13 volumio volumio[3697]: syscall: 'connect', Apr 15 21:00:13 volumio volumio[3697]: address: '31.13.69.169', Apr 15 21:00:13 volumio volumio[3697]: port: 443 Apr 15 21:00:13 volumio volumio[3697]: } Apr 15 21:00:13 volumio volumio[3697]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 15 21:00:13 volumio sudo[4393]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-15 20:59' Apr 15 21:00:13 volumio sudo[4393]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:45:45 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="6bf7cd61fe53483b72878254df87f1c0"