search

music-assistant / hass-music-assistant

Turn your Home Assistant instance into a jukebox, hassle free streaming of your favorite media to Home Assistant media players.
Apache License 2.0
1.21k stars 44 forks source link

When issuing a media_player.media_stop service call on a MASS speaker entity id, even with continue_on_error: true, the call sometimes times out and kills the automation. #2355

Closed ncd7 closed 2 weeks ago

ncd7 commented 1 month ago

What version of Music Assistant has the issue?

2.1.0b1

What version of the Home Assistant Integration have you got installed?

2024.5.1

Have you tried everything in the Troubleshooting FAQ and reviewed the Open and Closed Issues and Discussions to resolve this yourself?

The problem

The below action (used in an automation) sometimes fails despite adding a condition to check if the speaker is available and the continue_on_error also doesn't help -- the exception must be quite low-level and somehow escapes Home Assistant's catch.

Ideally, something should be added to the HA addon that converts a time-out to an exception that can be handled by the HA continue_on_error: true mechanism to make this more robust. As it stands, I can no longer use MASS speakers in my automations for fear of random killing of my automations.

alias: If Speakers in the room are playing, turn them off
if:
  - condition: template
    value_template: >-
      {{ not (states(music_assistant_speaker_entity_id) in ['off', 'unknown',
      'unavailable']) }}
    alias: If Speakers are not [off, unknown, unavailable]
then:
  - alias: Turn off any media playing on speakers.
    continue_on_error: true
    service: media_player.media_stop
    target:
      entity_id: "{{ music_assistant_speaker_entity_id }}"

How to reproduce

The below service call sometimes times out. It SEEMS to happen when another device is casting (eg a phone is casting) its music to the same speakers. 

    service: media_player.media_stop
    target:
      entity_id: MASS_SPEAKER_ENTITY_ID_HERE
    continue_on_error: true

Music Providers

YouTube Music but I think ANY one will repro

Player Providers

Chromecast

Full log output

The ONLY thing in the logs around the problematic event is a single line, that's not super helpful. There's nothing else. I'm also going to attach the HA logs in the "Additional Information" box just in case.

2024-05-24 08:11:38.900 ERROR (MainThread) [music_assistant.webserver] Error handling message: players/cmd/stop: Execution of stop timed out after 10.0 s.

Additional information

Error executing script. Unexpected error for call_service at pos 1: timed out after 10.0 s. Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 501, in _async_step await getattr(self, handler)() File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 736, in _async_call_service_step response_data = await self._async_run_long_action( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 699, in _async_run_long_action return await long_task ^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/core.py", line 2738, in async_call response_data = await coro ^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/core.py", line 2779, in _execute_service return await target(service_call) ^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 975, in entity_service_call single_response = await _handle_entity_call( ^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 1047, in _handle_entity_call result = await task ^^^^^^^^^^ File "/config/custom_components/mass/media_player.py", line 298, in async_media_stop await self.mass.players.player_command_stop(self.player_id) File "/usr/local/lib/python3.12/site-packages/music_assistant/client/players.py", line 53, in player_command_stop await self.client.send_command("players/cmd/stop", player_id=player_id) File "/usr/local/lib/python3.12/site-packages/music_assistant/client/client.py", line 254, in send_command return await future ^^^^^^^^^^^^ Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 501, in _async_step await getattr(self, handler)() File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1043, in _async_if_step await self._async_run_script(if_data["if_then"]) File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1210, in _async_run_script result = await self._async_run_long_action( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 699, in _async_run_long_action return await long_task ^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1731, in async_run return await asyncio.shield(create_eager_task(run.async_run())) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 451, in async_run await self._async_step(log_exceptions=False) File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 503, in _async_step self._handle_exception( File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 533, in _handle_exception raise exception File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 501, in _async_step await getattr(self, handler)() File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1043, in _async_if_step await self._async_run_script(if_data["if_then"]) File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1210, in _async_run_script result = await self._async_run_long_action( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 699, in _async_run_long_action return await long_task ^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1731, in async_run return await asyncio.shield(create_eager_task(run.async_run())) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 451, in async_run await self._async_step(log_exceptions=False) File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 503, in _async_step self._handle_exception( File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 556, in _handle_exception raise exception File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 501, in _async_step await getattr(self, handler)() File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 736, in _async_call_service_step response_data = await self._async_run_long_action( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 699, in _async_run_long_action return await long_task ^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/core.py", line 2738, in async_call response_data = await coro ^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/core.py", line 2779, in _execute_service return await target(service_call) ^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 975, in entity_service_call single_response = await _handle_entity_call( ^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 1047, in _handle_entity_call result = await task ^^^^^^^^^^ File "/config/custom_components/mass/media_player.py", line 298, in async_media_stop await self.mass.players.player_command_stop(self.player_id) File "/usr/local/lib/python3.12/site-packages/music_assistant/client/players.py", line 53, in player_command_stop await self.client.send_command("players/cmd/stop", player_id=player_id) File "/usr/local/lib/python3.12/site-packages/music_assistant/client/client.py", line 254, in send_command return await future ^^^^^^^^^^^^ music_assistant.common.models.errors.PlayerCommandFailed: Execution of stop timed out after 10.0 s. 2024-05-24 08:11:39.056 ERROR (MainThread) [homeassistant.components.automation.north_bedroom_perform_actions_when_sleep_mode_changes_2] North Bedroom: Perform Actions When Sleep Mode Changes: Error executing script. Unexpected error for if at pos 2: Execution of stop timed out after 10.0 s. Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 501, in _async_step await getattr(self, handler)() File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1049, in _async_if_step await self._async_run_script(if_data["if_else"]) File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1210, in _async_run_script result = await self._async_run_long_action( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 699, in _async_run_long_action return await long_task ^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1731, in async_run return await asyncio.shield(create_eager_task(run.async_run())) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 451, in async_run await self._async_step(log_exceptions=False) File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 503, in _async_step self._handle_exception( File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 533, in _handle_exception raise exception File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 501, in _async_step await getattr(self, handler)() File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1043, in _async_if_step await self._async_run_script(if_data["if_then"]) File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1210, in _async_run_script result = await self._async_run_long_action( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 699, in _async_run_long_action return await long_task ^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1731, in async_run return await asyncio.shield(create_eager_task(run.async_run())) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 451, in async_run await self._async_step(log_exceptions=False) File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 503, in _async_step self._handle_exception( File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 533, in _handle_exception raise exception File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 501, in _async_step await getattr(self, handler)() File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1043, in _async_if_step await self._async_run_script(if_data["if_then"]) File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1210, in _async_run_script result = await self._async_run_long_action( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 699, in _async_run_long_action return await long_task ^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1731, in async_run return await asyncio.shield(create_eager_task(run.async_run())) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 451, in async_run await self._async_step(log_exceptions=False) File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 503, in _async_step self._handle_exception( File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 556, in _handle_exception raise exception File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 501, in _async_step await getattr(self, handler)() File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 736, in _async_call_service_step response_data = await self._async_run_long_action( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 699, in _async_run_long_action return await long_task ^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/core.py", line 2738, in async_call response_data = await coro ^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/core.py", line 2779, in _execute_service return await target(service_call) ^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 975, in entity_service_call single_response = await _handle_entity_call( ^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 1047, in _handle_entity_call result = await task ^^^^^^^^^^ File "/config/custom_components/mass/media_player.py", line 298, in async_media_stop await self.mass.players.player_command_stop(self.player_id) File "/usr/local/lib/python3.12/site-packages/music_assistant/client/players.py", line 53, in player_command_stop await self.client.send_command("players/cmd/stop", player_id=player_id) File "/usr/local/lib/python3.12/site-packages/music_assistant/client/client.py", line 254, in send_command return await future ^^^^^^^^^^^^ music_assistant.common.models.errors.PlayerCommandFailed: Execution of stop timed out after 10.0 s. 2024-05-24 08:11:39.097 ERROR (MainThread) [homeassistant.components.automation.north_bedroom_perform_actions_when_sleep_mode_changes_2] While executing automation automation.north_bedroom_perform_actions_when_sleep_mode_changes_2 Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/components/automation/init.py", line 723, in async_trigger return await self.action_script.async_run( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1731, in async_run return await asyncio.shield(create_eager_task(run.async_run())) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1238, in async_run await super().async_run() File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 451, in async_run await self._async_step(log_exceptions=False) File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 503, in _async_step self._handle_exception( File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 533, in _handle_exception raise exception File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 501, in _async_step await getattr(self, handler)() File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1049, in _async_if_step await self._async_run_script(if_data["if_else"]) File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1210, in _async_run_script result = await self._async_run_long_action( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 699, in _async_run_long_action return await long_task ^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1731, in async_run return await asyncio.shield(create_eager_task(run.async_run())) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 451, in async_run await self._async_step(log_exceptions=False) File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 503, in _async_step self._handle_exception( File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 533, in _handle_exception raise exception File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 501, in _async_step await getattr(self, handler)() File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1043, in _async_if_step await self._async_run_script(if_data["if_then"]) File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1210, in _async_run_script result = await self._async_run_long_action( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 699, in _async_run_long_action return await long_task ^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1731, in async_run return await asyncio.shield(create_eager_task(run.async_run())) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 451, in async_run await self._async_step(log_exceptions=False) File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 503, in _async_step self._handle_exception( File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 533, in _handle_exception raise exception File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 501, in _async_step await getattr(self, handler)() File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1043, in _async_if_step await self._async_run_script(if_data["if_then"]) File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1210, in _async_run_script result = await self._async_run_long_action( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 699, in _async_run_long_action return await long_task ^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1731, in async_run return await asyncio.shield(create_eager_task(run.async_run())) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 451, in async_run await self._async_step(log_exceptions=False) File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 503, in _async_step self._handle_exception( File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 556, in _handle_exception raise exception File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 501, in _async_step await getattr(self, handler)() File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 736, in _async_call_service_step response_data = await self._async_run_long_action( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 699, in _async_run_long_action return await long_task ^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/core.py", line 2738, in async_call response_data = await coro ^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/core.py", line 2779, in _execute_service return await target(service_call) ^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 975, in entity_service_call single_response = await _handle_entity_call( ^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 1047, in _handle_entity_call result = await task ^^^^^^^^^^ File "/config/custom_components/mass/media_player.py", line 298, in async_media_stop await self.mass.players.player_command_stop(self.player_id) File "/usr/local/lib/python3.12/site-packages/music_assistant/client/players.py", line 53, in player_command_stop await self.client.send_command("players/cmd/stop", player_id=player_id) File "/usr/local/lib/python3.12/site-packages/music_assistant/client/client.py", line 254, in send_command return await future ^^^^^^^^^^^^ music_assistant.common.models.errors.PlayerCommandFailed: Execution of stop timed out after 10.0 s.

What version of Home Assistant Core are your running

2024.5.4

What type of installation are you running?

Home Assistant OS

On what type of hardware are you running?

Linux

ncd7 commented 1 month ago

This is becoming a huge problem for me. I am use MAS speakers in various automations and any time i do a STOP, there's a non-0 risk it will kill the automation and continue_on_error: true is not able to get around it. This has caused a lot of failures and complaints from household members :(.

I'm not sure if I'm the only one experiencing this and if it's highly specific to Chromecast player types with YTMusic providers, but it's created a huge liability so I'm going to roll back my use of MASS.

I hope this can get addressed quickly, it's extremely disruptive. :(

marcelveldt commented 2 weeks ago

Did you try sending a turn off command instead of the stop ? This is the first report I have seen about this but I do know that cast can be funky sometimes when multiple commands are received at once. Is there a possibility that this script is called multiple times at the same time ?

marcelveldt commented 2 weeks ago

Support for continue_on_error added to the integration, will be available in the next update (2024.6.2) later today. Its its always good to make your scripts sane and not send impossible commands to a player, it casuses overhead and errors in your logs. For example sending stop if a player isnt playing is a bit asking for trouble. Yes, the "Continue_on_error" will now hide that for you but me personally would have added a small check to the script only send stop (or power off etc.) if needed.

ncd7 commented 2 weeks ago

Thanks very much for making this honor continue_on_error - I truly appreciate it! To address your other comments: these were exactly the things I checked. (1) the script is only run once. (2) I immediately added a guard to only do it if playing. However, I still got errors after that. I subsequently changed it to turn_off which seemed to make it more robust BUT it still happens occasionally. It is rarer than with .stop.

marcelveldt commented 2 weeks ago

Please test using HA integration version 2024.6.2 and Server version 2.0.7 as that includes the "continue_on_error" fix.

OzGav commented 2 weeks ago

@ncd7 please confirm if this is still a problem with 2.0.7

ncd7 commented 2 weeks ago

Thanks it seems to work fine now