Feb 22 16:47:00 volumio-86 systemd[1]: setdatetime-helper.service: Deactivated successfully. Feb 22 16:47:00 volumio-86 systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Feb 22 16:47:05 volumio-86 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 479. Feb 22 16:47:05 volumio-86 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 22 16:47:05 volumio-86 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 22 16:47:05 volumio-86 upmpdcli[21649]: Could not open config: /tmp/upmpdcli.conf Feb 22 16:47:05 volumio-86 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 22 16:47:05 volumio-86 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 22 16:47:16 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioNext Feb 22 16:47:16 volumio-86 volumio[1604]: info: CoreStateMachine::next Feb 22 16:47:16 volumio-86 volumio[1604]: info: Received next Feb 22 16:47:16 volumio-86 vtcs[2464]: [close:85] Entering Feb 22 16:47:16 volumio-86 vtcs[2464]: [feedThread:276] Exiting Feb 22 16:47:16 volumio-86 vtcs[2464]: [close:100] Exiting Feb 22 16:47:16 volumio-86 volumio[1604]: info: Pushing metadata Feb 22 16:47:16 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:16 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:16 volumio-86 volumio[1604]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 16:47:16 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:16 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:16 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:16 volumio-86 volumio[1604]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 16:47:16 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:16 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:16 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:16 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:16 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:16.853+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=78489 volume=100 Feb 22 16:47:16 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:16.853+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title=Strongest Feb 22 16:47:16 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:16.856+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:16 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:16.856+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:16 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:16.856+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title=Strongest Feb 22 16:47:16 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:16.856+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title=Strongest Feb 22 16:47:16 volumio-86 vtcs[2464]: [close:85] Entering Feb 22 16:47:16 volumio-86 vtcs[2464]: [close:100] Exiting Feb 22 16:47:16 volumio-86 volumio[1604]: info: Pushing metadata Feb 22 16:47:16 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:16 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:16 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:17 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:17.001+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:17 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:17.001+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title=Strongest Feb 22 16:47:17 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:17 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:17 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:17 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:17 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:17 volumio-86 volumio[1604]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 16:47:17 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:17 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:17 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:17 volumio-86 volumio[1604]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 16:47:17 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:17 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:17.008+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:17 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:17.008+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PAUSED positionMs=0 volume=100 Feb 22 16:47:17 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:17.008+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:17 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:17.009+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title=Strongest Feb 22 16:47:17 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:17.009+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title=Strongest Feb 22 16:47:17 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:17.009+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title=Strongest Feb 22 16:47:17 volumio-86 vtcs[2464]: [close:85] Entering Feb 22 16:47:17 volumio-86 vtcs[2464]: [close:100] Exiting Feb 22 16:47:17 volumio-86 vtcs[2464]: [open:50] Opening with sample rate: 44100, type: 3 Feb 22 16:47:17 volumio-86 vtcs[2464]: [start:106] Entering Feb 22 16:47:17 volumio-86 vtcs[2464]: [start:113] Reopening PCM device... Feb 22 16:47:17 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:17 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:17 volumio-86 volumio[1604]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 16:47:17 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:17 volumio-86 vtcs[2464]: [start:115] PCM opened successfully. Feb 22 16:47:17 volumio-86 vtcs[2464]: [feedThread:223] Entering Feb 22 16:47:17 volumio-86 vtcs[2464]: [start:120] Exiting Feb 22 16:47:17 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:17.212+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:17 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:17.213+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title=Strongest Feb 22 16:47:17 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:17 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:17 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:17 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:17.220+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:17 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:17.220+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title=Strongest Feb 22 16:47:17 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:17 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:17 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:17 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:17.232+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:17 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:17.232+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title=Strongest Feb 22 16:47:17 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:17 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:17 volumio-86 volumio[1604]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 16:47:17 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:17 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:17.656+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=524 volume=100 Feb 22 16:47:17 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:17.656+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title=Strongest Feb 22 16:47:20 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioNext Feb 22 16:47:20 volumio-86 volumio[1604]: info: CoreStateMachine::next Feb 22 16:47:20 volumio-86 volumio[1604]: info: Received next Feb 22 16:47:20 volumio-86 vtcs[2464]: [close:85] Entering Feb 22 16:47:20 volumio-86 vtcs[2464]: [feedThread:276] Exiting Feb 22 16:47:20 volumio-86 vtcs[2464]: [close:100] Exiting Feb 22 16:47:20 volumio-86 volumio[1604]: info: Pushing metadata Feb 22 16:47:20 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:20 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:20 volumio-86 volumio[1604]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 16:47:20 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:20 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:20 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:20 volumio-86 volumio[1604]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 16:47:20 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:20 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:20 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:20 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:20 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:20.330+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:20 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:20.330+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=3123 volume=100 Feb 22 16:47:20 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:20.330+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title=Matters Feb 22 16:47:20 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:20.330+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:20 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:20.331+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title=Matters Feb 22 16:47:20 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:20.331+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title=Matters Feb 22 16:47:20 volumio-86 vtcs[2464]: [close:85] Entering Feb 22 16:47:20 volumio-86 vtcs[2464]: [close:100] Exiting Feb 22 16:47:20 volumio-86 volumio[1604]: info: Pushing metadata Feb 22 16:47:20 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:20 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:20 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:20 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:20.486+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:20 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:20.486+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title=Matters Feb 22 16:47:20 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:20 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:20 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:20 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:20 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:20 volumio-86 volumio[1604]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 16:47:20 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:20 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:20 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:20 volumio-86 volumio[1604]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 16:47:20 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:20 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:20 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:20 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:20 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:20.490+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:20 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:20.490+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:20 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:20.490+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title=Matters Feb 22 16:47:20 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:20.490+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title=Matters Feb 22 16:47:20 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:20.490+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PAUSED positionMs=0 volume=100 Feb 22 16:47:20 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:20.490+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title=Matters Feb 22 16:47:20 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:20.491+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:20 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:20.491+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title=Matters Feb 22 16:47:20 volumio-86 vtcs[2464]: [close:85] Entering Feb 22 16:47:20 volumio-86 vtcs[2464]: [close:100] Exiting Feb 22 16:47:20 volumio-86 vtcs[2464]: [open:50] Opening with sample rate: 48000, type: 3 Feb 22 16:47:20 volumio-86 vtcs[2464]: [start:106] Entering Feb 22 16:47:20 volumio-86 vtcs[2464]: [start:113] Reopening PCM device... Feb 22 16:47:20 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:20 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:20 volumio-86 volumio[1604]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 16:47:20 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:20 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:20.697+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:20 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:20.697+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title=Matters Feb 22 16:47:20 volumio-86 vtcs[2464]: [start:115] PCM opened successfully. Feb 22 16:47:20 volumio-86 vtcs[2464]: [start:120] Exiting Feb 22 16:47:20 volumio-86 vtcs[2464]: [feedThread:223] Entering Feb 22 16:47:20 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:20 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:20 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:20 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:20.743+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:20 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:20.744+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title=Matters Feb 22 16:47:21 volumio-86 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 480. Feb 22 16:47:21 volumio-86 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 22 16:47:21 volumio-86 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 22 16:47:21 volumio-86 upmpdcli[21698]: Could not open config: /tmp/upmpdcli.conf Feb 22 16:47:21 volumio-86 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 22 16:47:21 volumio-86 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 22 16:47:21 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:21 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:21 volumio-86 volumio[1604]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 16:47:21 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:21 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:21.137+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=500 volume=100 Feb 22 16:47:21 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:21.137+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title=Matters Feb 22 16:47:22 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioNext Feb 22 16:47:22 volumio-86 volumio[1604]: info: CoreStateMachine::next Feb 22 16:47:22 volumio-86 volumio[1604]: info: Received next Feb 22 16:47:22 volumio-86 vtcs[2464]: [close:85] Entering Feb 22 16:47:22 volumio-86 vtcs[2464]: [feedThread:276] Exiting Feb 22 16:47:22 volumio-86 vtcs[2464]: [close:100] Exiting Feb 22 16:47:22 volumio-86 volumio[1604]: info: Pushing metadata Feb 22 16:47:22 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:22 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:22 volumio-86 volumio[1604]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 16:47:22 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:22 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:22 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:22 volumio-86 volumio[1604]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 16:47:22 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:22 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:22 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:22 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:22 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:22.588+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:22 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:22.588+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:22 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:22.588+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=1575 volume=100 Feb 22 16:47:22 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:22.589+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title="A Little Something to Give" Feb 22 16:47:22 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:22.589+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title="A Little Something to Give" Feb 22 16:47:22 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:22.589+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title="A Little Something to Give" Feb 22 16:47:22 volumio-86 vtcs[2464]: [close:85] Entering Feb 22 16:47:22 volumio-86 vtcs[2464]: [close:100] Exiting Feb 22 16:47:22 volumio-86 volumio[1604]: info: Pushing metadata Feb 22 16:47:22 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:22 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:22 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:22 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:22.738+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:22 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:22.738+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title="A Little Something to Give" Feb 22 16:47:22 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:22 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:22 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:22 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:22 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:22 volumio-86 volumio[1604]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 16:47:22 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:22 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:22 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:22 volumio-86 volumio[1604]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 16:47:22 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:22 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:22 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:22 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:22 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:22.743+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:22 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:22.743+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:22 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:22.743+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title="A Little Something to Give" Feb 22 16:47:22 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:22.743+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PAUSED positionMs=0 volume=100 Feb 22 16:47:22 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:22.743+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title="A Little Something to Give" Feb 22 16:47:22 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:22.743+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title="A Little Something to Give" Feb 22 16:47:22 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:22.743+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:22 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:22.743+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title="A Little Something to Give" Feb 22 16:47:22 volumio-86 vtcs[2464]: [close:85] Entering Feb 22 16:47:22 volumio-86 vtcs[2464]: [close:100] Exiting Feb 22 16:47:22 volumio-86 vtcs[2464]: [open:50] Opening with sample rate: 44100, type: 3 Feb 22 16:47:22 volumio-86 vtcs[2464]: [start:106] Entering Feb 22 16:47:22 volumio-86 vtcs[2464]: [start:113] Reopening PCM device... Feb 22 16:47:22 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:22 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:22 volumio-86 volumio[1604]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 16:47:22 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:22 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:22.936+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:22 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:22.936+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title="A Little Something to Give" Feb 22 16:47:22 volumio-86 vtcs[2464]: [start:115] PCM opened successfully. Feb 22 16:47:22 volumio-86 vtcs[2464]: [start:120] Exiting Feb 22 16:47:22 volumio-86 vtcs[2464]: [feedThread:223] Entering Feb 22 16:47:22 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:22 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:22 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:22 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:22.971+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:22 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:22.972+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title="A Little Something to Give" Feb 22 16:47:23 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:23 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:23 volumio-86 volumio[1604]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 16:47:23 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:23 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:23.382+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=524 volume=100 Feb 22 16:47:23 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:23.382+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title="A Little Something to Give" Feb 22 16:47:25 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioNext Feb 22 16:47:25 volumio-86 volumio[1604]: info: CoreStateMachine::next Feb 22 16:47:25 volumio-86 volumio[1604]: info: Received next Feb 22 16:47:25 volumio-86 vtcs[2464]: [close:85] Entering Feb 22 16:47:25 volumio-86 vtcs[2464]: [feedThread:276] Exiting Feb 22 16:47:25 volumio-86 vtcs[2464]: [close:100] Exiting Feb 22 16:47:25 volumio-86 volumio[1604]: info: Pushing metadata Feb 22 16:47:25 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:25 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:25 volumio-86 volumio[1604]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 16:47:25 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:25 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:25 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:25 volumio-86 volumio[1604]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 16:47:25 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:25 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:25 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:25 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:25 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:25.258+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=2024 volume=100 Feb 22 16:47:25 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:25.258+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:25 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:25.258+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title=Fever Feb 22 16:47:25 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:25.258+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title=Fever Feb 22 16:47:25 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:25.258+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:25 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:25.258+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title=Fever Feb 22 16:47:25 volumio-86 vtcs[2464]: [close:85] Entering Feb 22 16:47:25 volumio-86 vtcs[2464]: [close:100] Exiting Feb 22 16:47:25 volumio-86 volumio[1604]: info: Pushing metadata Feb 22 16:47:25 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:25 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:25 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:25 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:25.407+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:25 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:25.407+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title=Fever Feb 22 16:47:25 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:25 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:25 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:25 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:25 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:25 volumio-86 volumio[1604]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 16:47:25 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:25 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:25 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:25 volumio-86 volumio[1604]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 16:47:25 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:25 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:25 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:25 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:25 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:25.411+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:25 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:25.411+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title=Fever Feb 22 16:47:25 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:25.413+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:25 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:25.413+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title=Fever Feb 22 16:47:25 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:25.413+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PAUSED positionMs=0 volume=100 Feb 22 16:47:25 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:25.413+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title=Fever Feb 22 16:47:25 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:25.413+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:25 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:25.413+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title=Fever Feb 22 16:47:25 volumio-86 vtcs[2464]: [close:85] Entering Feb 22 16:47:25 volumio-86 vtcs[2464]: [close:100] Exiting Feb 22 16:47:25 volumio-86 vtcs[2464]: [open:50] Opening with sample rate: 44100, type: 3 Feb 22 16:47:25 volumio-86 vtcs[2464]: [start:106] Entering Feb 22 16:47:25 volumio-86 vtcs[2464]: [start:113] Reopening PCM device... Feb 22 16:47:25 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:25 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:25 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:25 volumio-86 vtcs[2464]: [start:115] PCM opened successfully. Feb 22 16:47:25 volumio-86 vtcs[2464]: [start:120] Exiting Feb 22 16:47:25 volumio-86 vtcs[2464]: [feedThread:223] Entering Feb 22 16:47:25 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:25.656+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:25 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:25.656+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title=Fever Feb 22 16:47:25 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:25 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:25 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:25 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:25.680+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:25 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:25.680+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title=Fever Feb 22 16:47:26 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:26 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:26 volumio-86 volumio[1604]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 16:47:26 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:26 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:26.102+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=524 volume=100 Feb 22 16:47:26 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:26.103+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title=Fever Feb 22 16:47:27 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioNext Feb 22 16:47:27 volumio-86 volumio[1604]: info: CoreStateMachine::next Feb 22 16:47:27 volumio-86 volumio[1604]: info: Received next Feb 22 16:47:27 volumio-86 vtcs[2464]: [close:85] Entering Feb 22 16:47:27 volumio-86 vtcs[2464]: [feedThread:276] Exiting Feb 22 16:47:27 volumio-86 vtcs[2464]: [close:100] Exiting Feb 22 16:47:27 volumio-86 volumio[1604]: info: Pushing metadata Feb 22 16:47:27 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:27 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:27 volumio-86 volumio[1604]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 16:47:27 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:27 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:27 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:27 volumio-86 volumio[1604]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 16:47:27 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:27 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:27 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:27 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:27 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:27.704+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=2049 volume=100 Feb 22 16:47:27 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:27.704+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:27 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:27.705+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title="From Grace" Feb 22 16:47:27 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:27.705+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:27 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:27.705+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title="From Grace" Feb 22 16:47:27 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:27.705+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title="From Grace" Feb 22 16:47:27 volumio-86 volumio[1604]: info: Pushing metadata Feb 22 16:47:27 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:27 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:27 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:27 volumio-86 vtcs[2464]: [close:85] Entering Feb 22 16:47:27 volumio-86 vtcs[2464]: [close:100] Exiting Feb 22 16:47:27 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:27.989+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:27 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:27 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:27 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:27.989+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title="From Grace" Feb 22 16:47:27 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:27 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:27 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:27 volumio-86 volumio[1604]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 16:47:27 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:27 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:27 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:27 volumio-86 volumio[1604]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 16:47:27 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:27 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:27 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:27 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:27 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:27.997+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:27 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:27.997+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title="From Grace" Feb 22 16:47:27 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:27.997+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:27 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:27.998+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title="From Grace" Feb 22 16:47:27 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:27.998+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PAUSED positionMs=0 volume=100 Feb 22 16:47:27 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:27.998+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title="From Grace" Feb 22 16:47:28 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:27.999+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:28 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:28.000+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title="From Grace" Feb 22 16:47:28 volumio-86 vtcs[2464]: [close:85] Entering Feb 22 16:47:28 volumio-86 vtcs[2464]: [close:100] Exiting Feb 22 16:47:28 volumio-86 vtcs[2464]: [open:50] Opening with sample rate: 44100, type: 0 Feb 22 16:47:28 volumio-86 vtcs[2464]: [start:106] Entering Feb 22 16:47:28 volumio-86 vtcs[2464]: [start:113] Reopening PCM device... Feb 22 16:47:28 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:28 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:28 volumio-86 volumio[1604]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 16:47:28 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:28 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:28.275+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:28 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:28.275+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title="From Grace" Feb 22 16:47:28 volumio-86 vtcs[2464]: [start:115] PCM opened successfully. Feb 22 16:47:28 volumio-86 vtcs[2464]: [start:120] Exiting Feb 22 16:47:28 volumio-86 vtcs[2464]: [feedThread:223] Entering Feb 22 16:47:28 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:28 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:28 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:28 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:28.288+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=0 volume=100 Feb 22 16:47:28 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:28.288+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title="From Grace" Feb 22 16:47:28 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:47:28 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:47:28 volumio-86 volumio[1604]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 16:47:28 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:47:28 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:28.719+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PLAYING positionMs=524 volume=100 Feb 22 16:47:28 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:47:28.719+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title="From Grace" Feb 22 16:47:36 volumio-86 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 481. Feb 22 16:47:36 volumio-86 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 22 16:47:36 volumio-86 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 22 16:47:36 volumio-86 upmpdcli[21737]: Could not open config: /tmp/upmpdcli.conf Feb 22 16:47:36 volumio-86 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 22 16:47:36 volumio-86 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 22 16:47:51 volumio-86 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 482. Feb 22 16:47:51 volumio-86 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 22 16:47:51 volumio-86 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 22 16:47:51 volumio-86 upmpdcli[21782]: Could not open config: /tmp/upmpdcli.conf Feb 22 16:47:51 volumio-86 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 22 16:47:51 volumio-86 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 22 16:48:00 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioToggle Feb 22 16:48:00 volumio-86 volumio[1604]: info: CoreStateMachine::pause Feb 22 16:48:00 volumio-86 volumio[1604]: info: CoreStateMachine::stPlaybackTimer Feb 22 16:48:00 volumio-86 volumio[1604]: info: CoreStateMachine::servicePause Feb 22 16:48:00 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePause Feb 22 16:48:00 volumio-86 volumio[1604]: info: Received pause Feb 22 16:48:00 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:48:00 volumio-86 vtcs[2464]: [pause:147] Entering Feb 22 16:48:00 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:48:00 volumio-86 volumio[1604]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 16:48:00 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:48:00 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:48:00.028+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_PAUSED positionMs=31535 volume=100 Feb 22 16:48:00 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:48:00.028+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id= title="From Grace" Feb 22 16:48:00 volumio-86 vtcs[2464]: [feedThread:276] Exiting Feb 22 16:48:00 volumio-86 vtcs[2464]: [pause:161] Exiting Feb 22 16:48:04 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioToggle Feb 22 16:48:04 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioVolatilePlay Feb 22 16:48:04 volumio-86 volumio[1604]: ------------------------------------ BT MESSAGE: [FUNC] play Feb 22 16:48:04 volumio-86 volumio[1604]: ------------------------------------ BT MESSAGE: sendPlay skipped: activePlayer not bound or invalid Feb 22 16:48:05 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioToggle Feb 22 16:48:05 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioVolatilePlay Feb 22 16:48:05 volumio-86 volumio[1604]: ------------------------------------ BT MESSAGE: [FUNC] play Feb 22 16:48:05 volumio-86 volumio[1604]: ------------------------------------ BT MESSAGE: sendPlay skipped: activePlayer not bound or invalid Feb 22 16:48:06 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioToggle Feb 22 16:48:06 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioVolatilePlay Feb 22 16:48:06 volumio-86 volumio[1604]: ------------------------------------ BT MESSAGE: [FUNC] play Feb 22 16:48:06 volumio-86 volumio[1604]: ------------------------------------ BT MESSAGE: sendPlay skipped: activePlayer not bound or invalid Feb 22 16:48:06 volumio-86 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 483. Feb 22 16:48:06 volumio-86 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 22 16:48:06 volumio-86 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 22 16:48:06 volumio-86 upmpdcli[21814]: Could not open config: /tmp/upmpdcli.conf Feb 22 16:48:06 volumio-86 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 22 16:48:06 volumio-86 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 22 16:48:07 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioToggle Feb 22 16:48:07 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioVolatilePlay Feb 22 16:48:07 volumio-86 volumio[1604]: ------------------------------------ BT MESSAGE: [FUNC] play Feb 22 16:48:07 volumio-86 volumio[1604]: ------------------------------------ BT MESSAGE: sendPlay skipped: activePlayer not bound or invalid Feb 22 16:48:08 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioToggle Feb 22 16:48:08 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioVolatilePlay Feb 22 16:48:08 volumio-86 volumio[1604]: ------------------------------------ BT MESSAGE: [FUNC] play Feb 22 16:48:08 volumio-86 volumio[1604]: ------------------------------------ BT MESSAGE: sendPlay skipped: activePlayer not bound or invalid Feb 22 16:48:09 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioToggle Feb 22 16:48:09 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioVolatilePlay Feb 22 16:48:09 volumio-86 volumio[1604]: ------------------------------------ BT MESSAGE: [FUNC] play Feb 22 16:48:09 volumio-86 volumio[1604]: ------------------------------------ BT MESSAGE: sendPlay skipped: activePlayer not bound or invalid Feb 22 16:48:11 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioToggle Feb 22 16:48:11 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioVolatilePlay Feb 22 16:48:11 volumio-86 volumio[1604]: ------------------------------------ BT MESSAGE: [FUNC] play Feb 22 16:48:11 volumio-86 volumio[1604]: ------------------------------------ BT MESSAGE: sendPlay skipped: activePlayer not bound or invalid Feb 22 16:48:12 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioToggle Feb 22 16:48:12 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioVolatilePlay Feb 22 16:48:12 volumio-86 volumio[1604]: ------------------------------------ BT MESSAGE: [FUNC] play Feb 22 16:48:12 volumio-86 volumio[1604]: ------------------------------------ BT MESSAGE: sendPlay skipped: activePlayer not bound or invalid Feb 22 16:48:12 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioToggle Feb 22 16:48:12 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioVolatilePlay Feb 22 16:48:12 volumio-86 volumio[1604]: ------------------------------------ BT MESSAGE: [FUNC] play Feb 22 16:48:12 volumio-86 volumio[1604]: ------------------------------------ BT MESSAGE: sendPlay skipped: activePlayer not bound or invalid Feb 22 16:48:14 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioToggle Feb 22 16:48:14 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioVolatilePlay Feb 22 16:48:14 volumio-86 volumio[1604]: ------------------------------------ BT MESSAGE: [FUNC] play Feb 22 16:48:14 volumio-86 volumio[1604]: ------------------------------------ BT MESSAGE: sendPlay skipped: activePlayer not bound or invalid Feb 22 16:48:15 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioToggle Feb 22 16:48:15 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioVolatilePlay Feb 22 16:48:15 volumio-86 volumio[1604]: ------------------------------------ BT MESSAGE: [FUNC] play Feb 22 16:48:15 volumio-86 volumio[1604]: ------------------------------------ BT MESSAGE: sendPlay skipped: activePlayer not bound or invalid Feb 22 16:48:20 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioToggle Feb 22 16:48:20 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioVolatilePlay Feb 22 16:48:20 volumio-86 volumio[1604]: ------------------------------------ BT MESSAGE: [FUNC] play Feb 22 16:48:20 volumio-86 volumio[1604]: ------------------------------------ BT MESSAGE: sendPlay skipped: activePlayer not bound or invalid Feb 22 16:48:21 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioToggle Feb 22 16:48:21 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioVolatilePlay Feb 22 16:48:21 volumio-86 volumio[1604]: ------------------------------------ BT MESSAGE: [FUNC] play Feb 22 16:48:21 volumio-86 volumio[1604]: ------------------------------------ BT MESSAGE: sendPlay skipped: activePlayer not bound or invalid Feb 22 16:48:21 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioToggle Feb 22 16:48:21 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioVolatilePlay Feb 22 16:48:21 volumio-86 volumio[1604]: ------------------------------------ BT MESSAGE: [FUNC] play Feb 22 16:48:21 volumio-86 volumio[1604]: ------------------------------------ BT MESSAGE: sendPlay skipped: activePlayer not bound or invalid Feb 22 16:48:22 volumio-86 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 484. Feb 22 16:48:22 volumio-86 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 22 16:48:22 volumio-86 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 22 16:48:22 volumio-86 upmpdcli[21858]: Could not open config: /tmp/upmpdcli.conf Feb 22 16:48:22 volumio-86 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 22 16:48:22 volumio-86 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 22 16:48:33 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:48:33.130+01:00 level=INFO msg="player play request" component=server type=REQUEST_TYPE_PLAYER_PLAY peer="192.168.0.66:60310 @ 0xc0003b7b60" latency=-135.801888ms timeout=10s Feb 22 16:48:33 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPlay Feb 22 16:48:33 volumio-86 volumio[1604]: verbose: UNSET VOLATILE: Service: tidalconnect Feb 22 16:48:33 volumio-86 volumio[1604]: ------------------------------------ BT MESSAGE: [FUNC] detachBluetooth Feb 22 16:48:33 volumio-86 volumio[1604]: ------------------------------------ BT MESSAGE: [FUNC] btAudioOutput Feb 22 16:48:33 volumio-86 volumio[1604]: ------------------------------------ BT MESSAGE: [dbus-next] Disabling Bluetooth Audio Output Feb 22 16:48:33 volumio-86 volumio[1604]: info: CoreStateMachine::play index undefined Feb 22 16:48:33 volumio-86 volumio[1604]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 22 16:48:33 volumio-86 volumio[1604]: ------------------------------------ BT MESSAGE: Bluetooth audio output disabled. Feb 22 16:48:33 volumio-86 volumio[1604]: info: CorePlayQueue::getTrack 0 Feb 22 16:48:33 volumio-86 volumio[1604]: info: CoreStateMachine::startPlaybackTimer Feb 22 16:48:33 volumio-86 volumio[1604]: info: CorePlayQueue::getTrack 0 Feb 22 16:48:33 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioGetVisibleSources Feb 22 16:48:33 volumio-86 volumio[1604]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 22 16:48:33 volumio-86 volumio[1604]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Feb 22 16:48:33 volumio-86 volumio[1604]: verbose: ControllerMpd::sendMpdCommand play Feb 22 16:48:33 volumio-86 volumio[1604]: info: CoreStateMachine::resetVolumioState Feb 22 16:48:33 volumio-86 volumio[1604]: info: CoreStateMachine::getcurrentVolume Feb 22 16:48:33 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioRetrievevolume Feb 22 16:48:33 volumio-86 volumio[1604]: info: CoreStateMachine::pushState Feb 22 16:48:33 volumio-86 volumio[1604]: info: CorePlayQueue::getTrack 0 Feb 22 16:48:33 volumio-86 volumio[1604]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 16:48:33 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioPushState Feb 22 16:48:33 volumio-86 volumio[1604]: info: CoreCommandRouter::volumioStop Feb 22 16:48:33 volumio-86 volumio[1604]: info: CoreStateMachine::stop Feb 22 16:48:33 volumio-86 volumio[1604]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 22 16:48:33 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:48:33.137+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 16:48:33 volumio-86 volumio5-onboarding[2554]: time=2026-02-22T16:48:33.137+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:60310 @ 0xc0003b7b60" id=https://motherearth.streamserver24.com/listen/motherearth/motherearth title="Mother Earth Radio (flac)" Feb 22 16:48:33 volumio-86 volumio[1604]: info: sendMpdCommand play took 5 milliseconds Feb 22 16:48:33 volumio-86 volumio[1604]: info: CoreCommandRouter::servicePushState Feb 22 16:48:33 volumio-86 volumio[1604]: info: CorePlayQueue::getTrack 0 Feb 22 16:48:33 volumio-86 volumio[1604]: verbose: STATE SERVICE {"status":"play"} Feb 22 16:48:33 volumio-86 volumio[1604]: verbose: CURRENT POSITION 0 Feb 22 16:48:33 volumio-86 volumio[1604]: info: CoreStateMachine::syncState stateService play Feb 22 16:48:33 volumio-86 volumio[1604]: info: CoreStateMachine::syncState currentStatus stop Feb 22 16:48:33 volumio-86 volumio[1604]: info: [1771775313144] [MotherEarth] Error: connect ECONNREFUSED 127.0.0.1:443 Feb 22 16:48:33 volumio-86 volumio[1604]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 22 16:48:33 volumio-86 volumio[1604]: TypeError: Cannot read properties of undefined (reading 'toUpperCase') Feb 22 16:48:33 volumio-86 volumio[1604]: at motherearthradio.errorToast (/data/plugins/music_service/motherearthradio/index.js:423:41) Feb 22 16:48:33 volumio-86 volumio[1604]: at ClientRequest. (/data/plugins/music_service/motherearthradio/index.js:395:14) Feb 22 16:48:33 volumio-86 volumio[1604]: at ClientRequest.emit (node:events:514:28) Feb 22 16:48:33 volumio-86 volumio[1604]: at TLSSocket.socketErrorListener (node:_http_client:495:9) Feb 22 16:48:33 volumio-86 volumio[1604]: at TLSSocket.emit (node:events:514:28) Feb 22 16:48:33 volumio-86 volumio[1604]: at emitErrorNT (node:internal/streams/destroy:151:8) Feb 22 16:48:33 volumio-86 volumio[1604]: at emitErrorCloseNT (node:internal/streams/destroy:116:3) Feb 22 16:48:33 volumio-86 volumio[1604]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) Feb 22 16:48:33 volumio-86 volumio[1604]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 22 16:48:33 volumio-86 sudo[21899]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-22 16:47' Feb 22 16:48:33 volumio-86 sudo[21899]: 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="a78d359cf1dc63ac74e9d151015afd30d31a709a" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Feb 5 14:31:57 UTC 2026" VOLUMIO_VERSION="4.096" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="6759e875c98b942866984e844891d6c1"