-- Logs begin at Wed 2025-06-04 19:10:21 CEST, end at Tue 2025-06-10 21:23:46 CEST. -- Jun 10 21:22:00 rivo sudo[6694]: pam_unix(sudo:session): session closed for user root Jun 10 21:22:00 rivo qobuz-connect[12294]: 20250610 21:22:00.040 [12294.12294] INFO SampleApp: Stopping Local configuration server Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:00 rivo qobuz-connect[12294]: 20250610 21:22:00.050 [12294.12294] INFO SampleApp: shat down connection on UNIX socket Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 10 21:22:00 rivo sudo[6698]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Jun 10 21:22:00 rivo volumio[3206]: info: Not Reporting Auto name since its the default one Jun 10 21:22:00 rivo sudo[6698]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 10 21:22:00 rivo volumio[3206]: info: Not Reporting Auto name since its the default one Jun 10 21:22:00 rivo systemd[1]: qobuz-connect.service: Succeeded. Jun 10 21:22:00 rivo systemd[1]: Stopped Volumio Qobuz Connect Service. Jun 10 21:22:00 rivo systemd[1]: Started Volumio Qobuz Connect Service. Jun 10 21:22:00 rivo sudo[6698]: pam_unix(sudo:session): session closed for user root Jun 10 21:22:00 rivo sudo[6691]: pam_unix(sudo:session): session closed for user root Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 10 21:22:00 rivo volumio[3206]: info: Not Reporting Auto name since its the default one Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 10 21:22:00 rivo volumio[3206]: info: Not Reporting Auto name since its the default one Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jun 10 21:22:00 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:22:00 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:22:00 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:22:00 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 10 21:22:00 rivo volumio[3206]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Jun 10 21:22:00 rivo volumio[3206]: info: Reading ALSA contributions from plugins. Jun 10 21:22:00 rivo volumio[3206]: info: Signalling Playback active due to playback status change Jun 10 21:22:00 rivo volumio[3206]: info: Updating RAAT Signal Path Jun 10 21:22:00 rivo go-librespot[5493]: time="2025-06-10T21:22:00+02:00" level=debug msg="pause track at 24163ms" Jun 10 21:22:00 rivo volumio[3206]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Jun 10 21:22:00 rivo volumio[3206]: info: QobuzConnect: setDeactiveState invoked Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:22:00 rivo volumio[3206]: info: Executing endpoint qc_getconfig Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Jun 10 21:22:00 rivo qobuz-connect[6708]: 20250610 21:22:00.296 [6708.6708] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Jun 10 21:22:00 rivo qobuz-connect[6708]: 20250610 21:22:00.311 [6708.6708] INFO VolumeManager: [0xac7829c0]: Setting new playback volume: 75 Jun 10 21:22:00 rivo qobuz-connect[6708]: 20250610 21:22:00.311 [6708.6708] INFO VolumeManager: [0xac7829c0]: Setting new mute state: 0 Jun 10 21:22:00 rivo qobuz-connect[6708]: 20250610 21:22:00.311 [6708.6708] INFO QobuzConnect: [0xac783390]: Client initialized! Jun 10 21:22:00 rivo qobuz-connect[6708]: 20250610 21:22:00.311 [6708.6708] INFO SampleApp: Starting Avahi advertising, name: Rivo, service name: _qobuz-connect._tcp Jun 10 21:22:00 rivo qobuz-connect[6708]: 20250610 21:22:00.323 [6708.6708] INFO LocalConfigManager: [0xac7822a0]: Starting Local Configuration server Jun 10 21:22:00 rivo qobuz-connect[6708]: 20250610 21:22:00.323 [6708.6708] INFO SampleApp: Starting Local configuration server Jun 10 21:22:00 rivo qobuz-connect[6708]: 20250610 21:22:00.324 [6708.6708] INFO SampleApp: Connected to UNIX socket client 0xac777ed8 Jun 10 21:22:00 rivo go-librespot[5493]: time="2025-06-10T21:22:00+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 10 21:22:00 rivo volumio[3206]: No protocol specified Jun 10 21:22:00 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 10 21:22:00 rivo go-librespot[5493]: time="2025-06-10T21:22:00+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 10 21:22:00 rivo go-librespot[5493]: time="2025-06-10T21:22:00+02:00" level=trace msg="emitting websocket event: paused" Jun 10 21:22:00 rivo qobuz-connect[6708]: 20250610 21:22:00.446 [6708.6708] INFO SampleApp: Playback volume changed: 75 Jun 10 21:22:00 rivo volumio[3206]: No protocol specified Jun 10 21:22:00 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: raat , getAdditionalUiSection Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Jun 10 21:22:00 rivo volumio[3206]: No protocol specified Jun 10 21:22:00 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Jun 10 21:22:00 rivo sudo[6731]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Jun 10 21:22:00 rivo sudo[6731]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:22:00 rivo sudo[6731]: pam_unix(sudo:session): session closed for user root Jun 10 21:22:00 rivo sudo[6735]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Jun 10 21:22:00 rivo sudo[6735]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:22:00 rivo volumio[3206]: No protocol specified Jun 10 21:22:00 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:22:00 rivo systemd[1]: Stopping RAAT DAEMON... Jun 10 21:22:00 rivo systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM Jun 10 21:22:00 rivo systemd[1]: raat-daemon.service: Succeeded. Jun 10 21:22:00 rivo systemd[1]: Stopped RAAT DAEMON. Jun 10 21:22:00 rivo systemd[1]: Started RAAT DAEMON. Jun 10 21:22:00 rivo sudo[6735]: pam_unix(sudo:session): session closed for user root Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Jun 10 21:22:00 rivo sudo[6739]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Jun 10 21:22:00 rivo sudo[6739]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:22:00 rivo sudo[6739]: pam_unix(sudo:session): session closed for user root Jun 10 21:22:00 rivo sudo[6748]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Jun 10 21:22:00 rivo sudo[6748]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:22:00 rivo volumio[3206]: No protocol specified Jun 10 21:22:00 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:22:00 rivo kernel: aml_spdif_open Jun 10 21:22:00 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Jun 10 21:22:00 rivo kernel: spdif_a keep clk continuous Jun 10 21:22:00 rivo kernel: aml_spdif_close Jun 10 21:22:00 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Jun 10 21:22:00 rivo kernel: aml_spdif_open Jun 10 21:22:00 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Jun 10 21:22:00 rivo systemd[1]: Stopping RAAT DAEMON... Jun 10 21:22:00 rivo systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM Jun 10 21:22:00 rivo systemd[1]: raat-daemon.service: Succeeded. Jun 10 21:22:00 rivo kernel: spdif_a keep clk continuous Jun 10 21:22:00 rivo kernel: aml_spdif_close Jun 10 21:22:00 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Jun 10 21:22:00 rivo systemd[1]: Stopped RAAT DAEMON. Jun 10 21:22:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Jun 10 21:22:00 rivo systemd[1]: Started RAAT DAEMON. Jun 10 21:22:00 rivo sudo[6748]: pam_unix(sudo:session): session closed for user root Jun 10 21:22:00 rivo sudo[6754]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Jun 10 21:22:00 rivo sudo[6754]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:22:00 rivo sudo[6754]: pam_unix(sudo:session): session closed for user root Jun 10 21:22:00 rivo sudo[6767]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Jun 10 21:22:00 rivo sudo[6767]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:22:00 rivo kernel: aml_spdif_open Jun 10 21:22:00 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Jun 10 21:22:00 rivo kernel: spdif_a keep clk continuous Jun 10 21:22:00 rivo kernel: aml_spdif_close Jun 10 21:22:00 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Jun 10 21:22:00 rivo kernel: aml_spdif_open Jun 10 21:22:00 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Jun 10 21:22:00 rivo kernel: spdif_a keep clk continuous Jun 10 21:22:00 rivo kernel: aml_spdif_close Jun 10 21:22:00 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Jun 10 21:22:00 rivo systemd[1]: Stopping RAAT DAEMON... Jun 10 21:22:00 rivo systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM Jun 10 21:22:00 rivo systemd[1]: raat-daemon.service: Succeeded. Jun 10 21:22:00 rivo systemd[1]: Stopped RAAT DAEMON. Jun 10 21:22:00 rivo systemd[1]: Started RAAT DAEMON. Jun 10 21:22:01 rivo sudo[6767]: pam_unix(sudo:session): session closed for user root Jun 10 21:22:01 rivo volumio[3206]: No protocol specified Jun 10 21:22:01 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:22:01 rivo kernel: aml_spdif_open Jun 10 21:22:01 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Jun 10 21:22:01 rivo kernel: spdif_a keep clk continuous Jun 10 21:22:01 rivo kernel: aml_spdif_close Jun 10 21:22:01 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Jun 10 21:22:01 rivo kernel: aml_spdif_open Jun 10 21:22:01 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Jun 10 21:22:01 rivo kernel: spdif_a keep clk continuous Jun 10 21:22:01 rivo kernel: aml_spdif_close Jun 10 21:22:01 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Jun 10 21:22:01 rivo volumio[3206]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Jun 10 21:22:01 rivo volumio[3206]: info: QobuzConnect: QOBUZ Connect daemon connected Jun 10 21:22:01 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:22:01 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 10 21:22:01 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:22:01 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 10 21:22:01 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:22:01 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 10 21:22:01 rivo volumio[3206]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:episode:4XbpBKauLYF9RQ37yH3I1i","play_origin":"show"}} Jun 10 21:22:01 rivo volumio[3206]: SPOTIFY: PUSH STATE SPOTIFY Jun 10 21:22:01 rivo volumio[3206]: SPOTIFY: {"status":"pause","service":"spop","title":"Chabadabada chabadabada","artist":"La dernière","album":"La dernière","albumart":"https://i.scdn.co/image/ab6765630000f68d97d1f096a8b4f8221c6740be","uri":"spotify:episode:4XbpBKauLYF9RQ37yH3I1i","trackType":"spotify","seek":25000,"duration":257,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jun 10 21:22:01 rivo volumio[3206]: info: CoreCommandRouter::servicePushState Jun 10 21:22:01 rivo volumio[3206]: info: CoreStateMachine::pushState Jun 10 21:22:01 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 10 21:22:01 rivo volumio[3206]: info: CoreCommandRouter::volumioPushState Jun 10 21:22:01 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:22:01 rivo volumio[3206]: info: MRS: Pushing multiroomSync output update for this device Jun 10 21:22:01 rivo volumio[3206]: info: MRS: Pushing multiroomSync output Jun 10 21:22:01 rivo sudo[6790]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Jun 10 21:22:01 rivo sudo[6790]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:22:01 rivo volumio[3206]: info: Raat Daemon started successfully Jun 10 21:22:01 rivo volumio[3206]: info: Updating RAAT Signal Path Jun 10 21:22:01 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:22:01 rivo sudo[6790]: pam_unix(sudo:session): session closed for user root Jun 10 21:22:01 rivo volumio[3206]: info: Executing endpoint restartRAATSocket Jun 10 21:22:01 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection Jun 10 21:22:01 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:01 rivo sudo[6794]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Jun 10 21:22:01 rivo sudo[6794]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:22:01 rivo volumio[3206]: info: Asound.conf file unchanged, so no further update is needed Jun 10 21:22:01 rivo volumio[3206]: info: Output device has changed, restarting MPD Jun 10 21:22:01 rivo systemd[1]: Stopping RAAT DAEMON... Jun 10 21:22:01 rivo systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM Jun 10 21:22:01 rivo systemd[1]: raat-daemon.service: Succeeded. Jun 10 21:22:01 rivo systemd[1]: Stopped RAAT DAEMON. Jun 10 21:22:01 rivo systemd[1]: Started RAAT DAEMON. Jun 10 21:22:01 rivo sudo[6794]: pam_unix(sudo:session): session closed for user root Jun 10 21:22:01 rivo sudo[6799]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 10 21:22:01 rivo sudo[6799]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:22:01 rivo sudo[6799]: pam_unix(sudo:session): session closed for user root Jun 10 21:22:01 rivo kernel: aml_spdif_open Jun 10 21:22:01 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Jun 10 21:22:01 rivo kernel: spdif_a keep clk continuous Jun 10 21:22:01 rivo kernel: aml_spdif_close Jun 10 21:22:01 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Jun 10 21:22:01 rivo kernel: aml_spdif_open Jun 10 21:22:01 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Jun 10 21:22:01 rivo kernel: spdif_a keep clk continuous Jun 10 21:22:01 rivo kernel: aml_spdif_close Jun 10 21:22:01 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Jun 10 21:22:01 rivo volumio[3206]: info: Output device has changed, restarting Shairport Sync Jun 10 21:22:01 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:01 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 10 21:22:01 rivo sudo[6814]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 10 21:22:01 rivo sudo[6814]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:22:01 rivo systemd[1]: Stopping Music Player Daemon... Jun 10 21:22:01 rivo volumio[3206]: No protocol specified Jun 10 21:22:01 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:22:01 rivo volumio[3206]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 10 21:22:01 rivo volumio[3206]: No protocol specified Jun 10 21:22:01 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:22:01 rivo volumio[3206]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Jun 10 21:22:01 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:01 rivo volumio[3206]: info: QobuzConnect: setDeactiveState invoked Jun 10 21:22:01 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:22:01 rivo volumio[3206]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes Jun 10 21:22:01 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:01 rivo kernel: aml_spdif_open Jun 10 21:22:01 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Jun 10 21:22:01 rivo kernel: spdif_a keep clk continuous Jun 10 21:22:01 rivo kernel: aml_spdif_close Jun 10 21:22:01 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Jun 10 21:22:01 rivo volumio[3206]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes Jun 10 21:22:01 rivo sudo[6824]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Jun 10 21:22:01 rivo sudo[6824]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:22:01 rivo sudo[6824]: pam_unix(sudo:session): session closed for user root Jun 10 21:22:01 rivo sudo[6827]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Jun 10 21:22:01 rivo sudo[6827]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:22:01 rivo sudo[6827]: pam_unix(sudo:session): session closed for user root Jun 10 21:22:01 rivo sudo[6835]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Jun 10 21:22:01 rivo sudo[6835]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:22:01 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:22:01 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 10 21:22:01 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:22:01 rivo sudo[6835]: pam_unix(sudo:session): session closed for user root Jun 10 21:22:01 rivo volumio[3206]: info: Executing endpoint restartRAATSocket Jun 10 21:22:01 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection Jun 10 21:22:01 rivo sudo[6837]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Jun 10 21:22:01 rivo sudo[6837]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:22:01 rivo volumio[3206]: info: MPD Permissions set Jun 10 21:22:01 rivo volumio[3206]: info: Raat Daemon started successfully Jun 10 21:22:01 rivo volumio[3206]: info: MCU Signalled Playback Inactive Jun 10 21:22:01 rivo volumio[3206]: info: CoreStateMachine::pushState Jun 10 21:22:01 rivo systemd[1]: mpd.service: Succeeded. Jun 10 21:22:01 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 10 21:22:01 rivo volumio[3206]: info: CoreCommandRouter::volumioPushState Jun 10 21:22:01 rivo systemd[1]: Stopped Music Player Daemon. Jun 10 21:22:01 rivo go-librespot[5493]: time="2025-06-10T21:22:01+02:00" level=trace msg="sent dealer ping" Jun 10 21:22:01 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:22:01 rivo volumio[3206]: info: MRS: Pushing multiroomSync output update for this device Jun 10 21:22:01 rivo volumio[3206]: info: MRS: Pushing multiroomSync output Jun 10 21:22:01 rivo systemd[1]: Starting Music Player Daemon... Jun 10 21:22:01 rivo systemd[1]: Stopping Volumio Qobuz Connect Service... Jun 10 21:22:01 rivo qobuz-connect[6708]: 20250610 21:22:01.813 [6708.6708] INFO SampleApp: Stopping Local configuration server Jun 10 21:22:01 rivo qobuz-connect[6708]: 20250610 21:22:01.827 [6708.6708] INFO SampleApp: shat down connection on UNIX socket Jun 10 21:22:01 rivo volumio[3206]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 14 Jun 10 21:22:01 rivo systemd[1]: qobuz-connect.service: Succeeded. Jun 10 21:22:01 rivo go-librespot[5493]: time="2025-06-10T21:22:01+02:00" level=trace msg="received dealer pong" Jun 10 21:22:01 rivo systemd[1]: Stopped Volumio Qobuz Connect Service. Jun 10 21:22:01 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 10 21:22:01 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:22:01 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:22:01 rivo volumio[3206]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 10 21:22:01 rivo volumio[3206]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Jun 10 21:22:01 rivo volumio[3206]: info: QobuzConnect: setDeactiveState invoked Jun 10 21:22:01 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:22:01 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:01 rivo systemd[1]: Started Volumio Qobuz Connect Service. Jun 10 21:22:01 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:01 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:01 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:01 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:01 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:01 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:01 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:01 rivo sudo[6837]: pam_unix(sudo:session): session closed for user root Jun 10 21:22:01 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 10 21:22:01 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jun 10 21:22:01 rivo sudo[6840]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 10 21:22:01 rivo sudo[6840]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:22:02 rivo sudo[6840]: pam_unix(sudo:session): session closed for user root Jun 10 21:22:02 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:02 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 10 21:22:02 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:02 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:02 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:02 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:02 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 10 21:22:02 rivo volumio[3206]: info: Not Reporting Auto name since its the default one Jun 10 21:22:02 rivo volumio[3206]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 14 Jun 10 21:22:02 rivo volumio[3206]: info: Executing endpoint qc_getconfig Jun 10 21:22:02 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Jun 10 21:22:02 rivo qobuz-connect[6841]: 20250610 21:22:02.107 [6841.6841] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Jun 10 21:22:02 rivo qobuz-connect[6841]: 20250610 21:22:02.114 [6841.6841] INFO VolumeManager: [0xacff39c0]: Setting new playback volume: 75 Jun 10 21:22:02 rivo qobuz-connect[6841]: 20250610 21:22:02.114 [6841.6841] INFO VolumeManager: [0xacff39c0]: Setting new mute state: 0 Jun 10 21:22:02 rivo qobuz-connect[6841]: 20250610 21:22:02.114 [6841.6841] INFO QobuzConnect: [0xacff4390]: Client initialized! Jun 10 21:22:02 rivo qobuz-connect[6841]: 20250610 21:22:02.114 [6841.6841] INFO SampleApp: Starting Avahi advertising, name: Rivo, service name: _qobuz-connect._tcp Jun 10 21:22:02 rivo qobuz-connect[6841]: 20250610 21:22:02.129 [6841.6841] INFO LocalConfigManager: [0xacff32a0]: Starting Local Configuration server Jun 10 21:22:02 rivo qobuz-connect[6841]: 20250610 21:22:02.129 [6841.6841] INFO SampleApp: Starting Local configuration server Jun 10 21:22:02 rivo qobuz-connect[6841]: 20250610 21:22:02.130 [6841.6841] INFO SampleApp: Connected to UNIX socket client 0xacfe8ed8 Jun 10 21:22:02 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:02 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:02 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:02 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:02 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 10 21:22:02 rivo volumio[3206]: info: Not Reporting Auto name since its the default one Jun 10 21:22:02 rivo volumio[3206]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Jun 10 21:22:02 rivo volumio[3206]: info: QobuzConnect: QOBUZ Connect daemon connected Jun 10 21:22:02 rivo volumio[3206]: info: Starting Shairport Sync Jun 10 21:22:02 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Jun 10 21:22:02 rivo sudo[6862]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 10 21:22:02 rivo sudo[6862]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:22:02 rivo qobuz-connect[6841]: 20250610 21:22:02.256 [6841.6841] INFO SampleApp: Playback volume changed: 75 Jun 10 21:22:02 rivo systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 10 21:22:02 rivo systemd[1]: shairport-sync.service: Succeeded. Jun 10 21:22:02 rivo systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 10 21:22:02 rivo systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 10 21:22:02 rivo sudo[6862]: pam_unix(sudo:session): session closed for user root Jun 10 21:22:02 rivo volumio[3206]: No protocol specified Jun 10 21:22:02 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:22:02 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Jun 10 21:22:02 rivo sudo[6868]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Jun 10 21:22:02 rivo sudo[6868]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:22:02 rivo sudo[6868]: pam_unix(sudo:session): session closed for user root Jun 10 21:22:02 rivo sudo[6873]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Jun 10 21:22:02 rivo sudo[6873]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:22:02 rivo volumio[3206]: No protocol specified Jun 10 21:22:02 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:22:02 rivo systemd[1]: Stopping RAAT DAEMON... Jun 10 21:22:02 rivo systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM Jun 10 21:22:02 rivo systemd[1]: raat-daemon.service: Succeeded. Jun 10 21:22:02 rivo systemd[1]: Stopped RAAT DAEMON. Jun 10 21:22:02 rivo systemd[1]: Started RAAT DAEMON. Jun 10 21:22:02 rivo sudo[6873]: pam_unix(sudo:session): session closed for user root Jun 10 21:22:02 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:22:02 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:22:02 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 10 21:22:02 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:22:02 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 10 21:22:02 rivo sudo[6878]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Jun 10 21:22:02 rivo volumio[3206]: info: Shairport-Sync Started Jun 10 21:22:02 rivo sudo[6878]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:22:02 rivo volumio[3206]: info: Raat Daemon started successfully Jun 10 21:22:02 rivo volumio[3206]: info: TidalConnect service stoped! Jun 10 21:22:02 rivo sudo[6878]: pam_unix(sudo:session): session closed for user root Jun 10 21:22:02 rivo kernel: aml_spdif_open Jun 10 21:22:02 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Jun 10 21:22:02 rivo kernel: spdif_a keep clk continuous Jun 10 21:22:02 rivo kernel: aml_spdif_close Jun 10 21:22:02 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Jun 10 21:22:02 rivo kernel: aml_spdif_open Jun 10 21:22:02 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Jun 10 21:22:02 rivo volumio[3206]: info: TidalConnect service stoped! Jun 10 21:22:02 rivo kernel: spdif_a keep clk continuous Jun 10 21:22:02 rivo kernel: aml_spdif_close Jun 10 21:22:02 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Jun 10 21:22:02 rivo sudo[6884]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Jun 10 21:22:02 rivo sudo[6884]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:22:02 rivo systemd[1]: Stopping RAAT DAEMON... Jun 10 21:22:02 rivo systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM Jun 10 21:22:02 rivo systemd[1]: raat-daemon.service: Succeeded. Jun 10 21:22:02 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:22:02 rivo systemd[1]: Stopped RAAT DAEMON. Jun 10 21:22:02 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 10 21:22:02 rivo systemd[1]: Started RAAT DAEMON. Jun 10 21:22:02 rivo sudo[6884]: pam_unix(sudo:session): session closed for user root Jun 10 21:22:02 rivo volumio[3206]: info: Raat Daemon started successfully Jun 10 21:22:02 rivo kernel: aml_spdif_open Jun 10 21:22:02 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Jun 10 21:22:02 rivo kernel: spdif_a keep clk continuous Jun 10 21:22:02 rivo kernel: aml_spdif_close Jun 10 21:22:02 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Jun 10 21:22:02 rivo kernel: aml_spdif_open Jun 10 21:22:02 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Jun 10 21:22:02 rivo kernel: spdif_a keep clk continuous Jun 10 21:22:02 rivo kernel: aml_spdif_close Jun 10 21:22:02 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Jun 10 21:22:02 rivo volumio[3206]: info: Executing endpoint restartRAATSocket Jun 10 21:22:02 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection Jun 10 21:22:02 rivo volumio[3206]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 15 Jun 10 21:22:02 rivo volumio[3206]: info: TidalConnect service stoped! Jun 10 21:22:02 rivo volumio[3206]: info: TidalConnect service stoped! Jun 10 21:22:02 rivo volumio[3206]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Jun 10 21:22:02 rivo volumio[3206]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Jun 10 21:22:03 rivo sudo[6919]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Jun 10 21:22:03 rivo sudo[6919]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:22:03 rivo volumio[3206]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Jun 10 21:22:03 rivo volumio[3206]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Jun 10 21:22:03 rivo systemd[1]: Started Volumio Tidal Connect Service. Jun 10 21:22:03 rivo sudo[6919]: pam_unix(sudo:session): session closed for user root Jun 10 21:22:03 rivo sudo[6929]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Jun 10 21:22:03 rivo sudo[6929]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:22:03 rivo sudo[6929]: pam_unix(sudo:session): session closed for user root Jun 10 21:22:03 rivo volumio[3206]: info: Executing endpoint tc_getconfig Jun 10 21:22:03 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Jun 10 21:22:03 rivo vtcs[6925]: STARTING TidalConnect services, version: 1.4.0.34 Jun 10 21:22:03 rivo volumio[3206]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Jun 10 21:22:03 rivo volumio[3206]: info: CoreStateMachine::getcurrentVolume Jun 10 21:22:03 rivo volumio[3206]: info: CoreCommandRouter::volumioRetrievevolume Jun 10 21:22:03 rivo volumio[3206]: info: CoreStateMachine::pushState Jun 10 21:22:03 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 10 21:22:03 rivo volumio[3206]: info: CoreCommandRouter::volumioPushState Jun 10 21:22:03 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:22:03 rivo volumio[3206]: info: MRS: Pushing multiroomSync output update for this device Jun 10 21:22:03 rivo volumio[3206]: info: MRS: Pushing multiroomSync output Jun 10 21:22:03 rivo vtcs[6925]: STARTED TidalConnect services. Jun 10 21:22:03 rivo volumio[3206]: info: Updating RAAT Signal Path Jun 10 21:22:03 rivo volumio[3206]: info: RAAT: Requesting Headphone Status Jun 10 21:22:03 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Jun 10 21:22:03 rivo volumio[3206]: info: Executing endpoint tc_connect Jun 10 21:22:03 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Jun 10 21:22:03 rivo volumio[3206]: info: Connecting to TidalConnect Jun 10 21:22:03 rivo volumio[3206]: info: CoreCommandRouter::servicePushState Jun 10 21:22:03 rivo volumio[3206]: info: CoreStateMachine::pushState Jun 10 21:22:03 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 10 21:22:03 rivo volumio[3206]: info: CoreCommandRouter::volumioPushState Jun 10 21:22:03 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:22:03 rivo volumio[3206]: info: MRS: Pushing multiroomSync output update for this device Jun 10 21:22:03 rivo volumio[3206]: info: MRS: Pushing multiroomSync output Jun 10 21:22:03 rivo volumio[3206]: info: CoreCommandRouter::servicePushState Jun 10 21:22:03 rivo volumio[3206]: info: CoreStateMachine::pushState Jun 10 21:22:03 rivo volumio[3206]: info: CoreCommandRouter::volumioPushState Jun 10 21:22:03 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:22:03 rivo volumio[3206]: info: MRS: Pushing multiroomSync output update for this device Jun 10 21:22:03 rivo volumio[3206]: info: MRS: Pushing multiroomSync output Jun 10 21:22:03 rivo volumio[3206]: info: Updating RAAT Signal Path Jun 10 21:22:03 rivo volumio[3206]: info: Updating RAAT Signal Path Jun 10 21:22:03 rivo volumio[3206]: info: MCU Signalled Headphone Mode Disabled Jun 10 21:22:03 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Jun 10 21:22:03 rivo volumio[3206]: info: Reporting Headphone State: false Jun 10 21:22:03 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:03 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:03 rivo volumio[3206]: info: Updating RAAT Signal Path Jun 10 21:22:03 rivo volumio[3206]: info: RAAT: Requesting Headphone Status Jun 10 21:22:03 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Jun 10 21:22:03 rivo volumio[3206]: info: MCU Signalled Headphone Mode Disabled Jun 10 21:22:03 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Jun 10 21:22:03 rivo volumio[3206]: info: Reporting Headphone State: false Jun 10 21:22:03 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:03 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:03 rivo volumio[3206]: info: Updating RAAT Signal Path Jun 10 21:22:03 rivo volumio[3206]: info: RAAT: Requesting Headphone Status Jun 10 21:22:03 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Jun 10 21:22:03 rivo volumio[3206]: info: MCU Signalled Headphone Mode Disabled Jun 10 21:22:03 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Jun 10 21:22:03 rivo volumio[3206]: info: Reporting Headphone State: false Jun 10 21:22:03 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:03 rivo volumio[3206]: info: Updating RAAT Signal Path Jun 10 21:22:04 rivo volumio[3206]: info: RAAT: Requesting Headphone Status Jun 10 21:22:04 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Jun 10 21:22:04 rivo volumio[3206]: info: MCU Signalled Headphone Mode Disabled Jun 10 21:22:04 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Jun 10 21:22:04 rivo volumio[3206]: info: Reporting Headphone State: false Jun 10 21:22:04 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:04 rivo volumio[3206]: info: Updating RAAT Signal Path Jun 10 21:22:04 rivo mpd[6851]: Jun 10 21:22 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 10 21:22:04 rivo systemd[1]: Started Music Player Daemon. Jun 10 21:22:04 rivo sudo[6814]: pam_unix(sudo:session): session closed for user root Jun 10 21:22:04 rivo volumio[3206]: error: updateQueue error: null Jun 10 21:22:04 rivo volumio[3206]: info: TidalConnect service stoped! Jun 10 21:22:04 rivo volumio[3206]: info: TidalConnect service stoped! Jun 10 21:22:04 rivo volumio[3206]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Jun 10 21:22:04 rivo volumio[3206]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Jun 10 21:22:04 rivo sudo[6959]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Jun 10 21:22:04 rivo sudo[6959]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:22:04 rivo sudo[6959]: pam_unix(sudo:session): session closed for user root Jun 10 21:22:05 rivo volumio[3206]: info: RAAT: Requesting Headphone Status Jun 10 21:22:05 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Jun 10 21:22:05 rivo volumio[3206]: info: MCU Signalled Headphone Mode Disabled Jun 10 21:22:05 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Jun 10 21:22:05 rivo volumio[3206]: info: Reporting Headphone State: false Jun 10 21:22:05 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:05 rivo volumio[3206]: info: Updating RAAT Signal Path Jun 10 21:22:05 rivo volumio[3206]: info: RAAT: Requesting Headphone Status Jun 10 21:22:05 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Jun 10 21:22:05 rivo volumio[3206]: info: MCU Signalled Headphone Mode Disabled Jun 10 21:22:05 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Jun 10 21:22:05 rivo volumio[3206]: info: Reporting Headphone State: false Jun 10 21:22:05 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:22:05 rivo volumio[3206]: info: Updating RAAT Signal Path Jun 10 21:22:05 rivo volumio[3206]: info: Executing endpoint metavolumio Jun 10 21:22:05 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 10 21:22:05 rivo volumio[3206]: info: Executing endpoint metavolumio Jun 10 21:22:05 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 10 21:22:05 rivo volumio[3206]: info: Executing endpoint metavolumio Jun 10 21:22:05 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 10 21:22:06 rivo volumio[3206]: info: TidalConnect service started! Jun 10 21:22:06 rivo volumio[3206]: info: TidalConnect service started! Jun 10 21:22:07 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 10 21:22:07 rivo volumio[3206]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Jun 10 21:22:07 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Jun 10 21:22:07 rivo volumio[3206]: info: Received Get System Version Jun 10 21:22:07 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 10 21:22:07 rivo volumio[3206]: info: Received Get System Info Jun 10 21:22:07 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 10 21:22:07 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 10 21:22:07 rivo volumio[3206]: info: Discovery: Getting this device information Jun 10 21:22:07 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:22:07 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 10 21:22:07 rivo volumio[3206]: info: TidalConnect service started! Jun 10 21:22:17 rivo go-librespot[5493]: time="2025-06-10T21:22:17+02:00" level=debug msg="requested logout out from 31y2fxsk7c32lkgtuuexohb7bseu" Jun 10 21:22:17 rivo go-librespot[5493]: time="2025-06-10T21:22:17+02:00" level=debug msg="dealer connection closed" Jun 10 21:22:17 rivo go-librespot[5493]: time="2025-06-10T21:22:17+02:00" level=debug msg="dealer recv loop stopped" Jun 10 21:22:24 rivo go-librespot[5493]: time="2025-06-10T21:22:24+02:00" level=debug msg="obtained new client token: AABZvrVhcHqq/JrXcBtacV+Z2zkXpkELcGw4dQL3E+8B7efjyZfpKvwbKVWTis+RYH1kxk/zWG/UQmbiPk0y2steJumPSzki5w0zfa3ZGQgXceEINu3ibdt8sdp5NtSO1fWw7o2N2iOEUJ8PC+YDrStG8POyZs1+M33hR+20rbi3fULdmc2LzjW6xlT4VnVDQVhaDJaspRl00NpYdbWi0hKeKaUx13jAT/N2r3SjXgzN0vLWgbSAuRFd" Jun 10 21:22:24 rivo go-librespot[5493]: time="2025-06-10T21:22:24+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Jun 10 21:22:24 rivo go-librespot[5493]: time="2025-06-10T21:22:24+02:00" level=debug msg="completed keyexchange" Jun 10 21:22:24 rivo go-librespot[5493]: time="2025-06-10T21:22:24+02:00" level=debug msg="completed challenge" Jun 10 21:22:24 rivo go-librespot[5493]: time="2025-06-10T21:22:24+02:00" level=info msg="authenticated AP as 31y2fxsk7c32lkgtuuexohb7bseu" Jun 10 21:22:24 rivo go-librespot[5493]: time="2025-06-10T21:22:24+02:00" level=info msg="authenticated Login5 as 31y2fxsk7c32lkgtuuexohb7bseu" Jun 10 21:22:24 rivo go-librespot[5493]: time="2025-06-10T21:22:24+02:00" level=info msg="accepted zeroconf user 31y2fxsk7c32lkgtuuexohb7bseu from SM-G985F" Jun 10 21:22:24 rivo go-librespot[5493]: time="2025-06-10T21:22:24+02:00" level=debug msg="dealer connection opened" Jun 10 21:22:24 rivo go-librespot[5493]: time="2025-06-10T21:22:24+02:00" level=trace msg="starting accesspoint recv loop" Jun 10 21:22:24 rivo go-librespot[5493]: time="2025-06-10T21:22:24+02:00" level=trace msg="starting dealer recv loop" Jun 10 21:22:24 rivo go-librespot[5493]: time="2025-06-10T21:22:24+02:00" level=trace msg="received accesspoint ping" Jun 10 21:22:24 rivo go-librespot[5493]: time="2025-06-10T21:22:24+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jun 10 21:22:24 rivo go-librespot[5493]: time="2025-06-10T21:22:24+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jun 10 21:22:24 rivo go-librespot[5493]: time="2025-06-10T21:22:24+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jun 10 21:22:24 rivo go-librespot[5493]: time="2025-06-10T21:22:24+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jun 10 21:22:24 rivo go-librespot[5493]: time="2025-06-10T21:22:24+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jun 10 21:22:24 rivo go-librespot[5493]: time="2025-06-10T21:22:24+02:00" level=debug msg="received connection id: NTAzNGJkZjItZDA3Ni00OTE1LWFkNmQtOWZkNTYxN2YwOGFjK2RlYWxlcit0Y3A6Ly8wYWNhNDI1NS5pcC5nZXcxLnNwb3RpZnkubmV0OjU3MDArODI5NDlFODUxMTEyODNEODg3MThGMzQ2MTM3ODg3M0NGOUM5MUMwODExMEU0OTdDQkVERDJGQ0UwREY0RDAzNg==" Jun 10 21:22:24 rivo go-librespot[5493]: time="2025-06-10T21:22:24+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jun 10 21:22:24 rivo go-librespot[5493]: time="2025-06-10T21:22:24+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 338" Jun 10 21:22:24 rivo go-librespot[5493]: time="2025-06-10T21:22:24+02:00" level=trace msg="received accesspoint pong ack" Jun 10 21:22:24 rivo go-librespot[5493]: time="2025-06-10T21:22:24+02:00" level=debug msg="put connect state because NEW_DEVICE" Jun 10 21:22:25 rivo go-librespot[5493]: time="2025-06-10T21:22:25+02:00" level=debug msg="handling transfer player command from 2eae48d2d43ea2fa93a605e42ffac8675630eaba" Jun 10 21:22:25 rivo go-librespot[5493]: time="2025-06-10T21:22:25+02:00" level=debug msg="resolved context of episode" uri="spotify:show:6LkM2YRKfLWyc6uXAZpGQ1" Jun 10 21:22:25 rivo go-librespot[5493]: time="2025-06-10T21:22:25+02:00" level=trace msg="fetched new page 0 with 33 items (list: 33)" uri="spotify:show:6LkM2YRKfLWyc6uXAZpGQ1" Jun 10 21:22:25 rivo go-librespot[5493]: time="2025-06-10T21:22:25+02:00" level=debug msg="shuffled context with seed 5007717891003534047 (len: 33, keep: 28)" uri="spotify:show:6LkM2YRKfLWyc6uXAZpGQ1" Jun 10 21:22:25 rivo go-librespot[5493]: time="2025-06-10T21:22:25+02:00" level=debug msg="loading episode (paused: false, position: 27527ms)" uri="spotify:episode:4XbpBKauLYF9RQ37yH3I1i" Jun 10 21:22:25 rivo go-librespot[5493]: time="2025-06-10T21:22:25+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 10 21:22:25 rivo go-librespot[5493]: time="2025-06-10T21:22:25+02:00" level=trace msg="emitting websocket event: will_play" Jun 10 21:22:25 rivo volumio[3206]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:episode:4XbpBKauLYF9RQ37yH3I1i","play_origin":"show"}} Jun 10 21:22:25 rivo go-librespot[5493]: time="2025-06-10T21:22:25+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" Jun 10 21:22:25 rivo go-librespot[5493]: time="2025-06-10T21:22:25+02:00" level=debug msg="selected format OGG_VORBIS_96 (8e4ecf40896234e52cc56c986731accee4bfbfbe)" uri="spotify:episode:4XbpBKauLYF9RQ37yH3I1i" Jun 10 21:22:25 rivo go-librespot[5493]: time="2025-06-10T21:22:25+02:00" level=debug msg="requested aes key for file 8e4ecf40896234e52cc56c986731accee4bfbfbe, gid: 4XbpBKauLYF9RQ37yH3I1i" Jun 10 21:22:25 rivo go-librespot[5493]: time="2025-06-10T21:22:25+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1363" Jun 10 21:22:25 rivo go-librespot[5493]: time="2025-06-10T21:22:25+02:00" level=debug msg="fetched first chunk of 6, total size is 2651833 bytes" uri="spotify:episode:4XbpBKauLYF9RQ37yH3I1i" Jun 10 21:22:25 rivo go-librespot[5493]: time="2025-06-10T21:22:25+02:00" level=trace msg="seek to 27527ms (diff: 228ms, samples: 1213940, bytes: 281318)" uri="spotify:episode:4XbpBKauLYF9RQ37yH3I1i" Jun 10 21:22:25 rivo go-librespot[5493]: time="2025-06-10T21:22:25+02:00" level=debug msg="created new output device" Jun 10 21:22:25 rivo go-librespot[5493]: time="2025-06-10T21:22:25+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames" Jun 10 21:22:25 rivo go-librespot[5493]: time="2025-06-10T21:22:25+02:00" level=info msg="loaded episode \"Chabadabada chabadabada\" (paused: false, position: 27527ms, duration: 257773ms, prefetched: false)" uri="spotify:episode:4XbpBKauLYF9RQ37yH3I1i" Jun 10 21:22:25 rivo go-librespot[5493]: time="2025-06-10T21:22:25+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1124" Jun 10 21:22:25 rivo go-librespot[5493]: time="2025-06-10T21:22:25+02:00" level=debug msg="fetched chunk 1/5, size: 524288" uri="spotify:episode:4XbpBKauLYF9RQ37yH3I1i" Jun 10 21:22:25 rivo go-librespot[5493]: time="2025-06-10T21:22:25+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 10 21:22:25 rivo go-librespot[5493]: time="2025-06-10T21:22:25+02:00" level=trace msg="scheduling prefetch in 200s" Jun 10 21:22:25 rivo go-librespot[5493]: time="2025-06-10T21:22:25+02:00" level=trace msg="emitting websocket event: metadata" Jun 10 21:22:25 rivo go-librespot[5493]: time="2025-06-10T21:22:25+02:00" level=trace msg="emitting websocket event: active" Jun 10 21:22:25 rivo go-librespot[5493]: time="2025-06-10T21:22:25+02:00" level=debug msg="sending successful reply for dealer request" Jun 10 21:22:25 rivo go-librespot[5493]: time="2025-06-10T21:22:25+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jun 10 21:22:25 rivo volumio[3206]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:episode:4XbpBKauLYF9RQ37yH3I1i","name":"Chabadabada chabadabada","artist_names":["La dernière"],"album_name":"La dernière","album_cover_url":"https://i.scdn.co/image/ab6765630000f68d97d1f096a8b4f8221c6740be","position":27527,"duration":257773,"release_date":"","track_number":0,"disc_number":0}} Jun 10 21:22:25 rivo volumio[3206]: SPOTIFY: received: {"type":"active","data":null} Jun 10 21:22:25 rivo volumio[3206]: info: Aligning Spotify Volume to Volumio Volume Jun 10 21:22:25 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:22:25 rivo go-librespot[5493]: time="2025-06-10T21:22:25+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jun 10 21:22:25 rivo go-librespot[5493]: time="2025-06-10T21:22:25+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 10 21:22:25 rivo go-librespot[5493]: time="2025-06-10T21:22:25+02:00" level=trace msg="emitting websocket event: playing" Jun 10 21:22:25 rivo volumio[3206]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:episode:4XbpBKauLYF9RQ37yH3I1i","play_origin":"show"}} Jun 10 21:22:25 rivo volumio[3206]: info: Spotify is playing in volatile mode Jun 10 21:22:25 rivo volumio[3206]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 10 21:22:25 rivo volumio[3206]: SPOTIFY: UNSET VOLATILE Jun 10 21:22:25 rivo volumio[3206]: SPOTIFY: {"status":"pause","title":"Nite Flights","artist":"The Walker Brothers","album":"Nite Flights","albumart":"https://resources.tidal.com/images/36af44f6/4a6a/4d06/8b51/cae67a4fd969/1280x1280.jpg","uri":"","trackType":"tidal","codec":"flac","seek":0,"duration":262,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":false,"repeat":false,"repeatSingle":false,"consume":false,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":true,"stream":false,"updatedb":false,"volatile":true,"service":"tidalconnect"} Jun 10 21:22:25 rivo volumio[3206]: info: Setting Spotify stop after unset volatile call Jun 10 21:22:25 rivo volumio[3206]: SPOTIFY: PUSH STATE SPOTIFY Jun 10 21:22:25 rivo volumio[3206]: SPOTIFY: {"status":"play","service":"spop","title":"Chabadabada chabadabada","artist":"La dernière","album":"La dernière","albumart":"https://i.scdn.co/image/ab6765630000f68d97d1f096a8b4f8221c6740be","uri":"spotify:episode:4XbpBKauLYF9RQ37yH3I1i","trackType":"spotify","seek":27527,"duration":257,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jun 10 21:22:25 rivo volumio[3206]: info: CoreCommandRouter::servicePushState Jun 10 21:22:25 rivo volumio[3206]: info: CoreStateMachine::pushState Jun 10 21:22:25 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 10 21:22:25 rivo volumio[3206]: info: CoreCommandRouter::volumioPushState Jun 10 21:22:25 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:22:25 rivo volumio[3206]: info: MRS: Pushing multiroomSync output update for this device Jun 10 21:22:25 rivo volumio[3206]: info: MRS: Pushing multiroomSync output Jun 10 21:22:25 rivo volumio[3206]: info: Signalling Playback active due to playback status change Jun 10 21:22:25 rivo volumio[3206]: info: Updating RAAT Signal Path Jun 10 21:22:25 rivo go-librespot[5493]: time="2025-06-10T21:22:25+02:00" level=debug msg="fetched chunk 3/5, size: 524288" uri="spotify:episode:4XbpBKauLYF9RQ37yH3I1i" Jun 10 21:22:25 rivo volumio[3206]: info: MCU Signalled Playback Active Jun 10 21:22:25 rivo go-librespot[5493]: time="2025-06-10T21:22:25+02:00" level=debug msg="fetched chunk 2/5, size: 524288" uri="spotify:episode:4XbpBKauLYF9RQ37yH3I1i" Jun 10 21:22:26 rivo volumio[3206]: SPOTIFY: PUSH STATE SPOTIFY Jun 10 21:22:26 rivo volumio[3206]: SPOTIFY: {"status":"play","service":"spop","title":"Chabadabada chabadabada","artist":"La dernière","album":"La dernière","albumart":"https://i.scdn.co/image/ab6765630000f68d97d1f096a8b4f8221c6740be","uri":"spotify:episode:4XbpBKauLYF9RQ37yH3I1i","trackType":"spotify","seek":27527,"duration":257,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jun 10 21:22:26 rivo volumio[3206]: info: CoreCommandRouter::servicePushState Jun 10 21:22:26 rivo volumio[3206]: info: CoreStateMachine::pushState Jun 10 21:22:26 rivo volumio[3206]: info: CoreCommandRouter::volumioPushState Jun 10 21:22:26 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:22:26 rivo volumio[3206]: info: MRS: Pushing multiroomSync output update for this device Jun 10 21:22:26 rivo volumio[3206]: info: MRS: Pushing multiroomSync output Jun 10 21:22:26 rivo volumio[3206]: info: Signalling Playback active due to playback status change Jun 10 21:22:26 rivo volumio[3206]: info: Updating RAAT Signal Path Jun 10 21:22:26 rivo volumio[3206]: info: Spotify Stop Jun 10 21:22:26 rivo volumio[3206]: SPOTIFY: SPOTIFY STOP Jun 10 21:22:26 rivo volumio[3206]: SPOTIFY: {"status":"play","title":"Chabadabada chabadabada","artist":"La dernière","album":"La dernière","albumart":"https://i.scdn.co/image/ab6765630000f68d97d1f096a8b4f8221c6740be","uri":"spotify:episode:4XbpBKauLYF9RQ37yH3I1i","trackType":"spotify","codec":"ogg","seek":27527,"duration":257,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":true,"stream":false,"updatedb":false,"volatile":true,"service":"spop"} Jun 10 21:22:27 rivo volumio[3206]: info: Executing endpoint metavolumio Jun 10 21:22:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 10 21:22:27 rivo volumio[3206]: info: Executing endpoint metavolumio Jun 10 21:22:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 10 21:22:27 rivo volumio[3206]: info: Executing endpoint metavolumio Jun 10 21:22:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 10 21:22:31 rivo volumio[3206]: error: Failed request for metavolumio API Jun 10 21:22:31 rivo go-librespot[5493]: time="2025-06-10T21:22:31+02:00" level=debug msg="skipping dealer message" uri="hm://herodotus/uri/spotify:episode:4XbpBKauLYF9RQ37yH3I1i/resume-point-revision/50deb52a-0c3c-4801-8bfb-2c9894aadcdb" Jun 10 21:22:31 rivo go-librespot[5493]: time="2025-06-10T21:22:31+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 286" Jun 10 21:22:44 rivo go-librespot[5493]: time="2025-06-10T21:22:44+02:00" level=debug msg="handling play player command from 2eae48d2d43ea2fa93a605e42ffac8675630eaba" Jun 10 21:22:44 rivo go-librespot[5493]: time="2025-06-10T21:22:44+02:00" level=debug msg="resolved context of track" uri="spotify:playlist:37i9dQZF1E4xzBheJXwm4g" Jun 10 21:22:44 rivo go-librespot[5493]: time="2025-06-10T21:22:44+02:00" level=trace msg="fetched new page 0 with 50 items (list: 50)" uri="spotify:playlist:37i9dQZF1E4xzBheJXwm4g" Jun 10 21:22:44 rivo go-librespot[5493]: time="2025-06-10T21:22:44+02:00" level=debug msg="loading track (paused: false, position: 1ms)" uri="spotify:track:29rv9UrUEQRJ8ojCYFTxlh" Jun 10 21:22:44 rivo go-librespot[5493]: time="2025-06-10T21:22:44+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 10 21:22:44 rivo go-librespot[5493]: time="2025-06-10T21:22:44+02:00" level=trace msg="emitting websocket event: will_play" Jun 10 21:22:44 rivo volumio[3206]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:29rv9UrUEQRJ8ojCYFTxlh","play_origin":"playlist"}} Jun 10 21:22:44 rivo go-librespot[5493]: time="2025-06-10T21:22:44+02:00" level=debug msg="selected format OGG_VORBIS_320 (ac9736dfe427bc2d6083bb1a27c5962e7b3235b1)" uri="spotify:track:29rv9UrUEQRJ8ojCYFTxlh" Jun 10 21:22:44 rivo go-librespot[5493]: time="2025-06-10T21:22:44+02:00" level=debug msg="requested aes key for file ac9736dfe427bc2d6083bb1a27c5962e7b3235b1, gid: 29rv9UrUEQRJ8ojCYFTxlh" Jun 10 21:22:45 rivo go-librespot[5493]: time="2025-06-10T21:22:45+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 162" Jun 10 21:22:45 rivo go-librespot[5493]: time="2025-06-10T21:22:45+02:00" level=debug msg="fetched first chunk of 16, total size is 8229888 bytes" uri="spotify:track:29rv9UrUEQRJ8ojCYFTxlh" Jun 10 21:22:45 rivo go-librespot[5493]: time="2025-06-10T21:22:45+02:00" level=trace msg="seek to 1ms (diff: 1ms, samples: 44, bytes: 0)" uri="spotify:track:29rv9UrUEQRJ8ojCYFTxlh" Jun 10 21:22:45 rivo go-librespot[5493]: time="2025-06-10T21:22:45+02:00" level=info msg="loaded track \"La chanson de Satie\" (paused: false, position: 1ms, duration: 227986ms, prefetched: false)" uri="spotify:track:29rv9UrUEQRJ8ojCYFTxlh" Jun 10 21:22:45 rivo go-librespot[5493]: time="2025-06-10T21:22:45+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 10 21:22:45 rivo go-librespot[5493]: time="2025-06-10T21:22:45+02:00" level=trace msg="scheduling prefetch in 198s" Jun 10 21:22:45 rivo go-librespot[5493]: time="2025-06-10T21:22:45+02:00" level=trace msg="emitting websocket event: metadata" Jun 10 21:22:45 rivo go-librespot[5493]: time="2025-06-10T21:22:45+02:00" level=debug msg="sending successful reply for dealer request" Jun 10 21:22:45 rivo volumio[3206]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:29rv9UrUEQRJ8ojCYFTxlh","name":"La chanson de Satie","artist_names":["Arthur H","Feist"],"album_name":"Adieu Tristesse","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02f3d572f77a6cd06727215337","position":1,"duration":227986,"release_date":"year:2005 month:1 day:1","track_number":2,"disc_number":1}} Jun 10 21:22:45 rivo go-librespot[5493]: time="2025-06-10T21:22:45+02:00" level=debug msg="skipping dealer message" uri=playback-settings/content-settings-update Jun 10 21:22:45 rivo go-librespot[5493]: time="2025-06-10T21:22:45+02:00" level=debug msg="fetched chunk 2/15, size: 524288" uri="spotify:track:29rv9UrUEQRJ8ojCYFTxlh" Jun 10 21:22:45 rivo go-librespot[5493]: time="2025-06-10T21:22:45+02:00" level=debug msg="fetched chunk 1/15, size: 524288" uri="spotify:track:29rv9UrUEQRJ8ojCYFTxlh" Jun 10 21:22:45 rivo go-librespot[5493]: time="2025-06-10T21:22:45+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 10 21:22:45 rivo go-librespot[5493]: time="2025-06-10T21:22:45+02:00" level=trace msg="emitting websocket event: playing" Jun 10 21:22:45 rivo volumio[3206]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:29rv9UrUEQRJ8ojCYFTxlh","play_origin":"playlist"}} Jun 10 21:22:45 rivo volumio[3206]: SPOTIFY: PUSH STATE SPOTIFY Jun 10 21:22:45 rivo volumio[3206]: SPOTIFY: {"status":"play","service":"spop","title":"La chanson de Satie","artist":"Arthur H, Feist","album":"Adieu Tristesse","albumart":"https://i.scdn.co/image/ab67616d00001e02f3d572f77a6cd06727215337","uri":"spotify:track:29rv9UrUEQRJ8ojCYFTxlh","trackType":"spotify","seek":1,"duration":227,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jun 10 21:22:45 rivo volumio[3206]: info: CoreCommandRouter::servicePushState Jun 10 21:22:45 rivo volumio[3206]: info: CoreStateMachine::pushState Jun 10 21:22:45 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 10 21:22:45 rivo volumio[3206]: info: CoreCommandRouter::volumioPushState Jun 10 21:22:45 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:22:45 rivo volumio[3206]: info: MRS: Pushing multiroomSync output update for this device Jun 10 21:22:45 rivo volumio[3206]: info: MRS: Pushing multiroomSync output Jun 10 21:22:45 rivo volumio[3206]: info: Signalling Playback active due to playback status change Jun 10 21:22:45 rivo volumio[3206]: info: [LastFM] Current track has sufficient metadata: title (La chanson de Satie) and artist (Arthur H, Feist) passed on explicitly Jun 10 21:22:45 rivo volumio[3206]: error: [LastFM] plugin is not authenticated, please retry, or track info could not be determined (very rare) Jun 10 21:22:45 rivo go-librespot[5493]: time="2025-06-10T21:22:45+02:00" level=debug msg="fetched chunk 3/15, size: 524288" uri="spotify:track:29rv9UrUEQRJ8ojCYFTxlh" Jun 10 21:22:45 rivo volumio[3206]: info: Updating RAAT Signal Path Jun 10 21:22:45 rivo volumio[3206]: SPOTIFY: PUSH STATE SPOTIFY Jun 10 21:22:45 rivo volumio[3206]: SPOTIFY: {"status":"play","service":"spop","title":"La chanson de Satie","artist":"Arthur H, Feist","album":"Adieu Tristesse","albumart":"https://i.scdn.co/image/ab67616d00001e02f3d572f77a6cd06727215337","uri":"spotify:track:29rv9UrUEQRJ8ojCYFTxlh","trackType":"spotify","seek":1,"duration":227,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jun 10 21:22:45 rivo volumio[3206]: info: CoreCommandRouter::servicePushState Jun 10 21:22:45 rivo volumio[3206]: info: CoreStateMachine::pushState Jun 10 21:22:45 rivo volumio[3206]: info: CoreCommandRouter::volumioPushState Jun 10 21:22:45 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:22:45 rivo volumio[3206]: info: MRS: Pushing multiroomSync output update for this device Jun 10 21:22:45 rivo volumio[3206]: info: MRS: Pushing multiroomSync output Jun 10 21:22:45 rivo volumio[3206]: info: Signalling Playback active due to playback status change Jun 10 21:22:45 rivo volumio[3206]: info: Updating RAAT Signal Path Jun 10 21:22:47 rivo volumio[3206]: info: Executing endpoint metavolumio Jun 10 21:22:47 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 10 21:22:47 rivo volumio[3206]: info: Executing endpoint metavolumio Jun 10 21:22:47 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 10 21:22:47 rivo volumio[3206]: info: Executing endpoint metavolumio Jun 10 21:22:47 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 10 21:22:52 rivo go-librespot[5493]: time="2025-06-10T21:22:52+02:00" level=debug msg="handling seek_to player command from 2eae48d2d43ea2fa93a605e42ffac8675630eaba" Jun 10 21:22:52 rivo go-librespot[5493]: time="2025-06-10T21:22:52+02:00" level=debug msg="seek track to 89600ms" Jun 10 21:22:52 rivo go-librespot[5493]: time="2025-06-10T21:22:52+02:00" level=debug msg="fetched chunk 6/15, size: 524288" uri="spotify:track:29rv9UrUEQRJ8ojCYFTxlh" Jun 10 21:22:52 rivo go-librespot[5493]: time="2025-06-10T21:22:52+02:00" level=trace msg="seek to 89600ms (diff: 223ms, samples: 3951360, bytes: 3170168)" uri="spotify:track:29rv9UrUEQRJ8ojCYFTxlh" Jun 10 21:22:52 rivo go-librespot[5493]: time="2025-06-10T21:22:52+02:00" level=debug msg="fetched chunk 7/15, size: 524288" uri="spotify:track:29rv9UrUEQRJ8ojCYFTxlh" Jun 10 21:22:52 rivo go-librespot[5493]: time="2025-06-10T21:22:52+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 10 21:22:52 rivo go-librespot[5493]: time="2025-06-10T21:22:52+02:00" level=trace msg="scheduling prefetch in 108s" Jun 10 21:22:52 rivo go-librespot[5493]: time="2025-06-10T21:22:52+02:00" level=trace msg="emitting websocket event: seek" Jun 10 21:22:52 rivo go-librespot[5493]: time="2025-06-10T21:22:52+02:00" level=debug msg="sending successful reply for dealer request" Jun 10 21:22:52 rivo volumio[3206]: SPOTIFY: received: {"type":"seek","data":{"uri":"spotify:track:29rv9UrUEQRJ8ojCYFTxlh","position":89600,"duration":227986,"play_origin":"playlist"}} Jun 10 21:22:52 rivo volumio[3206]: SPOTIFY: PUSH STATE SPOTIFY Jun 10 21:22:52 rivo volumio[3206]: SPOTIFY: {"status":"play","service":"spop","title":"La chanson de Satie","artist":"Arthur H, Feist","album":"Adieu Tristesse","albumart":"https://i.scdn.co/image/ab67616d00001e02f3d572f77a6cd06727215337","uri":"spotify:track:29rv9UrUEQRJ8ojCYFTxlh","trackType":"spotify","seek":89600,"duration":227,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jun 10 21:22:52 rivo volumio[3206]: info: CoreCommandRouter::servicePushState Jun 10 21:22:52 rivo volumio[3206]: info: CoreStateMachine::pushState Jun 10 21:22:52 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 10 21:22:52 rivo volumio[3206]: info: CoreCommandRouter::volumioPushState Jun 10 21:22:52 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:22:52 rivo volumio[3206]: info: MRS: Pushing multiroomSync output update for this device Jun 10 21:22:52 rivo go-librespot[5493]: time="2025-06-10T21:22:52+02:00" level=debug msg="fetched chunk 8/15, size: 524288" uri="spotify:track:29rv9UrUEQRJ8ojCYFTxlh" Jun 10 21:22:52 rivo volumio[3206]: info: MRS: Pushing multiroomSync output Jun 10 21:22:52 rivo volumio[3206]: info: Signalling Playback active due to playback status change Jun 10 21:22:52 rivo volumio[3206]: info: Updating RAAT Signal Path Jun 10 21:22:52 rivo go-librespot[5493]: time="2025-06-10T21:22:52+02:00" level=debug msg="fetched chunk 9/15, size: 524288" uri="spotify:track:29rv9UrUEQRJ8ojCYFTxlh" Jun 10 21:22:54 rivo go-librespot[5493]: time="2025-06-10T21:22:54+02:00" level=trace msg="sent dealer ping" Jun 10 21:22:54 rivo go-librespot[5493]: time="2025-06-10T21:22:54+02:00" level=trace msg="received dealer pong" Jun 10 21:22:57 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 10 21:22:57 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 10 21:22:57 rivo volumio[3206]: info: Discovery: Getting this device information Jun 10 21:22:57 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:22:57 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 10 21:22:57 rivo volumio[3206]: verbose: New Socket.io Connection to 192.168.1.124:3000 from 192.168.1.27 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 10 Jun 10 21:22:57 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:22:57 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jun 10 21:22:57 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jun 10 21:22:58 rivo volumio[3206]: verbose: New Socket.io Connection to 192.168.1.124 from 192.168.1.27 UA: Mozilla/5.0 (Linux; Android 13; SM-G985F Build/TP1A.220624.014; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.125 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 11 Jun 10 21:22:58 rivo volumio[3206]: verbose: New Socket.io Connection to 192.168.1.124 from 192.168.1.27 UA: Mozilla/5.0 (Linux; Android 13; SM-G985F Build/TP1A.220624.014; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.125 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 12 Jun 10 21:22:58 rivo volumio[3206]: verbose: New Socket.io Connection to 192.168.1.124 from 192.168.1.27 UA: Mozilla/5.0 (Linux; Android 13; SM-G985F Build/TP1A.220624.014; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.125 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 13 Jun 10 21:22:58 rivo volumio[3206]: verbose: New Socket.io Connection to 192.168.1.124 from 192.168.1.27 UA: Mozilla/5.0 (Linux; Android 13; SM-G985F Build/TP1A.220624.014; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.125 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 14 Jun 10 21:22:58 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 10 21:22:58 rivo volumio[3206]: info: CoreCommandRouter::volumioGetVisibleSources Jun 10 21:22:58 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 10 21:22:58 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:22:58 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jun 10 21:22:58 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 10 21:22:58 rivo volumio[3206]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Jun 10 21:22:58 rivo volumio[3206]: info: Received Get System Info Jun 10 21:22:58 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 10 21:22:58 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 10 21:22:58 rivo volumio[3206]: info: Discovery: Getting this device information Jun 10 21:22:58 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:22:58 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 10 21:22:58 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:22:58 rivo volumio[3206]: info: Listing playlists Jun 10 21:22:58 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jun 10 21:23:00 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:00 rivo volumio[3206]: verbose: New Socket.io Connection to 192.168.1.124:3000 from 192.168.1.27 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 15 Jun 10 21:23:00 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jun 10 21:23:00 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jun 10 21:23:00 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:00 rivo sudo[7133]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 10 21:23:00 rivo sudo[7133]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:00 rivo sudo[7133]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:00 rivo sudo[7137]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 10 21:23:00 rivo sudo[7137]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:00 rivo sudo[7137]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:01 rivo volumio[3206]: verbose: New Socket.io Connection to 192.168.1.124 from 192.168.1.27 UA: Mozilla/5.0 (Linux; Android 13; SM-G985F Build/TP1A.220624.014; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.125 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 16 Jun 10 21:23:01 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 10 21:23:01 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jun 10 21:23:01 rivo sudo[7141]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 10 21:23:01 rivo sudo[7141]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:01 rivo sudo[7141]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:01 rivo sudo[7145]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 10 21:23:01 rivo sudo[7145]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:01 rivo sudo[7145]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:01 rivo volumio[3206]: verbose: New Socket.io Connection to 192.168.1.124 from 192.168.1.27 UA: Mozilla/5.0 (Linux; Android 13; SM-G985F Build/TP1A.220624.014; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.125 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 17 Jun 10 21:23:01 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 10 21:23:01 rivo volumio[3206]: info: CoreCommandRouter::volumioGetVisibleSources Jun 10 21:23:01 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 10 21:23:01 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:01 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jun 10 21:23:01 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 10 21:23:01 rivo volumio[3206]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Jun 10 21:23:01 rivo volumio[3206]: info: Received Get System Info Jun 10 21:23:01 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 10 21:23:01 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 10 21:23:01 rivo volumio[3206]: info: Discovery: Getting this device information Jun 10 21:23:01 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:01 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 10 21:23:01 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:01 rivo volumio[3206]: info: Listing playlists Jun 10 21:23:01 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jun 10 21:23:01 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 10 21:23:01 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jun 10 21:23:03 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jun 10 21:23:03 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 10 21:23:03 rivo volumio[3206]: info: Received Get System Info Jun 10 21:23:03 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 10 21:23:03 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 10 21:23:03 rivo volumio[3206]: info: Discovery: Getting this device information Jun 10 21:23:03 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:03 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 10 21:23:04 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 10 21:23:04 rivo volumio[3206]: info: Received Get System Info Jun 10 21:23:04 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 10 21:23:04 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 10 21:23:04 rivo volumio[3206]: info: Discovery: Getting this device information Jun 10 21:23:04 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:04 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 10 21:23:06 rivo go-librespot[5493]: time="2025-06-10T21:23:06+02:00" level=debug msg="fetched chunk 10/15, size: 524288" uri="spotify:track:29rv9UrUEQRJ8ojCYFTxlh" Jun 10 21:23:11 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:12 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jun 10 21:23:12 rivo sudo[7166]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 10 21:23:12 rivo sudo[7166]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:12 rivo sudo[7166]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:12 rivo sudo[7169]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 10 21:23:12 rivo sudo[7169]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:12 rivo sudo[7169]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:12 rivo volumio[3206]: verbose: New Socket.io Connection to 192.168.1.124 from 192.168.1.27 UA: Mozilla/5.0 (Linux; Android 13; SM-G985F Build/TP1A.220624.014; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.125 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 18 Jun 10 21:23:12 rivo sudo[7174]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 10 21:23:12 rivo sudo[7174]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:12 rivo sudo[7174]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:12 rivo sudo[7178]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 10 21:23:12 rivo sudo[7178]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:12 rivo sudo[7178]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:12 rivo volumio[3206]: verbose: New Socket.io Connection to 192.168.1.124 from 192.168.1.27 UA: Mozilla/5.0 (Linux; Android 13; SM-G985F Build/TP1A.220624.014; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.125 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 19 Jun 10 21:23:13 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 10 21:23:13 rivo volumio[3206]: info: CoreCommandRouter::volumioGetVisibleSources Jun 10 21:23:13 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 10 21:23:13 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:13 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jun 10 21:23:13 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 10 21:23:13 rivo volumio[3206]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Jun 10 21:23:13 rivo volumio[3206]: info: Received Get System Info Jun 10 21:23:13 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 10 21:23:13 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 10 21:23:13 rivo volumio[3206]: info: Discovery: Getting this device information Jun 10 21:23:13 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:13 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 10 21:23:13 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:13 rivo volumio[3206]: info: Listing playlists Jun 10 21:23:13 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jun 10 21:23:13 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 10 21:23:13 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jun 10 21:23:13 rivo volumio[3206]: info: CoreCommandRouter::volumioGetQueue Jun 10 21:23:13 rivo volumio[3206]: info: CoreStateMachine::getQueue Jun 10 21:23:13 rivo volumio[3206]: info: CorePlayQueue::getQueue Jun 10 21:23:14 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jun 10 21:23:14 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 10 21:23:14 rivo volumio[3206]: info: Received Get System Info Jun 10 21:23:14 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 10 21:23:14 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 10 21:23:14 rivo volumio[3206]: info: Discovery: Getting this device information Jun 10 21:23:14 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:14 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 10 21:23:16 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 10 21:23:16 rivo volumio[3206]: info: Received Get System Info Jun 10 21:23:16 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 10 21:23:16 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 10 21:23:16 rivo volumio[3206]: info: Discovery: Getting this device information Jun 10 21:23:16 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:16 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 10 21:23:16 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:16 rivo sudo[7201]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 10 21:23:16 rivo sudo[7201]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:16 rivo sudo[7201]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:16 rivo sudo[7206]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 10 21:23:16 rivo sudo[7206]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:16 rivo sudo[7206]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:16 rivo volumio[3206]: verbose: New Socket.io Connection to 192.168.1.124 from 192.168.1.27 UA: Mozilla/5.0 (Linux; Android 13; SM-G985F Build/TP1A.220624.014; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.125 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 20 Jun 10 21:23:17 rivo sudo[7210]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 10 21:23:17 rivo sudo[7210]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:17 rivo sudo[7210]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:17 rivo sudo[7214]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 10 21:23:17 rivo sudo[7214]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:17 rivo sudo[7214]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:17 rivo volumio[3206]: verbose: New Socket.io Connection to 192.168.1.124 from 192.168.1.27 UA: Mozilla/5.0 (Linux; Android 13; SM-G985F Build/TP1A.220624.014; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.125 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 21 Jun 10 21:23:17 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 10 21:23:17 rivo volumio[3206]: info: CoreCommandRouter::volumioGetVisibleSources Jun 10 21:23:17 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 10 21:23:17 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:17 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jun 10 21:23:17 rivo volumio[3206]: info: CoreCommandRouter::volumioGetQueue Jun 10 21:23:17 rivo volumio[3206]: info: CoreStateMachine::getQueue Jun 10 21:23:17 rivo volumio[3206]: info: CorePlayQueue::getQueue Jun 10 21:23:17 rivo volumio[3206]: info: Listing playlists Jun 10 21:23:17 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 10 21:23:17 rivo volumio[3206]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Jun 10 21:23:17 rivo volumio[3206]: info: Received Get System Info Jun 10 21:23:17 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 10 21:23:17 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 10 21:23:17 rivo volumio[3206]: info: Discovery: Getting this device information Jun 10 21:23:17 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:17 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 10 21:23:17 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:17 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jun 10 21:23:17 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 10 21:23:17 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jun 10 21:23:19 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 10 21:23:19 rivo volumio[3206]: info: Received Get System Info Jun 10 21:23:19 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 10 21:23:19 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 10 21:23:19 rivo volumio[3206]: info: Discovery: Getting this device information Jun 10 21:23:19 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:19 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 10 21:23:19 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jun 10 21:23:20 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 10 21:23:20 rivo volumio[3206]: info: Received Get System Info Jun 10 21:23:20 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 10 21:23:20 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 10 21:23:20 rivo volumio[3206]: info: Discovery: Getting this device information Jun 10 21:23:20 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:20 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 10 21:23:20 rivo volumio[3206]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 10 21:23:20 rivo volumio[3206]: No protocol specified Jun 10 21:23:20 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:23:20 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Jun 10 21:23:20 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 10 21:23:20 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 10 21:23:20 rivo go-librespot[5493]: time="2025-06-10T21:23:20+02:00" level=debug msg="fetched chunk 11/15, size: 524288" uri="spotify:track:29rv9UrUEQRJ8ojCYFTxlh" Jun 10 21:23:20 rivo volumio[3206]: No protocol specified Jun 10 21:23:20 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:23:20 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 10 21:23:20 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 10 21:23:20 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 10 21:23:20 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 10 21:23:20 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 10 21:23:20 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 10 21:23:20 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 10 21:23:20 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Jun 10 21:23:20 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jun 10 21:23:20 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: raat , getAdditionalUiSection Jun 10 21:23:20 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:20 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:21 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 10 21:23:21 rivo volumio[3206]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Jun 10 21:23:21 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Jun 10 21:23:21 rivo volumio[3206]: info: Received Get System Version Jun 10 21:23:21 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 10 21:23:21 rivo volumio[3206]: info: Received Get System Info Jun 10 21:23:21 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 10 21:23:21 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 10 21:23:21 rivo volumio[3206]: info: Discovery: Getting this device information Jun 10 21:23:21 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:21 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 10 21:23:24 rivo volumio[3206]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Jun 10 21:23:24 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Jun 10 21:23:24 rivo volumio[3206]: info: Preparing to save Alsa Options, stopping services first Jun 10 21:23:24 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:24 rivo volumio[3206]: info: CoreCommandRouter::volumioPause Jun 10 21:23:24 rivo volumio[3206]: info: CoreStateMachine::pause Jun 10 21:23:24 rivo volumio[3206]: info: CoreStateMachine::stPlaybackTimer Jun 10 21:23:24 rivo volumio[3206]: info: CoreStateMachine::servicePause Jun 10 21:23:24 rivo volumio[3206]: info: CoreCommandRouter::servicePause Jun 10 21:23:24 rivo volumio[3206]: info: Spotify Received pause Jun 10 21:23:24 rivo volumio[3206]: SPOTIFY: SPOTIFY PAUSE Jun 10 21:23:24 rivo volumio[3206]: SPOTIFY: {"status":"play","title":"La chanson de Satie","artist":"Arthur H, Feist","album":"Adieu Tristesse","albumart":"https://i.scdn.co/image/ab67616d00001e02f3d572f77a6cd06727215337","uri":"spotify:track:29rv9UrUEQRJ8ojCYFTxlh","trackType":"spotify","codec":"ogg","seek":89600,"duration":227,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":true,"stream":false,"updatedb":false,"volatile":true,"service":"spop"} Jun 10 21:23:24 rivo volumio[3206]: info: Sending Spotify command to local API: /player/pause Jun 10 21:23:24 rivo volumio[3206]: info: Saving Audio Output to: {"output_device":{"value":"5","label":"MUSICIAN USB HiRes Audio"}} Jun 10 21:23:24 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 10 21:23:24 rivo volumio[3206]: No protocol specified Jun 10 21:23:24 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:23:24 rivo volumio[3206]: No protocol specified Jun 10 21:23:24 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:23:24 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 10 21:23:24 rivo go-librespot[5493]: time="2025-06-10T21:23:24+02:00" level=trace msg="sent dealer ping" Jun 10 21:23:24 rivo volumio[3206]: No protocol specified Jun 10 21:23:24 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:23:24 rivo volumio[3206]: info: Setting mixer PCM for card MUSICIAN USB HiRes Audio Jun 10 21:23:24 rivo volumio[3206]: info: QobuzConnect: setDeactiveState invoked Jun 10 21:23:24 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:24 rivo volumio[3206]: info: Reconfiguring and Restarting RAAT Plugin due to audio path changes Jun 10 21:23:24 rivo vtcs[6925]: [2025-06-10 21:23:24.924] [tisoc] [warning] [SessionManagerImpl.cpp:243] Illegal State: IDLE Jun 10 21:23:24 rivo vtcs[6925]: [2025-06-10 21:23:24.925] [tisoc] [error] [SpkconServer.cpp:376] recv error. socket disconnected Jun 10 21:23:24 rivo vtcs[6925]: [2025-06-10 21:23:24.925] [tisoc] [error] [SpkconServer.cpp:473] socket write error. fd=3 errorno=32 error=Broken pipe Jun 10 21:23:24 rivo go-librespot[5493]: time="2025-06-10T21:23:24+02:00" level=trace msg="received dealer pong" Jun 10 21:23:24 rivo volumio[3206]: info: Reconfiguring and Restarting RAAT Plugin due to audio path changes Jun 10 21:23:24 rivo sudo[7295]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Jun 10 21:23:24 rivo sudo[7295]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:25 rivo systemd[1]: Stopping Volumio Tidal Connect Service... Jun 10 21:23:25 rivo systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM Jun 10 21:23:25 rivo systemd[1]: vtcs.service: Succeeded. Jun 10 21:23:25 rivo systemd[1]: Stopped Volumio Tidal Connect Service. Jun 10 21:23:25 rivo sudo[7295]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:25 rivo volumio[3206]: No protocol specified Jun 10 21:23:25 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::volumioUpdateVolumeSettings Jun 10 21:23:25 rivo volumio[3206]: info: Updating Volume Controller Parameters: Device: 5 Name: MUSICIAN USB HiRes Audio Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Jun 10 21:23:25 rivo volumio[3206]: info: Disabling external Volume Control Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 10 21:23:25 rivo volumio[3206]: info: Preparing to generate the ALSA configuration file Jun 10 21:23:25 rivo sudo[7302]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Jun 10 21:23:25 rivo sudo[7302]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:25 rivo sudo[7302]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:25 rivo volumio[3206]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Jun 10 21:23:25 rivo volumio[3206]: info: Reading ALSA contributions from plugins. Jun 10 21:23:25 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:23:25 rivo go-librespot[5493]: time="2025-06-10T21:23:25+02:00" level=debug msg="pause track at 121858ms" Jun 10 21:23:25 rivo sudo[7309]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Jun 10 21:23:25 rivo sudo[7309]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:25 rivo volumio[3206]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: No protocol specified Jun 10 21:23:25 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:23:25 rivo sudo[7309]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:25 rivo sudo[7312]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Jun 10 21:23:25 rivo sudo[7312]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:25 rivo systemd[1]: Stopping Volumio Qobuz Connect Service... Jun 10 21:23:25 rivo qobuz-connect[6841]: 20250610 21:23:25.349 [6841.6841] INFO SampleApp: Stopping Local configuration server Jun 10 21:23:25 rivo qobuz-connect[6841]: 20250610 21:23:25.360 [6841.6841] INFO SampleApp: shat down connection on UNIX socket Jun 10 21:23:25 rivo systemd[1]: qobuz-connect.service: Succeeded. Jun 10 21:23:25 rivo systemd[1]: Stopped Volumio Qobuz Connect Service. Jun 10 21:23:25 rivo systemd[1]: Started Volumio Qobuz Connect Service. Jun 10 21:23:25 rivo sudo[7312]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:25 rivo go-librespot[5493]: time="2025-06-10T21:23:25+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 10 21:23:25 rivo volumio[3206]: No protocol specified Jun 10 21:23:25 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 10 21:23:25 rivo go-librespot[5493]: time="2025-06-10T21:23:25+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 10 21:23:25 rivo go-librespot[5493]: time="2025-06-10T21:23:25+02:00" level=trace msg="emitting websocket event: paused" Jun 10 21:23:25 rivo volumio[3206]: No protocol specified Jun 10 21:23:25 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: raat , getAdditionalUiSection Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 10 21:23:25 rivo volumio[3206]: info: Not Reporting Auto name since its the default one Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 10 21:23:25 rivo volumio[3206]: info: Not Reporting Auto name since its the default one Jun 10 21:23:25 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:23:25 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 10 21:23:25 rivo volumio[3206]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:29rv9UrUEQRJ8ojCYFTxlh","play_origin":"playlist"}} Jun 10 21:23:25 rivo volumio[3206]: SPOTIFY: PUSH STATE SPOTIFY Jun 10 21:23:25 rivo volumio[3206]: SPOTIFY: {"status":"pause","service":"spop","title":"La chanson de Satie","artist":"Arthur H, Feist","album":"Adieu Tristesse","albumart":"https://i.scdn.co/image/ab67616d00001e02f3d572f77a6cd06727215337","uri":"spotify:track:29rv9UrUEQRJ8ojCYFTxlh","trackType":"spotify","seek":122600,"duration":227,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::servicePushState Jun 10 21:23:25 rivo volumio[3206]: info: CoreStateMachine::pushState Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::volumioPushState Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:25 rivo volumio[3206]: info: MRS: Pushing multiroomSync output update for this device Jun 10 21:23:25 rivo volumio[3206]: info: MRS: Pushing multiroomSync output Jun 10 21:23:25 rivo volumio[3206]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Jun 10 21:23:25 rivo volumio[3206]: info: QobuzConnect: setDeactiveState invoked Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:25 rivo volumio[3206]: info: VolumeController:: Volume=undefined Mute =false Jun 10 21:23:25 rivo volumio[3206]: info: CoreStateMachine::pushState Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::volumioPushState Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:25 rivo volumio[3206]: info: MRS: Pushing multiroomSync output update for this device Jun 10 21:23:25 rivo volumio[3206]: info: MRS: Pushing multiroomSync output Jun 10 21:23:25 rivo volumio[3206]: SPOTIFY: RECEIVED VOLUMIO VOLUME 82 Jun 10 21:23:25 rivo volumio[3206]: SPOTIFY: SPOTIFY VOLUME 100 Jun 10 21:23:25 rivo volumio[3206]: SPOTIFY: VOLUMIO VOLUME 82 Jun 10 21:23:25 rivo volumio[3206]: SPOTIFY: DELTA VOLUME ENOUGH: true Jun 10 21:23:25 rivo volumio[3206]: info: Setting Spotify Volume from Volumio: 82 Jun 10 21:23:25 rivo volumio[3206]: info: Updating RAAT Signal Path Jun 10 21:23:25 rivo volumio[3206]: info: Updating RAAT Signal Path Jun 10 21:23:25 rivo volumio[3206]: info: Executing endpoint qc_getconfig Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Jun 10 21:23:25 rivo qobuz-connect[7316]: 20250610 21:23:25.732 [7316.7316] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Jun 10 21:23:25 rivo qobuz-connect[7316]: 20250610 21:23:25.739 [7316.7316] INFO VolumeManager: [0xab44b9c0]: Setting new playback volume: 75 Jun 10 21:23:25 rivo qobuz-connect[7316]: 20250610 21:23:25.740 [7316.7316] INFO VolumeManager: [0xab44b9c0]: Setting new mute state: 0 Jun 10 21:23:25 rivo qobuz-connect[7316]: 20250610 21:23:25.740 [7316.7316] INFO QobuzConnect: [0xab44c390]: Client initialized! Jun 10 21:23:25 rivo qobuz-connect[7316]: 20250610 21:23:25.741 [7316.7316] INFO SampleApp: Starting Avahi advertising, name: Rivo, service name: _qobuz-connect._tcp Jun 10 21:23:25 rivo volumio[3206]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Jun 10 21:23:25 rivo volumio[3206]: info: QobuzConnect: QOBUZ Connect daemon connected Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Jun 10 21:23:25 rivo qobuz-connect[7316]: 20250610 21:23:25.756 [7316.7316] INFO LocalConfigManager: [0xab44b2a0]: Starting Local Configuration server Jun 10 21:23:25 rivo qobuz-connect[7316]: 20250610 21:23:25.756 [7316.7316] INFO SampleApp: Starting Local configuration server Jun 10 21:23:25 rivo qobuz-connect[7316]: 20250610 21:23:25.757 [7316.7316] INFO SampleApp: Connected to UNIX socket client 0xab440ed8 Jun 10 21:23:25 rivo volumio[3206]: No protocol specified Jun 10 21:23:25 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:23:25 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Jun 10 21:23:25 rivo qobuz-connect[7316]: 20250610 21:23:25.882 [7316.7316] INFO SampleApp: Playback volume changed: 75 Jun 10 21:23:25 rivo sudo[7340]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Jun 10 21:23:25 rivo sudo[7340]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:25 rivo sudo[7340]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:25 rivo sudo[7344]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Jun 10 21:23:25 rivo sudo[7344]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:25 rivo volumio[3206]: No protocol specified Jun 10 21:23:25 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:23:25 rivo systemd[1]: Stopping RAAT DAEMON... Jun 10 21:23:25 rivo systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM Jun 10 21:23:25 rivo systemd[1]: raat-daemon.service: Succeeded. Jun 10 21:23:25 rivo systemd[1]: Stopped RAAT DAEMON. Jun 10 21:23:25 rivo systemd[1]: Started RAAT DAEMON. Jun 10 21:23:25 rivo sudo[7344]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:26 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:23:26 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 10 21:23:26 rivo sudo[7348]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Jun 10 21:23:26 rivo sudo[7348]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:26 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:26 rivo volumio[3206]: info: Raat Daemon started successfully Jun 10 21:23:26 rivo volumio[3206]: info: MCU Signalled Playback Inactive Jun 10 21:23:26 rivo volumio[3206]: info: Asound.conf file written Jun 10 21:23:26 rivo sudo[7348]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:26 rivo sudo[7359]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Jun 10 21:23:26 rivo sudo[7359]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:26 rivo sudo[7361]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Jun 10 21:23:26 rivo sudo[7361]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:26 rivo sudo[7361]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:26 rivo systemd[1]: Stopping RAAT DAEMON... Jun 10 21:23:26 rivo systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM Jun 10 21:23:26 rivo systemd[1]: raat-daemon.service: Succeeded. Jun 10 21:23:26 rivo systemd[1]: Stopped RAAT DAEMON. Jun 10 21:23:26 rivo systemd[1]: Started RAAT DAEMON. Jun 10 21:23:26 rivo sudo[7359]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:26 rivo kernel: Fine tdm clk setting range (0~2000000), 12287994 Jun 10 21:23:26 rivo kernel: Fine spdif sysclk setting range(0~2000000), 5644797 Jun 10 21:23:26 rivo kernel: out of value, fixed it Jun 10 21:23:26 rivo kernel: id=0 set inskew=0 Jun 10 21:23:26 rivo volumio[3206]: No protocol specified Jun 10 21:23:26 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:23:26 rivo volumio[3206]: Found hardware: "AML-AUGESOUND-M" "" "" "" "" Jun 10 21:23:26 rivo volumio[3206]: Hardware is initialized using a generic method Jun 10 21:23:26 rivo volumio[3206]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:eARC_TX CDS:0' : Operation not permitted Jun 10 21:23:26 rivo volumio[3206]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:I2SIn CLK:0' : Operation not permitted Jun 10 21:23:26 rivo volumio[3206]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:SPDIFIN audio samplerate:0' : Operation not permitted Jun 10 21:23:26 rivo volumio[3206]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:SPDIFIN Audio Type:0' : Operation not permitted Jun 10 21:23:26 rivo volumio[3206]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:Clock Source 41 Validity:0' : Operation not permitted Jun 10 21:23:26 rivo volumio[3206]: info: Output device has changed, restarting MPD Jun 10 21:23:26 rivo sudo[7378]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 10 21:23:26 rivo sudo[7378]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:26 rivo sudo[7378]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:26 rivo volumio[3206]: info: Output device has changed, restarting Shairport Sync Jun 10 21:23:26 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:26 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 10 21:23:26 rivo sudo[7381]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 10 21:23:26 rivo sudo[7381]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:26 rivo systemd[1]: Stopping Music Player Daemon... Jun 10 21:23:26 rivo volumio[3206]: No protocol specified Jun 10 21:23:26 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:23:26 rivo volumio[3206]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 10 21:23:26 rivo volumio[3206]: No protocol specified Jun 10 21:23:26 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:23:26 rivo volumio[3206]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Jun 10 21:23:26 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:26 rivo systemd[1]: mpd.service: Succeeded. Jun 10 21:23:26 rivo systemd[1]: Stopped Music Player Daemon. Jun 10 21:23:26 rivo systemd[1]: Starting Music Player Daemon... Jun 10 21:23:26 rivo volumio[3206]: info: QobuzConnect: setDeactiveState invoked Jun 10 21:23:26 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:26 rivo volumio[3206]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes Jun 10 21:23:26 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:26 rivo volumio[3206]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes Jun 10 21:23:26 rivo volumio[3206]: info: Output device has changed, restarting MPD Jun 10 21:23:26 rivo sudo[7390]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Jun 10 21:23:26 rivo sudo[7390]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:26 rivo sudo[7390]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:26 rivo sudo[7393]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 10 21:23:26 rivo sudo[7393]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:26 rivo volumio[3206]: info: Output device has changed, restarting Shairport Sync Jun 10 21:23:26 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:26 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 10 21:23:26 rivo sudo[7393]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:26 rivo sudo[7397]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 10 21:23:26 rivo sudo[7397]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:26 rivo sudo[7387]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 10 21:23:26 rivo sudo[7387]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:26 rivo sudo[7387]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:26 rivo systemd[1]: mpd.service: Succeeded. Jun 10 21:23:26 rivo systemd[1]: Stopped Music Player Daemon. Jun 10 21:23:26 rivo systemd[1]: Starting Music Player Daemon... Jun 10 21:23:26 rivo volumio[3206]: No protocol specified Jun 10 21:23:26 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:23:26 rivo volumio[3206]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 10 21:23:26 rivo volumio[3206]: No protocol specified Jun 10 21:23:26 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:23:26 rivo volumio[3206]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Jun 10 21:23:26 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:26 rivo volumio[3206]: info: QobuzConnect: setDeactiveState invoked Jun 10 21:23:26 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:26 rivo volumio[3206]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes Jun 10 21:23:26 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:26 rivo volumio[3206]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes Jun 10 21:23:26 rivo sudo[7425]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Jun 10 21:23:26 rivo sudo[7425]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:26 rivo sudo[7414]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 10 21:23:26 rivo sudo[7414]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:26 rivo sudo[7425]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:26 rivo sudo[7428]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Jun 10 21:23:26 rivo sudo[7414]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:26 rivo sudo[7428]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:26 rivo sudo[7433]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Jun 10 21:23:26 rivo sudo[7428]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:26 rivo sudo[7433]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:26 rivo sudo[7433]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:27 rivo sudo[7442]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Jun 10 21:23:27 rivo sudo[7442]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:27 rivo sudo[7442]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:27 rivo sudo[7447]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Jun 10 21:23:27 rivo sudo[7447]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:27 rivo qobuz-connect[7316]: 20250610 21:23:27.084 [7316.7316] INFO SampleApp: Stopping Local configuration server Jun 10 21:23:27 rivo systemd[1]: Stopping Volumio Qobuz Connect Service... Jun 10 21:23:27 rivo qobuz-connect[7316]: 20250610 21:23:27.095 [7316.7316] INFO SampleApp: shat down connection on UNIX socket Jun 10 21:23:27 rivo systemd[1]: qobuz-connect.service: Succeeded. Jun 10 21:23:27 rivo sudo[7450]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Jun 10 21:23:27 rivo systemd[1]: Stopped Volumio Qobuz Connect Service. Jun 10 21:23:27 rivo sudo[7450]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:27 rivo systemd[1]: Started Volumio Qobuz Connect Service. Jun 10 21:23:27 rivo sudo[7447]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:27 rivo sudo[7450]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 10 21:23:27 rivo volumio[3206]: info: Not Reporting Auto name since its the default one Jun 10 21:23:27 rivo sudo[7457]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Jun 10 21:23:27 rivo sudo[7457]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:27 rivo systemd[1]: Stopping Volumio Qobuz Connect Service... Jun 10 21:23:27 rivo systemd[1]: qobuz-connect.service: Main process exited, code=killed, status=2/INT Jun 10 21:23:27 rivo systemd[1]: qobuz-connect.service: Succeeded. Jun 10 21:23:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 10 21:23:27 rivo systemd[1]: Stopped Volumio Qobuz Connect Service. Jun 10 21:23:27 rivo volumio[3206]: info: Not Reporting Auto name since its the default one Jun 10 21:23:27 rivo systemd[1]: Started Volumio Qobuz Connect Service. Jun 10 21:23:27 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:23:27 rivo sudo[7457]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:27 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 10 21:23:27 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:23:27 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 10 21:23:27 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:23:27 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 10 21:23:27 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:23:27 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 10 21:23:27 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:23:27 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:23:27 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 10 21:23:27 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:23:27 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 10 21:23:27 rivo volumio[3206]: info: MPD Permissions set Jun 10 21:23:27 rivo volumio[3206]: info: MPD Permissions set Jun 10 21:23:27 rivo volumio[3206]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Jun 10 21:23:27 rivo volumio[3206]: info: QobuzConnect: setDeactiveState invoked Jun 10 21:23:27 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:27 rivo volumio[3206]: info: Raat Daemon started successfully Jun 10 21:23:27 rivo volumio[3206]: SPOTIFY: SETTING SPOTIFY VOLUME 82 Jun 10 21:23:27 rivo volumio[3206]: info: Sending Spotify command with payload to local API: /player/volume Jun 10 21:23:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 10 21:23:27 rivo volumio[3206]: info: Not Reporting Auto name since its the default one Jun 10 21:23:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 10 21:23:27 rivo volumio[3206]: info: Not Reporting Auto name since its the default one Jun 10 21:23:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jun 10 21:23:27 rivo volumio[3206]: info: Executing endpoint restartRAATSocket Jun 10 21:23:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection Jun 10 21:23:27 rivo volumio[3206]: info: Executing endpoint restartRAATSocket Jun 10 21:23:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection Jun 10 21:23:27 rivo go-librespot[5493]: time="2025-06-10T21:23:27+02:00" level=debug msg="update volume to 53738/65535" Jun 10 21:23:27 rivo volumio[3206]: info: Executing endpoint qc_getconfig Jun 10 21:23:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Jun 10 21:23:27 rivo qobuz-connect[7465]: 20250610 21:23:27.459 [7465.7465] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Jun 10 21:23:27 rivo qobuz-connect[7465]: 20250610 21:23:27.469 [7465.7465] INFO VolumeManager: [0xaba629c0]: Setting new playback volume: 75 Jun 10 21:23:27 rivo qobuz-connect[7465]: 20250610 21:23:27.469 [7465.7465] INFO VolumeManager: [0xaba629c0]: Setting new mute state: 0 Jun 10 21:23:27 rivo qobuz-connect[7465]: 20250610 21:23:27.469 [7465.7465] INFO QobuzConnect: [0xaba63390]: Client initialized! Jun 10 21:23:27 rivo qobuz-connect[7465]: 20250610 21:23:27.469 [7465.7465] INFO SampleApp: Starting Avahi advertising, name: Rivo, service name: _qobuz-connect._tcp Jun 10 21:23:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:27 rivo qobuz-connect[7465]: 20250610 21:23:27.487 [7465.7465] INFO LocalConfigManager: [0xaba622a0]: Starting Local Configuration server Jun 10 21:23:27 rivo qobuz-connect[7465]: 20250610 21:23:27.488 [7465.7465] INFO SampleApp: Starting Local configuration server Jun 10 21:23:27 rivo qobuz-connect[7465]: 20250610 21:23:27.488 [7465.7465] INFO SampleApp: Connected to UNIX socket client 0xaba57ed8 Jun 10 21:23:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 10 21:23:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jun 10 21:23:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 10 21:23:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jun 10 21:23:27 rivo qobuz-connect[7465]: 20250610 21:23:27.609 [7465.7465] INFO SampleApp: Playback volume changed: 75 Jun 10 21:23:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Jun 10 21:23:27 rivo volumio[3206]: No protocol specified Jun 10 21:23:27 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:23:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Jun 10 21:23:27 rivo sudo[7492]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Jun 10 21:23:27 rivo sudo[7492]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:27 rivo sudo[7492]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:27 rivo sudo[7496]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Jun 10 21:23:27 rivo sudo[7496]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:27 rivo volumio[3206]: No protocol specified Jun 10 21:23:27 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:23:27 rivo systemd[1]: Stopping RAAT DAEMON... Jun 10 21:23:27 rivo systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM Jun 10 21:23:27 rivo systemd[1]: raat-daemon.service: Succeeded. Jun 10 21:23:27 rivo systemd[1]: Stopped RAAT DAEMON. Jun 10 21:23:27 rivo systemd[1]: Started RAAT DAEMON. Jun 10 21:23:27 rivo sudo[7496]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:27 rivo volumio[3206]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Jun 10 21:23:27 rivo volumio[3206]: info: QobuzConnect: QOBUZ Connect daemon connected Jun 10 21:23:27 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Jun 10 21:23:27 rivo sudo[7500]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Jun 10 21:23:27 rivo sudo[7500]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:28 rivo volumio[3206]: No protocol specified Jun 10 21:23:28 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:23:28 rivo sudo[7500]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:28 rivo sudo[7513]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Jun 10 21:23:28 rivo sudo[7513]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:28 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Jun 10 21:23:28 rivo sudo[7515]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Jun 10 21:23:28 rivo sudo[7515]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:28 rivo systemd[1]: Stopping RAAT DAEMON... Jun 10 21:23:28 rivo systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM Jun 10 21:23:28 rivo systemd[1]: raat-daemon.service: Succeeded. Jun 10 21:23:28 rivo systemd[1]: Stopped RAAT DAEMON. Jun 10 21:23:28 rivo systemd[1]: Started RAAT DAEMON. Jun 10 21:23:28 rivo sudo[7513]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:28 rivo sudo[7515]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:28 rivo volumio[3206]: No protocol specified Jun 10 21:23:28 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:23:28 rivo sudo[7522]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Jun 10 21:23:28 rivo sudo[7522]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:28 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:23:28 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 10 21:23:28 rivo sudo[7529]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Jun 10 21:23:28 rivo sudo[7529]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:28 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:23:28 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 10 21:23:28 rivo systemd[1]: Stopping RAAT DAEMON... Jun 10 21:23:28 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:28 rivo systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM Jun 10 21:23:28 rivo systemd[1]: raat-daemon.service: Succeeded. Jun 10 21:23:28 rivo volumio[3206]: info: Raat Daemon started successfully Jun 10 21:23:28 rivo systemd[1]: Stopped RAAT DAEMON. Jun 10 21:23:28 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:23:28 rivo volumio[3206]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 18 Jun 10 21:23:28 rivo volumio[3206]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 19 Jun 10 21:23:28 rivo volumio[3206]: info: Executing endpoint restartRAATSocket Jun 10 21:23:28 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection Jun 10 21:23:28 rivo volumio[3206]: info: TidalConnect service stoped! Jun 10 21:23:28 rivo systemd[1]: Started RAAT DAEMON. Jun 10 21:23:28 rivo sudo[7522]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:28 rivo sudo[7529]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:28 rivo sudo[7537]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Jun 10 21:23:28 rivo sudo[7537]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:28 rivo volumio[3206]: info: Raat Daemon started successfully Jun 10 21:23:28 rivo volumio[3206]: info: TidalConnect service stoped! Jun 10 21:23:28 rivo volumio[3206]: info: Starting Shairport Sync Jun 10 21:23:28 rivo systemd[1]: Stopping RAAT DAEMON... Jun 10 21:23:28 rivo systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM Jun 10 21:23:28 rivo systemd[1]: raat-daemon.service: Succeeded. Jun 10 21:23:28 rivo systemd[1]: Stopped RAAT DAEMON. Jun 10 21:23:28 rivo volumio[3206]: info: Starting Shairport Sync Jun 10 21:23:28 rivo systemd[1]: Started RAAT DAEMON. Jun 10 21:23:28 rivo sudo[7537]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:28 rivo sudo[7553]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 10 21:23:28 rivo sudo[7553]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:28 rivo systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 10 21:23:28 rivo systemd[1]: shairport-sync.service: Succeeded. Jun 10 21:23:28 rivo systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 10 21:23:28 rivo systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 10 21:23:28 rivo go-librespot[5493]: time="2025-06-10T21:23:28+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Jun 10 21:23:28 rivo go-librespot[5493]: time="2025-06-10T21:23:28+02:00" level=trace msg="emitting websocket event: volume" Jun 10 21:23:28 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 10 21:23:28 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 10 21:23:28 rivo volumio[3206]: info: Discovery: Getting this device information Jun 10 21:23:28 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:28 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 10 21:23:28 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 10 21:23:28 rivo sudo[7553]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:28 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:23:28 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 10 21:23:28 rivo sudo[7566]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 10 21:23:28 rivo sudo[7566]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:28 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:23:28 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 10 21:23:28 rivo volumio[3206]: info: Raat Daemon started successfully Jun 10 21:23:28 rivo systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 10 21:23:28 rivo volumio[3206]: info: Preparing to generate the ALSA configuration file Jun 10 21:23:28 rivo systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Jun 10 21:23:28 rivo systemd[1]: shairport-sync.service: Succeeded. Jun 10 21:23:28 rivo systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 10 21:23:28 rivo systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 10 21:23:28 rivo sudo[7566]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:28 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:23:28 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 10 21:23:28 rivo volumio[3206]: SPOTIFY: received: {"type":"volume","data":{"value":82,"max":100}} Jun 10 21:23:28 rivo volumio[3206]: SPOTIFY: RECEIVED SPOTIFY VOLUME 82 Jun 10 21:23:28 rivo volumio[3206]: info: Shairport-Sync Started Jun 10 21:23:28 rivo volumio[3206]: info: Raat Daemon started successfully Jun 10 21:23:28 rivo volumio[3206]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Jun 10 21:23:28 rivo volumio[3206]: info: Reading ALSA contributions from plugins. Jun 10 21:23:28 rivo volumio[3206]: info: Executing endpoint restartRAATSocket Jun 10 21:23:28 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection Jun 10 21:23:28 rivo volumio[3206]: info: Shairport-Sync Started Jun 10 21:23:28 rivo volumio[3206]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Jun 10 21:23:28 rivo volumio[3206]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Jun 10 21:23:28 rivo sudo[7578]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Jun 10 21:23:28 rivo sudo[7578]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:28 rivo volumio[3206]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 19 Jun 10 21:23:28 rivo volumio[3206]: info: Asound.conf file written Jun 10 21:23:28 rivo systemd[1]: Started Volumio Tidal Connect Service. Jun 10 21:23:28 rivo sudo[7578]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:28 rivo sudo[7585]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Jun 10 21:23:28 rivo sudo[7585]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:28 rivo sudo[7585]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:29 rivo kernel: Fine tdm clk setting range (0~2000000), 12287994 Jun 10 21:23:29 rivo kernel: Fine spdif sysclk setting range(0~2000000), 5644797 Jun 10 21:23:29 rivo kernel: out of value, fixed it Jun 10 21:23:29 rivo kernel: id=0 set inskew=0 Jun 10 21:23:29 rivo volumio[3206]: No protocol specified Jun 10 21:23:29 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:23:29 rivo volumio[3206]: Found hardware: "AML-AUGESOUND-M" "" "" "" "" Jun 10 21:23:29 rivo volumio[3206]: Hardware is initialized using a generic method Jun 10 21:23:29 rivo volumio[3206]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:eARC_TX CDS:0' : Operation not permitted Jun 10 21:23:29 rivo volumio[3206]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:I2SIn CLK:0' : Operation not permitted Jun 10 21:23:29 rivo volumio[3206]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:SPDIFIN audio samplerate:0' : Operation not permitted Jun 10 21:23:29 rivo volumio[3206]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:SPDIFIN Audio Type:0' : Operation not permitted Jun 10 21:23:29 rivo volumio[3206]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:Clock Source 41 Validity:0' : Operation not permitted Jun 10 21:23:29 rivo volumio[3206]: info: Output device has changed, restarting MPD Jun 10 21:23:29 rivo sudo[7590]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 10 21:23:29 rivo sudo[7590]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:29 rivo sudo[7590]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:29 rivo volumio[3206]: info: Output device has changed, restarting Shairport Sync Jun 10 21:23:29 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:29 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 10 21:23:29 rivo sudo[7593]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 10 21:23:29 rivo sudo[7593]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:29 rivo mpd[7435]: Jun 10 21:23 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 10 21:23:29 rivo systemd[1]: Started Music Player Daemon. Jun 10 21:23:29 rivo sudo[7397]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:29 rivo sudo[7381]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:29 rivo systemd[1]: Stopping Music Player Daemon... Jun 10 21:23:29 rivo volumio[3206]: No protocol specified Jun 10 21:23:29 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:23:29 rivo volumio[3206]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 10 21:23:29 rivo volumio[3206]: No protocol specified Jun 10 21:23:29 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:23:29 rivo volumio[3206]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Jun 10 21:23:29 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:29 rivo systemd[1]: mpd.service: Succeeded. Jun 10 21:23:29 rivo systemd[1]: Stopped Music Player Daemon. Jun 10 21:23:29 rivo systemd[1]: Starting Music Player Daemon... Jun 10 21:23:29 rivo volumio[3206]: info: QobuzConnect: setDeactiveState invoked Jun 10 21:23:29 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:29 rivo volumio[3206]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes Jun 10 21:23:29 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:29 rivo volumio[3206]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes Jun 10 21:23:29 rivo volumio[3206]: info: Preparing to generate the ALSA configuration file Jun 10 21:23:29 rivo sudo[7605]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Jun 10 21:23:29 rivo sudo[7605]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:29 rivo systemd[1]: Stopping Volumio Tidal Connect Service... Jun 10 21:23:29 rivo systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM Jun 10 21:23:29 rivo systemd[1]: vtcs.service: Succeeded. Jun 10 21:23:29 rivo systemd[1]: Stopped Volumio Tidal Connect Service. Jun 10 21:23:29 rivo sudo[7605]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:29 rivo sudo[7608]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Jun 10 21:23:29 rivo sudo[7608]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:29 rivo sudo[7602]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 10 21:23:29 rivo sudo[7602]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:29 rivo sudo[7602]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:29 rivo sudo[7608]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:29 rivo volumio[3206]: info: RAAT: Requesting Headphone Status Jun 10 21:23:29 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Jun 10 21:23:29 rivo volumio[3206]: info: RAAT: Requesting Headphone Status Jun 10 21:23:29 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Jun 10 21:23:29 rivo volumio[3206]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Jun 10 21:23:29 rivo volumio[3206]: info: CoreStateMachine::getcurrentVolume Jun 10 21:23:29 rivo volumio[3206]: info: CoreCommandRouter::volumioRetrievevolume Jun 10 21:23:29 rivo sudo[7618]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Jun 10 21:23:29 rivo sudo[7618]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:29 rivo volumio[3206]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Jun 10 21:23:29 rivo volumio[3206]: info: Reading ALSA contributions from plugins. Jun 10 21:23:29 rivo sudo[7618]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:29 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:23:29 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 10 21:23:29 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:23:29 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:23:29 rivo sudo[7621]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Jun 10 21:23:29 rivo sudo[7621]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:29 rivo volumio[3206]: info: Executing endpoint tc_getconfig Jun 10 21:23:29 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Jun 10 21:23:29 rivo volumio[3206]: info: MPD Permissions set Jun 10 21:23:29 rivo volumio[3206]: info: MCU Signalled Headphone Mode Disabled Jun 10 21:23:29 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Jun 10 21:23:29 rivo volumio[3206]: info: Reporting Headphone State: false Jun 10 21:23:29 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:29 rivo volumio[3206]: info: Updating RAAT Signal Path Jun 10 21:23:29 rivo qobuz-connect[7465]: 20250610 21:23:29.571 [7465.7465] INFO SampleApp: Stopping Local configuration server Jun 10 21:23:29 rivo systemd[1]: Stopping Volumio Qobuz Connect Service... Jun 10 21:23:29 rivo qobuz-connect[7465]: 20250610 21:23:29.582 [7465.7465] INFO SampleApp: shat down connection on UNIX socket Jun 10 21:23:29 rivo volumio[3206]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: No protocol specified Jun 10 21:23:29 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:23:29 rivo systemd[1]: qobuz-connect.service: Succeeded. Jun 10 21:23:29 rivo systemd[1]: Stopped Volumio Qobuz Connect Service. Jun 10 21:23:29 rivo systemd[1]: Started Volumio Qobuz Connect Service. Jun 10 21:23:29 rivo sudo[7621]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:29 rivo volumio[3206]: info: MCU Signalled Headphone Mode Disabled Jun 10 21:23:29 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Jun 10 21:23:29 rivo volumio[3206]: info: Reporting Headphone State: false Jun 10 21:23:29 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:29 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:29 rivo volumio[3206]: info: Updating RAAT Signal Path Jun 10 21:23:29 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:23:29 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 10 21:23:29 rivo volumio[3206]: info: TidalConnect service stoped! Jun 10 21:23:29 rivo volumio[3206]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Jun 10 21:23:29 rivo volumio[3206]: info: QobuzConnect: setDeactiveState invoked Jun 10 21:23:29 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:29 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:29 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:29 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:29 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:29 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:29 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:29 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 10 21:23:29 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jun 10 21:23:29 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:29 rivo volumio[3206]: info: VolumeController:: Volume=undefined Mute =false Jun 10 21:23:29 rivo volumio[3206]: info: CoreStateMachine::pushState Jun 10 21:23:29 rivo volumio[3206]: info: CoreCommandRouter::volumioPushState Jun 10 21:23:29 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:29 rivo volumio[3206]: info: MRS: Pushing multiroomSync output update for this device Jun 10 21:23:29 rivo volumio[3206]: info: MRS: Pushing multiroomSync output Jun 10 21:23:29 rivo volumio[3206]: info: CoreStateMachine::updateTrackBlock Jun 10 21:23:29 rivo volumio[3206]: info: CorePlayQueue::getTrackBlock Jun 10 21:23:29 rivo volumio[3206]: info: CoreCommandRouter::volumioRetrievevolume Jun 10 21:23:29 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:29 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:29 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 10 21:23:29 rivo volumio[3206]: info: Not Reporting Auto name since its the default one Jun 10 21:23:29 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:29 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:29 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:29 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:29 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 10 21:23:29 rivo volumio[3206]: info: Not Reporting Auto name since its the default one Jun 10 21:23:29 rivo volumio[3206]: info: Updating RAAT Signal Path Jun 10 21:23:29 rivo volumio[3206]: SPOTIFY: RECEIVED VOLUMIO VOLUME 82 Jun 10 21:23:29 rivo volumio[3206]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: No protocol specified Jun 10 21:23:29 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:23:29 rivo volumio[3206]: info: TidalConnect service stoped! Jun 10 21:23:30 rivo volumio[3206]: info: Executing endpoint qc_getconfig Jun 10 21:23:30 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Jun 10 21:23:30 rivo volumio[3206]: info: TidalConnect service stoped! Jun 10 21:23:30 rivo qobuz-connect[7624]: 20250610 21:23:30.008 [7624.7624] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Jun 10 21:23:30 rivo qobuz-connect[7624]: 20250610 21:23:30.031 [7624.7624] INFO VolumeManager: [0xac77e9c0]: Setting new playback volume: 75 Jun 10 21:23:30 rivo qobuz-connect[7624]: 20250610 21:23:30.031 [7624.7624] INFO VolumeManager: [0xac77e9c0]: Setting new mute state: 0 Jun 10 21:23:30 rivo qobuz-connect[7624]: 20250610 21:23:30.031 [7624.7624] INFO QobuzConnect: [0xac77f390]: Client initialized! Jun 10 21:23:30 rivo qobuz-connect[7624]: 20250610 21:23:30.031 [7624.7624] INFO SampleApp: Starting Avahi advertising, name: Rivo, service name: _qobuz-connect._tcp Jun 10 21:23:30 rivo qobuz-connect[7624]: 20250610 21:23:30.048 [7624.7624] INFO LocalConfigManager: [0xac77e2a0]: Starting Local Configuration server Jun 10 21:23:30 rivo qobuz-connect[7624]: 20250610 21:23:30.048 [7624.7624] INFO SampleApp: Starting Local configuration server Jun 10 21:23:30 rivo qobuz-connect[7624]: 20250610 21:23:30.049 [7624.7624] INFO SampleApp: Connected to UNIX socket client 0xac773ed8 Jun 10 21:23:30 rivo volumio[3206]: info: TidalConnect service stoped! Jun 10 21:23:30 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:30 rivo volumio[3206]: info: Starting Shairport Sync Jun 10 21:23:30 rivo qobuz-connect[7624]: 20250610 21:23:30.158 [7624.7624] INFO SampleApp: Playback volume changed: 75 Jun 10 21:23:30 rivo volumio[3206]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Jun 10 21:23:30 rivo volumio[3206]: info: QobuzConnect: QOBUZ Connect daemon connected Jun 10 21:23:30 rivo sudo[7654]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 10 21:23:30 rivo sudo[7654]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:30 rivo volumio[3206]: info: VolumeController:: Volume=undefined Mute =false Jun 10 21:23:30 rivo volumio[3206]: info: CoreStateMachine::pushState Jun 10 21:23:30 rivo volumio[3206]: info: CoreCommandRouter::volumioPushState Jun 10 21:23:30 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:30 rivo volumio[3206]: info: MRS: Pushing multiroomSync output update for this device Jun 10 21:23:30 rivo systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 10 21:23:30 rivo systemd[1]: shairport-sync.service: Succeeded. Jun 10 21:23:30 rivo volumio[3206]: info: MRS: Pushing multiroomSync output Jun 10 21:23:30 rivo systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 10 21:23:30 rivo systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 10 21:23:30 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Jun 10 21:23:30 rivo sudo[7654]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:30 rivo volumio[3206]: No protocol specified Jun 10 21:23:30 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:23:30 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Jun 10 21:23:30 rivo sudo[7667]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Jun 10 21:23:30 rivo sudo[7667]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:30 rivo sudo[7667]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:30 rivo sudo[7671]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Jun 10 21:23:30 rivo sudo[7671]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:30 rivo volumio[3206]: No protocol specified Jun 10 21:23:30 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:23:30 rivo systemd[1]: Stopping RAAT DAEMON... Jun 10 21:23:30 rivo systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM Jun 10 21:23:30 rivo systemd[1]: raat-daemon.service: Succeeded. Jun 10 21:23:30 rivo systemd[1]: Stopped RAAT DAEMON. Jun 10 21:23:30 rivo systemd[1]: Started RAAT DAEMON. Jun 10 21:23:30 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:23:30 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 10 21:23:30 rivo sudo[7671]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:30 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:23:30 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 10 21:23:30 rivo volumio[3206]: SPOTIFY: RECEIVED VOLUMIO VOLUME 82 Jun 10 21:23:30 rivo sudo[7675]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Jun 10 21:23:30 rivo sudo[7675]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:30 rivo volumio[3206]: info: Updating RAAT Signal Path Jun 10 21:23:30 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:30 rivo volumio[3206]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Jun 10 21:23:30 rivo volumio[3206]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Jun 10 21:23:30 rivo sudo[7675]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:30 rivo sudo[7681]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Jun 10 21:23:30 rivo sudo[7681]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:30 rivo systemd[1]: Stopping RAAT DAEMON... Jun 10 21:23:30 rivo systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM Jun 10 21:23:30 rivo systemd[1]: raat-daemon.service: Succeeded. Jun 10 21:23:30 rivo systemd[1]: Stopped RAAT DAEMON. Jun 10 21:23:30 rivo systemd[1]: Started RAAT DAEMON. Jun 10 21:23:30 rivo sudo[7681]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:30 rivo sudo[7688]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Jun 10 21:23:30 rivo sudo[7688]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:30 rivo volumio[3206]: info: Asound.conf file unchanged, so no further update is needed Jun 10 21:23:30 rivo volumio[3206]: info: Output device has changed, restarting MPD Jun 10 21:23:30 rivo systemd[1]: Started Volumio Tidal Connect Service. Jun 10 21:23:30 rivo sudo[7688]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:30 rivo sudo[7700]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 10 21:23:30 rivo sudo[7700]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:30 rivo sudo[7700]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:30 rivo volumio[3206]: info: Output device has changed, restarting Shairport Sync Jun 10 21:23:30 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:30 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 10 21:23:30 rivo sudo[7711]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 10 21:23:30 rivo sudo[7711]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:30 rivo systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Jun 10 21:23:30 rivo systemd[1]: mpd.service: Succeeded. Jun 10 21:23:30 rivo systemd[1]: Stopped Music Player Daemon. Jun 10 21:23:30 rivo volumio[3206]: No protocol specified Jun 10 21:23:30 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:23:30 rivo volumio[3206]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 10 21:23:30 rivo volumio[3206]: No protocol specified Jun 10 21:23:30 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:23:30 rivo volumio[3206]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Jun 10 21:23:30 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:30 rivo systemd[1]: Starting Music Player Daemon... Jun 10 21:23:31 rivo volumio[3206]: info: QobuzConnect: setDeactiveState invoked Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:31 rivo volumio[3206]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:31 rivo volumio[3206]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes Jun 10 21:23:31 rivo sudo[7720]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Jun 10 21:23:31 rivo sudo[7720]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:31 rivo systemd[1]: Stopping Volumio Tidal Connect Service... Jun 10 21:23:31 rivo systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM Jun 10 21:23:31 rivo systemd[1]: vtcs.service: Succeeded. Jun 10 21:23:31 rivo systemd[1]: Stopped Volumio Tidal Connect Service. Jun 10 21:23:31 rivo sudo[7716]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 10 21:23:31 rivo sudo[7716]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:31 rivo sudo[7723]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Jun 10 21:23:31 rivo sudo[7723]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:31 rivo sudo[7720]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:31 rivo sudo[7716]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:31 rivo sudo[7723]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:31 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:23:31 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 10 21:23:31 rivo sudo[7733]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Jun 10 21:23:31 rivo sudo[7733]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:31 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 10 21:23:31 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:23:31 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 10 21:23:31 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:23:31 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:23:31 rivo sudo[7733]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:31 rivo volumio[3206]: info: Raat Daemon started successfully Jun 10 21:23:31 rivo volumio[3206]: info: Raat Daemon started successfully Jun 10 21:23:31 rivo volumio[3206]: info: Shairport-Sync Started Jun 10 21:23:31 rivo volumio[3206]: info: RAAT: Requesting Headphone Status Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Jun 10 21:23:31 rivo volumio[3206]: info: RAAT: Requesting Headphone Status Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Jun 10 21:23:31 rivo volumio[3206]: info: RAAT: Requesting Headphone Status Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Jun 10 21:23:31 rivo volumio[3206]: info: RAAT: Requesting Headphone Status Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Jun 10 21:23:31 rivo volumio[3206]: info: MPD Permissions set Jun 10 21:23:31 rivo volumio[3206]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Jun 10 21:23:31 rivo volumio[3206]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Jun 10 21:23:31 rivo sudo[7735]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Jun 10 21:23:31 rivo sudo[7735]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:31 rivo volumio[3206]: info: Executing endpoint restartRAATSocket Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection Jun 10 21:23:31 rivo qobuz-connect[7624]: 20250610 21:23:31.408 [7624.7624] INFO SampleApp: Stopping Local configuration server Jun 10 21:23:31 rivo systemd[1]: Stopping Volumio Qobuz Connect Service... Jun 10 21:23:31 rivo volumio[3206]: info: MCU Signalled Headphone Mode Disabled Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Jun 10 21:23:31 rivo volumio[3206]: info: Reporting Headphone State: false Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:31 rivo volumio[3206]: info: Updating RAAT Signal Path Jun 10 21:23:31 rivo volumio[3206]: info: MCU Signalled Headphone Mode Disabled Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Jun 10 21:23:31 rivo volumio[3206]: info: Reporting Headphone State: false Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:31 rivo volumio[3206]: info: Updating RAAT Signal Path Jun 10 21:23:31 rivo volumio[3206]: info: MCU Signalled Headphone Mode Disabled Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Jun 10 21:23:31 rivo volumio[3206]: info: Reporting Headphone State: false Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:31 rivo qobuz-connect[7624]: 20250610 21:23:31.430 [7624.7624] INFO SampleApp: shat down connection on UNIX socket Jun 10 21:23:31 rivo volumio[3206]: info: Updating RAAT Signal Path Jun 10 21:23:31 rivo volumio[3206]: info: MCU Signalled Headphone Mode Disabled Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Jun 10 21:23:31 rivo volumio[3206]: info: Reporting Headphone State: false Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:31 rivo volumio[3206]: info: Updating RAAT Signal Path Jun 10 21:23:31 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:23:31 rivo systemd[1]: qobuz-connect.service: Succeeded. Jun 10 21:23:31 rivo systemd[1]: Stopped Volumio Qobuz Connect Service. Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:31 rivo sudo[7738]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Jun 10 21:23:31 rivo systemd[1]: Started Volumio Qobuz Connect Service. Jun 10 21:23:31 rivo sudo[7738]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:31 rivo sudo[7735]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:31 rivo systemd[1]: Started Volumio Tidal Connect Service. Jun 10 21:23:31 rivo sudo[7738]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:31 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 10 21:23:31 rivo volumio[3206]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Jun 10 21:23:31 rivo volumio[3206]: info: QobuzConnect: setDeactiveState invoked Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 10 21:23:31 rivo volumio[3206]: info: Not Reporting Auto name since its the default one Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 10 21:23:31 rivo volumio[3206]: info: Not Reporting Auto name since its the default one Jun 10 21:23:31 rivo volumio[3206]: info: TidalConnect service started! Jun 10 21:23:31 rivo volumio[3206]: info: Executing endpoint qc_getconfig Jun 10 21:23:31 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Jun 10 21:23:31 rivo qobuz-connect[7740]: 20250610 21:23:31.957 [7740.7740] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Jun 10 21:23:31 rivo volumio[3206]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 18 Jun 10 21:23:31 rivo volumio[3206]: info: Starting Shairport Sync Jun 10 21:23:31 rivo qobuz-connect[7740]: 20250610 21:23:31.969 [7740.7740] INFO VolumeManager: [0xab01d9c0]: Setting new playback volume: 75 Jun 10 21:23:31 rivo qobuz-connect[7740]: 20250610 21:23:31.969 [7740.7740] INFO VolumeManager: [0xab01d9c0]: Setting new mute state: 0 Jun 10 21:23:31 rivo qobuz-connect[7740]: 20250610 21:23:31.970 [7740.7740] INFO QobuzConnect: [0xab01e390]: Client initialized! Jun 10 21:23:31 rivo qobuz-connect[7740]: 20250610 21:23:31.970 [7740.7740] INFO SampleApp: Starting Avahi advertising, name: Rivo, service name: _qobuz-connect._tcp Jun 10 21:23:31 rivo qobuz-connect[7740]: 20250610 21:23:31.986 [7740.7740] INFO LocalConfigManager: [0xab01d2a0]: Starting Local Configuration server Jun 10 21:23:31 rivo qobuz-connect[7740]: 20250610 21:23:31.986 [7740.7740] INFO SampleApp: Starting Local configuration server Jun 10 21:23:31 rivo qobuz-connect[7740]: 20250610 21:23:31.986 [7740.7740] INFO SampleApp: Connected to UNIX socket client 0xab012ed8 Jun 10 21:23:32 rivo volumio[3206]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Jun 10 21:23:32 rivo volumio[3206]: info: QobuzConnect: QOBUZ Connect daemon connected Jun 10 21:23:32 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Jun 10 21:23:32 rivo sudo[7764]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 10 21:23:32 rivo sudo[7764]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:32 rivo systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 10 21:23:32 rivo systemd[1]: shairport-sync.service: Succeeded. Jun 10 21:23:32 rivo systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 10 21:23:32 rivo systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 10 21:23:32 rivo sudo[7764]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:32 rivo qobuz-connect[7740]: 20250610 21:23:32.107 [7740.7740] INFO SampleApp: Playback volume changed: 75 Jun 10 21:23:32 rivo volumio[3206]: No protocol specified Jun 10 21:23:32 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:23:32 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Jun 10 21:23:32 rivo sudo[7771]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Jun 10 21:23:32 rivo sudo[7771]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:32 rivo sudo[7771]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:32 rivo sudo[7777]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Jun 10 21:23:32 rivo sudo[7777]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:32 rivo volumio[3206]: No protocol specified Jun 10 21:23:32 rivo volumio[3206]: xcb_connection_has_error() returned true Jun 10 21:23:32 rivo systemd[1]: Stopping RAAT DAEMON... Jun 10 21:23:32 rivo systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM Jun 10 21:23:32 rivo systemd[1]: raat-daemon.service: Succeeded. Jun 10 21:23:32 rivo systemd[1]: Stopped RAAT DAEMON. Jun 10 21:23:32 rivo systemd[1]: Started RAAT DAEMON. Jun 10 21:23:32 rivo sudo[7777]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:32 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:23:32 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 10 21:23:32 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:23:32 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 10 21:23:32 rivo sudo[7781]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Jun 10 21:23:32 rivo sudo[7781]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:32 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:32 rivo volumio[3206]: info: Raat Daemon started successfully Jun 10 21:23:32 rivo volumio[3206]: info: Shairport-Sync Started Jun 10 21:23:32 rivo volumio[3206]: info: Executing endpoint tc_getconfig Jun 10 21:23:32 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Jun 10 21:23:32 rivo vtcs[7744]: STARTING TidalConnect services, version: 1.4.0.34 Jun 10 21:23:32 rivo volumio[3206]: info: TidalConnect service stoped! Jun 10 21:23:32 rivo sudo[7781]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:32 rivo sudo[7787]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Jun 10 21:23:32 rivo volumio[3206]: info: TidalConnect service stoped! Jun 10 21:23:32 rivo sudo[7787]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:32 rivo systemd[1]: Stopping RAAT DAEMON... Jun 10 21:23:32 rivo systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM Jun 10 21:23:32 rivo systemd[1]: raat-daemon.service: Succeeded. Jun 10 21:23:32 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 10 21:23:32 rivo systemd[1]: Stopped RAAT DAEMON. Jun 10 21:23:32 rivo volumio[3206]: info: Executing endpoint restartRAATSocket Jun 10 21:23:32 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection Jun 10 21:23:32 rivo systemd[1]: Started RAAT DAEMON. Jun 10 21:23:32 rivo volumio[3206]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 10 21:23:32 rivo sudo[7787]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:32 rivo vtcs[7744]: STARTED TidalConnect services. Jun 10 21:23:32 rivo volumio[3206]: info: Raat Daemon started successfully Jun 10 21:23:32 rivo volumio[3206]: info: Executing endpoint tc_connect Jun 10 21:23:32 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Jun 10 21:23:32 rivo volumio[3206]: info: Connecting to TidalConnect Jun 10 21:23:32 rivo volumio[3206]: info: CoreCommandRouter::servicePushState Jun 10 21:23:32 rivo volumio[3206]: info: CoreStateMachine::pushState Jun 10 21:23:32 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 10 21:23:32 rivo volumio[3206]: info: CoreCommandRouter::volumioPushState Jun 10 21:23:32 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:32 rivo volumio[3206]: info: MRS: Pushing multiroomSync output update for this device Jun 10 21:23:32 rivo volumio[3206]: info: MRS: Pushing multiroomSync output Jun 10 21:23:32 rivo volumio[3206]: info: CoreCommandRouter::servicePushState Jun 10 21:23:32 rivo volumio[3206]: info: CoreStateMachine::pushState Jun 10 21:23:32 rivo volumio[3206]: info: CoreCommandRouter::volumioPushState Jun 10 21:23:32 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:32 rivo volumio[3206]: info: MRS: Pushing multiroomSync output update for this device Jun 10 21:23:32 rivo volumio[3206]: info: MRS: Pushing multiroomSync output Jun 10 21:23:32 rivo volumio[3206]: SPOTIFY: RECEIVED VOLUMIO VOLUME 82 Jun 10 21:23:32 rivo volumio[3206]: SPOTIFY: RECEIVED VOLUMIO VOLUME 82 Jun 10 21:23:32 rivo volumio[3206]: info: Updating RAAT Signal Path Jun 10 21:23:32 rivo volumio[3206]: info: Updating RAAT Signal Path Jun 10 21:23:32 rivo volumio[3206]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Jun 10 21:23:32 rivo volumio[3206]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Jun 10 21:23:32 rivo volumio[3206]: info: Executing endpoint restartRAATSocket Jun 10 21:23:32 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection Jun 10 21:23:32 rivo sudo[7829]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Jun 10 21:23:32 rivo sudo[7829]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:32 rivo sudo[7829]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:32 rivo volumio[3206]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 18 Jun 10 21:23:33 rivo volumio[3206]: info: RAAT: Requesting Headphone Status Jun 10 21:23:33 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Jun 10 21:23:33 rivo volumio[3206]: info: MCU Signalled Headphone Mode Disabled Jun 10 21:23:33 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Jun 10 21:23:33 rivo volumio[3206]: info: Reporting Headphone State: false Jun 10 21:23:33 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:33 rivo volumio[3206]: info: Updating RAAT Signal Path Jun 10 21:23:33 rivo volumio[3206]: info: RAAT: Requesting Headphone Status Jun 10 21:23:33 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Jun 10 21:23:33 rivo volumio[3206]: info: MCU Signalled Headphone Mode Disabled Jun 10 21:23:33 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Jun 10 21:23:33 rivo volumio[3206]: info: Reporting Headphone State: false Jun 10 21:23:33 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:33 rivo volumio[3206]: info: Updating RAAT Signal Path Jun 10 21:23:33 rivo mpd[7732]: Jun 10 21:23 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 10 21:23:33 rivo systemd[1]: Started Music Player Daemon. Jun 10 21:23:33 rivo sudo[7711]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:33 rivo volumio[3206]: error: MPD error: The expression evaluated to a falsy value: Jun 10 21:23:33 rivo volumio[3206]: assert.ok(self.idling) Jun 10 21:23:33 rivo volumio[3206]: error: The expression evaluated to a falsy value: Jun 10 21:23:33 rivo volumio[3206]: assert.ok(self.idling) Jun 10 21:23:33 rivo sudo[7593]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:33 rivo volumio[3206]: error: updateQueue error: null Jun 10 21:23:33 rivo volumio[3206]: error: MPD error: The expression evaluated to a falsy value: Jun 10 21:23:33 rivo volumio[3206]: assert.ok(self.idling) Jun 10 21:23:33 rivo volumio[3206]: error: The expression evaluated to a falsy value: Jun 10 21:23:33 rivo volumio[3206]: assert.ok(self.idling) Jun 10 21:23:33 rivo volumio[3206]: error: updateQueue error: null Jun 10 21:23:33 rivo volumio[3206]: info: TidalConnect service started! Jun 10 21:23:34 rivo volumio[3206]: info: TidalConnect service stoped! Jun 10 21:23:34 rivo volumio[3206]: info: CoreCommandRouter::volumioVolatilePlay Jun 10 21:23:34 rivo volumio[3206]: info: CoreStateMachine::volatilePlay Jun 10 21:23:34 rivo volumio[3206]: info: Received play: Jun 10 21:23:34 rivo vtcs[7744]: [2025-06-10 21:23:34.192] [tisoc] [warning] [PlaybackControllerImpl.cpp:202] Illegal state:0 Jun 10 21:23:34 rivo volumio[3206]: info: TidalConnect service stoped! Jun 10 21:23:34 rivo volumio[3206]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Jun 10 21:23:34 rivo volumio[3206]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Jun 10 21:23:34 rivo sudo[7844]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Jun 10 21:23:34 rivo sudo[7844]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 10 21:23:34 rivo sudo[7844]: pam_unix(sudo:session): session closed for user root Jun 10 21:23:34 rivo volumio[3206]: info: TidalConnect service started! Jun 10 21:23:34 rivo volumio[3206]: info: Executing endpoint metavolumio Jun 10 21:23:34 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 10 21:23:34 rivo volumio[3206]: info: Executing endpoint metavolumio Jun 10 21:23:34 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 10 21:23:34 rivo volumio[3206]: info: Executing endpoint metavolumio Jun 10 21:23:34 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 10 21:23:35 rivo volumio[3206]: error: Failed request for metavolumio API Jun 10 21:23:35 rivo volumio[3206]: info: RAAT: Requesting Headphone Status Jun 10 21:23:35 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Jun 10 21:23:35 rivo volumio[3206]: info: MCU Signalled Headphone Mode Disabled Jun 10 21:23:35 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Jun 10 21:23:35 rivo volumio[3206]: info: Reporting Headphone State: false Jun 10 21:23:35 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:35 rivo volumio[3206]: info: Updating RAAT Signal Path Jun 10 21:23:35 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 10 21:23:35 rivo volumio[3206]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Jun 10 21:23:35 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Jun 10 21:23:35 rivo volumio[3206]: info: Received Get System Version Jun 10 21:23:35 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 10 21:23:35 rivo volumio[3206]: info: Received Get System Info Jun 10 21:23:35 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 10 21:23:35 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 10 21:23:35 rivo volumio[3206]: info: Discovery: Getting this device information Jun 10 21:23:35 rivo volumio[3206]: info: CoreCommandRouter::volumioGetState Jun 10 21:23:35 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 10 21:23:35 rivo volumio[3206]: info: RAAT: Requesting Headphone Status Jun 10 21:23:35 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Jun 10 21:23:35 rivo volumio[3206]: info: MCU Signalled Headphone Mode Disabled Jun 10 21:23:35 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Jun 10 21:23:35 rivo volumio[3206]: info: Reporting Headphone State: false Jun 10 21:23:35 rivo volumio[3206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 10 21:23:35 rivo volumio[3206]: info: Updating RAAT Signal Path Jun 10 21:23:35 rivo volumio[3206]: info: TidalConnect service started! Jun 10 21:23:37 rivo volumio[3206]: info: TidalConnect service started! Jun 10 21:23:38 rivo volumio[3206]: info: CoreCommandRouter::volumioVolatilePlay Jun 10 21:23:38 rivo volumio[3206]: info: CoreStateMachine::volatilePlay Jun 10 21:23:38 rivo volumio[3206]: info: Received play: Jun 10 21:23:38 rivo vtcs[7744]: [2025-06-10 21:23:38.240] [tisoc] [warning] [PlaybackControllerImpl.cpp:202] Illegal state:0 Jun 10 21:23:39 rivo volumio[3206]: info: CoreCommandRouter::volumioVolatilePlay Jun 10 21:23:39 rivo volumio[3206]: info: CoreStateMachine::volatilePlay Jun 10 21:23:39 rivo volumio[3206]: info: Received play: Jun 10 21:23:39 rivo vtcs[7744]: [2025-06-10 21:23:39.889] [tisoc] [warning] [PlaybackControllerImpl.cpp:202] Illegal state:0 Jun 10 21:23:45 rivo volumio[3206]: info: CoreCommandRouter::volumioRemoveQueueItem Jun 10 21:23:45 rivo volumio[3206]: info: CoreStateMachine::removeQueueItem Jun 10 21:23:45 rivo volumio[3206]: info: CoreStateMachine::stop Jun 10 21:23:45 rivo volumio[3206]: info: CoreStateMachine::serviceStop Jun 10 21:23:45 rivo volumio[3206]: info: CoreCommandRouter::serviceStop Jun 10 21:23:45 rivo vtcs[7744]: [2025-06-10 21:23:45.242] [tisoc] [warning] [SessionManagerImpl.cpp:243] Illegal State: IDLE Jun 10 21:23:45 rivo volumio[3206]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 10 21:23:45 rivo volumio[3206]: TypeError: Cannot read property 'then' of undefined Jun 10 21:23:45 rivo volumio[3206]: at CoreStateMachine.removeQueueItem (/volumio/app/statemachine.js:1368:7) Jun 10 21:23:45 rivo volumio[3206]: at CoreCommandRouter.volumioRemoveQueueItem (/volumio/app/index.js:121:28) Jun 10 21:23:45 rivo volumio[3206]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:173:33) Jun 10 21:23:45 rivo volumio[3206]: at Socket.emit (events.js:400:28) Jun 10 21:23:45 rivo volumio[3206]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Jun 10 21:23:45 rivo volumio[3206]: at processTicksAndRejections (internal/process/task_queues.js:77:11) Jun 10 21:23:45 rivo volumio[3206]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 10 21:23:46 rivo sudo[7877]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-10 21:22 Jun 10 21:23:46 rivo sudo[7877]: 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="570c5791513f5bac7da274aba6690c1a961705de" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 13 May 2025 06:24:39 PM CEST" VOLUMIO_VERSION="3.812" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="c8a59422b1bfedffc72f72cef58ad20b"