-- Logs begin at Sun 2025-05-11 22:10:57 MSK, end at Sun 2025-05-11 22:21:09 MSK. -- May 11 22:20:24 smsl-n100 volumio[1446]: info: CALLMETHOD: audio_interface alsa_controller saveVolumeOptions [object Object] May 11 22:20:24 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveVolumeOptions May 11 22:20:24 smsl-n100 volumio[1446]: info: CoreCommandRouter::volumioGetState May 11 22:20:24 smsl-n100 volumio[1446]: info: Restoring Previous Volume level: 100 false false May 11 22:20:24 smsl-n100 volumio[1446]: info: Output device has changed, restarting MPD May 11 22:20:24 smsl-n100 sudo[3023]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 11 22:20:24 smsl-n100 sudo[3023]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 22:20:24 smsl-n100 volumio[1446]: info: Output device has changed, restarting Shairport Sync May 11 22:20:24 smsl-n100 sudo[3023]: pam_unix(sudo:session): session closed for user root May 11 22:20:24 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 22:20:24 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 11 22:20:24 smsl-n100 sudo[3026]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 11 22:20:24 smsl-n100 sudo[3026]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 22:20:24 smsl-n100 systemd[1]: Stopping Music Player Daemon... May 11 22:20:24 smsl-n100 volumio[1446]: xcb_connection_has_error() returned true May 11 22:20:24 smsl-n100 volumio[1446]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 11 22:20:24 smsl-n100 volumio[1446]: xcb_connection_has_error() returned true May 11 22:20:24 smsl-n100 volumio[1446]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 11 22:20:24 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 22:20:24 smsl-n100 systemd[1]: mpd.service: Succeeded. May 11 22:20:24 smsl-n100 systemd[1]: Stopped Music Player Daemon. May 11 22:20:24 smsl-n100 systemd[1]: Starting Music Player Daemon... May 11 22:20:24 smsl-n100 volumio[1446]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes May 11 22:20:24 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 22:20:24 smsl-n100 vtcs[1786]: [2025-05-11 22:20:24.799] [tisoc] [warning] [SessionManagerImpl.cpp:243] Illegal State: IDLE May 11 22:20:24 smsl-n100 vtcs[1786]: [2025-05-11 22:20:24.805] [tisoc] [error] [SpkconServer.cpp:381] recv error. client fd=7 errorno=104 error=Connection reset by peer May 11 22:20:24 smsl-n100 vtcs[1786]: [2025-05-11 22:20:24.806] [tisoc] [error] [SpkconServer.cpp:376] recv error. socket disconnected May 11 22:20:24 smsl-n100 volumio[1446]: info: Volume configurations have been set May 11 22:20:24 smsl-n100 volumio[1446]: info: Reconfiguring and Restarting RAAT Plugin due to audio path changes May 11 22:20:24 smsl-n100 sudo[3036]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 11 22:20:24 smsl-n100 sudo[3036]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 22:20:24 smsl-n100 systemd[1]: Stopping Volumio Tidal Connect Service... May 11 22:20:24 smsl-n100 sudo[3039]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 11 22:20:24 smsl-n100 sudo[3031]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 11 22:20:24 smsl-n100 sudo[3039]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 22:20:24 smsl-n100 sudo[3031]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 22:20:24 smsl-n100 systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM May 11 22:20:24 smsl-n100 systemd[1]: vtcs.service: Succeeded. May 11 22:20:25 smsl-n100 systemd[1]: Stopped Volumio Tidal Connect Service. May 11 22:20:25 smsl-n100 sudo[3031]: pam_unix(sudo:session): session closed for user root May 11 22:20:25 smsl-n100 sudo[3036]: pam_unix(sudo:session): session closed for user root May 11 22:20:25 smsl-n100 sudo[3039]: pam_unix(sudo:session): session closed for user root May 11 22:20:25 smsl-n100 volumio[1446]: xcb_connection_has_error() returned true May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreCommandRouter::volumioUpdateVolumeSettings May 11 22:20:25 smsl-n100 volumio[1446]: info: Updating Volume Controller Parameters: Device: 1 Name: SPDIF Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume May 11 22:20:25 smsl-n100 volumio[1446]: info: Disabling external Volume Control May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreCommandRouter::getUIConfigOnPlugin May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreStateMachine::pushState May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreCommandRouter::volumioPushState May 11 22:20:25 smsl-n100 volumio[1446]: info: MRS: Pushing multiroomSync output update for this device May 11 22:20:25 smsl-n100 volumio[1446]: info: MRS: Pushing multiroomSync output May 11 22:20:25 smsl-n100 sudo[3063]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 11 22:20:25 smsl-n100 sudo[3063]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 22:20:25 smsl-n100 sudo[3066]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 11 22:20:25 smsl-n100 sudo[3066]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 22:20:25 smsl-n100 sudo[3063]: pam_unix(sudo:session): session closed for user root May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 11 22:20:25 smsl-n100 volumio[1446]: info: Not Reporting Auto name since its the default one May 11 22:20:25 smsl-n100 sudo[3066]: pam_unix(sudo:session): session closed for user root May 11 22:20:25 smsl-n100 volumio[1446]: ------------------------------------ BT MESSAGE: BT STATUS: running May 11 22:20:25 smsl-n100 volumio[1446]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 11 22:20:25 smsl-n100 volumio[1446]: ------------------------------------ BT MESSAGE: BT STATUS: running May 11 22:20:25 smsl-n100 volumio[1446]: ------------------------------------ BT MESSAGE: BT STATUS: running May 11 22:20:25 smsl-n100 volumio[1446]: info: Updating RAAT Signal Path May 11 22:20:25 smsl-n100 volumio[1446]: info: MPD Permissions set May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 11 22:20:25 smsl-n100 volumio[1446]: info: Not Reporting Auto name since its the default one May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreStateMachine::pushState May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreCommandRouter::volumioPushState May 11 22:20:25 smsl-n100 volumio[1446]: info: MRS: Pushing multiroomSync output update for this device May 11 22:20:25 smsl-n100 volumio[1446]: info: MRS: Pushing multiroomSync output May 11 22:20:25 smsl-n100 volumio[1446]: error: Serial API: Failed to decode command: 100, message: undefined May 11 22:20:25 smsl-n100 volumio[1446]: error: Serial API: Failed to decode command: MAXVOL, message: May 11 22:20:25 smsl-n100 volumio[1446]: error: Serial API: Failed to decode command: 100, message: undefined May 11 22:20:25 smsl-n100 volumio[1446]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreStateMachine::pushState May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreCommandRouter::volumioPushState May 11 22:20:25 smsl-n100 volumio[1446]: info: MRS: Pushing multiroomSync output update for this device May 11 22:20:25 smsl-n100 volumio[1446]: info: MRS: Pushing multiroomSync output May 11 22:20:25 smsl-n100 volumio[1446]: error: Serial API: Failed to decode command: 100, message: undefined May 11 22:20:25 smsl-n100 volumio[1446]: error: Serial API: Failed to decode command: MAXVOL, message: May 11 22:20:25 smsl-n100 volumio[1446]: error: Serial API: Failed to decode command: 100, message: undefined May 11 22:20:25 smsl-n100 volumio[1446]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 11 22:20:25 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 11 22:20:26 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 22:20:26 smsl-n100 volumio[1446]: xcb_connection_has_error() returned true May 11 22:20:26 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions May 11 22:20:26 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 11 22:20:26 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 11 22:20:26 smsl-n100 volumio[1446]: xcb_connection_has_error() returned true May 11 22:20:26 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 11 22:20:26 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 11 22:20:26 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 11 22:20:26 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 11 22:20:26 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 11 22:20:26 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 11 22:20:26 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 11 22:20:26 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode May 11 22:20:26 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 11 22:20:26 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: raat , getAdditionalUiSection May 11 22:20:26 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable May 11 22:20:26 smsl-n100 volumio[1446]: xcb_connection_has_error() returned true May 11 22:20:26 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable May 11 22:20:26 smsl-n100 sudo[3093]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service May 11 22:20:26 smsl-n100 sudo[3093]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 22:20:26 smsl-n100 sudo[3093]: pam_unix(sudo:session): session closed for user root May 11 22:20:26 smsl-n100 sudo[3097]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service May 11 22:20:26 smsl-n100 sudo[3097]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 22:20:26 smsl-n100 volumio[1446]: xcb_connection_has_error() returned true May 11 22:20:26 smsl-n100 systemd[1]: Stopping RAAT DAEMON... May 11 22:20:26 smsl-n100 systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM May 11 22:20:26 smsl-n100 systemd[1]: raat-daemon.service: Succeeded. May 11 22:20:26 smsl-n100 systemd[1]: Stopped RAAT DAEMON. May 11 22:20:26 smsl-n100 systemd[1]: Started RAAT DAEMON. May 11 22:20:26 smsl-n100 volumio[1446]: ------------------------------------ BT MESSAGE: BT STATUS: running May 11 22:20:26 smsl-n100 sudo[3097]: pam_unix(sudo:session): session closed for user root May 11 22:20:26 smsl-n100 volumio[1446]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 11 22:20:26 smsl-n100 volumio[1446]: info: Starting Shairport Sync May 11 22:20:26 smsl-n100 sudo[3100]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service May 11 22:20:26 smsl-n100 sudo[3100]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 22:20:26 smsl-n100 sudo[3100]: pam_unix(sudo:session): session closed for user root May 11 22:20:26 smsl-n100 volumio[1446]: info: Raat Daemon started successfully May 11 22:20:26 smsl-n100 sudo[3110]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service May 11 22:20:26 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 22:20:26 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 22:20:26 smsl-n100 sudo[3110]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 22:20:26 smsl-n100 sudo[3112]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 11 22:20:26 smsl-n100 sudo[3112]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 22:20:26 smsl-n100 volumio[1446]: info: Executing endpoint restartRAATSocket May 11 22:20:26 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection May 11 22:20:26 smsl-n100 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 11 22:20:26 smsl-n100 systemd[1]: Stopping RAAT DAEMON... May 11 22:20:26 smsl-n100 systemd[1]: shairport-sync.service: Succeeded. May 11 22:20:26 smsl-n100 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 11 22:20:27 smsl-n100 systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM May 11 22:20:27 smsl-n100 systemd[1]: raat-daemon.service: Succeeded. May 11 22:20:27 smsl-n100 systemd[1]: Stopped RAAT DAEMON. May 11 22:20:27 smsl-n100 volumio[1446]: ------------------------------------ BT MESSAGE: BT STATUS: running May 11 22:20:27 smsl-n100 volumio[1446]: ------------------------------------ BT MESSAGE: BT STATUS: running May 11 22:20:27 smsl-n100 volumio[1446]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 11 22:20:27 smsl-n100 systemd[1]: Started RAAT DAEMON. May 11 22:20:27 smsl-n100 sudo[3110]: pam_unix(sudo:session): session closed for user root May 11 22:20:27 smsl-n100 volumio[1446]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 11 22:20:27 smsl-n100 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 11 22:20:27 smsl-n100 sudo[3112]: pam_unix(sudo:session): session closed for user root May 11 22:20:27 smsl-n100 volumio[1446]: 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 11 22:20:27 smsl-n100 volumio[1446]: info: Shairport-Sync Started May 11 22:20:27 smsl-n100 volumio[1446]: info: Raat Daemon started successfully May 11 22:20:27 smsl-n100 volumio[1446]: info: Executing endpoint restartRAATSocket May 11 22:20:27 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection May 11 22:20:27 smsl-n100 volumio[1446]: 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 11 22:20:27 smsl-n100 systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM May 11 22:20:27 smsl-n100 systemd[1]: mpd.service: Failed with result 'protocol'. May 11 22:20:27 smsl-n100 systemd[1]: Failed to start Music Player Daemon. May 11 22:20:27 smsl-n100 sudo[3026]: pam_unix(sudo:session): session closed for user root May 11 22:20:27 smsl-n100 volumio[1446]: info: Cannot restart MPD: Error: Command failed: /usr/bin/sudo /bin/systemctl restart mpd.service May 11 22:20:27 smsl-n100 volumio[1446]: Job for mpd.service failed because the service did not take the steps required by its unit configuration. May 11 22:20:27 smsl-n100 volumio[1446]: See "systemctl status mpd.service" and "journalctl -xe" for details. May 11 22:20:27 smsl-n100 volumio[1446]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 11 22:20:27 smsl-n100 systemd[1]: Starting Music Player Daemon... May 11 22:20:27 smsl-n100 volumio[1446]: ------------------------------------ BT MESSAGE: BT STATUS: running May 11 22:20:27 smsl-n100 sudo[3137]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 11 22:20:27 smsl-n100 sudo[3137]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 22:20:27 smsl-n100 sudo[3137]: pam_unix(sudo:session): session closed for user root May 11 22:20:28 smsl-n100 volumio[1446]: info: TidalConnect service stoped! May 11 22:20:28 smsl-n100 volumio[1446]: info: TidalConnect service stoped! May 11 22:20:28 smsl-n100 volumio[1446]: info: TidalConnect service stoped! May 11 22:20:28 smsl-n100 volumio[1446]: info: TidalConnect service stoped! May 11 22:20:28 smsl-n100 volumio[1446]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 11 22:20:28 smsl-n100 volumio[1446]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect May 11 22:20:28 smsl-n100 volumio[1446]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 11 22:20:28 smsl-n100 volumio[1446]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect May 11 22:20:28 smsl-n100 sudo[3157]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service May 11 22:20:28 smsl-n100 sudo[3157]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 22:20:28 smsl-n100 sudo[3160]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service May 11 22:20:28 smsl-n100 sudo[3160]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 22:20:28 smsl-n100 systemd[1]: Started Volumio Tidal Connect Service. May 11 22:20:28 smsl-n100 sudo[3157]: pam_unix(sudo:session): session closed for user root May 11 22:20:28 smsl-n100 sudo[3160]: pam_unix(sudo:session): session closed for user root May 11 22:20:28 smsl-n100 volumio[1446]: info: VolumeController::SetAlsaVolume100 May 11 22:20:28 smsl-n100 volumio[1446]: info: CoreStateMachine::pushState May 11 22:20:28 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 22:20:29 smsl-n100 volumio[1446]: info: CoreCommandRouter::volumioPushState May 11 22:20:29 smsl-n100 volumio[1446]: info: MRS: Pushing multiroomSync output update for this device May 11 22:20:29 smsl-n100 volumio[1446]: info: MRS: Pushing multiroomSync output May 11 22:20:29 smsl-n100 volumio[1446]: info: Updating RAAT Signal Path May 11 22:20:29 smsl-n100 volumio[1446]: info: Executing endpoint tc_getconfig May 11 22:20:29 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig May 11 22:20:29 smsl-n100 vtcs[3161]: STARTING TidalConnect services, version: 1.4.0.34 May 11 22:20:29 smsl-n100 volumio[1446]: info: RAAT: Requesting Headphone Status May 11 22:20:29 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus May 11 22:20:29 smsl-n100 volumio[1446]: info: CoreStateMachine::pushState May 11 22:20:29 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 22:20:29 smsl-n100 volumio[1446]: info: CoreCommandRouter::volumioPushState May 11 22:20:29 smsl-n100 volumio[1446]: info: MRS: Pushing multiroomSync output update for this device May 11 22:20:29 smsl-n100 volumio[1446]: info: MRS: Pushing multiroomSync output May 11 22:20:29 smsl-n100 volumio[1446]: error: Serial API: Failed to decode command: 100, message: undefined May 11 22:20:29 smsl-n100 volumio[1446]: error: Serial API: Failed to decode command: MAXVOL, message: May 11 22:20:29 smsl-n100 volumio[1446]: error: Serial API: Failed to decode command: 100, message: undefined May 11 22:20:29 smsl-n100 volumio[1446]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff May 11 22:20:29 smsl-n100 vtcs[3161]: STARTED TidalConnect services. May 11 22:20:29 smsl-n100 volumio[1446]: info: Executing endpoint tc_connect May 11 22:20:29 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect May 11 22:20:29 smsl-n100 volumio[1446]: info: Connecting to TidalConnect May 11 22:20:29 smsl-n100 volumio[1446]: info: CoreCommandRouter::servicePushState May 11 22:20:29 smsl-n100 volumio[1446]: info: CoreStateMachine::pushState May 11 22:20:29 smsl-n100 volumio[1446]: info: CoreCommandRouter::volumioPushState May 11 22:20:29 smsl-n100 volumio[1446]: info: MRS: Pushing multiroomSync output update for this device May 11 22:20:29 smsl-n100 volumio[1446]: info: MRS: Pushing multiroomSync output May 11 22:20:29 smsl-n100 volumio[1446]: info: CorePlayQueue::getTrack 0 May 11 22:20:29 smsl-n100 volumio[1446]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current mpd Received tidalconnect May 11 22:20:29 smsl-n100 volumio[1446]: info: CoreCommandRouter::servicePushState May 11 22:20:29 smsl-n100 volumio[1446]: info: CoreStateMachine::pushState May 11 22:20:29 smsl-n100 volumio[1446]: info: CoreCommandRouter::volumioPushState May 11 22:20:29 smsl-n100 volumio[1446]: info: MRS: Pushing multiroomSync output update for this device May 11 22:20:29 smsl-n100 volumio[1446]: info: MRS: Pushing multiroomSync output May 11 22:20:29 smsl-n100 volumio[1446]: info: CorePlayQueue::getTrack 0 May 11 22:20:29 smsl-n100 volumio[1446]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current mpd Received tidalconnect May 11 22:20:29 smsl-n100 volumio[1446]: info: RAAT: Requesting Headphone Status May 11 22:20:29 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus May 11 22:20:29 smsl-n100 volumio[1446]: info: CoreStateMachine::pushState May 11 22:20:29 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 22:20:29 smsl-n100 volumio[1446]: info: CoreCommandRouter::volumioPushState May 11 22:20:29 smsl-n100 volumio[1446]: info: MRS: Pushing multiroomSync output update for this device May 11 22:20:29 smsl-n100 volumio[1446]: info: MRS: Pushing multiroomSync output May 11 22:20:29 smsl-n100 volumio[1446]: error: Serial API: Failed to decode command: 100, message: undefined May 11 22:20:29 smsl-n100 volumio[1446]: error: Serial API: Failed to decode command: MAXVOL, message: May 11 22:20:29 smsl-n100 volumio[1446]: error: Serial API: Failed to decode command: 100, message: undefined May 11 22:20:29 smsl-n100 volumio[1446]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff May 11 22:20:31 smsl-n100 mpd[3139]: May 11 22:20 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 11 22:20:31 smsl-n100 systemd[1]: Started Music Player Daemon. May 11 22:20:31 smsl-n100 mpd_monitor.sh[543]: MPD restarted due to no mpc output. May 11 22:20:31 smsl-n100 volumio[1446]: error: updateQueue error: null May 11 22:20:31 smsl-n100 volumio[1446]: info: TidalConnect service started! May 11 22:20:31 smsl-n100 volumio[1446]: info: TidalConnect service started! May 11 22:20:40 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri May 11 22:20:40 smsl-n100 volumio[1446]: info: handleBrowseUri took 202 milliseconds May 11 22:20:40 smsl-n100 volumio[1446]: info: Preload queue cleared May 11 22:20:40 smsl-n100 volumio[1446]: info: Preload queue cleared May 11 22:20:42 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri May 11 22:20:43 smsl-n100 volumio[1446]: info: handleBrowseUri took 839 milliseconds May 11 22:20:43 smsl-n100 volumio[1446]: info: Preload queue cleared May 11 22:20:46 smsl-n100 volumio[1446]: info: Preload queue cleared May 11 22:20:46 smsl-n100 volumio[1446]: info: CoreCommandRouter::volumioReplaceandPlayItems May 11 22:20:46 smsl-n100 volumio[1446]: info: CoreStateMachine::ClearQueue May 11 22:20:46 smsl-n100 volumio[1446]: info: CoreStateMachine::stop May 11 22:20:46 smsl-n100 volumio[1446]: info: CoreStateMachine::setConsumeUpdateService undefined May 11 22:20:46 smsl-n100 volumio[1446]: info: CoreStateMachine::stPlaybackTimer May 11 22:20:46 smsl-n100 volumio[1446]: info: CoreStateMachine::updateTrackBlock May 11 22:20:46 smsl-n100 volumio[1446]: info: CorePlayQueue::getTrackBlock May 11 22:20:46 smsl-n100 volumio[1446]: info: CoreStateMachine::pushState May 11 22:20:46 smsl-n100 volumio[1446]: info: CorePlayQueue::getTrack 0 May 11 22:20:46 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 22:20:46 smsl-n100 volumio[1446]: info: CoreCommandRouter::volumioPushState May 11 22:20:46 smsl-n100 volumio[1446]: info: MRS: Pushing multiroomSync output update for this device May 11 22:20:46 smsl-n100 volumio[1446]: info: MRS: Pushing multiroomSync output May 11 22:20:46 smsl-n100 volumio[1446]: info: CoreStateMachine::serviceStop May 11 22:20:46 smsl-n100 volumio[1446]: info: CorePlayQueue::getTrack 0 May 11 22:20:46 smsl-n100 volumio[1446]: info: CoreCommandRouter::serviceStop May 11 22:20:46 smsl-n100 volumio[1446]: info: [1746991246178] ControllerQobuz::stop May 11 22:20:46 smsl-n100 volumio[1446]: info: CoreStateMachine::setConsumeUpdateService mpd May 11 22:20:46 smsl-n100 volumio[1446]: info: ControllerMpd::stop May 11 22:20:46 smsl-n100 volumio[1446]: verbose: ControllerMpd::sendMpdCommand stop May 11 22:20:46 smsl-n100 volumio[1446]: info: CorePlayQueue::clearPlayQueue May 11 22:20:46 smsl-n100 volumio[1446]: info: CorePlayQueue::saveQueue May 11 22:20:46 smsl-n100 volumio[1446]: info: CoreCommandRouter::volumioPushQueue May 11 22:20:46 smsl-n100 volumio[1446]: info: CoreStateMachine::addQueueItems May 11 22:20:46 smsl-n100 volumio[1446]: info: CorePlayQueue::addQueueItems May 11 22:20:46 smsl-n100 volumio[1446]: info: Preload queue cleared May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/170300430 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/170300430 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/317986725 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/317986725 May 11 22:20:46 smsl-n100 volumio[1446]: info: CoreCommandRouter::volumioPushQueue May 11 22:20:46 smsl-n100 volumio[1446]: info: CorePlayQueue::saveQueue May 11 22:20:46 smsl-n100 volumio[1446]: info: CoreStateMachine::updateTrackBlock May 11 22:20:46 smsl-n100 volumio[1446]: info: CorePlayQueue::getTrackBlock May 11 22:20:46 smsl-n100 volumio[1446]: info: CoreCommandRouter::volumioPlay May 11 22:20:46 smsl-n100 volumio[1446]: info: CoreStateMachine::play index 1 May 11 22:20:46 smsl-n100 volumio[1446]: info: CoreStateMachine::setConsumeUpdateService undefined May 11 22:20:46 smsl-n100 volumio[1446]: info: CoreStateMachine::addQueueItems May 11 22:20:46 smsl-n100 volumio[1446]: info: CorePlayQueue::addQueueItems May 11 22:20:46 smsl-n100 volumio[1446]: info: Preload queue cleared May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/325763237 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/325763237 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/218586793 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/218586793 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/64225389 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/64225389 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/103071477 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/103071477 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/218586791 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/218586791 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/60756015 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/60756015 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/60846031 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/60846031 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/154735026 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/154735026 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/27258758 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/27258758 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/213224865 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/213224865 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/203636904 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/203636904 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/17985376 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/17985376 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/298216470 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/298216470 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/291036875 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/291036875 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/64859840 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/64859840 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/187066489 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/187066489 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/64859952 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/64859952 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/266725032 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/266725032 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/251995479 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/251995479 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/65897608 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/65897608 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/60846033 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/60846033 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/1755951 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/1755951 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/107007722 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/107007722 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/627460 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/627460 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/78254333 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/78254333 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/24786884 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/24786884 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/24597938 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/24597938 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/36304009 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/36304009 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/48912718 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/48912718 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/64868963 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/64868963 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/55650207 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/55650207 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/54091881 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/54091881 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/20260055 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/20260055 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/458302 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/458302 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/156618058 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/156618058 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/80530523 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/80530523 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/77469843 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/77469843 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/9033105 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/9033105 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/9033081 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/9033081 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/2575387 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/2575387 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/266725030 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/266725030 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/265734568 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/265734568 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/10870856 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/10870856 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/297806410 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/297806410 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/140067771 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/140067771 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/6008065 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/6008065 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/13968706 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/13968706 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/280465418 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/280465418 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/285443580 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/285443580 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/216445909 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/216445909 May 11 22:20:46 smsl-n100 volumio[1446]: info: Adding Item to queue: qobuz://song/46264840 May 11 22:20:46 smsl-n100 volumio[1446]: info: Using cached record of: qobuz://song/46264840 May 11 22:20:46 smsl-n100 volumio[1446]: info: CoreStateMachine::stop May 11 22:20:46 smsl-n100 volumio[1446]: info: CoreStateMachine::setConsumeUpdateService undefined May 11 22:20:46 smsl-n100 volumio[1446]: info: CoreCommandRouter::volumioPushQueue May 11 22:20:46 smsl-n100 volumio[1446]: info: CorePlayQueue::saveQueue May 11 22:20:46 smsl-n100 volumio[1446]: info: CoreStateMachine::play index undefined May 11 22:20:46 smsl-n100 volumio[1446]: info: CoreStateMachine::setConsumeUpdateService undefined May 11 22:20:46 smsl-n100 volumio[1446]: info: CoreStateMachine::updateTrackBlock May 11 22:20:46 smsl-n100 volumio[1446]: info: CorePlayQueue::getTrackBlock May 11 22:20:46 smsl-n100 volumio[1446]: info: CorePlayQueue::getTrack 1 May 11 22:20:46 smsl-n100 volumio[1446]: info: CoreStateMachine::startPlaybackTimer May 11 22:20:46 smsl-n100 volumio[1446]: info: CorePlayQueue::getTrack 1 May 11 22:20:46 smsl-n100 volumio[1446]: info: [1746991246372] ControllerQobuz::clearAddPlayTrack May 11 22:20:46 smsl-n100 volumio[1446]: verbose: ControllerMpd::sendMpdCommand stop May 11 22:20:46 smsl-n100 volumio[1446]: info: sendMpdCommand stop took 244 milliseconds May 11 22:20:46 smsl-n100 volumio[1446]: info: sendMpdCommand stop took 53 milliseconds May 11 22:20:46 smsl-n100 volumio[1446]: verbose: ControllerMpd::sendMpdCommand clear May 11 22:20:46 smsl-n100 volumio[1446]: info: May 11 22:20:46 smsl-n100 volumio[1446]: ---------------------------- MPD announces system playlist update May 11 22:20:46 smsl-n100 volumio[1446]: info: Ignoring MPD Status Update May 11 22:20:46 smsl-n100 volumio[1446]: info: sendMpdCommand clear took 23 milliseconds May 11 22:20:46 smsl-n100 volumio[1446]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/317986725" May 11 22:20:46 smsl-n100 volumio[1446]: error: updateQueue error: null May 11 22:20:46 smsl-n100 volumio[1446]: info: ------------------------------ 13ms May 11 22:20:46 smsl-n100 volumio[1446]: STREAMING PROXY: Handling url /?data=qobuz://song/317986725 May 11 22:20:46 smsl-n100 volumio[1446]: info: CoreStateMachine::pushState May 11 22:20:46 smsl-n100 volumio[1446]: info: CorePlayQueue::getTrack 1 May 11 22:20:46 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 22:20:46 smsl-n100 volumio[1446]: info: CoreCommandRouter::volumioPushState May 11 22:20:46 smsl-n100 volumio[1446]: info: MRS: Pushing multiroomSync output update for this device May 11 22:20:46 smsl-n100 volumio[1446]: info: MRS: Pushing multiroomSync output May 11 22:20:46 smsl-n100 volumio[1446]: error: Serial API: Failed to decode command: 100, message: undefined May 11 22:20:46 smsl-n100 volumio[1446]: error: Serial API: Failed to decode command: MAXVOL, message: May 11 22:20:46 smsl-n100 volumio[1446]: error: Serial API: Failed to decode command: 100, message: undefined May 11 22:20:46 smsl-n100 volumio[1446]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff May 11 22:20:46 smsl-n100 volumio[1446]: info: Executing endpoint getStreamUrlqobuz May 11 22:20:46 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI May 11 22:20:47 smsl-n100 volumio[1446]: info: getStreamUrl took 667 milliseconds May 11 22:20:47 smsl-n100 volumio[1446]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=3294111&eid=317986725&fmt=7&profile=raw&app_id=539451548&cid=2361934&etsp=1746994846&hmac=A6jXHfKgW6GbFmPYMOcBWo9lMUg May 11 22:20:47 smsl-n100 volumio[1446]: STREAMING PROXY: Response: 200, length: 55746091 May 11 22:20:47 smsl-n100 volumio[1446]: STREAMING PROXY: Client dropped request, destroying May 11 22:20:47 smsl-n100 volumio[1446]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/317986725" May 11 22:20:47 smsl-n100 volumio[1446]: info: May 11 22:20:47 smsl-n100 volumio[1446]: ---------------------------- MPD announces system playlist update May 11 22:20:47 smsl-n100 volumio[1446]: info: Ignoring MPD Status Update May 11 22:20:47 smsl-n100 volumio[1446]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/317986725" took 8 milliseconds May 11 22:20:47 smsl-n100 volumio[1446]: info: CoreStateMachine::setConsumeUpdateService mpd May 11 22:20:47 smsl-n100 volumio[1446]: verbose: ControllerMpd::sendMpdCommand play May 11 22:20:47 smsl-n100 volumio[1446]: info: ------------------------------ 10ms May 11 22:20:47 smsl-n100 volumio[1446]: info: sendMpdCommand play took 7 milliseconds May 11 22:20:47 smsl-n100 volumio[1446]: STREAMING PROXY: Handling url /?data=qobuz://song/317986725 May 11 22:20:47 smsl-n100 volumio[1446]: info: Executing endpoint getStreamUrlqobuz May 11 22:20:47 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI May 11 22:20:47 smsl-n100 volumio[1446]: info: getStreamUrl took 513 milliseconds May 11 22:20:47 smsl-n100 volumio[1446]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=3294111&eid=317986725&fmt=7&profile=raw&app_id=539451548&cid=2361934&etsp=1746994847&hmac=r3Jx_Eb9SWG3WPPH51o2L1Rpkjo May 11 22:20:48 smsl-n100 volumio[1446]: STREAMING PROXY: Response: 200, length: 55746091 May 11 22:20:48 smsl-n100 volumio[1446]: info: May 11 22:20:48 smsl-n100 volumio[1446]: ---------------------------- MPD announces state update: player May 11 22:20:48 smsl-n100 volumio[1446]: info: ControllerMpd::getState May 11 22:20:48 smsl-n100 volumio[1446]: verbose: ControllerMpd::sendMpdCommand status May 11 22:20:48 smsl-n100 volumio[1446]: info: May 11 22:20:48 smsl-n100 volumio[1446]: ---------------------------- MPD announces state update: player May 11 22:20:48 smsl-n100 volumio[1446]: info: sendMpdCommand status took 15 milliseconds May 11 22:20:48 smsl-n100 volumio[1446]: info: ControllerMpd::getState May 11 22:20:48 smsl-n100 volumio[1446]: verbose: ControllerMpd::sendMpdCommand status May 11 22:20:48 smsl-n100 volumio[1446]: verbose: ControllerMpd::parseState May 11 22:20:48 smsl-n100 volumio[1446]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 11 22:20:48 smsl-n100 volumio[1446]: info: sendMpdCommand status took 9 milliseconds May 11 22:20:48 smsl-n100 volumio[1446]: info: sendMpdCommand playlistinfo took 8 milliseconds May 11 22:20:48 smsl-n100 volumio[1446]: verbose: ControllerMpd::parseState May 11 22:20:48 smsl-n100 volumio[1446]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 11 22:20:48 smsl-n100 volumio[1446]: verbose: ControllerMpd::parseTrackInfo May 11 22:20:48 smsl-n100 volumio[1446]: info: ControllerMpd::pushState May 11 22:20:48 smsl-n100 volumio[1446]: info: CoreCommandRouter::servicePushState May 11 22:20:48 smsl-n100 volumio[1446]: info: CorePlayQueue::getTrack 1 May 11 22:20:48 smsl-n100 volumio[1446]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":211,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"317986725","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/317986725","trackType":"qobuz"} May 11 22:20:48 smsl-n100 volumio[1446]: verbose: CURRENT POSITION 1 May 11 22:20:48 smsl-n100 volumio[1446]: info: CoreStateMachine::syncState stateService play May 11 22:20:48 smsl-n100 volumio[1446]: info: CoreStateMachine::syncState currentStatus stop May 11 22:20:48 smsl-n100 volumio[1446]: info: ------------------------------ 65ms May 11 22:20:48 smsl-n100 volumio[1446]: info: sendMpdCommand playlistinfo took 27 milliseconds May 11 22:20:48 smsl-n100 volumio[1446]: verbose: ControllerMpd::parseTrackInfo May 11 22:20:48 smsl-n100 volumio[1446]: info: ControllerMpd::pushState May 11 22:20:48 smsl-n100 volumio[1446]: info: CoreCommandRouter::servicePushState May 11 22:20:48 smsl-n100 volumio[1446]: info: CorePlayQueue::getTrack 1 May 11 22:20:48 smsl-n100 volumio[1446]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":211,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"317986725","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/317986725","trackType":"qobuz"} May 11 22:20:48 smsl-n100 volumio[1446]: verbose: CURRENT POSITION 1 May 11 22:20:48 smsl-n100 volumio[1446]: info: CoreStateMachine::syncState stateService play May 11 22:20:48 smsl-n100 volumio[1446]: info: CoreStateMachine::syncState currentStatus play May 11 22:20:48 smsl-n100 volumio[1446]: info: Received an update from plugin. extracting info from payload May 11 22:20:48 smsl-n100 volumio[1446]: info: CoreStateMachine::pushState May 11 22:20:48 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 22:20:48 smsl-n100 volumio[1446]: info: CoreCommandRouter::volumioPushState May 11 22:20:48 smsl-n100 volumio[1446]: info: MRS: Pushing multiroomSync output update for this device May 11 22:20:48 smsl-n100 volumio[1446]: info: MRS: Pushing multiroomSync output May 11 22:20:48 smsl-n100 volumio[1446]: info: CoreStateMachine::pushState May 11 22:20:48 smsl-n100 volumio[1446]: info: CoreCommandRouter::volumioPushState May 11 22:20:48 smsl-n100 volumio[1446]: info: MRS: Pushing multiroomSync output update for this device May 11 22:20:48 smsl-n100 volumio[1446]: info: MRS: Pushing multiroomSync output May 11 22:20:48 smsl-n100 volumio[1446]: info: ------------------------------ 144ms May 11 22:20:48 smsl-n100 volumio[1446]: info: CoreStateMachine::pushState May 11 22:20:48 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 22:20:48 smsl-n100 volumio[1446]: info: CoreCommandRouter::volumioPushState May 11 22:20:48 smsl-n100 volumio[1446]: info: MRS: Pushing multiroomSync output update for this device May 11 22:20:48 smsl-n100 volumio[1446]: info: MRS: Pushing multiroomSync output May 11 22:20:48 smsl-n100 volumio[1446]: error: Serial API: Failed to decode command: 100, message: undefined May 11 22:20:48 smsl-n100 volumio[1446]: error: Serial API: Failed to decode command: MAXVOL, message: May 11 22:20:48 smsl-n100 volumio[1446]: error: Serial API: Failed to decode command: 100, message: undefined May 11 22:20:48 smsl-n100 volumio[1446]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff May 11 22:20:53 smsl-n100 volumio[1446]: info: VolumeController::SetAlsaVolume0 May 11 22:20:53 smsl-n100 volumio[1446]: info: CoreStateMachine::pushState May 11 22:20:53 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 22:20:53 smsl-n100 volumio[1446]: info: CoreCommandRouter::volumioPushState May 11 22:20:53 smsl-n100 volumio[1446]: info: MRS: Pushing multiroomSync output update for this device May 11 22:20:53 smsl-n100 volumio[1446]: info: MRS: Pushing multiroomSync output May 11 22:20:53 smsl-n100 volumio[1446]: info: Updating RAAT Signal Path May 11 22:21:00 smsl-n100 volumio[1446]: STREAMING PROXY: Client dropped request, destroying May 11 22:21:08 smsl-n100 volumio[1446]: info: CoreCommandRouter::executeOnPlugin: multiroom , audioOutputPlay May 11 22:21:08 smsl-n100 volumio[1446]: info: Error : CoreCommandRouter::executeOnPlugin: No method [audioOutputPlay] in plugin multiroom May 11 22:21:08 smsl-n100 volumio[1446]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 11 22:21:08 smsl-n100 volumio[1446]: TypeError: Cannot read property 'then' of undefined May 11 22:21:08 smsl-n100 volumio[1446]: at outputs.audioOutputPlay (/volumio/app/plugins/audio_interface/outputs/index.js:367:9) May 11 22:21:08 smsl-n100 volumio[1446]: at CoreCommandRouter.audioOutputPlay (/volumio/app/index.js:2273:30) May 11 22:21:08 smsl-n100 volumio[1446]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1450:26) May 11 22:21:08 smsl-n100 volumio[1446]: at Socket.emit (events.js:400:28) May 11 22:21:08 smsl-n100 volumio[1446]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 May 11 22:21:08 smsl-n100 volumio[1446]: at processTicksAndRejections (internal/process/task_queues.js:77:11) May 11 22:21:08 smsl-n100 volumio[1446]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 11 22:21:09 smsl-n100 sudo[3305]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-11 22:20 May 11 22:21:09 smsl-n100 sudo[3305]: 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="cc0042a1eab1cb7982711a1347e242f8947b54b6" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="723ba1d50268911818ebdca474fb7656df6050cb" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="smsl" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 14 Feb 2025 02:46:15 PM CET" VOLUMIO_VERSION="3.789" VOLUMIO_HARDWARE="nanopineo3" VOLUMIO_DEVICENAME="Nanopi Neo3" VOLUMIO_VENDOR_MODEL="SMSL S100" VOLUMIO_VENDOR="SMSL" VOLUMIO_MODEL="S100" VOLUMIO_HASH="215d731aee688e00fb3cc923952be9a7"