ebaauw / homebridge-nb

Homebridge plugin for Nuki Bridge
Apache License 2.0
51 stars 3 forks source link

Unclean shutdown cleanup doesn't work: too many callbacks registered #109

Closed nihalgonsalves closed 1 year ago

nihalgonsalves commented 1 year ago

Related: #5

I get the unclean shutdown warning which checks for stale subscriptions, but still get the too many callbacks registered error occasionally and then have to manually clear the subscriptions.

[NB] Nuki_Bridge_XXXXXXXX: warning: unclean shutdown - checking for stale subscriptions
[NB] listening on http://0.0.0.0:46199/notify
[NB] Nuki_Bridge_XXXXXXXX: subscribe to event notifications
[NB] Nuki_Bridge_XXXXXXXX: error: too many callbacks registered
[NB] Nuki_Bridge_XXXXXXXX: Last Updated: set to "Thu Jun 01 2023 19:33:54" (from "Thu Jun 01 2023 19:32:58")
[NB] Nuki_Bridge_XXXXXXXX: subscribe to event notifications
[NB] Nuki_Bridge_XXXXXXXX: error: too many callbacks registered
[NB] Nuki_Bridge_XXXXXXXX: Last Updated: set to "Thu Jun 01 2023 19:34:54" (from "Thu Jun 01 2023 19:33:54")
[NB] Nuki_Bridge_XXXXXXXX: subscribe to event notifications
[NB] Nuki_Bridge_XXXXXXXX: error: too many callbacks registered
[NB] Nuki_Bridge_XXXXXXXX: Last Updated: set to "Thu Jun 01 2023 19:35:54" (from "Thu Jun 01 2023 19:34:54")
[NB] Nuki_Bridge_XXXXXXXX: subscribe to event notifications
[NB] Nuki_Bridge_XXXXXXXX: error: too many callbacks registered
[NB] Nuki_Bridge_XXXXXXXX: Last Updated: set to "Thu Jun 01 2023 19:36:54" (from "Thu Jun 01 2023 19:35:54")
[NB] Nuki_Bridge_XXXXXXXX: subscribe to event notifications
[NB] Nuki_Bridge_XXXXXXXX: error: too many callbacks registered
[NB] Nuki_Bridge_XXXXXXXX: Last Updated: set to "Thu Jun 01 2023 19:37:54" (from "Thu Jun 01 2023 19:36:54")

When I manually check the callback list, it looks like this:

{
  "callbacks": [
    {
      "id": 0,
      "url": "http://192.168.x.x:35405/notify/XXXXXXXX"
    },
    {
      "id": 1,
      "url": "undefined"
    },
    {
      "id": 2,
      "url": "undefined"
    }
  ]
}

So I see two issues:

  1. This is the only software I have that interacts with the bridge, so the undefined values are probably also coming from here.
  2. The port on the current instance differs from prior callbacks (see ID 1, that is the IP of the server).

I would propose changing the check here to check both for an invalid URL and a partial match (e.g. ignoring the port) and cleaning those up:

https://github.com/ebaauw/homebridge-nb/blob/0aacaba41b0ae21fc9ce3b869468704af139d7f7/lib/NbAccessory.js#LL163C12-L163C12

Happy to contribute the fix if that sounds good to you!

ebaauw commented 1 year ago

I get the unclean shutdown warning

In that case, you better make sure to shutdown Homebridge cleanly.

I would propose changing the check here to check both for an invalid URL and a partial match (e.g. ignoring the port) and cleaning those up:

Sorry, that doesn't sound good. It's bad form for Homebridge NB to mess with callbacks by other clients of the Nuki bridge (even other instances of Homebridge NB). You can use nb in a script to remove any or all callbacks before starting Homebridge, if you want. But I'm not accepting this functionality in Homebridge NB.

This is the only software I have that interacts with the bridge, so the undefined values are probably also coming from here.

Please run Homebridge NB with debug logging enabled to catch it in the act of creating the "undefined" callbacks. I don't like "probably", especially since I've never seen this myself. And if the invalid callback is indeed somehow created by Homebridge NB, that should be fixed, by preventing the callback from being created in the first place, rather than providing a workaround, by deleting the callback.

The port on the current instance differs from prior callbacks (see ID 1, that is the IP of the server).

That's by design - by default, Homebridge NB uses a random, unused port when creating the web server to receive the callbacks. You can set port in config.json, to specify a fixed port, but then you need to make sure that port isn't already used.
The port is persisted under callbackUrl in cachedAccessories. When Homebridge shuts down cleanly, Homebridge NB removes the callback and deletes the callbackUrl from cachedAccesories. When Homebridge crashes, the callbackUrl remains in cachedAccessoires, so Homebridge NB deletes the callback for that URL. This logic is needed to support multiple instances of Homebridge NB against the same Nuki bridge (which I need for testing).

ebaauw commented 1 year ago

Double-checking the code, I don't see how Homebridge NB could make a call for an undefined callback URL, but there was no explicit check against that. Above commit adds this, just to be sure.

nihalgonsalves commented 1 year ago

I see, thanks for the clarification. I didn't realise that the port was cached and checked. I'm not sure where the undefined came from, but could have been a leftover from a different plugin I used in the past I suppose.

I guess it would be possible to clean up only callbacks created by this plugin by using an unique identifier in the URL (/notify/{some-platform-uuid}/{bridge-id}), but I don't know whether it's possible to have a persistent ID on a platform (and not the accessory context).

Either way, what do you think about setting the lock state as "unknown" if a callback cannot be registered? This is exposed in the Home app, so it would be a good way to know if something is wrong (e.g. also in the case of the bridge being unresponsive). Currently the lock action simply gets stuck in an "in progress" state when the bridge is not responsive, and notifications silently do not work.

This is the characteristic: https://github.com/homebridge/HAP-NodeJS/blob/9c9bd7101b2ab520a237c09da8017d18a5c2c7cc/src/lib/definitions/CharacteristicDefinitions.ts#L1939-L1960

ebaauw commented 1 year ago

Homebridge NB is fully functional when the callback cannot be registered or fails otherwise. It polls the Nuki bridge to get the (cached) states of connected smart locks and openers. The HomeKit states are updated, albeit with a delay. Press Identify on the lock accessory to have the Nuki bridge contact the device to refresh the cached state (the last contact with the device is reflected in Last Updated).

nihalgonsalves commented 1 year ago

While that works, I still don't have a way to proactively know when there's a connection issue, which would show up at the top of the home app if it was instead exposed as unknown.

And the case of an unavailable bridge isn't handled by polling - for example when the bridge has lost its WiFi connection or is unresponsive.

But we can close this for now if that's not something you want in the plugin. Thanks for the quick response and building the plugin!

ebaauw commented 1 year ago

If the Nuki bridge cannot be reached, Homebridge NB sets Status Fault. Apple’s Home app ignores this, but decent HomeKit apps will show a warning sign. I’ll have to see if I can also set lock state to unknown in that case. I think I already set that, when the bridge reports an unknown state.