ebaauw / homebridge-nb

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

Problem: press Nuki bridge button to obtain token #119

Closed StefanGebhardt closed 1 year ago

StefanGebhardt commented 1 year ago

Hi,

I find in my log of the homebridge these entries:

_[29.8.2023, 14:30:39] [Nuki] warning: Nuki bridge button not pressed [29.8.2023, 14:30:39] [Nuki] Nuki_Bridge_0C2A77A2: press Nuki bridge button to obtain token [29.8.2023, 14:30:54] [Nuki] Nuki_Bridge_C2A77A2: subscribe to event notifications [29.8.2023, 14:30:55] [Nuki] Nuki_Bridge_C2A77A2: request 76: GET /callback/add?url=http%3A%2F%2F192.168.178.55%3A37039%2Fnotify%2FC2A77A2 [29.8.2023, 14:30:55] [Nuki] Nuki_Bridge_C2A77A2: warning: request 76: error: http status 503 Service Unavailable [29.8.2023, 14:30:55] [Nuki] Nuki_BridgeC2A77A2: warning: heartbeat error: http status 503 Service Unavailable

After pressing the button on the nuki bridge everything seems ok:

_[29.8.2023, 14:35:17] [Nuki] Nuki_Bridge_C2A77A2: Nuki Bridge v1.24.0 C2A77A2 at 192.168.178.26:8080 [29.8.2023, 14:35:17] [Nuki] Nuki_Bridge_C2A77A2: Configured Name: warning: 4 listeners [29.8.2023, 14:35:17] [Nuki] Nuki_Bridge_C2A77A2: Heartrate: warning: 4 listeners [29.8.2023, 14:35:17] [Nuki] Nuki_Bridge_C2A77A2: Restart: warning: 4 listeners [29.8.2023, 14:35:17] [Nuki] Nuki_Bridge_C2A77A2: Log Level: warning: 4 listeners [29.8.2023, 14:35:17] [Nuki] NukiBridgeC2A77A2: Configured Name: warning: 4 listeners [29.8.2023, 14:35:17] [Nuki] Nuki_Bridge_C2A77A2: warning: recommended version: Nuki Bridge v2.15.0 [29.8.2023, 14:35:17] [Nuki] Nuki_Bridge_C2A77A2: warning: unclean shutdown - checking for stale subscriptions [29.8.2023, 14:35:17] [Nuki] Nuki_Bridge_C2A77A2: subscribe to event notifications [29.8.2023, 14:35:18] [Nuki] Nuki_Bridge_C2A77A2: error: too many callbacks registered [29.8.2023, 14:35:18] [Nuki] Nuki_BridgeC2A77A2: Last Updated: set to "Tue Aug 29 2023 14:35:18" (from "Tue Aug 29 2023 13:40:55") [29.8.2023, 14:35:18] [Nuki] HWR: Nuki Smart Lock 1.0 v1.14.1 nnnnnnnn [29.8.2023, 14:35:18] [Nuki] HWR: Configured Name: warning: 4 listeners [29.8.2023, 14:35:18] [Nuki] HWR: Lock Target State: warning: 4 listeners [29.8.2023, 14:35:18] [Nuki] HWR: Unlatch: warning: 4 listeners [29.8.2023, 14:35:18] [Nuki] HWR Battery: Configured Name: warning: 4 listeners [29.8.2023, 14:35:18] [Nuki] Haustür: Nuki Smart Lock 3.0 v3.6.9 nnnnnnnn [29.8.2023, 14:35:18] [Nuki] Haustür: Configured Name: warning: 4 listeners [29.8.2023, 14:35:18] [Nuki] Haustür: Lock Target State: warning: 4 listeners [29.8.2023, 14:35:18] [Nuki] Haustür: Unlatch: warning: 4 listeners [29.8.2023, 14:35:18] [Nuki] Haustür Battery: Configured Name: warning: 4 listeners

After some minutes I get this: _[29.8.2023, 14:37:17] [Nuki] Nuki_Bridge_C2A77A2: subscribe to event notifications [29.8.2023, 14:37:17] [Nuki] Nuki_Bridge_C2A77A2: error: too many callbacks registered [29.8.2023, 14:37:17] [Nuki] Nuki_BridgeC2A77A2: Last Updated: set to "Tue Aug 29 2023 14:37:18" (from "Tue Aug 29 2023 14:36:18")

And a bit later the above mentioned problem occours again.

Any idea? Thank you, Stefan

ebaauw commented 1 year ago

Did you try and power cycle the Nuki bridge and restart Homebridge?

StefanGebhardt commented 1 year ago

Thanks for the fast reply and spending time on my issue.

In the past I rebooted, but seperately. Now I tried directly one after another and the log changed: [29.8.2023, 21:11:16] [Nuki] Nuki_Bridge_C2A77A2: subscribe to event notifications [29.8.2023, 21:11:16] [Nuki] Nuki_Bridge_C2A77A2: error: too many callbacks registered [29.8.2023, 21:11:16] [Nuki] Nuki_Bridge_C2A77A2: Last Updated: set to "Tue Aug 29 2023 21:11:16" (from "Tue Aug 29 2023 21:10:16")

I will have an eye on it and have a look if I have a fallback to the error. I will report.

Thank you again

ebaauw commented 1 year ago

See closed issues for the “too many callbacks” error cause and resolution. Homebridge NB will still work, but the Nuki bridge won’t send notifications, causing a delay in detecting state changes.

StefanGebhardt commented 1 year ago

I did nothing :-)

12 hours later and the same error again:

_[30.8.2023, 13:12:49] [Nuki] Nuki_Bridge_0C2A77A2: press Nuki bridge button to obtain token [30.8.2023, 13:13:16] [Nuki] Nuki_Bridge_C2A77A2: subscribe to event notifications [30.8.2023, 13:13:16] [Nuki] Nuki_Bridge_C2A77A2: request 998: GET /callback/add?url=http%3A%2F%2F192.168.178.55%3A35575%2Fnotify%2FC2A77A2 [30.8.2023, 13:13:16] [Nuki] Nuki_Bridge_C2A77A2: warning: request 998: error: http status 503 Service Unavailable [30.8.2023, 13:13:16] [Nuki] Nuki_Bridge_C2A77A2: warning: heartbeat error: http status 503 Service Unavailable [30.8.2023, 13:13:20] [Nuki] warning: Nuki bridge button not pressed [30.8.2023, 13:13:20] [Nuki] Nuki_Bridge0C2A77A2: press Nuki bridge button to obtain token

Is it a problem because I had the "too many callbacks" for a much too long time? (saw the solution but had no time yet to solve the problem)

ebaauw commented 1 year ago

I fear you might have hit a bug in Homebridge NB introduced in v1.4.6. Note the subtle difference in the bridge name between the “press button” and other messages. v1.4.6 now uses 8 hex digits for the bridge ID, but not consistently. You bridge ID is smaller than 0x0FFFFFFF, resulting in a leading 0.

To confirm, could you check whether you still get these messages for v1.4.5? You still might need to clear the callbacks.

if you still run into issues in v1.4.5, please re-install the latest version, make sure Homebridge is running in DEBUG mode, and capture and attach the Homebridge log file.

StefanGebhardt commented 1 year ago

Thank you again. I downgraded to 1.4.5 and had to clear the callbacks. Now no problems, just the update status line _[30.8.2023, 18:39:47] [Nuki] Nuki_BridgeC2A77A2: Last Updated: set to "Wed Aug 30 2023 18:39:46" (from "Wed Aug 30 2023 18:38:46")

I will have a look if the problem occours again and then upgrade to 1.4.7 again. You'll get an info.

What I watched when pressing the button was this line _[30.8.2023, 18:22:09] [Nuki] Nuki_BridgeC2A77A2: warning: recommended version: Nuki Bridge v2.15.0

My bridge has the firmware 1.24.0 - and is not upgradable. Could it also be a hint for problems? Any incompatibility?

ebaauw commented 1 year ago

I think there's two hardware versions of the bridge, one with 2.x firmware and one with 1.x firmware, see https://developer.nuki.io/t/nuki-bridge-firmware-release-notes-public-releases/2797. I wouldn't know how to idenitify te models (other than the firmware version), nor what the differences are.

My bridge reports 2.15.0, and that's the version I develop and test Homebridge NB against, hence the warning.

ebaauw commented 1 year ago

Should be fixed in v1.4.8.

StefanGebhardt commented 1 year ago

It runned two days with 1.4.7 without any further problem. I just upgraded to 1.4.8 and will see. Thank you so much for your fast replies and your perfect support :-)

ghost-ps commented 1 year ago

@ebaauw, thanks for the update to 1.4.8, I had the same problem with one of my two Nuki Bridges!

Now with 1.4.8 everything runs smoothly and without any problems, I think this issue can be closed. 👍

Since 1.4.6 I had constantly the following in the log and I had to go back to 1.4.5 to get it working properly.


[28/07/2023, 22:33:15] [Nuki] homebridge-nb v1.4.6, node v18.17.0, homebridge v1.6.1, homebridge-lib v6.4.0
[28/07/2023, 22:33:15] [Nuki] Nuki_Bridge_B970AF0: Nuki Bridge v1.24.0 B970AF0 at 192.168.2.165:8080
[28/07/2023, 22:33:15] [Nuki] Nuki_Bridge_18D14BCB: Nuki Bridge v2.15.0 18D14BCB at 192.168.2.133:8080
[28/07/2023, 22:33:15] Homebridge v1.6.1 (HAP v0.11.1) (Nuki) is running on port 57222.
[28/07/2023, 22:33:15] [Nuki] hardware: Raspberry Pi 4B 1.2 (4GB)
[28/07/2023, 22:33:15] [Nuki] os: Raspbian GNU/Linux 11 (bullseye) [32 bit]
[28/07/2023, 22:33:15] [Nuki] restored 6 accessories from cache
[28/07/2023, 22:33:16] [Nuki] Nuki_Bridge_B970AF0: warning: recommended version: Nuki Bridge v2.15.0
[28/07/2023, 22:33:16] [Nuki] listening on http://0.0.0.0:43257/notify

[28/07/2023, 22:43:11] [Nuki] Nuki_Bridge_0B970AF0: press Nuki bridge button to obtain token
[28/07/2023, 22:43:16] [Nuki] Nuki_Bridge_B970AF0: warning: request 33: error: http status 503 Service Unavailable
[28/07/2023, 22:43:16] [Nuki] Nuki_Bridge_B970AF0: warning: heartbeat error: http status 503 Service Unavailable
[28/07/2023, 22:43:41] [Nuki] warning: Nuki bridge button not pressed
[28/07/2023, 22:43:41] [Nuki] Nuki_Bridge_0B970AF0: press Nuki bridge button to obtain token

[28/07/2023, 22:45:14] [Nuki] warning: Nuki bridge button not pressed
[28/07/2023, 22:45:14] [Nuki] Nuki_Bridge_0B970AF0: press Nuki bridge button to obtain token
[28/07/2023, 22:45:16] [Nuki] Nuki_Bridge_B970AF0: warning: request 36: error: http status 503 Service Unavailable
[28/07/2023, 22:45:16] [Nuki] Nuki_Bridge_B970AF0: warning: heartbeat error: http status 503 Service Unavailable
[28/07/2023, 22:45:45] [Nuki] Nuki_Bridge_B970AF0: Configured Name: warning: 2 listeners
[28/07/2023, 22:45:45] [Nuki] Nuki_Bridge_B970AF0: Nuki Bridge v1.24.0 B970AF0 at 192.168.2.165:8080
[28/07/2023, 22:45:45] [Nuki] Nuki_Bridge_B970AF0: Configured Name: warning: 2 listeners
[28/07/2023, 22:45:45] [Nuki] Nuki_Bridge_B970AF0: Heartrate: warning: 2 listeners
[28/07/2023, 22:45:45] [Nuki] Nuki_Bridge_B970AF0: Restart: warning: 2 listeners
[28/07/2023, 22:45:45] [Nuki] Nuki_Bridge_B970AF0: Log Level: warning: 2 listeners
[28/07/2023, 22:45:45] [Nuki] Nuki_Bridge_B970AF0: Configured Name: warning: 2 listeners
[28/07/2023, 22:45:46] [Nuki] Nuki_Bridge_B970AF0: warning: recommended version: Nuki Bridge v2.15.0
[28/07/2023, 22:45:46] [Nuki] Nuki_Bridge_B970AF0: warning: unclean shutdown - checking for stale subscriptions
StefanGebhardt commented 1 year ago

And also with 1.4.8 no problems any more. Thank you!