Mar 24 03:44:10 rpi4 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 213. Mar 24 03:44:10 rpi4 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Mar 24 03:44:10 rpi4 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Mar 24 03:44:10 rpi4 upmpdcli[6969]: Could not open config: /tmp/upmpdcli.conf Mar 24 03:44:10 rpi4 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Mar 24 03:44:10 rpi4 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Mar 24 03:44:16 rpi4 volumio[1248]: info: CoreCommandRouter::executeOnPlugin: volusonic , handleBrowseUri Mar 24 03:44:16 rpi4 volumio[1248]: info: Preload queue cleared Mar 24 03:44:16 rpi4 volumio[1248]: info: Preloading song: volusonic/track/8isXfsETUxYo7HBBCgMvAM Mar 24 03:44:16 rpi4 volumio[1248]: info: Preloading song: volusonic/track/v5BsW0ZTbiXN3LoCwOiLWV Mar 24 03:44:16 rpi4 volumio[1248]: info: Preloading song: volusonic/track/y8D0ul4oJGYTPaZ2AWzCNj Mar 24 03:44:16 rpi4 volumio[1248]: info: Preloading song: volusonic/track/CFXtIwcgzOlDVYbhC3XpCr Mar 24 03:44:16 rpi4 volumio[1248]: info: Preloading song: volusonic/track/6EYjYT9uREVkJ43HkRRFVs Mar 24 03:44:16 rpi4 volumio[1248]: info: Preloading song: volusonic/track/YGAtiE5rUKqBJU0JmJnhuR Mar 24 03:44:16 rpi4 volumio[1248]: info: Preloading song: volusonic/track/bSrIss4rHOqQLC7d8yA4mJ Mar 24 03:44:16 rpi4 volumio[1248]: info: Preloading song: volusonic/track/GvruqnR0ZO0wpfZ4H0P6xn Mar 24 03:44:16 rpi4 volumio[1248]: info: Preloading song: volusonic/track/ZNU7fAwGJ7AfX3dfvepJW5 Mar 24 03:44:16 rpi4 volumio[1248]: info: Preloading song: volusonic/track/hizfa1fyPytXay3HMoUpnC Mar 24 03:44:16 rpi4 volumio[1248]: info: Preloading song: volusonic/track/hyh3aa4LSH61Wa6SB9dB6G Mar 24 03:44:16 rpi4 volumio[1248]: info: Preloading song: volusonic/track/sXId7Cm4xxcp8WNEaT8vY2 Mar 24 03:44:16 rpi4 volumio[1248]: info: Preloading song: volusonic/track/OyUC65qMJZdYxasPHRTiBV Mar 24 03:44:16 rpi4 volumio[1248]: info: Preloading song: volusonic/track/QhhAiF6jNYQyXV2NaXG6ya Mar 24 03:44:16 rpi4 volumio[1248]: info: Preloading song: volusonic/track/sIJ9SqpFVTUDeiPwnRo0RU Mar 24 03:44:16 rpi4 volumio[1248]: info: Preloading song: volusonic/track/Jli6v4QXbf00ySSMA92Dil Mar 24 03:44:16 rpi4 volumio[1248]: info: Exploding uri volusonic/track/8isXfsETUxYo7HBBCgMvAM in service volusonic Mar 24 03:44:16 rpi4 volumio[1248]: error: Commandrouter: Cannot explode uri volusonic/track/8isXfsETUxYo7HBBCgMvAM from service volusonic: Error: explodeUri volusonic/track Mar 24 03:44:16 rpi4 volumio[1248]: info: Exploding uri volusonic/track/v5BsW0ZTbiXN3LoCwOiLWV in service volusonic Mar 24 03:44:16 rpi4 volumio[1248]: error: Commandrouter: Cannot explode uri volusonic/track/v5BsW0ZTbiXN3LoCwOiLWV from service volusonic: Error: explodeUri volusonic/track Mar 24 03:44:16 rpi4 volumio[1248]: info: No valid Plugin REST Endpoint Mar 24 03:44:16 rpi4 volumio[1248]: info: No valid Plugin REST Endpoint Mar 24 03:44:16 rpi4 volumio[1248]: info: Exploding uri volusonic/track/y8D0ul4oJGYTPaZ2AWzCNj in service volusonic Mar 24 03:44:16 rpi4 volumio[1248]: error: Commandrouter: Cannot explode uri volusonic/track/y8D0ul4oJGYTPaZ2AWzCNj from service volusonic: Error: explodeUri volusonic/track Mar 24 03:44:16 rpi4 volumio[1248]: info: Exploding uri volusonic/track/CFXtIwcgzOlDVYbhC3XpCr in service volusonic Mar 24 03:44:16 rpi4 volumio[1248]: error: Commandrouter: Cannot explode uri volusonic/track/CFXtIwcgzOlDVYbhC3XpCr from service volusonic: Error: explodeUri volusonic/track Mar 24 03:44:16 rpi4 volumio[1248]: info: Exploding uri volusonic/track/6EYjYT9uREVkJ43HkRRFVs in service volusonic Mar 24 03:44:16 rpi4 volumio[1248]: info: Exploding uri volusonic/track/YGAtiE5rUKqBJU0JmJnhuR in service volusonic Mar 24 03:44:17 rpi4 volumio[1248]: info: Exploding uri volusonic/track/bSrIss4rHOqQLC7d8yA4mJ in service volusonic Mar 24 03:44:17 rpi4 volumio[1248]: error: Commandrouter: Cannot explode uri volusonic/track/bSrIss4rHOqQLC7d8yA4mJ from service volusonic: Error: explodeUri volusonic/track Mar 24 03:44:17 rpi4 volumio[1248]: info: Exploding uri volusonic/track/GvruqnR0ZO0wpfZ4H0P6xn in service volusonic Mar 24 03:44:17 rpi4 volumio[1248]: info: Exploding uri volusonic/track/ZNU7fAwGJ7AfX3dfvepJW5 in service volusonic Mar 24 03:44:17 rpi4 volumio[1248]: info: Exploding uri volusonic/track/hizfa1fyPytXay3HMoUpnC in service volusonic Mar 24 03:44:17 rpi4 volumio[1248]: error: Commandrouter: Cannot explode uri volusonic/track/hizfa1fyPytXay3HMoUpnC from service volusonic: Error: explodeUri volusonic/track Mar 24 03:44:17 rpi4 volumio[1248]: info: Exploding uri volusonic/track/hyh3aa4LSH61Wa6SB9dB6G in service volusonic Mar 24 03:44:17 rpi4 volumio[1248]: info: Exploding uri volusonic/track/sXId7Cm4xxcp8WNEaT8vY2 in service volusonic Mar 24 03:44:17 rpi4 volumio[1248]: error: Commandrouter: Cannot explode uri volusonic/track/sXId7Cm4xxcp8WNEaT8vY2 from service volusonic: Error: explodeUri volusonic/track Mar 24 03:44:17 rpi4 volumio[1248]: info: Exploding uri volusonic/track/OyUC65qMJZdYxasPHRTiBV in service volusonic Mar 24 03:44:17 rpi4 volumio[1248]: error: Commandrouter: Cannot explode uri volusonic/track/OyUC65qMJZdYxasPHRTiBV from service volusonic: Error: explodeUri volusonic/track Mar 24 03:44:17 rpi4 volumio[1248]: info: Exploding uri volusonic/track/QhhAiF6jNYQyXV2NaXG6ya in service volusonic Mar 24 03:44:17 rpi4 volumio[1248]: info: Exploding uri volusonic/track/sIJ9SqpFVTUDeiPwnRo0RU in service volusonic Mar 24 03:44:17 rpi4 volumio[1248]: info: Exploding uri volusonic/track/Jli6v4QXbf00ySSMA92Dil in service volusonic Mar 24 03:44:17 rpi4 go-librespot[1674]: time="2026-03-24T03:44:17-04:00" level=trace msg="sent dealer ping" Mar 24 03:44:17 rpi4 go-librespot[1674]: time="2026-03-24T03:44:17-04:00" level=trace msg="received dealer pong" Mar 24 03:44:18 rpi4 volumio[1248]: info: Preload queue cleared Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreStateMachine::ClearQueue Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreStateMachine::stop Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreStateMachine::stPlaybackTimer Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreStateMachine::updateTrackBlock Mar 24 03:44:18 rpi4 volumio[1248]: info: CorePlayQueue::getTrackBlock Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreStateMachine::pushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreCommandRouter::volumioPushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreStateMachine::serviceStop Mar 24 03:44:18 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreCommandRouter::serviceStop Mar 24 03:44:18 rpi4 volumio[1248]: info: [1774338258021] ControllerVolusonic::stop Mar 24 03:44:18 rpi4 volumio[1248]: info: ControllerMpd::stop Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand stop Mar 24 03:44:18 rpi4 volumio[1248]: info: CorePlayQueue::clearPlayQueue Mar 24 03:44:18 rpi4 volumio[1248]: info: CorePlayQueue::saveQueue Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreCommandRouter::volumioPushQueue Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreStateMachine::addQueueItems Mar 24 03:44:18 rpi4 volumio[1248]: info: CorePlayQueue::addQueueItems Mar 24 03:44:18 rpi4 volumio[1248]: info: Preload queue cleared Mar 24 03:44:18 rpi4 volumio[1248]: info: Adding Item to queue: volusonic/random/6Cb21Ub67nlOOUuF5ul6cq Mar 24 03:44:18 rpi4 volumio[1248]: info: Exploding uri volusonic/random/6Cb21Ub67nlOOUuF5ul6cq in service volusonic Mar 24 03:44:18 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:44:18.024-04:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.8.211:36432 @ 0x28be570" state=STATUS_STOPPED positionMs=0 volume=100 Mar 24 03:44:18 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:44:18.024-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.211:36432 @ 0x28be030" state=STATUS_STOPPED positionMs=0 volume=100 Mar 24 03:44:18 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:44:18.025-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.8.211:36432 @ 0x28be570" id="https://navidrome.dubyte.com/rest/stream.view?id=9ee6657a66b0c64d8dd5394cff0653a4&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic" title="Five Years" Mar 24 03:44:18 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:44:18.025-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.211:36432 @ 0x28be030" id="https://navidrome.dubyte.com/rest/stream.view?id=9ee6657a66b0c64d8dd5394cff0653a4&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic" title="Five Years" Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreCommandRouter::volumioPushQueue Mar 24 03:44:18 rpi4 volumio[1248]: info: CorePlayQueue::saveQueue Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreStateMachine::updateTrackBlock Mar 24 03:44:18 rpi4 volumio[1248]: info: CorePlayQueue::getTrackBlock Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreCommandRouter::volumioPlay Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreStateMachine::play index 0 Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreStateMachine::stop Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreStateMachine::play index undefined Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 24 03:44:18 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreStateMachine::startPlaybackTimer Mar 24 03:44:18 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:44:18 rpi4 volumio[1248]: info: [1774338258041] ControllerVolusonic::clearAddPlayTrack Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand stop Mar 24 03:44:18 rpi4 volumio[1248]: info: [1774338258057] ControllerVolusonic: MPD player state update Mar 24 03:44:18 rpi4 volumio[1248]: info: ControllerMpd::getState Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand status Mar 24 03:44:18 rpi4 volumio[1248]: info: Mar 24 03:44:18 rpi4 volumio[1248]: ---------------------------- MPD announces state update: player Mar 24 03:44:18 rpi4 volumio[1248]: info: sendMpdCommand stop took 36 milliseconds Mar 24 03:44:18 rpi4 volumio[1248]: info: ControllerMpd::getState Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand status Mar 24 03:44:18 rpi4 volumio[1248]: info: sendMpdCommand stop took 16 milliseconds Mar 24 03:44:18 rpi4 volumio[1248]: info: ControllerMpd::getState Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand status Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand clear Mar 24 03:44:18 rpi4 volumio[1248]: info: Mar 24 03:44:18 rpi4 volumio[1248]: ---------------------------- MPD announces state update: player Mar 24 03:44:18 rpi4 volumio[1248]: info: ControllerMpd::getState Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand status Mar 24 03:44:18 rpi4 volumio[1248]: info: Mar 24 03:44:18 rpi4 volumio[1248]: ---------------------------- MPD announces system playlist update Mar 24 03:44:18 rpi4 volumio[1248]: info: Ignoring MPD Status Update Mar 24 03:44:18 rpi4 volumio[1248]: info: sendMpdCommand status took 2 milliseconds Mar 24 03:44:18 rpi4 volumio[1248]: info: sendMpdCommand status took 3 milliseconds Mar 24 03:44:18 rpi4 volumio[1248]: info: sendMpdCommand status took 2 milliseconds Mar 24 03:44:18 rpi4 volumio[1248]: info: sendMpdCommand clear took 2 milliseconds Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::parseState Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::parseState Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::parseState Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand load "https://navidrome.dubyte.com/rest/stream.view?id=8isXfsETUxYo7HBBCgMvAM&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic" Mar 24 03:44:18 rpi4 volumio[1248]: info: Mar 24 03:44:18 rpi4 volumio[1248]: ---------------------------- MPD announces state update: player Mar 24 03:44:18 rpi4 volumio[1248]: info: ControllerMpd::getState Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand status Mar 24 03:44:18 rpi4 volumio[1248]: info: Mar 24 03:44:18 rpi4 volumio[1248]: ---------------------------- MPD announces system playlist update Mar 24 03:44:18 rpi4 volumio[1248]: info: Ignoring MPD Status Update Mar 24 03:44:18 rpi4 volumio[1248]: error: updateQueue error: null Mar 24 03:44:18 rpi4 volumio[1248]: info: sendMpdCommand status took 5 milliseconds Mar 24 03:44:18 rpi4 volumio[1248]: info: ------------------------------ 5ms Mar 24 03:44:18 rpi4 volumio[1248]: info: sendMpdCommand playlistinfo took 4 milliseconds Mar 24 03:44:18 rpi4 volumio[1248]: info: sendMpdCommand playlistinfo took 4 milliseconds Mar 24 03:44:18 rpi4 volumio[1248]: info: sendMpdCommand playlistinfo took 4 milliseconds Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::parseState Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::parseTrackInfo Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::parseTrackInfo Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::parseTrackInfo Mar 24 03:44:18 rpi4 volumio[1248]: info: ControllerMpd::pushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreCommandRouter::servicePushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreStateMachine::pushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreCommandRouter::volumioPushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:44:18 rpi4 volumio[1248]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Mar 24 03:44:18 rpi4 volumio[1248]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Mar 24 03:44:18 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:44:18.073-04:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.8.211:36432 @ 0x28be570" state=STATUS_STOPPED positionMs=0 volume=100 Mar 24 03:44:18 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:44:18.073-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.211:36432 @ 0x28be030" state=STATUS_STOPPED positionMs=0 volume=100 Mar 24 03:44:18 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:44:18.074-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.8.211:36432 @ 0x28be570" id="https://navidrome.dubyte.com/rest/stream.view?id=8isXfsETUxYo7HBBCgMvAM&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic" title="Dramas y comedias" Mar 24 03:44:18 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:44:18.074-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.211:36432 @ 0x28be030" id="https://navidrome.dubyte.com/rest/stream.view?id=8isXfsETUxYo7HBBCgMvAM&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic" title="Dramas y comedias" Mar 24 03:44:18 rpi4 volumio[1248]: info: ------------------------------ 19ms Mar 24 03:44:18 rpi4 volumio[1248]: info: ------------------------------ 20ms Mar 24 03:44:18 rpi4 volumio[1248]: error: updateQueue error: null Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand add "https://navidrome.dubyte.com/rest/stream.view?id=8isXfsETUxYo7HBBCgMvAM&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic" Mar 24 03:44:18 rpi4 volumio[1248]: info: sendMpdCommand status took 18 milliseconds Mar 24 03:44:18 rpi4 volumio[1248]: info: ------------------------------ 18ms Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::parseState Mar 24 03:44:18 rpi4 volumio[1248]: info: ControllerMpd::pushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreCommandRouter::servicePushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreStateMachine::pushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreCommandRouter::volumioPushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:44:18 rpi4 volumio[1248]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Mar 24 03:44:18 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:44:18.087-04:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.8.211:36432 @ 0x28be570" state=STATUS_STOPPED positionMs=0 volume=100 Mar 24 03:44:18 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:44:18.087-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.211:36432 @ 0x28be030" state=STATUS_STOPPED positionMs=0 volume=100 Mar 24 03:44:18 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:44:18.088-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.8.211:36432 @ 0x28be570" id="https://navidrome.dubyte.com/rest/stream.view?id=8isXfsETUxYo7HBBCgMvAM&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic" title="Dramas y comedias" Mar 24 03:44:18 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:44:18.088-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.211:36432 @ 0x28be030" id="https://navidrome.dubyte.com/rest/stream.view?id=8isXfsETUxYo7HBBCgMvAM&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic" title="Dramas y comedias" Mar 24 03:44:18 rpi4 volumio[1248]: info: ------------------------------ 29ms Mar 24 03:44:18 rpi4 volumio[1248]: info: Mar 24 03:44:18 rpi4 volumio[1248]: ---------------------------- MPD announces system playlist update Mar 24 03:44:18 rpi4 volumio[1248]: info: Ignoring MPD Status Update Mar 24 03:44:18 rpi4 volumio[1248]: info: Mar 24 03:44:18 rpi4 volumio[1248]: ---------------------------- MPD announces system playlist update Mar 24 03:44:18 rpi4 volumio[1248]: info: Ignoring MPD Status Update Mar 24 03:44:18 rpi4 volumio[1248]: info: sendMpdCommand add "https://navidrome.dubyte.com/rest/stream.view?id=8isXfsETUxYo7HBBCgMvAM&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic" took 19 milliseconds Mar 24 03:44:18 rpi4 volumio[1248]: info: ------------------------------ 4ms Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand play Mar 24 03:44:18 rpi4 volumio[1248]: info: Mar 24 03:44:18 rpi4 volumio[1248]: ---------------------------- MPD announces system playlist update Mar 24 03:44:18 rpi4 volumio[1248]: info: Ignoring MPD Status Update Mar 24 03:44:18 rpi4 volumio[1248]: info: Mar 24 03:44:18 rpi4 volumio[1248]: ---------------------------- MPD announces system playlist update Mar 24 03:44:18 rpi4 volumio[1248]: info: Ignoring MPD Status Update Mar 24 03:44:18 rpi4 volumio[1248]: info: ------------------------------ 3ms Mar 24 03:44:18 rpi4 volumio[1248]: info: sendMpdCommand play took 3 milliseconds Mar 24 03:44:18 rpi4 volumio[1248]: info: ------------------------------ 3ms Mar 24 03:44:18 rpi4 volumio[1248]: info: ------------------------------ 2ms Mar 24 03:44:18 rpi4 volumio[1248]: info: ControllerMpd::getState Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand status Mar 24 03:44:18 rpi4 volumio[1248]: info: sendMpdCommand status took 1 milliseconds Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::parseState Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 03:44:18 rpi4 volumio[1248]: info: sendMpdCommand playlistinfo took 0 milliseconds Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::parseTrackInfo Mar 24 03:44:18 rpi4 volumio[1248]: info: [1774338258104] ControllerVolusonic::pushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreCommandRouter::servicePushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:44:18 rpi4 volumio[1248]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"stream.view?id=8isXfsETUxYo7HBBCgMvAM&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic","artist":null,"album":null,"uri":"https://navidrome.dubyte.com/rest/stream.view?id=8isXfsETUxYo7HBBCgMvAM&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic","trackType":""} Mar 24 03:44:18 rpi4 volumio[1248]: verbose: CURRENT POSITION 0 Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreStateMachine::syncState stateService play Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreStateMachine::syncState currentStatus stop Mar 24 03:44:18 rpi4 volumio[1248]: info: Mar 24 03:44:18 rpi4 volumio[1248]: ---------------------------- MPD announces state update: player Mar 24 03:44:18 rpi4 volumio[1248]: info: ControllerMpd::getState Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand status Mar 24 03:44:18 rpi4 volumio[1248]: info: Mar 24 03:44:18 rpi4 volumio[1248]: ---------------------------- MPD announces state update: player Mar 24 03:44:18 rpi4 volumio[1248]: info: ControllerMpd::getState Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand status Mar 24 03:44:18 rpi4 volumio[1248]: info: [1774338258236] ControllerVolusonic: MPD player state update Mar 24 03:44:18 rpi4 volumio[1248]: info: ControllerMpd::getState Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand status Mar 24 03:44:18 rpi4 volumio[1248]: info: Mar 24 03:44:18 rpi4 volumio[1248]: ---------------------------- MPD announces state update: player Mar 24 03:44:18 rpi4 volumio[1248]: info: Mar 24 03:44:18 rpi4 volumio[1248]: ---------------------------- MPD announces state update: player Mar 24 03:44:18 rpi4 volumio[1248]: info: ControllerMpd::getState Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand status Mar 24 03:44:18 rpi4 volumio[1248]: info: sendMpdCommand status took 4 milliseconds Mar 24 03:44:18 rpi4 volumio[1248]: info: ControllerMpd::getState Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand status Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::parseState Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 03:44:18 rpi4 volumio[1248]: info: Mar 24 03:44:18 rpi4 volumio[1248]: ---------------------------- MPD announces state update: player Mar 24 03:44:18 rpi4 volumio[1248]: info: ControllerMpd::getState Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand status Mar 24 03:44:18 rpi4 volumio[1248]: info: Mar 24 03:44:18 rpi4 volumio[1248]: ---------------------------- MPD announces state update: player Mar 24 03:44:18 rpi4 volumio[1248]: info: ControllerMpd::getState Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand status Mar 24 03:44:18 rpi4 volumio[1248]: info: sendMpdCommand status took 7 milliseconds Mar 24 03:44:18 rpi4 volumio[1248]: info: sendMpdCommand status took 6 milliseconds Mar 24 03:44:18 rpi4 volumio[1248]: info: sendMpdCommand status took 4 milliseconds Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::parseState Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::parseState Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::parseState Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 03:44:18 rpi4 volumio[1248]: info: sendMpdCommand status took 8 milliseconds Mar 24 03:44:18 rpi4 volumio[1248]: info: sendMpdCommand playlistinfo took 7 milliseconds Mar 24 03:44:18 rpi4 volumio[1248]: info: sendMpdCommand status took 5 milliseconds Mar 24 03:44:18 rpi4 volumio[1248]: info: sendMpdCommand status took 6 milliseconds Mar 24 03:44:18 rpi4 volumio[1248]: info: sendMpdCommand playlistinfo took 4 milliseconds Mar 24 03:44:18 rpi4 volumio[1248]: info: sendMpdCommand playlistinfo took 4 milliseconds Mar 24 03:44:18 rpi4 volumio[1248]: info: sendMpdCommand playlistinfo took 4 milliseconds Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::parseState Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::parseTrackInfo Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::parseState Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::parseState Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::parseTrackInfo Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::parseTrackInfo Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::parseTrackInfo Mar 24 03:44:18 rpi4 volumio[1248]: info: ControllerMpd::pushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreCommandRouter::servicePushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:44:18 rpi4 volumio[1248]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Mar 24 03:44:18 rpi4 volumio[1248]: info: ControllerMpd::pushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreCommandRouter::servicePushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:44:18 rpi4 volumio[1248]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Mar 24 03:44:18 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:44:18 rpi4 volumio[1248]: info: [1774338258252] ControllerVolusonic::pushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreCommandRouter::servicePushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:44:18 rpi4 volumio[1248]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":244,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"stream.view?id=8isXfsETUxYo7HBBCgMvAM&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic","artist":null,"album":null,"uri":"https://navidrome.dubyte.com/rest/stream.view?id=8isXfsETUxYo7HBBCgMvAM&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic","trackType":""} Mar 24 03:44:18 rpi4 volumio[1248]: verbose: CURRENT POSITION 0 Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreStateMachine::syncState stateService play Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreStateMachine::syncState currentStatus play Mar 24 03:44:18 rpi4 volumio[1248]: info: Received an update from plugin. extracting info from payload Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreStateMachine::pushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreCommandRouter::volumioPushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreStateMachine::pushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreCommandRouter::volumioPushState Mar 24 03:44:18 rpi4 volumio[1248]: info: ControllerMpd::pushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreCommandRouter::servicePushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:44:18 rpi4 volumio[1248]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Mar 24 03:44:18 rpi4 volumio[1248]: info: ------------------------------ 28ms Mar 24 03:44:18 rpi4 volumio[1248]: info: ------------------------------ 28ms Mar 24 03:44:18 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:44:18.267-04:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.8.211:36432 @ 0x28be570" state=STATUS_PLAYING positionMs=0 volume=100 Mar 24 03:44:18 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:44:18.267-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.211:36432 @ 0x28be030" state=STATUS_PLAYING positionMs=0 volume=100 Mar 24 03:44:18 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:44:18.267-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.8.211:36432 @ 0x28be570" id="https://navidrome.dubyte.com/rest/stream.view?id=8isXfsETUxYo7HBBCgMvAM&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic" title="Dramas y comedias" Mar 24 03:44:18 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:44:18.268-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.211:36432 @ 0x28be030" id="https://navidrome.dubyte.com/rest/stream.view?id=8isXfsETUxYo7HBBCgMvAM&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic" title="Dramas y comedias" Mar 24 03:44:18 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:44:18.268-04:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.8.211:36432 @ 0x28be570" state=STATUS_PLAYING positionMs=0 volume=100 Mar 24 03:44:18 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:44:18.269-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.211:36432 @ 0x28be030" state=STATUS_PLAYING positionMs=0 volume=100 Mar 24 03:44:18 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:44:18.269-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.8.211:36432 @ 0x28be570" id="https://navidrome.dubyte.com/rest/stream.view?id=8isXfsETUxYo7HBBCgMvAM&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic" title="Dramas y comedias" Mar 24 03:44:18 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:44:18.269-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.211:36432 @ 0x28be030" id="https://navidrome.dubyte.com/rest/stream.view?id=8isXfsETUxYo7HBBCgMvAM&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic" title="Dramas y comedias" Mar 24 03:44:18 rpi4 volumio[1248]: info: ------------------------------ 39ms Mar 24 03:44:18 rpi4 volumio[1248]: info: Mar 24 03:44:18 rpi4 volumio[1248]: ---------------------------- MPD announces system playlist update Mar 24 03:44:18 rpi4 volumio[1248]: info: Ignoring MPD Status Update Mar 24 03:44:18 rpi4 volumio[1248]: info: [1774338258278] ControllerVolusonic: MPD player state update Mar 24 03:44:18 rpi4 volumio[1248]: info: ControllerMpd::getState Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand status Mar 24 03:44:18 rpi4 volumio[1248]: info: Mar 24 03:44:18 rpi4 volumio[1248]: ---------------------------- MPD announces state update: player Mar 24 03:44:18 rpi4 volumio[1248]: info: ControllerMpd::getState Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand status Mar 24 03:44:18 rpi4 volumio[1248]: info: sendMpdCommand playlistinfo took 31 milliseconds Mar 24 03:44:18 rpi4 volumio[1248]: info: sendMpdCommand playlistinfo took 30 milliseconds Mar 24 03:44:18 rpi4 volumio[1248]: info: sendMpdCommand playlistinfo took 31 milliseconds Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::parseTrackInfo Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::parseTrackInfo Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::parseTrackInfo Mar 24 03:44:18 rpi4 volumio[1248]: info: ControllerMpd::pushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreCommandRouter::servicePushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:44:18 rpi4 volumio[1248]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Mar 24 03:44:18 rpi4 volumio[1248]: info: ControllerMpd::pushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreCommandRouter::servicePushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:44:18 rpi4 volumio[1248]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Mar 24 03:44:18 rpi4 volumio[1248]: info: ControllerMpd::pushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreCommandRouter::servicePushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:44:18 rpi4 volumio[1248]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Mar 24 03:44:18 rpi4 volumio[1248]: info: ------------------------------ 45ms Mar 24 03:44:18 rpi4 volumio[1248]: info: ------------------------------ 42ms Mar 24 03:44:18 rpi4 volumio[1248]: info: ------------------------------ 41ms Mar 24 03:44:18 rpi4 volumio[1248]: info: Mar 24 03:44:18 rpi4 volumio[1248]: ---------------------------- MPD announces system playlist update Mar 24 03:44:18 rpi4 volumio[1248]: info: Ignoring MPD Status Update Mar 24 03:44:18 rpi4 volumio[1248]: info: Mar 24 03:44:18 rpi4 volumio[1248]: ---------------------------- MPD announces state update: player Mar 24 03:44:18 rpi4 volumio[1248]: info: ControllerMpd::getState Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand status Mar 24 03:44:18 rpi4 volumio[1248]: info: Mar 24 03:44:18 rpi4 volumio[1248]: ---------------------------- MPD announces system playlist update Mar 24 03:44:18 rpi4 volumio[1248]: info: Ignoring MPD Status Update Mar 24 03:44:18 rpi4 volumio[1248]: info: Mar 24 03:44:18 rpi4 volumio[1248]: ---------------------------- MPD announces state update: player Mar 24 03:44:18 rpi4 volumio[1248]: info: ControllerMpd::getState Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand status Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreCommandRouter::volumioGetQueue Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreStateMachine::getQueue Mar 24 03:44:18 rpi4 volumio[1248]: info: CorePlayQueue::getQueue Mar 24 03:44:18 rpi4 volumio[1248]: info: sendMpdCommand status took 22 milliseconds Mar 24 03:44:18 rpi4 volumio[1248]: info: ------------------------------ 23ms Mar 24 03:44:18 rpi4 volumio[1248]: info: sendMpdCommand status took 22 milliseconds Mar 24 03:44:18 rpi4 volumio[1248]: info: ------------------------------ 18ms Mar 24 03:44:18 rpi4 volumio[1248]: info: sendMpdCommand status took 17 milliseconds Mar 24 03:44:18 rpi4 volumio[1248]: info: ------------------------------ 16ms Mar 24 03:44:18 rpi4 volumio[1248]: info: sendMpdCommand status took 15 milliseconds Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::parseState Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::parseState Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::parseState Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::parseState Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 03:44:18 rpi4 volumio[1248]: info: sendMpdCommand playlistinfo took 3 milliseconds Mar 24 03:44:18 rpi4 volumio[1248]: info: sendMpdCommand playlistinfo took 2 milliseconds Mar 24 03:44:18 rpi4 volumio[1248]: info: sendMpdCommand playlistinfo took 2 milliseconds Mar 24 03:44:18 rpi4 volumio[1248]: info: sendMpdCommand playlistinfo took 2 milliseconds Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::parseTrackInfo Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::parseTrackInfo Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::parseTrackInfo Mar 24 03:44:18 rpi4 volumio[1248]: verbose: ControllerMpd::parseTrackInfo Mar 24 03:44:18 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:44:18 rpi4 volumio[1248]: info: [1774338258305] ControllerVolusonic::pushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreCommandRouter::servicePushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:44:18 rpi4 volumio[1248]: verbose: STATE SERVICE {"status":"play","position":0,"seek":848,"duration":244,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"966 Kbps","isStreaming":false,"title":"Dramas y comedias","artist":"Fangoria","album":"Cuatricromía","uri":"https://navidrome.dubyte.com/rest/stream.view?id=8isXfsETUxYo7HBBCgMvAM&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic","trackType":""} Mar 24 03:44:18 rpi4 volumio[1248]: verbose: CURRENT POSITION 0 Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreStateMachine::syncState stateService play Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreStateMachine::syncState currentStatus play Mar 24 03:44:18 rpi4 volumio[1248]: info: Received an update from plugin. extracting info from payload Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreStateMachine::pushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreCommandRouter::volumioPushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreStateMachine::pushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreCommandRouter::volumioPushState Mar 24 03:44:18 rpi4 volumio[1248]: info: ControllerMpd::pushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreCommandRouter::servicePushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:44:18 rpi4 volumio[1248]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Mar 24 03:44:18 rpi4 volumio[1248]: info: ControllerMpd::pushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreCommandRouter::servicePushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:44:18 rpi4 volumio[1248]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Mar 24 03:44:18 rpi4 volumio[1248]: info: ControllerMpd::pushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CoreCommandRouter::servicePushState Mar 24 03:44:18 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:44:18 rpi4 volumio[1248]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Mar 24 03:44:18 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:44:18.321-04:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.8.211:36432 @ 0x28be570" state=STATUS_PLAYING positionMs=848 volume=100 Mar 24 03:44:18 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:44:18.322-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.211:36432 @ 0x28be030" state=STATUS_PLAYING positionMs=848 volume=100 Mar 24 03:44:18 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:44:18.322-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.8.211:36432 @ 0x28be570" id="https://navidrome.dubyte.com/rest/stream.view?id=8isXfsETUxYo7HBBCgMvAM&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic" title="Dramas y comedias" Mar 24 03:44:18 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:44:18.322-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.211:36432 @ 0x28be030" id="https://navidrome.dubyte.com/rest/stream.view?id=8isXfsETUxYo7HBBCgMvAM&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic" title="Dramas y comedias" Mar 24 03:44:18 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:44:18.324-04:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.8.211:36432 @ 0x28be570" state=STATUS_PLAYING positionMs=848 volume=100 Mar 24 03:44:18 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:44:18.325-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.211:36432 @ 0x28be030" state=STATUS_PLAYING positionMs=848 volume=100 Mar 24 03:44:18 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:44:18.325-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.8.211:36432 @ 0x28be570" id="https://navidrome.dubyte.com/rest/stream.view?id=8isXfsETUxYo7HBBCgMvAM&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic" title="Dramas y comedias" Mar 24 03:44:18 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:44:18.325-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.211:36432 @ 0x28be030" id="https://navidrome.dubyte.com/rest/stream.view?id=8isXfsETUxYo7HBBCgMvAM&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic" title="Dramas y comedias" Mar 24 03:44:18 rpi4 volumio[1248]: info: ------------------------------ 52ms Mar 24 03:44:18 rpi4 volumio[1248]: info: ------------------------------ 47ms Mar 24 03:44:18 rpi4 volumio[1248]: info: ------------------------------ 45ms Mar 24 03:44:22 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:44:22.380-04:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="00:00:00:00:00:00%01,192.168.8.211:36432 @ 0x28be570" latency=389.614233ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Mar 24 03:44:22 rpi4 sudo[6988]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 24 03:44:22 rpi4 sudo[6990]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 24 03:44:22 rpi4 sudo[6990]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:44:22 rpi4 sudo[6988]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:44:22 rpi4 sudo[6988]: pam_unix(sudo:session): session closed for user root Mar 24 03:44:22 rpi4 sudo[6990]: pam_unix(sudo:session): session closed for user root Mar 24 03:44:23 rpi4 volumio[1248]: verbose: New Socket.io Connection to 192.168.8.226 from 192.168.8.211 UA: Mozilla/5.0 (Linux; Android 16; Pixel 10 Pro Build/CP1A.260305.018; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/145.0.7632.159 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Mar 24 03:44:23 rpi4 sudo[6994]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 24 03:44:23 rpi4 sudo[6994]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:44:23 rpi4 sudo[6994]: pam_unix(sudo:session): session closed for user root Mar 24 03:44:23 rpi4 sudo[6996]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 24 03:44:23 rpi4 sudo[6996]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:44:23 rpi4 sudo[6996]: pam_unix(sudo:session): session closed for user root Mar 24 03:44:23 rpi4 volumio[1248]: verbose: New Socket.io Connection to 192.168.8.226 from 192.168.8.211 UA: Mozilla/5.0 (Linux; Android 16; Pixel 10 Pro Build/CP1A.260305.018; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/145.0.7632.159 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Mar 24 03:44:23 rpi4 volumio[1248]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 24 03:44:23 rpi4 volumio[1248]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Mar 24 03:44:23 rpi4 volumio[1248]: info: CoreCommandRouter::volumioGetVisibleSources Mar 24 03:44:23 rpi4 volumio[1248]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 03:44:23 rpi4 volumio[1248]: info: CoreCommandRouter::volumioGetState Mar 24 03:44:23 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:44:23 rpi4 volumio[1248]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 24 03:44:23 rpi4 volumio[1248]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 24 03:44:23 rpi4 volumio[1248]: info: Received Get System Info Mar 24 03:44:23 rpi4 volumio[1248]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 03:44:23 rpi4 volumio[1248]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 03:44:23 rpi4 volumio[1248]: info: Discovery: Getting this device information Mar 24 03:44:23 rpi4 volumio[1248]: info: CoreCommandRouter::volumioGetState Mar 24 03:44:23 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:44:23 rpi4 volumio[1248]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 03:44:23 rpi4 volumio[1248]: info: CoreCommandRouter::volumioGetState Mar 24 03:44:23 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:44:23 rpi4 volumio[1248]: info: Listing playlists Mar 24 03:44:23 rpi4 volumio[1248]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Mar 24 03:44:23 rpi4 volumio[1248]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 24 03:44:24 rpi4 volumio[1248]: info: CoreCommandRouter::volumioGetQueue Mar 24 03:44:24 rpi4 volumio[1248]: info: CoreStateMachine::getQueue Mar 24 03:44:24 rpi4 volumio[1248]: info: CorePlayQueue::getQueue Mar 24 03:44:24 rpi4 volumio[1248]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Mar 24 03:44:25 rpi4 volumio[1248]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 03:44:25 rpi4 volumio[1248]: info: Received Get System Info Mar 24 03:44:25 rpi4 volumio[1248]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 03:44:25 rpi4 volumio[1248]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 03:44:25 rpi4 volumio[1248]: info: Discovery: Getting this device information Mar 24 03:44:25 rpi4 volumio[1248]: info: CoreCommandRouter::volumioGetState Mar 24 03:44:25 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:44:25 rpi4 volumio[1248]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 03:44:25 rpi4 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 214. Mar 24 03:44:25 rpi4 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Mar 24 03:44:25 rpi4 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Mar 24 03:44:25 rpi4 upmpdcli[6999]: Could not open config: /tmp/upmpdcli.conf Mar 24 03:44:25 rpi4 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Mar 24 03:44:25 rpi4 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Mar 24 03:44:25 rpi4 volumio[1248]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 03:44:25 rpi4 volumio[1248]: info: Received Get System Info Mar 24 03:44:25 rpi4 volumio[1248]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 03:44:25 rpi4 volumio[1248]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 03:44:25 rpi4 volumio[1248]: info: Discovery: Getting this device information Mar 24 03:44:25 rpi4 volumio[1248]: info: CoreCommandRouter::volumioGetState Mar 24 03:44:25 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:44:25 rpi4 volumio[1248]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 03:44:33 rpi4 volumio[1248]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Mar 24 03:44:40 rpi4 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 215. Mar 24 03:44:40 rpi4 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Mar 24 03:44:40 rpi4 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Mar 24 03:44:40 rpi4 upmpdcli[7029]: Could not open config: /tmp/upmpdcli.conf Mar 24 03:44:40 rpi4 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Mar 24 03:44:40 rpi4 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Mar 24 03:44:41 rpi4 volumio[1248]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 24 03:44:41 rpi4 volumio[1248]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Mar 24 03:44:41 rpi4 volumio[1248]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Mar 24 03:44:41 rpi4 volumio[1248]: info: Received Get System Version Mar 24 03:44:41 rpi4 volumio[1248]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 03:44:41 rpi4 volumio[1248]: info: Received Get System Info Mar 24 03:44:41 rpi4 volumio[1248]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 03:44:41 rpi4 volumio[1248]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 03:44:41 rpi4 volumio[1248]: info: Discovery: Getting this device information Mar 24 03:44:41 rpi4 volumio[1248]: info: CoreCommandRouter::volumioGetState Mar 24 03:44:41 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:44:41 rpi4 volumio[1248]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 03:44:47 rpi4 go-librespot[1674]: time="2026-03-24T03:44:47-04:00" level=trace msg="received accesspoint ping" Mar 24 03:44:47 rpi4 go-librespot[1674]: time="2026-03-24T03:44:47-04:00" level=trace msg="received accesspoint pong ack" Mar 24 03:44:47 rpi4 go-librespot[1674]: time="2026-03-24T03:44:47-04:00" level=trace msg="sent dealer ping" Mar 24 03:44:47 rpi4 go-librespot[1674]: time="2026-03-24T03:44:47-04:00" level=trace msg="received dealer pong" Mar 24 03:44:55 rpi4 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 216. Mar 24 03:44:55 rpi4 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Mar 24 03:44:55 rpi4 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Mar 24 03:44:55 rpi4 upmpdcli[7046]: Could not open config: /tmp/upmpdcli.conf Mar 24 03:44:55 rpi4 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Mar 24 03:44:55 rpi4 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Mar 24 03:45:11 rpi4 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 217. Mar 24 03:45:11 rpi4 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Mar 24 03:45:11 rpi4 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Mar 24 03:45:11 rpi4 upmpdcli[7076]: Could not open config: /tmp/upmpdcli.conf Mar 24 03:45:11 rpi4 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Mar 24 03:45:11 rpi4 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Mar 24 03:45:17 rpi4 go-librespot[1674]: time="2026-03-24T03:45:17-04:00" level=trace msg="sent dealer ping" Mar 24 03:45:17 rpi4 go-librespot[1674]: time="2026-03-24T03:45:17-04:00" level=trace msg="received dealer pong" Mar 24 03:45:18 rpi4 volumio[1248]: info: CoreCommandRouter::executeOnPlugin: volusonic , handleBrowseUri Mar 24 03:45:18 rpi4 volumio[1248]: info: Preload queue cleared Mar 24 03:45:18 rpi4 volumio[1248]: info: Preloading song: volusonic/track/dfa79034c03f38fb6611f12d7687b45e Mar 24 03:45:18 rpi4 volumio[1248]: info: Preloading song: volusonic/track/d7d97507597efc777cc6e8348da5bd1b Mar 24 03:45:18 rpi4 volumio[1248]: info: Preloading song: volusonic/track/7194b11f43e137a4476d73eb426dce14 Mar 24 03:45:18 rpi4 volumio[1248]: info: Preloading song: volusonic/track/8c843326a1450fb1c6b711bdd8decf9f Mar 24 03:45:18 rpi4 volumio[1248]: info: Preloading song: volusonic/track/292aa6da3c075c2152cf9a31b532b751 Mar 24 03:45:18 rpi4 volumio[1248]: info: Preloading song: volusonic/track/29b9207fa87734eff9ec32b165329a19 Mar 24 03:45:18 rpi4 volumio[1248]: info: Preloading song: volusonic/track/6c4b3c72fa86fd77a371a1820effc789 Mar 24 03:45:18 rpi4 volumio[1248]: info: Preloading song: volusonic/track/eb9e6c770e73472260fff114d35a74c0 Mar 24 03:45:18 rpi4 volumio[1248]: info: Preloading song: volusonic/track/aa35aac840cf5d4b8bc1a08c8123e7d8 Mar 24 03:45:18 rpi4 volumio[1248]: info: Preloading song: volusonic/track/28a3f45c58a2cd1c769d8b3f931264d4 Mar 24 03:45:18 rpi4 volumio[1248]: info: Preloading song: volusonic/track/89d81fe25dbf442c9d96505752d31b95 Mar 24 03:45:18 rpi4 volumio[1248]: info: Preloading song: volusonic/track/fd120ffe589ced11a291c0609d320f5d Mar 24 03:45:18 rpi4 volumio[1248]: info: Preloading song: volusonic/track/ed9f835659304ac40a135a0d378572e9 Mar 24 03:45:18 rpi4 volumio[1248]: info: Preloading song: volusonic/track/aeb3dd5b246e63972b9a63e3952cd3b4 Mar 24 03:45:18 rpi4 volumio[1248]: info: Exploding uri volusonic/track/dfa79034c03f38fb6611f12d7687b45e in service volusonic Mar 24 03:45:18 rpi4 volumio[1248]: info: Exploding uri volusonic/track/d7d97507597efc777cc6e8348da5bd1b in service volusonic Mar 24 03:45:18 rpi4 volumio[1248]: info: No valid Plugin REST Endpoint Mar 24 03:45:18 rpi4 volumio[1248]: info: Exploding uri volusonic/track/7194b11f43e137a4476d73eb426dce14 in service volusonic Mar 24 03:45:18 rpi4 volumio[1248]: info: Exploding uri volusonic/track/8c843326a1450fb1c6b711bdd8decf9f in service volusonic Mar 24 03:45:19 rpi4 volumio[1248]: info: Exploding uri volusonic/track/292aa6da3c075c2152cf9a31b532b751 in service volusonic Mar 24 03:45:19 rpi4 volumio[1248]: info: Exploding uri volusonic/track/29b9207fa87734eff9ec32b165329a19 in service volusonic Mar 24 03:45:19 rpi4 volumio[1248]: info: Exploding uri volusonic/track/6c4b3c72fa86fd77a371a1820effc789 in service volusonic Mar 24 03:45:19 rpi4 volumio[1248]: info: Exploding uri volusonic/track/eb9e6c770e73472260fff114d35a74c0 in service volusonic Mar 24 03:45:19 rpi4 volumio[1248]: info: Exploding uri volusonic/track/aa35aac840cf5d4b8bc1a08c8123e7d8 in service volusonic Mar 24 03:45:19 rpi4 volumio[1248]: info: Exploding uri volusonic/track/28a3f45c58a2cd1c769d8b3f931264d4 in service volusonic Mar 24 03:45:19 rpi4 volumio[1248]: info: Exploding uri volusonic/track/89d81fe25dbf442c9d96505752d31b95 in service volusonic Mar 24 03:45:19 rpi4 volumio[1248]: info: Exploding uri volusonic/track/fd120ffe589ced11a291c0609d320f5d in service volusonic Mar 24 03:45:19 rpi4 volumio[1248]: info: Exploding uri volusonic/track/ed9f835659304ac40a135a0d378572e9 in service volusonic Mar 24 03:45:19 rpi4 volumio[1248]: info: Exploding uri volusonic/track/aeb3dd5b246e63972b9a63e3952cd3b4 in service volusonic Mar 24 03:45:20 rpi4 volumio[1248]: info: Preload queue cleared Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreStateMachine::ClearQueue Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreStateMachine::stop Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreStateMachine::stPlaybackTimer Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreStateMachine::updateTrackBlock Mar 24 03:45:20 rpi4 volumio[1248]: info: CorePlayQueue::getTrackBlock Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreStateMachine::pushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreCommandRouter::volumioPushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreStateMachine::serviceStop Mar 24 03:45:20 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreCommandRouter::serviceStop Mar 24 03:45:20 rpi4 volumio[1248]: info: [1774338320058] ControllerVolusonic::stop Mar 24 03:45:20 rpi4 volumio[1248]: info: ControllerMpd::stop Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand stop Mar 24 03:45:20 rpi4 volumio[1248]: info: CorePlayQueue::clearPlayQueue Mar 24 03:45:20 rpi4 volumio[1248]: info: CorePlayQueue::saveQueue Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreCommandRouter::volumioPushQueue Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreStateMachine::addQueueItems Mar 24 03:45:20 rpi4 volumio[1248]: info: CorePlayQueue::addQueueItems Mar 24 03:45:20 rpi4 volumio[1248]: info: Preload queue cleared Mar 24 03:45:20 rpi4 volumio[1248]: info: Adding Item to queue: volusonic/random/2ERNBcgs34UkFQVCW4SfrH Mar 24 03:45:20 rpi4 volumio[1248]: info: Exploding uri volusonic/random/2ERNBcgs34UkFQVCW4SfrH in service volusonic Mar 24 03:45:20 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:45:20.061-04:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.8.211:36432 @ 0x28be570" state=STATUS_STOPPED positionMs=0 volume=100 Mar 24 03:45:20 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:45:20.062-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.211:36432 @ 0x28be030" state=STATUS_STOPPED positionMs=0 volume=100 Mar 24 03:45:20 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:45:20.062-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.8.211:36432 @ 0x28be570" id="https://navidrome.dubyte.com/rest/stream.view?id=8isXfsETUxYo7HBBCgMvAM&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic" title="Dramas y comedias" Mar 24 03:45:20 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:45:20.062-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.211:36432 @ 0x28be030" id="https://navidrome.dubyte.com/rest/stream.view?id=8isXfsETUxYo7HBBCgMvAM&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic" title="Dramas y comedias" Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreCommandRouter::volumioPushQueue Mar 24 03:45:20 rpi4 volumio[1248]: info: CorePlayQueue::saveQueue Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreStateMachine::updateTrackBlock Mar 24 03:45:20 rpi4 volumio[1248]: info: CorePlayQueue::getTrackBlock Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreCommandRouter::volumioPlay Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreStateMachine::play index 0 Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreStateMachine::stop Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreStateMachine::play index undefined Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 24 03:45:20 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreStateMachine::startPlaybackTimer Mar 24 03:45:20 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:45:20 rpi4 volumio[1248]: info: [1774338320079] ControllerVolusonic::clearAddPlayTrack Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand stop Mar 24 03:45:20 rpi4 volumio[1248]: info: [1774338320087] ControllerVolusonic: MPD player state update Mar 24 03:45:20 rpi4 volumio[1248]: info: ControllerMpd::getState Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand status Mar 24 03:45:20 rpi4 volumio[1248]: info: Mar 24 03:45:20 rpi4 volumio[1248]: ---------------------------- MPD announces state update: player Mar 24 03:45:20 rpi4 volumio[1248]: info: sendMpdCommand stop took 29 milliseconds Mar 24 03:45:20 rpi4 volumio[1248]: info: ControllerMpd::getState Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand status Mar 24 03:45:20 rpi4 volumio[1248]: info: sendMpdCommand stop took 8 milliseconds Mar 24 03:45:20 rpi4 volumio[1248]: info: ControllerMpd::getState Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand status Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand clear Mar 24 03:45:20 rpi4 volumio[1248]: info: Mar 24 03:45:20 rpi4 volumio[1248]: ---------------------------- MPD announces system playlist update Mar 24 03:45:20 rpi4 volumio[1248]: info: Ignoring MPD Status Update Mar 24 03:45:20 rpi4 volumio[1248]: info: sendMpdCommand status took 2 milliseconds Mar 24 03:45:20 rpi4 volumio[1248]: info: sendMpdCommand status took 2 milliseconds Mar 24 03:45:20 rpi4 volumio[1248]: info: sendMpdCommand status took 2 milliseconds Mar 24 03:45:20 rpi4 volumio[1248]: info: sendMpdCommand clear took 2 milliseconds Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::parseState Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::parseState Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::parseState Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand load "https://navidrome.dubyte.com/rest/stream.view?id=dfa79034c03f38fb6611f12d7687b45e&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic" Mar 24 03:45:20 rpi4 volumio[1248]: info: Mar 24 03:45:20 rpi4 volumio[1248]: ---------------------------- MPD announces state update: player Mar 24 03:45:20 rpi4 volumio[1248]: info: ControllerMpd::getState Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand status Mar 24 03:45:20 rpi4 volumio[1248]: info: Mar 24 03:45:20 rpi4 volumio[1248]: ---------------------------- MPD announces state update: player Mar 24 03:45:20 rpi4 volumio[1248]: info: ControllerMpd::getState Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand status Mar 24 03:45:20 rpi4 volumio[1248]: error: updateQueue error: null Mar 24 03:45:20 rpi4 volumio[1248]: info: ------------------------------ 5ms Mar 24 03:45:20 rpi4 volumio[1248]: info: sendMpdCommand playlistinfo took 4 milliseconds Mar 24 03:45:20 rpi4 volumio[1248]: info: sendMpdCommand playlistinfo took 4 milliseconds Mar 24 03:45:20 rpi4 volumio[1248]: info: sendMpdCommand playlistinfo took 3 milliseconds Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::parseTrackInfo Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::parseTrackInfo Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::parseTrackInfo Mar 24 03:45:20 rpi4 volumio[1248]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Mar 24 03:45:20 rpi4 volumio[1248]: info: ------------------------------ 9ms Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand add "https://navidrome.dubyte.com/rest/stream.view?id=dfa79034c03f38fb6611f12d7687b45e&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic" Mar 24 03:45:20 rpi4 volumio[1248]: info: sendMpdCommand status took 14 milliseconds Mar 24 03:45:20 rpi4 volumio[1248]: info: sendMpdCommand status took 13 milliseconds Mar 24 03:45:20 rpi4 volumio[1248]: info: sendMpdCommand add "https://navidrome.dubyte.com/rest/stream.view?id=dfa79034c03f38fb6611f12d7687b45e&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic" took 1 milliseconds Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::parseState Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::parseState Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand play Mar 24 03:45:20 rpi4 volumio[1248]: info: ControllerMpd::pushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreCommandRouter::servicePushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreStateMachine::pushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreCommandRouter::volumioPushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:45:20 rpi4 volumio[1248]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Mar 24 03:45:20 rpi4 volumio[1248]: info: ControllerMpd::pushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreCommandRouter::servicePushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreStateMachine::pushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreCommandRouter::volumioPushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:45:20 rpi4 volumio[1248]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Mar 24 03:45:20 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:45:20.119-04:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.8.211:36432 @ 0x28be570" state=STATUS_STOPPED positionMs=20 volume=100 Mar 24 03:45:20 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:45:20.119-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.211:36432 @ 0x28be030" state=STATUS_STOPPED positionMs=20 volume=100 Mar 24 03:45:20 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:45:20.120-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.8.211:36432 @ 0x28be570" id="https://navidrome.dubyte.com/rest/stream.view?id=dfa79034c03f38fb6611f12d7687b45e&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic" title=Bitterblue Mar 24 03:45:20 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:45:20.120-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.211:36432 @ 0x28be030" id="https://navidrome.dubyte.com/rest/stream.view?id=dfa79034c03f38fb6611f12d7687b45e&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic" title=Bitterblue Mar 24 03:45:20 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:45:20.121-04:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.8.211:36432 @ 0x28be570" state=STATUS_STOPPED positionMs=20 volume=100 Mar 24 03:45:20 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:45:20.121-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.211:36432 @ 0x28be030" state=STATUS_STOPPED positionMs=20 volume=100 Mar 24 03:45:20 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:45:20.121-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.8.211:36432 @ 0x28be570" id="https://navidrome.dubyte.com/rest/stream.view?id=dfa79034c03f38fb6611f12d7687b45e&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic" title=Bitterblue Mar 24 03:45:20 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:45:20.121-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.211:36432 @ 0x28be030" id="https://navidrome.dubyte.com/rest/stream.view?id=dfa79034c03f38fb6611f12d7687b45e&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic" title=Bitterblue Mar 24 03:45:20 rpi4 volumio[1248]: info: ------------------------------ 37ms Mar 24 03:45:20 rpi4 volumio[1248]: info: ------------------------------ 35ms Mar 24 03:45:20 rpi4 volumio[1248]: info: Mar 24 03:45:20 rpi4 volumio[1248]: ---------------------------- MPD announces system playlist update Mar 24 03:45:20 rpi4 volumio[1248]: info: Ignoring MPD Status Update Mar 24 03:45:20 rpi4 volumio[1248]: info: Mar 24 03:45:20 rpi4 volumio[1248]: ---------------------------- MPD announces system playlist update Mar 24 03:45:20 rpi4 volumio[1248]: info: Ignoring MPD Status Update Mar 24 03:45:20 rpi4 volumio[1248]: info: Mar 24 03:45:20 rpi4 volumio[1248]: ---------------------------- MPD announces system playlist update Mar 24 03:45:20 rpi4 volumio[1248]: info: Ignoring MPD Status Update Mar 24 03:45:20 rpi4 volumio[1248]: info: sendMpdCommand play took 26 milliseconds Mar 24 03:45:20 rpi4 volumio[1248]: info: ------------------------------ 4ms Mar 24 03:45:20 rpi4 volumio[1248]: info: ------------------------------ 3ms Mar 24 03:45:20 rpi4 volumio[1248]: info: ControllerMpd::getState Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand status Mar 24 03:45:20 rpi4 volumio[1248]: info: Mar 24 03:45:20 rpi4 volumio[1248]: ---------------------------- MPD announces system playlist update Mar 24 03:45:20 rpi4 volumio[1248]: info: Ignoring MPD Status Update Mar 24 03:45:20 rpi4 volumio[1248]: info: Mar 24 03:45:20 rpi4 volumio[1248]: ---------------------------- MPD announces system playlist update Mar 24 03:45:20 rpi4 volumio[1248]: info: Ignoring MPD Status Update Mar 24 03:45:20 rpi4 volumio[1248]: info: ------------------------------ 9ms Mar 24 03:45:20 rpi4 volumio[1248]: info: sendMpdCommand status took 9 milliseconds Mar 24 03:45:20 rpi4 volumio[1248]: info: ------------------------------ 9ms Mar 24 03:45:20 rpi4 volumio[1248]: info: ------------------------------ 8ms Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::parseState Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 03:45:20 rpi4 volumio[1248]: info: sendMpdCommand playlistinfo took 4 milliseconds Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::parseTrackInfo Mar 24 03:45:20 rpi4 volumio[1248]: info: [1774338320146] ControllerVolusonic::pushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreCommandRouter::servicePushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:45:20 rpi4 volumio[1248]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"stream.view?id=dfa79034c03f38fb6611f12d7687b45e&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic","artist":null,"album":null,"uri":"https://navidrome.dubyte.com/rest/stream.view?id=dfa79034c03f38fb6611f12d7687b45e&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic","trackType":""} Mar 24 03:45:20 rpi4 volumio[1248]: verbose: CURRENT POSITION 0 Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreStateMachine::syncState stateService play Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreStateMachine::syncState currentStatus stop Mar 24 03:45:20 rpi4 volumio[1248]: info: Mar 24 03:45:20 rpi4 volumio[1248]: ---------------------------- MPD announces state update: player Mar 24 03:45:20 rpi4 volumio[1248]: info: ControllerMpd::getState Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand status Mar 24 03:45:20 rpi4 volumio[1248]: info: Mar 24 03:45:20 rpi4 volumio[1248]: ---------------------------- MPD announces state update: player Mar 24 03:45:20 rpi4 volumio[1248]: info: ControllerMpd::getState Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand status Mar 24 03:45:20 rpi4 volumio[1248]: info: [1774338320216] ControllerVolusonic: MPD player state update Mar 24 03:45:20 rpi4 volumio[1248]: info: ControllerMpd::getState Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand status Mar 24 03:45:20 rpi4 volumio[1248]: info: Mar 24 03:45:20 rpi4 volumio[1248]: ---------------------------- MPD announces state update: player Mar 24 03:45:20 rpi4 volumio[1248]: info: ControllerMpd::getState Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand status Mar 24 03:45:20 rpi4 volumio[1248]: info: Mar 24 03:45:20 rpi4 volumio[1248]: ---------------------------- MPD announces state update: player Mar 24 03:45:20 rpi4 volumio[1248]: info: sendMpdCommand status took 3 milliseconds Mar 24 03:45:20 rpi4 volumio[1248]: info: ControllerMpd::getState Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand status Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::parseState Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 03:45:20 rpi4 volumio[1248]: info: Mar 24 03:45:20 rpi4 volumio[1248]: ---------------------------- MPD announces state update: player Mar 24 03:45:20 rpi4 volumio[1248]: info: ControllerMpd::getState Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand status Mar 24 03:45:20 rpi4 volumio[1248]: info: sendMpdCommand status took 6 milliseconds Mar 24 03:45:20 rpi4 volumio[1248]: info: sendMpdCommand status took 5 milliseconds Mar 24 03:45:20 rpi4 volumio[1248]: info: sendMpdCommand status took 4 milliseconds Mar 24 03:45:20 rpi4 volumio[1248]: info: sendMpdCommand status took 3 milliseconds Mar 24 03:45:20 rpi4 volumio[1248]: info: sendMpdCommand playlistinfo took 3 milliseconds Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::parseState Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::parseState Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::parseState Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::parseState Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::parseTrackInfo Mar 24 03:45:20 rpi4 volumio[1248]: info: ControllerMpd::pushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreCommandRouter::servicePushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:45:20 rpi4 volumio[1248]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Mar 24 03:45:20 rpi4 volumio[1248]: info: ------------------------------ 9ms Mar 24 03:45:20 rpi4 volumio[1248]: info: Mar 24 03:45:20 rpi4 volumio[1248]: ---------------------------- MPD announces state update: player Mar 24 03:45:20 rpi4 volumio[1248]: info: ControllerMpd::getState Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand status Mar 24 03:45:20 rpi4 volumio[1248]: info: sendMpdCommand status took 5 milliseconds Mar 24 03:45:20 rpi4 volumio[1248]: info: sendMpdCommand playlistinfo took 3 milliseconds Mar 24 03:45:20 rpi4 volumio[1248]: info: sendMpdCommand playlistinfo took 3 milliseconds Mar 24 03:45:20 rpi4 volumio[1248]: info: sendMpdCommand playlistinfo took 4 milliseconds Mar 24 03:45:20 rpi4 volumio[1248]: info: sendMpdCommand playlistinfo took 4 milliseconds Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::parseState Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::parseTrackInfo Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::parseTrackInfo Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::parseTrackInfo Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::parseTrackInfo Mar 24 03:45:20 rpi4 volumio[1248]: info: ControllerMpd::pushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreCommandRouter::servicePushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:45:20 rpi4 volumio[1248]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Mar 24 03:45:20 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:45:20 rpi4 volumio[1248]: info: [1774338320228] ControllerVolusonic::pushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreCommandRouter::servicePushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:45:20 rpi4 volumio[1248]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":231,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"stream.view?id=dfa79034c03f38fb6611f12d7687b45e&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic","artist":null,"album":null,"uri":"https://navidrome.dubyte.com/rest/stream.view?id=dfa79034c03f38fb6611f12d7687b45e&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic","trackType":""} Mar 24 03:45:20 rpi4 volumio[1248]: verbose: CURRENT POSITION 0 Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreStateMachine::syncState stateService play Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreStateMachine::syncState currentStatus play Mar 24 03:45:20 rpi4 volumio[1248]: info: Received an update from plugin. extracting info from payload Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreStateMachine::pushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreCommandRouter::volumioPushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreStateMachine::pushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreCommandRouter::volumioPushState Mar 24 03:45:20 rpi4 volumio[1248]: info: ControllerMpd::pushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreCommandRouter::servicePushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:45:20 rpi4 volumio[1248]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Mar 24 03:45:20 rpi4 volumio[1248]: info: ControllerMpd::pushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreCommandRouter::servicePushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:45:20 rpi4 volumio[1248]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Mar 24 03:45:20 rpi4 volumio[1248]: info: ------------------------------ 27ms Mar 24 03:45:20 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:45:20.246-04:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.8.211:36432 @ 0x28be570" state=STATUS_PLAYING positionMs=0 volume=100 Mar 24 03:45:20 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:45:20.247-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.211:36432 @ 0x28be030" state=STATUS_PLAYING positionMs=0 volume=100 Mar 24 03:45:20 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:45:20.247-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.8.211:36432 @ 0x28be570" id="https://navidrome.dubyte.com/rest/stream.view?id=dfa79034c03f38fb6611f12d7687b45e&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic" title=Bitterblue Mar 24 03:45:20 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:45:20.247-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.211:36432 @ 0x28be030" id="https://navidrome.dubyte.com/rest/stream.view?id=dfa79034c03f38fb6611f12d7687b45e&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic" title=Bitterblue Mar 24 03:45:20 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:45:20.248-04:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.8.211:36432 @ 0x28be570" state=STATUS_PLAYING positionMs=0 volume=100 Mar 24 03:45:20 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:45:20.248-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.211:36432 @ 0x28be030" state=STATUS_PLAYING positionMs=0 volume=100 Mar 24 03:45:20 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:45:20.248-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.8.211:36432 @ 0x28be570" id="https://navidrome.dubyte.com/rest/stream.view?id=dfa79034c03f38fb6611f12d7687b45e&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic" title=Bitterblue Mar 24 03:45:20 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:45:20.251-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.211:36432 @ 0x28be030" id="https://navidrome.dubyte.com/rest/stream.view?id=dfa79034c03f38fb6611f12d7687b45e&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic" title=Bitterblue Mar 24 03:45:20 rpi4 volumio[1248]: info: ------------------------------ 41ms Mar 24 03:45:20 rpi4 volumio[1248]: info: ------------------------------ 40ms Mar 24 03:45:20 rpi4 volumio[1248]: info: Mar 24 03:45:20 rpi4 volumio[1248]: ---------------------------- MPD announces system playlist update Mar 24 03:45:20 rpi4 volumio[1248]: info: Ignoring MPD Status Update Mar 24 03:45:20 rpi4 volumio[1248]: info: [1774338320258] ControllerVolusonic: MPD player state update Mar 24 03:45:20 rpi4 volumio[1248]: info: ControllerMpd::getState Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand status Mar 24 03:45:20 rpi4 volumio[1248]: info: Mar 24 03:45:20 rpi4 volumio[1248]: ---------------------------- MPD announces state update: player Mar 24 03:45:20 rpi4 volumio[1248]: info: sendMpdCommand status took 35 milliseconds Mar 24 03:45:20 rpi4 volumio[1248]: info: sendMpdCommand playlistinfo took 33 milliseconds Mar 24 03:45:20 rpi4 volumio[1248]: info: ControllerMpd::getState Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand status Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::parseState Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::parseTrackInfo Mar 24 03:45:20 rpi4 volumio[1248]: info: ControllerMpd::pushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreCommandRouter::servicePushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:45:20 rpi4 volumio[1248]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Mar 24 03:45:20 rpi4 volumio[1248]: info: ------------------------------ 41ms Mar 24 03:45:20 rpi4 volumio[1248]: info: Mar 24 03:45:20 rpi4 volumio[1248]: ---------------------------- MPD announces system playlist update Mar 24 03:45:20 rpi4 volumio[1248]: info: Ignoring MPD Status Update Mar 24 03:45:20 rpi4 volumio[1248]: info: Mar 24 03:45:20 rpi4 volumio[1248]: ---------------------------- MPD announces state update: player Mar 24 03:45:20 rpi4 volumio[1248]: info: ControllerMpd::getState Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand status Mar 24 03:45:20 rpi4 volumio[1248]: info: Mar 24 03:45:20 rpi4 volumio[1248]: ---------------------------- MPD announces system playlist update Mar 24 03:45:20 rpi4 volumio[1248]: info: Ignoring MPD Status Update Mar 24 03:45:20 rpi4 volumio[1248]: info: Mar 24 03:45:20 rpi4 volumio[1248]: ---------------------------- MPD announces state update: player Mar 24 03:45:20 rpi4 volumio[1248]: info: ControllerMpd::getState Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand status Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreCommandRouter::volumioGetQueue Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreStateMachine::getQueue Mar 24 03:45:20 rpi4 volumio[1248]: info: CorePlayQueue::getQueue Mar 24 03:45:20 rpi4 volumio[1248]: info: sendMpdCommand status took 17 milliseconds Mar 24 03:45:20 rpi4 volumio[1248]: info: ------------------------------ 18ms Mar 24 03:45:20 rpi4 volumio[1248]: info: sendMpdCommand status took 17 milliseconds Mar 24 03:45:20 rpi4 volumio[1248]: info: sendMpdCommand playlistinfo took 17 milliseconds Mar 24 03:45:20 rpi4 volumio[1248]: info: ------------------------------ 16ms Mar 24 03:45:20 rpi4 volumio[1248]: info: sendMpdCommand status took 16 milliseconds Mar 24 03:45:20 rpi4 volumio[1248]: info: ------------------------------ 15ms Mar 24 03:45:20 rpi4 volumio[1248]: info: sendMpdCommand status took 15 milliseconds Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::parseState Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::parseState Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::parseTrackInfo Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::parseState Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::parseState Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 03:45:20 rpi4 volumio[1248]: info: ControllerMpd::pushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreCommandRouter::servicePushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:45:20 rpi4 volumio[1248]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Mar 24 03:45:20 rpi4 volumio[1248]: info: ------------------------------ 56ms Mar 24 03:45:20 rpi4 volumio[1248]: info: sendMpdCommand playlistinfo took 2 milliseconds Mar 24 03:45:20 rpi4 volumio[1248]: info: sendMpdCommand playlistinfo took 3 milliseconds Mar 24 03:45:20 rpi4 volumio[1248]: info: sendMpdCommand playlistinfo took 3 milliseconds Mar 24 03:45:20 rpi4 volumio[1248]: info: sendMpdCommand playlistinfo took 3 milliseconds Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::parseTrackInfo Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::parseTrackInfo Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::parseTrackInfo Mar 24 03:45:20 rpi4 volumio[1248]: verbose: ControllerMpd::parseTrackInfo Mar 24 03:45:20 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:45:20 rpi4 volumio[1248]: info: [1774338320282] ControllerVolusonic::pushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreCommandRouter::servicePushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:45:20 rpi4 volumio[1248]: verbose: STATE SERVICE {"status":"play","position":0,"seek":848,"duration":231,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"675 Kbps","isStreaming":false,"title":"Bitterblue","artist":"Bonnie Tyler","album":"Bitterblue","uri":"https://navidrome.dubyte.com/rest/stream.view?id=dfa79034c03f38fb6611f12d7687b45e&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic","trackType":""} Mar 24 03:45:20 rpi4 volumio[1248]: verbose: CURRENT POSITION 0 Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreStateMachine::syncState stateService play Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreStateMachine::syncState currentStatus play Mar 24 03:45:20 rpi4 volumio[1248]: info: Received an update from plugin. extracting info from payload Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreStateMachine::pushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreCommandRouter::volumioPushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreStateMachine::pushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreCommandRouter::volumioPushState Mar 24 03:45:20 rpi4 volumio[1248]: info: ControllerMpd::pushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreCommandRouter::servicePushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:45:20 rpi4 volumio[1248]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Mar 24 03:45:20 rpi4 volumio[1248]: info: ControllerMpd::pushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreCommandRouter::servicePushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:45:20 rpi4 volumio[1248]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Mar 24 03:45:20 rpi4 volumio[1248]: info: ControllerMpd::pushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CoreCommandRouter::servicePushState Mar 24 03:45:20 rpi4 volumio[1248]: info: CorePlayQueue::getTrack 0 Mar 24 03:45:20 rpi4 volumio[1248]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Mar 24 03:45:20 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:45:20.295-04:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.8.211:36432 @ 0x28be570" state=STATUS_PLAYING positionMs=848 volume=100 Mar 24 03:45:20 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:45:20.295-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.211:36432 @ 0x28be030" state=STATUS_PLAYING positionMs=848 volume=100 Mar 24 03:45:20 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:45:20.295-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.8.211:36432 @ 0x28be570" id="https://navidrome.dubyte.com/rest/stream.view?id=dfa79034c03f38fb6611f12d7687b45e&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic" title=Bitterblue Mar 24 03:45:20 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:45:20.296-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.211:36432 @ 0x28be030" id="https://navidrome.dubyte.com/rest/stream.view?id=dfa79034c03f38fb6611f12d7687b45e&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic" title=Bitterblue Mar 24 03:45:20 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:45:20.296-04:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.8.211:36432 @ 0x28be570" state=STATUS_PLAYING positionMs=848 volume=100 Mar 24 03:45:20 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:45:20.296-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.211:36432 @ 0x28be030" state=STATUS_PLAYING positionMs=848 volume=100 Mar 24 03:45:20 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:45:20.297-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.8.211:36432 @ 0x28be570" id="https://navidrome.dubyte.com/rest/stream.view?id=dfa79034c03f38fb6611f12d7687b45e&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic" title=Bitterblue Mar 24 03:45:20 rpi4 volumio5-onboarding[1613]: time=2026-03-24T03:45:20.297-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.211:36432 @ 0x28be030" id="https://navidrome.dubyte.com/rest/stream.view?id=dfa79034c03f38fb6611f12d7687b45e&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic" title=Bitterblue Mar 24 03:45:20 rpi4 volumio[1248]: info: ------------------------------ 47ms Mar 24 03:45:20 rpi4 volumio[1248]: info: ------------------------------ 45ms Mar 24 03:45:20 rpi4 volumio[1248]: info: ------------------------------ 44ms Mar 24 03:45:26 rpi4 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 218. Mar 24 03:45:26 rpi4 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Mar 24 03:45:26 rpi4 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Mar 24 03:45:26 rpi4 upmpdcli[7095]: Could not open config: /tmp/upmpdcli.conf Mar 24 03:45:26 rpi4 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Mar 24 03:45:26 rpi4 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Mar 24 03:45:31 rpi4 volumio[1248]: info: Adding https://navidrome.dubyte.com/rest/stream.view?id=dfa79034c03f38fb6611f12d7687b45e&format=raw&u=dubyte&t=d481eb5ed47ec0a1f577ef1e1fd2b257&s=MyahM&v=1.10.2&f=json&c=volusonic to favourites with specific volusonic method Mar 24 03:45:31 rpi4 volumio[1248]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 03:45:31 rpi4 volumio[1248]: TypeError: Cannot read properties of undefined (reading 'then') Mar 24 03:45:31 rpi4 volumio[1248]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:679:20) Mar 24 03:45:31 rpi4 volumio[1248]: at Socket.emit (node:events:514:28) Mar 24 03:45:31 rpi4 volumio[1248]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Mar 24 03:45:31 rpi4 volumio[1248]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Mar 24 03:45:31 rpi4 volumio[1248]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 03:45:32 rpi4 sudo[7125]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-24 03:44' Mar 24 03:45:32 rpi4 sudo[7125]: 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="dc61260dec5515dafd2b634881860b4c46c919ff" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Mar 6 16:46:58 UTC 2026" VOLUMIO_VERSION="4.103" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="aa741395b8bfc648ff5d04e312f53d2c"