core icon indicating copy to clipboard operation
core copied to clipboard

AppleTV 4K (tvOS 15.6) requires new authentication almost daily

Open Didel opened this issue 1 year ago • 22 comments

The problem

It looks like the Apple TV requires new authentication in an almost daily basis. ~~It could be, although not confirmed, it might require new authentication after turning off the Apple TV (that happens once or multiple times daily).~~ It appears that it does not matter how the AppleTV was turned off, either by automations or by the AppleTV Remote. After going through the authentication process in Home Assistant, everything’s works fine again until ~~(what I assume is the reason) the Apple TV is powered off again~~ [exact reason unknown].

What version of Home Assistant Core has the issue?

2022.08.03

What was the last working version of Home Assistant Core?

No response

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

No response

Anything in the logs that might be useful for us?

In order of occurrence:

Logger: homeassistant.components.apple_tv
Source: components/apple_tv/__init__.py:169 
Integration: Apple TV (documentation, issues) 
First occurred: 19 augustus 2022 17:46:51 (48 occurrences) 
Last logged: 07:54:14

Connection lost to Apple TV "Woonkamer"
Logger: pyatv.protocols.airplay
Source: /usr/local/lib/python3.10/site-packages/pyatv/protocols/airplay/__init__.py:267 
First occurred: 20 augustus 2022 15:35:20 (12 occurrences) 
Last logged: 07:54:25

Failed to set up remote control channel
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/local/lib/python3.10/site-packages/pyatv/protocols/airplay/__init__.py", line 258, in _connect_rc
    await control.start(str(core.config.address), control_port, credentials)
  File "/usr/local/lib/python3.10/site-packages/pyatv/protocols/airplay/remote_control.py", line 56, in start
    self.verifier = await verify_connection(credentials, self.connection)
  File "/usr/local/lib/python3.10/site-packages/pyatv/protocols/airplay/auth/__init__.py", line 103, in verify_connection
    has_encryption_keys = await verifier.verify_credentials()
  File "/usr/local/lib/python3.10/site-packages/pyatv/protocols/airplay/auth/hap.py", line 118, in verify_credentials
    await self._send(
  File "/usr/local/lib/python3.10/site-packages/pyatv/protocols/airplay/auth/hap.py", line 132, in _send
    return await self.http.post(
  File "/usr/local/lib/python3.10/site-packages/pyatv/support/http.py", line 360, in post
    return await self.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 POST /pair-verify (HTTP/1.1)
Logger: homeassistant.components.apple_tv
Source: components/apple_tv/__init__.py:323 
Integration: Apple TV (documentation, issues) 
First occurred: 20 augustus 2022 16:54:18 (2 occurrences) 
Last logged: 07:54:31

Authentication failed for Woonkamer, try reconfiguring device
Traceback (most recent call last):
  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/asyncio/tasks.py", line 456, in wait_for
    return fut.result()
asyncio.exceptions.CancelledError

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

Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/pyatv/protocols/companion/protocol.py", line 121, in _setup_encryption
    await pair_verifier.verify_credentials()
  File "/usr/local/lib/python3.10/site-packages/pyatv/protocols/companion/auth.py", line 163, in verify_credentials
    await self.protocol.exchange_auth(
  File "/usr/local/lib/python3.10/site-packages/pyatv/protocols/companion/protocol.py", line 145, in exchange_auth
    return await self._exchange_generic_opack(frame_type, data, identifier, timeout)
  File "/usr/local/lib/python3.10/site-packages/pyatv/protocols/companion/protocol.py", line 170, in _exchange_generic_opack
    unpacked_object = await self._queues[identifier].wait(timeout)
  File "/usr/local/lib/python3.10/site-packages/pyatv/support/collections.py", line 130, in wait
    await asyncio.wait_for(self._event.wait(), timeout)
  File "/usr/local/lib/python3.10/asyncio/tasks.py", line 458, in wait_for
    raise exceptions.TimeoutError() from exc
asyncio.exceptions.TimeoutError

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

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/apple_tv/__init__.py", line 222, in connect_once
    await self._connect(conf, raise_missing_credentials)
  File "/usr/src/homeassistant/homeassistant/components/apple_tv/__init__.py", line 323, in _connect
    self.atv = await connect(conf, self.hass.loop, session=session)
  File "/usr/local/lib/python3.10/site-packages/pyatv/__init__.py", line 135, in connect
    await atv.connect()
  File "/usr/local/lib/python3.10/site-packages/pyatv/core/facade.py", line 575, in connect
    if await setup_data.connect():
  File "/usr/local/lib/python3.10/site-packages/pyatv/protocols/companion/__init__.py", line 411, in _connect
    await api.connect()
  File "/usr/local/lib/python3.10/site-packages/pyatv/protocols/companion/api.py", line 121, in connect
    await self._protocol.start()
  File "/usr/local/lib/python3.10/site-packages/pyatv/protocols/companion/protocol.py", line 108, in start
    await self._setup_encryption()
  File "/usr/local/lib/python3.10/site-packages/pyatv/protocols/companion/protocol.py", line 127, in _setup_encryption
    raise exceptions.AuthenticationError(str(ex)) from ex
pyatv.exceptions.AuthenticationError
Logger: pyatv.support.http
Source: runner.py:119 
First occurred: 19 augustus 2022 17:46:47 (44 occurrences) 
Last logged: 07:54:37

Got response without having a request: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'date': 'Sat, 20 Aug 2022 14:50:19 GMT', 'content-length': '55', 'content-type': 'application/x-apple-binary-plist', 'server': 'AirTunes/620.8.2', 'cseq': '10'}, 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='HTTP', version='1.1', code=200, message='OK', headers={'date': 'Sat, 20 Aug 2022 14:51:56 GMT', 'content-length': '159', 'content-type': 'application/octet-stream', 'server': 'AirTunes/620.8.2'}, body=b"\x05xF\x1cv\xe5\xf6\xba\xa6\x15\xe8\xc6V\x11[\x02H\x17\xf9\x91\x9c\xd4\xbd\xa5\xad\x8b\x00?\x02\xaf#\xd7H\xdd\xddp\xdbm\x9e\x16\xeb^]\xa9 \xafF\x05\x04\x08\xa9\x1a4\x00\x1a\xc8\xc8\xbb6\x0c2\xf36C'\x9a\x15o\xb5\x18\x87\xc7\x9fGj\xca_7\x8c\xbb\x8a\x93\x18\xcc\x80u\x8a\xe2\t\xf3C\x00P\xac\xb9\xbbS\xf4\x8d\xfe\xb1\x94\xb1Hu\x8f\x81#\xc3n\xccJ\x94\x06Jr\x8b\x02{c*\xb6\x06\x01\x02\x03 !\xc2\x10d~\xae\xa4\xc37\xaeW\x826\x035\x07\xa5\xc3c\x02\xcb\xec]!\xdfK\x83\x1c\xaa\xfb\x8a\x0e")
Got response without having a request: HttpResponse(protocol='HTTP', version='1.1', code=200, message='OK', headers={'date': 'Sat, 20 Aug 2022 14:52:59 GMT', 'content-length': '3', 'content-type': 'application/octet-stream', 'server': 'AirTunes/620.8.2'}, body=b'\x06\x01\x04')
Got response without having a request: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'date': 'Sat, 20 Aug 2022 14:53:36 GMT', 'content-length': '59', 'content-type': 'application/x-apple-binary-plist', 'server': 'AirTunes/620.8.2', 'cseq': '0'}, body=b'bplist00\xd1\x01\x02YeventPort\x11\xc0\xa6\x08\x0b\x15\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\x18')
Got response without having a request: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'date': 'Sun, 21 Aug 2022 05:54:21 GMT', 'content-length': '0', 'audio-latency': '0', 'server': 'AirTunes/620.8.2', 'cseq': '1'}, body='')

Additional information

It could be that #76781 is caused by this as well.

Screenshot of Home Assistant interface:

EB50A611-F164-4DD6-B5B8-2AAD07868179

Didel avatar Aug 21 '22 07:08 Didel

Hey there @postlund, mind taking a look at this issue as it has been labeled with an integration (apple_tv) you are listed as a code owner for? Thanks! (message by CodeOwnersMention)

Same issue. My Apple TV is running public beta tvOS 16.

uspino2 avatar Aug 22 '22 05:08 uspino2

Same issue here, running latest tvOs on appletv 4k, latest HA.

rafalio avatar Sep 03 '22 02:09 rafalio

Same here. Apple TV is running on 15.6.

vdheidenet avatar Sep 14 '22 05:09 vdheidenet

Same here. Been on-going since the latest beta of pytv, but since I never managed to find any relevant log entries my filed issue staled out. Running the latest released tvos version.

This only seems to happen on the latest HW revision, i.e. the "new" AppleTV 4k. The older 4k model seems to just rock on...

emigrating avatar Sep 16 '22 14:09 emigrating

This only seems to happen on the latest HW revision, i.e. the "new" AppleTV 4k. The older 4k model seems to just rock on...

Not true, I have the ‘old’ / original 4K model and still have these problems.

Didel avatar Sep 16 '22 14:09 Didel

I

Fair enough.

In my setup I have an older one that I configured a few years ago which is still working just fine. That specific device has even been away in a different location for the summer but automation are still running when we came back in the autumn.

My two v2 4k devices just won't stick. Weird.

emigrating avatar Sep 16 '22 14:09 emigrating

All of you that have upgraded to tvOS 16: make sure to change AirPlay access permission to "everyone on the same network". It seems like apple has made a reset on this option.

postlund avatar Sep 16 '22 16:09 postlund

All of you that have upgraded to tvOS 16: make sure to change AirPlay access permission to "everyone on the same network". It seems like apple has made a reset on this option.

Is that to be read as though tvos 16 devices won't have this issue if reconfigured?

emigrating avatar Sep 19 '22 01:09 emigrating

I have noticed that while the integration says it needs to be reconfigured/reconnected to the Apple TV, a restart of Home Assistant makes it work again without actually doing so. It appears to me that the integration thinks it's disconnected when it is not, maybe through some faulty error detection?

mundschenk-at avatar Sep 19 '22 19:09 mundschenk-at

All of you that have upgraded to tvOS 16: make sure to change AirPlay access permission to "everyone on the same network". It seems like apple has made a reset on this option.

In iOS 16 the options are "Everyone", "Anyone on the same network" and "Only People Sharing This Home". I assume you mean the first option...

I have noticed that while the integration says it needs to be reconfigured/reconnected to the Apple TV, a restart of Home Assistant makes it work again without actually doing so. It appears to me that the integration thinks it's disconnected when it is not, maybe through some faulty error detection?

Same here. A simple restart of Home Assistant clears the error and the Reconfigure notification. In my case it only happens with one of the two identical Apple TVs in the house, both with static IPs and both with exactly the same settings.

uspino2 avatar Sep 21 '22 05:09 uspino2

@uspino2 "Anyone on the same network", otherwise you allow anyone to connect.

postlund avatar Sep 21 '22 05:09 postlund

Has anyone had any luck here? I've been having the same issue and would gladly do further testing if anyone has ideas.

TVOS 16 with airplay on 'Everyone' and 'Anyone on the same network' tested, issue arrises with both.

hogantg avatar Oct 07 '22 20:10 hogantg

@postlund Anything we can do to help debug this issue? It is kind of annoying.

mundschenk-at avatar Oct 16 '22 05:10 mundschenk-at

I've had this issue for months on one original Apple TV 4k. I moved it to the core switch, same issue. Finally I just factory reset it and did a manual setup without the iPhone and it solved the issue. YMMV

tsspmq avatar Oct 20 '22 19:10 tsspmq

I've had this issue for months on one original Apple TV 4k. I moved it to the core switch, same issue. Finally I just factory reset it and did a manual setup without the iPhone and it solved the issue. YMMV

@tsspmq - I have not set up an AppleTV in a long time. What do you mean by "without the iPhone"? Is there an option to complete setup of an Apple TV using iPhone I imagine? And therefore, you did not do that, but did it all on the TV itself?

hogantg avatar Oct 20 '22 20:10 hogantg

Yeah basically thats how it works. I don't like using the iPhone (You take it close to it and it "assists" in the setup). It loads in WiFi settings as well as the iCloud user/password. Since I use a different account for the store its easier to just do fresh and I segment my entertainment devices on a different VLAN and if a switch reboots it reverts to the client VLAN the phone uses. Just an annoyance.

One thing I did forget to mention - The one difference between this device and the other three was I had not assigned it to a room for HomeKit to stop nagging me to do it. I did that after the reset. I don't use HomeKit, but I got sick of that "badge" in the settings telling me to finish airplay setup. The one Apple TV is used by another family member so they never pay attention to it.

I could be experiencing a placebo effect and it breaks again tomorrow. I'll report back if it does, but maybe a few others can try that in the meantime.

When I looked at the debug logs, it would simply say it disconnected then it would reconnect, and keep doing that. Eventually it would start discovering it and have 10 "new devices" in the integrations section.

I had thought it was a bad cable, some kind of a mDNS reflection problem outside of HA but when I moved it, the problem followed it.

tsspmq avatar Oct 21 '22 01:10 tsspmq

When I find time this weekend I will give this reset a go. Report back if yours starts reauthenticating, and I'll be sure to report back my findings as well in the coming week. Hopefully providing some good starting points for debugging.

hogantg avatar Oct 21 '22 13:10 hogantg

Just wanted to report back that everything is still working great.

tsspmq avatar Oct 24 '22 01:10 tsspmq

I reset my AppleTV 4 (no k) just over an hour ago. Manual as did @tsspmq. No VLAN here, just static IP assignment. So far, it has not run into the failed automatic reauthentication. Will continue to monitor over the next few days and report back with any news.

hogantg avatar Oct 25 '22 03:10 hogantg

Unfortunately, I have bad news. The reset -> manual setup (no iPhone assistance) did not solve the authentication error for me. However, there were some interesting changes I have noticed. It seems as though I am not actually receiving the authentication error now, as I dont have those logs nor do I get a "Attention Required: reconfigure" message in the integrations screen.

I am noticing that while the integration is still connected, the status of my AppleTV is not changing away from either 'Paused' or 'Idle' when I come back to it hours later. I can however still use the media player to switch [app] sources, and turn off the AppleTV. Pretty odd.

If anyone has some insights, I'd love to hear them. In the meantime, I've set up a script/automation duo to run the 'reload integration' service every 10 minutes between 8pm-midnight, because that always resets the issue and allows my other automations to fire based on state of the AppleTV.

hogantg avatar Oct 27 '22 13:10 hogantg