Homekit Controller pairing of tado doesn't work after upgrading to Python 3.11

cf00 commented 1 year ago

The problem

With the release of 2023.3.0, I upgraded my installation (Home Assistant Core on Fedora 37) to Python 3.11.2 w/o problems (also after upgrading to 2023.3.1).

I am controlling my tado system via Homekit Controller, and while it still worked initially after the upgrade, it stopped working after the tado bridge lost power for a few minutes. I decided to remove the bridge and to pair it again, which resulted in time out errors shown in the logs. Several attempts to reset the bridge and pair it again were unsuccessful with the same errors.

My other homekit device (a Sony TV) continued to work w/o problem.

Downgrading to Python 3.10.10 resolved the problem and I could pair it on the first try.

What version of Home Assistant Core has the issue?

2023.3.2

What was the last working version of Home Assistant Core?

No response

What type of installation are you running?

Home Assistant Core

Integration causing the issue

Homekit Controller

Link to integration documentation on our website

https://www.home-assistant.io/integrations/homekit_controller/

Diagnostics information

No response

Example YAML snippet

No response

Anything in the logs that might be useful for us?

2023-03-09 16:15:57.809 DEBUG (MainThread) [homeassistant.components.homekit_controller.config_flow] Discovered device tado Internet Bridge IBXXXXXXXXX (tado Internet Bridge - yy:yy:yy:yy:yy:yy)
2023-03-09 16:15:59.924 DEBUG (MainThread) [aiohomekit.controller.ble.controller] Discovery for hkid yy:yy:yy:yy:yy:yy not found, waiting for advertisement with timeout: 30.0
2023-03-09 16:15:59.925 DEBUG (MainThread) [aiohomekit.controller.ip.connection] Starting reconnect loop to 10.6.6.112:80
2023-03-09 16:15:59.925 DEBUG (MainThread) [aiohomekit.controller.ip.connection] Attempting connection to 10.6.6.112:80
2023-03-09 16:15:59.931 DEBUG (MainThread) [aiohomekit.protocol] #1 ios -> accessory: send SRP start request
2023-03-09 16:15:59.931 DEBUG (MainThread) [aiohomekit.protocol.tlv] sending [
  6 (State): (1 bytes/<class 'bytearray'>) 0x01
  0 (Method): (1 bytes/<class 'bytearray'>) 0x01
]

2023-03-09 16:15:59.931 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 10.6.6.112: raw request: b'POST /pair-setup HTTP/1.1\r\nHost: 10.6.6.112\r\nContent-Length: 6\r\nContent-Type: HttpContentTypes.TLV\r\n\r\n\x06\x01\x01\x00\x01\x01'
2023-03-09 16:16:29.932 ERROR (MainThread) [homeassistant.components.homekit_controller.config_flow] Pairing attempt failed with an unhandled exception
Traceback (most recent call last):
  File "/opt/ha/lib64/python3.11/site-packages/aiohomekit/controller/ip/connection.py", line 81, in send_bytes
    return await result
           ^^^^^^^^^^^^
asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/ha/lib64/python3.11/site-packages/aiohomekit/controller/ip/connection.py", line 80, in send_bytes
    async with asyncio_timeout(30):
  File "/usr/lib64/python3.11/asyncio/timeouts.py", line 98, in __aexit__
    raise TimeoutError
TimeoutError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/ha/lib64/python3.11/site-packages/homeassistant/components/homekit_controller/config_flow.py", line 492, in async_step_pair
    self.finish_pairing = await discovery.async_start_pairing(self.hkid)
                          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/ha/lib64/python3.11/site-packages/aiohomekit/controller/ip/discovery.py", line 62, in async_start_pairing
    response = await self.connection.post_tlv(
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/ha/lib64/python3.11/site-packages/aiohomekit/controller/ip/connection.py", line 391, in post_tlv
    response = await self.post(
               ^^^^^^^^^^^^^^^^
  File "/opt/ha/lib64/python3.11/site-packages/aiohomekit/controller/ip/connection.py", line 355, in post
    return await self.request(
           ^^^^^^^^^^^^^^^^^^^
  File "/opt/ha/lib64/python3.11/site-packages/aiohomekit/controller/ip/connection.py", line 450, in request
    resp = await self.protocol.send_bytes(request_bytes)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/ha/lib64/python3.11/site-packages/aiohomekit/controller/ip/connection.py", line 85, in send_bytes
    raise AccessoryDisconnectedError("Timeout while waiting for response")
aiohomekit.exceptions.AccessoryDisconnectedError: Timeout while waiting for response
2023-03-09 16:16:29.934 DEBUG (MainThread) [aiohomekit.controller.ip.connection] Connection HomeKitConnection(host='10.6.6.112', port=80) lost.
2023-03-09 16:16:39.301 DEBUG (MainThread) [aiohomekit.controller.ble.controller] Discovery for hkid yy:yy:yy:yy:yy:yy not found, waiting for advertisement with timeout: 30.0
2023-03-09 16:16:39.301 DEBUG (MainThread) [aiohomekit.controller.ip.connection] Starting reconnect loop to 10.6.6.112:80
2023-03-09 16:16:39.301 DEBUG (MainThread) [aiohomekit.controller.ip.connection] Attempting connection to 10.6.6.112:80
2023-03-09 16:16:39.305 DEBUG (MainThread) [aiohomekit.protocol] #1 ios -> accessory: send SRP start request
2023-03-09 16:16:39.305 DEBUG (MainThread) [aiohomekit.protocol.tlv] sending [
  6 (State): (1 bytes/<class 'bytearray'>) 0x01
  0 (Method): (1 bytes/<class 'bytearray'>) 0x01
]

2023-03-09 16:16:39.306 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 10.6.6.112: raw request: b'POST /pair-setup HTTP/1.1\r\nHost: 10.6.6.112\r\nContent-Length: 6\r\nContent-Type: HttpContentTypes.TLV\r\n\r\n\x06\x01\x01\x00\x01\x01'
2023-03-09 16:17:09.306 ERROR (MainThread) [homeassistant.components.homekit_controller.config_flow] Pairing attempt failed with an unhandled exception
Traceback (most recent call last):
  File "/opt/ha/lib64/python3.11/site-packages/aiohomekit/controller/ip/connection.py", line 81, in send_bytes
    return await result
           ^^^^^^^^^^^^
asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/ha/lib64/python3.11/site-packages/aiohomekit/controller/ip/connection.py", line 80, in send_bytes
    async with asyncio_timeout(30):
  File "/usr/lib64/python3.11/asyncio/timeouts.py", line 98, in __aexit__
    raise TimeoutError
TimeoutError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/ha/lib64/python3.11/site-packages/homeassistant/components/homekit_controller/config_flow.py", line 492, in async_step_pair
    self.finish_pairing = await discovery.async_start_pairing(self.hkid)
                          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/ha/lib64/python3.11/site-packages/aiohomekit/controller/ip/discovery.py", line 62, in async_start_pairing
    response = await self.connection.post_tlv(
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/ha/lib64/python3.11/site-packages/aiohomekit/controller/ip/connection.py", line 391, in post_tlv
    response = await self.post(
               ^^^^^^^^^^^^^^^^
  File "/opt/ha/lib64/python3.11/site-packages/aiohomekit/controller/ip/connection.py", line 355, in post
    return await self.request(
           ^^^^^^^^^^^^^^^^^^^
  File "/opt/ha/lib64/python3.11/site-packages/aiohomekit/controller/ip/connection.py", line 450, in request
    resp = await self.protocol.send_bytes(request_bytes)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/ha/lib64/python3.11/site-packages/aiohomekit/controller/ip/connection.py", line 85, in send_bytes
    raise AccessoryDisconnectedError("Timeout while waiting for response")
aiohomekit.exceptions.AccessoryDisconnectedError: Timeout while waiting for response
2023-03-09 16:17:09.308 DEBUG (MainThread) [aiohomekit.controller.ip.connection] Connection HomeKitConnection(host='10.6.6.112', port=80) lost.

Additional information

No response

home-assistant[bot] commented 1 year ago

Hey there @jc2k, @bdraco, mind taking a look at this issue as it has been labeled with an integration (homekit_controller) you are listed as a code owner for? Thanks!

Code owner commands

Code owners of `homekit_controller` can trigger bot actions by commenting: - `@home-assistant close` Closes the issue. - `@home-assistant rename Awesome new title` Renames the issue. - `@home-assistant reopen` Reopen the issue. - `@home-assistant unassign homekit_controller` Removes the current integration label and assignees on the issue, add the integration domain after the command.

_{^{(message by CodeOwnersMention)}}

homekit_controller documentation homekit_controller source _{^{(message by IssueLinks)}}

diplix commented 1 year ago

same happend to me onHA core 2023.3.5 after restarting the tado bridge, homekit controller could not connect to the tado bridge. Setup erneut versuchen: Timeout while waiting for connection to device 192.168.1.78:80 downgrading to python 3.10 resolved the issue for me, too. i’m pretty sure if i switched, python 3.11 would again be able to connect to the tado bridge until the network connection is severed or the tado bridge is restarted.

cf00 commented 1 year ago

I just tried it again with 2023.4.0b4, and homekit_controller is still incompatible with Python 3.11. @Jc2k could you maybe take a look at the issue? Thanks.

issue-triage-workflows[bot] commented 1 year ago

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.

home-assistant / core