benzman81 / homebridge-nukiio

Nuki.io support for Homebridge: https://github.com/nfarina/homebridge
GNU General Public License v3.0
42 stars 6 forks source link

Nuki opens 2 x #93

Open martin0675 opened 2 years ago

martin0675 commented 2 years ago

Hallo Markus, vorab vielen Dank für Dein Plugin. Es erleichtert unseren Alltag ungemein. Ich habe in 2 Häusern seit einiger Zeit das gleiche Problem: Wenn ich über Homekit oder Homebridge öffne ("unlatch"), öffnet Nuki die Tür 2 Mal direkt hintereinander. Hast Du einen Tipp für mich, woran das liegen könnte?

Vielen Dank & Grüße, Martin

[23/06/2022, 12:41:19] [homebridge-nukiio] Request to Nuki bridge 'http://192.168.1.60:8080' finished with status code '200' and body '{"success": true, "batteryCritical": false, "batteryCharging": false, "batteryChargeState": 42}'. null [23/06/2022, 12:41:19] [homebridge-nukiio] HomeKit state change complete. [23/06/2022, 12:41:20] [homebridge-nukiio] Process lock action '3' for Nuki lock '74763181' (instance id '0') on Nuki bridge 'http://192.168.1.60:8080'. [23/06/2022, 12:41:20] [homebridge-nukiio] Send request to Nuki bridge 'http://192.168.1.60:8080' on '/lockAction' with '{"nukiId":"74763181","deviceType":0,"action":"3","token":"36586"}'. [23/06/2022, 12:41:20] [homebridge-nukiio] HomeKit change for door latch back to locked state complete. [23/06/2022, 12:41:26] [homebridge-nukiio] [INFO Nuki WebHook Server] Updated lock state from webhook to isLocked = 'false' (Nuki state '5' ) for lock '74763181' (instance id '0') with batteryCritical = 'false', battery charging = 'false', battery charge state = '42', contactClosed = 'true' and mode = '2', ringactionState = 'false'. [23/06/2022, 12:41:26] [homebridge-nukiio] HomeKit state change by webhook complete. New isLocked = 'false' and batteryCritical = 'false', battery charging = 'false', battery charge state = '42' and contactClosed = 'true'. [23/06/2022, 12:41:28] [Haustür Öffnen] locking Haustür Öffnen 1 [23/06/2022, 12:41:28] [Haustür Öffnen] 1 Haustür Öffnen [23/06/2022, 12:41:28] [homebridge-nukiio] Request to Nuki bridge 'http://192.168.1.60:8080' finished with status code '200' and body '{"success": true, "batteryCritical": false, "batteryCharging": false, "batteryChargeState": 42}'. null [23/06/2022, 12:41:28] [homebridge-nukiio] HomeKit state change complete. [23/06/2022, 12:41:29] [homebridge-nukiio] HomeKit change for door latch back to locked state complete. [23/06/2022, 12:41:30] [Haustür Öffnen] locking Haustür Öffnen 1 [23/06/2022, 12:41:30] [Haustür Öffnen] 1 Haustür Öffnen [23/06/2022, 12:41:38] [homebridge-nukiio] [INFO Nuki WebHook Server] Updated lock state from webhook to isLocked = 'false' (Nuki state '3' ) for lock '74763181' (instance id '0') with batteryCritical = 'false', battery charging = 'false', battery charge state = '42', contactClosed = 'true' and mode = '2', ringactionState = 'false'. [23/06/2022, 12:41:38] [homebridge-nukiio] HomeKit state change by webhook complete. New isLocked = 'false' and batteryCritical = 'false', battery charging = 'false', battery charge state = '42' and contactClosed = 'true'.

benzman81 commented 2 years ago

@martin0675 sorry für die späte antwort. wieso hast du das issue geschlossen? Ich hab selbst das problem seit kurzem. Code seitig wurde nix angepasst. Ggf arbeitet die bridge seit einem update anders. Bin noch nicht dahinter gestiegen :-(

benzman81 commented 2 years ago

@martin0675 might be related to this: https://developer.nuki.io/t/lockaction-response-is-negative-without-error-even-if-lockaction-was-executed-successfully/16093

martin0675 commented 2 years ago

Hallo Markus, danke für Deine Antwort. Zwischendurch war ich mir nicht mehr sicher, ob das Problem direkt von Deinem PlugIn verursacht wird. Es ist aber nach wie vor so, daß es viele Monate stabil funktioniert hatte, ohne das ich etwas geändert hätte. Irgendwann begann es in beiden Häusern 2 x zu öffnen. Wenn ich nicht der Einzige bin, freue ich mich über weitere Infos zur Lösung bzw. helfe gerne mit bei der Suche.

Danke & Grüße, Martin

Am 15.07.2022 um 22:39 schrieb Markus Krüger @.***>:

@martin0675 https://github.com/martin0675 sorry für die späte antwort. wieso hast du das issue geschlossen? Ich hab selbst das problem seit kurzem. Code seitig wurde nix angepasst. Ggf arbeitet die bridge seit einem update anders. Bin noch nicht dahinter gestiegen :-(

— Reply to this email directly, view it on GitHub https://github.com/benzman81/homebridge-nukiio/issues/93#issuecomment-1185899732, or unsubscribe https://github.com/notifications/unsubscribe-auth/AR7DYQPFSK4T25B6PNI5Z43VUHD6TANCNFSM5ZT5KNVA. You are receiving this because you were mentioned.

martin0675 commented 2 years ago

Zur Info: Um hardwareseitige Probleme auszuschließen, hatte ich eine neue Bridge, als auch ein neues Schloß getestet. Das Verhalten war aber identisch geblieben (öffnet 2 x). Hardware und Verbindungsprobleme würde ich also ausschließen. Übrigens hatte ich das Nuki Smart Lock 3.0 Pro getestet - es läuft auch wunderbar über Dein PlugIn (abgesehen vom aktuellen Problem).

benzman81 commented 2 years ago

irgendwie bekomm ich keine mails mehr von github, daher die späte antwort.

Ich hab das auch täglich. Es scheint mir so, als ob sich entweder and Apple Homekit oder am Verhalten der Nuki Bridge etwas geändert zu haben. Ich guck dann immer in http://bridgeURL/logs und in die homebridge logs, aber ich konnte bisher noch nicht feststellen, warum das verhalten so ist. Die homebridge logs zeigen keine fehler sondern führen den befehl nur zweimal aus, aber auch nicht immer. Wenn du was raus findest, immer her damit.

martin0675 commented 2 years ago

Hallo Markus, ich hatte alles noch mal neu installiert und seit dem ist es wieder in Ordnung. Welcher Schritt genau zum Erfolg geführt hat, kann ich leider nicht so genau sagen. Ich habe dabei auch alle Homekit-Hubs neu gestartet, was bei anderen Fehlerchen gelegentlich ebenfalls half. Ist wirklich nervig wenn man nicht weiß, woran es liegt…

Nochmals danke für Dein PlugIn und das damit verbundene Engagement für die Homebridge-Gemeinde. Finde ich klasse!!!

Viele Grüße, Martin

Am 29.07.2022 um 09:25 schrieb Markus Krüger @.***>:

irgendwie bekomm ich keine mails mehr von github, daher die späte antwort.

Ich hab das auch täglich. Es scheint mir so, als ob sich entweder and Apple Homekit oder am Verhalten der Nuki Bridge etwas geändert zu haben. Ich guck dann immer in http://bridgeURL/logs und in die homebridge logs, aber ich konnte bisher noch nicht feststellen, warum das verhalten so ist. Die homebridge logs zeigen keine fehler sondern führen den befehl nur zweimal aus, aber auch nicht immer. Wenn du was raus findest, immer her damit.

— Reply to this email directly, view it on GitHub https://github.com/benzman81/homebridge-nukiio/issues/93#issuecomment-1198963629, or unsubscribe https://github.com/notifications/unsubscribe-auth/AR7DYQNX3VBJRQKIP7ISVSLVWOBOZANCNFSM5ZT5KNVA. You are receiving this because you were mentioned.

benzman81 commented 2 years ago

Ich starte die hubs nächtlich neu und hab weiter ab und an die probleme. Issue lass ich solange offen.

pelo76 commented 1 year ago

Hi, hast du bereits etwas herausgefunden? Ich habe dein Plugin seit kurzem im Einsatz und habe das selbe Problem mit dem 2x öffnen - hier habe ich folgendes festgestellt:

Situation 1 - Schloss verriegelt: ich nutze den Öffner (DoorLatch) um zu entriegeln und gleichzeitig zu öffnen, dann öffnet er zweimal. Situation 2 - Schloss verriegelt: ich entriegel das Schloss erst und nutze dann im zweiten Step den Öffner, dann öffnet er nur einmal.

Ich glaube es liegt wie folgt: In der Situation 1 wird der Befehl Schloss öffnen und Öffner öffnen gesendet, aber das Schloß zurückmeldet, schloss geöffnet. Daher wird der Öffner erneut getätigt.

In Situation 2 wird erst Schloß öffnen und dann zurückgegeben, "Schloß geöffnet", erst dann wird der Öffner genutzt, und die Rückmeldung erfolgt, Öffner geöffnet...

benzman81 commented 1 year ago

Kannst du das Konstant nachvollziehen?

pelo76 commented 1 year ago

Ich gucke mir das gleich nochmal an und melde mich nach dem Essen

pelo76 commented 1 year ago

Ich habe mir die Logs Unterschiede zwischen HomeKit (HK) und HomeBridge (HB) mal angeschaut, dabei ist mit bei HK aufgefallen, dass der Schritt "lock state aborted" nicht durchgeführt wird, stattdessen wird "Process lock action '3' " ein zweites mal durchgeführt...

Ich selbst hoffe hier auf Dich - aber wie Du das beheben kannst (?)

Vielleicht hilft das weiter

Aufschließen mit Latch über HK:

8/15/2023, 6:47:39 PM] [NukiBridge] Getting current state for 'SwitchUnlatchAllowed'... [8/15/2023, 6:47:39 PM] [NukiBridge] Send request to Nuki bridge 'http://meine_ip:8080' on '/lockState' with '{"nukiId":"meine_ID","deviceType":0,"token":"mein_Token"}'. [8/15/2023, 6:47:40 PM] [NukiBridge] Request to Nuki bridge 'http://meine_ip:8080' finished with status code '200' and body '{"mode": 2, "state": 1, "stateName": "locked", "batteryCritical": false, "batteryCharging": false, "batteryChargeState": 86, "doorsensorState": 4, "doorsensorStateName": "door state unknown", "success": true}'. null [8/15/2023, 6:47:40 PM] [NukiBridge] Lock state is isLocked = 'true' (Nuki state '1' ) with battery critical = 'false', battery charging = 'false', battery charge state = '86', contactClosed = 'true' and mode = '2' [8/15/2023, 6:47:40 PM] [NukiBridge] Lock state is isLocked = 'true' (Nuki state '1' ) with battery critical = 'false', battery charging = 'false', battery charge state = '86', contactClosed = 'true' and mode = '2' [8/15/2023, 6:47:42 PM] [NukiBridge] Process lock action '3' for Nuki lock 'meine_ID' (instance id '0') on Nuki bridge 'http://meine_ip:8080'. [8/15/2023, 6:47:42 PM] [NukiBridge] Send request to Nuki bridge 'http://meine_ip:8080' on '/lockAction' with '{"nukiId":"meine_ID","deviceType":0,"action":"3","token":"mein_Token"}'. [8/15/2023, 6:47:51 PM] [NukiBridge] Getting current state for 'SwitchUnlatchAllowed'... [8/15/2023, 6:47:52 PM] [NukiBridge] Request to Nuki bridge 'http://meine_ip:8080' finished with status code '200' and body '{"success": true, "batteryCritical": false, "batteryCharging": false, "batteryChargeState": 86}'. null [8/15/2023, 6:47:52 PM] [NukiBridge] HomeKit state change complete. [8/15/2023, 6:47:52 PM] [NukiBridge] Send request to Nuki bridge 'http://meine_ip:8080' on '/lockState' with '{"nukiId":"meine_ID","deviceType":0,"token":"mein_Token"}'. [8/15/2023, 6:47:53 PM] [NukiBridge] Request to Nuki bridge 'http://meine_ip:8080' finished with status code '200' and body '{"mode": 2, "state": 3, "stateName": "unlocked", "batteryCritical": false, "batteryCharging": false, "batteryChargeState": 86, "doorsensorState": 2, "doorsensorStateName": "door closed", "success": true}'. null [8/15/2023, 6:47:53 PM] [NukiBridge] Lock state is isLocked = 'false' (Nuki state '3' ) with battery critical = 'false', battery charging = 'false', battery charge state = '86', contactClosed = 'true' and mode = '2' [8/15/2023, 6:47:53 PM] [NukiBridge] Lock state is isLocked = 'false' (Nuki state '3' ) with battery critical = 'false', battery charging = 'false', battery charge state = '86', contactClosed = 'true' and mode = '2' [8/15/2023, 6:47:53 PM] [NukiBridge] HomeKit change for door latch back to locked state complete. [8/15/2023, 6:47:54 PM] [NukiBridge] Process lock action '3' for Nuki lock 'meine_ID' (instance id '0') on Nuki bridge 'http://meine_ip:8080'. [8/15/2023, 6:47:54 PM] [NukiBridge] Send request to Nuki bridge 'http://meine_ip:8080' on '/lockAction' with '{"nukiId":"meine_ID","deviceType":0,"action":"3","token":"mein_Token"}'. [8/15/2023, 6:48:00 PM] [NukiBridge] Request to Nuki bridge 'http://meine_ip:8080' finished with status code '200' and body '{"success": true, "batteryCritical": false, "batteryCharging": false, "batteryChargeState": 86}'. null [8/15/2023, 6:48:00 PM] [NukiBridge] HomeKit state change complete. [8/15/2023, 6:48:01 PM] [NukiBridge] HomeKit change for door latch back to locked state complete.

Öffner mit Latch über HB

[8/15/2023, 7:44:01 PM] [NukiBridge] Getting current state for 'SwitchUnlatchAllowed'... [8/15/2023, 7:44:01 PM] [NukiBridge] Send request to Nuki bridge 'http://meine_IP:8080' on '/lockState' with '{"nukiId":"meine_ID","deviceType":0,"token":"mein_token"}'. [8/15/2023, 7:44:02 PM] [NukiBridge] Request to Nuki bridge 'http://meine_IP:8080' finished with status code '200' and body '{"mode": 2, "state": 1, "stateName": "locked", "batteryCritical": false, "batteryCharging": false, "batteryChargeState": 86, "doorsensorState": 4, "doorsensorStateName": "door state unknown", "success": true}'. null [8/15/2023, 7:44:02 PM] [NukiBridge] Lock state is isLocked = 'true' (Nuki state '1' ) with battery critical = 'false', battery charging = 'false', battery charge state = '86', contactClosed = 'true' and mode = '2' [8/15/2023, 7:44:02 PM] [NukiBridge] Lock state is isLocked = 'true' (Nuki state '1' ) with battery critical = 'false', battery charging = 'false', battery charge state = '86', contactClosed = 'true' and mode = '2' [8/15/2023, 7:44:02 PM] [NukiBridge] Getting current state for 'SwitchUnlatchAllowed'... [8/15/2023, 7:44:02 PM] [NukiBridge] Send request to Nuki bridge 'http://meine_IP:8080' on '/lockState' with '{"nukiId":"meine_ID","deviceType":0,"token":"mein_token"}'. [8/15/2023, 7:44:02 PM] [NukiBridge] Request to Nuki bridge 'http://meine_IP:8080' finished with status code '200' and body '{"mode": 2, "state": 1, "stateName": "locked", "batteryCritical": false, "batteryCharging": false, "batteryChargeState": 86, "doorsensorState": 4, "doorsensorStateName": "door state unknown", "success": true}'. null [8/15/2023, 7:44:02 PM] [NukiBridge] Lock state is isLocked = 'true' (Nuki state '1' ) with battery critical = 'false', battery charging = 'false', battery charge state = '86', contactClosed = 'true' and mode = '2' [8/15/2023, 7:44:02 PM] [NukiBridge] Lock state is isLocked = 'true' (Nuki state '1' ) with battery critical = 'false', battery charging = 'false', battery charge state = '86', contactClosed = 'true' and mode = '2' [8/15/2023, 7:44:05 PM] [NukiBridge] Getting current state for 'SwitchUnlatchAllowed'... [8/15/2023, 7:44:05 PM] [NukiBridge] Send request to Nuki bridge 'http://meine_IP:8080' on '/lockState' with '{"nukiId":"meine_ID","deviceType":0,"token":"mein_token"}'. [8/15/2023, 7:44:05 PM] [NukiBridge] Request to Nuki bridge 'http://meine_IP:8080' finished with status code '200' and body '{"mode": 2, "state": 1, "stateName": "locked", "batteryCritical": false, "batteryCharging": false, "batteryChargeState": 86, "doorsensorState": 4, "doorsensorStateName": "door state unknown", "success": true}'. null [8/15/2023, 7:44:05 PM] [NukiBridge] Lock state is isLocked = 'true' (Nuki state '1' ) with battery critical = 'false', battery charging = 'false', battery charge state = '86', contactClosed = 'true' and mode = '2' [8/15/2023, 7:44:06 PM] [NukiBridge] Lock state is isLocked = 'true' (Nuki state '1' ) with battery critical = 'false', battery charging = 'false', battery charge state = '86', contactClosed = 'true' and mode = '2' [8/15/2023, 7:44:07 PM] [NukiBridge] Process lock action '3' for Nuki lock 'meine_ID' (instance id '0') on Nuki bridge 'http://meine_IP:8080'. [8/15/2023, 7:44:07 PM] [NukiBridge] Send request to Nuki bridge 'http://meine_IP:8080' on '/lockAction' with '{"nukiId":"meine_ID","deviceType":0,"action":"3","token":"mein_token"}'. [8/15/2023, 7:44:16 PM] [NukiBridge] Getting current state for 'SwitchUnlatchAllowed'... [8/15/2023, 7:44:18 PM] [NukiBridge] Request to Nuki bridge 'http://meine_IP:8080' finished with status code '200' and body '{"success": true, "batteryCritical": false, "batteryCharging": false, "batteryChargeState": 86}'. null [8/15/2023, 7:44:18 PM] [NukiBridge] HomeKit state change complete. [8/15/2023, 7:44:18 PM] [NukiBridge] Send request to Nuki bridge 'http://meine_IP:8080' on '/lockState' with '{"nukiId":"meine_ID","deviceType":0,"token":"mein_token"}'. [8/15/2023, 7:44:18 PM] [NukiBridge] Request to Nuki bridge 'http://meine_IP:8080' finished with status code '503' and body 'HTTP 503 Unavailable'. null [8/15/2023, 7:44:18 PM] [NukiBridge] Request for lock state aborted. This is no problem and might happen due to canceled request or due to long response time of the Nuki bridge. Using cached value isLocked = 'false'. [8/15/2023, 7:44:18 PM] [NukiBridge] Request for lock state aborted. This is no problem and might happen due to canceled request or due to long response time of the Nuki bridge. Using cached value isLocked = 'false'. [8/15/2023, 7:44:19 PM] [NukiBridge] HomeKit change for door latch back to locked state complete. [8/15/2023, 7:44:19 PM] [NukiBridge] Getting current state for 'SwitchUnlatchAllowed'... [8/15/2023, 7:44:20 PM] [NukiBridge] Send request to Nuki bridge 'http://meine_IP:8080' on '/lockState' with '{"nukiId":"meine_ID","deviceType":0,"token":"mein_token"}'. [8/15/2023, 7:44:20 PM] [NukiBridge] Request to Nuki bridge 'http://meine_IP:8080' finished with status code '200' and body '{"mode": 2, "state": 3, "stateName": "unlocked", "batteryCritical": false, "batteryCharging": false, "batteryChargeState": 86, "doorsensorState": 4, "doorsensorStateName": "door state unknown", "success": true}'. null [8/15/2023, 7:44:20 PM] [NukiBridge] Lock state is isLocked = 'false' (Nuki state '3' ) with battery critical = 'false', battery charging = 'false', battery charge state = '86', contactClosed = 'true' and mode = '2' [8/15/2023, 7:44:20 PM] [NukiBridge] Lock state is isLocked = 'false' (Nuki state '3' ) with battery critical = 'false', battery charging = 'false', battery charge state = '86', contactClosed = 'true' and mode = '2'

Zum Vergleich hier die Schritte, wenn ich erst das Schloß öffne (lock action '1'), und danach den Öffner (lock action '3') nutze:

Aufschließen erst Schloss (7:40), dann Öffner (7:41) [8/15/2023, 7:40:27 PM] [NukiBridge] Send request to Nuki bridge 'http://meine_IP:8080' on '/lockState' with '{"nukiId":"meine_ID","deviceType":0,"token":"mein_token"}'. [8/15/2023, 7:40:28 PM] [NukiBridge] Request to Nuki bridge 'http://meine_IP:8080' finished with status code '200' and body '{"mode": 2, "state": 1, "stateName": "locked", "batteryCritical": false, "batteryCharging": false, "batteryChargeState": 86, "doorsensorState": 2, "doorsensorStateName": "door closed", "success": true}'. null [8/15/2023, 7:40:28 PM] [NukiBridge] Lock state is isLocked = 'true' (Nuki state '1' ) with battery critical = 'false', battery charging = 'false', battery charge state = '86', contactClosed = 'true' and mode = '2' [8/15/2023, 7:40:28 PM] [NukiBridge] Lock state is isLocked = 'true' (Nuki state '1' ) with battery critical = 'false', battery charging = 'false', battery charge state = '86', contactClosed = 'true' and mode = '2' [8/15/2023, 7:40:29 PM] [NukiBridge] Process lock action '1' for Nuki lock 'meine_ID' (instance id '0') on Nuki bridge 'http://meine_IP:8080'. [8/15/2023, 7:40:29 PM] [NukiBridge] Send request to Nuki bridge 'http://meine_IP:8080' on '/lockAction' with '{"nukiId":"meine_ID","deviceType":0,"action":"1","token":"mein_token"}'. [8/15/2023, 7:40:33 PM] [NukiBridge] Request to Nuki bridge 'http://meine_IP:8080' finished with status code '200' and body '{"success": true, "batteryCritical": false, "batteryCharging": false, "batteryChargeState": 86}'. null [8/15/2023, 7:40:33 PM] [NukiBridge] HomeKit state change complete.

[8/15/2023, 7:41:32 PM] [NukiBridge] Process lock action '3' for Nuki lock 'meine_ID' (instance id '0') on Nuki bridge 'http://meine_IP:8080'. [8/15/2023, 7:41:32 PM] [NukiBridge] Send request to Nuki bridge 'http://meine_IP:8080' on '/lockAction' with '{"nukiId":"meine_ID","deviceType":0,"action":"3","token":"mein_token"}'. [8/15/2023, 7:41:40 PM] [NukiBridge] Request to Nuki bridge 'http://meine_IP:8080' finished with status code '200' and body '{"success": true, "batteryCritical": false, "batteryCharging": false, "batteryChargeState": 86}'. null [8/15/2023, 7:41:40 PM] [NukiBridge] HomeKit state change complete. [8/15/2023, 7:41:41 PM] [NukiBridge] HomeKit change for door latch back to locked state complete.

pelo76 commented 1 year ago

Hast du eine Idee?

benzman81 commented 1 year ago

Guck ich mir am WE mal an. Danke für die Info schonmal.

benzman81 commented 1 year ago

@pelo76 kann ich bei mir so nicht nachvollziehen. Wenn ich das hab, dann immer ohne das aborted und zb nur bei geöffneter Tür und einem reinen unlatch. Ich hab mal eine version 0.16.1 veröffentlich mit temporärem zusätzlichen logging. Vielleicht hilft das, dem auf die spur zu kommen.

benzman81 commented 1 year ago

@pelo76 ich konnte mit dem extra logging, welches noch einen Dreher hatte, nun sehen, dass das schloss, auch wenn es schon aufgeschlossen ist, zweimal von Homebridge bzw HomeKit den Befehl zum setzen des States bekommt. Somit bekommt mein Plugin zweimal den Befehl zum unlatch, was das Plugin dann natürlich ausführt. Passiert ja nicht immer, aber ab und an. Als ich eben analysiert hab, hat der Request 8 Sekunden gebraucht. Hab das Gefühlt, dass wenn HomeKit nicht schnell genug Antwort bekommt, dann ggf. nochmal einen retry macht. Werd das weiter beobachten und mal ein bisschen ausprobieren, wenn ich was Zeit hab.

pelo76 commented 1 year ago

Hi, das hört sich nach einem Plan an - ich freue mich, wenn ich helfen konnte und wenn du da Problem lösen kannst…

Gruss Peter