ikalchev / HAP-python

A python implementation of the HomeKit Accessory Protocol (HAP)
Other
607 stars 116 forks source link

HAP-Python devices noted by iOS App as unresponsive every few minutes #327

Open bitaxis opened 3 years ago

bitaxis commented 3 years ago

Hi. I have been using this project to build custom accessories using a couple of Raspberry Pi machines (Models 3B and Zero W) and sensors to integrate with HomeKit. I also have a handful of purchased devices that are compatible with HomeKit.

However, it seems that my HAP-Python devices would stop responding to HomeKit every few minutes, evidenced by the Home app on my iOS devices reporting them as being not responding. But, after a few minutes, they'll start responding again. And then, after a few more minutes, the pattern repeats itself.

In contrast, I don't have this problem with my purchased devices.

Turning logging level up to DEBUG on one Raspberry Pi and reading through the log entries revealed a pattern for multiple IP addresses, which I assume represent my other accessories and iOS devices. Below is a sample filtered by one IP address and connection made/lost events. But these events are being reported for multiple IP addresses.

I assume this is not normal/expected behavior. If so, I'd appreciate assistance in helping me to eliminate them so my HAP-Python devices remain consistently responsive to HomeKit.

My Raspberry Pi machines are running Raspian Buster, Python 3.7, and HAP-Python 3.3.0:

PRETTY_NAME="Raspbian GNU/Linux 10 (buster)"
NAME="Raspbian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"
VERSION_CODENAME=buster
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"

I use an iPhone XR & an iPad Air to control & automate my accessories, and I have a HomePod mini that serves as the hub. All are running the latest respective operating systems.

2021-03-03 21:13:54,204 INFO  {3069941984} [hap_protocol.py:51] ('192.168.0.78', 64866): Connection made to Master Bath HAP-Python Bridge
2021-03-03 21:19:12,813 DEBUG {3069941984} [hap_protocol.py:41] ('192.168.0.78', 64866): Connection lost to Master Bath HAP-Python Bridge: None
2021-03-03 21:19:18,440 INFO  {3069941984} [hap_protocol.py:51] ('192.168.0.78', 64883): Connection made to Master Bath HAP-Python Bridge
2021-03-03 21:25:25,778 DEBUG {3069941984} [hap_protocol.py:41] ('192.168.0.78', 64883): Connection lost to Master Bath HAP-Python Bridge: None
2021-03-03 21:28:52,635 INFO  {3069941984} [hap_protocol.py:51] ('192.168.0.78', 64893): Connection made to Master Bath HAP-Python Bridge
2021-03-03 21:31:21,758 DEBUG {3069941984} [hap_protocol.py:41] ('192.168.0.78', 64893): Connection lost to Master Bath HAP-Python Bridge: None
2021-03-03 21:32:58,831 INFO  {3069941984} [hap_protocol.py:51] ('192.168.0.78', 64902): Connection made to Master Bath HAP-Python Bridge
2021-03-03 21:32:59,209 DEBUG {3069941984} [hap_protocol.py:41] ('192.168.0.78', 64902): Connection lost to Master Bath HAP-Python Bridge: None
2021-03-03 21:35:57,024 INFO  {3069941984} [hap_protocol.py:51] ('192.168.0.78', 64912): Connection made to Master Bath HAP-Python Bridge
2021-03-03 21:36:50,605 DEBUG {3069941984} [hap_protocol.py:41] ('192.168.0.78', 64912): Connection lost to Master Bath HAP-Python Bridge: None
2021-03-03 21:38:31,383 INFO  {3069941984} [hap_protocol.py:51] ('192.168.0.78', 64913): Connection made to Master Bath HAP-Python Bridge
bdraco commented 3 years ago

Can you try this PR to see if it resolves the issue https://github.com/ikalchev/HAP-python/pull/320

bdraco commented 3 years ago

Also it seems like the this might be an mdns issue. Does the bridge disappear in the https://apps.apple.com/us/app/discovery-dns-sd-browser/id1381004916?mt=12 app every few seconds?

SebasT87 commented 3 years ago

I'm experiencing the same symptoms. Not sure though it's the same issue. In my case it seems a mdns issue because ,like bdraco says, it disappears within the suggested discovery tool. It doesn't seem te be a network problem because all other mdns traffic flows freely. This has been puzzling me for a while now and i'm still hoping for some clue that points me in the right direction.

bdraco commented 3 years ago

Can you try the troubleshooting steps for LIFX as they are similar for homekit

https://support.lifx.com/hc/en-us/articles/360050331312-Free-Network-Improvement-Tool-RouteThis

SebasT87 commented 3 years ago

Sure thing, but no issues found. All optimal.

Don't know if it's related in any way under the hood, but when the records under hap._tcp disappear home-assistant._tcp also disappears. So to me it seems the entire subsystem (avahi/mdns??) dies/crashes. Does this make sense?

bdraco commented 3 years ago

That means the problem is definitely here https://github.com/jstasiak/python-zeroconf

Do you have any zeroconf errors in your log?

bdraco commented 3 years ago

Also do you have this setting on or off : https://www.home-assistant.io/integrations/zeroconf/#default_interface?

SebasT87 commented 3 years ago

The default interface option is false atm, but also tried true in an effort to resolve this in the past.

Will have another look in the logs to see if anything related to zeroconf comes up and keep you posted

SebasT87 commented 3 years ago

Enabled zeroconf debug log and my oh my the log is filling up fast. Haven't seen ant obvious errors yet but i do see a lot of these lines

DEBUG (zeroconf-Engine-243) [zeroconf] Ignoring duplicate message received from ...

bdraco commented 3 years ago

Duplicates are expected due to listening on multiple interfaces since its multicast

SebasT87 commented 3 years ago

I understand, makes perfect sense. But when default_interface is set to true these should disappear? This should make it listen on one interface only right?

SebasT87 commented 3 years ago

Enabled default interface and still seeing duplicates being ignored, but only on the default interface obviously. But Homekit seems to have stopped completely now because it seems to ignore everything.

bdraco commented 3 years ago

I understand, makes perfect sense. But when default_interface is set to true these should disappear? This should make it listen on one interface only right?

Responses are still sent on all interfaces even if only listening on one. Depending on how your network is setup, you may see the responses come back on listening interfaces since its multicast.

bitaxis commented 3 years ago

Also it seems like the this might be an mdns issue. Does the bridge disappear in the https://apps.apple.com/us/app/discovery-dns-sd-browser/id1381004916?mt=12 app every few seconds?

@bdraco, thanks for the tip. I downloaded the Discovery application onto my Mac mini, and I do observe the bridge disappearing and re-appearing every few minutes, roughly corresponding to the logs I see on my Raspberry PI Zero W. But not every few seconds like you said.

As for the PR you suggested that I try, I am not sure exactly how to get a hold of it. But looks like it was merged into @ikalchev's dev branch already, so I will try that.

bdraco commented 3 years ago

Its likely that python-zeroconf doesn't pass the Bonjour conformance test https://developer.apple.com/bonjour/ which is the source of the issue.

It looks like you need an airport extreme to run the test. I'll see if I can pickup one on ebay

SebasT87 commented 3 years ago

My issues have been resolved by adding a decent switch to my network. Before i used the build in switch on the provider modem/router which was the culprit

bitaxis commented 3 years ago

@SebasT87, are you talking about a wired Ethernet switch, or a wireless router?

bdraco commented 2 years ago

Please update to zeroconf 0.32.1 or later