-- Logs begin at Wed 2026-05-27 15:28:41 CEST, end at Wed 2026-05-27 17:27:35 CEST. -- May 27 17:26:04 rivo-black dbus-daemon[2851]: [system] The maximum number of active connections for UID 1000 has been reached (max_connections_per_user=256) May 27 17:26:04 rivo-black volumio[3139]: info: Discovery: Restarting Browsing May 27 17:26:06 rivo-black volumiologrotate[2852]: ls: cannot access '/var/log/samba/log.wb-RIVO': No such file or directory May 27 17:26:06 rivo-black volumiologrotate[2852]: ls: cannot access 'BLACK': No such file or directory May 27 17:26:09 rivo-black dbus-daemon[2851]: [system] The maximum number of active connections for UID 1000 has been reached (max_connections_per_user=256) May 27 17:26:09 rivo-black volumio[3139]: info: Discovery: Restarting Browsing May 27 17:26:14 rivo-black dbus-daemon[2851]: [system] The maximum number of active connections for UID 1000 has been reached (max_connections_per_user=256) May 27 17:26:14 rivo-black volumio[3139]: info: Discovery: Restarting Browsing May 27 17:26:19 rivo-black dbus-daemon[2851]: [system] The maximum number of active connections for UID 1000 has been reached (max_connections_per_user=256) May 27 17:26:19 rivo-black volumio[3139]: info: Discovery: Restarting Browsing May 27 17:26:24 rivo-black dbus-daemon[2851]: [system] The maximum number of active connections for UID 1000 has been reached (max_connections_per_user=256) May 27 17:26:24 rivo-black volumio[3139]: info: Discovery: Restarting Browsing May 27 17:26:29 rivo-black dbus-daemon[2851]: [system] The maximum number of active connections for UID 1000 has been reached (max_connections_per_user=256) May 27 17:26:29 rivo-black volumio[3139]: info: Discovery: Restarting Browsing May 27 17:26:30 rivo-black volumio[3139]: info: May 27 17:26:30 rivo-black volumio[3139]: ---------------------------- MPD announces state update: player May 27 17:26:30 rivo-black volumio[3139]: info: ControllerMpd::getState May 27 17:26:30 rivo-black volumio[3139]: verbose: ControllerMpd::sendMpdCommand status May 27 17:26:30 rivo-black volumio[3139]: info: May 27 17:26:30 rivo-black volumio[3139]: ---------------------------- MPD announces state update: player May 27 17:26:30 rivo-black volumio[3139]: info: ControllerMpd::getState May 27 17:26:30 rivo-black volumio[3139]: verbose: ControllerMpd::sendMpdCommand status May 27 17:26:30 rivo-black volumio[3139]: info: sendMpdCommand status took 6 milliseconds May 27 17:26:30 rivo-black volumio[3139]: verbose: ControllerMpd::parseState May 27 17:26:30 rivo-black volumio[3139]: info: ControllerMpd::pushState May 27 17:26:30 rivo-black volumio[3139]: info: CoreCommandRouter::servicePushState May 27 17:26:30 rivo-black volumio[3139]: info: CoreStateMachine::pushState May 27 17:26:30 rivo-black volumio[3139]: info: CoreCommandRouter::volumioPushState May 27 17:26:30 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetState May 27 17:26:30 rivo-black volumio[3139]: info: CorePlayQueue::getTrack 0 May 27 17:26:30 rivo-black volumio[3139]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 27 17:26:30 rivo-black volumio[3139]: verbose: CURRENT POSITION 0 May 27 17:26:30 rivo-black volumio[3139]: info: CoreStateMachine::syncState stateService stop May 27 17:26:30 rivo-black volumio[3139]: info: CoreStateMachine::syncState currentStatus play May 27 17:26:30 rivo-black volumio[3139]: info: CoreCommandRouter::volumioPushState May 27 17:26:30 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetState May 27 17:26:30 rivo-black volumio[3139]: info: CoreStateMachine::stPlaybackTimer May 27 17:26:30 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:26:30.759+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.6:51626,00:00:00:00:00:00%02 @ 0x18005d0" state=STATUS_STOPPED positionMs=0 volume=54 May 27 17:26:30 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:26:30.761+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.6:51626,00:00:00:00:00:00%02 @ 0x18005d0" state=STATUS_PLAYING positionMs=0 volume=54 May 27 17:26:30 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:26:30.761+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.6:51626,00:00:00:00:00:00%02 @ 0x18005d0" id= title= May 27 17:26:30 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:26:30.763+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.6:51626,00:00:00:00:00:00%02 @ 0x18005d0" id=http://192.168.1.5:49152/audirvana/audio_f_1.wav title="Threshold Meditation" May 27 17:26:30 rivo-black volumio[3139]: info: ------------------------------ 28ms May 27 17:26:30 rivo-black volumio[3139]: info: sendMpdCommand status took 27 milliseconds May 27 17:26:30 rivo-black volumio[3139]: verbose: ControllerMpd::parseState May 27 17:26:30 rivo-black volumio[3139]: info: ControllerMpd::pushState May 27 17:26:30 rivo-black volumio[3139]: info: CoreCommandRouter::servicePushState May 27 17:26:30 rivo-black volumio[3139]: info: CoreStateMachine::pushState May 27 17:26:30 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 17:26:30 rivo-black volumio[3139]: info: CoreCommandRouter::volumioPushState May 27 17:26:30 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetState May 27 17:26:30 rivo-black volumio[3139]: info: CorePlayQueue::getTrack 0 May 27 17:26:30 rivo-black volumio[3139]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 27 17:26:30 rivo-black volumio[3139]: verbose: CURRENT POSITION 0 May 27 17:26:30 rivo-black volumio[3139]: info: CoreStateMachine::syncState stateService stop May 27 17:26:30 rivo-black volumio[3139]: info: CoreStateMachine::syncState currentStatus stop May 27 17:26:30 rivo-black volumio[3139]: info: CoreStateMachine::pushState May 27 17:26:30 rivo-black volumio[3139]: info: CoreCommandRouter::volumioPushState May 27 17:26:30 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetState May 27 17:26:30 rivo-black volumio[3139]: info: No code May 27 17:26:30 rivo-black volumio[3139]: info: CoreStateMachine::pushState May 27 17:26:30 rivo-black volumio[3139]: info: CoreCommandRouter::volumioPushState May 27 17:26:30 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetState May 27 17:26:30 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:26:30.793+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.6:51626,00:00:00:00:00:00%02 @ 0x18005d0" state=STATUS_STOPPED positionMs= volume=54 May 27 17:26:30 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:26:30.793+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.6:51626,00:00:00:00:00:00%02 @ 0x18005d0" id=http://192.168.1.5:49152/audirvana/audio_f_1.wav title="Threshold Meditation" May 27 17:26:30 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:26:30.794+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.6:51626,00:00:00:00:00:00%02 @ 0x18005d0" state=STATUS_STOPPED positionMs= volume=54 May 27 17:26:30 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:26:30.795+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.6:51626,00:00:00:00:00:00%02 @ 0x18005d0" state=STATUS_STOPPED positionMs= volume=54 May 27 17:26:30 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:26:30.795+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.6:51626,00:00:00:00:00:00%02 @ 0x18005d0" id=http://192.168.1.5:49152/audirvana/audio_f_1.wav title="Threshold Meditation" May 27 17:26:30 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:26:30.796+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.6:51626,00:00:00:00:00:00%02 @ 0x18005d0" id=http://192.168.1.5:49152/audirvana/audio_f_1.wav title="Threshold Meditation" May 27 17:26:30 rivo-black volumio[3139]: info: ------------------------------ 64ms May 27 17:26:30 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetQueue May 27 17:26:30 rivo-black volumio[3139]: info: CoreStateMachine::getQueue May 27 17:26:30 rivo-black volumio[3139]: info: CorePlayQueue::getQueue May 27 17:26:30 rivo-black volumio[3139]: info: Signalling Playback active due to playback status change May 27 17:26:30 rivo-black volumio[3139]: info: Updating RAAT Signal Path May 27 17:26:30 rivo-black volumio[3139]: info: Updating RAAT Signal Path May 27 17:26:30 rivo-black volumio[3139]: info: Updating RAAT Signal Path May 27 17:26:30 rivo-black volumio[3139]: info: Updating RAAT Signal Path May 27 17:26:30 rivo-black volumio[3139]: info: Updating RAAT Signal Path May 27 17:26:30 rivo-black volumio[3139]: info: MCU Signalled Playback Inactive May 27 17:26:32 rivo-black volumio[3139]: info: Executing endpoint metavolumio May 27 17:26:32 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 27 17:26:32 rivo-black volumio[3139]: info: Executing endpoint metavolumio May 27 17:26:32 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 27 17:26:32 rivo-black volumio[3139]: info: Executing endpoint metavolumio May 27 17:26:32 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 27 17:26:33 rivo-black volumio[3139]: info: Executing endpoint metavolumio May 27 17:26:33 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 27 17:26:33 rivo-black volumio[3139]: info: Executing endpoint metavolumio May 27 17:26:33 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 27 17:26:33 rivo-black volumio[3139]: info: Executing endpoint metavolumio May 27 17:26:33 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 27 17:26:34 rivo-black dbus-daemon[2851]: [system] The maximum number of active connections for UID 1000 has been reached (max_connections_per_user=256) May 27 17:26:34 rivo-black volumio[3139]: info: Discovery: Restarting Browsing May 27 17:26:34 rivo-black volumio[3139]: error: Upnp client error: Error: This socket has been ended by the other party May 27 17:26:36 rivo-black volumio[3139]: info: May 27 17:26:36 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:36 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:36 rivo-black volumio[3139]: info: May 27 17:26:36 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:36 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:36 rivo-black volumio[3139]: info: Starting UPNP Playback May 27 17:26:36 rivo-black volumio[3139]: info: Preparing playback through UPNP May 27 17:26:36 rivo-black volumio[3139]: info: Consume mode May 27 17:26:36 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetState May 27 17:26:36 rivo-black volumio[3139]: info: CoreStateMachine::setConsumeUpdateService mpd May 27 17:26:36 rivo-black volumio[3139]: info: ------------------------------ 5ms May 27 17:26:36 rivo-black volumio[3139]: info: ------------------------------ 4ms May 27 17:26:37 rivo-black volumio[3139]: info: May 27 17:26:37 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:37 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:37 rivo-black volumio[3139]: info: May 27 17:26:37 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:37 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:37 rivo-black volumio[3139]: info: ------------------------------ 3ms May 27 17:26:37 rivo-black volumio[3139]: info: ------------------------------ 2ms May 27 17:26:37 rivo-black volumio[3139]: info: May 27 17:26:37 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:37 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:37 rivo-black volumio[3139]: info: May 27 17:26:37 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:37 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:37 rivo-black volumio[3139]: info: May 27 17:26:37 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:37 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:37 rivo-black volumio[3139]: info: ------------------------------ 4ms May 27 17:26:37 rivo-black volumio[3139]: info: ------------------------------ 3ms May 27 17:26:37 rivo-black volumio[3139]: info: ------------------------------ 3ms May 27 17:26:37 rivo-black volumio[3139]: info: May 27 17:26:37 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:37 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:37 rivo-black volumio[3139]: info: May 27 17:26:37 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:37 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:37 rivo-black volumio[3139]: info: ------------------------------ 3ms May 27 17:26:37 rivo-black volumio[3139]: info: ------------------------------ 2ms May 27 17:26:37 rivo-black volumio[3139]: info: May 27 17:26:37 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:37 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:37 rivo-black volumio[3139]: info: May 27 17:26:37 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:37 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:37 rivo-black volumio[3139]: info: ------------------------------ 3ms May 27 17:26:37 rivo-black volumio[3139]: info: ------------------------------ 2ms May 27 17:26:37 rivo-black volumio[3139]: info: May 27 17:26:37 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:37 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:37 rivo-black volumio[3139]: info: May 27 17:26:37 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:37 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:37 rivo-black volumio[3139]: info: ------------------------------ 3ms May 27 17:26:37 rivo-black volumio[3139]: info: ------------------------------ 2ms May 27 17:26:37 rivo-black volumio[3139]: info: May 27 17:26:37 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:37 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:37 rivo-black volumio[3139]: info: ------------------------------ 1ms May 27 17:26:39 rivo-black dbus-daemon[2851]: [system] The maximum number of active connections for UID 1000 has been reached (max_connections_per_user=256) May 27 17:26:39 rivo-black volumio[3139]: info: Discovery: Restarting Browsing May 27 17:26:40 rivo-black volumio[3139]: info: Clearing queue after UPNP request May 27 17:26:41 rivo-black volumio[3139]: info: CoreStateMachine::ClearQueue May 27 17:26:41 rivo-black volumio[3139]: info: CoreStateMachine::stop May 27 17:26:41 rivo-black volumio[3139]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 17:26:41 rivo-black volumio[3139]: info: CorePlayQueue::clearPlayQueue May 27 17:26:41 rivo-black volumio[3139]: info: CorePlayQueue::saveQueue May 27 17:26:41 rivo-black volumio[3139]: info: CoreCommandRouter::volumioPushState May 27 17:26:41 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetState May 27 17:26:41 rivo-black volumio[3139]: info: CorePlayQueue::getTrack 0 May 27 17:26:41 rivo-black volumio[3139]: info: CoreCommandRouter::volumioPushQueue May 27 17:26:41 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:26:41.310+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.6:51626,00:00:00:00:00:00%02 @ 0x18005d0" state=STATUS_STOPPED positionMs=0 volume=54 May 27 17:26:41 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:26:41.311+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.6:51626,00:00:00:00:00:00%02 @ 0x18005d0" id= title= May 27 17:26:41 rivo-black volumio[3139]: info: Updating RAAT Signal Path May 27 17:26:41 rivo-black volumio[3139]: info: May 27 17:26:41 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:41 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:41 rivo-black volumio[3139]: info: May 27 17:26:41 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:41 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:41 rivo-black volumio[3139]: error: updateQueue error: null May 27 17:26:41 rivo-black volumio[3139]: error: updateQueue error: null May 27 17:26:41 rivo-black volumio[3139]: info: ------------------------------ 5ms May 27 17:26:41 rivo-black volumio[3139]: info: ------------------------------ 3ms May 27 17:26:41 rivo-black volumio[3139]: info: Starting UPNP Playback May 27 17:26:41 rivo-black volumio[3139]: info: Preparing playback through UPNP May 27 17:26:41 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetState May 27 17:26:41 rivo-black volumio[3139]: info: CorePlayQueue::getTrack 0 May 27 17:26:41 rivo-black volumio[3139]: info: CoreStateMachine::setConsumeUpdateService mpd May 27 17:26:41 rivo-black volumio[3139]: info: May 27 17:26:41 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:41 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:41 rivo-black volumio[3139]: info: May 27 17:26:41 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:41 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:41 rivo-black volumio[3139]: info: ------------------------------ 3ms May 27 17:26:41 rivo-black volumio[3139]: info: ------------------------------ 2ms May 27 17:26:41 rivo-black volumio[3139]: info: May 27 17:26:41 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:41 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:41 rivo-black volumio[3139]: info: May 27 17:26:41 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:41 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:41 rivo-black volumio[3139]: info: May 27 17:26:41 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:41 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:41 rivo-black volumio[3139]: info: ------------------------------ 4ms May 27 17:26:41 rivo-black volumio[3139]: info: ------------------------------ 3ms May 27 17:26:41 rivo-black volumio[3139]: info: ------------------------------ 2ms May 27 17:26:41 rivo-black volumio[3139]: info: May 27 17:26:41 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:41 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:41 rivo-black volumio[3139]: info: May 27 17:26:41 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:41 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:41 rivo-black volumio[3139]: info: ------------------------------ 2ms May 27 17:26:41 rivo-black volumio[3139]: info: ------------------------------ 2ms May 27 17:26:41 rivo-black volumio[3139]: info: May 27 17:26:41 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:41 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:41 rivo-black volumio[3139]: info: May 27 17:26:41 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:41 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:41 rivo-black volumio[3139]: info: ------------------------------ 2ms May 27 17:26:41 rivo-black volumio[3139]: info: ------------------------------ 2ms May 27 17:26:41 rivo-black volumio[3139]: info: May 27 17:26:41 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:41 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:41 rivo-black volumio[3139]: info: May 27 17:26:41 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:41 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:41 rivo-black volumio[3139]: info: ------------------------------ 3ms May 27 17:26:41 rivo-black volumio[3139]: info: ------------------------------ 3ms May 27 17:26:41 rivo-black volumio[3139]: info: May 27 17:26:41 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:41 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:41 rivo-black volumio[3139]: info: ------------------------------ 2ms May 27 17:26:41 rivo-black volumio[3139]: info: May 27 17:26:41 rivo-black volumio[3139]: ---------------------------- MPD announces state update: player May 27 17:26:41 rivo-black volumio[3139]: info: ControllerMpd::getState May 27 17:26:41 rivo-black volumio[3139]: verbose: ControllerMpd::sendMpdCommand status May 27 17:26:41 rivo-black volumio[3139]: info: May 27 17:26:41 rivo-black volumio[3139]: ---------------------------- MPD announces state update: player May 27 17:26:41 rivo-black volumio[3139]: info: ControllerMpd::getState May 27 17:26:41 rivo-black volumio[3139]: verbose: ControllerMpd::sendMpdCommand status May 27 17:26:41 rivo-black volumio[3139]: info: May 27 17:26:41 rivo-black volumio[3139]: ---------------------------- MPD announces state update: player May 27 17:26:41 rivo-black volumio[3139]: info: sendMpdCommand status took 17 milliseconds May 27 17:26:41 rivo-black volumio[3139]: info: ControllerMpd::getState May 27 17:26:41 rivo-black volumio[3139]: verbose: ControllerMpd::sendMpdCommand status May 27 17:26:41 rivo-black volumio[3139]: info: sendMpdCommand status took 16 milliseconds May 27 17:26:41 rivo-black volumio[3139]: verbose: ControllerMpd::parseState May 27 17:26:41 rivo-black volumio[3139]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 17:26:41 rivo-black volumio[3139]: verbose: ControllerMpd::parseState May 27 17:26:41 rivo-black volumio[3139]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 17:26:41 rivo-black volumio[3139]: info: May 27 17:26:41 rivo-black volumio[3139]: ---------------------------- MPD announces state update: player May 27 17:26:41 rivo-black volumio[3139]: info: ControllerMpd::getState May 27 17:26:41 rivo-black volumio[3139]: verbose: ControllerMpd::sendMpdCommand status May 27 17:26:41 rivo-black volumio[3139]: info: sendMpdCommand status took 10 milliseconds May 27 17:26:41 rivo-black volumio[3139]: info: sendMpdCommand playlistinfo took 9 milliseconds May 27 17:26:41 rivo-black volumio[3139]: info: sendMpdCommand playlistinfo took 8 milliseconds May 27 17:26:41 rivo-black volumio[3139]: verbose: ControllerMpd::parseState May 27 17:26:41 rivo-black volumio[3139]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 17:26:41 rivo-black volumio[3139]: verbose: ControllerMpd::parseTrackInfo May 27 17:26:41 rivo-black volumio[3139]: info: ControllerMpd::pushState May 27 17:26:41 rivo-black volumio[3139]: info: CoreCommandRouter::servicePushState May 27 17:26:41 rivo-black volumio[3139]: verbose: In UPNP mode May 27 17:26:41 rivo-black volumio[3139]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":787,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Threshold Meditation","artist":"Steve Roach","album":"AS IT IS","uri":"http://192.168.1.5:49152/audirvana/audio_f_3.wav","trackType":"wav"} May 27 17:26:41 rivo-black volumio[3139]: verbose: CURRENT POSITION 0 May 27 17:26:41 rivo-black volumio[3139]: info: CoreStateMachine::syncState stateService play May 27 17:26:41 rivo-black volumio[3139]: info: CoreStateMachine::syncState currentStatus stop May 27 17:26:41 rivo-black volumio[3139]: info: ControllerMpd::pushState May 27 17:26:41 rivo-black volumio[3139]: info: CoreCommandRouter::servicePushState May 27 17:26:41 rivo-black volumio[3139]: verbose: In UPNP mode May 27 17:26:41 rivo-black volumio[3139]: verbose: STATE SERVICE {"status":"play","position":0,"seek":732,"duration":787,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Threshold Meditation","artist":"Steve Roach","album":"AS IT IS","uri":"http://192.168.1.5:49152/audirvana/audio_f_3.wav","trackType":"wav"} May 27 17:26:41 rivo-black volumio[3139]: verbose: CURRENT POSITION 0 May 27 17:26:41 rivo-black volumio[3139]: info: CoreStateMachine::syncState stateService play May 27 17:26:41 rivo-black volumio[3139]: info: CoreStateMachine::syncState currentStatus play May 27 17:26:41 rivo-black volumio[3139]: info: Received an update from plugin. extracting info from payload May 27 17:26:41 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 27 17:26:41 rivo-black volumio[3139]: info: CoreStateMachine::pushState May 27 17:26:41 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 17:26:41 rivo-black volumio[3139]: info: CoreCommandRouter::volumioPushState May 27 17:26:41 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetState May 27 17:26:41 rivo-black volumio[3139]: info: CoreStateMachine::pushState May 27 17:26:41 rivo-black volumio[3139]: info: CoreCommandRouter::volumioPushState May 27 17:26:41 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetState May 27 17:26:41 rivo-black volumio[3139]: info: ------------------------------ 51ms May 27 17:26:41 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:26:41.950+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.6:51626,00:00:00:00:00:00%02 @ 0x18005d0" state=STATUS_PLAYING positionMs=0 volume=54 May 27 17:26:41 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:26:41.950+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.6:51626,00:00:00:00:00:00%02 @ 0x18005d0" state=STATUS_PLAYING positionMs=0 volume=54 May 27 17:26:41 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:26:41.951+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.6:51626,00:00:00:00:00:00%02 @ 0x18005d0" id=http://192.168.1.5:49152/audirvana/audio_f_3.wav title="Threshold Meditation" May 27 17:26:41 rivo-black volumio[3139]: info: ------------------------------ 59ms May 27 17:26:41 rivo-black volumio[3139]: info: sendMpdCommand status took 38 milliseconds May 27 17:26:41 rivo-black volumio[3139]: info: sendMpdCommand playlistinfo took 34 milliseconds May 27 17:26:41 rivo-black volumio[3139]: verbose: ControllerMpd::parseState May 27 17:26:41 rivo-black volumio[3139]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 17:26:41 rivo-black volumio[3139]: verbose: ControllerMpd::parseTrackInfo May 27 17:26:41 rivo-black volumio[3139]: info: ControllerMpd::pushState May 27 17:26:41 rivo-black volumio[3139]: info: CoreCommandRouter::servicePushState May 27 17:26:41 rivo-black volumio[3139]: verbose: In UPNP mode May 27 17:26:41 rivo-black volumio[3139]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1212,"duration":787,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Threshold Meditation","artist":"Steve Roach","album":"AS IT IS","uri":"http://192.168.1.5:49152/audirvana/audio_f_3.wav","trackType":"wav"} May 27 17:26:41 rivo-black volumio[3139]: verbose: CURRENT POSITION 0 May 27 17:26:41 rivo-black volumio[3139]: info: CoreStateMachine::syncState stateService play May 27 17:26:41 rivo-black volumio[3139]: info: CoreStateMachine::syncState currentStatus play May 27 17:26:41 rivo-black volumio[3139]: info: Received an update from plugin. extracting info from payload May 27 17:26:41 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 27 17:26:41 rivo-black volumio[3139]: info: CoreStateMachine::pushState May 27 17:26:41 rivo-black volumio[3139]: info: CoreCommandRouter::volumioPushState May 27 17:26:41 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetState May 27 17:26:41 rivo-black volumio[3139]: info: CoreStateMachine::pushState May 27 17:26:41 rivo-black volumio[3139]: info: CoreCommandRouter::volumioPushState May 27 17:26:41 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetState May 27 17:26:41 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:26:41.985+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.6:51626,00:00:00:00:00:00%02 @ 0x18005d0" state=STATUS_PLAYING positionMs=0 volume=54 May 27 17:26:41 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:26:41.985+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.6:51626,00:00:00:00:00:00%02 @ 0x18005d0" id=http://192.168.1.5:49152/audirvana/audio_f_3.wav title="Threshold Meditation" May 27 17:26:41 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:26:41.987+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.6:51626,00:00:00:00:00:00%02 @ 0x18005d0" state=STATUS_PLAYING positionMs=0 volume=54 May 27 17:26:41 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:26:41.987+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.6:51626,00:00:00:00:00:00%02 @ 0x18005d0" id=http://192.168.1.5:49152/audirvana/audio_f_3.wav title="Threshold Meditation" May 27 17:26:41 rivo-black volumio[3139]: info: ------------------------------ 80ms May 27 17:26:42 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetQueue May 27 17:26:42 rivo-black volumio[3139]: info: CoreStateMachine::getQueue May 27 17:26:42 rivo-black volumio[3139]: info: CorePlayQueue::getQueue May 27 17:26:42 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetQueue May 27 17:26:42 rivo-black volumio[3139]: info: CoreStateMachine::getQueue May 27 17:26:42 rivo-black volumio[3139]: info: CorePlayQueue::getQueue May 27 17:26:42 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetQueue May 27 17:26:42 rivo-black volumio[3139]: info: CoreStateMachine::getQueue May 27 17:26:42 rivo-black volumio[3139]: info: CorePlayQueue::getQueue May 27 17:26:42 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetQueue May 27 17:26:42 rivo-black volumio[3139]: info: CoreStateMachine::getQueue May 27 17:26:42 rivo-black volumio[3139]: info: CorePlayQueue::getQueue May 27 17:26:42 rivo-black volumio[3139]: info: Signalling Playback active due to playback status change May 27 17:26:42 rivo-black volumio[3139]: info: Signalling Playback active due to playback status change May 27 17:26:42 rivo-black volumio[3139]: info: Updating RAAT Signal Path May 27 17:26:42 rivo-black volumio[3139]: info: Updating RAAT Signal Path May 27 17:26:42 rivo-black volumio[3139]: info: sendMpdCommand playlistinfo took 81 milliseconds May 27 17:26:42 rivo-black volumio[3139]: verbose: ControllerMpd::parseTrackInfo May 27 17:26:42 rivo-black volumio[3139]: info: ControllerMpd::pushState May 27 17:26:42 rivo-black volumio[3139]: info: CoreCommandRouter::servicePushState May 27 17:26:42 rivo-black volumio[3139]: verbose: In UPNP mode May 27 17:26:42 rivo-black volumio[3139]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1212,"duration":787,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Threshold Meditation","artist":"Steve Roach","album":"AS IT IS","uri":"http://192.168.1.5:49152/audirvana/audio_f_3.wav","trackType":"wav"} May 27 17:26:42 rivo-black volumio[3139]: verbose: CURRENT POSITION 0 May 27 17:26:42 rivo-black volumio[3139]: info: CoreStateMachine::syncState stateService play May 27 17:26:42 rivo-black volumio[3139]: info: CoreStateMachine::syncState currentStatus play May 27 17:26:42 rivo-black volumio[3139]: info: Received an update from plugin. extracting info from payload May 27 17:26:42 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 27 17:26:42 rivo-black volumio[3139]: info: CoreStateMachine::pushState May 27 17:26:42 rivo-black volumio[3139]: info: CoreCommandRouter::volumioPushState May 27 17:26:42 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetState May 27 17:26:42 rivo-black volumio[3139]: info: CoreStateMachine::pushState May 27 17:26:42 rivo-black volumio[3139]: info: CoreCommandRouter::volumioPushState May 27 17:26:42 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetState May 27 17:26:42 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:26:42.064+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.6:51626,00:00:00:00:00:00%02 @ 0x18005d0" state=STATUS_PLAYING positionMs=0 volume=54 May 27 17:26:42 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:26:42.065+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.6:51626,00:00:00:00:00:00%02 @ 0x18005d0" id=http://192.168.1.5:49152/audirvana/audio_f_3.wav title="Threshold Meditation" May 27 17:26:42 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:26:42.066+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.6:51626,00:00:00:00:00:00%02 @ 0x18005d0" state=STATUS_PLAYING positionMs=0 volume=54 May 27 17:26:42 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:26:42.066+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.6:51626,00:00:00:00:00:00%02 @ 0x18005d0" id=http://192.168.1.5:49152/audirvana/audio_f_3.wav title="Threshold Meditation" May 27 17:26:42 rivo-black volumio[3139]: info: ------------------------------ 154ms May 27 17:26:42 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetQueue May 27 17:26:42 rivo-black volumio[3139]: info: CoreStateMachine::getQueue May 27 17:26:42 rivo-black volumio[3139]: info: CorePlayQueue::getQueue May 27 17:26:42 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetQueue May 27 17:26:42 rivo-black volumio[3139]: info: CoreStateMachine::getQueue May 27 17:26:42 rivo-black volumio[3139]: info: CorePlayQueue::getQueue May 27 17:26:42 rivo-black volumio[3139]: info: Signalling Playback active due to playback status change May 27 17:26:42 rivo-black volumio[3139]: info: Signalling Playback active due to playback status change May 27 17:26:42 rivo-black volumio[3139]: info: Updating RAAT Signal Path May 27 17:26:42 rivo-black volumio[3139]: info: Updating RAAT Signal Path May 27 17:26:42 rivo-black volumio[3139]: info: MCU Signalled Playback Active May 27 17:26:42 rivo-black volumio[3139]: info: Starting UPNP Playback May 27 17:26:42 rivo-black volumio[3139]: info: Preparing playback through UPNP May 27 17:26:42 rivo-black volumio[3139]: info: Consume mode May 27 17:26:42 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetState May 27 17:26:42 rivo-black volumio[3139]: info: CoreStateMachine::setConsumeUpdateService mpd May 27 17:26:42 rivo-black volumio[3139]: info: May 27 17:26:42 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:42 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:42 rivo-black volumio[3139]: info: May 27 17:26:42 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:42 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:42 rivo-black volumio[3139]: info: ------------------------------ 3ms May 27 17:26:42 rivo-black volumio[3139]: info: ------------------------------ 2ms May 27 17:26:42 rivo-black volumio[3139]: info: May 27 17:26:42 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:42 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:42 rivo-black volumio[3139]: info: May 27 17:26:42 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:42 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:42 rivo-black volumio[3139]: info: ------------------------------ 8ms May 27 17:26:42 rivo-black volumio[3139]: info: May 27 17:26:42 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:42 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:42 rivo-black volumio[3139]: info: ------------------------------ 6ms May 27 17:26:42 rivo-black volumio[3139]: info: May 27 17:26:42 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:42 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:42 rivo-black volumio[3139]: info: ------------------------------ 4ms May 27 17:26:42 rivo-black volumio[3139]: info: ------------------------------ 3ms May 27 17:26:42 rivo-black volumio[3139]: info: May 27 17:26:42 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:42 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:42 rivo-black volumio[3139]: info: May 27 17:26:42 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:42 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:42 rivo-black volumio[3139]: info: ------------------------------ 4ms May 27 17:26:42 rivo-black volumio[3139]: info: ------------------------------ 3ms May 27 17:26:42 rivo-black volumio[3139]: info: May 27 17:26:42 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:42 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:42 rivo-black volumio[3139]: info: May 27 17:26:42 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:42 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:42 rivo-black volumio[3139]: info: ------------------------------ 3ms May 27 17:26:42 rivo-black volumio[3139]: info: ------------------------------ 3ms May 27 17:26:42 rivo-black volumio[3139]: info: May 27 17:26:42 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:42 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:42 rivo-black volumio[3139]: info: May 27 17:26:42 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:42 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:42 rivo-black volumio[3139]: info: ------------------------------ 4ms May 27 17:26:42 rivo-black volumio[3139]: info: ------------------------------ 2ms May 27 17:26:42 rivo-black volumio[3139]: info: May 27 17:26:42 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:42 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:42 rivo-black volumio[3139]: info: May 27 17:26:42 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:42 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:42 rivo-black volumio[3139]: info: ------------------------------ 3ms May 27 17:26:42 rivo-black volumio[3139]: info: ------------------------------ 3ms May 27 17:26:42 rivo-black volumio[3139]: info: Starting UPNP Playback May 27 17:26:42 rivo-black volumio[3139]: info: Preparing playback through UPNP May 27 17:26:42 rivo-black volumio[3139]: info: Consume mode May 27 17:26:42 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetState May 27 17:26:42 rivo-black volumio[3139]: info: CoreStateMachine::setConsumeUpdateService mpd May 27 17:26:43 rivo-black volumio[3139]: info: May 27 17:26:43 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:43 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:43 rivo-black volumio[3139]: info: May 27 17:26:43 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:43 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:43 rivo-black volumio[3139]: info: May 27 17:26:43 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:43 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:43 rivo-black volumio[3139]: info: ------------------------------ 7ms May 27 17:26:43 rivo-black volumio[3139]: info: ------------------------------ 5ms May 27 17:26:43 rivo-black volumio[3139]: info: May 27 17:26:43 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:43 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:43 rivo-black volumio[3139]: info: ------------------------------ 4ms May 27 17:26:43 rivo-black volumio[3139]: info: ------------------------------ 2ms May 27 17:26:43 rivo-black volumio[3139]: info: May 27 17:26:43 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:43 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:43 rivo-black volumio[3139]: info: May 27 17:26:43 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:43 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:43 rivo-black volumio[3139]: info: May 27 17:26:43 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:43 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:43 rivo-black volumio[3139]: info: ------------------------------ 4ms May 27 17:26:43 rivo-black volumio[3139]: info: ------------------------------ 2ms May 27 17:26:43 rivo-black volumio[3139]: info: May 27 17:26:43 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:43 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:43 rivo-black volumio[3139]: info: May 27 17:26:43 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:43 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:43 rivo-black volumio[3139]: info: ------------------------------ 3ms May 27 17:26:43 rivo-black volumio[3139]: info: ------------------------------ 2ms May 27 17:26:43 rivo-black volumio[3139]: info: May 27 17:26:43 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:43 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:43 rivo-black volumio[3139]: info: May 27 17:26:43 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:43 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:43 rivo-black volumio[3139]: info: ------------------------------ 3ms May 27 17:26:43 rivo-black volumio[3139]: info: ------------------------------ 3ms May 27 17:26:43 rivo-black volumio[3139]: info: May 27 17:26:43 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:43 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:43 rivo-black volumio[3139]: info: ------------------------------ 2ms May 27 17:26:43 rivo-black volumio[3139]: info: May 27 17:26:43 rivo-black volumio[3139]: ---------------------------- MPD announces state update: player May 27 17:26:43 rivo-black volumio[3139]: info: ControllerMpd::getState May 27 17:26:43 rivo-black volumio[3139]: verbose: ControllerMpd::sendMpdCommand status May 27 17:26:43 rivo-black volumio[3139]: info: May 27 17:26:43 rivo-black volumio[3139]: ---------------------------- MPD announces state update: player May 27 17:26:43 rivo-black volumio[3139]: info: ControllerMpd::getState May 27 17:26:43 rivo-black volumio[3139]: verbose: ControllerMpd::sendMpdCommand status May 27 17:26:43 rivo-black volumio[3139]: info: sendMpdCommand status took 2 milliseconds May 27 17:26:43 rivo-black volumio[3139]: verbose: ControllerMpd::parseState May 27 17:26:43 rivo-black volumio[3139]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 17:26:43 rivo-black volumio[3139]: info: sendMpdCommand status took 4 milliseconds May 27 17:26:43 rivo-black volumio[3139]: info: sendMpdCommand playlistinfo took 2 milliseconds May 27 17:26:43 rivo-black volumio[3139]: verbose: ControllerMpd::parseState May 27 17:26:43 rivo-black volumio[3139]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 17:26:43 rivo-black volumio[3139]: verbose: ControllerMpd::parseTrackInfo May 27 17:26:43 rivo-black volumio[3139]: info: ControllerMpd::pushState May 27 17:26:43 rivo-black volumio[3139]: info: CoreCommandRouter::servicePushState May 27 17:26:43 rivo-black volumio[3139]: verbose: In UPNP mode May 27 17:26:43 rivo-black volumio[3139]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":2837,"duration":787,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Threshold Meditation","artist":"Steve Roach","album":"AS IT IS","uri":"http://192.168.1.5:49152/audirvana/audio_f_3.wav","trackType":"wav"} May 27 17:26:43 rivo-black volumio[3139]: verbose: CURRENT POSITION 0 May 27 17:26:43 rivo-black volumio[3139]: info: CoreStateMachine::syncState stateService pause May 27 17:26:43 rivo-black volumio[3139]: info: CoreStateMachine::syncState currentStatus play May 27 17:26:43 rivo-black volumio[3139]: info: CoreStateMachine::pushState May 27 17:26:43 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 17:26:43 rivo-black volumio[3139]: info: CoreCommandRouter::volumioPushState May 27 17:26:43 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetState May 27 17:26:43 rivo-black volumio[3139]: info: CoreStateMachine::stPlaybackTimer May 27 17:26:43 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:26:43.462+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.6:51626,00:00:00:00:00:00%02 @ 0x18005d0" state=STATUS_PAUSED positionMs=0 volume=54 May 27 17:26:43 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:26:43.463+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.6:51626,00:00:00:00:00:00%02 @ 0x18005d0" id=http://192.168.1.5:49152/audirvana/audio_f_3.wav title="Threshold Meditation" May 27 17:26:43 rivo-black volumio[3139]: info: ------------------------------ 21ms May 27 17:26:43 rivo-black volumio[3139]: info: sendMpdCommand playlistinfo took 16 milliseconds May 27 17:26:43 rivo-black volumio[3139]: verbose: ControllerMpd::parseTrackInfo May 27 17:26:43 rivo-black volumio[3139]: info: ControllerMpd::pushState May 27 17:26:43 rivo-black volumio[3139]: info: CoreCommandRouter::servicePushState May 27 17:26:43 rivo-black volumio[3139]: verbose: In UPNP mode May 27 17:26:43 rivo-black volumio[3139]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":2837,"duration":787,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Threshold Meditation","artist":"Steve Roach","album":"AS IT IS","uri":"http://192.168.1.5:49152/audirvana/audio_f_3.wav","trackType":"wav"} May 27 17:26:43 rivo-black volumio[3139]: verbose: CURRENT POSITION 0 May 27 17:26:43 rivo-black volumio[3139]: info: CoreStateMachine::syncState stateService pause May 27 17:26:43 rivo-black volumio[3139]: info: CoreStateMachine::syncState currentStatus play May 27 17:26:43 rivo-black volumio[3139]: info: CoreStateMachine::pushState May 27 17:26:43 rivo-black volumio[3139]: info: CoreCommandRouter::volumioPushState May 27 17:26:43 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetState May 27 17:26:43 rivo-black volumio[3139]: info: CoreStateMachine::stPlaybackTimer May 27 17:26:43 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:26:43.485+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.6:51626,00:00:00:00:00:00%02 @ 0x18005d0" state=STATUS_PAUSED positionMs=0 volume=54 May 27 17:26:43 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:26:43.485+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.6:51626,00:00:00:00:00:00%02 @ 0x18005d0" id=http://192.168.1.5:49152/audirvana/audio_f_3.wav title="Threshold Meditation" May 27 17:26:43 rivo-black volumio[3139]: info: ------------------------------ 44ms May 27 17:26:43 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetQueue May 27 17:26:43 rivo-black volumio[3139]: info: CoreStateMachine::getQueue May 27 17:26:43 rivo-black volumio[3139]: info: CorePlayQueue::getQueue May 27 17:26:43 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetQueue May 27 17:26:43 rivo-black volumio[3139]: info: CoreStateMachine::getQueue May 27 17:26:43 rivo-black volumio[3139]: info: CorePlayQueue::getQueue May 27 17:26:43 rivo-black volumio[3139]: info: Updating RAAT Signal Path May 27 17:26:43 rivo-black volumio[3139]: info: MCU Signalled Playback Inactive May 27 17:26:43 rivo-black volumio[3139]: info: Executing endpoint metavolumio May 27 17:26:43 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 27 17:26:43 rivo-black volumio[3139]: info: Executing endpoint metavolumio May 27 17:26:43 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 27 17:26:44 rivo-black volumio[3139]: info: Executing endpoint metavolumio May 27 17:26:44 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 27 17:26:44 rivo-black volumio[3139]: info: Executing endpoint metavolumio May 27 17:26:44 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 27 17:26:44 rivo-black volumio[3139]: info: Executing endpoint metavolumio May 27 17:26:44 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 27 17:26:44 rivo-black volumio[3139]: info: Executing endpoint metavolumio May 27 17:26:44 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 27 17:26:44 rivo-black dbus-daemon[2851]: [system] The maximum number of active connections for UID 1000 has been reached (max_connections_per_user=256) May 27 17:26:44 rivo-black volumio[3139]: info: Discovery: Restarting Browsing May 27 17:26:49 rivo-black dbus-daemon[2851]: [system] The maximum number of active connections for UID 1000 has been reached (max_connections_per_user=256) May 27 17:26:49 rivo-black volumio[3139]: info: Discovery: Restarting Browsing May 27 17:26:54 rivo-black dbus-daemon[2851]: [system] The maximum number of active connections for UID 1000 has been reached (max_connections_per_user=256) May 27 17:26:54 rivo-black volumio[3139]: info: Discovery: Restarting Browsing May 27 17:26:58 rivo-black volumio[3139]: info: May 27 17:26:58 rivo-black volumio[3139]: ---------------------------- MPD announces state update: player May 27 17:26:58 rivo-black volumio[3139]: info: ControllerMpd::getState May 27 17:26:58 rivo-black volumio[3139]: verbose: ControllerMpd::sendMpdCommand status May 27 17:26:58 rivo-black volumio[3139]: info: May 27 17:26:58 rivo-black volumio[3139]: ---------------------------- MPD announces state update: player May 27 17:26:58 rivo-black volumio[3139]: info: ControllerMpd::getState May 27 17:26:58 rivo-black volumio[3139]: verbose: ControllerMpd::sendMpdCommand status May 27 17:26:58 rivo-black volumio[3139]: info: sendMpdCommand status took 2 milliseconds May 27 17:26:58 rivo-black volumio[3139]: info: sendMpdCommand status took 6 milliseconds May 27 17:26:58 rivo-black volumio[3139]: verbose: ControllerMpd::parseState May 27 17:26:58 rivo-black volumio[3139]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 17:26:58 rivo-black volumio[3139]: verbose: ControllerMpd::parseState May 27 17:26:58 rivo-black volumio[3139]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 17:26:58 rivo-black volumio[3139]: info: sendMpdCommand playlistinfo took 3 milliseconds May 27 17:26:58 rivo-black volumio[3139]: verbose: ControllerMpd::parseTrackInfo May 27 17:26:58 rivo-black volumio[3139]: info: ControllerMpd::pushState May 27 17:26:58 rivo-black volumio[3139]: info: CoreCommandRouter::servicePushState May 27 17:26:58 rivo-black volumio[3139]: verbose: In UPNP mode May 27 17:26:58 rivo-black volumio[3139]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":787,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Threshold Meditation","artist":"Steve Roach","album":"AS IT IS","uri":"http://192.168.1.5:49152/audirvana/audio_f_3.wav","trackType":"wav"} May 27 17:26:58 rivo-black volumio[3139]: verbose: CURRENT POSITION 0 May 27 17:26:58 rivo-black volumio[3139]: info: CoreStateMachine::syncState stateService pause May 27 17:26:58 rivo-black volumio[3139]: info: CoreStateMachine::syncState currentStatus play May 27 17:26:58 rivo-black volumio[3139]: info: CoreStateMachine::pushState May 27 17:26:58 rivo-black volumio[3139]: info: CoreCommandRouter::volumioPushState May 27 17:26:58 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetState May 27 17:26:58 rivo-black volumio[3139]: info: CoreStateMachine::stPlaybackTimer May 27 17:26:58 rivo-black volumio[3139]: info: ControllerMpd::pushState May 27 17:26:58 rivo-black volumio[3139]: info: CoreCommandRouter::servicePushState May 27 17:26:58 rivo-black volumio[3139]: verbose: In UPNP mode May 27 17:26:58 rivo-black volumio[3139]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":787,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Threshold Meditation","artist":"Steve Roach","album":"AS IT IS","uri":"http://192.168.1.5:49152/audirvana/audio_f_3.wav","trackType":"wav"} May 27 17:26:58 rivo-black volumio[3139]: verbose: CURRENT POSITION 0 May 27 17:26:58 rivo-black volumio[3139]: info: CoreStateMachine::syncState stateService pause May 27 17:26:58 rivo-black volumio[3139]: info: CoreStateMachine::syncState currentStatus play May 27 17:26:58 rivo-black volumio[3139]: info: CoreStateMachine::pushState May 27 17:26:58 rivo-black volumio[3139]: info: CoreCommandRouter::volumioPushState May 27 17:26:58 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetState May 27 17:26:58 rivo-black volumio[3139]: info: CoreStateMachine::stPlaybackTimer May 27 17:26:58 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:26:58.142+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.6:51626,00:00:00:00:00:00%02 @ 0x18005d0" state=STATUS_PAUSED positionMs=0 volume=54 May 27 17:26:58 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:26:58.143+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.6:51626,00:00:00:00:00:00%02 @ 0x18005d0" id=http://192.168.1.5:49152/audirvana/audio_f_3.wav title="Threshold Meditation" May 27 17:26:58 rivo-black volumio[3139]: info: ------------------------------ 40ms May 27 17:26:58 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetQueue May 27 17:26:58 rivo-black volumio[3139]: info: CoreStateMachine::getQueue May 27 17:26:58 rivo-black volumio[3139]: info: CorePlayQueue::getQueue May 27 17:26:58 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetQueue May 27 17:26:58 rivo-black volumio[3139]: info: CoreStateMachine::getQueue May 27 17:26:58 rivo-black volumio[3139]: info: CorePlayQueue::getQueue May 27 17:26:58 rivo-black volumio[3139]: info: Updating RAAT Signal Path May 27 17:26:58 rivo-black volumio[3139]: info: Updating RAAT Signal Path May 27 17:26:58 rivo-black volumio[3139]: info: May 27 17:26:58 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:58 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:58 rivo-black volumio[3139]: info: May 27 17:26:58 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:58 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:58 rivo-black volumio[3139]: info: ------------------------------ 4ms May 27 17:26:58 rivo-black volumio[3139]: info: ------------------------------ 2ms May 27 17:26:58 rivo-black volumio[3139]: info: Starting UPNP Playback May 27 17:26:58 rivo-black volumio[3139]: info: Preparing playback through UPNP May 27 17:26:58 rivo-black volumio[3139]: info: Consume mode May 27 17:26:58 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetState May 27 17:26:58 rivo-black volumio[3139]: info: CoreStateMachine::setConsumeUpdateService mpd May 27 17:26:59 rivo-black volumio[3139]: info: May 27 17:26:59 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:59 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:59 rivo-black volumio[3139]: info: May 27 17:26:59 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:59 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:59 rivo-black volumio[3139]: info: ------------------------------ 4ms May 27 17:26:59 rivo-black volumio[3139]: info: ------------------------------ 2ms May 27 17:26:59 rivo-black volumio[3139]: info: May 27 17:26:59 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:59 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:59 rivo-black volumio[3139]: info: May 27 17:26:59 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:59 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:59 rivo-black volumio[3139]: info: ------------------------------ 9ms May 27 17:26:59 rivo-black volumio[3139]: info: ------------------------------ 7ms May 27 17:26:59 rivo-black volumio[3139]: info: May 27 17:26:59 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:59 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:59 rivo-black volumio[3139]: info: May 27 17:26:59 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:59 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:59 rivo-black volumio[3139]: info: ------------------------------ 4ms May 27 17:26:59 rivo-black volumio[3139]: info: ------------------------------ 3ms May 27 17:26:59 rivo-black volumio[3139]: info: May 27 17:26:59 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:59 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:59 rivo-black volumio[3139]: info: May 27 17:26:59 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:59 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:59 rivo-black volumio[3139]: info: ------------------------------ 4ms May 27 17:26:59 rivo-black volumio[3139]: info: ------------------------------ 3ms May 27 17:26:59 rivo-black volumio[3139]: info: May 27 17:26:59 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:59 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:59 rivo-black volumio[3139]: info: May 27 17:26:59 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:59 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:59 rivo-black volumio[3139]: info: ------------------------------ 3ms May 27 17:26:59 rivo-black volumio[3139]: info: ------------------------------ 2ms May 27 17:26:59 rivo-black volumio[3139]: info: May 27 17:26:59 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:59 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:59 rivo-black volumio[3139]: info: May 27 17:26:59 rivo-black volumio[3139]: ---------------------------- MPD announces system playlist update May 27 17:26:59 rivo-black volumio[3139]: info: Ignoring MPD Status Update May 27 17:26:59 rivo-black volumio[3139]: info: ------------------------------ 3ms May 27 17:26:59 rivo-black volumio[3139]: info: ------------------------------ 2ms May 27 17:26:59 rivo-black dbus-daemon[2851]: [system] The maximum number of active connections for UID 1000 has been reached (max_connections_per_user=256) May 27 17:26:59 rivo-black volumio[3139]: info: Discovery: Restarting Browsing May 27 17:27:04 rivo-black dbus-daemon[2851]: [system] The maximum number of active connections for UID 1000 has been reached (max_connections_per_user=256) May 27 17:27:04 rivo-black volumio[3139]: info: Discovery: Restarting Browsing May 27 17:27:07 rivo-black volumiologrotate[2852]: ls: cannot access '/var/log/samba/log.wb-RIVO': No such file or directory May 27 17:27:07 rivo-black volumiologrotate[2852]: ls: cannot access 'BLACK': No such file or directory May 27 17:27:09 rivo-black dbus-daemon[2851]: [system] The maximum number of active connections for UID 1000 has been reached (max_connections_per_user=256) May 27 17:27:09 rivo-black volumio[3139]: info: Discovery: Restarting Browsing May 27 17:27:14 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:27:14.104+02:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.1.4:62783 May 27 17:27:14 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:27:14.140+02:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.1.4:62783 @ 0x1c9c0c0" latency=203.389007ms platform=PLATFORM_IOS version=5.260413.0 May 27 17:27:14 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:27:14.141+02:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.1.4:62783 @ 0x1c9c0c0" latency=204.526228ms timeout=10s May 27 17:27:14 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:27:14.141+02:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.1.4:62783 @ 0x1c9c0c0" May 27 17:27:14 rivo-black volumio[3139]: info: Received Get System Info May 27 17:27:14 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 27 17:27:14 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 27 17:27:14 rivo-black volumio[3139]: info: Discovery: Getting this device information May 27 17:27:14 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetState May 27 17:27:14 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 27 17:27:14 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:27:14.147+02:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.1.4:62783 @ 0x1c9c0c0" name="Rivo Black" May 27 17:27:14 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:27:14.150+02:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.1.4:62783 @ 0x1c9c0c0" language=it May 27 17:27:14 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone May 27 17:27:14 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:27:14.154+02:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.1.4:62783 @ 0x1c9c0c0" timezone=Europe/Rome May 27 17:27:14 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:27:14.156+02:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.1.4:62783 @ 0x1c9c0c0" available=true connected=true macAddress=02:00:00:30:18:01 ip4Address=192.168.1.3/24 ip6Address= May 27 17:27:14 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:27:14.158+02:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.1.4:62783 @ 0x1c9c0c0" available=true connected=false macAddress= ip4Address= ip6Address= ssid= May 27 17:27:14 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:27:14.159+02:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.1.4:62783 @ 0x1c9c0c0" setupComplete=true May 27 17:27:14 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices May 27 17:27:14 rivo-black volumio[3139]: No protocol specified May 27 17:27:14 rivo-black volumio[3139]: xcb_connection_has_error() returned true May 27 17:27:14 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions May 27 17:27:14 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 27 17:27:14 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 27 17:27:14 rivo-black dbus-daemon[2851]: [system] The maximum number of active connections for UID 1000 has been reached (max_connections_per_user=256) May 27 17:27:14 rivo-black volumio[3139]: info: Discovery: Restarting Browsing May 27 17:27:14 rivo-black volumio[3139]: No protocol specified May 27 17:27:14 rivo-black volumio[3139]: xcb_connection_has_error() returned true May 27 17:27:14 rivo-black volumio[3139]: amixer -c 5 info | grep "Volumio Preciso" May 27 17:27:14 rivo-black volumio[3139]: No protocol specified May 27 17:27:14 rivo-black volumio[3139]: xcb_connection_has_error() returned true May 27 17:27:14 rivo-black volumio[3139]: Card hw:5 'Preciso'/'Volumio srl Volumio Preciso at usb-xhci-hcd.0.auto-1.4.2, high speed' May 27 17:27:14 rivo-black volumio[3139]: No protocol specified May 27 17:27:14 rivo-black volumio[3139]: xcb_connection_has_error() returned true May 27 17:27:14 rivo-black volumio[3139]: amixer -c 5 info | grep "Volumio Preciso" May 27 17:27:14 rivo-black volumio[3139]: No protocol specified May 27 17:27:14 rivo-black volumio[3139]: xcb_connection_has_error() returned true May 27 17:27:14 rivo-black volumio[3139]: Card hw:5 'Preciso'/'Volumio srl Volumio Preciso at usb-xhci-hcd.0.auto-1.4.2, high speed' May 27 17:27:14 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:27:14.673+02:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.1.4:62783 @ 0x1c9c0c0" selectedOutputId=5 May 27 17:27:14 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 27 17:27:14 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 27 17:27:14 rivo-black volumio[3139]: info: Discovery: Getting this device information May 27 17:27:14 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetState May 27 17:27:14 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 27 17:27:14 rivo-black volumio[3139]: info: Received Get System Info May 27 17:27:14 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 27 17:27:14 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 27 17:27:14 rivo-black volumio[3139]: info: Discovery: Getting this device information May 27 17:27:14 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetState May 27 17:27:14 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 27 17:27:14 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:27:14.705+02:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.1.4:62783 @ 0x1c9c0c0" currentVersion=3.912 latestVersion=3.912 May 27 17:27:14 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:27:14.705+02:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.1.4:62783 @ 0x1c9c0c0" status=UPDATE_STATUS_NONE progress=0 May 27 17:27:14 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:27:14.706+02:00 level=INFO msg="emitting user changed event" component=server peer="192.168.1.4:62783 @ 0x1c9c0c0" userId= May 27 17:27:14 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:27:14.706+02:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.1.4:62783 @ 0x1c9c0c0" providers=3 May 27 17:27:14 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:27:14.706+02:00 level=INFO msg="emitting plugins changed event" component=server peer="192.168.1.4:62783 @ 0x1c9c0c0" plugins=32 May 27 17:27:14 rivo-black volumio[3139]: verbose: New Socket.io Connection to 192.168.1.3:3000 from 192.168.1.4 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 10 May 27 17:27:14 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetState May 27 17:27:14 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:27:14.715+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:62783 @ 0x1c9c0c0" state=STATUS_PAUSED positionMs=0 volume=54 May 27 17:27:14 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:27:14.716+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:62783 @ 0x1c9c0c0" id=http://192.168.1.5:49152/audirvana/audio_f_3.wav title="Threshold Meditation" May 27 17:27:14 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 27 17:27:14 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 27 17:27:16 rivo-black volumio5-onboarding[3888]: time=2026-05-27T17:27:16.425+02:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.1.4:62783 @ 0x1c9c0c0" latency=205.13147ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE May 27 17:27:17 rivo-black sudo[25846]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 27 17:27:17 rivo-black sudo[25846]: pam_unix(sudo:session): session opened for user root by (uid=0) May 27 17:27:17 rivo-black sudo[25849]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 27 17:27:17 rivo-black sudo[25849]: pam_unix(sudo:session): session opened for user root by (uid=0) May 27 17:27:17 rivo-black sudo[25846]: pam_unix(sudo:session): session closed for user root May 27 17:27:17 rivo-black sudo[25849]: pam_unix(sudo:session): session closed for user root May 27 17:27:17 rivo-black volumio[3139]: verbose: New Socket.io Connection to 192.168.1.3 from 192.168.1.4 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 10 May 27 17:27:17 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 27 17:27:17 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 27 17:27:17 rivo-black sudo[25854]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 27 17:27:17 rivo-black sudo[25854]: pam_unix(sudo:session): session opened for user root by (uid=0) May 27 17:27:17 rivo-black sudo[25857]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 27 17:27:17 rivo-black sudo[25857]: pam_unix(sudo:session): session opened for user root by (uid=0) May 27 17:27:17 rivo-black sudo[25854]: pam_unix(sudo:session): session closed for user root May 27 17:27:17 rivo-black sudo[25857]: pam_unix(sudo:session): session closed for user root May 27 17:27:17 rivo-black volumio[3139]: verbose: New Socket.io Connection to 192.168.1.3 from 192.168.1.4 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 10 May 27 17:27:17 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 27 17:27:17 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetVisibleSources May 27 17:27:17 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 27 17:27:17 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetState May 27 17:27:17 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 27 17:27:17 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 27 17:27:17 rivo-black volumio[3139]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom May 27 17:27:17 rivo-black volumio[3139]: info: Received Get System Info May 27 17:27:17 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 27 17:27:17 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 27 17:27:17 rivo-black volumio[3139]: info: Discovery: Getting this device information May 27 17:27:17 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetState May 27 17:27:17 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 27 17:27:17 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetState May 27 17:27:17 rivo-black volumio[3139]: info: Listing playlists May 27 17:27:17 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 27 17:27:17 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 27 17:27:18 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 27 17:27:19 rivo-black dbus-daemon[2851]: [system] The maximum number of active connections for UID 1000 has been reached (max_connections_per_user=256) May 27 17:27:19 rivo-black volumio[3139]: info: Discovery: Restarting Browsing May 27 17:27:19 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard May 27 17:27:19 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 27 17:27:19 rivo-black volumio[3139]: info: Received Get System Info May 27 17:27:19 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 27 17:27:19 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 27 17:27:19 rivo-black volumio[3139]: info: Discovery: Getting this device information May 27 17:27:19 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetState May 27 17:27:19 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 27 17:27:21 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 27 17:27:21 rivo-black volumio[3139]: info: Received Get System Info May 27 17:27:21 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 27 17:27:21 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 27 17:27:21 rivo-black volumio[3139]: info: Discovery: Getting this device information May 27 17:27:21 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetState May 27 17:27:21 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 27 17:27:22 rivo-black volumio[3139]: info: CoreCommandRouter::getUIConfigOnPlugin May 27 17:27:22 rivo-black volumio[3139]: info: CoreCommandRouter::getUIConfigOnPlugin May 27 17:27:22 rivo-black volumio[3139]: info: Retrieving Cloud Streaming UI May 27 17:27:22 rivo-black volumio[3139]: info: Getting Tidal Cloud Configuration May 27 17:27:22 rivo-black volumio[3139]: info: CoreCommandRouter::getUIConfigOnPlugin May 27 17:27:22 rivo-black volumio[3139]: info: Getting Qobuz Cloud Configuration May 27 17:27:22 rivo-black volumio[3139]: info: Asking plugin for UI Config May 27 17:27:22 rivo-black volumio[3139]: info: CoreCommandRouter::getUIConfigOnPlugin May 27 17:27:22 rivo-black volumio[3139]: info: Getting Spotify Cloud Configuration May 27 17:27:22 rivo-black volumio[3139]: info: Asking plugin for UI Config May 27 17:27:22 rivo-black volumio[3139]: info: CoreCommandRouter::getUIConfigOnPlugin May 27 17:27:22 rivo-black volumio[3139]: info: Saving Spotify Acccount May 27 17:27:22 rivo-black volumio[3139]: info: Got it May 27 17:27:22 rivo-black volumio[3139]: error: Could not retrieve Spotify Config from plugin Spotify: no section found May 27 17:27:22 rivo-black volumio[3139]: info: Got Tidal Cloud Configuration May 27 17:27:22 rivo-black volumio[3139]: info: Got it May 27 17:27:22 rivo-black volumio[3139]: info: CoreCommandRouter::getUIConfigOnPlugin May 27 17:27:22 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 27 17:27:22 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam May 27 17:27:22 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam May 27 17:27:22 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam May 27 17:27:22 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 27 17:27:22 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 27 17:27:22 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 27 17:27:22 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 27 17:27:22 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetBrowseSources May 27 17:27:22 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetBrowseSources May 27 17:27:22 rivo-black volumio[3139]: info: CoreCommandRouter::volumioGetBrowseSources May 27 17:27:22 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 27 17:27:22 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares May 27 17:27:24 rivo-black dbus-daemon[2851]: [system] The maximum number of active connections for UID 1000 has been reached (max_connections_per_user=256) May 27 17:27:24 rivo-black volumio[3139]: info: Discovery: Restarting Browsing May 27 17:27:26 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 27 17:27:27 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 27 17:27:27 rivo-black volumio[3139]: info: Disabling MyMusic plugin upnp May 27 17:27:27 rivo-black sudo[25915]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service May 27 17:27:27 rivo-black sudo[25915]: pam_unix(sudo:session): session opened for user root by (uid=0) May 27 17:27:27 rivo-black systemd[1]: Stopping UPnP Renderer front-end to MPD... May 27 17:27:28 rivo-black volumio[3139]: error: Upnp client error: Error: This socket has been ended by the other party May 27 17:27:28 rivo-black volumio[3139]: ------------------------------------ BT MESSAGE: BT STATUS: running May 27 17:27:29 rivo-black dbus-daemon[2851]: [system] The maximum number of active connections for UID 1000 has been reached (max_connections_per_user=256) May 27 17:27:29 rivo-black volumio[3139]: info: Discovery: Restarting Browsing May 27 17:27:30 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 27 17:27:34 rivo-black dbus-daemon[2851]: [system] The maximum number of active connections for UID 1000 has been reached (max_connections_per_user=256) May 27 17:27:34 rivo-black volumio[3139]: info: Discovery: Restarting Browsing May 27 17:27:34 rivo-black volumio[3139]: info: Enabling MyMusic plugin upnp May 27 17:27:34 rivo-black volumio[3139]: info: Enabling plugin upnp May 27 17:27:34 rivo-black volumio[3139]: info: Loading plugin "upnp"... May 27 17:27:34 rivo-black volumio[3139]: info: [1779895654667] Starting Upmpd Daemon May 27 17:27:34 rivo-black volumio[3139]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 27 17:27:34 rivo-black volumio[3139]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 27 17:27:34 rivo-black volumio[3139]: Error: listen EADDRINUSE: address already in use :::6599 May 27 17:27:34 rivo-black volumio[3139]: at Server.setupListenHandle [as _listen2] (net.js:1331:16) May 27 17:27:34 rivo-black volumio[3139]: at listenInCluster (net.js:1379:12) May 27 17:27:34 rivo-black volumio[3139]: at Server.listen (net.js:1465:7) May 27 17:27:34 rivo-black volumio[3139]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) May 27 17:27:34 rivo-black volumio[3139]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) May 27 17:27:34 rivo-black volumio[3139]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) May 27 17:27:34 rivo-black volumio[3139]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) May 27 17:27:34 rivo-black volumio[3139]: at processTicksAndRejections (internal/process/task_queues.js:77:11) { May 27 17:27:34 rivo-black volumio[3139]: code: 'EADDRINUSE', May 27 17:27:34 rivo-black volumio[3139]: errno: -98, May 27 17:27:34 rivo-black volumio[3139]: syscall: 'listen', May 27 17:27:34 rivo-black volumio[3139]: address: '::', May 27 17:27:34 rivo-black volumio[3139]: port: 6599 May 27 17:27:34 rivo-black volumio[3139]: } May 27 17:27:34 rivo-black volumio[3139]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 27 17:27:35 rivo-black sudo[25946]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-05-27 17:26 May 27 17:27:35 rivo-black sudo[25946]: 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="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 27 Feb 2026 11:38:48 AM CET" VOLUMIO_VERSION="3.912" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="8e381701610c2a79deb52e712150c089"