ChimeTTSQueueManager.queue_processor' was never awaited handle

JonLaliberte commented 7 months ago

System Health details

System Information

version	core-2024.4.1
installation_type	Home Assistant OS
dev	false
hassio	true
docker	true
user	root
virtualenv	false
python_version	3.12.2
os_name	Linux
os_version	6.6.20-haos
arch	x86_64
timezone	America/New_York
config_dir	/config

Home Assistant Community Store

Home Assistant Cloud

Home Assistant Supervisor

Dashboards

Recorder

Victor Smart-Kill

api_endpoint_reachable | ok -- | --

Checklist

[X] I have enabled debug logging for my installation.
[X] I have filled out the issue template to the best of my ability.
[X] This issue only contains 1 issue (if you have multiple issues, open one issue for each issue).
[X] This issue is not a duplicate issue of currently previous issues..

Describe the issue

I enabled debug logging the other day and checked it out this morning (after updating to 1.1.0-beta1). Here are the errors/warnings.

There are a few different warnings and one error here. The error may an error with the HomePod.

I tested using the ChimeTTS service just now and it worked fine to two homepods, but I know automation runs earlier today were not working. Prior to testing the ChimeTTS service I used the HomeAssistant Say/media player service to test if that worked - maybe doing that got something working? After this the automation I checked worked too.

Reproduction steps

I'm not sure.

Debug logs

Logger: py.warnings
Source: runner.py:189
First occurred: 9:03:36 AM (1 occurrences)
Last logged: 9:03:36 AM

/usr/local/lib/python3.12/asyncio/base_events.py:1989: RuntimeWarning: coroutine 'ChimeTTSQueueManager.queue_processor' was never awaited handle = None # Needed to break cycles when an exception occurs.

Logger: homeassistant.core
Source: core.py:2559
First occurred: 10:54:21 AM (1 occurrences)
Last logged: 10:54:21 AM

Error executing service: <ServiceCall media_player.play_media (c:01HV4811K9VS5RGHGYEG6VZ6B4): announce=True, entity_id=['media_player.kitchen_homepod'], extra=, media_type=music, media_id=media-source://media_source/local/sounds/temp/chime_tts/smayp6wm.mp3>
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/core.py", line 2559, in _run_service_call_catch_exceptions
    await coro_or_task
  File "/usr/src/homeassistant/homeassistant/core.py", line 2580, in _execute_service
    return await target(service_call)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 971, in entity_service_call
    single_response = await _handle_entity_call(
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 1043, in _handle_entity_call
    result = await task
             ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/apple_tv/media_player.py", line 346, in async_play_media
    await self.atv.stream.stream_file(media_id)
  File "/usr/local/lib/python3.12/site-packages/pyatv/core/facade.py", line 371, in stream_file
    await self.relay("stream_file")(
  File "/usr/local/lib/python3.12/site-packages/pyatv/protocols/raop/__init__.py", line 360, in stream_file
    audio_file = await open_source(
                 ^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/pyatv/protocols/raop/audio_source.py", line 729, in open_source
    return await InternetSource.open(source, sample_rate, channels, sample_size)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/pyatv/protocols/raop/audio_source.py", line 597, in open
    stream_generator = await loop.run_in_executor(
                       ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/miniaudio.py", line 1268, in stream_any
    raise DecodeError("failed to init decoder", result)
miniaudio.DecodeError: ('failed to init decoder', -1)

This error originated from a custom integration.

Logger: custom_components.chime_tts.helpers.media_player
Source: custom_components/chime_tts/helpers/media_player.py:368
integration: Chime TTS (documentation, issues)
First occurred: 10:44:09 AM (2 occurrences)
Last logged: 12:04:46 PM

Unable to set media_player.kitchen_homepod's volume to 0.35: RTSP/1.0 method SET_PARAMETER failed with code 455: Method Not Valid In This State

This error originated from a custom integration.

Logger: custom_components.chime_tts
Source: custom_components/chime_tts/__init__.py:305
integration: Chime TTS (documentation, issues)
First occurred: 9:18:43 AM (5 occurrences)
Last logged: 12:48:32 PM

Timed out waiting for playback to complete



### Diagnostics dump

_No response_

nimroddolev commented 7 months ago

Hi Jonathan, thank you for the logs messages. Do you still have the debug logs? Without them I can't tell when this happens exactly (before or after playback).

I looked at all 4 issues and I have a new beta build which I hope fixes some, but I am not sure how to address the issue:

Unable to set media_player.kitchen_homepod's volume to 0.35: RTSP/1.0 method SET_PARAMETER failed with code 455: Method Not Valid In This State

It seems like the HomePod can't run the media_player.set_volume service, perhaps because it is 'off'? Again, I need the debug logs to understand at which point the code tries to change the volume.

To test the new beta:

Open the Chime TTS repository in HACS
Click on the ⋮ button in the top right
Select the ↻ Redownload option
Enable the Show beta versions option (it may take a moment to update the list)
Select version v1.1.0-beta2 from the updated version drop-down list
Restart Home Assistant

To enable debug logging:

Call the logger.set_level service to turn on debug logging:

service: logger.set_level
data:
custom_components.chime_tts: debug

Use Chime TTS until you experience the issue again.

Check your log messages in Home Assistant:

https://{YOUR_HOME_ASSISTANT_ADDRESS}:8123/config/logs?filter=chime_tts

and click LOAD FULL LOGS

nimroddolev commented 7 months ago

Hi Jonathan. I have released a new beta version, v1.1.0-beta3, which might fix the issue.

Could you please upgrade to the new version and let me know if it fixes the problem?

To install the new beta version:

Open the Chime TTS repository in HACS
Click on the ⋮ button in the top right
Select the ↻ Redownload option
Enable the Show beta versions option (it may take a moment to update the list)
Select version v1.1.0-beta3 from the updated version drop-down list
Restart Home Assistant

nimroddolev commented 6 months ago

Hi @JonLaliberte, have you had a chance to try the latest beta?

JonLaliberte commented 6 months ago

@nimroddolev Yes, still having trouble. Sorry, I keep turning on debug logging, then I forget to check it, and by then I've restarted HA. I just enabled debug logging again now and I'll leave this tab open. Should have some logs soon.

JonLaliberte commented 6 months ago

I'm not sure if there is much of use here, but I've attached the log here. home-assistant_chime_tts_2024-05-08T14-22-03.676Z.txt

I have an automation that reminds me every 3 minutes if a certain door is left open. The other day (not in this log!) I left it open for a long time, 45 minutes or so. I was getting notifications to my phone about it every 3 minutes as expected, but the ChimeTTS notification wasn't playing. Then suddenly around 33 minutes in, it started working. But, only partially. It was playing the chime sound, then it would say "Attention, the dining room door has been open for".

The config for that specific call is:

service: chime_tts.say
target:
  entity_id: media_player.kitchen_homepod
data:
  chime_path: chord
  delay: 50
  tts_playback_speed: 150
  volume_level: 0.35
  message: Attention, the dining room door has been open for {{ door_open_in_minutes }}
  tts_platform: cloud
  cache: true
  announce: true
  gender: female
  force_announce: true

I noticed now the end of the message got cut off, it was missing "minutes", but for some reason it also didn't say the number of minutes either. I fixed that now, but I suspect something else is going on still. I'll leave debug logging on and test some more.

nimroddolev commented 6 months ago

Thanks for the debug log messages, but I don't see any issues there.

I think it's odd that only the first part of the text would have been converted into TTS audio...it should really be an all-or-nothing situation.

It's hard to determine the cause of the issue without the debug logs from when the issue occurs. Try to catch it with debug logs and we will try to continue from there.

JonLaliberte commented 6 months ago

Tested it just now and it worked perfectly. I'm very confused. I'll leave debug logging on incase there is a problem later today.

My only thought right now is it was caused by a network or (most likely) HomePod issue that somehow resolved.

nimroddolev commented 6 months ago

If it’s intermittent then it might be a network or hardware issue like you said…hopefully you can catch it with debug logs and we can get some clarity 👍

nimroddolev commented 5 months ago

I have released a new beta version, v1.1.0-beta10, which should fix this issue.

nimroddolev commented 5 months ago

The fix has been included in the latest stable release, v1.1.0.

JonLaliberte commented 2 months ago

@nimroddolev

I was testing something just now and received the "failed to init decoder" error again. I know this is coming from pyatv, but I'm not sure if it's caused by something going wrong with ChimeTTS's MP3 generation?

Logger: homeassistant.core
Source: core.py:2781
First occurred: 10:16:50 AM (4 occurrences)
Last logged: 10:18:34 AM

Error executing service: <ServiceCall media_player.play_media (c:01J7E4PA9HCVKVCA27EEXTQ6ZY): entity_id=['media_player.office'], announce=False, extra=, media_type=music, media_id=media-source://media_source/local/sounds/temp/chime_tts/_a36rrfa.mp3>
Error executing service: <ServiceCall media_player.play_media (c:01J7E4QJPTHBMR349KZRG0KRB4): entity_id=['media_player.office'], announce=False, extra=, media_type=music, media_id=media-source://media_source/local/sounds/temp/chime_tts/u8ggdsst.mp3>
Error executing service: <ServiceCall media_player.play_media (c:01J7E4R4RX2NAF287RBDX88RCR): entity_id=['media_player.office'], announce=False, extra=, media_type=music, media_id=media-source://media_source/local/sounds/temp/chime_tts/v2ha05e2.mp3>
Error executing service: <ServiceCall media_player.play_media (c:01J7E4SF8C15PBHAQE91RTNEK8): entity_id=['media_player.office'], announce=False, extra=, media_type=music, media_id=media-source://media_source/local/sounds/temp/chime_tts/1z8wfpqv.mp3>
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/core.py", line 2781, in _run_service_call_catch_exceptions
    await coro_or_task
  File "/usr/src/homeassistant/homeassistant/core.py", line 2804, in _execute_service
    return await target(service_call)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 996, in entity_service_call
    single_response = await _handle_entity_call(
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 1068, in _handle_entity_call
    result = await task
             ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/apple_tv/media_player.py", line 344, in async_play_media
    await self.atv.stream.stream_file(media_id)
  File "/usr/local/lib/python3.12/site-packages/pyatv/core/facade.py", line 374, in stream_file
    await self.relay("stream_file")(
  File "/usr/local/lib/python3.12/site-packages/pyatv/protocols/raop/__init__.py", line 360, in stream_file
    audio_file = await open_source(
                 ^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/pyatv/protocols/raop/audio_source.py", line 730, in open_source
    return await InternetSource.open(source, sample_rate, channels, sample_size)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/pyatv/protocols/raop/audio_source.py", line 598, in open
    stream_generator = await loop.run_in_executor(
                       ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/miniaudio.py", line 1270, in stream_any
    raise DecodeError("failed to init decoder", result)
miniaudio.DecodeError: ('failed to init decoder', -1)

JonLaliberte commented 2 months ago

@nimroddolev I think I figured out the problem.. Or at least part of it? I noticed this issue over here as well: https://github.com/nimroddolev/chime_tts/issues/183 (I'm going to comment there too, just in case closed issues don't get notified about). When I set the Chime Path to a default which has a space in it, for example "Bells 2" or "Ding Dong", it fails. If I set it to something without a space, it works.

nimroddolev / chime_tts