search

postlund / pyatv

A client library for Apple TV and AirPlay devices
https://pyatv.dev
MIT License
881 stars 96 forks source link

HELP: Help me understand and fix the "hanging connection" problem #812

Closed postlund closed 3 years ago

postlund commented 4 years ago

What's on your heart? I know a lot of you face the "hanging connection" problem, where no status updates are made and commands just time out. So far I've made a lot of improvements in order to mitigate this problem, but none have worked reliably. Probably because I don't know the root cause, so I don't know what to really fix.

There are a plethora of issues open that relates to this issue in one way or another. I will try to have a look at them and summarize problems when I have some time. A small note is that the same issue has been seen with atvremote and atvscript when just listening to push updates (I.e. calling with push_updates). So it's not strictly a Home Assistant problem.

Far from everyone seems to experience this issue though, me being one of them. This makes it additionally hard for me to debug. So I'm gonna need some help from the community. If you can reliably reproduce this problem and you want to help me out, this is basically what you need and what I'm interested in:

Assuming you have a Mac and know what you are doing (hehe), this should be fairly easy to do. I can give some additional guidance if needed, but I'm not gonna write a full-length tutorial just yet.

I believe the log from the Apple TV is the most important one as that probably can say what is happening.

Thanks for your help! 👍 I will keep updating the post once I have looked at the other issues.

Log configuguration:

logger:
  default: error
  logs:
    pyatv: debug
    custom_components.apple_tv: debug

Related Issues

batkite commented 4 years ago

Hi,

I will try to get you some inputs because I face the same situation as others. Mediaplayer do not reflect what is playing on ATV4K.

Well actually, while I'm writing I see that it is the ATV itself that do not reflect sometimes what it is actually playing.

For exemple, If I stream (airplay2) some music from my mac from a chrome tab or anything from my Iphone : sometimes I get what's playing on the ATV4K sidebar, sometimes not... and actually the HA media player is exactly reflecting this.

If I restart ATV4K and airplay 2 anything, I have the song in the sidebar of ATV and in HA media player. I've also noted that sometimes media player is not updating in HA if the ATV4 is playing some music but displaying the screen saver images. As soon as I hit the "menu" button on the remote, the HA media player updates instantly. Sorry if this post is somewhat irrelevant here but I'll try to investigate further.

loeffelpan commented 3 years ago

Just want to ask, if this helps: I can reliable reproduce this by turning off the ATV and wait (e. g. during the night). Connection is lost next morning. And I can make an wireshark trace (on homeassistant side). But I don't have a macbook with xcode to get logs from the ATV.

Please give a short answer if this would help.

postlund commented 3 years ago

At this point I think logs from the Apple TV via Xcode is the only way forward. Network captures have unfortunately not shown anything useful in the past (too much black box level).

loeffelpan commented 3 years ago

Thanks. Sorry, that I can't help with this. I work around with reloading the integration via REST triggered by ATV goes "unknown" more than a minute. That works for me.

postlund commented 3 years ago

When it breaks, do you see anything in the log?

loeffelpan commented 3 years ago

I got all the time these heartbeat errors. Status of ATV flips between idle/paused and unknown. Most of time this is not problem. If this is helpful let me know and I would create debug logs.

Maybe you can workaround with self reloading your extention like I do with my automation?

2021-03-28 17:38:22 ERROR (MainThread) [pyatv.mrp.protocol] heartbeat 0 failed
Traceback (most recent call last):
File "/usr/local/lib/python3.8/site-packages/pyatv/mrp/protocol.py", line 32, in heartbeat_loop
await protocol.send_and_receive(message)
File "/usr/local/lib/python3.8/site-packages/pyatv/mrp/protocol.py", line 169, in send_and_receive
return await self._receive(identifier, timeout)
File "/usr/local/lib/python3.8/site-packages/pyatv/mrp/protocol.py", line 177, in _receive
await asyncio.wait_for(semaphore.acquire(), timeout)
File "/usr/local/lib/python3.8/asyncio/tasks.py", line 501, in wait_for
raise exceptions.TimeoutError()
asyncio.exceptions.TimeoutError

When it breaks it stays „unknown“ and will be discovered as new device by HA after a while. When HA discovered as new device the „old“ one switches to „off“. Log (non-debug) says this.

2021-03-28 17:38:57 ERROR (MainThread) [homeassistant.components.apple_tv] Failed to connect
Traceback (most recent call last):
File "/usr/src/homeassistant/homeassistant/components/apple_tv/__init__.py", line 245, in _connect_loop
await self._connect(conf)
File "/usr/src/homeassistant/homeassistant/components/apple_tv/__init__.py", line 340, in _connect
'Connection was re-established to Apple TV "%s"', self.atv.service.name
AttributeError: 'MrpService' object has no attribute 'name'

And this.

2021-03-28 17:39:52 ERROR (MainThread) [homeassistant.util.logging] Exception in _async_disconnected when dispatching 'apple_tv_disconnected_054262D2-C7CA-47BC-AD00-66496C324B1A': ()
Traceback (most recent call last):
File "/usr/src/homeassistant/homeassistant/components/apple_tv/__init__.py", line 116, in _async_disconnected
self.async_device_disconnected()
File "/usr/src/homeassistant/homeassistant/components/apple_tv/media_player.py", line 92, in async_device_disconnected
self.atv.push_updater.stop()
AttributeError: 'NoneType' object has no attribute 'push_updater'
postlund commented 3 years ago

@loeffelpan That particular error is fixed on dev (in Home Assistant core), so it will be part of the next release.

loeffelpan commented 3 years ago

So this is not the error you need help with?

postlund commented 3 years ago

Nah, the problem is that the connection hangs with no updates being made whatsoever as well as no responses to commands (resulting in timeout exceptions).

loeffelpan commented 3 years ago

Thanks. Sorry for mixing this up.

nfstidham commented 3 years ago

Thanks. Sorry, that I can't help with this. I work around with reloading the integration via REST triggered by ATV goes "unknown" more than a minute. That works for me.

(Sorry to piggyback on a non-issue) @loeffelpan would you be able to share your automation for this? I think I'm having the same issue and would love to try your solution!

loeffelpan commented 3 years ago

Thanks. Sorry, that I can't help with this. I work around with reloading the integration via REST triggered by ATV goes "unknown" more than a minute. That works for me.

(Sorry to piggyback on a non-issue) @loeffelpan would you be able to share your automation for this? I think I'm having the same issue and would love to try your solution!

Please note: I don‘t use that automation since last major release of home assistant. I will share anyway: You have to configure a REST-Command in configuration.yaml. Mine look like this:

# Restart ATV integration
rest_command:
  reload_atv:
    url: http://homeassistant:8123/api/config/config_entries/entry/**066...**/reload
    method: POST
    headers:
      authorization: 'Bearer **eyJ...**‘
      content-type: 'application/json'

There are two information to insert. The auth-token you have to create as long life access token. And the id in the URL from /config/.storage/core.config_entries.

nfstidham commented 3 years ago

Thank you!

postlund commented 3 years ago

As tvOS 15 does not support MRP anymore, this issues becomes less relevant so I will close it now. It's possible that a similar issue will arise with the tvOS15+ as well, but that will likely be another kind of error.