-- Logs begin at Fri 2026-02-27 05:19:27 EST, end at Sun 2026-05-31 20:10:19 EDT. -- May 31 20:09:02 rivoplus volumio[3395]: info: CoreCommandRouter::servicePushState May 31 20:09:02 rivoplus volumio[3395]: info: CoreStateMachine::pushState May 31 20:09:02 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 20:09:02 rivoplus volumio[3395]: info: CoreCommandRouter::volumioPushState May 31 20:09:02 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetState May 31 20:09:02 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output update for this device May 31 20:09:02 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output May 31 20:09:02 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:02.190-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" state=STATUS_PLAYING positionMs=50000 volume=33 May 31 20:09:02 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:02.191-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" id= title="Band Call" May 31 20:09:02 rivoplus volumio[3395]: info: Signalling Playback active due to playback status change May 31 20:09:02 rivoplus volumio[3395]: info: Updating RAAT Signal Path May 31 20:09:02 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetState May 31 20:09:04 rivoplus volumio[3395]: info: Executing endpoint metavolumio May 31 20:09:04 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 31 20:09:04 rivoplus volumio[3395]: info: Executing endpoint metavolumio May 31 20:09:04 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 31 20:09:04 rivoplus volumio[3395]: info: Executing endpoint metavolumio May 31 20:09:04 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 31 20:09:05 rivoplus volumio[3395]: info: CoreCommandRouter::getUIConfigOnPlugin May 31 20:09:05 rivoplus volumio[3395]: info: CoreCommandRouter::getUIConfigOnPlugin May 31 20:09:05 rivoplus volumio[3395]: info: Retrieving Cloud Streaming UI May 31 20:09:05 rivoplus volumio[3395]: info: Getting Tidal Cloud Configuration May 31 20:09:05 rivoplus volumio[3395]: info: CoreCommandRouter::getUIConfigOnPlugin May 31 20:09:05 rivoplus volumio[3395]: info: Getting Qobuz Cloud Configuration May 31 20:09:05 rivoplus volumio[3395]: info: Asking plugin for UI Config May 31 20:09:05 rivoplus volumio[3395]: info: CoreCommandRouter::getUIConfigOnPlugin May 31 20:09:05 rivoplus volumio[3395]: info: Getting Spotify Cloud Configuration May 31 20:09:05 rivoplus volumio[3395]: info: Asking plugin for UI Config May 31 20:09:05 rivoplus volumio[3395]: info: CoreCommandRouter::getUIConfigOnPlugin May 31 20:09:05 rivoplus volumio[3395]: info: Saving Spotify Acccount May 31 20:09:05 rivoplus volumio[3395]: info: Got it May 31 20:09:05 rivoplus volumio[3395]: error: Could not retrieve Spotify Config from plugin Spotify: no section found May 31 20:09:05 rivoplus volumio[3395]: info: Got Tidal Cloud Configuration May 31 20:09:05 rivoplus volumio[3395]: info: Got it May 31 20:09:05 rivoplus volumio[3395]: info: CoreCommandRouter::getUIConfigOnPlugin May 31 20:09:05 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 31 20:09:05 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam May 31 20:09:05 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam May 31 20:09:05 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam May 31 20:09:05 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 20:09:05 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 20:09:05 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 20:09:05 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 20:09:05 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetBrowseSources May 31 20:09:05 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetBrowseSources May 31 20:09:05 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetBrowseSources May 31 20:09:05 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 31 20:09:05 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares May 31 20:09:06 rivoplus volumio[3395]: info: CoreCommandRouter::servicePushState May 31 20:09:06 rivoplus volumio[3395]: info: CoreStateMachine::pushState May 31 20:09:06 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 20:09:06 rivoplus volumio[3395]: info: CoreCommandRouter::volumioPushState May 31 20:09:06 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetState May 31 20:09:06 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output update for this device May 31 20:09:06 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output May 31 20:09:06 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:06.190-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" state=STATUS_PLAYING positionMs=54000 volume=33 May 31 20:09:06 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:06.191-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" id= title="Band Call" May 31 20:09:06 rivoplus volumio[3395]: info: Signalling Playback active due to playback status change May 31 20:09:06 rivoplus volumio[3395]: info: Updating RAAT Signal Path May 31 20:09:09 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 31 20:09:10 rivoplus volumio[3395]: info: CoreCommandRouter::servicePushState May 31 20:09:10 rivoplus volumio[3395]: info: CoreStateMachine::pushState May 31 20:09:10 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 20:09:10 rivoplus volumio[3395]: info: CoreCommandRouter::volumioPushState May 31 20:09:10 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetState May 31 20:09:10 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output update for this device May 31 20:09:10 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output May 31 20:09:10 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:10.196-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" state=STATUS_PLAYING positionMs=58000 volume=33 May 31 20:09:10 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:10.197-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" id= title="Band Call" May 31 20:09:10 rivoplus volumio[3395]: info: Signalling Playback active due to playback status change May 31 20:09:10 rivoplus volumio[3395]: info: Updating RAAT Signal Path May 31 20:09:13 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 31 20:09:14 rivoplus volumio[3395]: info: CoreCommandRouter::servicePushState May 31 20:09:14 rivoplus volumio[3395]: info: CoreStateMachine::pushState May 31 20:09:14 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 20:09:14 rivoplus volumio[3395]: info: CoreCommandRouter::volumioPushState May 31 20:09:14 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetState May 31 20:09:14 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output update for this device May 31 20:09:14 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output May 31 20:09:14 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:14.200-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" state=STATUS_PLAYING positionMs=62000 volume=33 May 31 20:09:14 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:14.201-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" id= title="Band Call" May 31 20:09:14 rivoplus volumio[3395]: info: Signalling Playback active due to playback status change May 31 20:09:14 rivoplus volumio[3395]: info: Updating RAAT Signal Path May 31 20:09:16 rivoplus volumio[3395]: info: Disabling MyMusic plugin multiroom May 31 20:09:16 rivoplus volumio[3395]: info: Disabling plugin multiroom May 31 20:09:16 rivoplus volumio[3395]: info: Preparing to generate the ALSA configuration file May 31 20:09:16 rivoplus volumio[3395]: info: Asound.conf file written May 31 20:09:16 rivoplus sudo[9357]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf May 31 20:09:16 rivoplus sudo[9357]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 20:09:16 rivoplus sudo[9357]: pam_unix(sudo:session): session closed for user root May 31 20:09:16 rivoplus kernel: Fine tdm clk setting range (0~2000000), 12287994 May 31 20:09:16 rivoplus kernel: Err: can not set rate to 4290967296! May 31 20:09:16 rivoplus kernel: Range[3920000 - 500000000] May 31 20:09:16 rivoplus kernel: out of value, fixed it May 31 20:09:16 rivoplus kernel: id=0 set inskew=0 May 31 20:09:16 rivoplus volumio[3395]: xcb_connection_has_error() returned true May 31 20:09:16 rivoplus volumio[3395]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:eARC_TX CDS:0' : Operation not permitted May 31 20:09:16 rivoplus volumio[3395]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:I2SIn CLK:0' : Operation not permitted May 31 20:09:16 rivoplus volumio[3395]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:SPDIFIN audio samplerate:0' : Operation not permitted May 31 20:09:16 rivoplus volumio[3395]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:SPDIFIN Audio Type:0' : Operation not permitted May 31 20:09:16 rivoplus volumio[3395]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:Clock Source 5 Validity:0' : Operation not permitted May 31 20:09:16 rivoplus volumio[3395]: info: Output device has changed, restarting MPD May 31 20:09:16 rivoplus sudo[9362]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 31 20:09:16 rivoplus sudo[9362]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 20:09:16 rivoplus sudo[9362]: pam_unix(sudo:session): session closed for user root May 31 20:09:16 rivoplus volumio[3395]: info: Output device has changed, restarting Shairport Sync May 31 20:09:16 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:16 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 20:09:16 rivoplus sudo[9365]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 31 20:09:16 rivoplus sudo[9365]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 20:09:16 rivoplus systemd[1]: Stopping Music Player Daemon... May 31 20:09:16 rivoplus volumio[3395]: xcb_connection_has_error() returned true May 31 20:09:16 rivoplus volumio[3395]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 31 20:09:16 rivoplus volumio[3395]: xcb_connection_has_error() returned true May 31 20:09:16 rivoplus volumio[3395]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 31 20:09:16 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:16 rivoplus volumio[3395]: info: QobuzConnect: setDeactiveState invoked May 31 20:09:16 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetState May 31 20:09:16 rivoplus volumio[3395]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes May 31 20:09:16 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:16 rivoplus vtcs[4207]: [2026-05-31 20:09:16.753] [tisoc] [warning] [SessionManagerImpl.cpp:240] Illegal State: IDLE May 31 20:09:16 rivoplus vtcs[4207]: [2026-05-31 20:09:16.755] [tisoc] [error] [SpkconServer.cpp:383] recv error. client fd=7 errorno=104 error=Connection reset by peer May 31 20:09:16 rivoplus vtcs[4207]: [2026-05-31 20:09:16.755] [tisoc] [error] [SpkconServer.cpp:378] recv error. socket disconnected May 31 20:09:16 rivoplus volumio[3395]: info: Done. May 31 20:09:16 rivoplus sudo[9373]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 31 20:09:16 rivoplus sudo[9373]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 20:09:16 rivoplus systemd[1]: mpd.service: Succeeded. May 31 20:09:16 rivoplus systemd[1]: Stopped Music Player Daemon. May 31 20:09:16 rivoplus systemd[1]: Starting Music Player Daemon... May 31 20:09:16 rivoplus sudo[9376]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 31 20:09:16 rivoplus sudo[9376]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 20:09:16 rivoplus systemd[1]: Stopping Volumio Tidal Connect Service... May 31 20:09:16 rivoplus systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM May 31 20:09:16 rivoplus systemd[1]: vtcs.service: Succeeded. May 31 20:09:16 rivoplus systemd[1]: Stopped Volumio Tidal Connect Service. May 31 20:09:16 rivoplus volumio[3395]: ------------------------------------ BT MESSAGE: BT STATUS: running May 31 20:09:16 rivoplus sudo[9373]: pam_unix(sudo:session): session closed for user root May 31 20:09:16 rivoplus volumio[3395]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 31 20:09:16 rivoplus volumio[3395]: ------------------------------------ BT MESSAGE: BT STATUS: running May 31 20:09:16 rivoplus volumio[3395]: ------------------------------------ BT MESSAGE: BT STATUS: running May 31 20:09:16 rivoplus sudo[9390]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service May 31 20:09:16 rivoplus sudo[9390]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 20:09:16 rivoplus volumio[3395]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read property 'split' of undefined May 31 20:09:16 rivoplus volumio[3395]: info: MPD Permissions set May 31 20:09:16 rivoplus sudo[9376]: pam_unix(sudo:session): session closed for user root May 31 20:09:16 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:16 rivoplus sudo[9390]: pam_unix(sudo:session): session closed for user root May 31 20:09:16 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:16 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:16 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:16 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:16 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:17 rivoplus sudo[9394]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service May 31 20:09:17 rivoplus sudo[9394]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 20:09:17 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 20:09:17 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 31 20:09:17 rivoplus qobuz-connect[4028]: 20260531 20:09:17.039 [4028.4028] INFO SampleApp: Stopping Local configuration server May 31 20:09:17 rivoplus systemd[1]: Stopping Volumio Qobuz Connect Service... May 31 20:09:17 rivoplus qobuz-connect[4028]: 20260531 20:09:17.050 [4028.4028] INFO SampleApp: shat down connection on UNIX socket May 31 20:09:17 rivoplus systemd[1]: qobuz-connect.service: Succeeded. May 31 20:09:17 rivoplus systemd[1]: Stopped Volumio Qobuz Connect Service. May 31 20:09:17 rivoplus sudo[9378]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 31 20:09:17 rivoplus sudo[9378]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 20:09:17 rivoplus systemd[1]: Started Volumio Qobuz Connect Service. May 31 20:09:17 rivoplus sudo[9394]: pam_unix(sudo:session): session closed for user root May 31 20:09:17 rivoplus sudo[9378]: pam_unix(sudo:session): session closed for user root May 31 20:09:17 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:17 rivoplus volumio[3395]: ------------------------------------ BT MESSAGE: BT STATUS: running May 31 20:09:17 rivoplus volumio[3395]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 31 20:09:17 rivoplus volumio[3395]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected May 31 20:09:17 rivoplus volumio[3395]: info: QobuzConnect: setDeactiveState invoked May 31 20:09:17 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetState May 31 20:09:17 rivoplus volumio[3395]: info: Starting Shairport Sync May 31 20:09:17 rivoplus volumio[3395]: info: Preparing to generate the ALSA configuration file May 31 20:09:17 rivoplus sudo[9411]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 31 20:09:17 rivoplus sudo[9411]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 20:09:17 rivoplus volumio[3395]: info: Executing endpoint qc_getconfig May 31 20:09:17 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig May 31 20:09:17 rivoplus systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 31 20:09:17 rivoplus systemd[1]: shairport-sync.service: Succeeded. May 31 20:09:17 rivoplus systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 31 20:09:17 rivoplus systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 31 20:09:17 rivoplus sudo[9411]: pam_unix(sudo:session): session closed for user root May 31 20:09:17 rivoplus qobuz-connect[9403]: 20260531 20:09:17.277 [9403.9403] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket May 31 20:09:17 rivoplus qobuz-connect[9403]: 20260531 20:09:17.285 [9403.9403] INFO VolumeManager: [0xac1cd858]: Setting new playback volume: 75 May 31 20:09:17 rivoplus qobuz-connect[9403]: 20260531 20:09:17.285 [9403.9403] INFO VolumeManager: [0xac1cd858]: Setting new mute state: 0 May 31 20:09:17 rivoplus qobuz-connect[9403]: 20260531 20:09:17.285 [9403.9403] INFO AudioStreamManager: [0xac1cd5b0]: Setting new audio download buffer size: 1048576 May 31 20:09:17 rivoplus qobuz-connect[9403]: 20260531 20:09:17.285 [9403.9403] INFO QobuzConnect: [0xac1ce120]: Client initialized! May 31 20:09:17 rivoplus qobuz-connect[9403]: 20260531 20:09:17.285 [9403.9403] INFO SampleApp: Starting Avahi advertising, name: Rivoplus, service name: _qobuz-connect._tcp May 31 20:09:17 rivoplus qobuz-connect[9403]: 20260531 20:09:17.304 [9403.9403] INFO LocalConfigManager: [0xac1cd2d8]: Starting Local Configuration server May 31 20:09:17 rivoplus qobuz-connect[9403]: 20260531 20:09:17.305 [9403.9403] INFO SampleApp: Starting Local configuration server May 31 20:09:17 rivoplus qobuz-connect[9403]: 20260531 20:09:17.306 [9403.9403] INFO SampleApp: Connected to UNIX socket client 0xac1c2ed8 May 31 20:09:17 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:17 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:17 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:17 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:17 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:17 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:17 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:17 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 20:09:17 rivoplus volumio[3395]: info: Not Reporting Auto name since its the default one May 31 20:09:17 rivoplus volumio[3395]: ------------------------------------ BT MESSAGE: BT STATUS: running May 31 20:09:17 rivoplus volumio[3395]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 31 20:09:17 rivoplus volumio[3395]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] May 31 20:09:17 rivoplus volumio[3395]: info: QobuzConnect: QOBUZ Connect daemon connected May 31 20:09:17 rivoplus volumio[3395]: info: Shairport-Sync Started May 31 20:09:17 rivoplus volumio[3395]: info: Asound.conf file unchanged, so no further update is needed May 31 20:09:17 rivoplus volumio[3395]: info: Output device has changed, restarting MPD May 31 20:09:17 rivoplus qobuz-connect[9403]: 20260531 20:09:17.427 [9403.9403] INFO SampleApp: Playback volume changed: 75 May 31 20:09:17 rivoplus sudo[9427]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 31 20:09:17 rivoplus sudo[9427]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 20:09:17 rivoplus sudo[9427]: pam_unix(sudo:session): session closed for user root May 31 20:09:17 rivoplus volumio[3395]: info: Output device has changed, restarting Shairport Sync May 31 20:09:17 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:17 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 20:09:17 rivoplus sudo[9430]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 31 20:09:17 rivoplus sudo[9430]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 20:09:17 rivoplus systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM May 31 20:09:17 rivoplus systemd[1]: mpd.service: Succeeded. May 31 20:09:17 rivoplus volumio[3395]: xcb_connection_has_error() returned true May 31 20:09:17 rivoplus volumio[3395]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 31 20:09:17 rivoplus volumio[3395]: xcb_connection_has_error() returned true May 31 20:09:17 rivoplus volumio[3395]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 31 20:09:17 rivoplus systemd[1]: Stopped Music Player Daemon. May 31 20:09:17 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:17 rivoplus systemd[1]: Starting Music Player Daemon... May 31 20:09:17 rivoplus volumio[3395]: info: QobuzConnect: setDeactiveState invoked May 31 20:09:17 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetState May 31 20:09:17 rivoplus volumio[3395]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes May 31 20:09:17 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:17 rivoplus sudo[9439]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 31 20:09:17 rivoplus sudo[9439]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 20:09:17 rivoplus sudo[9442]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 31 20:09:17 rivoplus sudo[9442]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 20:09:17 rivoplus sudo[9439]: pam_unix(sudo:session): session closed for user root May 31 20:09:17 rivoplus sudo[9442]: pam_unix(sudo:session): session closed for user root May 31 20:09:17 rivoplus sudo[9435]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 31 20:09:17 rivoplus sudo[9435]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 20:09:17 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetState May 31 20:09:17 rivoplus volumio[3395]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 31 20:09:17 rivoplus volumio[3395]: ------------------------------------ BT MESSAGE: BT STATUS: running May 31 20:09:17 rivoplus volumio[3395]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 31 20:09:17 rivoplus volumio[3395]: ------------------------------------ BT MESSAGE: BT STATUS: running May 31 20:09:17 rivoplus sudo[9435]: pam_unix(sudo:session): session closed for user root May 31 20:09:17 rivoplus sudo[9450]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service May 31 20:09:17 rivoplus sudo[9450]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 20:09:17 rivoplus volumio[3395]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read property 'split' of undefined May 31 20:09:17 rivoplus volumio[3395]: info: MPD Permissions set May 31 20:09:17 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable May 31 20:09:17 rivoplus sudo[9450]: pam_unix(sudo:session): session closed for user root May 31 20:09:17 rivoplus sudo[9454]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service May 31 20:09:17 rivoplus sudo[9454]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 20:09:17 rivoplus systemd[1]: Stopping Volumio Qobuz Connect Service... May 31 20:09:17 rivoplus volumio[3395]: xcb_connection_has_error() returned true May 31 20:09:17 rivoplus qobuz-connect[9403]: 20260531 20:09:17.840 [9403.9403] INFO SampleApp: Stopping Local configuration server May 31 20:09:17 rivoplus qobuz-connect[9403]: 20260531 20:09:17.850 [9403.9403] INFO SampleApp: shat down connection on UNIX socket May 31 20:09:17 rivoplus systemd[1]: qobuz-connect.service: Succeeded. May 31 20:09:17 rivoplus systemd[1]: Stopped Volumio Qobuz Connect Service. May 31 20:09:17 rivoplus systemd[1]: Started Volumio Qobuz Connect Service. May 31 20:09:17 rivoplus sudo[9454]: pam_unix(sudo:session): session closed for user root May 31 20:09:17 rivoplus volumio[3395]: ------------------------------------ BT MESSAGE: BT STATUS: running May 31 20:09:17 rivoplus volumio[3395]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 31 20:09:17 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 31 20:09:17 rivoplus volumio[3395]: error: MPD error: Error: This socket has been ended by the other party May 31 20:09:17 rivoplus volumio[3395]: error: This socket has been ended by the other party {"code":"EPIPE"} May 31 20:09:17 rivoplus volumio[3395]: error: MPD error: Error: This socket has been ended by the other party May 31 20:09:17 rivoplus volumio[3395]: error: This socket has been ended by the other party {"code":"EPIPE"} May 31 20:09:17 rivoplus volumio[3395]: error: MPD error: Error: This socket has been ended by the other party May 31 20:09:17 rivoplus volumio[3395]: error: This socket has been ended by the other party {"code":"EPIPE"} May 31 20:09:17 rivoplus volumio[3395]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected May 31 20:09:17 rivoplus volumio[3395]: info: QobuzConnect: setDeactiveState invoked May 31 20:09:17 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetState May 31 20:09:17 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:17 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:17 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:17 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:17 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:17 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:17 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:17 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:17 rivoplus sudo[9460]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service May 31 20:09:17 rivoplus sudo[9460]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 20:09:17 rivoplus sudo[9460]: pam_unix(sudo:session): session closed for user root May 31 20:09:17 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 20:09:17 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 31 20:09:17 rivoplus sudo[9469]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service May 31 20:09:17 rivoplus sudo[9469]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 20:09:18 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:18 rivoplus systemd[1]: Stopping RAAT DAEMON... May 31 20:09:18 rivoplus volumio[3395]: ------------------------------------ BT MESSAGE: BT STATUS: running May 31 20:09:18 rivoplus volumio[3395]: info: Executing endpoint qc_getconfig May 31 20:09:18 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig May 31 20:09:18 rivoplus systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM May 31 20:09:18 rivoplus systemd[1]: raat-daemon.service: Succeeded. May 31 20:09:18 rivoplus systemd[1]: Stopped RAAT DAEMON. May 31 20:09:18 rivoplus systemd[1]: Started RAAT DAEMON. May 31 20:09:18 rivoplus sudo[9469]: pam_unix(sudo:session): session closed for user root May 31 20:09:18 rivoplus qobuz-connect[9459]: 20260531 20:09:18.096 [9459.9459] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket May 31 20:09:18 rivoplus qobuz-connect[9459]: 20260531 20:09:18.102 [9459.9459] INFO VolumeManager: [0xacc2f858]: Setting new playback volume: 75 May 31 20:09:18 rivoplus qobuz-connect[9459]: 20260531 20:09:18.102 [9459.9459] INFO VolumeManager: [0xacc2f858]: Setting new mute state: 0 May 31 20:09:18 rivoplus qobuz-connect[9459]: 20260531 20:09:18.102 [9459.9459] INFO AudioStreamManager: [0xacc2f5b0]: Setting new audio download buffer size: 1048576 May 31 20:09:18 rivoplus qobuz-connect[9459]: 20260531 20:09:18.103 [9459.9459] INFO QobuzConnect: [0xacc30120]: Client initialized! May 31 20:09:18 rivoplus qobuz-connect[9459]: 20260531 20:09:18.103 [9459.9459] INFO SampleApp: Starting Avahi advertising, name: Rivoplus, service name: _qobuz-connect._tcp May 31 20:09:18 rivoplus qobuz-connect[9459]: 20260531 20:09:18.126 [9459.9459] INFO LocalConfigManager: [0xacc2f2d8]: Starting Local Configuration server May 31 20:09:18 rivoplus qobuz-connect[9459]: 20260531 20:09:18.126 [9459.9459] INFO SampleApp: Starting Local configuration server May 31 20:09:18 rivoplus qobuz-connect[9459]: 20260531 20:09:18.127 [9459.9459] INFO SampleApp: Connected to UNIX socket client 0xacc24ed8 May 31 20:09:18 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:18 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:18 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:18 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:18 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:18 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:18 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:18 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:18 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 20:09:18 rivoplus volumio[3395]: info: Not Reporting Auto name since its the default one May 31 20:09:18 rivoplus volumio[3395]: info: Starting Shairport Sync May 31 20:09:18 rivoplus volumio[3395]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 31 20:09:18 rivoplus volumio[3395]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] May 31 20:09:18 rivoplus volumio[3395]: info: QobuzConnect: QOBUZ Connect daemon connected May 31 20:09:18 rivoplus volumio[3395]: info: Raat Daemon started successfully May 31 20:09:18 rivoplus sudo[9493]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 31 20:09:18 rivoplus sudo[9493]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 20:09:18 rivoplus volumio[3395]: info: Executing endpoint restartRAATSocket May 31 20:09:18 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection May 31 20:09:18 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable May 31 20:09:18 rivoplus qobuz-connect[9459]: 20260531 20:09:18.245 [9459.9459] INFO SampleApp: Playback volume changed: 75 May 31 20:09:18 rivoplus sudo[9493]: pam_unix(sudo:session): session closed for user root May 31 20:09:18 rivoplus systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 31 20:09:18 rivoplus systemd[1]: shairport-sync.service: Succeeded. May 31 20:09:18 rivoplus systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 31 20:09:18 rivoplus systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 31 20:09:18 rivoplus volumio[3395]: xcb_connection_has_error() returned true May 31 20:09:18 rivoplus sudo[9501]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service May 31 20:09:18 rivoplus sudo[9501]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 20:09:18 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetState May 31 20:09:18 rivoplus volumio[3395]: ------------------------------------ BT MESSAGE: BT STATUS: running May 31 20:09:18 rivoplus volumio[3395]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 31 20:09:18 rivoplus sudo[9501]: pam_unix(sudo:session): session closed for user root May 31 20:09:18 rivoplus volumio[3395]: info: Shairport-Sync Started May 31 20:09:18 rivoplus volumio[3395]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 May 31 20:09:18 rivoplus sudo[9505]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service May 31 20:09:18 rivoplus sudo[9505]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 20:09:18 rivoplus systemd[1]: Stopping RAAT DAEMON... May 31 20:09:18 rivoplus systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM May 31 20:09:18 rivoplus systemd[1]: raat-daemon.service: Succeeded. May 31 20:09:18 rivoplus systemd[1]: Stopped RAAT DAEMON. May 31 20:09:18 rivoplus volumio[3395]: ------------------------------------ BT MESSAGE: BT STATUS: running May 31 20:09:18 rivoplus systemd[1]: Started RAAT DAEMON. May 31 20:09:18 rivoplus volumio[3395]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 31 20:09:18 rivoplus sudo[9505]: pam_unix(sudo:session): session closed for user root May 31 20:09:18 rivoplus volumio[3395]: info: Raat Daemon started successfully May 31 20:09:18 rivoplus volumio[3395]: info: Executing endpoint restartRAATSocket May 31 20:09:18 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection May 31 20:09:18 rivoplus volumio[3395]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 May 31 20:09:19 rivoplus volumio[3395]: info: CoreCommandRouter::servicePushState May 31 20:09:19 rivoplus volumio[3395]: info: CoreStateMachine::pushState May 31 20:09:19 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 20:09:19 rivoplus volumio[3395]: info: CoreCommandRouter::volumioPushState May 31 20:09:19 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetState May 31 20:09:19 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output update for this device May 31 20:09:19 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output May 31 20:09:19 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:19.061-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" state=STATUS_PLAYING positionMs=65000 volume=33 May 31 20:09:19 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:19.061-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" id= title="Band Call" May 31 20:09:19 rivoplus volumio[3395]: info: CoreCommandRouter::servicePushState May 31 20:09:19 rivoplus volumio[3395]: info: CoreStateMachine::pushState May 31 20:09:19 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 20:09:19 rivoplus volumio[3395]: info: CoreCommandRouter::volumioPushState May 31 20:09:19 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetState May 31 20:09:19 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output update for this device May 31 20:09:19 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output May 31 20:09:19 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:19.078-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" state=STATUS_PAUSED positionMs=65000 volume=33 May 31 20:09:19 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:19.079-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" id= title="Band Call" May 31 20:09:19 rivoplus volumio[3395]: info: Signalling Playback active due to playback status change May 31 20:09:19 rivoplus volumio[3395]: info: Updating RAAT Signal Path May 31 20:09:19 rivoplus volumio[3395]: info: Updating RAAT Signal Path May 31 20:09:19 rivoplus volumio[3395]: info: MCU Signalled Playback Inactive May 31 20:09:19 rivoplus mpd[9455]: May 31 20:09 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 31 20:09:19 rivoplus systemd[1]: Started Music Player Daemon. May 31 20:09:19 rivoplus sudo[9365]: pam_unix(sudo:session): session closed for user root May 31 20:09:19 rivoplus sudo[9430]: pam_unix(sudo:session): session closed for user root May 31 20:09:19 rivoplus volumio[3395]: error: MPD error: The expression evaluated to a falsy value: May 31 20:09:19 rivoplus volumio[3395]: assert.ok(self.idling) May 31 20:09:19 rivoplus volumio[3395]: error: The expression evaluated to a falsy value: May 31 20:09:19 rivoplus volumio[3395]: assert.ok(self.idling) May 31 20:09:19 rivoplus volumio[3395]: error: updateQueue error: null May 31 20:09:19 rivoplus volumio[3395]: info: TidalConnect service stoped! May 31 20:09:19 rivoplus volumio[3395]: info: TidalConnect service stoped! May 31 20:09:20 rivoplus volumio[3395]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 31 20:09:20 rivoplus volumio[3395]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect May 31 20:09:20 rivoplus sudo[9530]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service May 31 20:09:20 rivoplus sudo[9530]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 20:09:20 rivoplus systemd[1]: Started Volumio Tidal Connect Service. May 31 20:09:20 rivoplus sudo[9530]: pam_unix(sudo:session): session closed for user root May 31 20:09:20 rivoplus volumio[3395]: info: Executing endpoint tc_getconfig May 31 20:09:20 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig May 31 20:09:20 rivoplus vtcs[9532]: STARTING TidalConnect services, version: 1.6.1 May 31 20:09:20 rivoplus vtcs[9532]: STARTED TidalConnect services. May 31 20:09:20 rivoplus volumio[3395]: info: Executing endpoint tc_connect May 31 20:09:20 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect May 31 20:09:20 rivoplus volumio[3395]: info: Connecting to TidalConnect May 31 20:09:20 rivoplus volumio[3395]: info: CoreCommandRouter::servicePushState May 31 20:09:20 rivoplus volumio[3395]: info: CoreStateMachine::pushState May 31 20:09:20 rivoplus volumio[3395]: info: CoreCommandRouter::volumioPushState May 31 20:09:20 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetState May 31 20:09:20 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output update for this device May 31 20:09:20 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output May 31 20:09:20 rivoplus volumio[3395]: info: CorePlayQueue::getTrack 0 May 31 20:09:20 rivoplus volumio[3395]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} May 31 20:09:20 rivoplus volumio[3395]: verbose: CURRENT POSITION 0 May 31 20:09:20 rivoplus volumio[3395]: info: CoreStateMachine::syncState stateService stop May 31 20:09:20 rivoplus volumio[3395]: info: CoreStateMachine::syncState currentStatus pause May 31 20:09:20 rivoplus volumio[3395]: info: CoreStateMachine::pushState May 31 20:09:20 rivoplus volumio[3395]: info: CoreCommandRouter::volumioPushState May 31 20:09:20 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetState May 31 20:09:20 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output update for this device May 31 20:09:20 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output May 31 20:09:20 rivoplus volumio[3395]: info: CoreCommandRouter::servicePushState May 31 20:09:20 rivoplus volumio[3395]: info: CoreStateMachine::pushState May 31 20:09:20 rivoplus volumio[3395]: info: CoreCommandRouter::volumioPushState May 31 20:09:20 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetState May 31 20:09:20 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output update for this device May 31 20:09:20 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output May 31 20:09:20 rivoplus volumio[3395]: info: CorePlayQueue::getTrack 0 May 31 20:09:20 rivoplus volumio[3395]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} May 31 20:09:20 rivoplus volumio[3395]: verbose: CURRENT POSITION 0 May 31 20:09:20 rivoplus volumio[3395]: info: CoreStateMachine::syncState stateService stop May 31 20:09:20 rivoplus volumio[3395]: info: CoreStateMachine::syncState currentStatus pause May 31 20:09:20 rivoplus volumio[3395]: info: CoreStateMachine::pushState May 31 20:09:20 rivoplus volumio[3395]: info: CoreCommandRouter::volumioPushState May 31 20:09:20 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetState May 31 20:09:20 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output update for this device May 31 20:09:20 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output May 31 20:09:20 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:20.538-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" state=STATUS_PAUSED positionMs=65000 volume=33 May 31 20:09:20 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:20.539-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" id= title="Band Call" May 31 20:09:20 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:20.540-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" state=STATUS_PAUSED positionMs=65000 volume=33 May 31 20:09:20 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:20.540-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" id= title="Band Call" May 31 20:09:20 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:20.541-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" state=STATUS_PAUSED positionMs=65000 volume=33 May 31 20:09:20 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:20.543-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" state=STATUS_PAUSED positionMs=65000 volume=33 May 31 20:09:20 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:20.543-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" id= title="Band Call" May 31 20:09:20 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:20.544-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" id= title="Band Call" May 31 20:09:20 rivoplus volumio[3395]: info: Updating RAAT Signal Path May 31 20:09:20 rivoplus volumio[3395]: info: Updating RAAT Signal Path May 31 20:09:20 rivoplus volumio[3395]: info: Updating RAAT Signal Path May 31 20:09:20 rivoplus volumio[3395]: info: Updating RAAT Signal Path May 31 20:09:20 rivoplus volumio[3395]: info: TidalConnect service stoped! May 31 20:09:20 rivoplus volumio[3395]: info: TidalConnect service stoped! May 31 20:09:20 rivoplus volumio[3395]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 31 20:09:20 rivoplus volumio[3395]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect May 31 20:09:20 rivoplus sudo[9560]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service May 31 20:09:20 rivoplus sudo[9560]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 20:09:20 rivoplus volumio[3395]: info: RAAT: Requesting Headphone Status May 31 20:09:20 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus May 31 20:09:20 rivoplus sudo[9560]: pam_unix(sudo:session): session closed for user root May 31 20:09:20 rivoplus volumio[3395]: info: MCU Signalled Headphone Mode Disabled May 31 20:09:20 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState May 31 20:09:20 rivoplus volumio[3395]: info: Reporting Headphone State: false May 31 20:09:20 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:20 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:20 rivoplus volumio[3395]: info: Updating RAAT Signal Path May 31 20:09:21 rivoplus volumio[3395]: info: RAAT: Requesting Headphone Status May 31 20:09:21 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus May 31 20:09:21 rivoplus volumio[3395]: info: MCU Signalled Headphone Mode Disabled May 31 20:09:21 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState May 31 20:09:21 rivoplus volumio[3395]: info: Reporting Headphone State: false May 31 20:09:21 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 20:09:21 rivoplus volumio[3395]: info: Updating RAAT Signal Path May 31 20:09:21 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 31 20:09:23 rivoplus volumio[3395]: info: TidalConnect service started! May 31 20:09:23 rivoplus volumio[3395]: info: TidalConnect service started! May 31 20:09:25 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 31 20:09:29 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 31 20:09:34 rivoplus ntpd[3386]: 72.14.186.59 local addr 192.168.1.115 -> May 31 20:09:35 rivoplus volumio[3395]: info: [VRCP] preparing for control May 31 20:09:35 rivoplus volumio[3395]: info: RAAT Acquiring Control May 31 20:09:35 rivoplus volumio[3395]: info: CoreStateMachine::setConsumeUpdateService undefined May 31 20:09:35 rivoplus volumio[3395]: info: CoreCommandRouter::volumioStop May 31 20:09:35 rivoplus volumio[3395]: info: CoreStateMachine::stop May 31 20:09:35 rivoplus volumio[3395]: info: CoreStateMachine::serviceStop May 31 20:09:35 rivoplus volumio[3395]: info: Received STOP, but no service to execute it May 31 20:09:35 rivoplus volumio[3395]: info: RAAT Control Acquired May 31 20:09:35 rivoplus volumio[3395]: info: [VRCP] prepared for control May 31 20:09:35 rivoplus volumio[3395]: info: CoreStateMachine::setConsumeUpdateService undefined May 31 20:09:35 rivoplus volumio[3395]: info: [VRCP] acknowledged control May 31 20:09:35 rivoplus volumio[3395]: info: CoreCommandRouter::servicePushState May 31 20:09:35 rivoplus volumio[3395]: info: CoreStateMachine::pushState May 31 20:09:35 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 20:09:35 rivoplus volumio[3395]: info: CoreCommandRouter::volumioPushState May 31 20:09:35 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetState May 31 20:09:35 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output update for this device May 31 20:09:35 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output May 31 20:09:35 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:35.056-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" state=STATUS_PAUSED positionMs=0 volume=33 May 31 20:09:35 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:35.056-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" id= title="Band Call" May 31 20:09:35 rivoplus volumio[3395]: info: CoreCommandRouter::servicePushState May 31 20:09:35 rivoplus volumio[3395]: info: CoreStateMachine::pushState May 31 20:09:35 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 20:09:35 rivoplus volumio[3395]: info: CoreCommandRouter::volumioPushState May 31 20:09:35 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetState May 31 20:09:35 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output update for this device May 31 20:09:35 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output May 31 20:09:35 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:35.069-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" state=STATUS_PAUSED positionMs=65000 volume=33 May 31 20:09:35 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:35.069-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" id= title="Band Call" May 31 20:09:35 rivoplus volumio[3395]: info: Updating RAAT Signal Path May 31 20:09:35 rivoplus volumio[3395]: info: Updating RAAT Signal Path May 31 20:09:35 rivoplus volumio[3395]: info: CoreCommandRouter::servicePushState May 31 20:09:35 rivoplus volumio[3395]: info: CoreStateMachine::pushState May 31 20:09:35 rivoplus volumio[3395]: info: CoreCommandRouter::volumioPushState May 31 20:09:35 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetState May 31 20:09:35 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output update for this device May 31 20:09:35 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output May 31 20:09:35 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:35.875-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" state=STATUS_PAUSED positionMs=65000 volume=33 May 31 20:09:35 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:35.875-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" id= title="Band Call" May 31 20:09:35 rivoplus volumio[3395]: info: Updating RAAT Signal Path May 31 20:09:35 rivoplus volumio[3395]: info: CoreCommandRouter::servicePushState May 31 20:09:35 rivoplus volumio[3395]: info: CoreStateMachine::pushState May 31 20:09:35 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 20:09:35 rivoplus volumio[3395]: info: CoreCommandRouter::volumioPushState May 31 20:09:35 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetState May 31 20:09:35 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output update for this device May 31 20:09:35 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output May 31 20:09:35 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:35.899-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" state=STATUS_PLAYING positionMs=65000 volume=33 May 31 20:09:35 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:35.899-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" id= title="Band Call" May 31 20:09:35 rivoplus volumio[3395]: info: Signalling Playback active due to playback status change May 31 20:09:35 rivoplus volumio[3395]: info: Updating RAAT Signal Path May 31 20:09:35 rivoplus volumio[3395]: info: MCU Signalled Playback Active May 31 20:09:36 rivoplus volumio[3395]: info: CoreCommandRouter::servicePushState May 31 20:09:36 rivoplus volumio[3395]: info: CoreStateMachine::pushState May 31 20:09:36 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 20:09:36 rivoplus volumio[3395]: info: CoreCommandRouter::volumioPushState May 31 20:09:36 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetState May 31 20:09:36 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output update for this device May 31 20:09:36 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output May 31 20:09:36 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:36.039-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" state=STATUS_PAUSED positionMs=65000 volume=33 May 31 20:09:36 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:36.040-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" id= title="Band Call" May 31 20:09:36 rivoplus volumio[3395]: info: Updating RAAT Signal Path May 31 20:09:36 rivoplus volumio[3395]: info: MCU Signalled Playback Inactive May 31 20:09:37 rivoplus volumio[3395]: info: CoreCommandRouter::servicePushState May 31 20:09:37 rivoplus volumio[3395]: info: CoreStateMachine::pushState May 31 20:09:37 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 20:09:37 rivoplus volumio[3395]: info: CoreCommandRouter::volumioPushState May 31 20:09:37 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetState May 31 20:09:37 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output update for this device May 31 20:09:37 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output May 31 20:09:37 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:37.094-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" state=STATUS_PLAYING positionMs=65000 volume=33 May 31 20:09:37 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:37.095-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" id= title="Band Call" May 31 20:09:37 rivoplus volumio[3395]: info: Signalling Playback active due to playback status change May 31 20:09:37 rivoplus volumio[3395]: info: Updating RAAT Signal Path May 31 20:09:37 rivoplus volumio[3395]: info: MCU Signalled Playback Active May 31 20:09:40 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 31 20:09:40 rivoplus volumio[3395]: info: CoreCommandRouter::servicePushState May 31 20:09:40 rivoplus volumio[3395]: info: CoreStateMachine::pushState May 31 20:09:40 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 20:09:40 rivoplus volumio[3395]: info: CoreCommandRouter::volumioPushState May 31 20:09:40 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetState May 31 20:09:40 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output update for this device May 31 20:09:40 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output May 31 20:09:40 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:40.473-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" state=STATUS_PLAYING positionMs=68000 volume=33 May 31 20:09:40 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:40.474-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" id= title="Band Call" May 31 20:09:40 rivoplus volumio[3395]: info: Signalling Playback active due to playback status change May 31 20:09:40 rivoplus volumio[3395]: info: Updating RAAT Signal Path May 31 20:09:44 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 31 20:09:44 rivoplus volumio[3395]: info: CoreCommandRouter::servicePushState May 31 20:09:44 rivoplus volumio[3395]: info: CoreStateMachine::pushState May 31 20:09:44 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 20:09:44 rivoplus volumio[3395]: info: CoreCommandRouter::volumioPushState May 31 20:09:44 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetState May 31 20:09:44 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output update for this device May 31 20:09:44 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output May 31 20:09:44 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:44.474-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" state=STATUS_PLAYING positionMs=72000 volume=33 May 31 20:09:44 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:44.474-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" id= title="Band Call" May 31 20:09:44 rivoplus volumio[3395]: info: Signalling Playback active due to playback status change May 31 20:09:44 rivoplus volumio[3395]: info: Updating RAAT Signal Path May 31 20:09:48 rivoplus volumio[3395]: info: Disabling MyMusic plugin airplay_emulation May 31 20:09:48 rivoplus volumio[3395]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesShairport-Sync May 31 20:09:48 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 31 20:09:48 rivoplus volumio[3395]: Cannot find translation for source Bandcamp Discover May 31 20:09:48 rivoplus volumio[3395]: Cannot find translation for source SoundCloud May 31 20:09:48 rivoplus volumio[3395]: Cannot find translation for source Mother Earth Radio May 31 20:09:48 rivoplus volumio[3395]: Cannot find translation for source Podcast May 31 20:09:48 rivoplus volumio[3395]: Cannot find translation for source Radio Paradise May 31 20:09:48 rivoplus volumio[3395]: Cannot find translation for source QOBUZ May 31 20:09:48 rivoplus volumio[3395]: Cannot find translation for source TIDAL May 31 20:09:48 rivoplus volumio[3395]: info: Disabling plugin airplay_emulation May 31 20:09:48 rivoplus volumio[3395]: info: Done. May 31 20:09:48 rivoplus sudo[9625]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop shairport-sync May 31 20:09:48 rivoplus sudo[9625]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 20:09:48 rivoplus systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 31 20:09:48 rivoplus volumio[3395]: ------------------------------------ BT MESSAGE: BT STATUS: running May 31 20:09:48 rivoplus systemd[1]: shairport-sync.service: Succeeded. May 31 20:09:48 rivoplus systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 31 20:09:48 rivoplus sudo[9625]: pam_unix(sudo:session): session closed for user root May 31 20:09:48 rivoplus volumio[3395]: info: Shairport-Sync Stopped May 31 20:09:48 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 31 20:09:48 rivoplus volumio[3395]: info: CoreCommandRouter::servicePushState May 31 20:09:48 rivoplus volumio[3395]: info: CoreStateMachine::pushState May 31 20:09:48 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 20:09:48 rivoplus volumio[3395]: info: CoreCommandRouter::volumioPushState May 31 20:09:48 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetState May 31 20:09:48 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output update for this device May 31 20:09:48 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output May 31 20:09:48 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:48.463-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" state=STATUS_PLAYING positionMs=76000 volume=33 May 31 20:09:48 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:48.463-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" id= title="Band Call" May 31 20:09:48 rivoplus volumio[3395]: info: Signalling Playback active due to playback status change May 31 20:09:48 rivoplus volumio[3395]: info: Updating RAAT Signal Path May 31 20:09:52 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 31 20:09:52 rivoplus volumio[3395]: info: CoreCommandRouter::servicePushState May 31 20:09:52 rivoplus volumio[3395]: info: CoreStateMachine::pushState May 31 20:09:52 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 20:09:52 rivoplus volumio[3395]: info: CoreCommandRouter::volumioPushState May 31 20:09:52 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetState May 31 20:09:52 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output update for this device May 31 20:09:52 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output May 31 20:09:52 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:52.457-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" state=STATUS_PLAYING positionMs=80000 volume=33 May 31 20:09:52 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:52.457-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" id= title="Band Call" May 31 20:09:52 rivoplus volumio[3395]: info: Signalling Playback active due to playback status change May 31 20:09:52 rivoplus volumio[3395]: info: Updating RAAT Signal Path May 31 20:09:56 rivoplus volumio[3395]: info: Disabling MyMusic plugin qobuzconnect May 31 20:09:56 rivoplus qobuz-connect[9459]: 20260531 20:09:56.250 [9459.9459] INFO MediaEngine: [0xacc2f500]: Stopping playback, keeping tracks May 31 20:09:56 rivoplus volumio[3395]: info: QobuzConnect: setDeactiveState invoked May 31 20:09:56 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetState May 31 20:09:56 rivoplus sudo[9693]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop qobuz-connect May 31 20:09:56 rivoplus sudo[9693]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 20:09:56 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 31 20:09:56 rivoplus systemd[1]: Stopping Volumio Qobuz Connect Service... May 31 20:09:56 rivoplus qobuz-connect[9459]: 20260531 20:09:56.329 [9459.9459] INFO SampleApp: Stopping Local configuration server May 31 20:09:56 rivoplus volumio[3395]: ------------------------------------ BT MESSAGE: BT STATUS: running May 31 20:09:56 rivoplus qobuz-connect[9459]: 20260531 20:09:56.339 [9459.9459] INFO SampleApp: shat down connection on UNIX socket May 31 20:09:56 rivoplus volumio[3395]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected May 31 20:09:56 rivoplus volumio[3395]: info: QobuzConnect: setDeactiveState invoked May 31 20:09:56 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetState May 31 20:09:56 rivoplus systemd[1]: qobuz-connect.service: Succeeded. May 31 20:09:56 rivoplus systemd[1]: Stopped Volumio Qobuz Connect Service. May 31 20:09:56 rivoplus sudo[9693]: pam_unix(sudo:session): session closed for user root May 31 20:09:56 rivoplus volumio[3395]: info: CoreCommandRouter::servicePushState May 31 20:09:56 rivoplus volumio[3395]: info: CoreStateMachine::pushState May 31 20:09:56 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 20:09:56 rivoplus volumio[3395]: info: CoreCommandRouter::volumioPushState May 31 20:09:56 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetState May 31 20:09:56 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output update for this device May 31 20:09:56 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output May 31 20:09:56 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:56.386-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" state=STATUS_PLAYING positionMs=84000 volume=33 May 31 20:09:56 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:56.386-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" id= title="Band Call" May 31 20:09:56 rivoplus volumio[3395]: info: Signalling Playback active due to playback status change May 31 20:09:56 rivoplus volumio[3395]: info: Updating RAAT Signal Path May 31 20:09:56 rivoplus volumio[3395]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket disconnected and tore down May 31 20:09:56 rivoplus volumio[3395]: info: Disabling plugin qobuzconnect May 31 20:09:56 rivoplus volumio[3395]: info: Done. May 31 20:09:59 rivoplus volumio[3395]: info: CoreCommandRouter::servicePushState May 31 20:09:59 rivoplus volumio[3395]: info: CoreStateMachine::pushState May 31 20:09:59 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 20:09:59 rivoplus volumio[3395]: info: CoreCommandRouter::volumioPushState May 31 20:09:59 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetState May 31 20:09:59 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output update for this device May 31 20:09:59 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output May 31 20:09:59 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:59.418-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" state=STATUS_PLAYING positionMs=87000 volume=33 May 31 20:09:59 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:09:59.419-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" id= title="Band Call" May 31 20:09:59 rivoplus volumio[3395]: info: Signalling Playback active due to playback status change May 31 20:09:59 rivoplus volumio[3395]: info: Updating RAAT Signal Path May 31 20:10:00 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 31 20:10:02 rivoplus volumio[3395]: info: CoreCommandRouter::servicePushState May 31 20:10:02 rivoplus volumio[3395]: info: CoreStateMachine::pushState May 31 20:10:02 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 20:10:02 rivoplus volumio[3395]: info: CoreCommandRouter::volumioPushState May 31 20:10:02 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetState May 31 20:10:02 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output update for this device May 31 20:10:02 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output May 31 20:10:02 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:10:02.493-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" state=STATUS_PLAYING positionMs=90000 volume=33 May 31 20:10:02 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:10:02.494-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" id= title="Band Call" May 31 20:10:02 rivoplus volumio[3395]: info: Signalling Playback active due to playback status change May 31 20:10:02 rivoplus volumio[3395]: info: Updating RAAT Signal Path May 31 20:10:04 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 31 20:10:06 rivoplus volumio[3395]: info: Disabling MyMusic plugin tidalconnect May 31 20:10:06 rivoplus vtcs[9532]: [2026-05-31 20:10:06.101] [tisoc] [warning] [SessionManagerImpl.cpp:240] Illegal State: IDLE May 31 20:10:06 rivoplus vtcs[9532]: [2026-05-31 20:10:06.102] [tisoc] [error] [SpkconServer.cpp:476] socket write error. fd=3 errorno=32 error=Broken pipe May 31 20:10:06 rivoplus vtcs[9532]: [2026-05-31 20:10:06.102] [tisoc] [error] [SpkconServer.cpp:378] recv error. socket disconnected May 31 20:10:06 rivoplus volumio[3395]: info: Disabling plugin tidalconnect May 31 20:10:06 rivoplus volumio[3395]: info: Done. May 31 20:10:06 rivoplus sudo[9721]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 31 20:10:06 rivoplus sudo[9721]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 20:10:06 rivoplus systemd[1]: Stopping Volumio Tidal Connect Service... May 31 20:10:06 rivoplus systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM May 31 20:10:06 rivoplus volumio[3395]: ------------------------------------ BT MESSAGE: BT STATUS: running May 31 20:10:06 rivoplus systemd[1]: vtcs.service: Succeeded. May 31 20:10:06 rivoplus systemd[1]: Stopped Volumio Tidal Connect Service. May 31 20:10:06 rivoplus sudo[9721]: pam_unix(sudo:session): session closed for user root May 31 20:10:06 rivoplus volumio[3395]: info: CoreCommandRouter::servicePushState May 31 20:10:06 rivoplus volumio[3395]: info: CoreStateMachine::pushState May 31 20:10:06 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 20:10:06 rivoplus volumio[3395]: info: CoreCommandRouter::volumioPushState May 31 20:10:06 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetState May 31 20:10:06 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output update for this device May 31 20:10:06 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output May 31 20:10:06 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:10:06.487-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" state=STATUS_PLAYING positionMs=94000 volume=33 May 31 20:10:06 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:10:06.488-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" id= title="Band Call" May 31 20:10:06 rivoplus volumio[3395]: info: Signalling Playback active due to playback status change May 31 20:10:06 rivoplus volumio[3395]: info: Updating RAAT Signal Path May 31 20:10:08 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 31 20:10:09 rivoplus volumio[3395]: info: TidalConnect service stoped! May 31 20:10:10 rivoplus volumio[3395]: info: CoreCommandRouter::servicePushState May 31 20:10:10 rivoplus volumio[3395]: info: CoreStateMachine::pushState May 31 20:10:10 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 20:10:10 rivoplus volumio[3395]: info: CoreCommandRouter::volumioPushState May 31 20:10:10 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetState May 31 20:10:10 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output update for this device May 31 20:10:10 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output May 31 20:10:10 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:10:10.488-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" state=STATUS_PLAYING positionMs=98000 volume=33 May 31 20:10:10 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:10:10.491-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" id= title="Band Call" May 31 20:10:10 rivoplus volumio[3395]: info: Signalling Playback active due to playback status change May 31 20:10:10 rivoplus volumio[3395]: info: Updating RAAT Signal Path May 31 20:10:12 rivoplus volumio[3395]: info: Disabling MyMusic plugin upnp May 31 20:10:12 rivoplus sudo[9725]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service May 31 20:10:12 rivoplus sudo[9725]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 20:10:12 rivoplus systemd[1]: Stopping UPnP Renderer front-end to MPD... May 31 20:10:12 rivoplus volumio[3395]: error: Upnp client error: Error: This socket has been ended by the other party May 31 20:10:12 rivoplus volumio[3395]: ------------------------------------ BT MESSAGE: BT STATUS: running May 31 20:10:12 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 31 20:10:14 rivoplus volumio[3395]: info: CoreCommandRouter::servicePushState May 31 20:10:14 rivoplus volumio[3395]: info: CoreStateMachine::pushState May 31 20:10:14 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 20:10:14 rivoplus volumio[3395]: info: CoreCommandRouter::volumioPushState May 31 20:10:14 rivoplus volumio[3395]: info: CoreCommandRouter::volumioGetState May 31 20:10:14 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output update for this device May 31 20:10:14 rivoplus volumio[3395]: info: MRS: Pushing multiroomSync output May 31 20:10:14 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:10:14.478-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" state=STATUS_PLAYING positionMs=102000 volume=33 May 31 20:10:14 rivoplus volumio5-onboarding[4400]: time=2026-05-31T20:10:14.478-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.219:52926,192.168.1.219:53052 @ 0x2801c80" id= title="Band Call" May 31 20:10:14 rivoplus volumio[3395]: info: Signalling Playback active due to playback status change May 31 20:10:14 rivoplus volumio[3395]: info: Updating RAAT Signal Path May 31 20:10:16 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 31 20:10:18 rivoplus volumio[3395]: info: Enabling MyMusic plugin upnp May 31 20:10:18 rivoplus volumio[3395]: info: Enabling plugin upnp May 31 20:10:18 rivoplus volumio[3395]: info: Loading plugin "upnp"... May 31 20:10:18 rivoplus volumio[3395]: info: [1780272618430] Starting Upmpd Daemon May 31 20:10:18 rivoplus volumio[3395]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 31 20:10:18 rivoplus volumio[3395]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 31 20:10:18 rivoplus volumio[3395]: Error: listen EADDRINUSE: address already in use :::6599 May 31 20:10:18 rivoplus volumio[3395]: at Server.setupListenHandle [as _listen2] (net.js:1331:16) May 31 20:10:18 rivoplus volumio[3395]: at listenInCluster (net.js:1379:12) May 31 20:10:18 rivoplus volumio[3395]: at Server.listen (net.js:1465:7) May 31 20:10:18 rivoplus volumio[3395]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) May 31 20:10:18 rivoplus volumio[3395]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) May 31 20:10:18 rivoplus volumio[3395]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) May 31 20:10:18 rivoplus volumio[3395]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) May 31 20:10:18 rivoplus volumio[3395]: at processTicksAndRejections (internal/process/task_queues.js:77:11) { May 31 20:10:18 rivoplus volumio[3395]: code: 'EADDRINUSE', May 31 20:10:18 rivoplus volumio[3395]: errno: -98, May 31 20:10:18 rivoplus volumio[3395]: syscall: 'listen', May 31 20:10:18 rivoplus volumio[3395]: address: '::', May 31 20:10:18 rivoplus volumio[3395]: port: 6599 May 31 20:10:18 rivoplus volumio[3395]: } May 31 20:10:18 rivoplus volumio[3395]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 31 20:10:19 rivoplus sudo[9754]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-05-31 20:09 May 31 20:10:19 rivoplus sudo[9754]: 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"