Unable to configure Apple TV - does not accept PIN

[mirekmal]

Describe the bug

While trying to add ATV to integration cannot pass the step of entering the PIN, but it is not accepted. Configuration wizard displays message:

Pairing
Pairing is required for the RAOP protocol. Please enter the PIN code displayed on 
screen. Leading zeros shall be omitted, i.e. enter 123 if the displayed code is 0123.
Invalid authentication

After evry retry new PIN is displayed by ATV, but none is accepted by integration. Every retry logs error in homeassistant.log - listed below

Error log

021-12-18 14:39:59 ERROR (MainThread) [custom_components.apple_tv.config_flow] Authentication problem
Traceback (most recent call last):
  File "/usr/local/lib/python3.9/site-packages/pyatv/support/__init__.py", line 33, in error_handler
    return await func(*args, **kwargs)
  File "/usr/local/lib/python3.9/site-packages/pyatv/protocols/airplay/auth/legacy.py", line 62, in finish_pairing
    await self._send_plist(
  File "/usr/local/lib/python3.9/site-packages/pyatv/protocols/airplay/auth/legacy.py", line 79, in _send_plist
    return await self.http.post(
  File "/usr/local/lib/python3.9/site-packages/pyatv/support/http.py", line 359, in post
    return await self.send_and_receive(
  File "/usr/local/lib/python3.9/site-packages/pyatv/support/http.py", line 412, in send_and_receive
    raise exceptions.HttpError(
pyatv.exceptions.HttpError: HTTP/1.1 method POST failed with code 500: Internal Server Error

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

Traceback (most recent call last):
  File "/config/custom_components/apple_tv/config_flow.py", line 424, in async_step_pair_with_pin
    await self.pairing.finish()
  File "/usr/local/lib/python3.9/site-packages/pyatv/protocols/airplay/pairing.py", line 74, in finish
    await error_handler(
  File "/usr/local/lib/python3.9/site-packages/pyatv/support/__init__.py", line 41, in error_handler
    raise fallback(str(ex)) from ex
pyatv.exceptions.PairingError: HTTP/1.1 method POST failed with code 500: Internal Server Error

How to reproduce the bug?

I receive this error every try to add ATV to HA.

What is expected behavior?

Completion of configuration wizard.

Operating System

Mac OS 12.0.1

Python

3.9

pyatv

2.2.0

Device

Apple TV 4k, TV OS 15.2

Additional context

Not sure about python version, using supervised HA in VM under ESXi. All the lates update, so assuming the latest version of python too.

[postlund]

Are the Apple TV and Home Assistant on separate VLANs?

[mirekmal]

Nope, I have only 1 VLAN...

[Colorado4Wheeler]

I haven't pulled the debug logs on the AppleTV beta but this sounds like exactly what happened to me. Enter the three pins and get the "Aborted" UI notification.

[postlund]

@mirekmal Just realized this is another error (since it's RAOP and not Companion). Not really sure what is happening here though. Is access restrictions set to "All on the same network" under Settings->AirPlayon your Apple TV?

@Colorado4Wheeler That's a bit different. Re-authentication should happen in case authentication fails for an already existing device. So it should not happen when adding a new device. But I would love some logs for this so I can figure out what is going on.

[Colorado4Wheeler]

@postlund I added custom_component.apple_tv: debug to my logger and I never got anything more.

[mirekmal]

OK, I think I know what the problem was... timeout? I was initiating pairing from my desk computer, while the ATV is one floor up, in the TV room. It was giving me enough time to get up and memorize the code, but at the time I was back at my computer, code probably (?) expired. I tried pairing process from the phone, to avoid running stairways and to my surprise it went flawlesly... I was asked 3 times for PIN code for various services and each of codes was accepted. So false alarm... but operhaps this might be good hint to include in the documentation, that PIN is expireing on ATV quite quickly, so whole operation need tobe performed quite quckly. Or my observations are wrong and something changed that I did not spotted...

[postlund]

@Colorado4Wheeler I will look into that. Can you explain exactly what you did and if you had already added this device before or not? Is it still reproducible for you?

@mirekmal That sounds very reasonable. I haven't looked into it, but PIN codes like this generally have a short lifespan for security reasons. I would imagine 30-60s or so. I'll have a look and see if I can provide a better error message as guidance.

[mirekmal]

@postlund OK, thanks! So for now it seems closed from my side.

[postlund]

@Colorado4Wheeler I think we found the problem. For some reason there's an old entry lurking around in .storage/core.config_entries for your device. I don't quite understand why this isn't visible in the frontend, but if you remove that it will work again.

[Colorado4Wheeler]

I'll take another look but when I manually purged everything from core.config_entries before (when you posted that it was needed generally for the update) I was pretty thorough.