-- Logs begin at Sun 2025-05-18 10:37:28 +07, end at Sun 2025-05-18 10:51:42 +07. -- May 18 10:50:02 rivoplus kernel: usb 1-1.4.2: new high-speed USB device number 8 using xhci-hcd May 18 10:50:02 rivoplus kernel: usb 1-1.4.2: New USB device found, idVendor=16d0, idProduct=071a May 18 10:50:02 rivoplus kernel: usb 1-1.4.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3 May 18 10:50:02 rivoplus kernel: usb 1-1.4.2: Product: Combo384 Amanero May 18 10:50:02 rivoplus kernel: usb 1-1.4.2: Manufacturer: Amanero Technologies May 18 10:50:02 rivoplus kernel: usb 1-1.4.2: SerialNumber: 413-001 May 18 10:50:02 rivoplus kernel: usb 1-1.4.2: Unsupported device May 18 10:50:02 rivoplus kernel: usb 1-1.4.2: Warning! Unlikely big volume range (=32767), cval->res is probably wrong. May 18 10:50:02 rivoplus kernel: usb 1-1.4.2: [10] FU [PCM Playback Volume] ch = 2, val = -32767/0/1 May 18 10:50:02 rivoplus kernel: usb 1-1.4.2: Warning! Unlikely big volume range (=32767), cval->res is probably wrong. May 18 10:50:02 rivoplus kernel: usb 1-1.4.2: [10] FU [PCM Playback Volume] ch = 1, val = -32767/0/1 May 18 10:50:02 rivoplus volumio[6290]: info: May 18 10:50:02 rivoplus volumio[6290]: ---------------------------- USB Audio Device Attached May 18 10:50:02 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioAttach May 18 10:50:02 rivoplus volumio[6290]: No protocol specified May 18 10:50:02 rivoplus volumio[6290]: xcb_connection_has_error() returned true May 18 10:50:02 rivoplus volumio[6290]: info: CoreCommandRouter::Close All Modals sent May 18 10:50:02 rivoplus volumio[6290]: info: Preparing to save Alsa Options, stopping services first May 18 10:50:02 rivoplus volumio[6290]: info: CoreCommandRouter::volumioGetState May 18 10:50:02 rivoplus volumio[6290]: info: CoreCommandRouter::volumioPause May 18 10:50:02 rivoplus volumio[6290]: info: CoreStateMachine::pause May 18 10:50:02 rivoplus volumio[6290]: info: CoreStateMachine::stPlaybackTimer May 18 10:50:02 rivoplus volumio[6290]: info: CoreStateMachine::servicePause May 18 10:50:02 rivoplus volumio[6290]: info: CorePlayQueue::getTrack 1 May 18 10:50:02 rivoplus volumio[6290]: info: Error: no service or no trackblock to pause May 18 10:50:02 rivoplus volumio[6290]: info: Saving Audio Output to: {"disallowPush":true,"output_device":{"value":"5","label":"Combo384 Amanero","alsacard":"Amanero"},"i2s":false} May 18 10:50:02 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 18 10:50:02 rivoplus volumio[6290]: No protocol specified May 18 10:50:02 rivoplus volumio[6290]: xcb_connection_has_error() returned true May 18 10:50:02 rivoplus volumio[6290]: No protocol specified May 18 10:50:02 rivoplus volumio[6290]: xcb_connection_has_error() returned true May 18 10:50:02 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 18 10:50:02 rivoplus volumio[6290]: No protocol specified May 18 10:50:02 rivoplus volumio[6290]: xcb_connection_has_error() returned true May 18 10:50:02 rivoplus volumio[6290]: info: Setting mixer PCM for card Combo384 Amanero May 18 10:50:02 rivoplus volumio[6290]: info: QobuzConnect: setDeactiveState invoked May 18 10:50:02 rivoplus volumio[6290]: info: CoreCommandRouter::volumioGetState May 18 10:50:02 rivoplus volumio[6290]: info: Reconfiguring and Restarting RAAT Plugin due to audio path changes May 18 10:50:02 rivoplus vtcs[6659]: [2025-05-18 10:50:02.864] [tisoc] [warning] [SessionManagerImpl.cpp:243] Illegal State: IDLE May 18 10:50:02 rivoplus vtcs[6659]: [2025-05-18 10:50:02.870] [tisoc] [error] [SpkconServer.cpp:381] recv error. client fd=8 errorno=104 error=Connection reset by peer May 18 10:50:02 rivoplus vtcs[6659]: [2025-05-18 10:50:02.871] [tisoc] [error] [SpkconServer.cpp:376] recv error. socket disconnected May 18 10:50:02 rivoplus vtcs[6659]: [2025-05-18 10:50:02.871] [tisoc] [error] [SpkconServer.cpp:473] socket write error. fd=3 errorno=32 error=Broken pipe May 18 10:50:02 rivoplus sudo[7536]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 18 10:50:02 rivoplus sudo[7536]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 10:50:02 rivoplus systemd[1]: Stopping Volumio Tidal Connect Service... May 18 10:50:02 rivoplus systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM May 18 10:50:02 rivoplus systemd[1]: vtcs.service: Succeeded. May 18 10:50:02 rivoplus systemd[1]: Stopped Volumio Tidal Connect Service. May 18 10:50:02 rivoplus sudo[7536]: pam_unix(sudo:session): session closed for user root May 18 10:50:02 rivoplus volumio[6290]: No protocol specified May 18 10:50:02 rivoplus volumio[6290]: xcb_connection_has_error() returned true May 18 10:50:02 rivoplus volumio[6290]: info: CoreCommandRouter::volumioUpdateVolumeSettings May 18 10:50:02 rivoplus volumio[6290]: info: Updating Volume Controller Parameters: Device: 5 Name: Combo384 Amanero Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 May 18 10:50:02 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume May 18 10:50:02 rivoplus volumio[6290]: info: Disabling external Volume Control May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::getUIConfigOnPlugin May 18 10:50:03 rivoplus volumio[6290]: info: Preparing to generate the ALSA configuration file May 18 10:50:03 rivoplus sudo[7543]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 18 10:50:03 rivoplus sudo[7543]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 10:50:03 rivoplus sudo[7543]: pam_unix(sudo:session): session closed for user root May 18 10:50:03 rivoplus volumio[6290]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf May 18 10:50:03 rivoplus volumio[6290]: info: Reading ALSA contributions from plugins. May 18 10:50:03 rivoplus sudo[7550]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service May 18 10:50:03 rivoplus sudo[7550]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 10:50:03 rivoplus volumio[6290]: ------------------------------------ BT MESSAGE: BT STATUS: running May 18 10:50:03 rivoplus sudo[7550]: pam_unix(sudo:session): session closed for user root May 18 10:50:03 rivoplus volumio[6290]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: No protocol specified May 18 10:50:03 rivoplus volumio[6290]: xcb_connection_has_error() returned true May 18 10:50:03 rivoplus sudo[7552]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service May 18 10:50:03 rivoplus sudo[7552]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 10:50:03 rivoplus qobuz-connect[6545]: 20250518 10:50:03.300 [6545.6545] INFO SampleApp: Stopping Local configuration server May 18 10:50:03 rivoplus systemd[1]: Stopping Volumio Qobuz Connect Service... May 18 10:50:03 rivoplus qobuz-connect[6545]: 20250518 10:50:03.310 [6545.6545] INFO SampleApp: shat down connection on UNIX socket May 18 10:50:03 rivoplus volumio[6290]: ------------------------------------ BT MESSAGE: BT STATUS: running May 18 10:50:03 rivoplus systemd[1]: qobuz-connect.service: Succeeded. May 18 10:50:03 rivoplus systemd[1]: Stopped Volumio Qobuz Connect Service. May 18 10:50:03 rivoplus systemd[1]: Started Volumio Qobuz Connect Service. May 18 10:50:03 rivoplus sudo[7552]: pam_unix(sudo:session): session closed for user root May 18 10:50:03 rivoplus volumio[6290]: No protocol specified May 18 10:50:03 rivoplus volumio[6290]: xcb_connection_has_error() returned true May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 18 10:50:03 rivoplus volumio[6290]: No protocol specified May 18 10:50:03 rivoplus volumio[6290]: xcb_connection_has_error() returned true May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: raat , getAdditionalUiSection May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: inputs , getAdditionalUiSection May 18 10:50:03 rivoplus volumio[6290]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected May 18 10:50:03 rivoplus volumio[6290]: info: QobuzConnect: setDeactiveState invoked May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::volumioGetState May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 18 10:50:03 rivoplus volumio[6290]: info: Not Reporting Auto name since its the default one May 18 10:50:03 rivoplus volumio[6290]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 18 10:50:03 rivoplus volumio[6290]: info: VolumeController:: Volume=undefined Mute =false May 18 10:50:03 rivoplus volumio[6290]: info: CoreStateMachine::pushState May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::volumioPushState May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::volumioGetState May 18 10:50:03 rivoplus volumio[6290]: info: MRS: Pushing multiroomSync output update for this device May 18 10:50:03 rivoplus volumio[6290]: info: MRS: Pushing multiroomSync output May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: raat , restartRaat May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 18 10:50:03 rivoplus volumio[6290]: info: Not Reporting Auto name since its the default one May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::volumioGetQueue May 18 10:50:03 rivoplus volumio[6290]: info: CoreStateMachine::getQueue May 18 10:50:03 rivoplus volumio[6290]: info: CorePlayQueue::getQueue May 18 10:50:03 rivoplus volumio[6290]: info: Signalling Playback active due to playback status change May 18 10:50:03 rivoplus volumio[6290]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined May 18 10:50:03 rivoplus volumio[6290]: info: Updating RAAT Signal Path May 18 10:50:03 rivoplus volumio[6290]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined May 18 10:50:03 rivoplus volumio[6290]: info: Executing endpoint qc_getconfig May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig May 18 10:50:03 rivoplus qobuz-connect[7555]: 20250518 10:50:03.693 [7555.7555] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket May 18 10:50:03 rivoplus volumio[6290]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] May 18 10:50:03 rivoplus volumio[6290]: info: QobuzConnect: QOBUZ Connect daemon connected May 18 10:50:03 rivoplus qobuz-connect[7555]: 20250518 10:50:03.700 [7555.7555] INFO VolumeManager: [0xac956320]: Setting new playback volume: 75 May 18 10:50:03 rivoplus qobuz-connect[7555]: 20250518 10:50:03.700 [7555.7555] INFO VolumeManager: [0xac956320]: Setting new mute state: 0 May 18 10:50:03 rivoplus qobuz-connect[7555]: 20250518 10:50:03.700 [7555.7555] INFO QobuzConnect: [0xac956cf0]: Client initialized! May 18 10:50:03 rivoplus qobuz-connect[7555]: 20250518 10:50:03.700 [7555.7555] INFO SampleApp: Starting Avahi advertising, name: Rivoplus, service name: _qobuz-connect._tcp May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 10:50:03 rivoplus qobuz-connect[7555]: 20250518 10:50:03.713 [7555.7555] INFO LocalConfigManager: [0xac955c00]: Starting Local Configuration server May 18 10:50:03 rivoplus qobuz-connect[7555]: 20250518 10:50:03.713 [7555.7555] INFO SampleApp: Starting Local configuration server May 18 10:50:03 rivoplus qobuz-connect[7555]: 20250518 10:50:03.714 [7555.7555] INFO SampleApp: Connected to UNIX socket client 0xac94bed8 May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable May 18 10:50:03 rivoplus volumio[6290]: No protocol specified May 18 10:50:03 rivoplus volumio[6290]: xcb_connection_has_error() returned true May 18 10:50:03 rivoplus volumio[6290]: info: Asound.conf file unchanged, so no further update is needed May 18 10:50:03 rivoplus volumio[6290]: info: Output device has changed, restarting MPD May 18 10:50:03 rivoplus sudo[7577]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service May 18 10:50:03 rivoplus qobuz-connect[7555]: 20250518 10:50:03.843 [7555.7555] INFO SampleApp: Playback volume changed: 75 May 18 10:50:03 rivoplus sudo[7577]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 10:50:03 rivoplus sudo[7577]: pam_unix(sudo:session): session closed for user root May 18 10:50:03 rivoplus sudo[7580]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 18 10:50:03 rivoplus sudo[7580]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 10:50:03 rivoplus volumio[6290]: info: Output device has changed, restarting Shairport Sync May 18 10:50:03 rivoplus sudo[7581]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 10:50:03 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 18 10:50:03 rivoplus sudo[7581]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 10:50:03 rivoplus sudo[7580]: pam_unix(sudo:session): session closed for user root May 18 10:50:03 rivoplus sudo[7583]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 18 10:50:03 rivoplus sudo[7583]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 10:50:03 rivoplus systemd[1]: Started RAAT DAEMON. May 18 10:50:03 rivoplus sudo[7581]: pam_unix(sudo:session): session closed for user root May 18 10:50:03 rivoplus systemd[1]: Stopping Music Player Daemon... May 18 10:50:03 rivoplus mpd[6527]: player: played "http://192.168.1.5:10452/tidal/253992134.flac" May 18 10:50:04 rivoplus volumio[6290]: No protocol specified May 18 10:50:04 rivoplus volumio[6290]: xcb_connection_has_error() returned true May 18 10:50:04 rivoplus volumio[6290]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 18 10:50:04 rivoplus volumio[6290]: No protocol specified May 18 10:50:04 rivoplus volumio[6290]: xcb_connection_has_error() returned true May 18 10:50:04 rivoplus volumio[6290]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 18 10:50:04 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 10:50:04 rivoplus volumio[6290]: info: QobuzConnect: setDeactiveState invoked May 18 10:50:04 rivoplus volumio[6290]: info: CoreCommandRouter::volumioGetState May 18 10:50:04 rivoplus volumio[6290]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes May 18 10:50:04 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 10:50:04 rivoplus kernel: asoc-aml-card auge_sound: tdm playback stop May 18 10:50:04 rivoplus kernel: spdif_a is set to disable May 18 10:50:04 rivoplus kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 May 18 10:50:04 rivoplus kernel: aml_dai_tdm_hw_free(), disable mclk for TDM-B May 18 10:50:04 rivoplus kernel: tdm playback mute: 1, lane_cnt = 8 May 18 10:50:04 rivoplus kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:tdm@1 May 18 10:50:04 rivoplus sudo[7605]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 18 10:50:04 rivoplus sudo[7605]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 10:50:04 rivoplus sudo[7607]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 18 10:50:04 rivoplus sudo[7607]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 10:50:04 rivoplus systemd[1]: mpd.service: Succeeded. May 18 10:50:04 rivoplus systemd[1]: Stopped Music Player Daemon. May 18 10:50:04 rivoplus sudo[7605]: pam_unix(sudo:session): session closed for user root May 18 10:50:04 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable May 18 10:50:04 rivoplus sudo[7616]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service May 18 10:50:04 rivoplus sudo[7616]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 10:50:04 rivoplus systemd[1]: Starting Music Player Daemon... May 18 10:50:04 rivoplus sudo[7607]: pam_unix(sudo:session): session closed for user root May 18 10:50:04 rivoplus sudo[7616]: pam_unix(sudo:session): session closed for user root May 18 10:50:04 rivoplus volumio[6290]: No protocol specified May 18 10:50:04 rivoplus volumio[6290]: xcb_connection_has_error() returned true May 18 10:50:04 rivoplus sudo[7621]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service May 18 10:50:04 rivoplus sudo[7621]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 10:50:04 rivoplus qobuz-connect[7555]: 20250518 10:50:04.315 [7555.7555] INFO SampleApp: Stopping Local configuration server May 18 10:50:04 rivoplus systemd[1]: Stopping Volumio Qobuz Connect Service... May 18 10:50:04 rivoplus qobuz-connect[7555]: 20250518 10:50:04.326 [7555.7555] INFO SampleApp: shat down connection on UNIX socket May 18 10:50:04 rivoplus systemd[1]: qobuz-connect.service: Succeeded. May 18 10:50:04 rivoplus systemd[1]: Stopped Volumio Qobuz Connect Service. May 18 10:50:04 rivoplus sudo[7624]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service May 18 10:50:04 rivoplus sudo[7624]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 10:50:04 rivoplus systemd[1]: Started Volumio Qobuz Connect Service. May 18 10:50:04 rivoplus sudo[7621]: pam_unix(sudo:session): session closed for user root May 18 10:50:04 rivoplus volumio[6290]: ------------------------------------ BT MESSAGE: BT STATUS: running May 18 10:50:04 rivoplus sudo[7615]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 18 10:50:04 rivoplus sudo[7615]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 10:50:04 rivoplus volumio[6290]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 18 10:50:04 rivoplus sudo[7624]: pam_unix(sudo:session): session closed for user root May 18 10:50:04 rivoplus volumio[6290]: ------------------------------------ BT MESSAGE: BT STATUS: running May 18 10:50:04 rivoplus sudo[7615]: pam_unix(sudo:session): session closed for user root May 18 10:50:04 rivoplus sudo[7628]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service May 18 10:50:04 rivoplus sudo[7628]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 10:50:04 rivoplus volumio[6290]: ------------------------------------ BT MESSAGE: BT STATUS: running May 18 10:50:04 rivoplus volumio[6290]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 18 10:50:04 rivoplus volumio[6290]: info: CoreCommandRouter::volumioGetState May 18 10:50:04 rivoplus volumio[6290]: info: MPD Permissions set May 18 10:50:04 rivoplus systemd[1]: Stopping RAAT DAEMON... May 18 10:50:04 rivoplus volumio[6290]: info: Raat Daemon started successfully May 18 10:50:04 rivoplus volumio[6290]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected May 18 10:50:04 rivoplus volumio[6290]: info: QobuzConnect: setDeactiveState invoked May 18 10:50:04 rivoplus volumio[6290]: info: CoreCommandRouter::volumioGetState May 18 10:50:04 rivoplus systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM May 18 10:50:04 rivoplus systemd[1]: raat-daemon.service: Succeeded. May 18 10:50:04 rivoplus systemd[1]: Stopped RAAT DAEMON. May 18 10:50:04 rivoplus volumio[6290]: ------------------------------------ BT MESSAGE: BT STATUS: running May 18 10:50:04 rivoplus volumio[6290]: info: Executing endpoint restartRAATSocket May 18 10:50:04 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection May 18 10:50:04 rivoplus systemd[1]: Started RAAT DAEMON. May 18 10:50:04 rivoplus sudo[7628]: pam_unix(sudo:session): session closed for user root May 18 10:50:04 rivoplus volumio[6290]: info: Executing endpoint qc_getconfig May 18 10:50:04 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig May 18 10:50:04 rivoplus volumio[6290]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 18 10:50:04 rivoplus qobuz-connect[7626]: 20250518 10:50:04.538 [7626.7626] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket May 18 10:50:04 rivoplus qobuz-connect[7626]: 20250518 10:50:04.576 [7626.7626] INFO VolumeManager: [0xac1f7320]: Setting new playback volume: 75 May 18 10:50:04 rivoplus qobuz-connect[7626]: 20250518 10:50:04.576 [7626.7626] INFO VolumeManager: [0xac1f7320]: Setting new mute state: 0 May 18 10:50:04 rivoplus qobuz-connect[7626]: 20250518 10:50:04.576 [7626.7626] INFO QobuzConnect: [0xac1f7cf0]: Client initialized! May 18 10:50:04 rivoplus qobuz-connect[7626]: 20250518 10:50:04.576 [7626.7626] INFO SampleApp: Starting Avahi advertising, name: Rivoplus, service name: _qobuz-connect._tcp May 18 10:50:04 rivoplus volumio[6290]: info: Raat Daemon started successfully May 18 10:50:04 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 10:50:04 rivoplus qobuz-connect[7626]: 20250518 10:50:04.601 [7626.7626] INFO LocalConfigManager: [0xac1f6c00]: Starting Local Configuration server May 18 10:50:04 rivoplus qobuz-connect[7626]: 20250518 10:50:04.601 [7626.7626] INFO SampleApp: Starting Local configuration server May 18 10:50:04 rivoplus qobuz-connect[7626]: 20250518 10:50:04.602 [7626.7626] INFO SampleApp: Connected to UNIX socket client 0xac1eced8 May 18 10:50:04 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 18 10:50:04 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 18 10:50:04 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 10:50:04 rivoplus volumio[6290]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] May 18 10:50:04 rivoplus volumio[6290]: info: QobuzConnect: QOBUZ Connect daemon connected May 18 10:50:04 rivoplus qobuz-connect[7626]: 20250518 10:50:04.688 [7626.7626] INFO SampleApp: Playback volume changed: 75 May 18 10:50:04 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 10:50:04 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 10:50:04 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 10:50:04 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 10:50:04 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 10:50:04 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 10:50:04 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 10:50:04 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 10:50:04 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 18 10:50:04 rivoplus volumio[6290]: info: Not Reporting Auto name since its the default one May 18 10:50:04 rivoplus volumio[6290]: info: CoreCommandRouter::volumioGetState May 18 10:50:04 rivoplus volumio[6290]: info: Executing endpoint restartRAATSocket May 18 10:50:04 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection May 18 10:50:04 rivoplus volumio[6290]: info: Starting Shairport Sync May 18 10:50:04 rivoplus sudo[7659]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 18 10:50:04 rivoplus sudo[7659]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 10:50:04 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable May 18 10:50:04 rivoplus systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 18 10:50:04 rivoplus systemd[1]: shairport-sync.service: Succeeded. May 18 10:50:04 rivoplus systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 18 10:50:04 rivoplus systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 18 10:50:04 rivoplus sudo[7659]: pam_unix(sudo:session): session closed for user root May 18 10:50:04 rivoplus volumio[6290]: No protocol specified May 18 10:50:04 rivoplus volumio[6290]: xcb_connection_has_error() returned true May 18 10:50:04 rivoplus volumio[6290]: ------------------------------------ BT MESSAGE: BT STATUS: running May 18 10:50:04 rivoplus volumio[6290]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 18 10:50:04 rivoplus sudo[7667]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service May 18 10:50:04 rivoplus sudo[7667]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 10:50:04 rivoplus volumio[6290]: info: Shairport-Sync Started May 18 10:50:04 rivoplus volumio[6290]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 May 18 10:50:04 rivoplus sudo[7667]: pam_unix(sudo:session): session closed for user root May 18 10:50:05 rivoplus sudo[7670]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service May 18 10:50:05 rivoplus sudo[7670]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 10:50:05 rivoplus systemd[1]: Stopping RAAT DAEMON... May 18 10:50:05 rivoplus systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM May 18 10:50:05 rivoplus systemd[1]: raat-daemon.service: Succeeded. May 18 10:50:05 rivoplus systemd[1]: Stopped RAAT DAEMON. May 18 10:50:05 rivoplus volumio[6290]: ------------------------------------ BT MESSAGE: BT STATUS: running May 18 10:50:05 rivoplus volumio[6290]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 18 10:50:05 rivoplus systemd[1]: Started RAAT DAEMON. May 18 10:50:05 rivoplus sudo[7670]: pam_unix(sudo:session): session closed for user root May 18 10:50:05 rivoplus volumio[6290]: info: Raat Daemon started successfully May 18 10:50:05 rivoplus volumio[6290]: info: Executing endpoint restartRAATSocket May 18 10:50:05 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection May 18 10:50:05 rivoplus volumio[6290]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 May 18 10:50:05 rivoplus volumio[6290]: info: TidalConnect service stoped! May 18 10:50:06 rivoplus volumio[6290]: info: TidalConnect service stoped! May 18 10:50:06 rivoplus volumio[6290]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 18 10:50:06 rivoplus volumio[6290]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect May 18 10:50:06 rivoplus sudo[7709]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service May 18 10:50:06 rivoplus sudo[7709]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 10:50:06 rivoplus systemd[1]: Started Volumio Tidal Connect Service. May 18 10:50:06 rivoplus sudo[7709]: pam_unix(sudo:session): session closed for user root May 18 10:50:06 rivoplus mpd[7632]: May 18 10:50 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 18 10:50:06 rivoplus systemd[1]: Started Music Player Daemon. May 18 10:50:06 rivoplus sudo[7583]: pam_unix(sudo:session): session closed for user root May 18 10:50:06 rivoplus volumio[6290]: error: updateQueue error: null May 18 10:50:06 rivoplus volumio[6290]: info: Executing endpoint tc_getconfig May 18 10:50:06 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig May 18 10:50:06 rivoplus vtcs[7711]: STARTING TidalConnect services, version: 1.4.0.34 May 18 10:50:06 rivoplus volumio[6290]: info: RAAT: Requesting Headphone Status May 18 10:50:06 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus May 18 10:50:06 rivoplus volumio[6290]: info: MCU Signalled Headphone Mode Disabled May 18 10:50:06 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState May 18 10:50:06 rivoplus volumio[6290]: info: Reporting Headphone State: false May 18 10:50:06 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 10:50:06 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 10:50:06 rivoplus volumio[6290]: info: Updating RAAT Signal Path May 18 10:50:06 rivoplus vtcs[7711]: STARTED TidalConnect services. May 18 10:50:06 rivoplus volumio[6290]: info: Executing endpoint tc_connect May 18 10:50:06 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect May 18 10:50:06 rivoplus volumio[6290]: info: Connecting to TidalConnect May 18 10:50:06 rivoplus volumio[6290]: info: CoreCommandRouter::servicePushState May 18 10:50:06 rivoplus volumio[6290]: info: CoreStateMachine::pushState May 18 10:50:06 rivoplus volumio[6290]: info: CoreCommandRouter::volumioPushState May 18 10:50:06 rivoplus volumio[6290]: info: CoreCommandRouter::volumioGetState May 18 10:50:06 rivoplus volumio[6290]: info: MRS: Pushing multiroomSync output update for this device May 18 10:50:06 rivoplus volumio[6290]: info: MRS: Pushing multiroomSync output May 18 10:50:06 rivoplus volumio[6290]: info: CorePlayQueue::getTrack 1 May 18 10:50:06 rivoplus volumio[6290]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current mpd Received tidalconnect May 18 10:50:06 rivoplus volumio[6290]: info: CoreCommandRouter::servicePushState May 18 10:50:06 rivoplus volumio[6290]: info: CoreStateMachine::pushState May 18 10:50:06 rivoplus volumio[6290]: info: CoreCommandRouter::volumioPushState May 18 10:50:06 rivoplus volumio[6290]: info: CoreCommandRouter::volumioGetState May 18 10:50:06 rivoplus volumio[6290]: info: MRS: Pushing multiroomSync output update for this device May 18 10:50:06 rivoplus volumio[6290]: info: MRS: Pushing multiroomSync output May 18 10:50:06 rivoplus volumio[6290]: info: CorePlayQueue::getTrack 1 May 18 10:50:06 rivoplus volumio[6290]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current mpd Received tidalconnect May 18 10:50:06 rivoplus volumio[6290]: info: CoreCommandRouter::volumioGetQueue May 18 10:50:06 rivoplus volumio[6290]: info: CoreStateMachine::getQueue May 18 10:50:06 rivoplus volumio[6290]: info: CorePlayQueue::getQueue May 18 10:50:06 rivoplus volumio[6290]: info: CoreCommandRouter::volumioGetQueue May 18 10:50:06 rivoplus volumio[6290]: info: CoreStateMachine::getQueue May 18 10:50:06 rivoplus volumio[6290]: info: CorePlayQueue::getQueue May 18 10:50:06 rivoplus volumio[6290]: info: Signalling Playback active due to playback status change May 18 10:50:06 rivoplus volumio[6290]: info: Signalling Playback active due to playback status change May 18 10:50:06 rivoplus volumio[6290]: info: Updating RAAT Signal Path May 18 10:50:07 rivoplus volumio[6290]: info: CoreCommandRouter::volumioRetrieveVolumeLevels May 18 10:50:07 rivoplus volumio[6290]: info: CoreStateMachine::getcurrentVolume May 18 10:50:07 rivoplus volumio[6290]: info: CoreCommandRouter::volumioRetrievevolume May 18 10:50:07 rivoplus volumio[6290]: info: VolumeController:: Volume=100 Mute =false May 18 10:50:07 rivoplus volumio[6290]: info: CoreStateMachine::pushState May 18 10:50:07 rivoplus volumio[6290]: info: CoreCommandRouter::volumioPushState May 18 10:50:07 rivoplus volumio[6290]: info: CoreCommandRouter::volumioGetState May 18 10:50:07 rivoplus volumio[6290]: info: MRS: Pushing multiroomSync output update for this device May 18 10:50:07 rivoplus volumio[6290]: info: MRS: Pushing multiroomSync output May 18 10:50:07 rivoplus volumio[6290]: info: CoreStateMachine::updateTrackBlock May 18 10:50:07 rivoplus volumio[6290]: info: CorePlayQueue::getTrackBlock May 18 10:50:07 rivoplus volumio[6290]: info: CoreCommandRouter::volumioRetrievevolume May 18 10:50:07 rivoplus volumio[6290]: info: CoreCommandRouter::volumioGetQueue May 18 10:50:07 rivoplus volumio[6290]: info: CoreStateMachine::getQueue May 18 10:50:07 rivoplus volumio[6290]: info: CorePlayQueue::getQueue May 18 10:50:07 rivoplus volumio[6290]: info: Signalling Playback active due to playback status change May 18 10:50:07 rivoplus volumio[6290]: info: Updating RAAT Signal Path May 18 10:50:07 rivoplus volumio[6290]: info: TidalConnect service stoped! May 18 10:50:07 rivoplus volumio[6290]: info: TidalConnect service stoped! May 18 10:50:07 rivoplus volumio[6290]: info: RAAT: Requesting Headphone Status May 18 10:50:07 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus May 18 10:50:07 rivoplus volumio[6290]: info: VolumeController:: Volume=100 Mute =false May 18 10:50:07 rivoplus volumio[6290]: info: CoreStateMachine::pushState May 18 10:50:07 rivoplus volumio[6290]: info: CoreCommandRouter::volumioPushState May 18 10:50:07 rivoplus volumio[6290]: info: CoreCommandRouter::volumioGetState May 18 10:50:07 rivoplus volumio[6290]: info: MRS: Pushing multiroomSync output update for this device May 18 10:50:07 rivoplus volumio[6290]: info: MRS: Pushing multiroomSync output May 18 10:50:07 rivoplus volumio[6290]: info: CoreCommandRouter::volumioGetQueue May 18 10:50:07 rivoplus volumio[6290]: info: CoreStateMachine::getQueue May 18 10:50:07 rivoplus volumio[6290]: info: CorePlayQueue::getQueue May 18 10:50:07 rivoplus volumio[6290]: info: Signalling Playback active due to playback status change May 18 10:50:07 rivoplus volumio[6290]: info: Updating RAAT Signal Path May 18 10:50:07 rivoplus volumio[6290]: info: MCU Signalled Headphone Mode Disabled May 18 10:50:07 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState May 18 10:50:07 rivoplus volumio[6290]: info: Reporting Headphone State: false May 18 10:50:07 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 10:50:07 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 10:50:07 rivoplus volumio[6290]: info: Updating RAAT Signal Path May 18 10:50:07 rivoplus volumio[6290]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 18 10:50:07 rivoplus volumio[6290]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect May 18 10:50:07 rivoplus sudo[7749]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service May 18 10:50:07 rivoplus sudo[7749]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 10:50:07 rivoplus sudo[7749]: pam_unix(sudo:session): session closed for user root May 18 10:50:07 rivoplus volumio[6290]: info: RAAT: Requesting Headphone Status May 18 10:50:07 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus May 18 10:50:07 rivoplus volumio[6290]: info: MCU Signalled Headphone Mode Disabled May 18 10:50:07 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState May 18 10:50:07 rivoplus volumio[6290]: info: Reporting Headphone State: false May 18 10:50:07 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 10:50:07 rivoplus volumio[6290]: info: Updating RAAT Signal Path May 18 10:50:09 rivoplus volumio[6290]: info: TidalConnect service started! May 18 10:50:10 rivoplus volumio[6290]: info: TidalConnect service started! May 18 10:50:10 rivoplus volumio[6290]: info: Clearing queue after UPNP request May 18 10:50:11 rivoplus volumio[6290]: info: CoreStateMachine::ClearQueue May 18 10:50:11 rivoplus volumio[6290]: info: CoreStateMachine::stop May 18 10:50:11 rivoplus volumio[6290]: info: CoreStateMachine::setConsumeUpdateService undefined May 18 10:50:11 rivoplus volumio[6290]: info: CoreStateMachine::updateTrackBlock May 18 10:50:11 rivoplus volumio[6290]: info: CorePlayQueue::getTrackBlock May 18 10:50:11 rivoplus volumio[6290]: info: CoreStateMachine::stPlaybackTimer May 18 10:50:11 rivoplus volumio[6290]: info: CoreStateMachine::pushState May 18 10:50:11 rivoplus volumio[6290]: info: CorePlayQueue::getTrack 1 May 18 10:50:11 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 10:50:11 rivoplus volumio[6290]: info: CoreCommandRouter::volumioPushState May 18 10:50:11 rivoplus volumio[6290]: info: CoreCommandRouter::volumioGetState May 18 10:50:11 rivoplus volumio[6290]: info: CorePlayQueue::getTrack 1 May 18 10:50:11 rivoplus volumio[6290]: info: MRS: Pushing multiroomSync output update for this device May 18 10:50:11 rivoplus volumio[6290]: info: MRS: Pushing multiroomSync output May 18 10:50:11 rivoplus volumio[6290]: info: CoreStateMachine::serviceStop May 18 10:50:11 rivoplus volumio[6290]: info: CorePlayQueue::getTrack 1 May 18 10:50:11 rivoplus volumio[6290]: info: ControllerMpd::stop May 18 10:50:11 rivoplus volumio[6290]: verbose: ControllerMpd::sendMpdCommand stop May 18 10:50:11 rivoplus volumio[6290]: info: CorePlayQueue::clearPlayQueue May 18 10:50:11 rivoplus volumio[6290]: info: CorePlayQueue::saveQueue May 18 10:50:11 rivoplus volumio[6290]: info: CoreCommandRouter::volumioPushState May 18 10:50:11 rivoplus volumio[6290]: info: CoreCommandRouter::volumioGetState May 18 10:50:11 rivoplus volumio[6290]: info: CorePlayQueue::getTrack 1 May 18 10:50:11 rivoplus volumio[6290]: info: MRS: Pushing multiroomSync output update for this device May 18 10:50:11 rivoplus volumio[6290]: info: MRS: Pushing multiroomSync output May 18 10:50:11 rivoplus volumio[6290]: info: CoreCommandRouter::volumioPushQueue May 18 10:50:11 rivoplus volumio[6290]: info: Updating RAAT Signal Path May 18 10:50:11 rivoplus volumio[6290]: info: Updating RAAT Signal Path May 18 10:50:11 rivoplus volumio[6290]: info: May 18 10:50:11 rivoplus volumio[6290]: ---------------------------- MPD announces system playlist update May 18 10:50:11 rivoplus volumio[6290]: info: Ignoring MPD Status Update May 18 10:50:11 rivoplus volumio[6290]: info: sendMpdCommand stop took 50 milliseconds May 18 10:50:11 rivoplus volumio[6290]: error: updateQueue error: null May 18 10:50:11 rivoplus volumio[6290]: info: ------------------------------ 4ms May 18 10:50:11 rivoplus volumio[6290]: info: Starting UPNP Playback May 18 10:50:11 rivoplus volumio[6290]: info: Preparing playback through UPNP May 18 10:50:11 rivoplus volumio[6290]: info: CoreCommandRouter::volumioGetState May 18 10:50:11 rivoplus volumio[6290]: info: CorePlayQueue::getTrack 1 May 18 10:50:11 rivoplus volumio[6290]: info: CoreStateMachine::setConsumeUpdateService mpd May 18 10:50:11 rivoplus volumio[6290]: info: MCU Signalled Playback Inactive May 18 10:50:11 rivoplus volumio[6290]: info: May 18 10:50:11 rivoplus volumio[6290]: ---------------------------- MPD announces system playlist update May 18 10:50:11 rivoplus volumio[6290]: info: Ignoring MPD Status Update May 18 10:50:11 rivoplus volumio[6290]: info: ------------------------------ 3ms May 18 10:50:11 rivoplus volumio[6290]: info: May 18 10:50:11 rivoplus volumio[6290]: ---------------------------- MPD announces system playlist update May 18 10:50:11 rivoplus volumio[6290]: info: Ignoring MPD Status Update May 18 10:50:11 rivoplus volumio[6290]: info: ------------------------------ 2ms May 18 10:50:11 rivoplus volumio[6290]: info: May 18 10:50:11 rivoplus volumio[6290]: ---------------------------- MPD announces system playlist update May 18 10:50:11 rivoplus volumio[6290]: info: Ignoring MPD Status Update May 18 10:50:11 rivoplus volumio[6290]: info: May 18 10:50:11 rivoplus volumio[6290]: ---------------------------- MPD announces system playlist update May 18 10:50:11 rivoplus volumio[6290]: info: Ignoring MPD Status Update May 18 10:50:11 rivoplus volumio[6290]: info: ------------------------------ 3ms May 18 10:50:11 rivoplus volumio[6290]: info: ------------------------------ 3ms May 18 10:50:11 rivoplus volumio[6290]: info: May 18 10:50:11 rivoplus volumio[6290]: ---------------------------- MPD announces system playlist update May 18 10:50:11 rivoplus volumio[6290]: info: Ignoring MPD Status Update May 18 10:50:11 rivoplus volumio[6290]: info: ------------------------------ 2ms May 18 10:50:11 rivoplus volumio[6290]: info: May 18 10:50:11 rivoplus volumio[6290]: ---------------------------- MPD announces system playlist update May 18 10:50:11 rivoplus volumio[6290]: info: Ignoring MPD Status Update May 18 10:50:11 rivoplus volumio[6290]: info: ------------------------------ 2ms May 18 10:50:11 rivoplus volumio[6290]: error: error May 18 10:50:11 rivoplus volumio[6290]: info: May 18 10:50:11 rivoplus volumio[6290]: ---------------------------- MPD announces state update: player May 18 10:50:11 rivoplus volumio[6290]: info: ControllerMpd::getState May 18 10:50:11 rivoplus volumio[6290]: verbose: ControllerMpd::sendMpdCommand status May 18 10:50:11 rivoplus volumio[6290]: info: sendMpdCommand status took 1 milliseconds May 18 10:50:11 rivoplus volumio[6290]: verbose: ControllerMpd::parseState May 18 10:50:11 rivoplus volumio[6290]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 10:50:11 rivoplus volumio[6290]: info: sendMpdCommand playlistinfo took 1 milliseconds May 18 10:50:11 rivoplus volumio[6290]: verbose: ControllerMpd::parseTrackInfo May 18 10:50:11 rivoplus volumio[6290]: info: ControllerMpd::pushState May 18 10:50:11 rivoplus volumio[6290]: info: CoreCommandRouter::servicePushState May 18 10:50:11 rivoplus volumio[6290]: verbose: In UPNP mode May 18 10:50:11 rivoplus volumio[6290]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":0,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Japanese Roots","artist":"TakéDaké","album":"Asian Roots","uri":"http://192.168.1.5:10452/tidal/99219623.flac","trackType":"tidal"} May 18 10:50:11 rivoplus volumio[6290]: verbose: CURRENT POSITION 1 May 18 10:50:11 rivoplus volumio[6290]: info: CoreStateMachine::syncState stateService pause May 18 10:50:11 rivoplus volumio[6290]: info: CoreStateMachine::syncState currentStatus stop May 18 10:50:11 rivoplus volumio[6290]: info: CoreStateMachine::pushState May 18 10:50:11 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 10:50:11 rivoplus volumio[6290]: info: CoreCommandRouter::volumioPushState May 18 10:50:11 rivoplus volumio[6290]: info: CoreCommandRouter::volumioGetState May 18 10:50:11 rivoplus volumio[6290]: info: MRS: Pushing multiroomSync output update for this device May 18 10:50:11 rivoplus volumio[6290]: info: MRS: Pushing multiroomSync output May 18 10:50:11 rivoplus volumio[6290]: info: ------------------------------ 22ms May 18 10:50:11 rivoplus volumio[6290]: info: CoreCommandRouter::volumioGetQueue May 18 10:50:11 rivoplus volumio[6290]: info: CoreStateMachine::getQueue May 18 10:50:11 rivoplus volumio[6290]: info: CorePlayQueue::getQueue May 18 10:50:11 rivoplus volumio[6290]: info: Signalling Playback active due to playback status change May 18 10:50:11 rivoplus volumio[6290]: info: Updating RAAT Signal Path May 18 10:50:12 rivoplus volumio[6290]: info: MCU Signalled Playback Active May 18 10:50:12 rivoplus volumio[6290]: info: May 18 10:50:12 rivoplus volumio[6290]: ---------------------------- MPD announces state update: player May 18 10:50:12 rivoplus volumio[6290]: info: ControllerMpd::getState May 18 10:50:12 rivoplus volumio[6290]: verbose: ControllerMpd::sendMpdCommand status May 18 10:50:12 rivoplus volumio[6290]: info: sendMpdCommand status took 2 milliseconds May 18 10:50:12 rivoplus volumio[6290]: verbose: ControllerMpd::parseState May 18 10:50:12 rivoplus volumio[6290]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 10:50:12 rivoplus volumio[6290]: info: sendMpdCommand playlistinfo took 2 milliseconds May 18 10:50:12 rivoplus volumio[6290]: verbose: ControllerMpd::parseTrackInfo May 18 10:50:12 rivoplus volumio[6290]: info: ControllerMpd::pushState May 18 10:50:12 rivoplus volumio[6290]: info: CoreCommandRouter::servicePushState May 18 10:50:12 rivoplus volumio[6290]: verbose: In UPNP mode May 18 10:50:12 rivoplus volumio[6290]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":457,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Japanese Roots","artist":"TakéDaké","album":"Asian Roots","uri":"http://192.168.1.5:10452/tidal/99219623.flac","trackType":"tidal"} May 18 10:50:12 rivoplus volumio[6290]: verbose: CURRENT POSITION 1 May 18 10:50:12 rivoplus volumio[6290]: info: CoreStateMachine::syncState stateService pause May 18 10:50:12 rivoplus volumio[6290]: info: CoreStateMachine::syncState currentStatus stop May 18 10:50:12 rivoplus volumio[6290]: info: CoreStateMachine::pushState May 18 10:50:12 rivoplus volumio[6290]: info: CoreCommandRouter::volumioPushState May 18 10:50:12 rivoplus volumio[6290]: info: CoreCommandRouter::volumioGetState May 18 10:50:12 rivoplus volumio[6290]: info: MRS: Pushing multiroomSync output update for this device May 18 10:50:12 rivoplus volumio[6290]: info: MRS: Pushing multiroomSync output May 18 10:50:12 rivoplus volumio[6290]: info: ------------------------------ 38ms May 18 10:50:12 rivoplus volumio[6290]: info: CoreCommandRouter::volumioGetQueue May 18 10:50:12 rivoplus volumio[6290]: info: CoreStateMachine::getQueue May 18 10:50:12 rivoplus volumio[6290]: info: CorePlayQueue::getQueue May 18 10:50:12 rivoplus volumio[6290]: info: Signalling Playback active due to playback status change May 18 10:50:12 rivoplus volumio[6290]: info: Updating RAAT Signal Path May 18 10:50:13 rivoplus volumio[6290]: info: Executing endpoint metavolumio May 18 10:50:13 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 18 10:50:14 rivoplus volumio[6290]: info: Executing endpoint metavolumio May 18 10:50:14 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 18 10:50:14 rivoplus volumio[6290]: info: Executing endpoint metavolumio May 18 10:50:14 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 18 10:50:19 rivoplus volumio[6290]: info: May 18 10:50:19 rivoplus volumio[6290]: ---------------------------- MPD announces state update: player May 18 10:50:19 rivoplus volumio[6290]: info: ControllerMpd::getState May 18 10:50:19 rivoplus volumio[6290]: verbose: ControllerMpd::sendMpdCommand status May 18 10:50:19 rivoplus volumio[6290]: info: sendMpdCommand status took 3 milliseconds May 18 10:50:19 rivoplus volumio[6290]: verbose: ControllerMpd::parseState May 18 10:50:19 rivoplus volumio[6290]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 10:50:19 rivoplus volumio[6290]: info: sendMpdCommand playlistinfo took 2 milliseconds May 18 10:50:19 rivoplus volumio[6290]: verbose: ControllerMpd::parseTrackInfo May 18 10:50:19 rivoplus volumio[6290]: info: ControllerMpd::pushState May 18 10:50:19 rivoplus volumio[6290]: info: CoreCommandRouter::servicePushState May 18 10:50:19 rivoplus volumio[6290]: verbose: In UPNP mode May 18 10:50:19 rivoplus volumio[6290]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":457,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Japanese Roots","artist":"TakéDaké","album":"Asian Roots","uri":"http://192.168.1.5:10452/tidal/99219623.flac","trackType":"tidal"} May 18 10:50:19 rivoplus volumio[6290]: verbose: CURRENT POSITION 1 May 18 10:50:19 rivoplus volumio[6290]: info: CoreStateMachine::syncState stateService play May 18 10:50:19 rivoplus volumio[6290]: info: CoreStateMachine::syncState currentStatus stop May 18 10:50:19 rivoplus volumio[6290]: info: ------------------------------ 11ms May 18 10:50:21 rivoplus volumio[6290]: error: Failed request for metavolumio API May 18 10:50:21 rivoplus volumio[6290]: error: Failed request for metavolumio API May 18 10:50:29 rivoplus volumio[6290]: info: May 18 10:50:29 rivoplus volumio[6290]: ---------------------------- MPD announces state update: player May 18 10:50:29 rivoplus volumio[6290]: info: ControllerMpd::getState May 18 10:50:29 rivoplus volumio[6290]: verbose: ControllerMpd::sendMpdCommand status May 18 10:50:29 rivoplus volumio[6290]: info: sendMpdCommand status took 3 milliseconds May 18 10:50:29 rivoplus volumio[6290]: verbose: ControllerMpd::parseState May 18 10:50:29 rivoplus volumio[6290]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 10:50:29 rivoplus volumio[6290]: info: sendMpdCommand playlistinfo took 1 milliseconds May 18 10:50:29 rivoplus volumio[6290]: verbose: ControllerMpd::parseTrackInfo May 18 10:50:29 rivoplus volumio[6290]: info: ControllerMpd::pushState May 18 10:50:29 rivoplus volumio[6290]: info: CoreCommandRouter::servicePushState May 18 10:50:29 rivoplus volumio[6290]: info: CoreStateMachine::pushState May 18 10:50:29 rivoplus volumio[6290]: info: CoreCommandRouter::volumioPushState May 18 10:50:29 rivoplus volumio[6290]: info: CoreCommandRouter::volumioGetState May 18 10:50:29 rivoplus volumio[6290]: info: MRS: Pushing multiroomSync output update for this device May 18 10:50:29 rivoplus volumio[6290]: info: MRS: Pushing multiroomSync output May 18 10:50:29 rivoplus volumio[6290]: info: CorePlayQueue::getTrack 1 May 18 10:50:29 rivoplus volumio[6290]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Japanese Roots","artist":"TakéDaké","album":"Asian Roots","uri":"http://192.168.1.5:10452/tidal/99219623.flac","trackType":"tidal"} May 18 10:50:29 rivoplus volumio[6290]: verbose: CURRENT POSITION 1 May 18 10:50:29 rivoplus volumio[6290]: info: CoreStateMachine::syncState stateService stop May 18 10:50:29 rivoplus volumio[6290]: info: CoreStateMachine::syncState currentStatus play May 18 10:50:29 rivoplus volumio[6290]: info: CoreCommandRouter::volumioPushState May 18 10:50:29 rivoplus volumio[6290]: info: CoreCommandRouter::volumioGetState May 18 10:50:29 rivoplus volumio[6290]: info: MRS: Pushing multiroomSync output update for this device May 18 10:50:29 rivoplus volumio[6290]: info: MRS: Pushing multiroomSync output May 18 10:50:29 rivoplus volumio[6290]: info: CoreStateMachine::stPlaybackTimer May 18 10:50:29 rivoplus volumio[6290]: info: ------------------------------ 38ms May 18 10:50:29 rivoplus volumio[6290]: info: CoreCommandRouter::volumioGetQueue May 18 10:50:29 rivoplus volumio[6290]: info: CoreStateMachine::getQueue May 18 10:50:29 rivoplus volumio[6290]: info: CorePlayQueue::getQueue May 18 10:50:29 rivoplus volumio[6290]: info: Signalling Playback active due to playback status change May 18 10:50:29 rivoplus volumio[6290]: info: Updating RAAT Signal Path May 18 10:50:29 rivoplus volumio[6290]: info: Updating RAAT Signal Path May 18 10:50:29 rivoplus volumio[6290]: info: MCU Signalled Playback Inactive May 18 10:50:38 rivoplus volumio[6290]: info: Clearing queue after UPNP request May 18 10:50:38 rivoplus volumio[6290]: info: CoreStateMachine::ClearQueue May 18 10:50:38 rivoplus volumio[6290]: info: CoreStateMachine::stop May 18 10:50:38 rivoplus volumio[6290]: info: CoreStateMachine::setConsumeUpdateService undefined May 18 10:50:38 rivoplus volumio[6290]: info: CorePlayQueue::clearPlayQueue May 18 10:50:38 rivoplus volumio[6290]: info: CorePlayQueue::saveQueue May 18 10:50:38 rivoplus volumio[6290]: info: CoreCommandRouter::volumioPushState May 18 10:50:38 rivoplus volumio[6290]: info: CoreCommandRouter::volumioGetState May 18 10:50:38 rivoplus volumio[6290]: info: CorePlayQueue::getTrack 0 May 18 10:50:38 rivoplus volumio[6290]: info: MRS: Pushing multiroomSync output update for this device May 18 10:50:38 rivoplus volumio[6290]: info: MRS: Pushing multiroomSync output May 18 10:50:38 rivoplus volumio[6290]: info: CoreCommandRouter::volumioPushQueue May 18 10:50:38 rivoplus volumio[6290]: info: Updating RAAT Signal Path May 18 10:50:38 rivoplus volumio[6290]: info: May 18 10:50:38 rivoplus volumio[6290]: ---------------------------- MPD announces system playlist update May 18 10:50:38 rivoplus volumio[6290]: info: Ignoring MPD Status Update May 18 10:50:38 rivoplus volumio[6290]: error: updateQueue error: null May 18 10:50:38 rivoplus volumio[6290]: info: ------------------------------ 3ms May 18 10:50:38 rivoplus volumio[6290]: info: Starting UPNP Playback May 18 10:50:38 rivoplus volumio[6290]: info: Preparing playback through UPNP May 18 10:50:38 rivoplus volumio[6290]: info: CoreCommandRouter::volumioGetState May 18 10:50:38 rivoplus volumio[6290]: info: CorePlayQueue::getTrack 0 May 18 10:50:38 rivoplus volumio[6290]: info: CoreStateMachine::setConsumeUpdateService mpd May 18 10:50:38 rivoplus volumio[6290]: info: May 18 10:50:38 rivoplus volumio[6290]: ---------------------------- MPD announces system playlist update May 18 10:50:38 rivoplus volumio[6290]: info: Ignoring MPD Status Update May 18 10:50:38 rivoplus volumio[6290]: info: ------------------------------ 2ms May 18 10:50:38 rivoplus volumio[6290]: info: May 18 10:50:38 rivoplus volumio[6290]: ---------------------------- MPD announces system playlist update May 18 10:50:38 rivoplus volumio[6290]: info: Ignoring MPD Status Update May 18 10:50:38 rivoplus volumio[6290]: info: May 18 10:50:38 rivoplus volumio[6290]: ---------------------------- MPD announces system playlist update May 18 10:50:38 rivoplus volumio[6290]: info: Ignoring MPD Status Update May 18 10:50:38 rivoplus volumio[6290]: info: ------------------------------ 3ms May 18 10:50:38 rivoplus volumio[6290]: info: ------------------------------ 2ms May 18 10:50:38 rivoplus volumio[6290]: info: May 18 10:50:38 rivoplus volumio[6290]: ---------------------------- MPD announces system playlist update May 18 10:50:38 rivoplus volumio[6290]: info: Ignoring MPD Status Update May 18 10:50:38 rivoplus volumio[6290]: info: May 18 10:50:38 rivoplus volumio[6290]: ---------------------------- MPD announces system playlist update May 18 10:50:38 rivoplus volumio[6290]: info: Ignoring MPD Status Update May 18 10:50:38 rivoplus volumio[6290]: info: ------------------------------ 3ms May 18 10:50:38 rivoplus volumio[6290]: info: ------------------------------ 2ms May 18 10:50:38 rivoplus volumio[6290]: info: May 18 10:50:38 rivoplus volumio[6290]: ---------------------------- MPD announces system playlist update May 18 10:50:38 rivoplus volumio[6290]: info: Ignoring MPD Status Update May 18 10:50:38 rivoplus volumio[6290]: info: ------------------------------ 2ms May 18 10:50:39 rivoplus volumio[6290]: info: May 18 10:50:39 rivoplus volumio[6290]: ---------------------------- MPD announces state update: player May 18 10:50:39 rivoplus volumio[6290]: info: ControllerMpd::getState May 18 10:50:39 rivoplus volumio[6290]: verbose: ControllerMpd::sendMpdCommand status May 18 10:50:39 rivoplus volumio[6290]: info: sendMpdCommand status took 27 milliseconds May 18 10:50:39 rivoplus volumio[6290]: verbose: ControllerMpd::parseState May 18 10:50:39 rivoplus volumio[6290]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 10:50:39 rivoplus volumio[6290]: info: May 18 10:50:39 rivoplus volumio[6290]: ---------------------------- MPD announces state update: player May 18 10:50:39 rivoplus volumio[6290]: info: ControllerMpd::getState May 18 10:50:39 rivoplus volumio[6290]: verbose: ControllerMpd::sendMpdCommand status May 18 10:50:39 rivoplus volumio[6290]: info: sendMpdCommand playlistinfo took 2 milliseconds May 18 10:50:39 rivoplus volumio[6290]: verbose: ControllerMpd::parseTrackInfo May 18 10:50:39 rivoplus volumio[6290]: info: ControllerMpd::pushState May 18 10:50:39 rivoplus volumio[6290]: info: CoreCommandRouter::servicePushState May 18 10:50:39 rivoplus volumio[6290]: verbose: In UPNP mode May 18 10:50:39 rivoplus volumio[6290]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":284,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Ghemmà","artist":"Fausto Mesolella","album":"Canto Stefano","uri":"http://192.168.1.5:10452/tidal/52027342.flac","trackType":"tidal"} May 18 10:50:39 rivoplus volumio[6290]: verbose: CURRENT POSITION 0 May 18 10:50:39 rivoplus volumio[6290]: info: CoreStateMachine::syncState stateService play May 18 10:50:39 rivoplus volumio[6290]: info: CoreStateMachine::syncState currentStatus stop May 18 10:50:39 rivoplus volumio[6290]: info: ------------------------------ 34ms May 18 10:50:39 rivoplus volumio[6290]: info: sendMpdCommand status took 4 milliseconds May 18 10:50:39 rivoplus volumio[6290]: verbose: ControllerMpd::parseState May 18 10:50:39 rivoplus volumio[6290]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 10:50:39 rivoplus volumio[6290]: info: sendMpdCommand playlistinfo took 1 milliseconds May 18 10:50:39 rivoplus volumio[6290]: verbose: ControllerMpd::parseTrackInfo May 18 10:50:39 rivoplus volumio[6290]: info: ControllerMpd::pushState May 18 10:50:39 rivoplus volumio[6290]: info: CoreCommandRouter::servicePushState May 18 10:50:39 rivoplus volumio[6290]: verbose: In UPNP mode May 18 10:50:39 rivoplus volumio[6290]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":284,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Ghemmà","artist":"Fausto Mesolella","album":"Canto Stefano","uri":"http://192.168.1.5:10452/tidal/52027342.flac","trackType":"tidal"} May 18 10:50:39 rivoplus volumio[6290]: verbose: CURRENT POSITION 0 May 18 10:50:39 rivoplus volumio[6290]: info: CoreStateMachine::syncState stateService play May 18 10:50:39 rivoplus volumio[6290]: info: CoreStateMachine::syncState currentStatus play May 18 10:50:39 rivoplus volumio[6290]: info: Received an update from plugin. extracting info from payload May 18 10:50:39 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 18 10:50:39 rivoplus volumio[6290]: info: CoreStateMachine::pushState May 18 10:50:39 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 10:50:39 rivoplus volumio[6290]: info: CoreCommandRouter::volumioPushState May 18 10:50:39 rivoplus volumio[6290]: info: CoreCommandRouter::volumioGetState May 18 10:50:39 rivoplus volumio[6290]: info: MRS: Pushing multiroomSync output update for this device May 18 10:50:39 rivoplus volumio[6290]: info: MRS: Pushing multiroomSync output May 18 10:50:39 rivoplus volumio[6290]: info: CoreStateMachine::pushState May 18 10:50:39 rivoplus volumio[6290]: info: CoreCommandRouter::volumioPushState May 18 10:50:39 rivoplus volumio[6290]: info: CoreCommandRouter::volumioGetState May 18 10:50:39 rivoplus volumio[6290]: info: MRS: Pushing multiroomSync output update for this device May 18 10:50:39 rivoplus volumio[6290]: info: MRS: Pushing multiroomSync output May 18 10:50:39 rivoplus volumio[6290]: info: ------------------------------ 33ms May 18 10:50:39 rivoplus volumio[6290]: info: CoreCommandRouter::volumioGetQueue May 18 10:50:39 rivoplus volumio[6290]: info: CoreStateMachine::getQueue May 18 10:50:39 rivoplus volumio[6290]: info: CorePlayQueue::getQueue May 18 10:50:39 rivoplus volumio[6290]: info: CoreCommandRouter::volumioGetQueue May 18 10:50:39 rivoplus volumio[6290]: info: CoreStateMachine::getQueue May 18 10:50:39 rivoplus volumio[6290]: info: CorePlayQueue::getQueue May 18 10:50:39 rivoplus volumio[6290]: info: Signalling Playback active due to playback status change May 18 10:50:39 rivoplus volumio[6290]: info: Signalling Playback active due to playback status change May 18 10:50:39 rivoplus volumio[6290]: info: Updating RAAT Signal Path May 18 10:50:39 rivoplus volumio[6290]: info: Updating RAAT Signal Path May 18 10:50:39 rivoplus volumio[6290]: info: MCU Signalled Playback Active May 18 10:50:41 rivoplus volumio[6290]: info: Executing endpoint metavolumio May 18 10:50:41 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 18 10:50:41 rivoplus volumio[6290]: info: Executing endpoint metavolumio May 18 10:50:41 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 18 10:50:41 rivoplus volumio[6290]: info: Executing endpoint metavolumio May 18 10:50:41 rivoplus volumio[6290]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 18 10:50:45 rivoplus ntpd[3303]: Soliciting pool server 115.165.161.155 May 18 10:50:48 rivoplus ntpd[3303]: Soliciting pool server 103.70.115.65 May 18 10:50:51 rivoplus ntpd[3303]: Soliciting pool server 103.199.19.135 May 18 10:50:51 rivoplus wpa_supplicant[3185]: nl80211: send_and_recv->nl_recvmsgs failed: -33 May 18 10:50:56 rivoplus ntpd[3303]: Soliciting pool server 2400:6760:0:200::254 May 18 10:51:01 rivoplus volumio[6290]: error: error May 18 10:51:42 rivoplus volumio[6290]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 18 10:51:42 rivoplus volumio[6290]: Error: connect ETIMEDOUT 151.101.66.79:443 May 18 10:51:42 rivoplus volumio[6290]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) { May 18 10:51:42 rivoplus volumio[6290]: errno: -110, May 18 10:51:42 rivoplus volumio[6290]: code: 'ETIMEDOUT', May 18 10:51:42 rivoplus volumio[6290]: syscall: 'connect', May 18 10:51:42 rivoplus volumio[6290]: address: '151.101.66.79', May 18 10:51:42 rivoplus volumio[6290]: port: 443 May 18 10:51:42 rivoplus volumio[6290]: } May 18 10:51:42 rivoplus volumio[6290]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 18 10:51:42 rivoplus sudo[8370]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-18 10:50 May 18 10:51:42 rivoplus sudo[8370]: 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="rivoplus" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 13 May 2025 06:04:38 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="0064c1a7ac4363e567dacab062cb5da8"