-- Logs begin at Thu 2026-03-05 03:07:05 GMT, end at Wed 2026-05-27 13:11:56 BST. -- May 27 13:11:34 rivo1 volumio[3096]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] May 27 13:11:34 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions May 27 13:11:34 rivo1 volumio[3096]: info: Preparing to save Alsa Options, stopping services first May 27 13:11:34 rivo1 volumio[3096]: info: CoreCommandRouter::volumioGetState May 27 13:11:34 rivo1 volumio[3096]: info: CorePlayQueue::getTrack 0 May 27 13:11:34 rivo1 volumio[3096]: info: CoreCommandRouter::volumioPause May 27 13:11:34 rivo1 volumio[3096]: info: CoreStateMachine::pause May 27 13:11:34 rivo1 volumio[3096]: info: Saving Audio Output to: {"output_device":{"value":"0,2","label":"S/PDIF + AES/EBU"}} May 27 13:11:34 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 27 13:11:35 rivo1 volumio[3096]: No protocol specified May 27 13:11:35 rivo1 volumio[3096]: xcb_connection_has_error() returned true May 27 13:11:35 rivo1 volumio[3096]: No protocol specified May 27 13:11:35 rivo1 volumio[3096]: xcb_connection_has_error() returned true May 27 13:11:35 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 27 13:11:35 rivo1 volumio[3096]: No protocol specified May 27 13:11:35 rivo1 volumio[3096]: xcb_connection_has_error() returned true May 27 13:11:35 rivo1 volumio[3096]: info: Setting mixer Audio hdmi-out mute for card S/PDIF + AES/EBU May 27 13:11:35 rivo1 volumio[3096]: info: QobuzConnect: setDeactiveState invoked May 27 13:11:35 rivo1 volumio[3096]: info: CoreCommandRouter::volumioGetState May 27 13:11:35 rivo1 volumio[3096]: info: CorePlayQueue::getTrack 0 May 27 13:11:35 rivo1 volumio[3096]: info: Reconfiguring and Restarting RAAT Plugin due to audio path changes May 27 13:11:35 rivo1 vtcs[8370]: [2026-05-27 13:11:35.160] [tisoc] [warning] [SessionManagerImpl.cpp:240] Illegal State: IDLE May 27 13:11:35 rivo1 vtcs[8370]: [2026-05-27 13:11:35.161] [tisoc] [error] [SpkconServer.cpp:378] recv error. socket disconnected May 27 13:11:35 rivo1 vtcs[8370]: [2026-05-27 13:11:35.161] [tisoc] [error] [SpkconServer.cpp:476] socket write error. fd=3 errorno=32 error=Broken pipe May 27 13:11:35 rivo1 sudo[8698]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 27 13:11:35 rivo1 sudo[8698]: pam_unix(sudo:session): session opened for user root by (uid=0) May 27 13:11:35 rivo1 systemd[1]: Stopping Volumio Tidal Connect Service... May 27 13:11:35 rivo1 systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM May 27 13:11:35 rivo1 systemd[1]: vtcs.service: Succeeded. May 27 13:11:35 rivo1 systemd[1]: Stopped Volumio Tidal Connect Service. May 27 13:11:35 rivo1 sudo[8698]: pam_unix(sudo:session): session closed for user root May 27 13:11:35 rivo1 volumio[3096]: No protocol specified May 27 13:11:35 rivo1 volumio[3096]: xcb_connection_has_error() returned true May 27 13:11:35 rivo1 volumio[3096]: info: CoreCommandRouter::volumioUpdateVolumeSettings May 27 13:11:35 rivo1 volumio[3096]: info: Updating Volume Controller Parameters: Device: 0,2 Name: S/PDIF + AES/EBU Mixer: Audio hdmi-out mute Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 May 27 13:11:35 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume May 27 13:11:35 rivo1 volumio[3096]: info: Disabling external Volume Control May 27 13:11:35 rivo1 volumio[3096]: info: CoreCommandRouter::getUIConfigOnPlugin May 27 13:11:35 rivo1 volumio[3096]: info: Preparing to generate the ALSA configuration file May 27 13:11:35 rivo1 sudo[8705]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 27 13:11:35 rivo1 sudo[8705]: pam_unix(sudo:session): session opened for user root by (uid=0) May 27 13:11:35 rivo1 sudo[8705]: pam_unix(sudo:session): session closed for user root May 27 13:11:35 rivo1 volumio[3096]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf May 27 13:11:35 rivo1 volumio[3096]: info: Reading ALSA contributions from plugins. May 27 13:11:35 rivo1 volumio[3096]: ------------------------------------ BT MESSAGE: BT STATUS: running May 27 13:11:35 rivo1 volumio[3096]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: No protocol specified May 27 13:11:35 rivo1 volumio[3096]: xcb_connection_has_error() returned true May 27 13:11:35 rivo1 sudo[8712]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service May 27 13:11:35 rivo1 sudo[8712]: pam_unix(sudo:session): session opened for user root by (uid=0) May 27 13:11:35 rivo1 sudo[8712]: pam_unix(sudo:session): session closed for user root May 27 13:11:35 rivo1 sudo[8715]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service May 27 13:11:35 rivo1 sudo[8715]: pam_unix(sudo:session): session opened for user root by (uid=0) May 27 13:11:35 rivo1 systemd[1]: Stopping Volumio Qobuz Connect Service... May 27 13:11:35 rivo1 qobuz-connect[8297]: 20260527 13:11:35.522 [8297.8297] INFO SampleApp: Stopping Local configuration server May 27 13:11:35 rivo1 qobuz-connect[8297]: 20260527 13:11:35.532 [8297.8297] INFO SampleApp: shat down connection on UNIX socket May 27 13:11:35 rivo1 systemd[1]: qobuz-connect.service: Succeeded. May 27 13:11:35 rivo1 systemd[1]: Stopped Volumio Qobuz Connect Service. May 27 13:11:35 rivo1 volumio[3096]: No protocol specified May 27 13:11:35 rivo1 volumio[3096]: xcb_connection_has_error() returned true May 27 13:11:35 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions May 27 13:11:35 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 27 13:11:35 rivo1 systemd[1]: Started Volumio Qobuz Connect Service. May 27 13:11:35 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 27 13:11:35 rivo1 sudo[8715]: pam_unix(sudo:session): session closed for user root May 27 13:11:35 rivo1 volumio[3096]: No protocol specified May 27 13:11:35 rivo1 volumio[3096]: xcb_connection_has_error() returned true May 27 13:11:35 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 27 13:11:35 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 27 13:11:35 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 27 13:11:35 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 27 13:11:35 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 27 13:11:35 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 27 13:11:35 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 27 13:11:35 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode May 27 13:11:35 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 27 13:11:35 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: raat , getAdditionalUiSection May 27 13:11:35 rivo1 volumio[3096]: ------------------------------------ BT MESSAGE: BT STATUS: running May 27 13:11:35 rivo1 volumio[3096]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 27 13:11:35 rivo1 volumio[3096]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected May 27 13:11:35 rivo1 volumio[3096]: info: QobuzConnect: setDeactiveState invoked May 27 13:11:35 rivo1 volumio[3096]: info: CoreCommandRouter::volumioGetState May 27 13:11:35 rivo1 volumio[3096]: info: CorePlayQueue::getTrack 0 May 27 13:11:35 rivo1 volumio[3096]: info: VolumeController:: Volume=undefined Mute =false May 27 13:11:35 rivo1 volumio[3096]: info: CoreStateMachine::pushState May 27 13:11:35 rivo1 volumio[3096]: info: CorePlayQueue::getTrack 0 May 27 13:11:35 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 13:11:35 rivo1 volumio[3096]: info: CoreCommandRouter::volumioPushState May 27 13:11:35 rivo1 volumio[3096]: info: CoreCommandRouter::volumioGetState May 27 13:11:35 rivo1 volumio[3096]: info: CorePlayQueue::getTrack 0 May 27 13:11:35 rivo1 volumio[3096]: info: MRS: Pushing multiroomSync output update for this device May 27 13:11:35 rivo1 volumio[3096]: info: MRS: Pushing multiroomSync output May 27 13:11:35 rivo1 volumio5-onboarding[3634]: time=2026-05-27T13:11:35.693+01:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.68.53:49215 @ 0x2cc5680" state=STATUS_STOPPED positionMs=106894 volume=0 May 27 13:11:35 rivo1 volumio5-onboarding[3634]: time=2026-05-27T13:11:35.694+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.68.53:49215 @ 0x2c00c30" state=STATUS_STOPPED positionMs=106894 volume=0 May 27 13:11:35 rivo1 volumio5-onboarding[3634]: time=2026-05-27T13:11:35.694+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.68.53:49215 @ 0x2cc5680" id=tidal://song/69041902 title="You Really Got Me" May 27 13:11:35 rivo1 volumio5-onboarding[3634]: time=2026-05-27T13:11:35.694+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.68.53:49215 @ 0x2c00c30" id=tidal://song/69041902 title="You Really Got Me" May 27 13:11:35 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 13:11:35 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 13:11:35 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 13:11:35 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 27 13:11:35 rivo1 volumio[3096]: info: Not Reporting Auto name since its the default one May 27 13:11:35 rivo1 volumio[3096]: info: Updating RAAT Signal Path May 27 13:11:35 rivo1 volumio[3096]: info: Executing endpoint qc_getconfig May 27 13:11:35 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig May 27 13:11:35 rivo1 qobuz-connect[8719]: 20260527 13:11:35.847 [8719.8719] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket May 27 13:11:35 rivo1 qobuz-connect[8719]: 20260527 13:11:35.854 [8719.8719] INFO VolumeManager: [0xabcf7898]: Setting new playback volume: 75 May 27 13:11:35 rivo1 qobuz-connect[8719]: 20260527 13:11:35.854 [8719.8719] INFO VolumeManager: [0xabcf7898]: Setting new mute state: 0 May 27 13:11:35 rivo1 qobuz-connect[8719]: 20260527 13:11:35.854 [8719.8719] INFO AudioStreamManager: [0xabcf75f0]: Setting new audio download buffer size: 1048576 May 27 13:11:35 rivo1 qobuz-connect[8719]: 20260527 13:11:35.854 [8719.8719] INFO QobuzConnect: [0xabcf8160]: Client initialized! May 27 13:11:35 rivo1 qobuz-connect[8719]: 20260527 13:11:35.854 [8719.8719] INFO SampleApp: Starting Avahi advertising, name: Rivo1, service name: _qobuz-connect._tcp May 27 13:11:35 rivo1 qobuz-connect[8719]: 20260527 13:11:35.868 [8719.8719] INFO LocalConfigManager: [0xabcf7318]: Starting Local Configuration server May 27 13:11:35 rivo1 qobuz-connect[8719]: 20260527 13:11:35.868 [8719.8719] INFO SampleApp: Starting Local configuration server May 27 13:11:35 rivo1 qobuz-connect[8719]: 20260527 13:11:35.868 [8719.8719] INFO SampleApp: Connected to UNIX socket client 0xabceced8 May 27 13:11:35 rivo1 volumio[3096]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] May 27 13:11:35 rivo1 volumio[3096]: info: QobuzConnect: QOBUZ Connect daemon connected May 27 13:11:35 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 13:11:35 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 13:11:35 rivo1 volumio[3096]: info: Asound.conf file unchanged, so no further update is needed May 27 13:11:35 rivo1 volumio[3096]: info: Output device has changed, restarting MPD May 27 13:11:35 rivo1 sudo[8740]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 27 13:11:35 rivo1 sudo[8740]: pam_unix(sudo:session): session opened for user root by (uid=0) May 27 13:11:35 rivo1 volumio[3096]: info: Output device has changed, restarting Shairport Sync May 27 13:11:35 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 13:11:35 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 27 13:11:35 rivo1 sudo[8740]: pam_unix(sudo:session): session closed for user root May 27 13:11:35 rivo1 sudo[8743]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 27 13:11:35 rivo1 sudo[8743]: pam_unix(sudo:session): session opened for user root by (uid=0) May 27 13:11:35 rivo1 systemd[1]: Stopping Music Player Daemon... May 27 13:11:35 rivo1 qobuz-connect[8719]: 20260527 13:11:35.997 [8719.8719] INFO SampleApp: Playback volume changed: 75 May 27 13:11:36 rivo1 volumio[3096]: No protocol specified May 27 13:11:36 rivo1 volumio[3096]: xcb_connection_has_error() returned true May 27 13:11:36 rivo1 volumio[3096]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 27 13:11:36 rivo1 volumio[3096]: No protocol specified May 27 13:11:36 rivo1 volumio[3096]: xcb_connection_has_error() returned true May 27 13:11:36 rivo1 volumio[3096]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 27 13:11:36 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 13:11:36 rivo1 systemd[1]: mpd.service: Succeeded. May 27 13:11:36 rivo1 systemd[1]: Stopped Music Player Daemon. May 27 13:11:36 rivo1 systemd[1]: Starting Music Player Daemon... May 27 13:11:36 rivo1 volumio[3096]: info: QobuzConnect: setDeactiveState invoked May 27 13:11:36 rivo1 volumio[3096]: info: CoreCommandRouter::volumioGetState May 27 13:11:36 rivo1 volumio[3096]: info: CorePlayQueue::getTrack 0 May 27 13:11:36 rivo1 volumio[3096]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes May 27 13:11:36 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 13:11:36 rivo1 kernel: aml_spdif_open May 27 13:11:36 rivo1 kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 May 27 13:11:36 rivo1 kernel: spdif_a keep clk continuous May 27 13:11:36 rivo1 kernel: aml_spdif_close May 27 13:11:36 rivo1 kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 May 27 13:11:36 rivo1 sudo[8754]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 27 13:11:36 rivo1 sudo[8754]: pam_unix(sudo:session): session opened for user root by (uid=0) May 27 13:11:36 rivo1 sudo[8757]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 27 13:11:36 rivo1 sudo[8757]: pam_unix(sudo:session): session opened for user root by (uid=0) May 27 13:11:36 rivo1 sudo[8754]: pam_unix(sudo:session): session closed for user root May 27 13:11:36 rivo1 sudo[8757]: pam_unix(sudo:session): session closed for user root May 27 13:11:36 rivo1 sudo[8750]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 27 13:11:36 rivo1 sudo[8750]: pam_unix(sudo:session): session opened for user root by (uid=0) May 27 13:11:36 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable May 27 13:11:36 rivo1 sudo[8750]: pam_unix(sudo:session): session closed for user root May 27 13:11:36 rivo1 sudo[8768]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service May 27 13:11:36 rivo1 sudo[8768]: pam_unix(sudo:session): session opened for user root by (uid=0) May 27 13:11:36 rivo1 sudo[8768]: pam_unix(sudo:session): session closed for user root May 27 13:11:36 rivo1 volumio[3096]: No protocol specified May 27 13:11:36 rivo1 volumio[3096]: xcb_connection_has_error() returned true May 27 13:11:36 rivo1 sudo[8773]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service May 27 13:11:36 rivo1 sudo[8773]: pam_unix(sudo:session): session opened for user root by (uid=0) May 27 13:11:36 rivo1 qobuz-connect[8719]: 20260527 13:11:36.337 [8719.8719] INFO SampleApp: Stopping Local configuration server May 27 13:11:36 rivo1 systemd[1]: Stopping Volumio Qobuz Connect Service... May 27 13:11:36 rivo1 qobuz-connect[8719]: 20260527 13:11:36.348 [8719.8719] INFO SampleApp: shat down connection on UNIX socket May 27 13:11:36 rivo1 volumio[3096]: ------------------------------------ BT MESSAGE: BT STATUS: running May 27 13:11:36 rivo1 systemd[1]: qobuz-connect.service: Succeeded. May 27 13:11:36 rivo1 sudo[8776]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service May 27 13:11:36 rivo1 volumio[3096]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 27 13:11:36 rivo1 sudo[8776]: pam_unix(sudo:session): session opened for user root by (uid=0) May 27 13:11:36 rivo1 volumio[3096]: ------------------------------------ BT MESSAGE: BT STATUS: running May 27 13:11:36 rivo1 systemd[1]: Stopped Volumio Qobuz Connect Service. May 27 13:11:36 rivo1 volumio[3096]: ------------------------------------ BT MESSAGE: BT STATUS: running May 27 13:11:36 rivo1 volumio[3096]: info: CoreCommandRouter::volumioGetState May 27 13:11:36 rivo1 volumio[3096]: info: CorePlayQueue::getTrack 0 May 27 13:11:36 rivo1 systemd[1]: Started Volumio Qobuz Connect Service. May 27 13:11:36 rivo1 sudo[8773]: pam_unix(sudo:session): session closed for user root May 27 13:11:36 rivo1 volumio[3096]: info: MPD Permissions set May 27 13:11:36 rivo1 volumio[3096]: info: CoreStateMachine::pushState May 27 13:11:36 rivo1 volumio[3096]: info: CorePlayQueue::getTrack 0 May 27 13:11:36 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 13:11:36 rivo1 volumio[3096]: info: CoreCommandRouter::volumioPushState May 27 13:11:36 rivo1 volumio[3096]: info: CoreCommandRouter::volumioGetState May 27 13:11:36 rivo1 volumio[3096]: info: CorePlayQueue::getTrack 0 May 27 13:11:36 rivo1 volumio[3096]: info: MRS: Pushing multiroomSync output update for this device May 27 13:11:36 rivo1 volumio[3096]: info: MRS: Pushing multiroomSync output May 27 13:11:36 rivo1 volumio5-onboarding[3634]: time=2026-05-27T13:11:36.403+01:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.68.53:49215 @ 0x2cc5680" state=STATUS_STOPPED positionMs=107809 volume=100 May 27 13:11:36 rivo1 volumio5-onboarding[3634]: time=2026-05-27T13:11:36.404+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.68.53:49215 @ 0x2c00c30" state=STATUS_STOPPED positionMs=107809 volume=100 May 27 13:11:36 rivo1 volumio5-onboarding[3634]: time=2026-05-27T13:11:36.404+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.68.53:49215 @ 0x2cc5680" id=tidal://song/69041902 title="You Really Got Me" May 27 13:11:36 rivo1 volumio5-onboarding[3634]: time=2026-05-27T13:11:36.405+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.68.53:49215 @ 0x2c00c30" id=tidal://song/69041902 title="You Really Got Me" May 27 13:11:36 rivo1 sudo[8776]: pam_unix(sudo:session): session closed for user root May 27 13:11:36 rivo1 volumio[3096]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 27 13:11:36 rivo1 volumio[3096]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected May 27 13:11:36 rivo1 volumio[3096]: info: QobuzConnect: setDeactiveState invoked May 27 13:11:36 rivo1 volumio[3096]: info: CoreCommandRouter::volumioGetState May 27 13:11:36 rivo1 volumio[3096]: info: CorePlayQueue::getTrack 0 May 27 13:11:36 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 13:11:36 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 13:11:36 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 13:11:36 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 13:11:36 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 13:11:36 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 13:11:36 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 13:11:36 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 13:11:36 rivo1 sudo[8779]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service May 27 13:11:36 rivo1 sudo[8779]: pam_unix(sudo:session): session opened for user root by (uid=0) May 27 13:11:36 rivo1 systemd[1]: Stopping RAAT DAEMON... May 27 13:11:36 rivo1 systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM May 27 13:11:36 rivo1 systemd[1]: raat-daemon.service: Succeeded. May 27 13:11:36 rivo1 systemd[1]: Stopped RAAT DAEMON. May 27 13:11:36 rivo1 systemd[1]: Started RAAT DAEMON. May 27 13:11:36 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 27 13:11:36 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 27 13:11:36 rivo1 sudo[8779]: pam_unix(sudo:session): session closed for user root May 27 13:11:36 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 13:11:36 rivo1 kernel: aml_spdif_open May 27 13:11:36 rivo1 kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 May 27 13:11:36 rivo1 kernel: spdif_a keep clk continuous May 27 13:11:36 rivo1 kernel: aml_spdif_close May 27 13:11:36 rivo1 kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 May 27 13:11:36 rivo1 kernel: aml_spdif_open May 27 13:11:36 rivo1 kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 May 27 13:11:36 rivo1 kernel: spdif_a keep clk continuous May 27 13:11:36 rivo1 kernel: aml_spdif_close May 27 13:11:36 rivo1 kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 May 27 13:11:36 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 13:11:36 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 13:11:36 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 13:11:36 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 13:11:36 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 13:11:36 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 13:11:36 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 13:11:36 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 13:11:36 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 27 13:11:36 rivo1 volumio[3096]: info: Not Reporting Auto name since its the default one May 27 13:11:36 rivo1 volumio[3096]: ------------------------------------ BT MESSAGE: BT STATUS: running May 27 13:11:36 rivo1 volumio[3096]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 27 13:11:36 rivo1 volumio[3096]: info: Raat Daemon started successfully May 27 13:11:36 rivo1 volumio[3096]: info: Executing endpoint qc_getconfig May 27 13:11:36 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig May 27 13:11:36 rivo1 qobuz-connect[8778]: 20260527 13:11:36.732 [8778.8778] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket May 27 13:11:36 rivo1 volumio[3096]: info: Starting Shairport Sync May 27 13:11:36 rivo1 qobuz-connect[8778]: 20260527 13:11:36.739 [8778.8778] INFO VolumeManager: [0xab4a9898]: Setting new playback volume: 75 May 27 13:11:36 rivo1 qobuz-connect[8778]: 20260527 13:11:36.739 [8778.8778] INFO VolumeManager: [0xab4a9898]: Setting new mute state: 0 May 27 13:11:36 rivo1 qobuz-connect[8778]: 20260527 13:11:36.739 [8778.8778] INFO AudioStreamManager: [0xab4a95f0]: Setting new audio download buffer size: 1048576 May 27 13:11:36 rivo1 qobuz-connect[8778]: 20260527 13:11:36.739 [8778.8778] INFO QobuzConnect: [0xab4aa160]: Client initialized! May 27 13:11:36 rivo1 qobuz-connect[8778]: 20260527 13:11:36.739 [8778.8778] INFO SampleApp: Starting Avahi advertising, name: Rivo1, service name: _qobuz-connect._tcp May 27 13:11:36 rivo1 qobuz-connect[8778]: 20260527 13:11:36.754 [8778.8778] INFO LocalConfigManager: [0xab4a9318]: Starting Local Configuration server May 27 13:11:36 rivo1 qobuz-connect[8778]: 20260527 13:11:36.754 [8778.8778] INFO SampleApp: Starting Local configuration server May 27 13:11:36 rivo1 qobuz-connect[8778]: 20260527 13:11:36.755 [8778.8778] INFO SampleApp: Connected to UNIX socket client 0xab49eed8 May 27 13:11:36 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable May 27 13:11:36 rivo1 sudo[8810]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 27 13:11:36 rivo1 sudo[8810]: pam_unix(sudo:session): session opened for user root by (uid=0) May 27 13:11:36 rivo1 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 27 13:11:36 rivo1 systemd[1]: shairport-sync.service: Succeeded. May 27 13:11:36 rivo1 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 27 13:11:36 rivo1 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 27 13:11:36 rivo1 volumio[3096]: No protocol specified May 27 13:11:36 rivo1 volumio[3096]: xcb_connection_has_error() returned true May 27 13:11:36 rivo1 sudo[8810]: pam_unix(sudo:session): session closed for user root May 27 13:11:36 rivo1 qobuz-connect[8778]: 20260527 13:11:36.882 [8778.8778] INFO SampleApp: Playback volume changed: 75 May 27 13:11:36 rivo1 volumio[3096]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] May 27 13:11:36 rivo1 volumio[3096]: info: QobuzConnect: QOBUZ Connect daemon connected May 27 13:11:36 rivo1 volumio[3096]: ------------------------------------ BT MESSAGE: BT STATUS: running May 27 13:11:36 rivo1 volumio[3096]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 27 13:11:36 rivo1 volumio[3096]: info: Executing endpoint restartRAATSocket May 27 13:11:36 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection May 27 13:11:36 rivo1 sudo[8818]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service May 27 13:11:36 rivo1 sudo[8818]: pam_unix(sudo:session): session opened for user root by (uid=0) May 27 13:11:36 rivo1 volumio[3096]: info: CoreCommandRouter::volumioGetState May 27 13:11:36 rivo1 volumio[3096]: info: CorePlayQueue::getTrack 0 May 27 13:11:36 rivo1 volumio[3096]: info: Shairport-Sync Started May 27 13:11:36 rivo1 volumio[3096]: info: CorePlayQueue::getTrack 0 May 27 13:11:36 rivo1 volumio[3096]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 May 27 13:11:36 rivo1 sudo[8818]: pam_unix(sudo:session): session closed for user root May 27 13:11:37 rivo1 sudo[8822]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service May 27 13:11:37 rivo1 sudo[8822]: pam_unix(sudo:session): session opened for user root by (uid=0) May 27 13:11:37 rivo1 systemd[1]: Stopping RAAT DAEMON... May 27 13:11:37 rivo1 systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM May 27 13:11:37 rivo1 systemd[1]: raat-daemon.service: Succeeded. May 27 13:11:37 rivo1 volumio[3096]: ------------------------------------ BT MESSAGE: BT STATUS: running May 27 13:11:37 rivo1 systemd[1]: Stopped RAAT DAEMON. May 27 13:11:37 rivo1 volumio[3096]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 27 13:11:37 rivo1 systemd[1]: Started RAAT DAEMON. May 27 13:11:37 rivo1 sudo[8822]: pam_unix(sudo:session): session closed for user root May 27 13:11:37 rivo1 volumio[3096]: info: Raat Daemon started successfully May 27 13:11:37 rivo1 kernel: aml_spdif_open May 27 13:11:37 rivo1 kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 May 27 13:11:37 rivo1 kernel: spdif_a keep clk continuous May 27 13:11:37 rivo1 kernel: aml_spdif_close May 27 13:11:37 rivo1 kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 May 27 13:11:37 rivo1 kernel: aml_spdif_open May 27 13:11:37 rivo1 kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 May 27 13:11:37 rivo1 kernel: spdif_a keep clk continuous May 27 13:11:37 rivo1 kernel: aml_spdif_close May 27 13:11:37 rivo1 kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 May 27 13:11:37 rivo1 volumio[3096]: info: Executing endpoint restartRAATSocket May 27 13:11:37 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection May 27 13:11:37 rivo1 volumio[3096]: info: CorePlayQueue::getTrack 0 May 27 13:11:37 rivo1 volumio[3096]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 May 27 13:11:38 rivo1 mpd[8771]: May 27 13:11 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 27 13:11:38 rivo1 systemd[1]: Started Music Player Daemon. May 27 13:11:38 rivo1 sudo[8743]: pam_unix(sudo:session): session closed for user root May 27 13:11:38 rivo1 volumio[3096]: info: TidalConnect service stoped! May 27 13:11:38 rivo1 volumio[3096]: error: updateQueue error: null May 27 13:11:38 rivo1 volumio[3096]: info: TidalConnect service stoped! May 27 13:11:38 rivo1 volumio[3096]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 27 13:11:38 rivo1 volumio[3096]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect May 27 13:11:38 rivo1 sudo[8848]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service May 27 13:11:38 rivo1 sudo[8848]: pam_unix(sudo:session): session opened for user root by (uid=0) May 27 13:11:38 rivo1 systemd[1]: Started Volumio Tidal Connect Service. May 27 13:11:38 rivo1 sudo[8848]: pam_unix(sudo:session): session closed for user root May 27 13:11:38 rivo1 volumio[3096]: info: Executing endpoint tc_getconfig May 27 13:11:38 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig May 27 13:11:38 rivo1 vtcs[8850]: STARTING TidalConnect services, version: 1.6.1 May 27 13:11:38 rivo1 vtcs[8850]: STARTED TidalConnect services. May 27 13:11:38 rivo1 volumio[3096]: info: Executing endpoint tc_connect May 27 13:11:38 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect May 27 13:11:38 rivo1 volumio[3096]: info: Connecting to TidalConnect May 27 13:11:38 rivo1 volumio[3096]: info: CoreCommandRouter::servicePushState May 27 13:11:38 rivo1 volumio[3096]: info: CoreStateMachine::pushState May 27 13:11:38 rivo1 volumio[3096]: info: CorePlayQueue::getTrack 0 May 27 13:11:38 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 13:11:38 rivo1 volumio[3096]: info: CoreCommandRouter::volumioPushState May 27 13:11:38 rivo1 volumio[3096]: info: CoreCommandRouter::volumioGetState May 27 13:11:38 rivo1 volumio[3096]: info: CorePlayQueue::getTrack 0 May 27 13:11:38 rivo1 volumio[3096]: info: MRS: Pushing multiroomSync output update for this device May 27 13:11:38 rivo1 volumio[3096]: info: MRS: Pushing multiroomSync output May 27 13:11:38 rivo1 volumio[3096]: info: CorePlayQueue::getTrack 0 May 27 13:11:38 rivo1 volumio[3096]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received tidalconnect May 27 13:11:38 rivo1 volumio[3096]: info: CoreCommandRouter::servicePushState May 27 13:11:38 rivo1 volumio[3096]: info: CoreStateMachine::pushState May 27 13:11:38 rivo1 volumio[3096]: info: CorePlayQueue::getTrack 0 May 27 13:11:38 rivo1 volumio[3096]: info: CoreCommandRouter::volumioPushState May 27 13:11:38 rivo1 volumio[3096]: info: CoreCommandRouter::volumioGetState May 27 13:11:38 rivo1 volumio[3096]: info: CorePlayQueue::getTrack 0 May 27 13:11:38 rivo1 volumio[3096]: info: MRS: Pushing multiroomSync output update for this device May 27 13:11:38 rivo1 volumio[3096]: info: MRS: Pushing multiroomSync output May 27 13:11:38 rivo1 volumio[3096]: info: CorePlayQueue::getTrack 0 May 27 13:11:38 rivo1 volumio[3096]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received tidalconnect May 27 13:11:38 rivo1 volumio5-onboarding[3634]: time=2026-05-27T13:11:38.939+01:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.68.53:49215 @ 0x2cc5680" state=STATUS_STOPPED positionMs=110173 volume=100 May 27 13:11:38 rivo1 volumio5-onboarding[3634]: time=2026-05-27T13:11:38.939+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.68.53:49215 @ 0x2c00c30" state=STATUS_STOPPED positionMs=110173 volume=100 May 27 13:11:38 rivo1 volumio5-onboarding[3634]: time=2026-05-27T13:11:38.940+01:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.68.53:49215 @ 0x2cc5680" state=STATUS_STOPPED positionMs=110173 volume=100 May 27 13:11:38 rivo1 volumio5-onboarding[3634]: time=2026-05-27T13:11:38.940+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.68.53:49215 @ 0x2cc5680" id=tidal://song/69041902 title="You Really Got Me" May 27 13:11:38 rivo1 volumio5-onboarding[3634]: time=2026-05-27T13:11:38.940+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.68.53:49215 @ 0x2c00c30" state=STATUS_STOPPED positionMs=110173 volume=100 May 27 13:11:38 rivo1 volumio5-onboarding[3634]: time=2026-05-27T13:11:38.940+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.68.53:49215 @ 0x2c00c30" id=tidal://song/69041902 title="You Really Got Me" May 27 13:11:38 rivo1 volumio5-onboarding[3634]: time=2026-05-27T13:11:38.940+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.68.53:49215 @ 0x2cc5680" id=tidal://song/69041902 title="You Really Got Me" May 27 13:11:38 rivo1 volumio5-onboarding[3634]: time=2026-05-27T13:11:38.940+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.68.53:49215 @ 0x2c00c30" id=tidal://song/69041902 title="You Really Got Me" May 27 13:11:39 rivo1 volumio[3096]: info: TidalConnect service stoped! May 27 13:11:39 rivo1 volumio[3096]: info: TidalConnect service stoped! May 27 13:11:39 rivo1 volumio[3096]: info: CoreCommandRouter::volumioRetrieveVolumeLevels May 27 13:11:39 rivo1 volumio[3096]: info: CoreStateMachine::getcurrentVolume May 27 13:11:39 rivo1 volumio[3096]: info: CoreCommandRouter::volumioRetrievevolume May 27 13:11:39 rivo1 volumio[3096]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 27 13:11:39 rivo1 volumio[3096]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect May 27 13:11:39 rivo1 volumio[3096]: info: RAAT: Requesting Headphone Status May 27 13:11:39 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus May 27 13:11:39 rivo1 volumio[3096]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: No protocol specified May 27 13:11:39 rivo1 volumio[3096]: xcb_connection_has_error() returned true May 27 13:11:39 rivo1 sudo[8879]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service May 27 13:11:39 rivo1 sudo[8879]: pam_unix(sudo:session): session opened for user root by (uid=0) May 27 13:11:39 rivo1 volumio[3096]: info: MCU Signalled Headphone Mode Disabled May 27 13:11:39 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState May 27 13:11:39 rivo1 volumio[3096]: info: Reporting Headphone State: false May 27 13:11:39 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 13:11:39 rivo1 volumio[3096]: info: Updating RAAT Signal Path May 27 13:11:39 rivo1 sudo[8879]: pam_unix(sudo:session): session closed for user root May 27 13:11:39 rivo1 volumio[3096]: Unable to parse: May 27 13:11:39 rivo1 volumio[3096]: Simple mixer control 'Audio hdmi-out mute',0 May 27 13:11:39 rivo1 volumio[3096]: Capabilities: pswitch pswitch-joined May 27 13:11:39 rivo1 volumio[3096]: Playback channels: Mono May 27 13:11:39 rivo1 volumio[3096]: Mono: Playback [off] May 27 13:11:39 rivo1 volumio[3096]: info: VolumeController:: Volume=undefined Mute =false May 27 13:11:39 rivo1 volumio[3096]: info: CoreStateMachine::pushState May 27 13:11:39 rivo1 volumio[3096]: info: CorePlayQueue::getTrack 0 May 27 13:11:39 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 13:11:39 rivo1 volumio[3096]: info: CoreCommandRouter::volumioPushState May 27 13:11:39 rivo1 volumio[3096]: info: CoreCommandRouter::volumioGetState May 27 13:11:39 rivo1 volumio[3096]: info: CorePlayQueue::getTrack 0 May 27 13:11:39 rivo1 volumio[3096]: info: MRS: Pushing multiroomSync output update for this device May 27 13:11:39 rivo1 volumio[3096]: info: MRS: Pushing multiroomSync output May 27 13:11:39 rivo1 volumio[3096]: info: CoreStateMachine::updateTrackBlock May 27 13:11:39 rivo1 volumio[3096]: info: CorePlayQueue::getTrackBlock May 27 13:11:39 rivo1 volumio[3096]: info: CoreCommandRouter::volumioRetrievevolume May 27 13:11:39 rivo1 volumio5-onboarding[3634]: time=2026-05-27T13:11:39.476+01:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.68.53:49215 @ 0x2cc5680" state=STATUS_STOPPED positionMs=110693 volume=0 May 27 13:11:39 rivo1 volumio5-onboarding[3634]: time=2026-05-27T13:11:39.476+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.68.53:49215 @ 0x2c00c30" state=STATUS_STOPPED positionMs=110693 volume=0 May 27 13:11:39 rivo1 volumio5-onboarding[3634]: time=2026-05-27T13:11:39.477+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.68.53:49215 @ 0x2cc5680" id=tidal://song/69041902 title="You Really Got Me" May 27 13:11:39 rivo1 volumio5-onboarding[3634]: time=2026-05-27T13:11:39.477+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.68.53:49215 @ 0x2c00c30" id=tidal://song/69041902 title="You Really Got Me" May 27 13:11:39 rivo1 volumio[3096]: info: Updating RAAT Signal Path May 27 13:11:39 rivo1 volumio[3096]: Unable to parse: May 27 13:11:39 rivo1 volumio[3096]: Simple mixer control 'Audio hdmi-out mute',0 May 27 13:11:39 rivo1 volumio[3096]: Capabilities: pswitch pswitch-joined May 27 13:11:39 rivo1 volumio[3096]: Playback channels: Mono May 27 13:11:39 rivo1 volumio[3096]: Mono: Playback [off] May 27 13:11:39 rivo1 volumio[3096]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output May 27 13:11:39 rivo1 volumio[3096]: Unable to parse: May 27 13:11:39 rivo1 volumio[3096]: Simple mixer control 'Audio hdmi-out mute',0 May 27 13:11:39 rivo1 volumio[3096]: Capabilities: pswitch pswitch-joined May 27 13:11:39 rivo1 volumio[3096]: Playback channels: Mono May 27 13:11:39 rivo1 volumio[3096]: Mono: Playback [off] May 27 13:11:39 rivo1 volumio[3096]: info: VolumeController:: Volume=undefined Mute =false May 27 13:11:39 rivo1 volumio[3096]: info: CoreStateMachine::pushState May 27 13:11:39 rivo1 volumio[3096]: info: CorePlayQueue::getTrack 0 May 27 13:11:39 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 13:11:39 rivo1 volumio[3096]: info: CoreCommandRouter::volumioPushState May 27 13:11:39 rivo1 volumio[3096]: info: CoreCommandRouter::volumioGetState May 27 13:11:39 rivo1 volumio[3096]: info: CorePlayQueue::getTrack 0 May 27 13:11:39 rivo1 volumio[3096]: info: MRS: Pushing multiroomSync output update for this device May 27 13:11:39 rivo1 volumio[3096]: info: MRS: Pushing multiroomSync output May 27 13:11:39 rivo1 volumio5-onboarding[3634]: time=2026-05-27T13:11:39.595+01:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.68.53:49215 @ 0x2cc5680" state=STATUS_STOPPED positionMs=110967 volume=0 May 27 13:11:39 rivo1 volumio5-onboarding[3634]: time=2026-05-27T13:11:39.596+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.68.53:49215 @ 0x2c00c30" state=STATUS_STOPPED positionMs=110967 volume=0 May 27 13:11:39 rivo1 volumio5-onboarding[3634]: time=2026-05-27T13:11:39.596+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.68.53:49215 @ 0x2cc5680" id=tidal://song/69041902 title="You Really Got Me" May 27 13:11:39 rivo1 volumio5-onboarding[3634]: time=2026-05-27T13:11:39.596+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.68.53:49215 @ 0x2c00c30" id=tidal://song/69041902 title="You Really Got Me" May 27 13:11:39 rivo1 volumio[3096]: info: Updating RAAT Signal Path May 27 13:11:39 rivo1 volumio[3096]: info: RAAT: Requesting Headphone Status May 27 13:11:39 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus May 27 13:11:39 rivo1 volumio[3096]: info: MCU Signalled Headphone Mode Disabled May 27 13:11:39 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState May 27 13:11:39 rivo1 volumio[3096]: info: Reporting Headphone State: false May 27 13:11:39 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 13:11:39 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 27 13:11:39 rivo1 volumio[3096]: info: Updating RAAT Signal Path May 27 13:11:41 rivo1 volumio[3096]: info: CoreCommandRouter::volumioGetState May 27 13:11:41 rivo1 volumio[3096]: info: CorePlayQueue::getTrack 0 May 27 13:11:41 rivo1 volumio[3096]: info: TidalConnect service started! May 27 13:11:42 rivo1 volumio[3096]: info: TidalConnect service started! May 27 13:11:43 rivo1 volumio[3096]: info: Executing endpoint metavolumio May 27 13:11:43 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 27 13:11:43 rivo1 volumio[3096]: info: Executing endpoint metavolumio May 27 13:11:43 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 27 13:11:43 rivo1 volumio[3096]: info: Executing endpoint metavolumio May 27 13:11:43 rivo1 volumio[3096]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 27 13:11:55 rivo1 volumio[3096]: info: CorePlayQueue::getTrack 0 May 27 13:11:55 rivo1 volumio[3096]: info: CorePlayQueue::getTrack 1 May 27 13:11:55 rivo1 volumio[3096]: info: Prefetching next song May 27 13:11:55 rivo1 volumio[3096]: info: [1779883915770] ControllerTidal::prefetch May 27 13:11:55 rivo1 volumio[3096]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 27 13:11:55 rivo1 volumio[3096]: TypeError: Cannot read property 'highestSoundQuality' of undefined May 27 13:11:55 rivo1 volumio[3096]: at ControllerTidal.getProperSoundQuality (/volumio/app/plugins/music_service/tidal/tidal_real:1:19583) May 27 13:11:55 rivo1 volumio[3096]: at ControllerTidal.prefetch (/volumio/app/plugins/music_service/tidal/tidal_real:1:20287) May 27 13:11:55 rivo1 volumio[3096]: at CoreStateMachine.increasePlaybackTimer (/volumio/app/statemachine.js:464:18) May 27 13:11:55 rivo1 volumio[3096]: at listOnTimeout (internal/timers.js:557:17) May 27 13:11:55 rivo1 volumio[3096]: at processTimers (internal/timers.js:500:7) May 27 13:11:55 rivo1 volumio[3096]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 27 13:11:56 rivo1 sudo[8969]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-05-27 13:10 May 27 13:11:56 rivo1 sudo[8969]: 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"