search

ikalchev / HAP-python

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

Homekit intermittent problem with 'No response' on IOS devices #176

Closed jr3us closed 5 years ago

jr3us commented 5 years ago

Copied title over here per @cdce8p recommendation:

The issue on home assistant is #15675 has the history for what has happened, but I'll paste my last commentary here.

After uprading to 83.1 this morning, and still using the same platform as described initially, I am also seeing that I have no response more often than I have valid information in the Home app for iOS.

As @dmonagle indicated on home assistant pull request #18355, the status for devices in Home will work correctly for a few minutes, and then go No response for 4 or 5 minutes.

Side note: I had to comment out the start up automation I used above as homeassistant complained about the action: homekit.start. I also removed the autostart False so it would start up.

Regards!

ASchneiderBR commented 5 years ago

Thanks for you comment @jr3us ! I am too having problems with no updates using Home Assistant and Homekit. This problem was not present for the last few months and after the latest update that includes v2.4.1 this very annoying issue started again. I really appreciate if someone could help me. Thanks a lot for the great work done here!

ikalchev commented 5 years ago

Hi all,

@tatunts Are you sure the issue shows up with HAP-python 2.4.1? Can someone run netstat -an | egrep <port of HAP-python> when the accessory goes to "No response"?

Best, Ivan

ikalchev commented 5 years ago

@cdce8p In any case, can you integrate with 2.4.1, 2.4.0 is somewhat broken.

ASchneiderBR commented 5 years ago

Hello @ikalchev ! Thanks for you reply, really appreciate you time here.

Yes, this problem started for sure when I have updated my Hassio from 81.6 to 83.x. Sometimes it takes 10, 30 minutes or even a couple of hours after restart Home Assistant and no updates are shown on Home app if states of the devices are changed from another Home App or Home Assistant UI.

Now all devices are not updating, so I have run the command using SSH on my Hassio, here are the results (sorry, could not copy and paste from terminal):

image

All devices not ending with .12 (Hassio) are iPhones and one iPad.

Thanks a lot!

ASchneiderBR commented 5 years ago

Sorry if this problem is only related to the HA integration and has nothing do with your work here, I am really not sure were to go. Thanks.

jr3us commented 5 years ago

@ikalchev , I have done a quick check, with the following results:

iphone getting responses and working as it should.

iphone starts getting no responses with the following

pi@hassbian:~ $ netstat -al | grep -i 192.168.1.37 tcp 0 0 192.168.1.40:51827 192.168.1.37:52853 ESTABLISHED tcp 0 0 192.168.1.40:51827 192.168.1.37:54089 ESTABLISHED

a few minutes later, iphone starts getting responses again, and the following is shown.

pi@hassbian:~ $ netstat -al | grep -i 192.168.1.37 tcp 0 0 192.168.1.40:51827 192.168.1.37:52853 ESTABLISHED tcp 0 0 192.168.1.40:51827 192.168.1.37:54147 ESTABLISHED tcp 0 0 192.168.1.40:51827 192.168.1.37:54089 ESTABLISHED

it then becomes responsive again.

If you need any additional info, let me know.

Regards,

jr3us commented 5 years ago

Side note: going back to anything prior to 2.4.0 would be bad for home assistant on hassbian for me. The newest version for me fixes the stale socket problem and keeps me from having to reboot every few days. by the way, thanks for fixing that part!

ikalchev commented 5 years ago

Thank you both for the quick info. From the snippets you show me, I am pretty sure that old sockets stay in ESTABLISHED and are not closed for some reason, because I see two ports opened for the same address. I got the same behaviour on HAP-python 2.4.0, but I thought I fixed that with 2.4.1.

Does anyone knows which python version is that? Also, can you say what type of accessory (e.g. characteristics that are showing in the UI as no response) are you testing with - my local fake temperature sensor has no problems for over an hour now.

jr3us commented 5 years ago

hassbian is currently using either 2.7.13 or 3.5.3. I'm not sure which one homeassistant is using.

jr3us commented 5 years ago

I"m pretty sure homeassistant is using 3.5 as I had to migrate to hassbian stretch since homeassistant was not happy with the version used prior to about a year or so ago.

ikalchev commented 5 years ago

HAP-python doesn't support 2.7, I guess you are right. Okay, I haven't tested with 3.5, let me try it.

jr3us commented 5 years ago

holler if you need any additional assistance!

jr3us commented 5 years ago

I forgot to answer the 2nd have of your question.. All of the devices go to no response. I have light switches, and a NEST thermostat with all of its bag of switches, controls, and sensors.

cdce8p commented 5 years ago

Only as clarification: I did the update to 2.4.1 a while ago. It was first included in Home Assistant 0.83. I assume @jr3us and @tatunts are using that.

As for python: The min requirement for Home Assistant is 3.5.3.

Regarding the services and chars used, you could find the complete list here: homekit/const.py -> Services & Chars. However I would guess that it's not related and rather an issue with having a few / many accessories.

ASchneiderBR commented 5 years ago

Yes, exactly my case. Migrated to version 83. I have 107 devices configured on my setup but still using the same number as the version before, that was working perfectly.

jr3us commented 5 years ago

I am also running version 83.1 and hap-python is version 2.4.1.

ASchneiderBR commented 5 years ago

@jr3us , do you think it is possible to revert back only the HomeKit component to the version that was compiled on version 81? I know that you use Hassbian, but there is a way to use the folder custom_components and put the python code there to load that component but not sure if there is a HAP-python code outside the HomeKit python code...

jr3us commented 5 years ago

no clue.. I defer to cdce8p and ikalchev.

ASchneiderBR commented 5 years ago

Hello guys! I've just updated to version 83.3 of Home Assistant, I am pretty sure that it will not fix my problem since it needs to bump the version of HAP-python first but here is screen of the connections open when the system is just restarted and fully functional with HomeKit:

image

Thanks!

ikalchev commented 5 years ago

I am still debugging this, as I needed to setup a python 3.5 env

cdce8p commented 5 years ago

@tatunts Although it was working fine before, can you try reducing the number of accessories to well below 100? That's usually the suggested limit for one bridge.

As for the downgrade: It's possible but I wouldn't recommend doing it since it will probably create issues in the long run. Anyway you would need to put all files from here into custom_components/homekit.

ASchneiderBR commented 5 years ago

Thanks a lot @ikalchev for your time!

Many thanks @cdce8p for this info. I was wondering exacly that: does those files have everything it needs to run HomeKit? Including the HAP-python v2.3 code? That would be awesome and an easy fix for me, since this version works like a charm for me, even with 107 devices.

cdce8p commented 5 years ago

Yeah they should. After you have placed the files there and restarted HA, the old HAP-python version should be installed in the deps folder.

However just to iterate, I don't recommend to do so!

ASchneiderBR commented 5 years ago

Hello again! Just a quick update: tried to load HomeKit as custom component (v81.6) and after a an hour or so, same behavior. Also there no duplicate connections from server using the same port like before, very odd. Thanks.

theFeverDog commented 5 years ago

Had the same issues appear in my setup after upgrading Homeassistant to 0.83. Deleted and re-paired the bridge (which took a few tries). Problems reappeared at first but haven‘t reappeared in the past 36h. However I also manually specified the IP adress of the server after I re-paired the bridge, this might have helped with the problem.

Update: Spoke too soon, devices are unavailable again.

ikalchev commented 5 years ago

Folks, it appears that @xbtsw may have tracked down the problem. It doesn't solve the root cause, but it should remove this issue. (see merged pull request)

Can some of you test with dev@latest? @cdce8p can you assist? Let me know if the issue is resolved.

ASchneiderBR commented 5 years ago

Amazing work @ikalchev ! Thanks a lot!

Please, let me know if you need anything, I can help testing on my setup.

ikalchev commented 5 years ago

Go for it. I can’t give advice on how to use the version from the dev branch though

cdce8p commented 5 years ago

Can some of you test with dev@latest? @cdce8p can you assist?

Happy to help.

@tatunts You are using Hassio right? That might be a bit more difficult, since I don't know the exact path. However you would want to find the python environment -> lib -> python3.x -> site-packages -> pyhap. Maybe a search for pyhap does this?

For Hassbian it should be in /srv/homeassistant/lib/python3.x/site-packages/pyhap.

In the pyhap folder, you need to replace the hap_server.py file with this one: hap_server.py. Remember to restart Home Assistant afterwards.

jr3us commented 5 years ago

Installed and testing now.

jr3us commented 5 years ago

worked for a few minutes, but now no response returns.

netstat now shows no connections as follows:

pi@hassbian:~ $ netstat -an | grep 51827 tcp 0 0 192.168.1.40:51827 0.0.0.0:* LISTEN

jr3us commented 5 years ago

I am using a year old ipad and an iphone SE with latest iOS in the house and on WiFi.

I did see tcp connections to them in netstat, and after a few minutes the connection went away.

I do see this in the logs:

Dec 7 08:30:19 hassbian hass[19910]: 2018-12-07 08:30:19 DEBUG (Thread-25) [pyhap.hap_server] exception [Errno 9] Bad file descriptor for ('192.168.1.23', 56783) in push_event() Dec 7 08:30:19 hassbian hass[19910]: 2018-12-07 08:30:19 DEBUG (Thread-25) [pyhap.hap_server] Connection timeout for ('192.168.1.23', 56783) with exception [Errno 9] Bad file descriptor Dec 7 08:30:19 hassbian hass[19910]: 2018-12-07 08:30:19 DEBUG (Thread-25) [pyhap.hap_server] Current connections {('192.168.1.23', 56784): <pyhap.hap_server.HAPSocket object at 0x5bc6ac90>, ('192.168.1.23', 56783): <pyhap.hap_server.HAPSocket object at 0x53c8f910>, ('192.168.1.29', 61404): <pyhap.hap_server.HAPSocket object at 0x51c083f0>} Dec 7 08:30:19 hassbian hass[19910]: 2018-12-07 08:30:19 DEBUG (Thread-25) [pyhap.accessory_driver] Could not send event to ('192.168.1.23', 56783), probably stale socket.

jr3us commented 5 years ago

I am very comfortable with adding additional debug/ test stuff in the python code.. If you want me to add anything to hap_server.py I am willing to do that.

ASchneiderBR commented 5 years ago

@tatunts You are using Hassio right? That might be a bit more difficult, since I don't know the exact path. However you would want to find the python environment -> lib -> python3.x -> site-packages -> pyhap. Maybe a search for pyhap does this?

Hello @cdce8p! Thanks for your reply.

I've search all files using the addon configurator as I can see all files outside the config folder and could not find hap_server.py.

I can access Hassio over SSH, do you think there is a command that I could manually update HAP-python?

If there is another way to do it, I really appreciate your help.

Thanks again my friend!

gabgabe commented 5 years ago

@tatunts You are using Hassio right? That might be a bit more difficult, since I don't know the exact path. However you would want to find the python environment -> lib -> python3.x -> site-packages -> pyhap. Maybe a search for pyhap does this?

Hello @cdce8p! Thanks for your reply.

I've search all files using the addon configurator as I can see all files outside the config folder and could not find hap_server.py.

I can access Hassio over SSH, do you think there is a command that I could manually update HAP-python?

If there is another way to do it, I really appreciate your help.

Thanks again my friend!

I can easy access all the files using ubuntu. Can't edit using windows or mac. I can't configure samba so I don't even know if is possible to access that partition. Waiting for your magic fixing this issue!!

cdce8p commented 5 years ago

@tatunts If you have access over SSH, does SCP work?

ASchneiderBR commented 5 years ago

@cdce8p yes I can, but I can see the same files as using the configurator addon...

This is the lib folder:

image

I think since Hassio is like docker, file structure and access are very different from Hassbian.

cdce8p commented 5 years ago

Try searching for pyhap

ASchneiderBR commented 5 years ago

Hey! I think I've found it haha

image

cdce8p commented 5 years ago

Looks about right!

ASchneiderBR commented 5 years ago

Should I try it or wait for an update, since @jr3us said it did not work for him?

Also, @gabgabe: here is were the file is located :)

cdce8p commented 5 years ago

It doesn't hurt to try it. Would be interesting to see if you have the same error. Make sure to enable debug logging for all pyhap files if you haven't already.

ASchneiderBR commented 5 years ago

Hello @cdce8p! Sorry to bother again: actually I've found these files easily by the SAMBA share created by Hassio, on config folder. You can see the full path to this:

image

I see that it is inside Python 3.6, not 3.5 as mentioned before. Do you think that doing it just using SCP by changing that file will work? Since HomeKit component looks for the latest version of HAP-python on initialization (2.4.1)?

Sorry to bother you, I am not a coder or a Hassbian user, I really like to use Hassio because of its easy of use.

Thanks!

ASchneiderBR commented 5 years ago

Anyways, I've made a backup from the current hap_server.py file and transferred the new one. Restarting now. I'll let you know if it works. Thanks!

gabgabe commented 5 years ago

Tried new hap_server.py

worked fine for 10 minutes, then I ask for a command, homekit shut down the light then immediately not responding

IP 192.168.10.237 is apple tv 4th gen other IP are other devices invited to the house (workmate iphone etc...)

2018-12-07 17:59:26 DEBUG (Thread-10) [pyhap.hap_server] Request PUT from address '('192.168.10.237', 49179)' for path '/characteristics'. 2018-12-07 17:59:26 DEBUG (Thread-10) [pyhap.hap_server] Set characteristics content: {'characteristics': [{'aid': 228917929, 'iid': 9, 'value': False}]} 2018-12-07 17:59:26 DEBUG (Thread-10) [pyhap.characteristic] client_update_value: On to False 2018-12-07 17:59:26 INFO (Thread-10) [pyhap.hap_server] 192.168.10.237 - "PUT /characteristics HTTP/1.1" 204 - 2018-12-07 17:59:26 DEBUG (Thread-3) [pyhap.accessory_driver] Send event: topic(228917929.9), data(b'{"characteristics": [{"aid": 228917929, "iid": 9, "value": false}]}') 2018-12-07 17:59:26 DEBUG (Thread-3) [pyhap.accessory_driver] Sending event to client: ('192.168.10.237', 49178) 2018-12-07 17:59:27 DEBUG (Thread-3) [pyhap.hap_server] exception [Errno 9] Bad file descriptor for ('192.168.10.237', 49178) in push_event() 2018-12-07 17:59:27 DEBUG (Thread-3) [pyhap.hap_server] Connection timeout for ('192.168.10.237', 49178) with exception [Errno 9] Bad file descriptor 2018-12-07 17:59:27 DEBUG (Thread-3) [pyhap.hap_server] Current connections {('192.168.10.237', 49178): <pyhap.hap_server.HAPSocket object at 0x72cfc810>, ('192.168.10.166', 58935): <pyhap.hap_server.HAPSocket object at 0x70538890>, ('192.168.10.208', 49204): <pyhap.hap_server.HAPSocket object at 0x7042c190>, ('192.168.10.188', 49968): <pyhap.hap_server.HAPSocket object at 0x6eab44b0>, ('192.168.10.222', 49184): <pyhap.hap_server.HAPSocket object at 0x7356b8f0>, ('192.168.10.237', 49179): <pyhap.hap_server.HAPSocket object at 0x70426c70>} 2018-12-07 17:59:27 DEBUG (Thread-3) [pyhap.accessory_driver] Could not send event to ('192.168.10.237', 49178), probably stale socket. 2018-12-07 17:59:27 DEBUG (Thread-3) [pyhap.accessory_driver] Sending event to client: ('192.168.10.208', 49204) 2018-12-07 17:59:27 DEBUG (Thread-3) [pyhap.accessory_driver] Sending event to client: ('192.168.10.237', 49179) 2018-12-07 17:59:27 DEBUG (Thread-3) [pyhap.accessory_driver] Sending event to client: ('192.168.10.166', 58935) 2018-12-07 17:59:27 DEBUG (Thread-3) [pyhap.hap_server] exception [Errno 9] Bad file descriptor for ('192.168.10.166', 58935) in push_event() 2018-12-07 17:59:27 DEBUG (Thread-3) [pyhap.hap_server] Connection timeout for ('192.168.10.166', 58935) with exception [Errno 9] Bad file descriptor 2018-12-07 17:59:27 DEBUG (Thread-3) [pyhap.hap_server] Current connections {('192.168.10.166', 58935): <pyhap.hap_server.HAPSocket object at 0x70538890>, ('192.168.10.208', 49204): <pyhap.hap_server.HAPSocket object at 0x7042c190>, ('192.168.10.188', 49968): <pyhap.hap_server.HAPSocket object at 0x6eab44b0>, ('192.168.10.222', 49184): <pyhap.hap_server.HAPSocket object at 0x7356b8f0>, ('192.168.10.237', 49179): <pyhap.hap_server.HAPSocket object at 0x70426c70>} 2018-12-07 17:59:27 DEBUG (Thread-3) [pyhap.accessory_driver] Could not send event to ('192.168.10.166', 58935), probably stale socket.

cdce8p commented 5 years ago

I noticed the Bad file descriptor exception. Looks like HAP-python tries to send something to already closed sockets. However I don't know if that's also the reason all accessories turn unresponsive. @ikalchev

ikalchev commented 5 years ago

Unfortunately I am traveling now, I will have a look at the issue over the weekend. You all see the issue only on a RPi right?

gabgabe commented 5 years ago

RPi 3 B Home Assistant 83.3 on Hass.os

Also disabled IPv6 on RPi Tried various routers remaining on ddwrt Apple TV on wifi RPi on ethernet

jr3us commented 5 years ago

Rpi 3b also using hassbian

weichensw commented 5 years ago

Hi @jr3us, it looks like you run into a similar issue I got before, and it seems not HAP-python's fault.

During my debugging, I found that

In the latter case, what happens on my home network is as follows:

So if you are already in this situation, you need to either: