Feb 22 21:57:00 volumio kernel: vc4-drm gpu: [drm] *ERROR* flip_done timed out Feb 22 21:57:00 volumio kernel: vc4-drm gpu: [drm] *ERROR* [CRTC:100:pixelvalve-2] commit wait timed out Feb 22 21:57:01 volumio wpa_supplicant[3207]: RRM: Ignoring radio measurement request: Not RRM network Feb 22 21:57:03 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 22 21:57:03 volumio sudo[8270]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 22 21:57:03 volumio sudo[8270]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 22 21:57:03 volumio sudo[8270]: pam_unix(sudo:session): session closed for user root Feb 22 21:57:03 volumio sudo[8272]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 22 21:57:03 volumio sudo[8272]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 22 21:57:03 volumio sudo[8272]: pam_unix(sudo:session): session closed for user root Feb 22 21:57:03 volumio sudo[8276]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 22 21:57:03 volumio sudo[8276]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 22 21:57:04 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 22 21:57:04 volumio sudo[8276]: pam_unix(sudo:session): session closed for user root Feb 22 21:57:04 volumio volumio[1200]: info: Upmpdcli Daemon Started Feb 22 21:57:04 volumio upmpdcli[8293]: writing RSA key Feb 22 21:57:04 volumio wpa_supplicant[3207]: RRM: Ignoring radio measurement request: Not RRM network Feb 22 21:57:07 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 22 21:57:08 volumio wpa_supplicant[3207]: RRM: Ignoring radio measurement request: Not RRM network Feb 22 21:57:10 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , updateDb Feb 22 21:57:10 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand update Feb 22 21:57:10 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand status Feb 22 21:57:10 volumio volumio[1200]: info: Feb 22 21:57:10 volumio volumio[1200]: ---------------------------- MPD announces state update: update Feb 22 21:57:10 volumio volumio[1200]: info: sendMpdCommand update took 4 milliseconds Feb 22 21:57:10 volumio volumio[1200]: info: ControllerMpd::getState Feb 22 21:57:10 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand status Feb 22 21:57:10 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand status Feb 22 21:57:10 volumio volumio[1200]: info: Feb 22 21:57:10 volumio volumio[1200]: ---------------------------- MPD announces state update: update Feb 22 21:57:10 volumio volumio[1200]: info: ControllerMpd::getState Feb 22 21:57:10 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand status Feb 22 21:57:10 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand status Feb 22 21:57:10 volumio volumio[1200]: info: Feb 22 21:57:10 volumio volumio[1200]: ---------------------------- MPD announces state update: update Feb 22 21:57:10 volumio volumio[1200]: info: ControllerMpd::getState Feb 22 21:57:10 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand status Feb 22 21:57:10 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand status Feb 22 21:57:10 volumio volumio[1200]: info: Feb 22 21:57:10 volumio volumio[1200]: ---------------------------- MPD announces state update: update Feb 22 21:57:10 volumio volumio[1200]: info: ControllerMpd::getState Feb 22 21:57:10 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand status Feb 22 21:57:10 volumio volumio[1200]: info: sendMpdCommand status took 13 milliseconds Feb 22 21:57:10 volumio volumio[1200]: info: sendMpdCommand status took 11 milliseconds Feb 22 21:57:10 volumio volumio[1200]: info: sendMpdCommand status took 10 milliseconds Feb 22 21:57:10 volumio volumio[1200]: info: sendMpdCommand status took 10 milliseconds Feb 22 21:57:10 volumio volumio[1200]: info: sendMpdCommand status took 9 milliseconds Feb 22 21:57:10 volumio volumio[1200]: info: sendMpdCommand status took 8 milliseconds Feb 22 21:57:10 volumio volumio[1200]: verbose: ControllerMpd::parseState Feb 22 21:57:11 volumio volumio[1200]: info: Command Router : Notfying DB Updatefalse Feb 22 21:57:11 volumio volumio[1200]: info: CoreCommandRouter::Close All Modals sent Feb 22 21:57:11 volumio volumio[1200]: verbose: ControllerMpd::parseState Feb 22 21:57:11 volumio volumio[1200]: verbose: ControllerMpd::parseState Feb 22 21:57:11 volumio volumio[1200]: info: Command Router : Notfying DB Updatefalse Feb 22 21:57:11 volumio volumio[1200]: info: CoreCommandRouter::Close All Modals sent Feb 22 21:57:11 volumio volumio[1200]: verbose: ControllerMpd::parseState Feb 22 21:57:11 volumio volumio[1200]: verbose: ControllerMpd::parseState Feb 22 21:57:11 volumio volumio[1200]: info: Command Router : Notfying DB Updatefalse Feb 22 21:57:11 volumio volumio[1200]: info: CoreCommandRouter::Close All Modals sent Feb 22 21:57:11 volumio volumio[1200]: verbose: ControllerMpd::parseState Feb 22 21:57:11 volumio volumio[1200]: info: ControllerMpd::pushState Feb 22 21:57:11 volumio volumio[1200]: info: CoreCommandRouter::servicePushState Feb 22 21:57:11 volumio volumio[1200]: info: CoreStateMachine::pushState Feb 22 21:57:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:11 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 22 21:57:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:11 volumio volumio[1200]: 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 22 21:57:11 volumio volumio[1200]: verbose: CURRENT POSITION 0 Feb 22 21:57:11 volumio volumio[1200]: info: CoreStateMachine::syncState stateService stop Feb 22 21:57:11 volumio volumio[1200]: info: CoreStateMachine::syncState currentStatus stop Feb 22 21:57:11 volumio volumio[1200]: info: CoreStateMachine::pushState Feb 22 21:57:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:11 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 22 21:57:11 volumio volumio[1200]: info: No code Feb 22 21:57:11 volumio volumio[1200]: info: CoreStateMachine::pushState Feb 22 21:57:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:11 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 22 21:57:11 volumio volumio[1200]: info: ControllerMpd::pushState Feb 22 21:57:11 volumio volumio[1200]: info: CoreCommandRouter::servicePushState Feb 22 21:57:11 volumio volumio[1200]: info: CoreStateMachine::pushState Feb 22 21:57:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:11 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 22 21:57:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:11 volumio volumio[1200]: 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 22 21:57:11 volumio volumio[1200]: verbose: CURRENT POSITION 0 Feb 22 21:57:11 volumio volumio[1200]: info: CoreStateMachine::syncState stateService stop Feb 22 21:57:11 volumio volumio[1200]: info: CoreStateMachine::syncState currentStatus stop Feb 22 21:57:11 volumio volumio[1200]: info: CoreStateMachine::pushState Feb 22 21:57:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:11 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 22 21:57:11 volumio volumio[1200]: info: No code Feb 22 21:57:11 volumio volumio[1200]: info: CoreStateMachine::pushState Feb 22 21:57:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:11 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 22 21:57:11 volumio volumio[1200]: info: ControllerMpd::pushState Feb 22 21:57:11 volumio volumio[1200]: info: CoreCommandRouter::servicePushState Feb 22 21:57:11 volumio volumio[1200]: info: CoreStateMachine::pushState Feb 22 21:57:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:11 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 22 21:57:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:11 volumio volumio[1200]: 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 22 21:57:11 volumio volumio[1200]: verbose: CURRENT POSITION 0 Feb 22 21:57:11 volumio volumio[1200]: info: CoreStateMachine::syncState stateService stop Feb 22 21:57:11 volumio volumio[1200]: info: CoreStateMachine::syncState currentStatus stop Feb 22 21:57:11 volumio volumio[1200]: info: CoreStateMachine::pushState Feb 22 21:57:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:11 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 22 21:57:11 volumio volumio[1200]: info: No code Feb 22 21:57:11 volumio volumio[1200]: info: CoreStateMachine::pushState Feb 22 21:57:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:11 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 22 21:57:11 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:11.165+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" state=STATUS_STOPPED positionMs=0 volume=86 Feb 22 21:57:11 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:11.166+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" id= title= Feb 22 21:57:11 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:11.167+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" state=STATUS_STOPPED positionMs=0 volume=86 Feb 22 21:57:11 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:11.167+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" id= title= Feb 22 21:57:11 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:11.168+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" state=STATUS_STOPPED positionMs=0 volume=86 Feb 22 21:57:11 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:11.168+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" id= title= Feb 22 21:57:11 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:11.170+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" state=STATUS_STOPPED positionMs=0 volume=86 Feb 22 21:57:11 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:11.170+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" state=STATUS_STOPPED positionMs=0 volume=86 Feb 22 21:57:11 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:11.172+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" id= title= Feb 22 21:57:11 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:11.172+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" id= title= Feb 22 21:57:11 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:11.173+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" state=STATUS_STOPPED positionMs=0 volume=86 Feb 22 21:57:11 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:11.173+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" state=STATUS_STOPPED positionMs=0 volume=86 Feb 22 21:57:11 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:11.173+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" id= title= Feb 22 21:57:11 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:11.173+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" id= title= Feb 22 21:57:11 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:11.174+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" state=STATUS_STOPPED positionMs=0 volume=86 Feb 22 21:57:11 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:11.174+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" id= title= Feb 22 21:57:11 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:11.174+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" state=STATUS_STOPPED positionMs=0 volume=86 Feb 22 21:57:11 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:11.174+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" id= title= Feb 22 21:57:11 volumio volumio[1200]: info: ------------------------------ 289ms Feb 22 21:57:11 volumio volumio[1200]: info: ------------------------------ 287ms Feb 22 21:57:11 volumio volumio[1200]: info: ------------------------------ 285ms Feb 22 21:57:11 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand status Feb 22 21:57:11 volumio volumio[1200]: info: Feb 22 21:57:11 volumio volumio[1200]: ---------------------------- MPD announces state update: update Feb 22 21:57:11 volumio volumio[1200]: info: ControllerMpd::getState Feb 22 21:57:11 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand status Feb 22 21:57:11 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand status Feb 22 21:57:11 volumio volumio[1200]: info: Feb 22 21:57:11 volumio volumio[1200]: ---------------------------- MPD announces state update: update Feb 22 21:57:11 volumio volumio[1200]: info: ControllerMpd::getState Feb 22 21:57:11 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand status Feb 22 21:57:11 volumio volumio[1200]: info: sendMpdCommand status took 290 milliseconds Feb 22 21:57:11 volumio volumio[1200]: info: sendMpdCommand status took 287 milliseconds Feb 22 21:57:11 volumio volumio[1200]: info: sendMpdCommand status took 6 milliseconds Feb 22 21:57:11 volumio volumio[1200]: info: sendMpdCommand status took 6 milliseconds Feb 22 21:57:11 volumio volumio[1200]: info: sendMpdCommand status took 5 milliseconds Feb 22 21:57:11 volumio volumio[1200]: info: sendMpdCommand status took 4 milliseconds Feb 22 21:57:11 volumio volumio[1200]: verbose: ControllerMpd::parseState Feb 22 21:57:11 volumio kernel: vc4-drm gpu: [drm] *ERROR* flip_done timed out Feb 22 21:57:11 volumio kernel: vc4-drm gpu: [drm] *ERROR* [CONNECTOR:33:HDMI-A-1] commit wait timed out Feb 22 21:57:11 volumio volumio[1200]: info: Command Router : Notfying DB Updatefalse Feb 22 21:57:11 volumio volumio[1200]: info: CoreCommandRouter::Close All Modals sent Feb 22 21:57:11 volumio volumio[1200]: verbose: ControllerMpd::parseState Feb 22 21:57:11 volumio volumio[1200]: verbose: ControllerMpd::parseState Feb 22 21:57:11 volumio volumio[1200]: info: Command Router : Notfying DB Updatefalse Feb 22 21:57:11 volumio volumio[1200]: info: CoreCommandRouter::Close All Modals sent Feb 22 21:57:11 volumio volumio[1200]: verbose: ControllerMpd::parseState Feb 22 21:57:11 volumio volumio[1200]: verbose: ControllerMpd::parseState Feb 22 21:57:11 volumio volumio[1200]: info: Command Router : Notfying DB Updatefalse Feb 22 21:57:11 volumio volumio[1200]: info: CoreCommandRouter::Close All Modals sent Feb 22 21:57:11 volumio volumio[1200]: verbose: ControllerMpd::parseState Feb 22 21:57:11 volumio volumio[1200]: info: ControllerMpd::pushState Feb 22 21:57:11 volumio volumio[1200]: info: CoreCommandRouter::servicePushState Feb 22 21:57:11 volumio volumio[1200]: info: CoreStateMachine::pushState Feb 22 21:57:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:11 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 22 21:57:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:11 volumio volumio[1200]: 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 22 21:57:11 volumio volumio[1200]: verbose: CURRENT POSITION 0 Feb 22 21:57:11 volumio volumio[1200]: info: CoreStateMachine::syncState stateService stop Feb 22 21:57:11 volumio volumio[1200]: info: CoreStateMachine::syncState currentStatus stop Feb 22 21:57:11 volumio volumio[1200]: info: CoreStateMachine::pushState Feb 22 21:57:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:11 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 22 21:57:11 volumio volumio[1200]: info: No code Feb 22 21:57:11 volumio volumio[1200]: info: CoreStateMachine::pushState Feb 22 21:57:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:11 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 22 21:57:11 volumio volumio[1200]: info: ControllerMpd::pushState Feb 22 21:57:11 volumio volumio[1200]: info: CoreCommandRouter::servicePushState Feb 22 21:57:11 volumio volumio[1200]: info: CoreStateMachine::pushState Feb 22 21:57:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:11 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 22 21:57:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:11 volumio volumio[1200]: 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 22 21:57:11 volumio volumio[1200]: verbose: CURRENT POSITION 0 Feb 22 21:57:11 volumio volumio[1200]: info: CoreStateMachine::syncState stateService stop Feb 22 21:57:11 volumio volumio[1200]: info: CoreStateMachine::syncState currentStatus stop Feb 22 21:57:11 volumio volumio[1200]: info: CoreStateMachine::pushState Feb 22 21:57:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:11 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 22 21:57:11 volumio volumio[1200]: info: No code Feb 22 21:57:11 volumio volumio[1200]: info: CoreStateMachine::pushState Feb 22 21:57:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:11 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 22 21:57:11 volumio volumio[1200]: info: ControllerMpd::pushState Feb 22 21:57:11 volumio volumio[1200]: info: CoreCommandRouter::servicePushState Feb 22 21:57:11 volumio volumio[1200]: info: CoreStateMachine::pushState Feb 22 21:57:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:11 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 22 21:57:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:11 volumio volumio[1200]: 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 22 21:57:11 volumio volumio[1200]: verbose: CURRENT POSITION 0 Feb 22 21:57:11 volumio volumio[1200]: info: CoreStateMachine::syncState stateService stop Feb 22 21:57:11 volumio volumio[1200]: info: CoreStateMachine::syncState currentStatus stop Feb 22 21:57:11 volumio volumio[1200]: info: CoreStateMachine::pushState Feb 22 21:57:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:11 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 22 21:57:11 volumio volumio[1200]: info: No code Feb 22 21:57:11 volumio volumio[1200]: info: CoreStateMachine::pushState Feb 22 21:57:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:11 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 22 21:57:11 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:11.336+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" state=STATUS_STOPPED positionMs=0 volume=86 Feb 22 21:57:11 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:11.336+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" id= title= Feb 22 21:57:11 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:11.337+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" state=STATUS_STOPPED positionMs=0 volume=86 Feb 22 21:57:11 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:11.337+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" id= title= Feb 22 21:57:11 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:11.339+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" state=STATUS_STOPPED positionMs=0 volume=86 Feb 22 21:57:11 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:11.340+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" id= title= Feb 22 21:57:11 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:11.340+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" state=STATUS_STOPPED positionMs=0 volume=86 Feb 22 21:57:11 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:11.340+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" id= title= Feb 22 21:57:11 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:11.342+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" state=STATUS_STOPPED positionMs=0 volume=86 Feb 22 21:57:11 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:11.342+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" id= title= Feb 22 21:57:11 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:11.344+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" state=STATUS_STOPPED positionMs=0 volume=86 Feb 22 21:57:11 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:11.344+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" state=STATUS_STOPPED positionMs=0 volume=86 Feb 22 21:57:11 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:11.345+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" state=STATUS_STOPPED positionMs=0 volume=86 Feb 22 21:57:11 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:11.345+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" id= title= Feb 22 21:57:11 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:11.345+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" id= title= Feb 22 21:57:11 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:11.345+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" id= title= Feb 22 21:57:11 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:11.345+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" state=STATUS_STOPPED positionMs=0 volume=86 Feb 22 21:57:11 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:11.346+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" id= title= Feb 22 21:57:11 volumio volumio[1200]: info: ------------------------------ 454ms Feb 22 21:57:11 volumio volumio[1200]: info: ------------------------------ 172ms Feb 22 21:57:11 volumio volumio[1200]: info: ------------------------------ 171ms Feb 22 21:57:11 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 22 21:57:11 volumio wpa_supplicant[3207]: RRM: Ignoring radio measurement request: Not RRM network Feb 22 21:57:15 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 22 21:57:15 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Feb 22 21:57:15 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Feb 22 21:57:16 volumio wpa_supplicant[3207]: RRM: Ignoring radio measurement request: Not RRM network Feb 22 21:57:19 volumio wpa_supplicant[3207]: RRM: Ignoring radio measurement request: Not RRM network Feb 22 21:57:19 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 22 21:57:21 volumio kernel: vc4-drm gpu: [drm] *ERROR* flip_done timed out Feb 22 21:57:21 volumio kernel: vc4-drm gpu: [drm] *ERROR* [PLANE:89:plane-3] commit wait timed out Feb 22 21:57:22 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 22 21:57:22 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Feb 22 21:57:23 volumio wpa_supplicant[3207]: RRM: Ignoring radio measurement request: Not RRM network Feb 22 21:57:24 volumio volumio[1200]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 22 21:57:24 volumio volumio[1200]: info: touch_display: About to detect HDMI ports... Feb 22 21:57:26 volumio wpa_supplicant[3207]: RRM: Ignoring radio measurement request: Not RRM network Feb 22 21:57:30 volumio wpa_supplicant[3207]: RRM: Ignoring radio measurement request: Not RRM network Feb 22 21:57:31 volumio kernel: vc4-drm gpu: [drm] *ERROR* flip_done timed out Feb 22 21:57:31 volumio kernel: vc4-drm gpu: [drm] *ERROR* Timed out waiting for commit Feb 22 21:57:33 volumio wpa_supplicant[3207]: RRM: Ignoring radio measurement request: Not RRM network Feb 22 21:57:37 volumio wpa_supplicant[3207]: RRM: Ignoring radio measurement request: Not RRM network Feb 22 21:57:37 volumio volumio[1200]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 22 21:57:37 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Feb 22 21:57:37 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 22 21:57:37 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 22 21:57:37 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 22 21:57:37 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 22 21:57:37 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 22 21:57:37 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 22 21:57:37 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 22 21:57:37 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 22 21:57:37 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 22 21:57:37 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Feb 22 21:57:37 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Feb 22 21:57:40 volumio wpa_supplicant[3207]: RRM: Ignoring radio measurement request: Not RRM network Feb 22 21:57:41 volumio volumio[1200]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Feb 22 21:57:41 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Feb 22 21:57:41 volumio volumio[1200]: info: Preparing to save Alsa Options, stopping services first Feb 22 21:57:41 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Feb 22 21:57:41 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:41 volumio volumio[1200]: info: CoreCommandRouter::volumioPause Feb 22 21:57:41 volumio volumio[1200]: info: CoreStateMachine::pause Feb 22 21:57:41 volumio volumio[1200]: info: Saving Audio Output to: {"output_device":{"value":"5","label":"SMSL USB AUDIO"},"i2s":false,"i2sid":{"value":"adafruit-max98357","label":"Adafruit MAX98357"}} Feb 22 21:57:41 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 22 21:57:41 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 22 21:57:41 volumio kernel: vc4-drm gpu: [drm] *ERROR* [CRTC:100:pixelvalve-2] flip_done timed out Feb 22 21:57:41 volumio volumio[1200]: info: Device 5 does not have any Mixer Control Available Feb 22 21:57:41 volumio volumio[1200]: info: CoreCommandRouter::volumioUpdateVolumeSettings Feb 22 21:57:41 volumio volumio[1200]: info: Updating Volume Controller Parameters: Device: 5 Name: SMSL USB AUDIO Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Feb 22 21:57:42 volumio volumio[1200]: info: Disabling external Volume Control Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 22 21:57:42 volumio volumio[1200]: info: CoreStateMachine::pushState Feb 22 21:57:42 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 22 21:57:42 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:42.028+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 21:57:42 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:42.029+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" id= title= Feb 22 21:57:42 volumio volumio[1200]: info: Preparing to generate the ALSA configuration file Feb 22 21:57:42 volumio volumio[1200]: info: Feb 22 21:57:42 volumio volumio[1200]: ---------------------------- MPD announces state update: mixer Feb 22 21:57:42 volumio volumio[1200]: info: ControllerMpd::getState Feb 22 21:57:42 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand status Feb 22 21:57:42 volumio volumio[1200]: info: Feb 22 21:57:42 volumio volumio[1200]: ---------------------------- MPD announces state update: mixer Feb 22 21:57:42 volumio volumio[1200]: info: ControllerMpd::getState Feb 22 21:57:42 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand status Feb 22 21:57:42 volumio volumio[1200]: info: Feb 22 21:57:42 volumio volumio[1200]: ---------------------------- MPD announces state update: mixer Feb 22 21:57:42 volumio volumio[1200]: info: ControllerMpd::getState Feb 22 21:57:42 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand status Feb 22 21:57:42 volumio volumio[1200]: info: sendMpdCommand status took 4 milliseconds Feb 22 21:57:42 volumio volumio[1200]: verbose: ControllerMpd::parseState Feb 22 21:57:42 volumio volumio[1200]: info: ControllerMpd::pushState Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::servicePushState Feb 22 21:57:42 volumio volumio[1200]: info: CoreStateMachine::pushState Feb 22 21:57:42 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 22 21:57:42 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:42 volumio volumio[1200]: 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 22 21:57:42 volumio volumio[1200]: verbose: CURRENT POSITION 0 Feb 22 21:57:42 volumio volumio[1200]: info: CoreStateMachine::syncState stateService stop Feb 22 21:57:42 volumio volumio[1200]: info: CoreStateMachine::syncState currentStatus stop Feb 22 21:57:42 volumio volumio[1200]: info: CoreStateMachine::pushState Feb 22 21:57:42 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 22 21:57:42 volumio volumio[1200]: info: No code Feb 22 21:57:42 volumio volumio[1200]: info: CoreStateMachine::pushState Feb 22 21:57:42 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 22 21:57:42 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:42.077+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 21:57:42 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:42.079+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 21:57:42 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:42.079+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" id= title= Feb 22 21:57:42 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:42.079+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" id= title= Feb 22 21:57:42 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:42.080+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 21:57:42 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:42.081+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" id= title= Feb 22 21:57:42 volumio volumio[1200]: info: ------------------------------ 30ms Feb 22 21:57:42 volumio volumio[1200]: info: sendMpdCommand status took 42 milliseconds Feb 22 21:57:42 volumio volumio[1200]: info: sendMpdCommand status took 39 milliseconds Feb 22 21:57:42 volumio volumio[1200]: verbose: ControllerMpd::parseState Feb 22 21:57:42 volumio volumio[1200]: verbose: ControllerMpd::parseState Feb 22 21:57:42 volumio volumio[1200]: info: ControllerMpd::pushState Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::servicePushState Feb 22 21:57:42 volumio volumio[1200]: info: CoreStateMachine::pushState Feb 22 21:57:42 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 22 21:57:42 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:42 volumio volumio[1200]: 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 22 21:57:42 volumio volumio[1200]: verbose: CURRENT POSITION 0 Feb 22 21:57:42 volumio volumio[1200]: info: CoreStateMachine::syncState stateService stop Feb 22 21:57:42 volumio volumio[1200]: info: CoreStateMachine::syncState currentStatus stop Feb 22 21:57:42 volumio volumio[1200]: info: CoreStateMachine::pushState Feb 22 21:57:42 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 22 21:57:42 volumio volumio[1200]: info: No code Feb 22 21:57:42 volumio volumio[1200]: info: CoreStateMachine::pushState Feb 22 21:57:42 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 22 21:57:42 volumio volumio[1200]: info: ControllerMpd::pushState Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::servicePushState Feb 22 21:57:42 volumio volumio[1200]: info: CoreStateMachine::pushState Feb 22 21:57:42 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 22 21:57:42 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:42 volumio volumio[1200]: 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 22 21:57:42 volumio volumio[1200]: verbose: CURRENT POSITION 0 Feb 22 21:57:42 volumio volumio[1200]: info: CoreStateMachine::syncState stateService stop Feb 22 21:57:42 volumio volumio[1200]: info: CoreStateMachine::syncState currentStatus stop Feb 22 21:57:42 volumio volumio[1200]: info: CoreStateMachine::pushState Feb 22 21:57:42 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 22 21:57:42 volumio volumio[1200]: info: No code Feb 22 21:57:42 volumio volumio[1200]: info: CoreStateMachine::pushState Feb 22 21:57:42 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 22 21:57:42 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:42.138+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 21:57:42 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:42.139+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" id= title= Feb 22 21:57:42 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:42.140+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 21:57:42 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:42.140+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" id= title= Feb 22 21:57:42 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:42.142+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 21:57:42 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:42.142+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" id= title= Feb 22 21:57:42 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:42.144+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 21:57:42 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:42.144+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 21:57:42 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:42.145+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" id= title= Feb 22 21:57:42 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:42.145+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 21:57:42 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:42.145+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" id= title= Feb 22 21:57:42 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:42.145+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" id= title= Feb 22 21:57:42 volumio volumio[1200]: info: ------------------------------ 99ms Feb 22 21:57:42 volumio volumio[1200]: info: ------------------------------ 98ms Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Feb 22 21:57:42 volumio volumio[1200]: info: Asound.conf file written Feb 22 21:57:42 volumio sudo[8426]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Feb 22 21:57:42 volumio sudo[8426]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 22 21:57:42 volumio sudo[8426]: pam_unix(sudo:session): session closed for user root Feb 22 21:57:42 volumio volumio[1200]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Feb 22 21:57:42 volumio volumio[1200]: No state is present for card b1 Feb 22 21:57:42 volumio volumio[1200]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Feb 22 21:57:42 volumio volumio[1200]: /usr/share/alsa/init/bcm2835:14: control element not found Feb 22 21:57:42 volumio volumio[1200]: No state is present for card b1 Feb 22 21:57:42 volumio volumio[1200]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Feb 22 21:57:42 volumio volumio[1200]: No state is present for card Headphones Feb 22 21:57:42 volumio volumio[1200]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Feb 22 21:57:42 volumio volumio[1200]: /usr/share/alsa/init/bcm2835:20: control element not found Feb 22 21:57:42 volumio volumio[1200]: No state is present for card Headphones Feb 22 21:57:42 volumio volumio[1200]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Feb 22 21:57:42 volumio volumio[1200]: No state is present for card vc4hdmi0 Feb 22 21:57:42 volumio volumio[1200]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Feb 22 21:57:42 volumio volumio[1200]: Found hardware: "vc4-hdmi" "" "" "" "" Feb 22 21:57:42 volumio volumio[1200]: Hardware is initialized using a generic method Feb 22 21:57:42 volumio volumio[1200]: No state is present for card vc4hdmi0 Feb 22 21:57:42 volumio volumio[1200]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:3 use case configuration -2 Feb 22 21:57:42 volumio volumio[1200]: No state is present for card vc4hdmi1 Feb 22 21:57:42 volumio volumio[1200]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:3 use case configuration -2 Feb 22 21:57:42 volumio volumio[1200]: Found hardware: "vc4-hdmi" "" "" "" "" Feb 22 21:57:42 volumio volumio[1200]: Hardware is initialized using a generic method Feb 22 21:57:42 volumio volumio[1200]: No state is present for card vc4hdmi1 Feb 22 21:57:42 volumio volumio[1200]: No state is present for card AUDIO Feb 22 21:57:42 volumio volumio[1200]: Found hardware: "USB-Audio" "USB Mixer" "USB152a:85dd" "" "" Feb 22 21:57:42 volumio volumio[1200]: Hardware is initialized using a generic method Feb 22 21:57:42 volumio volumio[1200]: No state is present for card AUDIO Feb 22 21:57:42 volumio volumio[1200]: info: Output device has changed, restarting MPD Feb 22 21:57:42 volumio volumio[1200]: info: Output device has changed, restarting Shairport Sync Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 22 21:57:42 volumio sudo[8432]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 22 21:57:42 volumio sudo[8432]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 22 21:57:42 volumio sudo[8432]: pam_unix(sudo:session): session closed for user root Feb 22 21:57:42 volumio sudo[8434]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 22 21:57:42 volumio sudo[8434]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 22 21:57:42 volumio volumio[1200]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 22 21:57:42 volumio volumio[1200]: info: Output device has changed, restarting MPD Feb 22 21:57:42 volumio volumio[1200]: info: Output device has changed, restarting Shairport Sync Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 22 21:57:42 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 22 21:57:42 volumio sudo[8442]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 22 21:57:42 volumio sudo[8442]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 22 21:57:42 volumio sudo[8442]: pam_unix(sudo:session): session closed for user root Feb 22 21:57:42 volumio sudo[8445]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 22 21:57:42 volumio sudo[8445]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 22 21:57:42 volumio volumio[1200]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 22 21:57:42 volumio volumio[1200]: info: MPD Permissions set Feb 22 21:57:42 volumio volumio[1200]: info: MPD Permissions set Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 22 21:57:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 21:57:42 volumio volumio[1200]: info: Starting Shairport Sync Feb 22 21:57:42 volumio volumio[1200]: info: Starting Shairport Sync Feb 22 21:57:42 volumio sudo[8462]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 22 21:57:42 volumio sudo[8462]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 22 21:57:42 volumio sudo[8464]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 22 21:57:42 volumio sudo[8464]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 22 21:57:42 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 22 21:57:42 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 22 21:57:42 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 22 21:57:42 volumio systemd[1]: shairport-sync.service: Consumed 3.669s CPU time. Feb 22 21:57:42 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 22 21:57:42 volumio sudo[8464]: pam_unix(sudo:session): session closed for user root Feb 22 21:57:42 volumio sudo[8462]: pam_unix(sudo:session): session closed for user root Feb 22 21:57:42 volumio volumio[1200]: info: Shairport-Sync Started Feb 22 21:57:42 volumio volumio[1200]: info: Shairport-Sync Started Feb 22 21:57:43 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 22 21:57:43 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 22 21:57:43 volumio systemd[1]: mpd.service: Consumed 3.325s CPU time. Feb 22 21:57:43 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 22 21:57:43 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 22 21:57:43 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 22 21:57:43 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 22 21:57:43 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 22 21:57:43 volumio sudo[8483]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 22 21:57:43 volumio sudo[8483]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 22 21:57:43 volumio sudo[8483]: pam_unix(sudo:session): session closed for user root Feb 22 21:57:44 volumio wpa_supplicant[3207]: RRM: Ignoring radio measurement request: Not RRM network Feb 22 21:57:45 volumio mpd[8485]: 2026-02-22T21:57:45 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 22 21:57:45 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 22 21:57:45 volumio sudo[8434]: pam_unix(sudo:session): session closed for user root Feb 22 21:57:45 volumio sudo[8445]: pam_unix(sudo:session): session closed for user root Feb 22 21:57:45 volumio volumio[1200]: error: MPD error: The expression evaluated to a falsy value: Feb 22 21:57:45 volumio volumio[1200]: assert.ok(self.idling) Feb 22 21:57:45 volumio volumio[1200]: error: The expression evaluated to a falsy value: Feb 22 21:57:45 volumio volumio[1200]: assert.ok(self.idling) Feb 22 21:57:45 volumio volumio[1200]: error: updateQueue error: null Feb 22 21:57:46 volumio volumio[1200]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Feb 22 21:57:46 volumio volumio[1200]: info: CoreStateMachine::getcurrentVolume Feb 22 21:57:46 volumio volumio[1200]: info: CoreCommandRouter::volumioRetrievevolume Feb 22 21:57:46 volumio volumio[1200]: info: CoreStateMachine::pushState Feb 22 21:57:46 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 22 21:57:46 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 22 21:57:46 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:46.013+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 21:57:46 volumio volumio5-onboarding[3458]: time=2026-02-22T21:57:46.014+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.25:33590 @ 0x275e8d0" id= title= Feb 22 21:57:47 volumio wpa_supplicant[3207]: RRM: Ignoring radio measurement request: Not RRM network Feb 22 21:57:51 volumio wpa_supplicant[3207]: RRM: Ignoring radio measurement request: Not RRM network Feb 22 21:57:52 volumio kernel: vc4-drm gpu: [drm] *ERROR* flip_done timed out Feb 22 21:57:52 volumio kernel: vc4-drm gpu: [drm] *ERROR* [CRTC:100:pixelvalve-2] commit wait timed out Feb 22 21:57:54 volumio wpa_supplicant[3207]: RRM: Ignoring radio measurement request: Not RRM network Feb 22 21:57:56 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 22 21:57:56 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Feb 22 21:57:58 volumio wpa_supplicant[3207]: RRM: Ignoring radio measurement request: Not RRM network Feb 22 21:58:01 volumio wpa_supplicant[3207]: RRM: Ignoring radio measurement request: Not RRM network Feb 22 21:58:02 volumio kernel: vc4-drm gpu: [drm] *ERROR* flip_done timed out Feb 22 21:58:02 volumio kernel: vc4-drm gpu: [drm] *ERROR* [CONNECTOR:33:HDMI-A-1] commit wait timed out Feb 22 21:58:05 volumio volumio[1200]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 22 21:58:05 volumio volumio[1200]: info: touch_display: About to detect HDMI ports... Feb 22 21:58:06 volumio wpa_supplicant[3207]: RRM: Ignoring radio measurement request: Not RRM network Feb 22 21:58:09 volumio wpa_supplicant[3207]: RRM: Ignoring radio measurement request: Not RRM network Feb 22 21:58:12 volumio kernel: vc4-drm gpu: [drm] *ERROR* flip_done timed out Feb 22 21:58:12 volumio kernel: vc4-drm gpu: [drm] *ERROR* [PLANE:89:plane-3] commit wait timed out Feb 22 21:58:13 volumio wpa_supplicant[3207]: RRM: Ignoring radio measurement request: Not RRM network Feb 22 21:58:16 volumio wpa_supplicant[3207]: RRM: Ignoring radio measurement request: Not RRM network Feb 22 21:58:20 volumio wpa_supplicant[3207]: RRM: Ignoring radio measurement request: Not RRM network Feb 22 21:58:22 volumio kernel: vc4-drm gpu: [drm] *ERROR* flip_done timed out Feb 22 21:58:22 volumio kernel: vc4-drm gpu: [drm] *ERROR* Timed out waiting for commit Feb 22 21:58:23 volumio wpa_supplicant[3207]: RRM: Ignoring radio measurement request: Not RRM network Feb 22 21:58:27 volumio wpa_supplicant[3207]: RRM: Ignoring radio measurement request: Not RRM network Feb 22 21:58:28 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 22 21:58:28 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Feb 22 21:58:30 volumio wpa_supplicant[3207]: RRM: Ignoring radio measurement request: Not RRM network Feb 22 21:58:31 volumio sudo[8562]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/95-touch_display-plugin.conf Feb 22 21:58:31 volumio sudo[8562]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 22 21:58:31 volumio sudo[8569]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start getty@tty1.service Feb 22 21:58:31 volumio sudo[8562]: pam_unix(sudo:session): session closed for user root Feb 22 21:58:31 volumio sudo[8569]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 22 21:58:31 volumio sudo[8571]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl enable getty@tty1.service Feb 22 21:58:31 volumio volumio[1200]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/95-touch_display-plugin.conf set. Feb 22 21:58:31 volumio sudo[8571]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 22 21:58:31 volumio volumio[1200]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 22 21:58:31 volumio volumio[1200]: TypeError: Cannot read properties of undefined (reading 'split') Feb 22 21:58:31 volumio volumio[1200]: at /data/plugins/user_interface/touch_display/index.js:1298:37 Feb 22 21:58:31 volumio volumio[1200]: at ChildProcess.exithandler (node:child_process:413:7) Feb 22 21:58:31 volumio volumio[1200]: at ChildProcess.emit (node:events:514:28) Feb 22 21:58:31 volumio volumio[1200]: at maybeClose (node:internal/child_process:1105:16) Feb 22 21:58:31 volumio volumio[1200]: at ChildProcess._handle.onexit (node:internal/child_process:305:5) Feb 22 21:58:31 volumio volumio[1200]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 22 21:58:31 volumio sudo[8575]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumio-kiosk.service Feb 22 21:58:31 volumio sudo[8575]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 22 21:58:32 volumio systemd[1]: Reloading. Feb 22 21:58:32 volumio sudo[8610]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-22 21:57' Feb 22 21:58:32 volumio sudo[8610]: 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"