HomeKit devices 'No Response' after a while

[bobsoppe]

The problem

When using the HomeKit integration all of the devices will turn up with a 'No Response' message after a while in the Home.app. I tried to debug the network by removing the Home Assistant HomeKit bridge and add the Trådfrï HomeKit bridge, which is working without any problem. So that will make me think something is wrong with the HomeKit integration

Environment

• Home Assistant Core release with the issue: 0.116.4
• Last working Home Assistant Core release (if known): -
• Operating environment (OS/Container/Supervised/Core): FreeNAS-11.3-U3.2 in a jail using a venv install
• Integration causing this issue: HomeKit
• Link to integration documentation on our website: https://www.home-assistant.io/integrations/homekit

Problem-relevant configuration.yaml

Tried it configuring using the UI and also using a very simple homekit configuration.

homekit:

Traceback/Error logs

No (relevant) traceback/error logs

Additional information

Network discovery

The results of the network discovery are the same when running it inside the jail of Home Assistant and on another machine (laptop)

$ python -m netdisco dump

homekit:
[{'host': '192.168.10.50',
  'hostname': 'HASS Bridge NOTK 15799F._hap._tcp.local.',
  'name': 'HASS Bridge NOTK 15799F',
  'port': 51828,
  'properties': {'c#': '2',
                 'ci': '2',
                 'ff': '0',
                 'id': 'E7:DE:60:15:79:9F',
                 'md': 'HASS Bridge NOTK',
                 'pv': '1.0',
                 's#': '1',
                 'sf': '0',
                 'sh': '9Gnksg=='}}]

Zeroconf
[record[ptr,in,_hap._tcp.local.]=4500/4487,HASS Bridge NOTK 15799F._hap._tcp.local.,
 record[srv,in-unique,HASS Bridge NOTK 15799F._hap._tcp.local.]=120/107,HASS Bridge NOTK 15799F._hap._tcp.local.:51828,
 record[txt,in-unique,HASS Bridge NOTK 15799F._hap._tcp.local.]=4500/4487,b'\x13md=HAS'...,
 record[a,in-unique,HASS Bridge NOTK 15799F._hap._tcp.local.]=120/107,192.168.10.50,
 record[ptr,in,_home-assistant._tcp.local.]=4500/4487,Home._home-assistant._tcp.local.,
 record[srv,in-unique,Home._home-assistant._tcp.local.]=120/107,4e2fef37043f458f937cca250940ac2c.local.:8123,
 record[txt,in-unique,Home._home-assistant._tcp.local.]=4500/4487,b'\x12locati'...,
 record[a,in-unique,4e2fef37043f458f937cca250940ac2c.local.]=120/107,192.168.10.50,
 record[srv,in-unique,TRADFRI gateway._hap._tcp.local.]=120/114,TRADFRI-Gateway-a0c9a0d81a3f.local.:80,
 record[txt,in-unique,TRADFRI gateway._hap._tcp.local.]=4500/4494,b'\x04c#=1\x04f'...,
 record[ptr,in,_coap._udp.local.]=4500/4494,gw-a0c9a0d81a3f._coap._udp.local.,
 record[srv,in-unique,gw-a0c9a0d81a3f._coap._udp.local.]=120/114,TRADFRI-Gateway-a0c9a0d81a3f.local.:5684,
 record[txt,in-unique,gw-a0c9a0d81a3f._coap._udp.local.]=4500/4494,b'\x0fversio'...,
 record[a,in-unique,TRADFRI-Gateway-a0c9a0d81a3f.local.]=120/114,192.168.40.10]

nmap

To be sure the port for the HomeKit integration is open and accepting requests I ran nmap

$ nmap -p22,80,51828 192.168.10.50

Starting Nmap 7.91 ( https://nmap.org ) at 2020-10-21 11:42 CEST
Nmap scan report for 192.168.10.50
Host is up (0.0074s latency).

PORT      STATE SERVICE
22/tcp    open  ssh
80/tcp    open  http
51828/tcp open  unknown

Nmap done: 1 IP address (1 host up) scanned in 0.12 seconds

[probot-home-assistant]

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

[probot-home-assistant]

Hey there @bdraco, mind taking a look at this issue as its been labeled with an integration (homekit) you are listed as a codeowner for? Thanks!
_{^{(message by CodeOwnersMention)}}

[b3nnyk22]

I am having the same issue. About once a day all of my devices stop responding in Home. I'll still have control from HA but the only way to get them back in Home is to restart the HA server.

arch	x86_64
chassis	vm
dev	false
docker	true
docker_version	19.03.11
hassio	true
host_os	HassOS 4.13
installation_type	Home Assistant OS
os_name	Linux
os_version	5.4.63
python_version	3.8.5
supervisor	249
timezone	Australia/Melbourne
version	0.116.2
virtualenv	false

[bdraco]

Try turning on debug logging for pyhap

[b3nnyk22]

Sorry for hijacking the thread but perhaps we're having the same problem. My apologies in advance as I'm new to this world. I turned on debug logging for pyhap and have been monitoring for a few days.

I've realised the same time my Home Integration is becoming unrespsonsive my two LIFX (Beam and Strip) are becoming unavailable in Home Assisant as well. It also seems to happen around the exact same time every day. Here's the Log from around the time things go offline:

[bdraco]

Please provide a py-spy and profile : https://community.home-assistant.io/t/python3-high-cpu-usage/160012/1

[anthonycvella]

Hey @bdraco, this is happening to me too. Any additional logging I can provide to help as well? I am running on hassio so unfortunately I don't believe I'll be able to run py-spy.

I am seeing the following error, repeated many times, in my logs though.

AttributeError: 'NoneType' object has no attribute 'available'
2020-10-29 11:20:44 ERROR (Thread-27) [pyhap.accessory_driver] Unexpected error getting value for characteristic <built-in function id>.
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/pyhap/accessory_driver.py", line 673, in get_characteristics
    available = acc.available

[bdraco]

Try turning on debug logging for pyhap

[anthonycvella]

Here is some recent data about when my accessories stopped responding. My one observation, may be nothing, is that the sender_client_addr is None from the pyhap.accessory_driver.

2020-10-29 15:48:06 DEBUG (MainThread) [homeassistant.components.homekit.accessories] New_state: <state light.hallway_lights=on; min_mireds=153, max_mireds=500, brightness=254, color_temp=300, entity_id=['light.fronthallway', 'light.rearhallway'], friendly_name=Hallway Lights, supported_features=43 @ 2020-10-29T15:48:06.850653-07:00>
2020-10-29 15:48:06 DEBUG (MainThread) [pyhap.characteristic] set_value: On to 1
2020-10-29 15:48:06 DEBUG (MainThread) [pyhap.characteristic] set_value: ColorTemperature to 300
2020-10-29 15:48:06 DEBUG (Thread-7) [pyhap.accessory_driver] Send event: topic(922966253.9), data(b'{"characteristics": [{"aid": 922966253, "iid": 9, "value": true}]}'), sender_client_addr(None)
2020-10-29 15:48:06 DEBUG (Thread-7) [pyhap.accessory_driver] Sending event to client: ('192.168.86.250', 63829)
2020-10-29 15:48:06 DEBUG (Thread-7) [pyhap.accessory_driver] Send event: topic(922966253.11), data(b'{"characteristics": [{"aid": 922966253, "iid": 11, "value": 300}]}'), sender_client_addr(None)
2020-10-29 15:48:06 DEBUG (Thread-7) [pyhap.accessory_driver] Sending event to client: ('192.168.86.250', 63829)
2020-10-29 15:50:06 DEBUG (MainThread) [homeassistant.components.homekit.accessories] New_state: <state light.hallway_lights=off; min_mireds=153, max_mireds=500, entity_id=['light.fronthallway', 'light.rearhallway'], friendly_name=Hallway Lights, supported_features=43 @ 2020-10-29T15:50:06.938466-07:00>
2020-10-29 15:50:06 DEBUG (MainThread) [pyhap.characteristic] set_value: On to 0
2020-10-29 15:50:06 DEBUG (Thread-7) [pyhap.accessory_driver] Send event: topic(922966253.9), data(b'{"characteristics": [{"aid": 922966253, "iid": 9, "value": false}]}'), sender_client_addr(None)
2020-10-29 15:50:06 DEBUG (Thread-7) [pyhap.accessory_driver] Sending event to client: ('192.168.86.250', 63829)

[bdraco]

Here is some recent data about when my accessories stopped responding. My one observation, may be nothing, is that the sender_client_addr is None from the pyhap.accessory_driver.

That is expected when Hass makes the change and not a controller ( iPhone )

[bdraco]

It is likely a thread safety issue.

Try this fix

diff --git a/pyhap/accessory_driver.py b/pyhap/accessory_driver.py
index 52ae3e3..1dc54fc 100644
--- a/pyhap/accessory_driver.py
+++ b/pyhap/accessory_driver.py
@@ -670,6 +670,8 @@ class AccessoryDriver:
                     available = True
                 else:
                     acc = self.accessory.accessories.get(aid)
+                    if acc is None:
+                        continue
                     available = acc.available
                     char = acc.iid_manager.get_obj(iid)
 

[anthonycvella]

I'm not familiar with the file structure of homeassistant. Where do integrations live?

[anthonycvella]

Alright I managed to finally get access after following https://developers.home-assistant.io/docs/operating-system/debugging and I've patched the file. I'll let you know of my results after an hour or so.

Update: Things are definitely a lot more stable but I've noticed a few drops.