Intermittent Homebridge Hangs

[Colorado4Wheeler]

This has happened two or three times since the very start of the project, so it's not very often, but I've noticed that sometimes Homebridge can hang and just stop responding. This happened last night when my HomePod kept telling me that it couldn't reach HomeKit no matter what I asked it to do. When I looked at my iOS device every device on every server showed "No response" and I thought maybe I was having an issue like #70 did yesterday with a blow up, but I noticed that my Hue bulbs were just fine. Restarting the plugin, which in turn forces a restart of Homebridge, solved the issue instantly. I checked that the API was still answering at it was, just Homebridge crapped out.

I don't recall ever having this problem with the original HB builds but I don't know that I had so many running at once either (I run 8 servers right now), but I suspect there might be something that may be puking in the script but it's not often enough to be a major issue at this point.

[webdeck]

Please provide a log when that happens.

[Colorado4Wheeler]

Ok, so it happened again, all HKB servers up and running and the API's responding but every single device across every single server showed as "No Response" in Homebridge. Not a single error in the logs, but once I bounced Homebridge on each server it all came right back up to normal again. I do have the logs from 8 or so servers if you want them but they look 100% normal, it's just like Homebridge simply stopped responding.

[Colorado4Wheeler]

Just "sort of" happened again, everything was "updating" for quite a while, 3-4 minutes so I went to look at the API and logs and it all went to "No response" again then it just sort of kicked in and worked. Again, the logs show no errors and it was only for a single server, other servers seemed to be OK.

[webdeck]

Can you send logs? Theory is that one of the calls back to HKB is hanging waiting for a response, because I serialize the requests to a single thread so that you don't get multiple callbacks in parallel.

[Colorado4Wheeler]

Sure, here you go. The API is multi-threaded, I'm not sure if that would or could cause an issue with multiple requests, I suppose you could try it on your end and see how it works but theoretically the API should be able to handle as many requests as you throw at it. There are some performance things I'm working on to try to speed things up, but even with 80 or so devices on one server the full request only takes 5-8 seconds or so.

8servers.txt
sortofhang.txt

[webdeck]

Roughly, what was the time of the hang?

[Colorado4Wheeler]

I pulled the log a couple of minutes after the hang, you can see the time stamp on the console log. I would say 3 to 5 minutes or so.

[Colorado4Wheeler]

Other than those, the servers update pretty fast, I just watched a full update complete in a second or two. That’s what makes these incidents stand out.

[webdeck]

Odd... the last request from HomeKit was:

[2018-3-26 20:38:09] [HomeKit Bridge Server] Bedroom Entry: get(On) => false

Everything after that was updates to devices from HKB, which were bring processed successfully. I can't explain how homebridge would stop responding to HomeKit - that shouldn't be possible unless something crashed, and there's nothing in the log saying there was a crash or an error of any sort. HKB requests are processed by a different thread, and that thread kept working - it's homebridge itself that stopped working, not the homebridge-indigo2 plugin.

[webdeck]

On top of that, get() calls from homebridge just return a cached value - they don't call out to HKB, so there isn't really much code there at all to fail.

[Colorado4Wheeler]

Oh I don’t doubt it, I didn’t suspect the plugin but didn’t know what, if anything, could be done to stabilize it. It didn’t do this in HBB so maybe it’s this build of HB or about how we are talking to it. How often do you auto callback? I could write something that says “if HB hasn’t phoned home in X then bounce the server”. What do you think?

[webdeck]

In theory, at this point, HKB only gets called when someone updates a characteristic value via HomeKit.

[Colorado4Wheeler]

For some reason I thought it was checking in periodically. Was this the same in the HBB build?

[webdeck]

This is different. homebridge-indigo would call to Indigo RESTful API for every get from HomeKit. For this, since you always tell me when state changes, I just cache those values and return them immediately for every HomeKit get request. I only call out to you for HomeKit set requests and the initial device list query.

[Colorado4Wheeler]

Gotcha. I wonder if this glitch is why I keep losing devices from rooms and scenes like it’s a fresh install. Happened four times this week already, I’ve given up trying to keep it organized, but only on one server, the others are staying intact. I’m still experiment and will keep you posted.