Closed steuerzentrale closed 1 year ago
Same, I kept updating in the past few days and realized today that it doesn't work properly anymore. I can't share the logs or behavior right now but will do soon.
Most likely same issue as #84233
probably yes, I read the issue too and wasnt sure to which integration the problem is related too, maybe websocket API and the Apple TV integration. I am more than happy to support with logs or information to find the issue.
Hi @steuerzentrale
the log shows, that you are using an custom integration (_custom_components.apple_tv
_), but not the HA core provided one.
To get support here, please first switch to the HA core provided apple_tv integration. Otherwise please gat in contact with the developer of this custom integration.
thx 👍
Hi there
yeah, thats true. I deleted the custom_component and try out the apple_tv integration from HA. thanks for the tip.
quick update, I deleted the custom_component and used the apple_tv integration from HA instead.
I still get this error and I can see in Node-RED that there es in error with the API.
Logger: homeassistant.components.websocket_api.http.connection Source: components/apple_tv/media_player.py:427 Integration: Home Assistant WebSocket API (documentation, issues) First occurred: 14:13:31 (1 occurrences) Last logged: 14:13:31
[547331592048] Command _hidC failed 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/api.py", line 139, in _send_command resp = await self._protocol.exchange_opack( File "/usr/local/lib/python3.10/site-packages/pyatv/protocols/companion/protocol.py", line 157, in exchange_opack 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/websocket_api/commands.py", line 200, in handle_call_service await hass.services.async_call( File "/usr/src/homeassistant/homeassistant/core.py", line 1745, in async_call task.result() File "/usr/src/homeassistant/homeassistant/core.py", line 1782, in _execute_service await cast(Callable[[ServiceCall], Awaitable[None]], handler.job.target)( File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 213, in handle_service await service.entity_service_call( File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 678, in entity_service_call future.result() # pop exception if have File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 943, in async_request_call await coro File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 715, in _handle_entity_call await result File "/usr/src/homeassistant/homeassistant/components/apple_tv/media_player.py", line 427, in async_turn_on await self.atv.power.turn_on() File "/usr/local/lib/python3.10/site-packages/pyatv/core/facade.py", line 353, in turn_on await self.relay("turn_on", priority=self.OVERRIDE_PRIORITIES)( File "/usr/local/lib/python3.10/site-packages/pyatv/protocols/companion/init.py", line 193, in turn_on await self.api.hid_command(False, HidCommand.Wake) File "/usr/local/lib/python3.10/site-packages/pyatv/protocols/companion/api.py", line 234, in hid_command await self._send_command( File "/usr/local/lib/python3.10/site-packages/pyatv/protocols/companion/api.py", line 150, in _send_command raise exceptions.ProtocolError(f"Command {identifier} failed") from ex pyatv.exceptions.ProtocolError: Command _hidC failed
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)
apple_tv documentation apple_tv source (message by IssueLinks)
can confirm. Next to my NR flow and API error message, trying the remote.send_command service (wakeup) directly in the UI times out. I had this issue starting from 16.2, updating the ATV to 16.3 didn't fix it. I completely removed and added the ATV integration but that didnt help.
023-01-28 12:58:56.615 INFO (MainThread) [homeassistant.components.apple_tv.remote] Sending command wakeup 2023-01-28 12:58:56.616 DEBUG (MainThread) [pyatv.auth.hap_channel] Sending data (Encrypted=ce00df411ecc3006ebedfa038f75a7aee975cf9eb1cc81292bb4478732f05a2bc81a9352e7676d28d4e84f21be9eab67410a3dfa04660497ac5b4fc3efc3e303b261e6cb08c7d1ce44eea2e6bf981f42b9a4789cfc0fc0b102d9332d1ace04fade68f3c4dada4dbdf32dfac97150dd705e120905ef41cc3f0a34987408dc49dd04127fe12048b06302853bc67057c4acf41fbdbb00da9add620d1a9fc2dc95e55fbfbfdf943b9bf7e865ff483d842190763a6d0047bec3854b8c1bf08500e691f77b5da2d6f668859709d81715360f1f9e788b7e09c91fcd4fbc78cb167a04a6) 2023-01-28 12:58:56.616 DEBUG (MainThread) [pyatv.protocols.airplay.mrp_connection] >> Send: Protobuf: type: SEND_HID_EVENT_MESSAGE errorCode: NoError [sendHIDEventMessage] { hidEventData: "C\211\"\317\010\002\000\000\000\000\000\000\000\000\000\000\001\000\000\000\000\000\000\000\002\000\000\000 \000\000\000\003\000\0... } uniqueIdentifier: "A0501115-09FF-456B-B19A-41957F22908F" 2023-01-28 12:58:56.617 DEBUG (MainThread) [pyatv.auth.hap_channel] Sending data (Encrypted=ce00cb4b1da10e176a36ffb33e1b007096deeebf80e49c4d3474d1c5f8abfbb503d8109d4fc50f6b97ae13ff443876ccf0de884ebe1c32d60a5b14495bdaa47460a8315644bd05ba169353131c616fa6bf84351c0689786d752697c00d372f3fbc69678f593f555034e24d99630a5dc6918015c4a157be14378453fe389bc52721642bfd59cc45761695db37a8d04616c15b5749eac0d25719e6684448f0306a6847c1d1be843858ee81d90781b36bbfbbe6d8b0cc3240e24025e24d991fe0daf74da68ac7bde8baecd01d610e1cb850971829809be9f58a325735566984d9aa) 2023-01-28 12:58:56.617 DEBUG (MainThread) [pyatv.protocols.airplay.mrp_connection] >> Send: Protobuf: type: SEND_HID_EVENT_MESSAGE errorCode: NoError [sendHIDEventMessage] { hidEventData: "C\211\"\317\010\002\000\000\000\000\000\000\000\000\000\000\001\000\000\000\000\000\000\000\002\000\000\000 \000\000\000\003\000\0... } uniqueIdentifier: "0EFCD20F-C90D-4F58-A8C9-2EBF017FA19C" 2023-01-28 12:58:56.618 DEBUG (MainThread) [pyatv.auth.hap_channel] Sending data (Encrypted=b40061adc68e8e44f900e295f268ab22e2f83ec2c625d0baf3330c050a0e36ea85c8114a20017ab000d6fa20b3b9166a19e67a2387bc51b301faf4326be23add9d8def83715c1e361cf6e307d6a1d84309cdb9e16396c3fa80a89579e45901557d5fd9d830c5337339acaae10bb1269fd7ccc18625adaf0e4ea8a7d32e5e315d6c1ed9e12635000f0002dc30db182b99eab7595fd151874db6f49954294416f604b23eb89a1f0ec4a747c51efd92f6e4ad6bdb2aeedd7853ad6b546e6ac07f0738a63f3aeab8) 2023-01-28 12:58:56.619 DEBUG (MainThread) [pyatv.protocols.airplay.mrp_connection] >> Send: Protobuf: type: GENERIC_MESSAGE identifier: "43FD481D-5E4E-47A2-9135-5F39E94FD0FC" errorCode: NoError uniqueIdentifier: "949942B1-EF55-493A-98B4-2786F60B5B96" 2023-01-28 12:58:56.620 DEBUG (MainThread) [pyatv.auth.hap_channel] Received data (Data=2000ed1db8c92f26dca989dede3a1a2de981cd6a6ac91465ae9143b0133d10389147210377dfaac31b3e8b51f5092f8e91102a00534a8f1f1cab3406ecd8b8c14e1d049aa8409e892c834beaf89f4790d02b59d4e860bba61c58484a7e4358821d47483c01582586b3a176d2f25a) 2023-01-28 12:58:56.621 DEBUG (MainThread) [pyatv.auth.hap_channel] Received data (Data=2000d7d8e7bef3846e0fa241aca7f6b9c6937a998e059d7cb304c9b5f0863a6492cfec7d9834ce3a68beaa67175e12d5f8e22a0063abe459b26d17f1297b4a0770439820b71ef9437bd1e09c5ac5ce9188194d4d593b6c27c3e24a221aa56535d2bc9e085550499b104ad62da7d7) 2023-01-28 12:58:56.622 DEBUG (MainThread) [pyatv.auth.hap_channel] Received data (Data=20001567721eb4330a2b2cee57a940913bc28c0e92fb420bc9049b45be6d00dd8744284c86ccda1d1fdb048a363826de9f0b2a00e982ef08f74d51e55ee0b8beec0e0120b8461e7630d8a5e95df09e4d61c02da31bd3272af53bc9156321d2dab767888d9f033f2d12d1d3d58689) 2023-01-28 12:58:57.842 DEBUG (MainThread) [pyatv.core.protocol] Sending periodic heartbeat 223 (AirPlay:10.0.20.22) 2023-01-28 12:58:57.842 DEBUG (MainThread) [pyatv.support.http] Sending RTSP/1.0 message: b'POST /feedback RTSP/1.0\r\nUser-Agent: AirPlay/540.31\r\nCSeq: 226\r\nDACP-ID: 418187C930517A38\r\nActive-Remote: 1398781041\r\nClient-Instance: 418187C930517A38\r\n\r\n' 2023-01-28 12:58:57.846 DEBUG (MainThread) [pyatv.support.http] Received: b'RTSP/1.0 200 OK\r\nDate: Sat, 28 Jan 2023 11:58:57 GMT\r\nContent-Length: 55\r\nContent-Type: application/x-apple-binary-plist\r\nServer: AirTunes/675.4.1\r\nCSeq: 226\r\n\r\nbplist00\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' 2023-01-28 12:58:57.846 DEBUG (MainThread) [pyatv.support.http] Got RTSP response: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'date': 'Sat, 28 Jan 2023 11:58:57 GMT', 'content-length': '55', 'content-type': 'application/x-apple-binary-plist', 'server': 'AirTunes/675.4.1', 'cseq': '226'}, 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'): 2023-01-28 12:58:57.846 DEBUG (MainThread) [pyatv.core.protocol] Got heartbeat 223 (AirPlay:10.0.20.22) 2023-01-28 12:58:59.848 DEBUG (MainThread) [pyatv.core.protocol] Sending periodic heartbeat 224 (AirPlay:10.0.20.22) 2023-01-28 12:58:59.849 DEBUG (MainThread) [pyatv.support.http] Sending RTSP/1.0 message: b'POST /feedback RTSP/1.0\r\nUser-Agent: AirPlay/540.31\r\nCSeq: 227\r\nDACP-ID: 418187C930517A38\r\nActive-Remote: 1398781041\r\nClient-Instance: 418187C930517A38\r\n\r\n' 2023-01-28 12:58:59.858 DEBUG (MainThread) [pyatv.support.http] Received: b'RTSP/1.0 200 OK\r\nDate: Sat, 28 Jan 2023 11:58:59 GMT\r\nContent-Length: 55\r\nContent-Type: application/x-apple-binary-plist\r\nServer: AirTunes/675.4.1\r\nCSeq: 227\r\n\r\nbplist00\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' 2023-01-28 12:58:59.859 DEBUG (MainThread) [pyatv.support.http] Got RTSP response: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'date': 'Sat, 28 Jan 2023 11:58:59 GMT', 'content-length': '55', 'content-type': 'application/x-apple-binary-plist', 'server': 'AirTunes/675.4.1', 'cseq': '227'}, 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'): 2023-01-28 12:58:59.859 DEBUG (MainThread) [pyatv.core.protocol] Got heartbeat 224 (AirPlay:10.0.20.22) 2023-01-28 12:59:01.620 ERROR (MainThread) [homeassistant.helpers.script.websocket_api_script] websocket_api script: Error executing script. Unexpected error for call_service at pos 1: Traceback (most recent call last): File "/usr/local/lib/python3.10/site-packages/pyatv/protocols/mrp/protocol.py", line 274, in _receive await semaphore.acquire() File "/usr/local/lib/python3.10/asyncio/locks.py", line 390, in acquire await fut asyncio.exceptions.CancelledError During handling of the above exception, another exception occurred: Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 451, in _async_step await getattr(self, handler)() File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 684, in _async_call_service_step await service_task File "/usr/src/homeassistant/homeassistant/core.py", line 1755, in async_call task.result() File "/usr/src/homeassistant/homeassistant/core.py", line 1792, in _execute_service await cast(Callable[[ServiceCall], Awaitable[None]], handler.job.target)( File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 213, in handle_service await service.entity_service_call( File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 678, in entity_service_call future.result() # pop exception if have File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 958, in async_request_call await coro File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 715, in _handle_entity_call await result File "/usr/src/homeassistant/homeassistant/components/apple_tv/remote.py", line 69, in async_send_command await attr_value() File "/usr/local/lib/python3.10/site-packages/pyatv/core/facade.py", line 150, in wakeup return await self.relay("wakeup")() File "/usr/local/lib/python3.10/site-packages/pyatv/protocols/mrp/init.py", line 419, in wakeup await _send_hid_key(self.protocol, "wakeup", InputAction.SingleTap) File "/usr/local/lib/python3.10/site-packages/pyatv/protocols/mrp/init.py", line 297, in _send_hid_key await _do_press(keycode, False) File "/usr/local/lib/python3.10/site-packages/pyatv/protocols/mrp/init.py", line 290, in _do_press await protocol.send_and_receive(messages.create(protobuf.GENERIC_MESSAGE)) File "/usr/local/lib/python3.10/site-packages/pyatv/protocols/mrp/protocol.py", line 261, in send_and_receive return await self._receive(identifier, timeout) File "/usr/local/lib/python3.10/site-packages/pyatv/protocols/mrp/protocol.py", line 273, in _receive async with async_timeout.timeout(timeout): 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 2023-01-28 12:59:01.622 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [140379200944352] Error handling message: Timeout (timeout) from 10.0.20.43 (Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36) 2023-01-28 12:59:01.860 DEBUG (MainThread) [pyatv.core.protocol] Sending periodic heartbeat 225 (AirPlay:10.0.20.22) 2023-01-28 12:59:01.860 DEBUG (MainThread) [pyatv.support.http] Sending RTSP/1.0 message: b'POST /feedback RTSP/1.0\r\nUser-Agent: AirPlay/540.31\r\nCSeq: 228\r\nDACP-ID: 418187C930517A38\r\nActive-Remote: 1398781041\r\nClient-Instance: 418187C930517A38\r\n\r\n' 2023-01-28 12:59:01.864 DEBUG (MainThread) [pyatv.support.http] Received: b'RTSP/1.0 200 OK\r\nDate: Sat, 28 Jan 2023 11:59:01 GMT\r\nContent-Length: 55\r\nContent-Type: application/x-apple-binary-plist\r\nServer: AirTunes/675.4.1\r\nCSeq: 228\r\n\r\nbplist00\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' 2023-01-28 12:59:01.864 DEBUG (MainThread) [pyatv.support.http] Got RTSP response: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'date': 'Sat, 28 Jan 2023 11:59:01 GMT', 'content-length': '55', 'content-type': 'application/x-apple-binary-plist', 'server': 'AirTunes/675.4.1', 'cseq': '228'}, 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'): 2023-01-28 12:59:01.864 DEBUG (MainThread) [pyatv.core.protocol] Got heartbeat 225 (AirPlay:10.0.20.22) 2023-01-28 12:59:03.865 DEBUG (MainThread) [pyatv.core.protocol] Sending periodic heartbeat 226 (AirPlay:10.0.20.22) 2023-01-28 12:59:03.865 DEBUG (MainThread) [pyatv.support.http] Sending RTSP/1.0 message: b'POST /feedback RTSP/1.0\r\nUser-Agent: AirPlay/540.31\r\nCSeq: 229\r\nDACP-ID: 418187C930517A38\r\nActive-Remote: 1398781041\r\nClient-Instance: 418187C930517A38\r\n\r\n' 2023-01-28 12:59:03.869 DEBUG (MainThread) [pyatv.support.http] Received: b'RTSP/1.0 200 OK\r\nDate: Sat, 28 Jan 2023 11:59:03 GMT\r\nContent-Length: 55\r\nContent-Type: application/x-apple-binary-plist\r\nServer: AirTunes/675.4.1\r\nCSeq: 229\r\n\r\nbplist00\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' 2023-01-28 12:59:03.869 DEBUG (MainThread) [pyatv.support.http] Got RTSP response: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'date': 'Sat, 28 Jan 2023 11:59:03 GMT', 'content-length': '55', 'content-type': 'application/x-apple-binary-plist', 'server': 'AirTunes/675.4.1', 'cseq': '229'}, 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'): 2023-01-28 12:59:03.869 DEBUG (MainThread) [pyatv.core.protocol] Got heartbeat 226 (AirPlay:10.0.20.22) 2023-01-28 12:59:05.870 DEBUG (MainThread) [pyatv.core.protocol] Sending periodic heartbeat 227 (AirPlay:10.0.20.22) 2023-01-28 12:59:05.870 DEBUG (MainThread) [pyatv.support.http] Sending RTSP/1.0 message: b'POST /feedback RTSP/1.0\r\nUser-Agent: AirPlay/540.31\r\nCSeq: 230\r\nDACP-ID: 418187C930517A38\r\nActive-Remote: 1398781041\r\nClient-Instance: 418187C930517A38\r\n\r\n' 2023-01-28 12:59:05.874 DEBUG (MainThread) [pyatv.support.http] Received: b'RTSP/1.0 200 OK\r\nDate: Sat, 28 Jan 2023 11:59:05 GMT\r\nContent-Length: 55\r\nContent-Type: application/x-apple-binary-plist\r\nServer: AirTunes/675.4.1\r\nCSeq: 230\r\n\r\nbplist00\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' 2023-01-28 12:59:05.874 DEBUG (MainThread) [pyatv.support.http] Got RTSP response: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'date': 'Sat, 28 Jan 2023 11:59:05 GMT', 'content-length': '55', 'content-type': 'application/x-apple-binary-plist', 'server': 'AirTunes/675.4.1', 'cseq': '230'}, 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'): 2023-01-28 12:59:05.874 DEBUG (MainThread) [pyatv.core.protocol] Got heartbeat 227 (AirPlay:10.0.20.22) 2023-01-28 12:59:07.875 DEBUG (MainThread) [pyatv.core.protocol] Sending periodic heartbeat 228 (AirPlay:10.0.20.22) 2023-01-28 12:59:07.875 DEBUG (MainThread) [pyatv.support.http] Sending RTSP/1.0 message: b'POST /feedback RTSP/1.0\r\nUser-Agent: AirPlay/540.31\r\nCSeq: 231\r\nDACP-ID: 418187C930517A38\r\nActive-Remote: 1398781041\r\nClient-Instance: 418187C930517A38\r\n\r\n' 2023-01-28 12:59:07.879 DEBUG (MainThread) [pyatv.support.http] Received: b'RTSP/1.0 200 OK\r\nDate: Sat, 28 Jan 2023 11:59:07 GMT\r\nContent-Length: 55\r\nContent-Type: application/x-apple-binary-plist\r\nServer: AirTunes/675.4.1\r\nCSeq: 231\r\n\r\nbplist00\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' 2023-01-28 12:59:07.879 DEBUG (MainThread) [pyatv.support.http] Got RTSP response: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'date': 'Sat, 28 Jan 2023 11:59:07 GMT', 'content-length': '55', 'content-type': 'application/x-apple-binary-plist', 'server': 'AirTunes/675.4.1', 'cseq': '231'}, 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'): 2023-01-28 12:59:07.879 DEBUG (MainThread) [pyatv.core.protocol] Got heartbeat 228 (AirPlay:10.0.20.22) 2023-01-28 12:59:09.880 DEBUG (MainThread) [pyatv.core.protocol] Sending periodic heartbeat 229 (AirPlay:10.0.20.22) 2023-01-28 12:59:09.880 DEBUG (MainThread) [pyatv.support.http] Sending RTSP/1.0 message: b'POST /feedback RTSP/1.0\r\nUser-Agent: AirPlay/540.31\r\nCSeq: 232\r\nDACP-ID: 418187C930517A38\r\nActive-Remote: 1398781041\r\nClient-Instance: 418187C930517A38\r\n\r\n' 2023-01-28 12:59:09.884 DEBUG (MainThread) [pyatv.support.http] Received: b'RTSP/1.0 200 OK\r\nDate: Sat, 28 Jan 2023 11:59:09 GMT\r\nContent-Length: 55\r\nContent-Type: application/x-apple-binary-plist\r\nServer: AirTunes/675.4.1\r\nCSeq: 232\r\n\r\nbplist00\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' 2023-01-28 12:59:09.884 DEBUG (MainThread) [pyatv.support.http] Got RTSP response: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'date': 'Sat, 28 Jan 2023 11:59:09 GMT', 'content-length': '55', 'content-type': 'application/x-apple-binary-plist', 'server': 'AirTunes/675.4.1', 'cseq': '232'}, 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'): 2023-01-28 12:59:09.884 DEBUG (MainThread) [pyatv.core.protocol] Got heartbeat 229 (AirPlay:10.0.20.22) 2023-01-28 12:59:11.886 DEBUG (MainThread) [pyatv.core.protocol] Sending periodic heartbeat 230 (AirPlay:10.0.20.22) 2023-01-28 12:59:11.886 DEBUG (MainThread) [pyatv.support.http] Sending RTSP/1.0 message: b'POST /feedback RTSP/1.0\r\nUser-Agent: AirPlay/540.31\r\nCSeq: 233\r\nDACP-ID: 418187C930517A38\r\nActive-Remote: 1398781041\r\nClient-Instance: 418187C930517A38\r\n\r\n'
When i disable the Apple remote entity in the UI and enable it again, everything functions for a short while.
When it works:
023-02-02 15:40:34.930 INFO (MainThread) [homeassistant.components.apple_tv.remote] Sending command wakeup 2023-02-02 15:40:34.931 DEBUG (MainThread) [pyatv.auth.hap_channel] Sending data (Encrypted=ce00e890147448bc91b210d9ee30111eb9522171c0ce8b7d5d0197a389acdadef3a610b9425a6c1661073fd63d35342e1da84e9a613337ec9488c992346cec76883208626e245a9d3679b2d4bad776217046986173a24cd6107914e8e33c2bd7dc62a2a9fb19b407b8d41c27a9715daff046a457e4cf159b457c2253cafe3f4d42dc3da033e437d5e7d429fe07bfba60ec015e7c822e66f969416c0e05a0592dbec155a276dd0480b6d3ff8027e2f45a5c890b3a605e5c39ab533c0324f0a2d697c58cf334b131f64a29d737876b88c85e26863557cf70f3d63c200f5f532f30) 2023-02-02 15:40:34.931 DEBUG (MainThread) [pyatv.protocols.airplay.mrp_connection] >> Send: Protobuf: type: SEND_HID_EVENT_MESSAGE errorCode: NoError [sendHIDEventMessage] { hidEventData: "C\211\"\317\010\002\000\000\000\000\000\000\000\000\000\000\001\000\000\000\000\000\000\000\002\000\000\000 \000\000\000\003\000\0... } uniqueIdentifier: "C1F7984F-723D-4566-B6B5-750BDE198495" 2023-02-02 15:40:34.931 DEBUG (MainThread) [pyatv.auth.hap_channel] Sending data (Encrypted=ce0067b884ae54d5d022d09f52ac6399a36fbcf176a1d55367458beec3f32f46d730f8b81b21e57ed7746c130997e030c31f2c72a53168feed0733f7f76ee6e8eff23cca3b603b3f125188ae132c99c88c838e0d2b1644ecc5429899a6bd00e5373bc2492054b5d24017e9c52fc1cc38d145f32e5c3b0ef74b194c3082cc5058ed45a75185f865482e0b04acf97063ddbdcc978aaac6e954fcd725075694fb3abf5834576c23770ba6a216ec6db1ee7bacbbb0ca74e6f3ceb291be20a4d69380880c53e88e59b662df9e12bc50d8d83dbddc7b15de5a3d2567c1c8472de57c32) errorCode: NoError [sendHIDEventMessage] { hidEventData: "C\211\"\317\010\002\000\000\000\000\000\000\000\000\000\000\001\000\000\000\000\000\000\000\002\000\000\000 \000\000\000\003\000\0... } uniqueIdentifier: "C8EEDA79-BE4B-4F14-B34A-4D1B83A8064E" 2023-02-02 15:40:34.932 DEBUG (MainThread) [pyatv.auth.hap_channel] Sending data (Encrypted=b400d7e749da84c1bba0752e5922501cc2dd7804e00ff25a10ef291a2ba46fc87d56411fbd58e819f6367679e3b02fd8a7808b1fe934a5ab86327af8ba91d7800fe4ad01c3f40296d0a23c4aae659464dcaa4b9a391e5ae80c94a671ef9c4ed32ba6346edc4010ef25853d7bdd70c32f1cfbff7ceacf09d44be90867e0acc4538642d7fb97e99aa6555b74389fc571261f92b2e4de78fc114cf3763b39d30ba9efff53d732517ea65336165339f29e641f402a38c3ce2fcd6bcfde3036c380c1af028f0f49f4) 2023-02-02 15:40:34.932 DEBUG (MainThread) [pyatv.protocols.airplay.mrp_connection] >> Send: Protobuf: type: GENERIC_MESSAGE identifier: "15DFE733-C267-420B-AA08-FBB7E2603665" errorCode: NoError uniqueIdentifier: "DA99FD69-83D3-4AC3-9D4E-7A06BE0ADBA7" 2023-02-02 15:40:34.935 DEBUG (MainThread) [pyatv.auth.hap_channel] Received data (Data=20000f2e7b8a38b216f751041dfb18e85b5af84354d472bedec7564b80191b9c51c84bab96c792f8815b258877e82972f5c72a00e5b38f9a65f584912bcf911e2e5ef1678580da9a281eb6938d089d7c10690656a0634087680b3ca0b72c466d4c641ae75fdd5856de840c1a9714200086f2e92860e30aab02429400ca9206a888438512e3697d158e328534aee34c7f1a0e8a370038e16337d7e5c9de51ee852a00e15717fd0bef5b40db985a55d4a70b447ed78b6e7d83a8a34b41a67432f1f82cecc4d450167a5d7cde023a8f2da2e99717a6a17fa537c3a11715) 2023-02-02 15:40:34.936 DEBUG (MainThread) [pyatv.auth.hap_channel] Received data (Data=2000b3b1baaf928b98dd9affb6b63e21045a111b33fbe1e43c998730171c037af0e49fd32b3eacffedec214e52fb9077682d2a00ccc3f1857f7a5841e84a2cae4873fe5fad4872ad46addd535baee0c259a70e2a492a07b5d322a7eacec9f044bd530b1c3a031346f1ebc4bc2890) 2023-02-02 15:40:35.037 DEBUG (MainThread) [pyatv.auth.hap_channel] Received data (Data=2000d0a0bedadd8acf42da776af6cac6035154be7b4378626c4ce6ed4ac84901016a052bd705bd2a02978894fbb462af28dd920046f3d2e1cbc051b21cd884219f3b568c57511f17fcb9cf18e8d2bc18036d51384886252b1b86cf672a00bdf180a92cc2b82ca417cb9544cabfc8db43c6f30561e7a3bf9eb5f2c45455f2c3ab82b607236fdbd4fddedb2163b2769dd192fd37f91f67414a340ea2b9281770041ebc3eff63d20ed80c6a2c7cd241f0aaaddc3c5d6f887b8c444faded66c22046e690d376bbe18989229b40eb89ab0130898a25fef901) 2023-02-02 15:40:35.041 DEBUG (MainThread) [pyatv.protocols.airplay.mrp_connection] << Receive: Protobuf: type: UNKNOWN_MESSAGE identifier: "15DFE733-C267-420B-AA08-FBB7E2603665" uniqueIdentifier: "B9E097D4-BC59-4A91-A2F6-CD89AB9C17A5" 2023-02-02 15:40:35.043 DEBUG (MainThread) [pyatv.auth.hap_channel] Sending data (Encrypted=20009e36e1246b2b02c4fcbcb427736258257a8aff91ef451615b67a2d6c2984bf474b8a54b3d22d7bce75d2e63a47ee7d3f) 2023-02-02 15:40:35.684 DEBUG (MainThread) [pyatv.core.protocol] Sending periodic heartbeat 3 (AirPlay:10.0.20.22) 2023-02-02 15:40:35.684 DEBUG (MainThread) [pyatv.support.http] Sending RTSP/1.0 message: b'POST /feedback RTSP/1.0\r\nUser-Agent: AirPlay/540.31\r\nCSeq: 6\r\nDACP-ID: 39306920BD21DD31\r\nActive-Remote: 1125296697\r\nClient-Instance: 39306920BD21DD31\r\n\r\n' 2023-02-02 15:40:35.784 DEBUG (MainThread) [pyatv.support.http] Received: b'RTSP/1.0 200 OK\r\nDate: Thu, 02 Feb 2023 14:40:35 GMT\r\nContent-Length: 55\r\nContent-Type: application/x-apple-binary-plist\r\nServer: AirTunes/675.4.1\r\nCSeq: 6\r\n\r\nbplist00\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' 2023-02-02 15:40:35.786 DEBUG (MainThread) [pyatv.support.http] Got RTSP response: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'date': 'Thu, 02 Feb 2023 14:40:35 GMT', 'content-length': '55', 'content-type': 'application/x-apple-binary-plist', 'server': 'AirTunes/675.4.1', 'cseq': '6'}, 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'): 2023-02-02 15:40:35.786 DEBUG (MainThread) [pyatv.core.protocol] Got heartbeat 3 (AirPlay:10.0.20.22) 2023-02-02 15:40:37.118 DEBUG (MainThread) [pyatv.auth.hap_channel] Received data (Data=2000c5fe547af9cb695fbe1b18bbe9d2d920fe70699672c2854d81b62e375d0ddeac488c15bd2c7e2705b73209828c08905a85043f94b4b5c660bc83af1fb6ac9d1e0ed04057bb2a0efe121b878e0e2c49bf143b84c635c8ad2a2e6e883072038d46e3d9658ca60474a4fa66105fa039c3bf73b33639215865d54391ac7f8cf4cc7afbe48abce1fe07558f212838d39751ff9e5a14492daea4d32fa6b51024b17b93f6a998852c5b9f7fe51191fac63785655b3516260b4424d4d06d513bc31b65e8ae65656a0f13eb12af376dc3c41d58dc4efd866da1faf080a2dfbd16ae6717aff60142456035c8c116a31da88fe52fd27b4c63efeb860416c68a7d8c2...) 2023-02-02 15:40:37.124 DEBUG (MainThread) [pyatv.protocols.airplay.mrp_connection] << Receive: Protobuf: type: UPDATE_OUTPUT_DEVICEMESSAGE [updateOutputDeviceMessage] { outputDevices { name: "ATV" uniqueIdentifier: "5FA7BD29-64A7-4655-BBCF-A4847965463A" canAccessRemoteAssets: false isRemoteControllable: false isGroupLeader: false isGroupable: true deviceType: Wired deviceSubType: HDMI modelSpecificInfoData: "bplist00\324\001\002\003\004\005\006\007\nX$versionY$archiverT$topX$objects\022\000\001\206\240\020\017NSKeyedArchiver... isLocalDevice: false supportsExternalScreen: false requiresAuthorization: true sourceInfo { routingContextUID: "577E1BCA-2D9B-41C2-A8F8-C515CE8072D4" multipleBuiltInDevices: false } isDeviceGroupable: true canRelayCommunicationChannel: false isProxyGroupPlayer: false canAccessAppleMusic: false canAccessiCloudMusicLibrary: false groupContainsGroupLeader: false supportsBufferedAirPlay: false canPlayEncryptedProgressiveDownloadAssets: true canFetchMediaDataFromSender: true resentsOptimizedUserInterfaceWhenPlayingFetchedAudioOnlyAssets: true isAirPlayReceiverSessionActive: false parentGroupContainsDiscoverableLeader: false isAddedToHomeKit: false supportsHAP: false usingJSONProtocol: false clusterType: 0 primaryUID: "5FA7BD29-64A7-4655-BBCF-A4847965463A" configuredClusterSize: 0 producesLowFidelityAudio: false 45: 0 47: "AVOutputDeviceBluetoothListeningModeNormal" 48: 0 50: 18446744073709551615 52: 1 56: 1 57: 1 59: 0 60: 0 } clusterAwareOutputDevices { name: "ATV" uniqueIdentifier: "5FA7BD29-64A7-4655-BBCF-A4847965463A" canAccessRemoteAssets: false isRemoteControllable: false isGroupLeader: false isGroupable: true deviceType: Wired deviceSubType: HDMI modelSpecificInfoData: "bplist00\324\001\002\003\004\005\006\007\nX$versionY$archiverT$topX$objects\022\000\001\206\240_\020\017NSKeyedArchiver... isLocalDevice: false supportsExternalScreen: false requiresAuthorization: true sourceInfo { routingContextUID: "577E1BCA-2D9B-41C2-A8F8-C515CE8072D4" multipleBuiltInDevices: false } isDeviceGroupable: true canRelayCommunicationChannel: false isProxyGroupPlayer: false canAccessAppleMusic: false canAccessiCloudMusicLibrary: false groupContainsGroupLeader: false supportsBufferedAirPlay: false canPlayEncryptedProgressiveDownloadAssets: true canFetchMediaDataFromSender: true resentsOptimizedUserInterfaceWhenPlayingFetchedAudioOnlyAssets: true isAirPlayReceiverSessionActive: false parentGroupContainsDiscoverableLeader: false isAddedToHomeKit: false supportsHAP: false usingJSONProtocol: false clusterType: 0 primaryUID: "5FA7BD29-64A7-4655-BBCF-A4847965463A" configuredClusterSize: 0 producesLowFidelityAudio: false 45: 0 47: "AVOutputDeviceBluetoothListeningModeNormal" 48: 0 50: 18446744073709551615 52: 1 56: 1 57: 1 59: 0 60: 0 } } 3c77e4ef16e49492975163813565e4c3d512cd5319b1a78d379bb8bc88f525adc95ed8a13f8d085396193ca929ee1ddc2ec6a076a2e6e43d213631c2261e9815cfb808cc27e828883bd9057e451e69a4a655ce563442f42af9ef852ecac13a506ee37a16eb2f90660ae57a6bfcf351aac3421a232358a9ac7dd664b33235e66c84e9d45e2fa18769821164e160623c5b27be655b389e4e9b9a90e0e85764f14a86a8b05c5482261ef639c938bf65b2014f904ea2075f802d46f5362d3d6d9c15bf531bc348eb29223649a1f11edd781e2417f6aeb5d44a029ad) 2023-02-02 15:40:47.620 DEBUG (MainThread) [pyatv.protocols.airplay.mrp_connection] >> Send: Protobuf: type: SEND_HID_EVENT_MESSAGE errorCode: NoError
This is an ongoing issue. Constant disconnects and errors coming from this integration even with "Allow Access: Everyone" selected.
So I've been looking at the logs off and on with this one and I'm not sure if this is helpful but I seem to get consistent disconnects on Heartbeat 12 & 13. Then the connection is dropped, and restarted.
Sort of a strange pattern happening over and over again so I figured I would share it.
@postlund I know you are busy, but maybe this could help? Let me know if there's a better way I could help with debugging this or where to send you a coffee or other beverage!
2023-04-05 22:24:49.735 DEBUG (MainThread) [pyatv.core.protocol] Heartbeat 12 failed (AirPlay:192.168.7.248)
2023-04-05 22:24:49.735 DEBUG (MainThread) [pyatv.core.protocol] Sending periodic heartbeat 13 (AirPlay:192.168.7.248)
2023-04-05 22:24:49.735 DEBUG (MainThread) [pyatv.support.http] Sending RTSP/1.0 message: b'POST /feedback RTSP/1.0\r\nUser-Agent: AirPlay/540.31\r\nCSeq: 16\r\nDACP-ID: 2777424C6A45190B\r\nActive-Remote: 1368943563\r\nClient-Instance: 2777424C6A45190B\r\n\r\n'
2023-04-05 22:24:53.738 DEBUG (MainThread) [pyatv.core.protocol] Heartbeat 13 failed after 2 tries (AirPlay:192.168.7.248)
2023-04-05 22:24:53.738 DEBUG (MainThread) [pyatv.protocols.airplay.mrp_connection] Closing connection
2023-04-05 22:24:53.739 WARNING (MainThread) [homeassistant.components.apple_tv] Connection lost to Apple TV "Basement Theatre Apple TV"
For me the fix was 2023.2, although this really doesn't apply anymore as when this issue first arose and it didn't work I immediately returned them and bought Chromecast Google TVs
Wish that was the case but still seeing this on 2023.4
@postlund @michalmo I've seen a lot of recent py-atv code activity 👏👏. Wanted to see if these disconnect / reconnect / discovery issues are on your radar and if I could help by logging issues on the pyatv repo with recent repro steps?
Thanks!
Unfortunately I haven't seen any issues with connectivity. Even while developing, running multiple concurrent connections, or even sending bad data over the connections, the Home Assistant pyatv connections to all devices stay stable over many days.
Understood. Alright. Let me try to do a bit more digging.
If there is a particular type of info that would be helpful please let me know.
I have seen this a few times in the past, but extremely rare. If it could be reproduced easily it would be easier to debug.
There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates. Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍 This issue has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.
The problem
I experience problems since I updated my Apple TV to the latest version (16.2 , 20K362) on my HA instance 2022.12.7. I tried to turn on and off Apple TV and got the below error message. It seems that something is not working anymore and I think its due to the update of Apple TV OS. I am not an expert and try to deliver as much information as I can. Nor a restart of HA or Apple TV helped.
What version of Home Assistant Core has the issue?
Home Assistant 2022.12.7
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
websocket_api, apple tv
Link to integration documentation on our website
No response
Diagnostics information
home-assistant_apple_tv_2022-12-20T12-20-17.220Z.log
Example YAML snippet
No response
Anything in the logs that might be useful for us?
Additional information
Dieser Fehler wurde von einer benutzerdefinierten Integration verursacht
Logger: custom_components.apple_tv Source: custom_components/apple_tv/init.py:166 Integration: Apple TV First occurred: 12:37:36 (13 occurrences) Last logged: 13:16:43
Connection lost to Apple TV "Apple TV 4K"
Dieser Fehler wurde von einer benutzerdefinierten Integration verursacht
Logger: custom_components.apple_tv.media_player Source: custom_components/apple_tv/media_player.py:159 Integration: Apple TV First occurred: 13:16:48 (1 occurrences) Last logged: 13:16:48
Failed to update app list 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/api.py", line 139, in _send_command resp = await self._protocol.exchange_opack( File "/usr/local/lib/python3.10/site-packages/pyatv/protocols/companion/protocol.py", line 157, in exchange_opack 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 "/config/custom_components/apple_tv/media_player.py", line 159, in _update_app_list apps = await self.atv.apps.app_list() File "/usr/local/lib/python3.10/site-packages/pyatv/core/facade.py", line 395, in app_list return await self.relay("app_list")() File "/usr/local/lib/python3.10/site-packages/pyatv/protocols/companion/init.py", line 166, in app_list app_list = await self.api.app_list() File "/usr/local/lib/python3.10/site-packages/pyatv/protocols/companion/api.py", line 230, in app_list return await self._send_command("FetchLaunchableApplicationsEvent", {}) File "/usr/local/lib/python3.10/site-packages/pyatv/protocols/companion/api.py", line 150, in _send_command raise exceptions.ProtocolError(f"Command {identifier} failed") from ex pyatv.exceptions.ProtocolError: Command FetchLaunchableApplicationsEvent failed