-- Logs begin at Wed 2026-03-25 17:41:37 GMT, end at Thu 2026-03-26 09:24:36 GMT. -- Mar 26 09:23:50 rivoplus volumio[3430]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 26 09:23:50 rivoplus volumio[3430]: info: Preload queue cleared Mar 26 09:23:51 rivoplus volumio[3430]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Aaron%20Davis/cfa96598-f090-4c88-b51a-dea01e81ac79.jpg' Mar 26 09:23:51 rivoplus volumio[3430]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Aaron%20Neville/1bc4fe06-35af-473d-b010-12de2a8a9c61.jpg' Mar 26 09:24:06 rivoplus volumio[3430]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Jeff%20Beck%20Feat.%20Imelda%20May/ec0e26db-1ad5-431a-b557-81eb7609988e.jpg' Mar 26 09:24:20 rivoplus volumio[3430]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 26 09:24:20 rivoplus volumio[3430]: info: Preload queue cleared Mar 26 09:24:20 rivoplus volumio[3430]: info: Preloading song: upnp/http://192.168.1.65:50001/ContentDirectory/control@27$28328$@28331 Mar 26 09:24:20 rivoplus volumio[3430]: info: Preloading song: upnp/http://192.168.1.65:50001/ContentDirectory/control@27$28328$@28333 Mar 26 09:24:20 rivoplus volumio[3430]: info: Preloading song: upnp/http://192.168.1.65:50001/ContentDirectory/control@27$28328$@28336 Mar 26 09:24:20 rivoplus volumio[3430]: info: Preloading song: upnp/http://192.168.1.65:50001/ContentDirectory/control@27$28328$@28329 Mar 26 09:24:20 rivoplus volumio[3430]: info: Preloading song: upnp/http://192.168.1.65:50001/ContentDirectory/control@27$28328$@28335 Mar 26 09:24:20 rivoplus volumio[3430]: info: Preloading song: upnp/http://192.168.1.65:50001/ContentDirectory/control@27$28328$@28330 Mar 26 09:24:20 rivoplus volumio[3430]: info: Preloading song: upnp/http://192.168.1.65:50001/ContentDirectory/control@27$28328$@28328 Mar 26 09:24:20 rivoplus volumio[3430]: info: Preloading song: upnp/http://192.168.1.65:50001/ContentDirectory/control@27$28328$@28334 Mar 26 09:24:20 rivoplus volumio[3430]: info: Preloading song: upnp/http://192.168.1.65:50001/ContentDirectory/control@27$28328$@28332 Mar 26 09:24:20 rivoplus volumio[3430]: info: Exploding uri upnp/http://192.168.1.65:50001/ContentDirectory/control@27$28328$@28331 in service upnp_browser Mar 26 09:24:20 rivoplus volumio[3430]: info: Exploding uri upnp/http://192.168.1.65:50001/ContentDirectory/control@27$28328$@28333 in service upnp_browser Mar 26 09:24:20 rivoplus volumio[3430]: info: Exploding uri upnp/http://192.168.1.65:50001/ContentDirectory/control@27$28328$@28336 in service upnp_browser Mar 26 09:24:20 rivoplus volumio[3430]: info: Exploding uri upnp/http://192.168.1.65:50001/ContentDirectory/control@27$28328$@28329 in service upnp_browser Mar 26 09:24:20 rivoplus volumio[3430]: info: Exploding uri upnp/http://192.168.1.65:50001/ContentDirectory/control@27$28328$@28335 in service upnp_browser Mar 26 09:24:20 rivoplus volumio[3430]: info: Exploding uri upnp/http://192.168.1.65:50001/ContentDirectory/control@27$28328$@28330 in service upnp_browser Mar 26 09:24:20 rivoplus volumio[3430]: info: Exploding uri upnp/http://192.168.1.65:50001/ContentDirectory/control@27$28328$@28328 in service upnp_browser Mar 26 09:24:20 rivoplus volumio[3430]: info: Exploding uri upnp/http://192.168.1.65:50001/ContentDirectory/control@27$28328$@28334 in service upnp_browser Mar 26 09:24:20 rivoplus volumio[3430]: info: Exploding uri upnp/http://192.168.1.65:50001/ContentDirectory/control@27$28328$@28332 in service upnp_browser Mar 26 09:24:24 rivoplus volumio[3430]: info: Preload queue cleared Mar 26 09:24:24 rivoplus volumio[3430]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 26 09:24:24 rivoplus volumio[3430]: info: CoreStateMachine::ClearQueue Mar 26 09:24:24 rivoplus volumio[3430]: info: CoreStateMachine::stop Mar 26 09:24:24 rivoplus volumio[3430]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 26 09:24:24 rivoplus volumio[3430]: info: CoreStateMachine::stPlaybackTimer Mar 26 09:24:24 rivoplus volumio[3430]: info: CoreStateMachine::updateTrackBlock Mar 26 09:24:24 rivoplus volumio[3430]: info: CorePlayQueue::getTrackBlock Mar 26 09:24:24 rivoplus volumio[3430]: info: CoreStateMachine::pushState Mar 26 09:24:24 rivoplus volumio[3430]: info: CorePlayQueue::getTrack 0 Mar 26 09:24:24 rivoplus volumio[3430]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 09:24:24 rivoplus volumio[3430]: info: CoreCommandRouter::volumioPushState Mar 26 09:24:24 rivoplus volumio[3430]: info: CoreCommandRouter::volumioGetState Mar 26 09:24:24 rivoplus volumio[3430]: info: CorePlayQueue::getTrack 0 Mar 26 09:24:24 rivoplus volumio[3430]: info: MRS: Pushing multiroomSync output update for this device Mar 26 09:24:24 rivoplus volumio[3430]: info: MRS: Pushing multiroomSync output Mar 26 09:24:24 rivoplus volumio[3430]: info: CoreStateMachine::serviceStop Mar 26 09:24:24 rivoplus volumio[3430]: info: CorePlayQueue::getTrack 0 Mar 26 09:24:24 rivoplus volumio[3430]: info: CoreCommandRouter::serviceStop Mar 26 09:24:24 rivoplus volumio[3430]: info: [1774517064767] ControllerUPNPBrowser::stop Mar 26 09:24:24 rivoplus volumio[3430]: verbose: ControllerMpd::sendMpdCommand stop Mar 26 09:24:24 rivoplus volumio[3430]: info: CorePlayQueue::clearPlayQueue Mar 26 09:24:24 rivoplus volumio[3430]: info: CorePlayQueue::saveQueue Mar 26 09:24:24 rivoplus volumio[3430]: info: CoreCommandRouter::volumioPushQueue Mar 26 09:24:24 rivoplus volumio[3430]: info: CoreStateMachine::addQueueItems Mar 26 09:24:24 rivoplus volumio[3430]: info: CorePlayQueue::addQueueItems Mar 26 09:24:24 rivoplus volumio[3430]: info: Preload queue cleared Mar 26 09:24:24 rivoplus volumio[3430]: info: Adding Item to queue: upnp/folder/http://192.168.1.65:50001/ContentDirectory/control@27$28328 Mar 26 09:24:24 rivoplus volumio[3430]: info: Exploding uri upnp/folder/http://192.168.1.65:50001/ContentDirectory/control@27$28328 in service upnp_browser Mar 26 09:24:24 rivoplus volumio5-onboarding[3944]: time=2026-03-26T09:24:24.775Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.245:60691,192.168.1.245:60798,00:00:00:00:00:00%07 @ 0x35346c0" state=STATUS_STOPPED positionMs=0 volume=100 Mar 26 09:24:24 rivoplus volumio5-onboarding[3944]: time=2026-03-26T09:24:24.777Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.245:60798 @ 0x3400e70" state=STATUS_STOPPED positionMs=0 volume=100 Mar 26 09:24:24 rivoplus volumio5-onboarding[3944]: time=2026-03-26T09:24:24.777Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.245:60691,192.168.1.245:60798,00:00:00:00:00:00%07 @ 0x35346c0" id=http://192.168.1.65:50002/m/NDLNA/29216.m4a title="101 Eastbound" Mar 26 09:24:24 rivoplus volumio5-onboarding[3944]: time=2026-03-26T09:24:24.778Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.245:60798 @ 0x3400e70" id=http://192.168.1.65:50002/m/NDLNA/29216.m4a title="101 Eastbound" Mar 26 09:24:24 rivoplus volumio[3430]: info: Mar 26 09:24:24 rivoplus volumio[3430]: ---------------------------- MPD announces state update: player Mar 26 09:24:24 rivoplus volumio[3430]: info: sendMpdCommand stop took 77 milliseconds Mar 26 09:24:24 rivoplus volumio[3430]: info: ControllerMpd::getState Mar 26 09:24:24 rivoplus volumio[3430]: verbose: ControllerMpd::sendMpdCommand status Mar 26 09:24:24 rivoplus volumio[3430]: info: sendMpdCommand status took 8 milliseconds Mar 26 09:24:24 rivoplus volumio[3430]: verbose: ControllerMpd::parseState Mar 26 09:24:24 rivoplus volumio[3430]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 26 09:24:24 rivoplus volumio[3430]: info: CoreCommandRouter::volumioPushQueue Mar 26 09:24:24 rivoplus volumio[3430]: info: CorePlayQueue::saveQueue Mar 26 09:24:24 rivoplus volumio[3430]: info: CoreStateMachine::updateTrackBlock Mar 26 09:24:24 rivoplus volumio[3430]: info: CorePlayQueue::getTrackBlock Mar 26 09:24:24 rivoplus volumio[3430]: info: CoreCommandRouter::volumioPlay Mar 26 09:24:24 rivoplus volumio[3430]: info: CoreStateMachine::play index 0 Mar 26 09:24:24 rivoplus volumio[3430]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 26 09:24:24 rivoplus volumio[3430]: info: CoreStateMachine::stop Mar 26 09:24:24 rivoplus volumio[3430]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 26 09:24:24 rivoplus volumio[3430]: info: CoreStateMachine::play index undefined Mar 26 09:24:24 rivoplus volumio[3430]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 26 09:24:24 rivoplus volumio[3430]: info: CorePlayQueue::getTrack 0 Mar 26 09:24:24 rivoplus volumio[3430]: info: CoreStateMachine::startPlaybackTimer Mar 26 09:24:24 rivoplus volumio[3430]: info: CorePlayQueue::getTrack 0 Mar 26 09:24:24 rivoplus volumio[3430]: info: [1774517064899] ControllerUPNPBrowser::clearAddPlayTrack Mar 26 09:24:24 rivoplus volumio[3430]: verbose: ControllerMpd::sendMpdCommand stop Mar 26 09:24:24 rivoplus volumio[3430]: info: sendMpdCommand playlistinfo took 49 milliseconds Mar 26 09:24:24 rivoplus volumio[3430]: info: sendMpdCommand stop took 7 milliseconds Mar 26 09:24:24 rivoplus volumio[3430]: verbose: ControllerMpd::parseTrackInfo Mar 26 09:24:24 rivoplus volumio[3430]: verbose: ControllerMpd::sendMpdCommand clear Mar 26 09:24:24 rivoplus volumio[3430]: info: ControllerMpd::pushState Mar 26 09:24:24 rivoplus volumio[3430]: info: CoreCommandRouter::servicePushState Mar 26 09:24:24 rivoplus volumio[3430]: info: CoreStateMachine::pushState Mar 26 09:24:24 rivoplus volumio[3430]: info: CorePlayQueue::getTrack 0 Mar 26 09:24:24 rivoplus volumio[3430]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 09:24:24 rivoplus volumio[3430]: info: CoreCommandRouter::volumioPushState Mar 26 09:24:24 rivoplus volumio[3430]: info: CoreCommandRouter::volumioGetState Mar 26 09:24:24 rivoplus volumio[3430]: info: CorePlayQueue::getTrack 0 Mar 26 09:24:24 rivoplus volumio[3430]: info: MRS: Pushing multiroomSync output update for this device Mar 26 09:24:24 rivoplus volumio[3430]: info: MRS: Pushing multiroomSync output Mar 26 09:24:24 rivoplus volumio[3430]: info: CorePlayQueue::getTrack 0 Mar 26 09:24:24 rivoplus volumio[3430]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"29216.m4a","artist":null,"album":null,"uri":"http://192.168.1.65:50002/m/NDLNA/29216.m4a","trackType":"m4a"} Mar 26 09:24:24 rivoplus volumio[3430]: verbose: CURRENT POSITION 0 Mar 26 09:24:24 rivoplus volumio[3430]: info: CoreStateMachine::syncState stateService stop Mar 26 09:24:24 rivoplus volumio[3430]: info: CoreStateMachine::syncState currentStatus stop Mar 26 09:24:24 rivoplus volumio[3430]: info: CoreStateMachine::pushState Mar 26 09:24:24 rivoplus volumio[3430]: info: CorePlayQueue::getTrack 0 Mar 26 09:24:24 rivoplus volumio[3430]: info: CoreCommandRouter::volumioPushState Mar 26 09:24:24 rivoplus volumio[3430]: info: CoreCommandRouter::volumioGetState Mar 26 09:24:24 rivoplus volumio[3430]: info: CorePlayQueue::getTrack 0 Mar 26 09:24:24 rivoplus volumio[3430]: info: MRS: Pushing multiroomSync output update for this device Mar 26 09:24:24 rivoplus volumio[3430]: info: MRS: Pushing multiroomSync output Mar 26 09:24:24 rivoplus volumio[3430]: info: No code Mar 26 09:24:24 rivoplus volumio[3430]: info: CoreStateMachine::pushState Mar 26 09:24:24 rivoplus volumio[3430]: info: CorePlayQueue::getTrack 0 Mar 26 09:24:24 rivoplus volumio[3430]: info: CoreCommandRouter::volumioPushState Mar 26 09:24:24 rivoplus volumio[3430]: info: CoreCommandRouter::volumioGetState Mar 26 09:24:24 rivoplus volumio[3430]: info: CorePlayQueue::getTrack 0 Mar 26 09:24:24 rivoplus volumio[3430]: info: MRS: Pushing multiroomSync output update for this device Mar 26 09:24:24 rivoplus volumio[3430]: info: MRS: Pushing multiroomSync output Mar 26 09:24:24 rivoplus volumio5-onboarding[3944]: time=2026-03-26T09:24:24.942Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.245:60691,192.168.1.245:60798,00:00:00:00:00:00%07 @ 0x35346c0" state=STATUS_STOPPED positionMs=0 volume=100 Mar 26 09:24:24 rivoplus volumio5-onboarding[3944]: time=2026-03-26T09:24:24.943Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.245:60798 @ 0x3400e70" state=STATUS_STOPPED positionMs=0 volume=100 Mar 26 09:24:24 rivoplus volumio5-onboarding[3944]: time=2026-03-26T09:24:24.943Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.245:60691,192.168.1.245:60798,00:00:00:00:00:00%07 @ 0x35346c0" id=http://192.168.1.65:50002/m/NDLNA/28331.flac title=Tenderly Mar 26 09:24:24 rivoplus volumio5-onboarding[3944]: time=2026-03-26T09:24:24.944Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.245:60798 @ 0x3400e70" id=http://192.168.1.65:50002/m/NDLNA/28331.flac title=Tenderly Mar 26 09:24:24 rivoplus volumio5-onboarding[3944]: time=2026-03-26T09:24:24.945Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.245:60691,192.168.1.245:60798,00:00:00:00:00:00%07 @ 0x35346c0" state=STATUS_STOPPED positionMs=0 volume=100 Mar 26 09:24:24 rivoplus volumio5-onboarding[3944]: time=2026-03-26T09:24:24.945Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.245:60798 @ 0x3400e70" state=STATUS_STOPPED positionMs=0 volume=100 Mar 26 09:24:24 rivoplus volumio5-onboarding[3944]: time=2026-03-26T09:24:24.945Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.245:60691,192.168.1.245:60798,00:00:00:00:00:00%07 @ 0x35346c0" state=STATUS_STOPPED positionMs=0 volume=100 Mar 26 09:24:24 rivoplus volumio5-onboarding[3944]: time=2026-03-26T09:24:24.946Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.245:60691,192.168.1.245:60798,00:00:00:00:00:00%07 @ 0x35346c0" id=http://192.168.1.65:50002/m/NDLNA/28331.flac title=Tenderly Mar 26 09:24:24 rivoplus volumio5-onboarding[3944]: time=2026-03-26T09:24:24.946Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.245:60798 @ 0x3400e70" state=STATUS_STOPPED positionMs=0 volume=100 Mar 26 09:24:24 rivoplus volumio5-onboarding[3944]: time=2026-03-26T09:24:24.946Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.245:60798 @ 0x3400e70" id=http://192.168.1.65:50002/m/NDLNA/28331.flac title=Tenderly Mar 26 09:24:24 rivoplus volumio5-onboarding[3944]: time=2026-03-26T09:24:24.946Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.245:60691,192.168.1.245:60798,00:00:00:00:00:00%07 @ 0x35346c0" id=http://192.168.1.65:50002/m/NDLNA/28331.flac title=Tenderly Mar 26 09:24:24 rivoplus volumio5-onboarding[3944]: time=2026-03-26T09:24:24.946Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.245:60798 @ 0x3400e70" id=http://192.168.1.65:50002/m/NDLNA/28331.flac title=Tenderly Mar 26 09:24:24 rivoplus volumio[3430]: info: ------------------------------ 118ms Mar 26 09:24:25 rivoplus volumio[3430]: info: MCU Signalled Playback Inactive Mar 26 09:24:25 rivoplus volumio[3430]: info: Mar 26 09:24:25 rivoplus volumio[3430]: ---------------------------- MPD announces system playlist update Mar 26 09:24:25 rivoplus volumio[3430]: info: Ignoring MPD Status Update Mar 26 09:24:25 rivoplus volumio[3430]: info: sendMpdCommand clear took 101 milliseconds Mar 26 09:24:25 rivoplus volumio[3430]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.65:50002/m/NDLNA/28331.flac" Mar 26 09:24:25 rivoplus volumio[3430]: error: updateQueue error: null Mar 26 09:24:25 rivoplus volumio[3430]: info: ------------------------------ 18ms Mar 26 09:24:25 rivoplus volumio[3430]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.65:50002/m/NDLNA/28331.flac" Mar 26 09:24:25 rivoplus volumio[3430]: info: Mar 26 09:24:25 rivoplus volumio[3430]: ---------------------------- MPD announces system playlist update Mar 26 09:24:25 rivoplus volumio[3430]: info: Ignoring MPD Status Update Mar 26 09:24:25 rivoplus volumio[3430]: info: sendMpdCommand add "http://192.168.1.65:50002/m/NDLNA/28331.flac" took 2 milliseconds Mar 26 09:24:25 rivoplus volumio[3430]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 26 09:24:25 rivoplus volumio[3430]: verbose: ControllerMpd::sendMpdCommand play Mar 26 09:24:25 rivoplus volumio[3430]: info: ------------------------------ 6ms Mar 26 09:24:25 rivoplus volumio[3430]: info: sendMpdCommand play took 5 milliseconds Mar 26 09:24:25 rivoplus volumio[3430]: info: Mar 26 09:24:25 rivoplus volumio[3430]: ---------------------------- MPD announces state update: player Mar 26 09:24:25 rivoplus volumio[3430]: info: ControllerMpd::getState Mar 26 09:24:25 rivoplus volumio[3430]: verbose: ControllerMpd::sendMpdCommand status Mar 26 09:24:25 rivoplus volumio[3430]: info: Mar 26 09:24:25 rivoplus volumio[3430]: ---------------------------- MPD announces state update: player Mar 26 09:24:25 rivoplus volumio[3430]: info: sendMpdCommand status took 96 milliseconds Mar 26 09:24:25 rivoplus volumio[3430]: info: ControllerMpd::getState Mar 26 09:24:25 rivoplus volumio[3430]: verbose: ControllerMpd::sendMpdCommand status Mar 26 09:24:25 rivoplus volumio[3430]: verbose: ControllerMpd::parseState Mar 26 09:24:25 rivoplus volumio[3430]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 26 09:24:25 rivoplus volumio[3430]: info: sendMpdCommand status took 5 milliseconds Mar 26 09:24:25 rivoplus volumio[3430]: info: sendMpdCommand playlistinfo took 4 milliseconds Mar 26 09:24:25 rivoplus volumio[3430]: verbose: ControllerMpd::parseState Mar 26 09:24:25 rivoplus volumio[3430]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 26 09:24:25 rivoplus volumio[3430]: verbose: ControllerMpd::parseTrackInfo Mar 26 09:24:25 rivoplus volumio[3430]: info: ControllerMpd::pushState Mar 26 09:24:25 rivoplus volumio[3430]: info: CoreCommandRouter::servicePushState Mar 26 09:24:25 rivoplus volumio[3430]: info: CorePlayQueue::getTrack 0 Mar 26 09:24:25 rivoplus volumio[3430]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":245,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"28331.flac","artist":null,"album":null,"uri":"http://192.168.1.65:50002/m/NDLNA/28331.flac","trackType":"flac"} Mar 26 09:24:25 rivoplus volumio[3430]: verbose: CURRENT POSITION 0 Mar 26 09:24:25 rivoplus volumio[3430]: info: CoreStateMachine::syncState stateService play Mar 26 09:24:25 rivoplus volumio[3430]: info: CoreStateMachine::syncState currentStatus stop Mar 26 09:24:25 rivoplus volumio[3430]: info: ------------------------------ 115ms Mar 26 09:24:25 rivoplus volumio[3430]: info: sendMpdCommand playlistinfo took 12 milliseconds Mar 26 09:24:25 rivoplus volumio[3430]: verbose: ControllerMpd::parseTrackInfo Mar 26 09:24:25 rivoplus volumio[3430]: info: ControllerMpd::pushState Mar 26 09:24:25 rivoplus volumio[3430]: info: CoreCommandRouter::servicePushState Mar 26 09:24:25 rivoplus volumio[3430]: info: CorePlayQueue::getTrack 0 Mar 26 09:24:25 rivoplus volumio[3430]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":245,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"28331.flac","artist":null,"album":null,"uri":"http://192.168.1.65:50002/m/NDLNA/28331.flac","trackType":"flac"} Mar 26 09:24:25 rivoplus volumio[3430]: verbose: CURRENT POSITION 0 Mar 26 09:24:25 rivoplus volumio[3430]: info: CoreStateMachine::syncState stateService play Mar 26 09:24:25 rivoplus volumio[3430]: info: CoreStateMachine::syncState currentStatus play Mar 26 09:24:25 rivoplus volumio[3430]: info: Received an update from plugin. extracting info from payload Mar 26 09:24:25 rivoplus volumio[3430]: info: CoreStateMachine::pushState Mar 26 09:24:25 rivoplus volumio[3430]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 09:24:25 rivoplus volumio[3430]: info: CoreCommandRouter::volumioPushState Mar 26 09:24:25 rivoplus volumio[3430]: info: CoreCommandRouter::volumioGetState Mar 26 09:24:25 rivoplus volumio[3430]: info: MRS: Pushing multiroomSync output update for this device Mar 26 09:24:25 rivoplus volumio[3430]: info: MRS: Pushing multiroomSync output Mar 26 09:24:25 rivoplus volumio[3430]: info: CoreStateMachine::pushState Mar 26 09:24:25 rivoplus volumio[3430]: info: CoreCommandRouter::volumioPushState Mar 26 09:24:25 rivoplus volumio[3430]: info: CoreCommandRouter::volumioGetState Mar 26 09:24:25 rivoplus volumio[3430]: info: MRS: Pushing multiroomSync output update for this device Mar 26 09:24:25 rivoplus volumio[3430]: info: MRS: Pushing multiroomSync output Mar 26 09:24:25 rivoplus volumio5-onboarding[3944]: time=2026-03-26T09:24:25.608Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.245:60691,192.168.1.245:60798,00:00:00:00:00:00%07 @ 0x35346c0" state=STATUS_PLAYING positionMs=0 volume=100 Mar 26 09:24:25 rivoplus volumio5-onboarding[3944]: time=2026-03-26T09:24:25.609Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.245:60798 @ 0x3400e70" state=STATUS_PLAYING positionMs=0 volume=100 Mar 26 09:24:25 rivoplus volumio5-onboarding[3944]: time=2026-03-26T09:24:25.609Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.245:60691,192.168.1.245:60798,00:00:00:00:00:00%07 @ 0x35346c0" id=http://192.168.1.65:50002/m/NDLNA/28331.flac title=28331.flac Mar 26 09:24:25 rivoplus volumio5-onboarding[3944]: time=2026-03-26T09:24:25.609Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.245:60691,192.168.1.245:60798,00:00:00:00:00:00%07 @ 0x35346c0" state=STATUS_PLAYING positionMs=0 volume=100 Mar 26 09:24:25 rivoplus volumio5-onboarding[3944]: time=2026-03-26T09:24:25.609Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.245:60798 @ 0x3400e70" id=http://192.168.1.65:50002/m/NDLNA/28331.flac title=28331.flac Mar 26 09:24:25 rivoplus volumio5-onboarding[3944]: time=2026-03-26T09:24:25.610Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.245:60798 @ 0x3400e70" state=STATUS_PLAYING positionMs=0 volume=100 Mar 26 09:24:25 rivoplus volumio5-onboarding[3944]: time=2026-03-26T09:24:25.611Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.245:60691,192.168.1.245:60798,00:00:00:00:00:00%07 @ 0x35346c0" id=http://192.168.1.65:50002/m/NDLNA/28331.flac title=28331.flac Mar 26 09:24:25 rivoplus volumio5-onboarding[3944]: time=2026-03-26T09:24:25.612Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.245:60798 @ 0x3400e70" id=http://192.168.1.65:50002/m/NDLNA/28331.flac title=28331.flac Mar 26 09:24:25 rivoplus volumio[3430]: info: ------------------------------ 99ms Mar 26 09:24:25 rivoplus volumio[3430]: info: Mar 26 09:24:25 rivoplus volumio[3430]: ---------------------------- MPD announces system playlist update Mar 26 09:24:25 rivoplus volumio[3430]: info: Ignoring MPD Status Update Mar 26 09:24:25 rivoplus volumio[3430]: info: Mar 26 09:24:25 rivoplus volumio[3430]: ---------------------------- MPD announces state update: player Mar 26 09:24:25 rivoplus volumio[3430]: info: ControllerMpd::getState Mar 26 09:24:25 rivoplus volumio[3430]: verbose: ControllerMpd::sendMpdCommand status Mar 26 09:24:25 rivoplus volumio[3430]: info: Signalling Playback active due to playback status change Mar 26 09:24:25 rivoplus volumio[3430]: info: ------------------------------ 33ms Mar 26 09:24:25 rivoplus volumio[3430]: info: sendMpdCommand status took 32 milliseconds Mar 26 09:24:25 rivoplus volumio[3430]: verbose: ControllerMpd::parseState Mar 26 09:24:25 rivoplus volumio[3430]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 26 09:24:25 rivoplus volumio[3430]: info: sendMpdCommand playlistinfo took 19 milliseconds Mar 26 09:24:25 rivoplus volumio[3430]: verbose: ControllerMpd::parseTrackInfo Mar 26 09:24:25 rivoplus volumio[3430]: info: ControllerMpd::pushState Mar 26 09:24:25 rivoplus volumio[3430]: info: CoreCommandRouter::servicePushState Mar 26 09:24:25 rivoplus volumio[3430]: info: CorePlayQueue::getTrack 0 Mar 26 09:24:25 rivoplus volumio[3430]: verbose: STATE SERVICE {"status":"play","position":0,"seek":850,"duration":245,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2731 Kbps","isStreaming":false,"title":"Tenderly","artist":"Art Lande","album":"While She Sleeps","uri":"http://192.168.1.65:50002/m/NDLNA/28331.flac","trackType":"flac"} Mar 26 09:24:25 rivoplus volumio[3430]: verbose: CURRENT POSITION 0 Mar 26 09:24:25 rivoplus volumio[3430]: info: CoreStateMachine::syncState stateService play Mar 26 09:24:25 rivoplus volumio[3430]: info: CoreStateMachine::syncState currentStatus play Mar 26 09:24:25 rivoplus volumio[3430]: info: Received an update from plugin. extracting info from payload Mar 26 09:24:25 rivoplus volumio[3430]: info: CoreStateMachine::pushState Mar 26 09:24:25 rivoplus volumio[3430]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 09:24:25 rivoplus volumio[3430]: info: CoreCommandRouter::volumioPushState Mar 26 09:24:25 rivoplus volumio[3430]: info: CoreCommandRouter::volumioGetState Mar 26 09:24:25 rivoplus volumio[3430]: info: MRS: Pushing multiroomSync output update for this device Mar 26 09:24:25 rivoplus volumio[3430]: info: MRS: Pushing multiroomSync output Mar 26 09:24:25 rivoplus volumio[3430]: info: CoreStateMachine::pushState Mar 26 09:24:25 rivoplus volumio[3430]: info: CoreCommandRouter::volumioPushState Mar 26 09:24:25 rivoplus volumio[3430]: info: CoreCommandRouter::volumioGetState Mar 26 09:24:25 rivoplus volumio[3430]: info: MRS: Pushing multiroomSync output update for this device Mar 26 09:24:25 rivoplus volumio[3430]: info: MRS: Pushing multiroomSync output Mar 26 09:24:25 rivoplus volumio5-onboarding[3944]: time=2026-03-26T09:24:25.744Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.245:60691,192.168.1.245:60798,00:00:00:00:00:00%07 @ 0x35346c0" state=STATUS_PLAYING positionMs=256 volume=100 Mar 26 09:24:25 rivoplus volumio5-onboarding[3944]: time=2026-03-26T09:24:25.744Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.245:60798 @ 0x3400e70" state=STATUS_PLAYING positionMs=256 volume=100 Mar 26 09:24:25 rivoplus volumio5-onboarding[3944]: time=2026-03-26T09:24:25.745Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.245:60691,192.168.1.245:60798,00:00:00:00:00:00%07 @ 0x35346c0" id=http://192.168.1.65:50002/m/NDLNA/28331.flac title=Tenderly Mar 26 09:24:25 rivoplus volumio5-onboarding[3944]: time=2026-03-26T09:24:25.745Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.245:60798 @ 0x3400e70" id=http://192.168.1.65:50002/m/NDLNA/28331.flac title=Tenderly Mar 26 09:24:25 rivoplus volumio5-onboarding[3944]: time=2026-03-26T09:24:25.747Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.245:60691,192.168.1.245:60798,00:00:00:00:00:00%07 @ 0x35346c0" state=STATUS_PLAYING positionMs=256 volume=100 Mar 26 09:24:25 rivoplus volumio5-onboarding[3944]: time=2026-03-26T09:24:25.747Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.245:60798 @ 0x3400e70" state=STATUS_PLAYING positionMs=256 volume=100 Mar 26 09:24:25 rivoplus volumio5-onboarding[3944]: time=2026-03-26T09:24:25.748Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.245:60691,192.168.1.245:60798,00:00:00:00:00:00%07 @ 0x35346c0" id=http://192.168.1.65:50002/m/NDLNA/28331.flac title=Tenderly Mar 26 09:24:25 rivoplus volumio5-onboarding[3944]: time=2026-03-26T09:24:25.748Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.245:60798 @ 0x3400e70" id=http://192.168.1.65:50002/m/NDLNA/28331.flac title=Tenderly Mar 26 09:24:25 rivoplus volumio[3430]: info: ------------------------------ 111ms Mar 26 09:24:25 rivoplus volumio[3430]: info: CoreCommandRouter::volumioGetQueue Mar 26 09:24:25 rivoplus volumio[3430]: info: CoreStateMachine::getQueue Mar 26 09:24:25 rivoplus volumio[3430]: info: CorePlayQueue::getQueue Mar 26 09:24:25 rivoplus volumio[3430]: info: CoreCommandRouter::volumioGetQueue Mar 26 09:24:25 rivoplus volumio[3430]: info: CoreStateMachine::getQueue Mar 26 09:24:25 rivoplus volumio[3430]: info: CorePlayQueue::getQueue Mar 26 09:24:25 rivoplus volumio[3430]: info: MCU Signalled Playback Active Mar 26 09:24:35 rivoplus volumio[3430]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 26 09:24:35 rivoplus volumio[3430]: TypeError: Cannot read property 'slice' of null Mar 26 09:24:35 rivoplus volumio[3430]: at download (/volumio/app/plugins/miscellanea/albumart/albumart.js:718:41) Mar 26 09:24:35 rivoplus volumio[3430]: at ClientRequest. (/volumio/app/plugins/miscellanea/albumart/albumart.js:728:7) Mar 26 09:24:35 rivoplus volumio[3430]: at Object.onceWrapper (events.js:520:26) Mar 26 09:24:35 rivoplus volumio[3430]: at ClientRequest.emit (events.js:400:28) Mar 26 09:24:35 rivoplus volumio[3430]: at HTTPParser.parserOnIncomingClient [as onIncoming] (_http_client.js:647:27) Mar 26 09:24:35 rivoplus volumio[3430]: at HTTPParser.parserOnHeadersComplete (_http_common.js:127:17) Mar 26 09:24:35 rivoplus volumio[3430]: at TLSSocket.socketOnData (_http_client.js:515:22) Mar 26 09:24:35 rivoplus volumio[3430]: at TLSSocket.emit (events.js:400:28) Mar 26 09:24:35 rivoplus volumio[3430]: at addChunk (internal/streams/readable.js:293:12) Mar 26 09:24:35 rivoplus volumio[3430]: at readableAddChunk (internal/streams/readable.js:267:9) Mar 26 09:24:35 rivoplus volumio[3430]: at TLSSocket.Readable.push (internal/streams/readable.js:206:10) Mar 26 09:24:35 rivoplus volumio[3430]: at TLSWrap.onStreamRead (internal/stream_base_commons.js:188:23) Mar 26 09:24:35 rivoplus volumio[3430]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 26 09:24:36 rivoplus sudo[14441]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-03-26 09:23 Mar 26 09:24:36 rivoplus sudo[14441]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="e9612ec5034fb2e958508aaefbca2962fd6f6654" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="464fc672d77d3df6ee72b331d36cdf1fa936e1ec" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivoplus" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 27 Feb 2026 11:19:27 AM CET" VOLUMIO_VERSION="3.912" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo Plus" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo Plus" VOLUMIO_HASH="a7285124ffc88c43265bb2db03526f6a"