core: Media playback automation not working

The problem

I have an automation that plays an mp3 file to my homepods on a schedule. . The file is stored locally. It was working fine up until this morning. As of this morning the file is not playing on any of the homepods. I’m noticing the following errors in the logs shortly after the automation runs.

Logger: homeassistant
Source: components/apple_tv/media_player.py:292
First occurred: February 12, 2023 at 11:59:05 AM (4 occurrences)
Last logged: 9:39:00 AM

Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/pyatv/support/http.py", line 390, in send_and_receive
    await event.wait()
  File "/usr/local/lib/python3.10/asyncio/locks.py", line 214, in wait
    await fut
asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/pyatv/support/http.py", line 389, in send_and_receive
    async with async_timeout.timeout(4):
  File "/usr/local/lib/python3.10/site-packages/async_timeout/__init__.py", line 129, in __aexit__
    self._do_exit(exc_type)
  File "/usr/local/lib/python3.10/site-packages/async_timeout/__init__.py", line 212, in _do_exit
    raise asyncio.TimeoutError
asyncio.exceptions.TimeoutError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 968, in async_request_call
    await coro
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 720, in _handle_entity_call
    await result
  File "/usr/src/homeassistant/homeassistant/components/apple_tv/media_player.py", line 292, in async_play_media
    await self.atv.stream.stream_file(media_id)
  File "/usr/local/lib/python3.10/site-packages/pyatv/core/facade.py", line 392, in stream_file
    await self.relay("stream_file")(file, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/pyatv/protocols/raop/__init__.py", line 352, in stream_file
    await client.initialize(self.core.service.properties)
  File "/usr/local/lib/python3.10/site-packages/pyatv/protocols/raop/raop.py", line 457, in initialize
    await self._setup_session()
  File "/usr/local/lib/python3.10/site-packages/pyatv/protocols/raop/raop.py", line 479, in _setup_session
    await self.rtsp.announce(
  File "/usr/local/lib/python3.10/site-packages/pyatv/support/rtsp.py", line 153, in announce
    response = await self.exchange(
  File "/usr/local/lib/python3.10/site-packages/pyatv/support/rtsp.py", line 265, in exchange
    resp = await self.connection.send_and_receive(
  File "/usr/local/lib/python3.10/site-packages/pyatv/support/http.py", line 393, in send_and_receive
    raise TimeoutError(f"no response to {method} {uri} ({protocol})") from ex
TimeoutError: no response to ANNOUNCE rtsp://10.107.112.240/325807200 (RTSP/1.0)

Logger: homeassistant.components.apple_tv
Source: components/apple_tv/__init__.py:169
Integration: Apple TV (documentation, issues)
First occurred: February 9, 2023 at 4:30:09 PM (29 occurrences)
Last logged: 9:30:13 AM

Connection lost to Apple TV "Office"
Connection lost to Apple TV "Dining Room"
Connection lost to Apple TV "Basement"
Connection lost to Apple TV "Bedroom"

Logger: pyatv.support.http
Source: runner.py:128
First occurred: February 8, 2023 at 1:30:04 PM (59 occurrences)
Last logged: 9:30:09 AM

Got response without having a request: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'date': 'Mon, 13 Feb 2023 14:30:08 GMT', 'content-length': '0', 'server': 'AirTunes/675.4.1', 'cseq': '1'}, body='')
Got response without having a request: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'date': 'Mon, 13 Feb 2023 14:30:08 GMT', 'content-length': '55', 'content-type': 'application/x-apple-binary-plist', 'server': 'AirTunes/675.4.1', 'cseq': '1789'}, body=b'bplist00\xd1\x01\x02Wstreams\xa0\x08\x0b\x13\x00\x00\x00\x00\x00\x00\x01\x01\x00\x00\x00\x00\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x14')
Got response without having a request: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'date': 'Mon, 13 Feb 2023 15:30:04 GMT', 'content-length': '0', 'server': 'AirTunes/675.4.1', 'cseq': '1'}, body='')
Got response without having a request: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'date': 'Mon, 13 Feb 2023 15:30:09 GMT', 'content-length': '0', 'server': 'AirTunes/675.4.1', 'cseq': '1'}, body='')
Got response without having a request: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'date': 'Mon, 13 Feb 2023 15:30:09 GMT', 'content-length': '55', 'content-type': 'application/x-apple-binary-plist', 'server': 'AirTunes/675.4.1', 'cseq': '1790'}, body=b'bplist00\xd1\x01\x02Wstreams\xa0\x08\x0b\x13\x00\x00\x00\x00\x00\x00\x01\x01\x00\x00\x00\x00\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x14')

What version of Home Assistant Core has the issue?

core-2023.2.3

What was the last working version of Home Assistant Core?

2023.2.3

What type of installation are you running?

Home Assistant OS

Integration causing the issue

apple_tv

Link to integration documentation on our website

https://www.home-assistant.io/integrations/apple_tv

Diagnostics information

No response

Example YAML snippet

alias: Dogs - Out to potty schedule
description: Reminder to take the dogs out
trigger:
  - platform: time_pattern
    hours: /1
    minutes: "30"
condition:
  - condition: time
    after: "07:00:00"
    before: "20:00:00"
    weekday:
      - sun
      - mon
      - tue
      - wed
      - thu
      - fri
      - sat
action:
  - service: media_player.play_media
    data:
      media_content_id: http://10.107.112.240:8123/local/sounds/Notification2.mp3
      media_content_type: music
    target:
      entity_id: media_player.all_homepods
mode: single

Anything in the logs that might be useful for us?

No response

Additional information

No response

About this issue

Original URL
State: closed
Created a year ago
Comments: 60 (2 by maintainers)

Most upvoted comments

I’m slowly working my way through the PR backlog and will make an update in due time. Hopefully not in a galaxy too far away.

postlund on Apr 9, 2023

I’ve heard about this is several places and I will look into it when I have some time over. I’m a bit choked right now though.

postlund on Mar 31, 2023

I think I have fixed this above - see the fork, and my issue in pyatv above. Was related to 4 second timeout in http, suspect this relates to problems with OS16.4 overall, various complaints…. Still testing some more but haven’t seen it again since. There may be more to it - as to why it takes longer than 4 seconds to complete, but with a longer timeout all seems to be good. To install fork update of pyatv - can use below after uninstalled pyatv, or likely with update. pip3 install git+https://github.com/Ghawken/pyatv@os16.4fix

I’ve tested here… and you were right… the very first playback takes around 7-8 seconds to start playing, that’s why 4secs wasn’t enough. After increasing it to 10 like you did in your PR, it is working every single time! Question… why this time got worse in 16.4? maybe there’s another fix for this issue no? instead of adding a bigger timeout, we should optimize the playback delay from 7-8secs to < 4s (as before)

That sounds like great news. How do I implement this fix? Can you give me the steps to install your fork?

Hehe, I didn’t want to mess up with libraries… this was just a quick test changing the timeout manually, since this was just a single line of code I took this route.

open ha cli then type login it should give you a prompt # type: docker exec -it $(docker ps -f name=homeassistant -q) bash now you should be inside the homeassistant container open the pyatv file: vi /usr/local/lib/python3.10/site-packages/pyatv/support/http.py change the timeout from 4 to 10 before: async with async_timeout.timeout(4): after: async with async_timeout.timeout(10): restart your homeassistant and you should be good to go!

pyatv-change

NOTE THAT YOU SHOULD AVOID DOING THIS!!! IT CAN CAUSE UPGRADE PROBLEMS!! I DID JUST FOR TESTING PURPOSES IF SOMETHING BREAKS, YOU OWN IT!

jpconfessor on Apr 1, 2023

The wait for this fix seems to be abnormally long indeed. It’s just a matter of changing one constant from 5s to 10s and the work has been done already. I don’t know how many HA users are using TTS on HomePods, but I doubt it’s only affecting those in this thread… Granted, I modified all my calls with the Retry integration as a workaround, but it was a PITA and can’t be considered as a definitive fix. Any update on the matter would really be appreciated.

TekFan on Apr 27, 2023

Thanks @jpconfessor for the tip. I managed to downgrade to 16.3.2. Plug Homepod mini into a computer via USB-C. First download the ISPW: https://ipsw.me/AudioAccessory5,1. Once downloaded go to Finder or iTunes and select the HomePod mini in the Sidebar. Hold down the Option or Alt key and click on Restore. You should now be presented with a window to select the file you just downloaded. Choose the 16.3 IPSW and select open. The software will now install onto the HomePod. I removed and re-added the Homepod on the Home app. Tested TTS and it works perfectly!

dkkr23 on Mar 4, 2023

I’m slowly working my way through the PR backlog and will make an update in due time. Hopefully not in a galaxy too far away.

Will the fix be included in a future HA Update (and included in the release notes) or will I need to keep an eye on this thread?

VeniceNerd on Apr 17, 2023

Hi together. i have the same problem. This solution worked for me: Disable automatic updates for HomePods in the Home-App. Downgrade all my HomePods(mini) to Version 16.3.2 After restart an newcofigure all my HomePods, all automations with play audio on a HomePod worked. 😃

nireins on Mar 31, 2023

I am having the same behavior as yours… Unexpected error for call_service at pos 4: no response to ANNOUNCE TimeoutError: no response to ANNOUNCE rtsp://192.168.4.13/4248748160 (RTSP/1.0)

The workaround I’ve been using so far is playing some music from my phone in the affected homepod… then everything is back to normal.

I am not sure who changed this behavior… HA or Apple.

jpconfessor on Feb 26, 2023