HomeKit integration occasionally has stale accessory state since 2022.11.x

jfroy commented 1 year ago

The problem

With 2022.11.x, the HomeKit integration feels somewhat less reliable. Specifically, accessory state is sometimes stale. Switching to a different view in the Home app or re-opening the Home app usually updates the state. I do not remember this behavior with 2022.10.x. Nothing has changed on my network (no hardware, software, or configuration change).

I bridge a mix of accessories via the HomeKit integration, including Z-Wave devices (deadbolts, scene controllers, light switches, LED strip controllers, sensors), HomeKit Bridge devices (light switches). I use a YAML configuration for my main bridge integration in order to associate battery sensors with some of the bridged accessories.

Home Assistant 2022.11.2 Supervisor 2022.10.2 Operating System 9.3 Frontend 20221108.0 - latest

What version of Home Assistant Core has the issue?

2022.11.2

What was the last working version of Home Assistant Core?

2022.10

What type of installation are you running?

Home Assistant OS

Integration causing the issue

HomeKit

Link to integration documentation on our website

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

Diagnostics information

No response

Example YAML snippet

No response

Anything in the logs that might be useful for us?

No response

Additional information

No response

home-assistant[bot] commented 1 year ago

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

Code owner commands

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

_{^{(message by CodeOwnersMention)}}

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

jfroy commented 1 year ago

This may be particularly bad with Eve light switches (the new US model using Thread). There is pretty immediate state desync even within Home Assistant.

jfroy commented 1 year ago

It may be more buffering than dropped requests. I've just been futzing with a particular light, turning it on and off in Apple Home (on an iPhone), and at some point it stopped responding, only to actuate my sequence of on-off's a couple of seconds later in rapid succession. I don't know if the buffering is happening in the integration, in HASS (core or OS), in the border router (AppleTV 4K first gen), or the Thread network.

jfroy commented 1 year ago

Maybe some relevant logs.

Logger: aiohomekit.controller.coap.connection
Source: components/homekit_controller/connection.py:711
First occurred: 18:30:22 (6 occurrences)
Last logged: 19:11:06

CoAP POST returned unexpected code <aiocoap.Message at 0x7f5e5b6c20: Type.ACK 4.04 Not Found (MID 6897, token a4c4) remote <UDP6EndpointAddress [fdbc:107:de33:0:14e:8a26:b28d:a0f9] (locally fd00::4:19ed:32e9:7dad:37b8%eth0)>>
Decryption failed, desynchronized? Counter=54/55
Failed flailing attempts to resynchronize, self-destructing in 3, 2, 1...
Pair verify timed out
Decryption failed, desynchronized? Counter=68/70

fdbc:107:de33:0:14e:8a26:b28d:a0f9 is the address of the Eve light I was playing with.

Also these logs around turn_on service calls:

Logger: homeassistant.core
Source: components/homekit_controller/connection.py:711
First occurred: 19:11:05 (1 occurrences)
Last logged: 19:11:05

Error executing service: <ServiceCall switch.turn_on (c:01GHMX31CZ19B3622P9GMWEJMP): entity_id=['switch.hallway_lights']>
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/aiohomekit/controller/coap/connection.py", line 167, in post_bytes
    response = await asyncio.wait_for(
  File "/usr/local/lib/python3.10/asyncio/tasks.py", line 458, in wait_for
    raise exceptions.TimeoutError() from exc
asyncio.exceptions.TimeoutError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/core.py", line 1762, in catch_exceptions
    await coro_or_task
  File "/usr/src/homeassistant/homeassistant/core.py", line 1781, in _execute_service
    await cast(Callable[[ServiceCall], Awaitable[None]], handler.job.target)(
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 208, 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/homekit_controller/switch.py", line 78, in async_turn_on
    await self.async_put_characteristics({CharacteristicsTypes.ON: True})
  File "/usr/src/homeassistant/homeassistant/components/homekit_controller/entity.py", line 91, in async_put_characteristics
    return await self._accessory.put_characteristics(payload)
  File "/usr/src/homeassistant/homeassistant/components/homekit_controller/connection.py", line 711, in put_characteristics
    results = await self.pairing.put_characteristics(characteristics)
  File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/coap/pairing.py", line 203, in put_characteristics
    return await self.connection.write_characteristics(characteristics)
  File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/coap/connection.py", line 559, in write_characteristics
    pdu_results = await self.enc_ctx.post_all(
  File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/coap/connection.py", line 190, in post_all
    res_pdu = await self.post_bytes(req_pdu)
  File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/coap/connection.py", line 171, in post_bytes
    raise AccessoryDisconnectedError("Request timeout")
aiohomekit.exceptions.AccessoryDisconnectedError: Request timeout

Logger: homeassistant.core
Source: components/homekit_controller/connection.py:711
First occurred: 18:30:44 (2 occurrences)
Last logged: 18:30:54

Error executing service: <ServiceCall light.turn_off (c:01GHMTSKVZW24EK2E6R7T7BCCK): entity_id=['light.hallway_lights'], params=>
Error executing service: <ServiceCall light.turn_off (c:01GHMTSRM6CYPN43AJT6EK2JYC): entity_id=['light.hallway_lights'], params=>
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/core.py", line 1762, in catch_exceptions
    await coro_or_task
  File "/usr/src/homeassistant/homeassistant/core.py", line 1781, in _execute_service
    await cast(Callable[[ServiceCall], Awaitable[None]], handler.job.target)(
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 208, 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/light/__init__.py", line 581, in async_handle_light_off_service
    await light.async_turn_off(**filter_turn_off_params(light, params))
  File "/usr/src/homeassistant/homeassistant/components/switch_as_x/entity.py", line 90, in async_turn_off
    await self.hass.services.async_call(
  File "/usr/src/homeassistant/homeassistant/core.py", line 1744, in async_call
    task.result()
  File "/usr/src/homeassistant/homeassistant/core.py", line 1781, in _execute_service
    await cast(Callable[[ServiceCall], Awaitable[None]], handler.job.target)(
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 208, 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/homekit_controller/switch.py", line 82, in async_turn_off
    await self.async_put_characteristics({CharacteristicsTypes.ON: False})
  File "/usr/src/homeassistant/homeassistant/components/homekit_controller/entity.py", line 91, in async_put_characteristics
    return await self._accessory.put_characteristics(payload)
  File "/usr/src/homeassistant/homeassistant/components/homekit_controller/connection.py", line 711, in put_characteristics
    results = await self.pairing.put_characteristics(characteristics)
  File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/coap/pairing.py", line 202, in put_characteristics
    await self._ensure_connected()
  File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/coap/pairing.py", line 97, in _ensure_connected
    raise AccessoryDisconnectedError(
aiohomekit.exceptions.AccessoryDisconnectedError: primary coroutine failed to connect

Logger: homeassistant.core
Source: components/homekit_controller/connection.py:711
First occurred: 18:30:44 (2 occurrences)
Last logged: 18:30:54

Error executing service: <ServiceCall light.turn_on (c:01GHMTSCQMY5Z9F9PB644Z29XB): entity_id=['light.hallway_lights'], params=>
Error executing service: <ServiceCall light.turn_on (c:01GHMTSPN3H6B0CM7EGKWRKZZP): entity_id=['light.hallway_lights'], params=>
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/aiohomekit/controller/coap/connection.py", line 386, in connect
    await self.do_pair_verify(pairing_data)
  File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/coap/connection.py", line 345, in do_pair_verify
    response = await asyncio.wait_for(
  File "/usr/local/lib/python3.10/asyncio/tasks.py", line 458, in wait_for
    raise exceptions.TimeoutError() from exc
asyncio.exceptions.TimeoutError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/coap/pairing.py", line 105, in _ensure_connected
    await self.connection_future
  File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/coap/connection.py", line 389, in connect
    raise AccessoryDisconnectedError("Pair verify timed out")
aiohomekit.exceptions.AccessoryDisconnectedError: Pair verify timed out

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/core.py", line 1762, in catch_exceptions
    await coro_or_task
  File "/usr/src/homeassistant/homeassistant/core.py", line 1781, in _execute_service
    await cast(Callable[[ServiceCall], Awaitable[None]], handler.job.target)(
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 208, 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/light/__init__.py", line 570, in async_handle_light_on_service
    await light.async_turn_on(**filter_turn_on_params(light, params))
  File "/usr/src/homeassistant/homeassistant/components/switch_as_x/entity.py", line 80, in async_turn_on
    await self.hass.services.async_call(
  File "/usr/src/homeassistant/homeassistant/core.py", line 1744, in async_call
    task.result()
  File "/usr/src/homeassistant/homeassistant/core.py", line 1781, in _execute_service
    await cast(Callable[[ServiceCall], Awaitable[None]], handler.job.target)(
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 208, 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/homekit_controller/switch.py", line 78, in async_turn_on
    await self.async_put_characteristics({CharacteristicsTypes.ON: True})
  File "/usr/src/homeassistant/homeassistant/components/homekit_controller/entity.py", line 91, in async_put_characteristics
    return await self._accessory.put_characteristics(payload)
  File "/usr/src/homeassistant/homeassistant/components/homekit_controller/connection.py", line 711, in put_characteristics
    results = await self.pairing.put_characteristics(characteristics)
  File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/coap/pairing.py", line 202, in put_characteristics
    await self._ensure_connected()
  File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/coap/pairing.py", line 107, in _ensure_connected
    raise AccessoryDisconnectedError("failed to connect")
aiohomekit.exceptions.AccessoryDisconnectedError: failed to connect

And one more, this time for a turn_off service call.

Logger: homeassistant.core
Source: components/homekit_controller/connection.py:711
First occurred: 18:30:22 (1 occurrences)
Last logged: 18:30:22

Error executing service: <ServiceCall light.turn_off (c:01GHMTRYK176EBQKKJ03KE7P0D): entity_id=['light.hallway_lights'], params=>
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/coap/connection.py", line 117, in _decrypt_response
    return self.decrypt(response.payload)
  File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/coap/connection.py", line 94, in decrypt
    dec_data = self.recv_ctx.decrypt(
  File "/usr/local/lib/python3.10/site-packages/cryptography/hazmat/primitives/ciphers/aead.py", line 62, in decrypt
    return aead._decrypt(backend, self, nonce, data, [associated_data], 16)
  File "/usr/local/lib/python3.10/site-packages/cryptography/hazmat/backends/openssl/aead.py", line 207, in _decrypt
    raise InvalidTag
cryptography.exceptions.InvalidTag

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/core.py", line 1762, in catch_exceptions
    await coro_or_task
  File "/usr/src/homeassistant/homeassistant/core.py", line 1781, in _execute_service
    await cast(Callable[[ServiceCall], Awaitable[None]], handler.job.target)(
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 208, 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/light/__init__.py", line 581, in async_handle_light_off_service
    await light.async_turn_off(**filter_turn_off_params(light, params))
  File "/usr/src/homeassistant/homeassistant/components/switch_as_x/entity.py", line 90, in async_turn_off
    await self.hass.services.async_call(
  File "/usr/src/homeassistant/homeassistant/core.py", line 1744, in async_call
    task.result()
  File "/usr/src/homeassistant/homeassistant/core.py", line 1781, in _execute_service
    await cast(Callable[[ServiceCall], Awaitable[None]], handler.job.target)(
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 208, 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/homekit_controller/switch.py", line 82, in async_turn_off
    await self.async_put_characteristics({CharacteristicsTypes.ON: False})
  File "/usr/src/homeassistant/homeassistant/components/homekit_controller/entity.py", line 91, in async_put_characteristics
    return await self._accessory.put_characteristics(payload)
  File "/usr/src/homeassistant/homeassistant/components/homekit_controller/connection.py", line 711, in put_characteristics
    results = await self.pairing.put_characteristics(characteristics)
  File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/coap/pairing.py", line 203, in put_characteristics
    return await self.connection.write_characteristics(characteristics)
  File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/coap/connection.py", line 559, in write_characteristics
    pdu_results = await self.enc_ctx.post_all(
  File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/coap/connection.py", line 190, in post_all
    res_pdu = await self.post_bytes(req_pdu)
  File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/coap/connection.py", line 176, in post_bytes
    return await self._decrypt_response(response)
  File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/coap/connection.py", line 159, in _decrypt_response
    raise EncryptionError("Decryption of PDU POST response failed")
aiohomekit.exceptions.EncryptionError: Decryption of PDU POST response failed

They all kind of suggest the connectivity is problematic to the light switch. However, using the switch natively paired to Apple Home (via the Apple Home app or the Eve app) works flawlessly.

It's... rather difficult to debug the Thread network created by Apple Home right now. Maybe the iOS API to get the network's commissioning credentials could be used to build a debug tool, but there's nothing off the shelf that I know of.

jfroy commented 1 year ago

I've made a mess of this issue. The desync / late sync issue happens for all sorts of devices (for example zwave lights in another room). The issues with the Eve light switch is compounded by Thread/coap problems.

jfroy commented 1 year ago

I suppose I should mention all my Apple devices are running the latest public stable release (so iOS 16.1.1, equivalent ATV version, and latest Ventura on macOS). It's quite possible these is an issue on Apple's side, and maybe I can devise a test methodology to discern that.

iEddy1985 commented 1 year ago

Having problems too... I can switch lights within home assistant but not in Homekit. The problem occurred with the update from 10.5 to 11.1. After restoring 10.5 it worked again...

Logger: homeassistant Source: components/homekit/accessories.py:665 First occurred: 12:10:33 (1 occurrences) Last logged: 12:10:33

Error doing job: Task exception was never retrieved Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/components/homekit/init.py", line 778, in async_start if not await self._async_create_accessories(): File "/usr/src/homeassistant/homeassistant/components/homekit/init.py", line 940, in _async_create_accessories acc = await self._async_create_bridge_accessory(entity_states) File "/usr/src/homeassistant/homeassistant/components/homekit/init.py", line 929, in _async_create_bridge_accessory self.add_bridge_triggers_accessory(device, device_triggers) File "/usr/src/homeassistant/homeassistant/components/homekit/init.py", line 708, in add_bridge_triggers_accessory DeviceTriggerAccessory( File "/usr/src/homeassistant/homeassistant/components/homekit/type_triggers.py", line 49, in init serv_stateless_switch = self.add_preload_service( File "/usr/local/lib/python3.10/site-packages/pyhap/accessory.py", line 129, in add_preload_service self.add_service(service) File "/usr/local/lib/python3.10/site-packages/pyhap/accessory.py", line 151, in add_service self.iid_manager.assign(s) File "/usr/local/lib/python3.10/site-packages/pyhap/iid_manager.py", line 31, in assign iid = self.get_iid_for_obj(obj) File "/usr/src/homeassistant/homeassistant/components/homekit/accessories.py", line 665, in get_iid_for_obj raise RuntimeError( RuntimeError: Cannot assign IID 8 to <service display_name=StatelessProgrammableSwitch unique_id=changed_states- chars={'ProgrammableSwitchEvent': None, 'Name': '', 'ServiceLabelIndex': 1}> as it is already in use by: <service display_name=StatelessProgrammableSwitch unique_id=changed_states- chars={'ProgrammableSwitchEvent': None, 'Name': 'Changed_States', 'ServiceLabelIndex': 1}>

bdraco commented 1 year ago

Having problems too... I can switch lights within home assistant but not in Homekit. The problem occurred with the update from 10.5 to 11.1. After restoring 10.5 it worked again...

Logger: homeassistant Source: components/homekit/accessories.py:665 First occurred: 12:10:33 (1 occurrences) Last logged: 12:10:33

Error doing job: Task exception was never retrieved Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/components/homekit/init.py", line 778, in async_start if not await self._async_create_accessories(): File "/usr/src/homeassistant/homeassistant/components/homekit/init.py", line 940, in _async_create_accessories acc = await self._async_create_bridge_accessory(entity_states) File "/usr/src/homeassistant/homeassistant/components/homekit/init.py", line 929, in _async_create_bridge_accessory self.add_bridge_triggers_accessory(device, device_triggers) File "/usr/src/homeassistant/homeassistant/components/homekit/init.py", line 708, in add_bridge_triggers_accessory DeviceTriggerAccessory( File "/usr/src/homeassistant/homeassistant/components/homekit/type_triggers.py", line 49, in init serv_stateless_switch = self.add_preload_service( File "/usr/local/lib/python3.10/site-packages/pyhap/accessory.py", line 129, in add_preload_service self.add_service(service) File "/usr/local/lib/python3.10/site-packages/pyhap/accessory.py", line 151, in add_service self.iid_manager.assign(s) File "/usr/local/lib/python3.10/site-packages/pyhap/iid_manager.py", line 31, in assign iid = self.get_iid_for_obj(obj) File "/usr/src/homeassistant/homeassistant/components/homekit/accessories.py", line 665, in get_iid_for_obj raise RuntimeError( RuntimeError: Cannot assign IID 8 to <service display_name=StatelessProgrammableSwitch unique_id=changed_states- chars={'ProgrammableSwitchEvent': None, 'Name': '', 'ServiceLabelIndex': 1}> as it is already in use by: <service display_name=StatelessProgrammableSwitch unique_id=changed_states- chars={'ProgrammableSwitchEvent': None, 'Name': 'Changed_States', 'ServiceLabelIndex': 1}>

I don't think thats related to this issue but it is resolved in https://github.com/home-assistant/core/pull/80703 which is not yet merged and released

bdraco commented 1 year ago

I've made a mess of this issue. The desync / late sync issue happens for all sorts of devices (for example zwave lights in another room). The issues with the Eve light switch is compounded by Thread/coap problems.

There is a lot to unpack here so I'm going to try to give you information about what has changed in the hopes that it can get you to a resolution.

There were some changes to how HomeKit works in 16.1/16.1.1 n the Apple side in preparation for the new architecture that Apple is releasing in 16.2. You may find your iOS device is talking to the home hub instead of accessories directly now.
There have been no protocol level changes on the HAP-python (underling library used by HomeKit` side except for a bugfix to send paired UUIDs in uppercase (this is likely not related) and the stable iid restore listed below.
Any HomeKit pairing made with HA before 2022.11 (day one problem with the HomeKit integraiton) never saved the iids between restarts and they were completely unstable. Unpairing and repairing will be sure that the Home Hub and iCloud has the correct iids. This sounds like it could be the issue
Any BLE HomeKit Controller pairing made before 2022.11 had incorrect service iids. I don't think this is the issue but they should be unpaired and re-paired as well.

jfroy commented 1 year ago

What's the procedure for re-pairing or resetting a HA HomeKit bridge? Something like

Remove bridge from HomeKit
Remove bridge integration
Restart HA core
Re-add bridge integration
Re-pair new bridge in HomeKit

bdraco commented 1 year ago

Remove bridge from HomeKit (verify QR code re-appears in HA)
Reload HA HomeKit integration to get a new ID
Re-pair new bridge in HomeKit

bdraco commented 1 year ago

Actually the ID will probably not change unless you delete it and recreate it. But you could also modify the .state file in /config/.storage/homekit.ENTRY_ID.state and pick a new random id and reload

jfroy commented 1 year ago

I followed my procedure and made a brand new bridge. Going to see how the system behaves over the weekend.

I'll open a new issue specifically for the Thread devices. They all do seem to go unavailable in HA after some time.

jfroy commented 1 year ago

The problem has just occurred again. Went into the Apple Home app and I had a very stale turned on lights count and light states across the home which did not update after waiting idle in the app for 10 seconds or so. I went out of the app back to the home screen, waiting a few seconds, went back into Apple Home and that triggered a refresh. I never observed this behavior in the recent past (a month ago).

bdraco commented 1 year ago

If you enable debug logs for pyhap do you see the events still being sent?

jfroy commented 1 year ago

If you enable debug logs for pyhap do you see the ends still being sent?

The ends?

In any case, debug logging is enabled and I'll keep an eye out for the problem again so I have a time region to look at in the logs. I don't have a good sense of when the problem occurs. It may be when I leave home and the phone goes on cellular, it could be a lapse of time w/o going into the Apple Home app, or something else entirely.

bdraco commented 1 year ago

Autocorrect fail: should have been "events"

bdraco commented 1 year ago

Also check in the Home app which Apple device is the home hub. You'll likely find in the pyhap debug log thats where the events are being sent. Sometimes events can be missed if

its a Home Pod (Mini) and the wifi connection is flakey (I wish Apple provided a way to disable HomeKit on these like they do for the apple tvs)
it needs to be rebooted because of stability issues with the device itself. I saw on the homekit subreddit recently that someone had a similar issue and solved it by rebooting all their home pod minis

jfroy commented 1 year ago

I use a wired AppleTV as my only HomeKit hub (do not own any HomePods). Apple Home on my phone and Mac shows it as connected.

However, I just remembered that some of my accessories (WeMo lights) are directly paired to my HomeKit home. I'll pay extra attention the next time the issue occurs, but I believe some of those lights also had stale state. If that's the case, the issue is on the ATV HomeKit hub, not in HA. I don't know if there would be indication that the hub stopped responding in the pyhap logs.

bdraco commented 1 year ago

I don't know if there would be indication that the hub stopped responding in the pyhap logs.

If its network is down you'll see it stop getting events. If its network is up it could still be receiving the events but not processing them

bdraco commented 1 year ago

I use a wired AppleTV as my only HomeKit hub (do not own any HomePods).

Glad we can rule that out as that one is always nearly impossible to resolve if its wifi

Which version of TvOS and AppleTV hardware do you have?

jfroy commented 1 year ago

I use a wired AppleTV as my only HomeKit hub (do not own any HomePods).

Glad we can rule that out as that one is always nearly impossible to resolve if its wifi

Which version of TvOS and AppleTV hardware do you have?

Apple TV 4K 2nd gen (AppleTV11,1). It's currently on tvOS 16.1.

bdraco commented 1 year ago

I've got almost the same setup for my production except I'm using a 4k gen3 AppleTV14,1 w/tvOS 16.1

I haven't had any luck replicating this yet, but I'll keep watching.

jfroy commented 1 year ago

I have radically simplified my prod network over the weekend. No more VLANs, everything on the default LAN. I have not observed the issue again yet, but will keep open a few more days.

A Unifi OS 1.x network with VLANs + Unifi OS 1.x's mdns reflector may have reliability problems. I did reboot my ATV and a lot of other devices however (as part of the network arch change), so it is also possible I "flushed out the badness" just by rebooting devices.

jfroy commented 1 year ago

This is still ongoing. I have a feeling it's an issue with Apple Home app and not strictly related to the HomeKit integration, though of course there could be an interaction (would be very difficult to prove w/o ripping apart most of my HomeKit home).

bdraco commented 1 year ago

Might be best to wait for iOS 16.2 and see if the new architecture fixes it since whatever time we invest in digging through this is likely going to be wasted effort when everything changes again shortly.

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