pyatv 🚀 - Status shows unknown after powering off apple tv

This sounds like the component ends up in a re-connect loop, which it shouldn't. It would help me a lot if you provide some logs, I don't see this behavior myself.

postlund on 17 Apr 2020

Sure, I can definitely get you the logs. Where do I find them?

darkknightjs24 on 17 Apr 2020

Preferably like this:

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

It will set default log level to warning to avoid getting swamped with debug data from other components.

postlund on 17 Apr 2020

Awesome, here are the logs:

Another issue seems to have arisen (I am not sure if this is related), but when I restarted my Home Assistant instance, upon start up the Apple TV showed it was in the "Paused" state, even though the Apple TV is completely turned off.

2020-04-17 00:08:50 DEBUG (MainThread) [custom_components.apple_tv] Disconnecting from device
2020-04-17 00:08:50 DEBUG (MainThread) [custom_components.apple_tv] Updating state: connected=False, disconnected=False
2020-04-17 00:08:50 DEBUG (MainThread) [pyatv.mrp.connection] Disconnected from device: None
2020-04-17 00:08:50 DEBUG (MainThread) [custom_components.apple_tv] Updating state: connected=False, disconnected=True
2020-04-17 00:08:50 DEBUG (MainThread) [custom_components.apple_tv] Not starting connect loop (True, False)
2020-04-17 00:08:55 DEBUG (MainThread) [custom_components.apple_tv] Starting connect loop
2020-04-17 00:08:55 DEBUG (MainThread) [custom_components.apple_tv] Updating state: connected=False, disconnected=False
2020-04-17 00:08:55 DEBUG (MainThread) [pyatv.support.udns] Sending DNS request to 192.168.8.184 (Data=35ff012000040000000000000b5f6170706c6574762d7632045f746370056c6f63616c0000ff80010b5f746f7563682d61626c65045f746370056c6f63616c0000ff80010e5f6d6564696172656d6f74657476045f746370056c6f63616c0000ff8001085f616972706c6179045f746370056c6f63616c0000ff8001)
2020-04-17 00:09:00 DEBUG (MainThread) [custom_components.apple_tv] Failed to find device 93B23502-4B77-4795-ADC4-D0016032545E with address 192.168.8.184, trying to scan
2020-04-17 00:09:00 DEBUG (MainThread) [pyatv] Discovering devices for 5 seconds
2020-04-17 00:09:01 DEBUG (MainThread) [pyatv] Auto-discovered Bedroom at 192.168.8.65:7000 (Protocol.AirPlay)
2020-04-17 00:09:05 DEBUG (MainThread) [custom_components.apple_tv] Updating state: connected=False, disconnected=False
2020-04-17 00:09:05 DEBUG (MainThread) [custom_components.apple_tv] Failed to find device 93B23502-4B77-4795-ADC4-D0016032545E, trying later
2020-04-17 00:09:05 DEBUG (MainThread) [custom_components.apple_tv] Reconnecting in 1 seconds
2020-04-17 00:09:06 DEBUG (MainThread) [custom_components.apple_tv] Updating state: connected=False, disconnected=False
2020-04-17 00:09:06 DEBUG (MainThread) [pyatv.support.udns] Sending DNS request to 192.168.8.184 (Data=35ff012000040000000000000b5f6170706c6574762d7632045f746370056c6f63616c0000ff80010b5f746f7563682d61626c65045f746370056c6f63616c0000ff80010e5f6d6564696172656d6f74657476045f746370056c6f63616c0000ff8001085f616972706c6179045f746370056c6f63616c0000ff8001)
2020-04-17 00:09:11 DEBUG (MainThread) [custom_components.apple_tv] Failed to find device 93B23502-4B77-4795-ADC4-D0016032545E with address 192.168.8.184, trying to scan
2020-04-17 00:09:11 DEBUG (MainThread) [pyatv] Discovering devices for 5 seconds
2020-04-17 00:09:12 DEBUG (MainThread) [pyatv] Auto-discovered Bedroom at 192.168.8.65:7000 (Protocol.AirPlay)
2020-04-17 00:09:16 DEBUG (MainThread) [custom_components.apple_tv] Updating state: connected=False, disconnected=False
2020-04-17 00:09:16 DEBUG (MainThread) [custom_components.apple_tv] Failed to find device 93B23502-4B77-4795-ADC4-D0016032545E, trying later
2020-04-17 00:09:16 DEBUG (MainThread) [custom_components.apple_tv] Reconnecting in 3 seconds
2020-04-17 00:09:19 DEBUG (MainThread) [custom_components.apple_tv] Updating state: connected=False, disconnected=False
2020-04-17 00:09:19 DEBUG (MainThread) [pyatv.support.udns] Sending DNS request to 192.168.8.184 (Data=35ff012000040000000000000b5f6170706c6574762d7632045f746370056c6f63616c0000ff80010b5f746f7563682d61626c65045f746370056c6f63616c0000ff80010e5f6d6564696172656d6f74657476045f746370056c6f63616c0000ff8001085f616972706c6179045f746370056c6f63616c0000ff8001)
2020-04-17 00:09:24 DEBUG (MainThread) [custom_components.apple_tv] Failed to find device 93B23502-4B77-4795-ADC4-D0016032545E with address 192.168.8.184, trying to scan
2020-04-17 00:09:24 DEBUG (MainThread) [pyatv] Discovering devices for 5 seconds
2020-04-17 00:09:25 DEBUG (MainThread) [pyatv] Auto-discovered Bedroom at 192.168.8.65:7000 (Protocol.AirPlay)
2020-04-17 00:09:29 DEBUG (MainThread) [custom_components.apple_tv] Updating state: connected=False, disconnected=False

PS - the device the component ends up auto-discovering titled "Bedroom" is my airplay-enable Sonos speaker.

darkknightjs24 on 17 Apr 2020

Another issue seems to have arisen (I am not sure if this is related), but when I restarted my Home Assistant instance, upon start up the Apple TV showed it was in the "Paused" state, even though the Apple TV is completely turned off.

Powered off is a fuzzy concept here because the device can appear to be turned off (no white light or image output), but still have power and an IP connection. In that case it can report what ever it feels like. My Apple TV sometimes reports that the music app is active and a song is paused, even though it is "off". Best would be if you check the Remote app on your phone and see what that is reporting.

2020-04-17 00:08:50 DEBUG (MainThread) [custom_components.apple_tv] Disconnecting from device
2020-04-17 00:08:50 DEBUG (MainThread) [custom_components.apple_tv] Updating state: connected=False, disconnected=False
2020-04-17 00:08:50 DEBUG (MainThread) [pyatv.mrp.connection] Disconnected from device: None
2020-04-17 00:08:50 DEBUG (MainThread) [custom_components.apple_tv] Updating state: connected=False, disconnected=True
2020-04-17 00:08:50 DEBUG (MainThread) [custom_components.apple_tv] Not starting connect loop (True, False)
2020-04-17 00:08:55 DEBUG (MainThread) [custom_components.apple_tv] Starting connect loop
2020-04-17 00:08:55 DEBUG (MainThread) [custom_components.apple_tv] Updating state: connected=False, disconnected=False
2020-04-17 00:08:55 DEBUG (MainThread) [pyatv.support.udns] Sending DNS request to 192.168.8.184 (Data=35ff012000040000000000000b5f6170706c6574762d7632045f746370056c6f63616c0000ff80010b5f746f7563682d61626c65045f746370056c6f63616c0000ff80010e5f6d6564696172656d6f74657476045f746370056c6f63616c0000ff8001085f616972706c6179045f746370056c6f63616c0000ff8001)
2020-04-17 00:09:00 DEBUG (MainThread) [custom_components.apple_tv] Failed to find device 93B23502-4B77-4795-ADC4-D0016032545E with address 192.168.8.184, trying to scan
2020-04-17 00:09:00 DEBUG (MainThread) [pyatv] Discovering devices for 5 seconds
2020-04-17 00:09:01 DEBUG (MainThread) [pyatv] Auto-discovered Bedroom at 192.168.8.65:7000 (Protocol.AirPlay)
2020-04-17 00:09:05 DEBUG (MainThread) [custom_components.apple_tv] Updating state: connected=False, disconnected=False
2020-04-17 00:09:05 DEBUG (MainThread) [custom_components.apple_tv] Failed to find device 93B23502-4B77-4795-ADC4-D0016032545E, trying later
2020-04-17 00:09:05 DEBUG (MainThread) [custom_components.apple_tv] Reconnecting in 1 seconds
2020-04-17 00:09:06 DEBUG (MainThread) [custom_components.apple_tv] Updating state: connected=False, disconnected=False
2020-04-17 00:09:06 DEBUG (MainThread) [pyatv.support.udns] Sending DNS request to 192.168.8.184 (Data=35ff012000040000000000000b5f6170706c6574762d7632045f746370056c6f63616c0000ff80010b5f746f7563682d61626c65045f746370056c6f63616c0000ff80010e5f6d6564696172656d6f74657476045f746370056c6f63616c0000ff8001085f616972706c6179045f746370056c6f63616c0000ff8001)
2020-04-17 00:09:11 DEBUG (MainThread) [custom_components.apple_tv] Failed to find device 93B23502-4B77-4795-ADC4-D0016032545E with address 192.168.8.184, trying to scan
2020-04-17 00:09:11 DEBUG (MainThread) [pyatv] Discovering devices for 5 seconds
2020-04-17 00:09:12 DEBUG (MainThread) [pyatv] Auto-discovered Bedroom at 192.168.8.65:7000 (Protocol.AirPlay)
2020-04-17 00:09:16 DEBUG (MainThread) [custom_components.apple_tv] Updating state: connected=False, disconnected=False
2020-04-17 00:09:16 DEBUG (MainThread) [custom_components.apple_tv] Failed to find device 93B23502-4B77-4795-ADC4-D0016032545E, trying later
2020-04-17 00:09:16 DEBUG (MainThread) [custom_components.apple_tv] Reconnecting in 3 seconds
2020-04-17 00:09:19 DEBUG (MainThread) [custom_components.apple_tv] Updating state: connected=False, disconnected=False
2020-04-17 00:09:19 DEBUG (MainThread) [pyatv.support.udns] Sending DNS request to 192.168.8.184 (Data=35ff012000040000000000000b5f6170706c6574762d7632045f746370056c6f63616c0000ff80010b5f746f7563682d61626c65045f746370056c6f63616c0000ff80010e5f6d6564696172656d6f74657476045f746370056c6f63616c0000ff8001085f616972706c6179045f746370056c6f63616c0000ff8001)
2020-04-17 00:09:24 DEBUG (MainThread) [custom_components.apple_tv] Failed to find device 93B23502-4B77-4795-ADC4-D0016032545E with address 192.168.8.184, trying to scan
2020-04-17 00:09:24 DEBUG (MainThread) [pyatv] Discovering devices for 5 seconds
2020-04-17 00:09:25 DEBUG (MainThread) [pyatv] Auto-discovered Bedroom at 192.168.8.65:7000 (Protocol.AirPlay)
2020-04-17 00:09:29 DEBUG (MainThread) [custom_components.apple_tv] Updating state: connected=False, disconnected=False

Yep, definitely a connect loop due to sleep here. I'm working on a "fix" for this, but it is again very tricky. I think I will have to do a proper write-up about power management and figure out a good approach to that. But lets leave it at "it's not as easy as it seems".

PS - the device the component ends up auto-discovering titled "Bedroom" is my airplay-enable Sonos speaker.

It will be visible in the debug logs but it should hopefully not appear in the dialog where you add devices I hope? That was something I fixed in 0.5.0.

postlund on 17 Apr 2020

I just pushed a new update that should hopefully make this better. Hopefully the device should end up in idle state.

postlund on 28 Apr 2020

Hey, just updated the integration but now I am getting an error that makes the state 'Unavailable'. Here are the logs:

2020-04-28 08:43:27 ERROR (MainThread) [homeassistant.setup] Setup failed for apple_tv: unknown error
Traceback (most recent call last):
File "/usr/src/homeassistant/homeassistant/setup.py", line 137, in _async_setup_component component = integration.get_component()
File "/usr/src/homeassistant/homeassistant/loader.py", line 268, in get_component cache[self.domain] = importlib.import_module(self.pkg_path)
File "/usr/local/lib/python3.7/importlib/__init__.py", line 127, in import_module return _bootstrap._gcd_import(name[level:], package, level)
File "<frozen importlib._bootstrap>", line 1006, in _gcd_import
File "<frozen importlib._bootstrap>", line 983, in _find_and_load
File "<frozen importlib._bootstrap>", line 967, in _find_and_load_unlocked
File "<frozen importlib._bootstrap>", line 677, in _load_unlocked
File "<frozen importlib._bootstrap_external>", line 728, in exec_module
File "<frozen importlib._bootstrap>", line 219, in _call_with_frames_removed
File "/config/custom_components/apple_tv/__init__.py", line 8, in <module> from pyatv import connect, exceptions, scan
File "/usr/local/lib/python3.7/site-packages/pyatv/__init__.py", line 20, in <module> from pyatv.mrp import MrpAppleTV
File "/usr/local/lib/python3.7/site-packages/pyatv/mrp/__init__.py", line 25, in <module> from pyatv.mrp import messages, protobuf
File "/usr/local/lib/python3.7/site-packages/pyatv/mrp/messages.py", line 140, in <module> identifier, send_error=protobuf.SendCommandResultMessage.SendError.NoError
AttributeError: 'EnumTypeWrapper' object has no attribute 'NoError'

darkknightjs24 on 28 Apr 2020

Same as in #623, just pushed a fix for it.

postlund on 28 Apr 2020

Thanks, just updated and the re-connect loop is not happening!

However, there is one issue that has arisen (I do not know if it is related to this issue or not). After a restart, the Apple TV state remains idle even if there is something playing or paused on the device. To get the proper state, I have to turn off the Apple TV (from HA), and then turn it back on. Unfortunately, nothing shows up in the logs about this. Any other way I can help you resolve this issue?

darkknightjs24 on 28 Apr 2020

Yeah, this is an issue other people see as well. I don't really know what the problem is or how to solve it. But if you can provide some logs, that would be great. Log diversity might be a good thing here.

postlund on 3 May 2020

Can you possibly try with the latest update I just pushed to the component?

postlund on 14 Jul 2020

I have the same problem running the latest version.
Apple tv is often unavailable and HA is stuck in a reconnect loop. No "key press" working from HA. From my iphone remote everything works fine.

swenox on 22 Jul 2020

@swenox Can you provide some logs from the re-connect loop? I suspect something "bad" happens which leads to a disconnect. But then scanning fails so the connection is never restored because of that.

postlund on 22 Jul 2020

@postlund
I will try to get a log as soon as i have figured out how to. :)

swenox on 23 Jul 2020

@swenox Right here 😉

postlund on 23 Jul 2020

@postlund
Here is a log.
Is this what youre looking for? 😊

2020-07-28 22:40:15 ERROR (MainThread) [custom_components.apple_tv] Failed to connect
Traceback (most recent call last):
  File "/config/custom_components/apple_tv/__init__.py", line 227, in _connect_loop
    await self._connect(conf)
  File "/config/custom_components/apple_tv/__init__.py", line 317, in _connect
    self.atv = await connect(conf, self.hass.loop, session=session)
  File "/usr/local/lib/python3.8/site-packages/pyatv/__init__.py", line 76, in connect
    await atv.connect()
  File "/usr/local/lib/python3.8/site-packages/pyatv/mrp/__init__.py", line 704, in connect
    await self._protocol.start()
  File "/usr/local/lib/python3.8/site-packages/pyatv/mrp/protocol.py", line 66, in start
    self.device_info = await self.send_and_receive(msg)
  File "/usr/local/lib/python3.8/site-packages/pyatv/mrp/protocol.py", line 138, in send_and_receive
    return await self._receive(identifier, timeout)
  File "/usr/local/lib/python3.8/site-packages/pyatv/mrp/protocol.py", line 146, in _receive
    await asyncio.wait_for(semaphore.acquire(), timeout)
  File "/usr/local/lib/python3.8/asyncio/tasks.py", line 490, in wait_for
    raise exceptions.TimeoutError()
asyncio.exceptions.TimeoutError
2020-07-28 22:40:33 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for simpleicons which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant.
2020-07-28 22:41:18 ERROR (MainThread) [custom_components.apple_tv] Failed to connect
Traceback (most recent call last):
  File "/config/custom_components/apple_tv/__init__.py", line 227, in _connect_loop
    await self._connect(conf)
  File "/config/custom_components/apple_tv/__init__.py", line 317, in _connect
    self.atv = await connect(conf, self.hass.loop, session=session)
  File "/usr/local/lib/python3.8/site-packages/pyatv/__init__.py", line 76, in connect
    await atv.connect()
  File "/usr/local/lib/python3.8/site-packages/pyatv/mrp/__init__.py", line 704, in connect
    await self._protocol.start()
  File "/usr/local/lib/python3.8/site-packages/pyatv/mrp/protocol.py", line 66, in start
    self.device_info = await self.send_and_receive(msg)
  File "/usr/local/lib/python3.8/site-packages/pyatv/mrp/protocol.py", line 138, in send_and_receive
    return await self._receive(identifier, timeout)
  File "/usr/local/lib/python3.8/site-packages/pyatv/mrp/protocol.py", line 146, in _receive
    await asyncio.wait_for(semaphore.acquire(), timeout)
  File "/usr/local/lib/python3.8/asyncio/tasks.py", line 490, in wait_for
    raise exceptions.TimeoutError()
asyncio.exceptions.TimeoutError
2020-07-28 22:41:54 ERROR (MainThread) [custom_components.apple_tv] Failed to connect
Traceback (most recent call last):
  File "/config/custom_components/apple_tv/__init__.py", line 227, in _connect_loop
    await self._connect(conf)
  File "/config/custom_components/apple_tv/__init__.py", line 317, in _connect
    self.atv = await connect(conf, self.hass.loop, session=session)
  File "/usr/local/lib/python3.8/site-packages/pyatv/__init__.py", line 76, in connect
    await atv.connect()
  File "/usr/local/lib/python3.8/site-packages/pyatv/mrp/__init__.py", line 704, in connect
    await self._protocol.start()
  File "/usr/local/lib/python3.8/site-packages/pyatv/mrp/protocol.py", line 66, in start
    self.device_info = await self.send_and_receive(msg)
  File "/usr/local/lib/python3.8/site-packages/pyatv/mrp/protocol.py", line 138, in send_and_receive
    return await self._receive(identifier, timeout)
  File "/usr/local/lib/python3.8/site-packages/pyatv/mrp/protocol.py", line 146, in _receive
    await asyncio.wait_for(semaphore.acquire(), timeout)
  File "/usr/local/lib/python3.8/asyncio/tasks.py", line 490, in wait_for
    raise exceptions.TimeoutError()
asyncio.exceptions.TimeoutError
2020-07-28 22:42:50 ERROR (MainThread) [custom_components.apple_tv] Failed to connect
Traceback (most recent call last):
  File "/config/custom_components/apple_tv/__init__.py", line 227, in _connect_loop
    await self._connect(conf)
  File "/config/custom_components/apple_tv/__init__.py", line 317, in _connect
    self.atv = await connect(conf, self.hass.loop, session=session)
  File "/usr/local/lib/python3.8/site-packages/pyatv/__init__.py", line 76, in connect
    await atv.connect()
  File "/usr/local/lib/python3.8/site-packages/pyatv/mrp/__init__.py", line 704, in connect
    await self._protocol.start()
  File "/usr/local/lib/python3.8/site-packages/pyatv/mrp/protocol.py", line 66, in start
    self.device_info = await self.send_and_receive(msg)
  File "/usr/local/lib/python3.8/site-packages/pyatv/mrp/protocol.py", line 138, in send_and_receive
    return await self._receive(identifier, timeout)
  File "/usr/local/lib/python3.8/site-packages/pyatv/mrp/protocol.py", line 146, in _receive
    await asyncio.wait_for(semaphore.acquire(), timeout)
  File "/usr/local/lib/python3.8/asyncio/tasks.py", line 490, in wait_for
    raise exceptions.TimeoutError()
asyncio.exceptions.TimeoutError
2020-07-28 22:46:57 ERROR (MainThread) [custom_components.apple_tv] Failed to connect
Traceback (most recent call last):
  File "/config/custom_components/apple_tv/__init__.py", line 227, in _connect_loop
    await self._connect(conf)
  File "/config/custom_components/apple_tv/__init__.py", line 317, in _connect
    self.atv = await connect(conf, self.hass.loop, session=session)
  File "/usr/local/lib/python3.8/site-packages/pyatv/__init__.py", line 76, in connect
    await atv.connect()
  File "/usr/local/lib/python3.8/site-packages/pyatv/mrp/__init__.py", line 704, in connect
    await self._protocol.start()
  File "/usr/local/lib/python3.8/site-packages/pyatv/mrp/protocol.py", line 66, in start
    self.device_info = await self.send_and_receive(msg)
  File "/usr/local/lib/python3.8/site-packages/pyatv/mrp/protocol.py", line 138, in send_and_receive
    return await self._receive(identifier, timeout)
  File "/usr/local/lib/python3.8/site-packages/pyatv/mrp/protocol.py", line 146, in _receive
    await asyncio.wait_for(semaphore.acquire(), timeout)
  File "/usr/local/lib/python3.8/asyncio/tasks.py", line 490, in wait_for
    raise exceptions.TimeoutError()
asyncio.exceptions.TimeoutError

swenox on 28 Jul 2020

@swenox Sorry about the delay. But yes, that's what I'm after. Very peculiar issue I must say. Can you start by testing with the latest updated component and see if the same re-connect loop happens?

postlund on 21 Aug 2020

@postlund
I will try to update.
I have been ignoring this issue for a while now and today i checked and HA havent seen my apple tv in 3 weeks. (It's on every day)
I'll get back to you with results after the update.

swenox on 22 Aug 2020

@postlund
Im now running the latest version of HA and appletv addon and it's still not working.
Status is mostly unknown and HA cant find the apple tv even when it's on and playing something.
This is really strange.

swenox on 11 Sep 2020

Just "dumping" my debug here. Maybe it's usefull.
tvOS 14.3

Log output

homeassistant.log

2021-01-01 22:11:22 DEBUG (MainThread) [custom_components.apple_tv] Starting connect loop
2021-01-01 22:11:22 DEBUG (MainThread) [custom_components.apple_tv] Updating state: connected=False, disconnected=False
2021-01-01 22:11:22 DEBUG (SyncWorker_2) [pyatv.support.knock] Knocking at port 3689 on 10.10.1.9
2021-01-01 22:11:22 DEBUG (SyncWorker_4) [pyatv.support.knock] Knocking at port 7000 on 10.10.1.9
2021-01-01 22:11:22 DEBUG (SyncWorker_0) [pyatv.support.knock] Knocking at port 49152 on 10.10.1.9
2021-01-01 22:11:22 DEBUG (SyncWorker_3) [pyatv.support.knock] Knocking at port 32498 on 10.10.1.9
2021-01-01 22:11:22 DEBUG (MainThread) [pyatv.support.mdns] Cleaning up after UDNS request
2021-01-01 22:11:22 DEBUG (MainThread) [pyatv.support.mdns] Cleaning up after UDNS request
2021-01-01 22:11:22 DEBUG (MainThread) [pyatv.support.mdns] Cleaning up after UDNS request
2021-01-01 22:11:22 DEBUG (MainThread) [pyatv.support.scan] Auto-discovered Woonkamer at 10.10.1.9:49153 (Protocol.MRP)
2021-01-01 22:11:22 DEBUG (MainThread) [pyatv.support.scan] Auto-discovered Woonkamer at 10.10.1.9:7000 (Protocol.AirPlay)
2021-01-01 22:11:22 DEBUG (MainThread) [custom_components.apple_tv] Updating state: connected=False, disconnected=False
2021-01-01 22:11:22 DEBUG (MainThread) [pyatv.airplay] Loaded AirPlay credentials: <snip>:<snip>
2021-01-01 22:11:22 DEBUG (MainThread) [pyatv.mrp.connection] Connection made to device
2021-01-01 22:11:22 DEBUG (MainThread) [pyatv.support.net] Configured keep-alive on <asyncio.TransportSocket fd=30, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('10.10.0.33', 43168), raddr=('10.10.1.9', 49153)> (Linux)
2021-01-01 22:11:22 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:43168<->10.10.1.9:49153 Connection established
2021-01-01 22:11:22 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:43168<->10.10.1.9:49153 >> Send (Data=080f122434313434463138462d364644432d344337432d414439392d3237383836413143384139422000a20183010a2435666131383837632d353236632d343331382d616463632d633334613731663836396531120570796174761a066950686f6e6522063138413339332a12636f6d2e6170706c652e545652656d6f746532063334342e32383801404d480150016211636f6d2e6170706c652e54564d75736963680170017801880102a80101b00101)
2021-01-01 22:11:22 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:43168<->10.10.1.9:49153 >> Send: Protobuf: type: DEVICE_INFO_MESSAGE
identifier: "4144F18F-6FDC-4C7C-AD99-27886A1C8A9B"
errorCode: NoError
[deviceInfoMessage] {
uniqueIdentifier: "5fa1887c-526c-4318-adcc-c34a71f869e1"
name: "pyatv"
localizedModelName: "iPhone"
systemBuildVersion: "18A393"
applicationBundleIdentifier: "com.apple.TVRemote"
applicationBundleVersion: "344.28"
protocolVersion: 1
lastSupportedMessageType: 77
supportsSystemPairing: true
allowsPairing: true
systemMediaApplication: "com.apple.TVMusic"
supportsACL: true
supportsSharedQueue: true
supportsExtendedMotion: true
sharedQueueVersion: 2
deviceClass: iPhone
logicalDeviceCount: 1
}
2021-01-01 22:11:22 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:43168<->10.10.1.9:49153 << Receive (Data=a103080f122434313434463138462d364644432d344337432d414439392d3237383836413143384139422000a201cc020a2431343732334241372d373545442d344642352d383638302d4131343533393735373843431209576f6f6e6b616d65721a094170706c65c2a05456220631384b3536312a16636f6d2e6170706c652e6d6564696172656d6f7465643801406c480150016211636f6d2e6170706c652e54564d757369636801700178018801029a012431343732334241372d373545442d344642352d383638302d413134353339373537384343a2011136633a34613a38353a32363a64393a6462a80104b00100c00100d20124363744373831463...)
2021-01-01 22:11:22 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:43168<->10.10.1.9:49153 << Receive: Protobuf: type: DEVICE_INFO_MESSAGE
identifier: "4144F18F-6FDC-4C7C-AD99-27886A1C8A9B"
errorCode: NoError
[deviceInfoMessage] {
uniqueIdentifier: "14723BA7-75ED-4FB5-8680-A145397578CC"
name: "Woonkamer"
localizedModelName: "Apple\302\240TV"
systemBuildVersion: "18K561"
applicationBundleIdentifier: "com.apple.mediaremoted"
protocolVersion: 1
lastSupportedMessageType: 108
supportsSystemPairing: true
allowsPairing: true
systemMediaApplication: "com.apple.TVMusic"
supportsACL: true
supportsSharedQueue: true
supportsExtendedMotion: true
sharedQueueVersion: 2
deviceUID: "14723BA7-75ED-4FB5-8680-A145397578CC"
managedConfigDeviceID: "6c:4a:85:26:d9:db"
deviceClass: AppleTV
logicalDeviceCount: 0
isProxyGroupPlayer: false
groupUID: "67D781F8-D87E-4606-BF91-54BDF698FB5E"
isGroupLeader: true
isAirplayActive: false
systemPodcastApplication: "com.apple.podcasts"
enderDefaultGroupUID: "67D781F8-D87E-4606-BF91-54BDF698FB5E"
airplayReceivers: "TVAirPlay"
37: 0
38: 1
39: "AppleTV6,2"
}
85: "B9ABFC94-5297-45DF-A1AD-1D85849F1B62"
2021-01-01 22:11:22 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:43168<->10.10.1.9:49153 >> Send (Data=08222000ba022f0a250601010320877a6c8e0d9d4f8684284da92fa81d1f4206df92d9d7e22e5486dfab29a9d8511000180020002800)
2021-01-01 22:11:22 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:43168<->10.10.1.9:49153 >> Send: Protobuf: type: CRYPTO_PAIRING_MESSAGE
errorCode: NoError
[cryptoPairingMessage] {
pairingData: "\006\001\001\003 \207zl\216\r\235O\206\204(M\251/\250\035\037B\006\337\222\331\327\342.T\206\337\253)\251\330Q"
status: 0
isRetrying: false
isUsingSystemPairing: false
state: 0
}
2021-01-01 22:11:22 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:43168<->10.10.1.9:49153 << Receive (Data=d90108222000ba02aa010a9f01057818703a26e5604839cce1bcc903549013a624a3b1af2b305389dff35210dac46a6580681247b9581570161a49f756ce67b4ed0f676e90bd962fb1446c733c0d8214bac18f941a4262ab8b5e781556fffb423d67db24548ff1da87f1b959d187c955d56d84cbbaaa2c5400ea8da250db80892c88b60b5d25e806010203207ecc444ab6f90c32e757904805b465771932a14d0f07dbf263b97680c38b825e1000180020002800aa052443464538443744302d363235442d343531352d394131392d323245454238464339344331)
2021-01-01 22:11:22 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:43168<->10.10.1.9:49153 << Receive: Protobuf: type: CRYPTO_PAIRING_MESSAGE
errorCode: NoError
[cryptoPairingMessage] {
pairingData: "\005x\030p:&\345`H9\314\341\274\311\003T\220\023\246$\243\261\257+0S\211\337\363R\020\332\304je\200h\022G\271X\025p\026\032I\367V\3...
status: 0
isRetrying: false
isUsingSystemPairing: false
state: 0
}
85: "CFE8D7D0-625D-4515-9A19-22EEB8FC94C1"
2021-01-01 22:11:22 DEBUG (MainThread) [pyatv.mrp.auth] Device (Encrypted=18703a26e5604839cce1bcc903549013a624a3b1af2b305389dff35210dac46a6580681247b9581570161a49f756ce67b4ed0f676e90bd962fb1446c733c0d8214bac18f941a4262ab8b5e781556fffb423d67db24548ff1da87f1b959d187c955d56d84cbbaaa2c5400ea8da250db80892c88b60b5d25e8, Public=cee7c5a7471183819b71c56d770446279d02ebd0530e0a4ebaae657ae3d2175f)
2021-01-01 22:11:22 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:43168<->10.10.1.9:49153 >> Send (Data=08222000ba0287010a7d060103057887fa0f88aaa741d90354ed743fcf67560461ecedb5b98d5edfabc905198d7b9e4a35b8c901f4eda8704793cb992547066cef6711ab03000e1577fdd271cd165f8093435188c6d2f319107f90bf794c47bcaba793ba32d8f16adc4d58ef16151c69e441720abe48a25ecec738a0b729d76550f29fae2a34dc1000180020002800)
2021-01-01 22:11:22 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:43168<->10.10.1.9:49153 >> Send: Protobuf: type: CRYPTO_PAIRING_MESSAGE
errorCode: NoError
[cryptoPairingMessage] {
pairingData: "\006\001\003\005x\207\372\017\210\252\247A\331\003T\355t?\317gV\004a\354\355\265\271\215^\337\253\311\005\031\215{\236J5\270\311\00...
status: 0
isRetrying: false
isUsingSystemPairing: false
state: 0
}
2021-01-01 22:11:22 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:43168<->10.10.1.9:49153 << Receive (Data=3e08222000ba02100a060701020601041000180020002800aa052446334144463843322d453232372d344541392d383538462d413437434642324241413633)
2021-01-01 22:11:22 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:43168<->10.10.1.9:49153 << Receive: Protobuf: type: CRYPTO_PAIRING_MESSAGE
errorCode: NoError
[cryptoPairingMessage] {
pairingData: "\007\001\002\006\001\004"
status: 0
isRetrying: false
isUsingSystemPairing: false
state: 0
}
85: "F3ADF8C2-E227-4EA9-858F-A47CFB2BAA63"
2021-01-01 22:11:22 DEBUG (MainThread) [pyatv.mrp.srp] Keys (Input=0676ecd33cff0a72f3410eb3691ca3369ca31878cdbbc4a1ae8527110010a114, Output=6d8136b8e528ee938b21afbd471c26774987a04d1e82dfa8578b70cca1e92e96)
2021-01-01 22:11:22 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:43168<->10.10.1.9:49153 >> Send (Data=08262000d202020802)
2021-01-01 22:11:22 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:43168<->10.10.1.9:49153 >> Send (Encrypted=220b700121b53dd98180c0769360b877a9d20204af64799d10)
2021-01-01 22:11:22 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:43168<->10.10.1.9:49153 >> Send: Protobuf: type: SET_CONNECTION_STATE_MESSAGE
errorCode: NoError
[setConnectionStateMessage] {
state: Connected
}
2021-01-01 22:11:22 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:43168<->10.10.1.9:49153 >> Send (Data=0810122438424638303633312d323641312d343734362d414633352d3843313838324638373135442000aa010a08011000180120012800)
2021-01-01 22:11:22 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:43168<->10.10.1.9:49153 >> Send (Encrypted=bb8b4934b0a37a59251e8bbbe3fc323afb051cc3f7edde3199a79588ee505fae601e159ec488357dca1c200e7df407251b1ada02f8cc76f0492ed7dac4b2fda7015c3122ff8584)
2021-01-01 22:11:22 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:43168<->10.10.1.9:49153 >> Send: Protobuf: type: CLIENT_UPDATES_CONFIG_MESSAGE
identifier: "8BF80631-26A1-4746-AF35-8C1882F8715D"
errorCode: NoError
[clientUpdatesConfigMessage] {
artworkUpdates: true
nowPlayingUpdates: false
volumeUpdates: true
keyboardUpdates: true
outputDeviceUpdates: false
}
2021-01-01 22:11:22 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:43168<->10.10.1.9:49153 Disconnected from device: [Errno 104] Connection reset by peer
2021-01-01 22:11:27 ERROR (MainThread) [custom_components.apple_tv] Failed to connect
Traceback (most recent call last):
File "/config/custom_components/apple_tv/__init__.py", line 227, in _connect_loop
await self._connect(conf)
File "/config/custom_components/apple_tv/__init__.py", line 317, in _connect
self.atv = await connect(conf, self.hass.loop, session=session)
File "/usr/local/lib/python3.8/site-packages/pyatv/__init__.py", line 76, in connect
await atv.connect()
File "/usr/local/lib/python3.8/site-packages/pyatv/mrp/__init__.py", line 704, in connect
await self._protocol.start()
File "/usr/local/lib/python3.8/site-packages/pyatv/mrp/protocol.py", line 81, in start
await self.send_and_receive(messages.client_updates_config())
File "/usr/local/lib/python3.8/site-packages/pyatv/mrp/protocol.py", line 138, in send_and_receive
return await self._receive(identifier, timeout)
File "/usr/local/lib/python3.8/site-packages/pyatv/mrp/protocol.py", line 146, in _receive
await asyncio.wait_for(semaphore.acquire(), timeout)
File "/usr/local/lib/python3.8/asyncio/tasks.py", line 498, in wait_for
raise exceptions.TimeoutError()
asyncio.exceptions.TimeoutError
2021-01-01 22:11:27 DEBUG (MainThread) [custom_components.apple_tv] Reconnecting in 1 seconds

HA Info

System Health

Home Assistant Community Store

Home Assistant Supervisor

Lovelace

Edit: make it smaller :)

MarcHagen on 1 Jan 2021

It would be great if anyone of you in this issue could retry with latest version of Home Assistant and let me know what happens. No need for the custom component anymore.

postlund on 26 Feb 2021

@postlund

It would be great if anyone of you in this issue could retry with latest version of Home Assistant and let me know what happens. No need for the custom component anymore.

Still issues...

HA Info

System Health

Home Assistant Community Store

Home Assistant Supervisor

Lovelace

Log output

2021-03-02 23:23:40 DEBUG (MainThread) [pyatv.support.knock] Knocking at ports [3689, 7000, 49152, 32498] on 10.10.1.9
2021-03-02 23:23:40 DEBUG (MainThread) [pyatv.support.scan] Auto-discovered Woonkamer at 10.10.1.9:7000 (Protocol.AirPlay)
2021-03-02 23:23:40 DEBUG (MainThread) [pyatv.support.scan] Auto-discovered Woonkamer at 10.10.1.9:49244 (Protocol.MRP)
2021-03-02 23:23:40 DEBUG (MainThread) [pyatv.airplay] Loaded AirPlay credentials: 92BB9CFD8CA43653:46F646EC37A9094057620DE2A9439CCEEAEEC0796BE33A77946E503F4A481A10
2021-03-02 23:23:40 DEBUG (MainThread) [pyatv.mrp.connection] Connection made to device
2021-03-02 23:23:40 DEBUG (MainThread) [pyatv.support.net] Configured keep-alive on <asyncio.TransportSocket fd=39, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('10.10.0.33', 49966), raddr=('10.10.1.9', 49244)> (Linux)
2021-03-02 23:23:40 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:49966<->10.10.1.9:49244 Connection established
2021-03-02 23:23:40 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:49966<->10.10.1.9:49244 >> Send (Data=080f122438364643374434312d463439422d344341352d393933422d4232383841323333333834372000a20183010a2435666131383837632d353236632d343331382d616463632d633334613731663836396531120570796174761a066950686f6e6522063138413339332a12636f6d2e6170706c652e545652656d6f746532063334342e32383801406c480150016211636f6d2e6170706c652e54564d75736963680170017801880102a80101b00101)
2021-03-02 23:23:40 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:49966<->10.10.1.9:49244 >> Send: Protobuf: type: DEVICE_INFO_MESSAGE
identifier: "86FC7D41-F49B-4CA5-993B-B288A2333847"
errorCode: NoError
[deviceInfoMessage] {
uniqueIdentifier: "5fa1887c-526c-4318-adcc-c34a71f869e1"
name: "pyatv"
localizedModelName: "iPhone"
systemBuildVersion: "18A393"
applicationBundleIdentifier: "com.apple.TVRemote"
applicationBundleVersion: "344.28"
protocolVersion: 1
lastSupportedMessageType: 108
supportsSystemPairing: true
allowsPairing: true
systemMediaApplication: "com.apple.TVMusic"
supportsACL: true
supportsSharedQueue: true
supportsExtendedMotion: true
sharedQueueVersion: 2
deviceClass: iPhone
logicalDeviceCount: 1
}
2021-03-02 23:23:40 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:49966<->10.10.1.9:49244 << Receive (Data=aa03080f122438364643374434312d463439422d344341352d393933422d4232383841323333333834372000a201d5020a2431343732334241372d373545442d344642352d383638302d4131343533393735373843431209576f6f6e6b616d65721a094170706c65c2a05456220631384b3830322a16636f6d2e6170706c652e6d6564696172656d6f7465643801406c480150016211636f6d2e6170706c652e54564d757369636801700178018201066c4a852621d98801029a012431343732334241372d373545442d344642352d383638302d413134353339373537384343a2011136633a34613a38353a32363a64393a6462a80104b00101c00100d20...)
2021-03-02 23:23:40 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:49966<->10.10.1.9:49244 << Receive: Protobuf: type: DEVICE_INFO_MESSAGE
identifier: "86FC7D41-F49B-4CA5-993B-B288A2333847"
errorCode: NoError
[deviceInfoMessage] {
uniqueIdentifier: "14723BA7-75ED-4FB5-8680-A145397578CC"
name: "Woonkamer"
localizedModelName: "Apple\302\240TV"
systemBuildVersion: "18K802"
applicationBundleIdentifier: "com.apple.mediaremoted"
protocolVersion: 1
lastSupportedMessageType: 108
supportsSystemPairing: true
allowsPairing: true
systemMediaApplication: "com.apple.TVMusic"
supportsACL: true
supportsSharedQueue: true
supportsExtendedMotion: true
bluetoothAddress: "lJ\205&!\331"
sharedQueueVersion: 2
deviceUID: "14723BA7-75ED-4FB5-8680-A145397578CC"
managedConfigDeviceID: "6c:4a:85:26:d9:db"
deviceClass: AppleTV
logicalDeviceCount: 1
isProxyGroupPlayer: false
groupUID: "57504D0D-38C3-4EE9-A409-EC5450A83AD4"
isGroupLeader: true
isAirplayActive: false
systemPodcastApplication: "com.apple.podcasts"
enderDefaultGroupUID: "57504D0D-38C3-4EE9-A409-EC5450A83AD4"
airplayReceivers: "TVAirPlay"
clusterType: 0
isClusterAware: true
modelID: "AppleTV6,2"
}
uniqueIdentifier: "BCC86DD3-ACB3-49CC-9369-1E8B93733A5F"
2021-03-02 23:23:40 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:49966<->10.10.1.9:49244 >> Send (Data=08222000ba022f0a250601010320b99fc28d33903c99621cfca995feb061180cc8e4c0b268e42b5f10cabf2ce43c1000180020002800)
2021-03-02 23:23:40 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:49966<->10.10.1.9:49244 >> Send: Protobuf: type: CRYPTO_PAIRING_MESSAGE
errorCode: NoError
[cryptoPairingMessage] {
pairingData: "\006\001\001\003 \271\237\302\2153\220<\231b\034\374\251\225\376\260a\030\014\310\344\300\262h\344+_\020\312\277,\344<"
status: 0
isRetrying: false
isUsingSystemPairing: false
state: 0
}
2021-03-02 23:23:40 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:49966<->10.10.1.9:49244 << Receive (Data=d90108222000ba02aa010a9f01057841eb1fad8c1a2f4615be1e49c3a1fed2b22a89206d7122803f6d0df948244a6d45563a5aaf6526648df58c20af8435cd0baea73ab2c3bb7a89875456cda506e71e2bf68c36578f36247a2e862f98f029a2dfdbedaa9766eceb11e6c264e4c0f0f65da5e25ae0a77f555d610669a30172f1150706754fbdec0601020320c8e839ffa87ec878bc44fa55f94283dad2484d0a3e4cbcec1df9d1adda6277731000180020002800aa052446354632423433462d383545382d343230462d413835452d323441413144323432413636)
2021-03-02 23:23:40 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:49966<->10.10.1.9:49244 << Receive: Protobuf: type: CRYPTO_PAIRING_MESSAGE
errorCode: NoError
[cryptoPairingMessage] {
pairingData: "\005xA\353\037\255\214\032/F\025\276\036I\303\241\376\322\262*\211 mq\"\200?m\r\371H$JmEV:Z\257e&d\215\365\214 \257\2045\315\013\25...
status: 0
isRetrying: false
isUsingSystemPairing: false
state: 0
}
uniqueIdentifier: "F5F2B43F-85E8-420F-A85E-24AA1D242A66"
2021-03-02 23:23:40 DEBUG (MainThread) [pyatv.mrp.auth] Device (Encrypted=41eb1fad8c1a2f4615be1e49c3a1fed2b22a89206d7122803f6d0df948244a6d45563a5aaf6526648df58c20af8435cd0baea73ab2c3bb7a89875456cda506e71e2bf68c36578f36247a2e862f98f029a2dfdbedaa9766eceb11e6c264e4c0f0f65da5e25ae0a77f555d610669a30172f1150706754fbdec, Public=cee7c5a7471183819b71c56d770446279d02ebd0530e0a4ebaae657ae3d2175f)
2021-03-02 23:23:40 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:49966<->10.10.1.9:49244 >> Send (Data=08222000ba0287010a7d06010305788e6bbfd9167f16be03d577a813a1b8f4ecee6c71caebece0a1d766d65a17a6b82944bd9d88a1512a63712039348fbcfd8abfc3f09969f0d87acbaef75e4762743555e7a290579c837da306b3d3404dfcd18237aebb7a4045b25f0dfa9c560bb6b6c8aa7c99b8c0c68ce707e6f0c2cd6fe0a60683e3fd91441000180020002800)
2021-03-02 23:23:40 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:49966<->10.10.1.9:49244 >> Send: Protobuf: type: CRYPTO_PAIRING_MESSAGE
errorCode: NoError
[cryptoPairingMessage] {
pairingData: "\006\001\003\005x\216k\277\331\026\177\026\276\003\325w\250\023\241\270\364\354\356lq\312\353\354\340\241\327f\326Z\027\246\270)D\2...
status: 0
isRetrying: false
isUsingSystemPairing: false
state: 0
}
2021-03-02 23:23:40 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:49966<->10.10.1.9:49244 << Receive (Data=3e08222000ba02100a060701020601041000180020002800aa052434464446334235362d333734452d344131302d394644352d323537363844304145363339)
2021-03-02 23:23:40 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:49966<->10.10.1.9:49244 << Receive: Protobuf: type: CRYPTO_PAIRING_MESSAGE
errorCode: NoError
[cryptoPairingMessage] {
pairingData: "\007\001\002\006\001\004"
status: 0
isRetrying: false
isUsingSystemPairing: false
state: 0
}
uniqueIdentifier: "4FDF3B56-374E-4A10-9FD5-25768D0AE639"
2021-03-02 23:23:40 DEBUG (MainThread) [pyatv.mrp.srp] Keys (Input=d8bb7f76831ed6a4ed3256a7be559b704ac4b154485a21845dda7dc4fc9c1c7c, Output=49565c2b0b2dd55bdc863974d5e99f5c10212a5d798d2ffda9ae9b805704ed86)
2021-03-02 23:23:40 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:49966<->10.10.1.9:49244 >> Send (Data=08262000d202020802)
2021-03-02 23:23:40 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:49966<->10.10.1.9:49244 >> Send (Encrypted=d9bb16403539597304a4d0f1d7eee1952d6ce793dc229ef395)
2021-03-02 23:23:40 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:49966<->10.10.1.9:49244 >> Send: Protobuf: type: SET_CONNECTION_STATE_MESSAGE
errorCode: NoError
[setConnectionStateMessage] {
state: Connected
}
2021-03-02 23:23:40 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:49966<->10.10.1.9:49244 >> Send (Data=0810122443383234393230462d343131392d343036442d394230352d3643304236314343393544312000aa010a08011000180120012800)
2021-03-02 23:23:40 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:49966<->10.10.1.9:49244 >> Send (Encrypted=bbbe113a50c8e3e2325e5c4c77a172b389127cbb51329bbd94c6c7c697b92c75a5fb23da7b1ddcd46b36504508876ff6891bbfbb678fc91f75913a67a043779874cbb6819d6efc)
2021-03-02 23:23:40 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:49966<->10.10.1.9:49244 >> Send: Protobuf: type: CLIENT_UPDATES_CONFIG_MESSAGE
identifier: "C824920F-4119-406D-9B05-6C0B61CC95D1"
errorCode: NoError
[clientUpdatesConfigMessage] {
artworkUpdates: true
nowPlayingUpdates: false
volumeUpdates: true
keyboardUpdates: true
outputDeviceUpdates: false
}
2021-03-02 23:23:40 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:49966<->10.10.1.9:49244 Received EOF from server
2021-03-02 23:23:40 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:49966<->10.10.1.9:49244 Disconnected from device: None
2021-03-02 23:23:40 WARNING (MainThread) [pyatv.mrp.protocol] There were 1 outstanding requests
2021-03-02 23:23:40 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:49966<->10.10.1.9:49244 Closing connection
2021-03-02 23:23:45 ERROR (MainThread) [homeassistant.components.apple_tv] Failed to connect
Traceback (most recent call last):
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
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/usr/src/homeassistant/homeassistant/components/apple_tv/__init__.py", line 242, in _connect_loop
await self._connect(conf)
File "/usr/src/homeassistant/homeassistant/components/apple_tv/__init__.py", line 326, in _connect
self.atv = await connect(conf, self.hass.loop, session=session)
File "/usr/local/lib/python3.8/site-packages/pyatv/__init__.py", line 76, in connect
await atv.connect()
File "/usr/local/lib/python3.8/site-packages/pyatv/mrp/__init__.py", line 701, in connect
await self._protocol.start()
File "/usr/local/lib/python3.8/site-packages/pyatv/mrp/protocol.py", line 107, in start
await self.send_and_receive(messages.client_updates_config())
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 180, in _receive
del self._outstanding[identifier]
KeyError: 'C824920F-4119-406D-9B05-6C0B61CC95D1'

MarcHagen on 2 Mar 2021

Generated html log for for comment #789274266 is here.

github-actions[bot] on 3 Mar 2021

🎉1

Still same with Home Assistant 2021.3.2

HA Info

System Health

Home Assistant Community Store

Home Assistant Supervisor

Lovelace

Log output

2021-03-07 20:05:47 DEBUG (MainThread) [pyatv.support.knock] Knocking at ports [3689, 7000, 49152, 32498] on 10.10.1.9
2021-03-07 20:05:47 DEBUG (MainThread) [pyatv.support.scan] Auto-discovered Woonkamer at 10.10.1.9:7000 (Protocol.AirPlay)
2021-03-07 20:05:47 DEBUG (MainThread) [pyatv.support.scan] Auto-discovered Woonkamer at 10.10.1.9:49244 (Protocol.MRP)
2021-03-07 20:05:47 DEBUG (MainThread) [pyatv.airplay] Loaded AirPlay credentials: 92BB9CFD8CA43653:46F646EC37A9094057620DE2A9439CCEEAEEC0796BE33A77946E503F4A481A10
2021-03-07 20:05:47 DEBUG (MainThread) [pyatv.mrp.connection] Connection made to device
2021-03-07 20:05:47 DEBUG (MainThread) [pyatv.support.net] Configured keep-alive on <asyncio.TransportSocket fd=36, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('10.10.0.33', 55932), raddr=('10.10.1.9', 49244)> (Linux)
2021-03-07 20:05:47 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:55932<->10.10.1.9:49244 Connection established
2021-03-07 20:05:47 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:55932<->10.10.1.9:49244 >> Send (Data=080f122446363944423445322d333630452d343046302d394146462d4539363635453341433231442000a20183010a2435666131383837632d353236632d343331382d616463632d633334613731663836396531120570796174761a066950686f6e6522063138413339332a12636f6d2e6170706c652e545652656d6f746532063334342e32383801406c480150016211636f6d2e6170706c652e54564d75736963680170017801880102a80101b00101)
2021-03-07 20:05:47 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:55932<->10.10.1.9:49244 >> Send: Protobuf: type: DEVICE_INFO_MESSAGE
identifier: "F69DB4E2-360E-40F0-9AFF-E9665E3AC21D"
errorCode: NoError
[deviceInfoMessage] {
uniqueIdentifier: "5fa1887c-526c-4318-adcc-c34a71f869e1"
name: "pyatv"
localizedModelName: "iPhone"
systemBuildVersion: "18A393"
applicationBundleIdentifier: "com.apple.TVRemote"
applicationBundleVersion: "344.28"
protocolVersion: 1
lastSupportedMessageType: 108
supportsSystemPairing: true
allowsPairing: true
systemMediaApplication: "com.apple.TVMusic"
supportsACL: true
supportsSharedQueue: true
supportsExtendedMotion: true
sharedQueueVersion: 2
deviceClass: iPhone
logicalDeviceCount: 1
}
2021-03-07 20:05:47 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:55932<->10.10.1.9:49244 << Receive (Data=a103080f122446363944423445322d333630452d343046302d394146462d4539363635453341433231442000a201cc020a2431343732334241372d373545442d344642352d383638302d4131343533393735373843431209576f6f6e6b616d65721a094170706c65c2a05456220631384b3830322a16636f6d2e6170706c652e6d6564696172656d6f7465643801406c480150016211636f6d2e6170706c652e54564d757369636801700178018801029a012431343732334241372d373545442d344642352d383638302d413134353339373537384343a2011136633a34613a38353a32363a64393a6462a80104b00101c00100d20124353735303444304...)
2021-03-07 20:05:47 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:55932<->10.10.1.9:49244 << Receive: Protobuf: type: DEVICE_INFO_MESSAGE
identifier: "F69DB4E2-360E-40F0-9AFF-E9665E3AC21D"
errorCode: NoError
[deviceInfoMessage] {
uniqueIdentifier: "14723BA7-75ED-4FB5-8680-A145397578CC"
name: "Woonkamer"
localizedModelName: "Apple\302\240TV"
systemBuildVersion: "18K802"
applicationBundleIdentifier: "com.apple.mediaremoted"
protocolVersion: 1
lastSupportedMessageType: 108
supportsSystemPairing: true
allowsPairing: true
systemMediaApplication: "com.apple.TVMusic"
supportsACL: true
supportsSharedQueue: true
supportsExtendedMotion: true
sharedQueueVersion: 2
deviceUID: "14723BA7-75ED-4FB5-8680-A145397578CC"
managedConfigDeviceID: "6c:4a:85:26:d9:db"
deviceClass: AppleTV
logicalDeviceCount: 1
isProxyGroupPlayer: false
groupUID: "57504D0D-38C3-4EE9-A409-EC5450A83AD4"
isGroupLeader: true
isAirplayActive: false
systemPodcastApplication: "com.apple.podcasts"
enderDefaultGroupUID: "57504D0D-38C3-4EE9-A409-EC5450A83AD4"
airplayReceivers: "TVAirPlay"
clusterType: 0
isClusterAware: true
modelID: "AppleTV6,2"
}
uniqueIdentifier: "CF8DBCDE-AE19-41EF-845D-19E81797C3B5"
2021-03-07 20:05:47 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:55932<->10.10.1.9:49244 >> Send (Data=08222000ba022f0a25060101032074328770e32f5f4be9c66d1d388f1ae00646b67bb4167946682eb0e3bc010b6b1000180020002800)
2021-03-07 20:05:47 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:55932<->10.10.1.9:49244 >> Send: Protobuf: type: CRYPTO_PAIRING_MESSAGE
errorCode: NoError
[cryptoPairingMessage] {
pairingData: "\006\001\001\003 t2\207p\343/_K\351\306m\0358\217\032\340\006F\266{\264\026yFh.\260\343\274\001\013k"
status: 0
isRetrying: false
isUsingSystemPairing: false
state: 0
}
2021-03-07 20:05:47 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:55932<->10.10.1.9:49244 << Receive (Data=d90108222000ba02aa010a9f010578c5832005d606d05fb6b20841afb6e521a4bd62dfc48611b99131b7eada8278d324461cacfae633d32488c5ea9dc6b0ac16e231880b898c6085a179efcf9e06b4ab385f0ab937bb24558595cba8459f544b74afe7ad182b28d24acea42a67521cbd015aa4ceab4d5fb9dd26e6b5123b77493e1f531c285d340601020320475f4030f5c9afab4eda5f4e59532830453b122a5fa25a7b9c68f6877f1dfd741000180020002800aa052431313835344339352d343231382d343930332d414134462d313045344633414146393438)
2021-03-07 20:05:47 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:55932<->10.10.1.9:49244 << Receive: Protobuf: type: CRYPTO_PAIRING_MESSAGE
errorCode: NoError
[cryptoPairingMessage] {
pairingData: "\005x\305\203 \005\326\006\320_\266\262\010A\257\266\345!\244\275b\337\304\206\021\271\2211\267\352\332\202x\323$F\034\254\372\3463...
status: 0
isRetrying: false
isUsingSystemPairing: false
state: 0
}
uniqueIdentifier: "11854C95-4218-4903-AA4F-10E4F3AAF948"
2021-03-07 20:05:47 DEBUG (MainThread) [pyatv.mrp.auth] Device (Encrypted=c5832005d606d05fb6b20841afb6e521a4bd62dfc48611b99131b7eada8278d324461cacfae633d32488c5ea9dc6b0ac16e231880b898c6085a179efcf9e06b4ab385f0ab937bb24558595cba8459f544b74afe7ad182b28d24acea42a67521cbd015aa4ceab4d5fb9dd26e6b5123b77493e1f531c285d34, Public=cee7c5a7471183819b71c56d770446279d02ebd0530e0a4ebaae657ae3d2175f)
2021-03-07 20:05:47 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:55932<->10.10.1.9:49244 >> Send (Data=08222000ba0287010a7d0601030578ef2642133593b922152498d0919ee788cb7ff87753847e679af949cafa4cc6c982064ebfcb7c9e3d48d7b26c27d1e90381a379815e913590a654b546af6b2cd07adadf650abee981e04e526abf0290eee9673a2ee3f1ecce4ccf23f9d85a2efc101e1af09fc6a00ef6a6539d1d2ef21ce46d96f286058e441000180020002800)
2021-03-07 20:05:47 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:55932<->10.10.1.9:49244 >> Send: Protobuf: type: CRYPTO_PAIRING_MESSAGE
errorCode: NoError
[cryptoPairingMessage] {
pairingData: "\006\001\003\005x\357&B\0235\223\271\"\025$\230\320\221\236\347\210\313\177\370wS\204~g\232\371I\312\372L\306\311\202\006N\277\313|...
status: 0
isRetrying: false
isUsingSystemPairing: false
state: 0
}
2021-03-07 20:05:47 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:55932<->10.10.1.9:49244 << Receive (Data=3e08222000ba02100a060701020601041000180020002800aa052444314634394634412d464232462d344141342d383441362d384543313732364237353341)
2021-03-07 20:05:47 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:55932<->10.10.1.9:49244 << Receive: Protobuf: type: CRYPTO_PAIRING_MESSAGE
errorCode: NoError
[cryptoPairingMessage] {
pairingData: "\007\001\002\006\001\004"
status: 0
isRetrying: false
isUsingSystemPairing: false
state: 0
}
uniqueIdentifier: "D1F49F4A-FB2F-4AA4-84A6-8EC1726B753A"
2021-03-07 20:05:47 DEBUG (MainThread) [pyatv.mrp.srp] Keys (Input=acd3b1474dcc31fab450b2ab4724a031fa347593e9408abab988d44978988656, Output=c703c8ae58fc13383cc94a72696c701cdf2c4c4dce319bd13893403451e9ca56)
2021-03-07 20:05:47 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:55932<->10.10.1.9:49244 >> Send (Data=08262000d202020802)
2021-03-07 20:05:47 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:55932<->10.10.1.9:49244 >> Send (Encrypted=0deb822f81e1bf6b26c6bc5e37328ed16b672965ea9916eb97)
2021-03-07 20:05:47 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:55932<->10.10.1.9:49244 >> Send: Protobuf: type: SET_CONNECTION_STATE_MESSAGE
errorCode: NoError
[setConnectionStateMessage] {
state: Connected
}
2021-03-07 20:05:47 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:55932<->10.10.1.9:49244 >> Send (Data=0810122430454434344642382d353937422d343130312d414446372d4635323437344630374234422000aa010a08011000180120012800)
2021-03-07 20:05:47 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:55932<->10.10.1.9:49244 >> Send (Encrypted=37742576c3b0783962a22679e018d927c07cc75d1aadbe827e097b31c8b86bb0eb86a9b8a28589c7c3aecbec2e00e58abddbb0b2b0aa1da5d357f0a8995c8a23f59f96bb7f5178)
2021-03-07 20:05:47 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:55932<->10.10.1.9:49244 >> Send: Protobuf: type: CLIENT_UPDATES_CONFIG_MESSAGE
identifier: "0ED44FB8-597B-4101-ADF7-F52474F07B4B"
errorCode: NoError
[clientUpdatesConfigMessage] {
artworkUpdates: true
nowPlayingUpdates: false
volumeUpdates: true
keyboardUpdates: true
outputDeviceUpdates: false
}
2021-03-07 20:05:47 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:55932<->10.10.1.9:49244 Disconnected from device: [Errno 104] Connection reset by peer
2021-03-07 20:05:47 WARNING (MainThread) [pyatv.mrp.protocol] There were 1 outstanding requests
2021-03-07 20:05:47 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:55932<->10.10.1.9:49244 Closing connection
2021-03-07 20:05:53 ERROR (MainThread) [homeassistant.components.apple_tv] Failed to connect
Traceback (most recent call last):
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
During handling of the above exception, another exception occurred:
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 329, in _connect
self.atv = await connect(conf, self.hass.loop, session=session)
File "/usr/local/lib/python3.8/site-packages/pyatv/__init__.py", line 76, in connect
await atv.connect()
File "/usr/local/lib/python3.8/site-packages/pyatv/mrp/__init__.py", line 701, in connect
await self._protocol.start()
File "/usr/local/lib/python3.8/site-packages/pyatv/mrp/protocol.py", line 107, in start
await self.send_and_receive(messages.client_updates_config())
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 180, in _receive
del self._outstanding[identifier]
KeyError: '0ED44FB8-597B-4101-ADF7-F52474F07B4B'
2021-03-07 20:05:54 DEBUG (MainThread) [pyatv.support.knock] Knocking at ports [3689, 7000, 49152, 32498] on 10.10.1.9
2021-03-07 20:05:54 DEBUG (MainThread) [pyatv.support.scan] Auto-discovered Woonkamer at 10.10.1.9:7000 (Protocol.AirPlay)
2021-03-07 20:05:54 DEBUG (MainThread) [pyatv.support.scan] Auto-discovered Woonkamer at 10.10.1.9:49244 (Protocol.MRP)
2021-03-07 20:05:54 DEBUG (MainThread) [pyatv.airplay] Loaded AirPlay credentials: 92BB9CFD8CA43653:46F646EC37A9094057620DE2A9439CCEEAEEC0796BE33A77946E503F4A481A10
2021-03-07 20:05:54 DEBUG (MainThread) [pyatv.mrp.connection] Connection made to device
2021-03-07 20:05:54 DEBUG (MainThread) [pyatv.support.net] Configured keep-alive on <asyncio.TransportSocket fd=56, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('10.10.0.33', 56020), raddr=('10.10.1.9', 49244)> (Linux)
2021-03-07 20:05:54 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56020<->10.10.1.9:49244 Connection established
2021-03-07 20:05:54 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56020<->10.10.1.9:49244 >> Send (Data=080f122438414332333431412d443936362d343046422d383341412d3732363641414335303434322000a20183010a2435666131383837632d353236632d343331382d616463632d633334613731663836396531120570796174761a066950686f6e6522063138413339332a12636f6d2e6170706c652e545652656d6f746532063334342e32383801406c480150016211636f6d2e6170706c652e54564d75736963680170017801880102a80101b00101)
2021-03-07 20:05:54 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56020<->10.10.1.9:49244 >> Send: Protobuf: type: DEVICE_INFO_MESSAGE
identifier: "8AC2341A-D966-40FB-83AA-7266AAC50442"
errorCode: NoError
[deviceInfoMessage] {
uniqueIdentifier: "5fa1887c-526c-4318-adcc-c34a71f869e1"
name: "pyatv"
localizedModelName: "iPhone"
systemBuildVersion: "18A393"
applicationBundleIdentifier: "com.apple.TVRemote"
applicationBundleVersion: "344.28"
protocolVersion: 1
lastSupportedMessageType: 108
supportsSystemPairing: true
allowsPairing: true
systemMediaApplication: "com.apple.TVMusic"
supportsACL: true
supportsSharedQueue: true
supportsExtendedMotion: true
sharedQueueVersion: 2
deviceClass: iPhone
logicalDeviceCount: 1
}
2021-03-07 20:05:54 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56020<->10.10.1.9:49244 << Receive (Data=a103080f122438414332333431412d443936362d343046422d383341412d3732363641414335303434322000a201cc020a2431343732334241372d373545442d344642352d383638302d4131343533393735373843431209576f6f6e6b616d65721a094170706c65c2a05456220631384b3830322a16636f6d2e6170706c652e6d6564696172656d6f7465643801406c480150016211636f6d2e6170706c652e54564d757369636801700178018801029a012431343732334241372d373545442d344642352d383638302d413134353339373537384343a2011136633a34613a38353a32363a64393a6462a80104b00101c00100d20124353735303444304...)
2021-03-07 20:05:54 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56020<->10.10.1.9:49244 << Receive: Protobuf: type: DEVICE_INFO_MESSAGE
identifier: "8AC2341A-D966-40FB-83AA-7266AAC50442"
errorCode: NoError
[deviceInfoMessage] {
uniqueIdentifier: "14723BA7-75ED-4FB5-8680-A145397578CC"
name: "Woonkamer"
localizedModelName: "Apple\302\240TV"
systemBuildVersion: "18K802"
applicationBundleIdentifier: "com.apple.mediaremoted"
protocolVersion: 1
lastSupportedMessageType: 108
supportsSystemPairing: true
allowsPairing: true
systemMediaApplication: "com.apple.TVMusic"
supportsACL: true
supportsSharedQueue: true
supportsExtendedMotion: true
sharedQueueVersion: 2
deviceUID: "14723BA7-75ED-4FB5-8680-A145397578CC"
managedConfigDeviceID: "6c:4a:85:26:d9:db"
deviceClass: AppleTV
logicalDeviceCount: 1
isProxyGroupPlayer: false
groupUID: "57504D0D-38C3-4EE9-A409-EC5450A83AD4"
isGroupLeader: true
isAirplayActive: false
systemPodcastApplication: "com.apple.podcasts"
enderDefaultGroupUID: "57504D0D-38C3-4EE9-A409-EC5450A83AD4"
airplayReceivers: "TVAirPlay"
clusterType: 0
isClusterAware: true
modelID: "AppleTV6,2"
}
uniqueIdentifier: "B33A8054-7085-4B68-BEEB-490612BAAD0C"
2021-03-07 20:05:54 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56020<->10.10.1.9:49244 >> Send (Data=08222000ba022f0a25060101032032936176ffb17f48428d1e3387668a517a919075991ff49f014c1c1ab65ef13f1000180020002800)
2021-03-07 20:05:54 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56020<->10.10.1.9:49244 >> Send: Protobuf: type: CRYPTO_PAIRING_MESSAGE
errorCode: NoError
[cryptoPairingMessage] {
pairingData: "\006\001\001\003 2\223av\377\261\177HB\215\0363\207f\212Qz\221\220u\231\037\364\237\001L\034\032\266^\361?"
status: 0
isRetrying: false
isUsingSystemPairing: false
state: 0
}
2021-03-07 20:05:54 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56020<->10.10.1.9:49244 << Receive (Data=d90108222000ba02aa010a9f0105783f4b5aa214a0e6f72553f33e45fde0959cf1da5bbf838996b41662e76d521f6c79e3ecd849b51f7a363727a318b794d9be0b68179b440634964e6a1c9fc23b495193df17bdf8a2eb3d2aa03c1beb59ebb2575c3142845f45608f7006c6d660aeeb975e1d8248a91c6e4e86e4fa40f158e00523e9236cffe606010203201503081f9c84f01f6321b86608d9ebaf0060c3815d74f4574e4e4bd5226596601000180020002800aa052434354638434139342d433046302d343846332d383532322d434236353233353335373641)
2021-03-07 20:05:54 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56020<->10.10.1.9:49244 << Receive: Protobuf: type: CRYPTO_PAIRING_MESSAGE
errorCode: NoError
[cryptoPairingMessage] {
pairingData: "\005x?KZ\242\024\240\346\367%S\363>E\375\340\225\234\361\332[\277\203\211\226\264\026b\347mR\037ly\343\354\330I\265\037z67\'\243\03...
status: 0
isRetrying: false
isUsingSystemPairing: false
state: 0
}
uniqueIdentifier: "45F8CA94-C0F0-48F3-8522-CB652353576A"
2021-03-07 20:05:54 DEBUG (MainThread) [pyatv.mrp.auth] Device (Encrypted=3f4b5aa214a0e6f72553f33e45fde0959cf1da5bbf838996b41662e76d521f6c79e3ecd849b51f7a363727a318b794d9be0b68179b440634964e6a1c9fc23b495193df17bdf8a2eb3d2aa03c1beb59ebb2575c3142845f45608f7006c6d660aeeb975e1d8248a91c6e4e86e4fa40f158e00523e9236cffe6, Public=cee7c5a7471183819b71c56d770446279d02ebd0530e0a4ebaae657ae3d2175f)
2021-03-07 20:05:54 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56020<->10.10.1.9:49244 >> Send (Data=08222000ba0287010a7d0601030578b5be55e5c2808c978d2bc9de555153e8bd028a85b2d575695f40d9b4e3b6e58c96ae3138ca0755dfbe635da9a0bc15704c77db169b2080b576df3dbea215190b2e96b1f100a94a3a0f3fc52c4d6a44d1ec62c64b06537ceb943f3ad7793f467d5962279bfa7b9402ac0f5a3f887c203a6f8155ef311369d01000180020002800)
2021-03-07 20:05:54 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56020<->10.10.1.9:49244 >> Send: Protobuf: type: CRYPTO_PAIRING_MESSAGE
errorCode: NoError
[cryptoPairingMessage] {
pairingData: "\006\001\003\005x\265\276U\345\302\200\214\227\215+\311\336UQS\350\275\002\212\205\262\325ui_@\331\264\343\266\345\214\226\25618\31...
status: 0
isRetrying: false
isUsingSystemPairing: false
state: 0
}
2021-03-07 20:05:54 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56020<->10.10.1.9:49244 << Receive (Data=3e08222000ba02100a060701020601041000180020002800aa052443443137353234312d324442312d344332332d423839322d303944383331363639363042)
2021-03-07 20:05:54 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56020<->10.10.1.9:49244 << Receive: Protobuf: type: CRYPTO_PAIRING_MESSAGE
errorCode: NoError
[cryptoPairingMessage] {
pairingData: "\007\001\002\006\001\004"
status: 0
isRetrying: false
isUsingSystemPairing: false
state: 0
}
uniqueIdentifier: "CD175241-2DB1-4C23-B892-09D83166960B"
2021-03-07 20:05:54 DEBUG (MainThread) [pyatv.mrp.srp] Keys (Input=8c138a89ca1288910a8c2f815cd40e4693787b6eaae04253cf83c1d82aba2aa3, Output=126faa57b788967b6a44c267dccf22d74509a169fd94ee06a66fd12f1eafd438)
2021-03-07 20:05:54 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56020<->10.10.1.9:49244 >> Send (Data=08262000d202020802)
2021-03-07 20:05:54 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56020<->10.10.1.9:49244 >> Send (Encrypted=514745b70f757853705c905122c4ea160064b3ba54d1bc1493)
2021-03-07 20:05:54 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56020<->10.10.1.9:49244 >> Send: Protobuf: type: SET_CONNECTION_STATE_MESSAGE
errorCode: NoError
[setConnectionStateMessage] {
state: Connected
}
2021-03-07 20:05:54 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56020<->10.10.1.9:49244 >> Send (Data=0810122436333237364644462d334146322d344333332d393235442d3242453234334644413330412000aa010a08011000180120012800)
2021-03-07 20:05:54 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56020<->10.10.1.9:49244 >> Send (Encrypted=173b442256eb284a6d96ce3e26f11bad4768cdf3cdea0ced387d9c1bfe73c3dc2afc79fa51bec076aeff974bbb8792d0f9bcacf539f3f09dada8260511571fcfd9bef843885173)
2021-03-07 20:05:54 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56020<->10.10.1.9:49244 >> Send: Protobuf: type: CLIENT_UPDATES_CONFIG_MESSAGE
identifier: "63276FDF-3AF2-4C33-925D-2BE243FDA30A"
errorCode: NoError
[clientUpdatesConfigMessage] {
artworkUpdates: true
nowPlayingUpdates: false
volumeUpdates: true
keyboardUpdates: true
outputDeviceUpdates: false
}
2021-03-07 20:05:54 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56020<->10.10.1.9:49244 Disconnected from device: [Errno 104] Connection reset by peer
2021-03-07 20:05:54 WARNING (MainThread) [pyatv.mrp.protocol] There were 1 outstanding requests
2021-03-07 20:05:54 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56020<->10.10.1.9:49244 Closing connection
2021-03-07 20:05:59 ERROR (MainThread) [homeassistant.components.apple_tv] Failed to connect
Traceback (most recent call last):
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
During handling of the above exception, another exception occurred:
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 329, in _connect
self.atv = await connect(conf, self.hass.loop, session=session)
File "/usr/local/lib/python3.8/site-packages/pyatv/__init__.py", line 76, in connect
await atv.connect()
File "/usr/local/lib/python3.8/site-packages/pyatv/mrp/__init__.py", line 701, in connect
await self._protocol.start()
File "/usr/local/lib/python3.8/site-packages/pyatv/mrp/protocol.py", line 107, in start
await self.send_and_receive(messages.client_updates_config())
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 180, in _receive
del self._outstanding[identifier]
KeyError: '63276FDF-3AF2-4C33-925D-2BE243FDA30A'
2021-03-07 20:06:01 DEBUG (MainThread) [pyatv.support.knock] Knocking at ports [3689, 7000, 49152, 32498] on 10.10.1.9
2021-03-07 20:06:01 DEBUG (MainThread) [pyatv.support.scan] Auto-discovered Woonkamer at 10.10.1.9:7000 (Protocol.AirPlay)
2021-03-07 20:06:01 DEBUG (MainThread) [pyatv.support.scan] Auto-discovered Woonkamer at 10.10.1.9:49244 (Protocol.MRP)
2021-03-07 20:06:01 DEBUG (MainThread) [pyatv.airplay] Loaded AirPlay credentials: 92BB9CFD8CA43653:46F646EC37A9094057620DE2A9439CCEEAEEC0796BE33A77946E503F4A481A10
2021-03-07 20:06:01 DEBUG (MainThread) [pyatv.mrp.connection] Connection made to device
2021-03-07 20:06:01 DEBUG (MainThread) [pyatv.support.net] Configured keep-alive on <asyncio.TransportSocket fd=56, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('10.10.0.33', 56040), raddr=('10.10.1.9', 49244)> (Linux)
2021-03-07 20:06:01 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56040<->10.10.1.9:49244 Connection established
2021-03-07 20:06:01 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56040<->10.10.1.9:49244 >> Send (Data=080f122431433932424144462d463332442d344434302d423034452d4643314144464234394537302000a20183010a2435666131383837632d353236632d343331382d616463632d633334613731663836396531120570796174761a066950686f6e6522063138413339332a12636f6d2e6170706c652e545652656d6f746532063334342e32383801406c480150016211636f6d2e6170706c652e54564d75736963680170017801880102a80101b00101)
2021-03-07 20:06:01 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56040<->10.10.1.9:49244 >> Send: Protobuf: type: DEVICE_INFO_MESSAGE
identifier: "1C92BADF-F32D-4D40-B04E-FC1ADFB49E70"
errorCode: NoError
[deviceInfoMessage] {
uniqueIdentifier: "5fa1887c-526c-4318-adcc-c34a71f869e1"
name: "pyatv"
localizedModelName: "iPhone"
systemBuildVersion: "18A393"
applicationBundleIdentifier: "com.apple.TVRemote"
applicationBundleVersion: "344.28"
protocolVersion: 1
lastSupportedMessageType: 108
supportsSystemPairing: true
allowsPairing: true
systemMediaApplication: "com.apple.TVMusic"
supportsACL: true
supportsSharedQueue: true
supportsExtendedMotion: true
sharedQueueVersion: 2
deviceClass: iPhone
logicalDeviceCount: 1
}
2021-03-07 20:06:01 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56040<->10.10.1.9:49244 << Receive (Data=a103080f122431433932424144462d463332442d344434302d423034452d4643314144464234394537302000a201cc020a2431343732334241372d373545442d344642352d383638302d4131343533393735373843431209576f6f6e6b616d65721a094170706c65c2a05456220631384b3830322a16636f6d2e6170706c652e6d6564696172656d6f7465643801406c480150016211636f6d2e6170706c652e54564d757369636801700178018801029a012431343732334241372d373545442d344642352d383638302d413134353339373537384343a2011136633a34613a38353a32363a64393a6462a80104b00101c00100d20124353735303444304...)
2021-03-07 20:06:01 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56040<->10.10.1.9:49244 << Receive: Protobuf: type: DEVICE_INFO_MESSAGE
identifier: "1C92BADF-F32D-4D40-B04E-FC1ADFB49E70"
errorCode: NoError
[deviceInfoMessage] {
uniqueIdentifier: "14723BA7-75ED-4FB5-8680-A145397578CC"
name: "Woonkamer"
localizedModelName: "Apple\302\240TV"
systemBuildVersion: "18K802"
applicationBundleIdentifier: "com.apple.mediaremoted"
protocolVersion: 1
lastSupportedMessageType: 108
supportsSystemPairing: true
allowsPairing: true
systemMediaApplication: "com.apple.TVMusic"
supportsACL: true
supportsSharedQueue: true
supportsExtendedMotion: true
sharedQueueVersion: 2
deviceUID: "14723BA7-75ED-4FB5-8680-A145397578CC"
managedConfigDeviceID: "6c:4a:85:26:d9:db"
deviceClass: AppleTV
logicalDeviceCount: 1
isProxyGroupPlayer: false
groupUID: "57504D0D-38C3-4EE9-A409-EC5450A83AD4"
isGroupLeader: true
isAirplayActive: false
systemPodcastApplication: "com.apple.podcasts"
enderDefaultGroupUID: "57504D0D-38C3-4EE9-A409-EC5450A83AD4"
airplayReceivers: "TVAirPlay"
clusterType: 0
isClusterAware: true
modelID: "AppleTV6,2"
}
uniqueIdentifier: "881DB8E1-8A53-46B4-9665-CBF79388BEA4"
2021-03-07 20:06:01 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56040<->10.10.1.9:49244 >> Send (Data=08222000ba022f0a2506010103206b30f3664b2969106fbec2c01088be36d9a72726648da0c8da86278e69071c101000180020002800)
2021-03-07 20:06:01 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56040<->10.10.1.9:49244 >> Send: Protobuf: type: CRYPTO_PAIRING_MESSAGE
errorCode: NoError
[cryptoPairingMessage] {
pairingData: "\006\001\001\003 k0\363fK)i\020o\276\302\300\020\210\2766\331\247\'&d\215\240\310\332\206\'\216i\007\034\020"
status: 0
isRetrying: false
isUsingSystemPairing: false
state: 0
}
2021-03-07 20:06:01 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56040<->10.10.1.9:49244 << Receive (Data=d90108222000ba02aa010a9f010578d51a929ed1f77ce29f723f95721d1823aadbd2ddbc8aea00bfa21b4ebdeab2f2159a085278993a4d24df159d6d0c6492abf05dd3d157a4859ceed5fc40c66c8bd24b6954a58f4af4c4a7d5f5a9dd17d9ba18111ec0fb3725343a98bc52d816dfe4cb3d53f0f761e500c3a6bfb31e3ef49005ad61a63ad39a06010203206e3fe8b65cf3dc328b0ba4cf8c6fe076d24ed37f5596b154a5bedeb5c49ad2251000180020002800aa052444454533423634362d324137422d344638442d414245392d463642354444343735413934)
2021-03-07 20:06:01 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56040<->10.10.1.9:49244 << Receive: Protobuf: type: CRYPTO_PAIRING_MESSAGE
errorCode: NoError
[cryptoPairingMessage] {
pairingData: "\005x\325\032\222\236\321\367|\342\237r?\225r\035\030#\252\333\322\335\274\212\352\000\277\242\033N\275\352\262\362\025\232\010Rx\2...
status: 0
isRetrying: false
isUsingSystemPairing: false
state: 0
}
uniqueIdentifier: "DEE3B646-2A7B-4F8D-ABE9-F6B5DD475A94"
2021-03-07 20:06:01 DEBUG (MainThread) [pyatv.mrp.auth] Device (Encrypted=d51a929ed1f77ce29f723f95721d1823aadbd2ddbc8aea00bfa21b4ebdeab2f2159a085278993a4d24df159d6d0c6492abf05dd3d157a4859ceed5fc40c66c8bd24b6954a58f4af4c4a7d5f5a9dd17d9ba18111ec0fb3725343a98bc52d816dfe4cb3d53f0f761e500c3a6bfb31e3ef49005ad61a63ad39a, Public=cee7c5a7471183819b71c56d770446279d02ebd0530e0a4ebaae657ae3d2175f)
2021-03-07 20:06:01 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56040<->10.10.1.9:49244 >> Send (Data=08222000ba0287010a7d0601030578aa4ca946c435445f8c8b01b76d2739cf5ec3e371b10d2e0d08315d625bad11181156f7743fdcf04c9f429f65e9e21622f5793cc237b60345404b2a921d3854f2722f8e384709249813b6981e6690c7a94b7c9c849ce58997c30d69e600b7fbab58b2b4cece5bb6442e9b503d4f6c7fbc8abe860b3c853fcf1000180020002800)
2021-03-07 20:06:01 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56040<->10.10.1.9:49244 >> Send: Protobuf: type: CRYPTO_PAIRING_MESSAGE
errorCode: NoError
[cryptoPairingMessage] {
pairingData: "\006\001\003\005x\252L\251F\3045D_\214\213\001\267m\'9\317^\303\343q\261\r.\r\0101]b[\255\021\030\021V\367t?\334\360L\237B\237e\351...
status: 0
isRetrying: false
isUsingSystemPairing: false
state: 0
}
2021-03-07 20:06:01 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56040<->10.10.1.9:49244 << Receive (Data=3e08222000ba02100a060701020601041000180020002800aa052439463735423930302d433641452d343741372d414541352d453439303346313730454245)
2021-03-07 20:06:01 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56040<->10.10.1.9:49244 << Receive: Protobuf: type: CRYPTO_PAIRING_MESSAGE
errorCode: NoError
[cryptoPairingMessage] {
pairingData: "\007\001\002\006\001\004"
status: 0
isRetrying: false
isUsingSystemPairing: false
state: 0
}
uniqueIdentifier: "9F75B900-C6AE-47A7-AEA5-E4903F170EBE"
2021-03-07 20:06:01 DEBUG (MainThread) [pyatv.mrp.srp] Keys (Input=7df0cd63e8791be864b465ab0b8083d115d7848857b487094bcad00e23da05f6, Output=7cf306f79ab93de74ad55d404a4c40d24efa29151b396d2ae64ccc8990d51d4d)
2021-03-07 20:06:01 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56040<->10.10.1.9:49244 >> Send (Data=08262000d202020802)
2021-03-07 20:06:01 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56040<->10.10.1.9:49244 >> Send (Encrypted=f2078a8345cf33c6e8d1cbdb2b768a072d3a45fe6e820c411e)
2021-03-07 20:06:01 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56040<->10.10.1.9:49244 >> Send: Protobuf: type: SET_CONNECTION_STATE_MESSAGE
errorCode: NoError
[setConnectionStateMessage] {
state: Connected
}
2021-03-07 20:06:01 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56040<->10.10.1.9:49244 >> Send (Data=0810122435334334464332392d464246362d343636462d383544332d4446373135453444364232382000aa010a08011000180120012800)
2021-03-07 20:06:01 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56040<->10.10.1.9:49244 >> Send (Encrypted=920a1ca745485320c9324585bac7ad3af0a02fecba51a55f861748a0ecbd2dcdb54dbb3846c6421d267fff8be7bacf65f1b5d5d7a46418e56b188e1fc390a6969e264e795c9a45)
2021-03-07 20:06:01 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56040<->10.10.1.9:49244 >> Send: Protobuf: type: CLIENT_UPDATES_CONFIG_MESSAGE
identifier: "53C4FC29-FBF6-466F-85D3-DF715E4D6B28"
errorCode: NoError
[clientUpdatesConfigMessage] {
artworkUpdates: true
nowPlayingUpdates: false
volumeUpdates: true
keyboardUpdates: true
outputDeviceUpdates: false
}
2021-03-07 20:06:01 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56040<->10.10.1.9:49244 Received EOF from server
2021-03-07 20:06:01 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56040<->10.10.1.9:49244 Disconnected from device: [Errno 107] Socket not connected
2021-03-07 20:06:01 WARNING (MainThread) [pyatv.mrp.protocol] There were 1 outstanding requests
2021-03-07 20:06:01 DEBUG (MainThread) [pyatv.mrp.connection] 10.10.0.33:56040<->10.10.1.9:49244 Closing connection
2021-03-07 20:06:06 ERROR (MainThread) [homeassistant.components.apple_tv] Failed to connect
Traceback (most recent call last):
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
During handling of the above exception, another exception occurred:
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 329, in _connect
self.atv = await connect(conf, self.hass.loop, session=session)
File "/usr/local/lib/python3.8/site-packages/pyatv/__init__.py", line 76, in connect
await atv.connect()
File "/usr/local/lib/python3.8/site-packages/pyatv/mrp/__init__.py", line 701, in connect
await self._protocol.start()
File "/usr/local/lib/python3.8/site-packages/pyatv/mrp/protocol.py", line 107, in start
await self.send_and_receive(messages.client_updates_config())
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 180, in _receive
del self._outstanding[identifier]
KeyError: '53C4FC29-FBF6-466F-85D3-DF715E4D6B28'

MarcHagen on 7 Mar 2021

@MarcHagen Can you provide some logs as well?

postlund on 7 Mar 2021

👍1

Generated html log for for comment #792330994 is here.

github-actions[bot] on 7 Mar 2021

@MarcHagen I don't quite get why the device decides to close the connection. Encryption is set up just fine and then, when the first message is sent after that: connection reset. Can you try running atvremote from another host and see if that works?

postlund on 8 Mar 2021

@MarcHagen Also, what is the exact use case here? What are you doing?

postlund on 8 Mar 2021

@postlund oke, i have to admit, i feel pretty stupid. So apparently somewhere in updating of hass the pair keys where invalid/gone/not working.
I had removed the integration/entity, rebooted hass, added paired it again and now it works. I had tried this before in the 2021.2 something version but that didn't work. So sorry if this caused you(of someone else) some inconvenience.

@MarcHagen Also, what is the exact use case here? What are you doing?

I use some automations within HA to control my apple tv. To a "netflix and chill" setting, turning on every media device.
Also to do some "force" shutdowns when were going to bed, or away. And it sometimes get used just as a photoslider/videoslider/videowall. HA sends the remote command to the ATV to open a app and start a show.

MarcHagen on 10 Mar 2021

Pyatv: Status shows unknown after powering off apple tv

All 29 comments

System Health

System Health

System Health

Related issues