Test Adapter Z-Wave 2 (v1.7.x)

[AlCalzone]

@Chris_78 sagte in Alpha-Test Adapter Z-Wave 2 (v1.7.x):

als Dead eingestuft

Das ist blöd - solange sie "unknown" sind, geht es nämlich.

Log bitte - am besten mit geleertem Cache, damit ich alles sehe.

[EvilEls]

Hi @AlCalzone!
Nach deinem Rat (https://forum.iobroker.net/topic/34739/test-adapter-z-wave-2-v1-4-x-1-5-0-1-6-x/202) auf 1.7zu wechseln. HIer die ersten Logs.

Schon vorab, der mit 1.6.3 auftretende Bug, dass der Adapter stehenbleibt, ist noch nicht aufgetreten. 1.7. läuft aber auch erst für ein paar h.

9.9.20.zip

Habe Logging aktiviert, kurz gewartet, Cache gelöscht, Interviews abgewartet.
Prinzipiell gingen diese schneller als bei 1.6.3
Allerdings konnte meine Node4 gar nicht interviewt werden. Dead-Alive-Loop.
Node4 ist ein qubino flush dimmer ZMNHDD1 H1S1P1 (unterstützt keine Secure Inclusion)

Ich habe dann ein paar Mal die Node3 über das targetValue verändert, was auch prima und sehr schnell funktioniert hat.
Dann habe ich noch ein paar Mal den Wandschalter bemüht und die Lampen rauf- und runter gedimmt. Dabei verändert sich nur das currentValue. targetValue blieb auf dem letzten in iobroker gesetzten Wert.

Selbes Prozedere habe ich dann mit dem scheintoten Node4 durchgeführt.
Beim ersten Schaltversuch mittels Änderung von targetValue im iobroker, hat das Gerät tatsächlich das Licht geschalten. Allerdings hat der currentValue sich nicht verändert.
https://forum.iobroker.net/topic/34414/test-adapter-z-wave-2-v1-3-x/62
bzw.
https://github.com/ioBroker/ioBroker.zwave/issues/84#issue-498239421
Erst bei nochmaligen Schalten, zog der currentValue zum targetValue gleich.
Weitere Versuchen über den iobroker zu Schalten, klappten nicht. Status des Gerät wechselte dabei immer zwischen dead und alive.
Das direkte Schalten am Wandschalter funktioniert und ändert auch den currentValue korrekt.

Besten Dank und viele Grüße!

EvilEls created this issue in ioBroker/ioBroker.zwave

open 🚩 Certain Object Values Not Updating For Single Node #84

[AlCalzone]

@EvilEls Laut deinem Log ist Node 4 secure eingebunden und kommuniziert auch secure

Es scheint allerdings keine Antwort zu geben bei der Abfrage einzelner Konfigurationsparameter und das wird im Code nicht korrekt abgefangen. Wird gefixt!

Dann habe ich noch ein paar Mal den Wandschalter bemüht und die Lampen rauf- und runter gedimmt. Dabei verändert sich nur das currentValue. targetValue blieb auf dem letzten in iobroker gesetzten Wert.

Das ist das derzeit erwartete Verhalten, da dein Gerät nur einen neuen currentValue meldet.

[EvilEls]

@AlCalzone oh, Recht hast du! Den alten ZMNHDD1 H1S1P1 habe ich doch schon vor einer ganzen Weile getauscht...
Jetzt müsste ein ZMNHDD1 H1S4P5 verbaut sein, der in der Tat Secure kann.
Sorry, wegen der Verwirrung!

Ich habe bemerkt, dass wohl alle Nodes immer mal wieder kurz sterben und ein paar Sekunden danach wiederkommen (Halleluja! ), und dass die in dem Zeitraum versuchten Übertragungen scheinbar nicht nachgeholt werden.

Spoiler

Ich dimme zB um 23oo die Lichter im Flur runter. Genau um 23oo war die Node aber nicht unter den Lebenden und der Schaltbefehl wurde nicht ausgeführt. Da die Todesspanne idR ca 7-10 Sek dauert, dachte ich dass die Schaltung nach Wiederbelebung nachgeholt wird. Das passierte aber nicht. Lichter blieben hell.
Ich konnte aber direkt nach der Auferstehung mit targetValue steuern.

Da habe ich mich gefragt, ob es eine Retry Strategie für fehlgeschlagene Übertragungen gibt, und wie diese aussieht.

[Harry94]

Habe auch mal auf 1.7 geupdated, bin gespannt

[AlCalzone]

@EvilEls sagte in Alpha-Test Adapter Z-Wave 2 (v1.7.x):

Ich habe bemerkt, dass wohl alle Nodes immer mal wieder kurz sterben und ein paar Sekunden danach wiederkommen

Wenn das obige Problem mit der nächsten Version weiter besteht, müsste ich mir das nochmal im Log anschauen.

An sich gibt es eine retry-Strategie. Nahezu jedes Kommando wird 3x hintereinander versucht, bei viel Funkverkehr ggf. auch öfters. Dazwischen liegt jeweils eine kurze Pause. Nach dem dritten fehlgeschlagenen Versuch werden batteriebetriebene Geräte als schlafend angenommen, netzbetriebene als tot markiert.
Das sollte das sein, was du siehst - sobald eine Nachricht empfangen wird, sind die auch wieder "lebendig".

[AlCalzone]

@EvilEls 1.7.0-alpha.1 sollte in Kürze verfügbar sein und den dead-alive-loop von Node 4 beim Interview beheben. Danach bitte nochmal beobachten, ob die sonstigen Probleme weiterhin bestehen und mir ggf. nen Log schicken.

[EvilEls]

Moin @AlCalzone!
Danke für das neue Release! Es ist wirklich viel stabiler nun. Keine dead-alive-loops mehr!

Die Nodes stehen jetzt idR bei unknown oder alive und sind schaltbar.
Node 4 - der alte Spielverderber - zickt aber immer noch herum.

In den Logs müsstest du folgendes sehen können:
Cache gelöscht, Adapter läuft los.
Alle Nodes melden sich brav und lassen sich interviewen.
Node 4 geht erst mal sterben... kommt aber schließlich zurück und Interview gelingt.
Meldung kommt, dass alle Nodes ready sind. (das hatte ich mit alpha0 nicht hinbekommen)
Ich fange an mit dem targetValue von Node 3 herum zu spielen, welche eigentlich keine Probleme macht.
Doch nach ein paar Schaltungen stirbt die Node kurz, kommt aber wieder und lässt sich wieder steuern. Vllt siehst du ja, was da passiert ist.
Dann versuche ich Node 4 zu steuern. Die stirbt nach wenigen Eingaben in targetValue und kommt auch nicht wieder.
(Zwischenzeitlich schalte ich wieder Node 3. Das läuft problemlos)
Ich gehe zum Schalter mache das Licht, an dem Node 4 werkelt, an und wieder aus.
Node 4 sofort alive und steuerbar. Stirbt aber nach wenigen Schaltungen wieder. Kommt zurück und stirbt wieder. Ein paar Mal geht das so.
Es lässt sich keine Zeitspanne oder Anzahl von Schaltungen reproduzieren, nach der die Node wegstirbt. Auch die Dauer, wie lange sie tot ist und ob sie zurückkommt kann ich nicht beeinflussen.
Ich schalte noch ein paar Mal Node 3. Alles fein da.

Hier das Log Paket zu der Geschichte:
10.9.20.zip

PS:
Ich habe hier noch einen baugleichen Dimmer wie für Node 4 herumliegen. Da bastel ich morgen mal Strom dran und schaue, ob das bei dem Teil genauso aussieht. Vllt hat ja auch meine Hardware nur einen Treffer...?!

Besten Dank nochmals und gute N8!

[AlCalzone]

@EvilEls Mit deinen Nodes dürfte alles in Ordnung sein.
Es gibt noch einen Zustand, in dem der Adapter nicht auf Schlüsselanfragen der Nodes reagiert. Daraufhin wollen die auch nicht antworten.
Ich muss da noch ein bisschen umbauen, hoffentlich klappt das übers Wochenende.

[AlCalzone]

@EvilEls alpha.2 ist demnächst verfügbar. Kannst du mir damit nochmal ein Log machen bitte?

[EvilEls]

Hi @AlCalzone!
Danke für die neue Version!

Verhalten der Node 4 ist jetzt besser. Ich konnte sie jetzt öfter schalten bevor sie gestorben ist. Leider kommt sie noch nicht zuverlässig wieder.
Nachdem ich den Schalter betätigt hatte, war sie wieder alive und ging nach ein paar Schaltungen wieder tot.
Ich habe das Gefühl, dass wann immer ich auf einen Wert targetValue schalte der gerade bei auch currentValue gesetzt ist (also currentValue = 0 und ich stelle targetValue = 0, die Wahrscheinlichkeit höher ist, dass die Node stirbt, als wenn ich den Wert tatsächlich verändere.
Probleme hat heute beim Testdurchgang Node 3 gemacht, die sonst die Referenz für gutes Benehmen ist. Interview kam nicht zustande. Alle Schaltungen sind fehlgeschlagen.

2020-09-11_01.zip

Beim zweiten Anlauf sah alles anders aus.

zwave2.0	2020-09-11 21:17:08.604	info	(16792) Node 4: interview completed, all values are updated
zwave2.0	2020-09-11 21:17:08.603	info	(16792) Node 4: ready to use
zwave2.0	2020-09-11 21:17:08.603	info	(16792) All nodes are ready to use
zwave2.0	2020-09-11 21:16:50.539	info	(16792) Node 3: interview completed, all values are updated
zwave2.0	2020-09-11 21:16:50.537	info	(16792) Node 3: ready to use
zwave2.0	2020-09-11 21:16:50.510	info	(16792) Node 2: interview completed, all values are updated
zwave2.0	2020-09-11 21:16:50.509	info	(16792) Node 2: ready to use
zwave2.0	2020-09-11 21:16:27.995	info	(16792) Node 5: interview completed, all values are updated
zwave2.0	2020-09-11 21:16:27.994	info	(16792) Node 5: ready to use
zwave2.0	2020-09-11 21:15:30.498	info	(16792) Node 5 is alive
zwave2.0	2020-09-11 21:15:30.465	info	(16792) Node 4 is alive
zwave2.0	2020-09-11 21:15:30.450	info	(16792) Node 3 is alive
zwave2.0	2020-09-11 21:15:30.410	info	(16792) Node 2 is alive
zwave2.0	2020-09-11 21:15:30.302	info	(16792) Node 1 is alive
zwave2.0	2020-09-11 21:15:30.288	info	(16792) Node 1: interview completed, all values are updated
zwave2.0	2020-09-11 21:15:30.286	info	(16792) Node 1: ready to use
zwave2.0	2020-09-11 21:15:30.237	info	(16792) The driver is ready. Found 5 nodes.
zwave2.0	2020-09-11 21:15:28.072	info	(16792) starting. Version 1.7.0-alpha.2 in /opt/iobroker/node_modules/iobroker.zwave2, node: v12.18.3, js-controller: 3.1.6

Die Interviews waren sehr zügig fertig und alle Geräte alive.
Und siehe da, Node 3 macht wieder den Strahlemann und lässt sich vorbildlich bedienen. Selbst wenn sie nach einem Schaltvorgang kurz hängt, fängt sie sich wieder und bekommt es hin nicht wegzusterben.

Dagegen weiter Land unter bei Node 4. Taumelt nicht mehr ganz so viel zwischen dead-alive beim Schalten, aber stirbt doch noch zuverlässig nach x Schaltungen weg und kommt zum Teil sehr lange nicht wieder. Oder gar erst nach Schalter Betätigung.

Hier die Logs dazu:
2020-09-11_02.zip

Lessons learned: Wenn das Interview beim Start des Adapter nicht erfolgreich ist, sollte die Node vllt gar nicht erst freigegeben werden, da durch versuchte Schaltbefehle gar kein Interview mehr zustande kommt und die Node unbenutzbar bleibt.

Besten Dank und viele Grüße!

PS: Habe es heute leider nicht geschafft den Node 4 Harware Klon zu bestromen. Mal sehn ob ich das WE dazu komme

[EvilEls]

@AlCalzone sorry, will nicht nerven, aber eine Sache viel mir noch ein.

Wie entscheidet der Adapter, wann ein Kommando als fehlgeschlagen eingestuft wird? Wartet er auf ein Callback?
Das die Node 4 hier immer stirbt beim Schalten ist ja nur ein Problem was die Node hat.
Es gibt da ja auch noch dieses, dass der currentValue nicht oder erst eine Schaltung verspätet gesetzt wird:

Beim ersten Schaltversuch mittels Änderung von targetValue im iobroker, hat das Gerät tatsächlich das Licht geschalten. Allerdings hat der currentValue sich nicht verändert.
https://forum.iobroker.net/topic/34414/test-adapter-z-wave-2-v1-3-x/62
bzw.
https://github.com/ioBroker/ioBroker.zwave/issues/84#issue-498239421
Erst bei nochmaligen Schalten, zog der currentValue zum targetValue gleich.

Könnte das uU irgendwie zusammenhängen?

[AlCalzone]

@EvilEls Ne das hat alles mit der Verschlüsselung zu tun. Zur Verschlüsselung ist ständig ein Austausch einmaliger Schlüssel nötig. Daher wird vor jeder Nachricht eine weitere Anfrage nach einem aktuellen Einmalschlüssel geschickt

Im aktuellen Log ist es so, dass Node 3 anfangs nicht auf die verschlüsselten Kommandos antwortet. Daraufhin denkt der Adapter, Node 3 wäre nicht verschlüsselt und versucht, unverschlüsselt mit ihm zu reden. Das mag Node 3 aber nicht, da er doch verschlüsselt ist, und ignoriert die Kommunikationsversuche.
Hier müsste der Adapter merken, dass Node 3 dennoch verschlüsselt kommuniziert und wieder verschlüsselt Verbindung aufnehmen.

Node 4 scheint etwas sturer zu sein. Ich kann mindestens 2x eine Situation identifizieren, bei der der Adapter nach einem Schlüssel fragt und eine Antwort darauf erwartet. Stattdessen sendet Node 4 ebenfalls eine Schlüsselanfrage und wartet darauf, dass der Adapter eine Antwort sendet. Damit sind wir in einer Patt-Situation und der Adapter stuft den Node als tot ein.

@EvilEls sagte in Alpha-Test Adapter Z-Wave 2 (v1.7.x):

Wie entscheidet der Adapter, wann ein Kommando als fehlgeschlagen eingestuft wird? Wartet er auf ein Callback?

Das ist etwas komplizierter. Der Nachrichtenfluss ist in etwa wie folgt (ohne Verschlüsselung)

Adapter -> Stick: Nachricht XYZ senden
Stick -> Node: (sendet Nachricht)
Stick -> Adapter: Sendebestätigung
Node -> Stick: Empfangsbestätigung
Stick -> Adapter: Empfangsbestätigung (oder Info über Ausbleiben der Bestätigung)
...
Node -> Stick: Antwort auf Nachricht
Stick -> Adapter: Antwort auf Nachricht

Wenn entweder die Bestätigung oder eine Antwort ausbleibt, versucht der Adapter noch 2x zu senden, dann wird der Node als tot eingestuft.

Bei Verschlüsselung wird dieser Prozess je Frage-Antwort-Spiel mehrfach durchgeführt, jeder dieser Schritte erwartet eine Sende- und Empfangsbestätigung:

Adapter -> Node: Anfrage Einmalschlüssel
Node -> Adapter: Antwort auf Anfrage
Adapter -> Node: Verschlüsselte Nachricht
...
Node -> Adapter: Anfrage Einmalschlüssel
Adapter -> Node: Antwort auf Anfrage
Node -> Adapter: Antwort auf verschlüsselte Nachricht

Bei Node 4 passiert ab und zu folgendes:

Adapter -> Node: Anfrage Einmalschlüssel
Node -> Adapter: Anfrage Einmalschlüssel
Adapter: wartet auf Antwort, versucht es kurz darauf erneut
Node: wartet ebenfalls auf Antwort, versucht es erneut.
...

In diesem Fall müsste der Adapter nachgeben und direkt die Antwort senden. Dann wäre Node 4 zufrieden und sollte hoffentlich die Antwort auf unsere Nachricht senden.

[EvilEls]

@AlCalzone hab vielen Dank für die super Erklärung!
Wenn ich was Testen kann und/oder du Logs brauchst, bitte einfach Bescheid geben.
Danke noch mal für deine großartige Arbeit hier!

[Marsx79]

@AlCalzone
Ist es geplant einen Z-Wave Stick auch per Serial-ID wie beim "alten" Z-Wave Adapter auswählen zu können anstatt der festen Vorgabe?

Feste Vorgabe: z.B. /dev/ttyACM1
Serial-ID: /dev/serial/by-id/...

Grüße
Marcel

[AlCalzone]

@Marsx79 Müsste ich mir anschauen wie das geht. Bisher nutzt der Adapter eine eingebaute Funktion hierfür. Du kannst es aber mit einem Trick jetzt schon machen:
Adapter stoppen, Konfiguration auf, Pfad bearbeiten, speichern, Adapter starten.

[Marsx79]

@AlCalzone
Super hat funktioniert. Ist genau das was ich wollte. Danke dir!

[Harry94]

Hallo,

habe den Adapter mittlerweile etwas testen können und insgesamt kommt er mir deutlich langsamer wie die Version 1.6 vor. Wenn ich mehrere Schaltvorgänge hintereinander durchführte, sind Wartezeiten von ca. 10s keine Seltenheit.

Meine Netzwerkkarte lädt leider auch nicht.

und im Zwave-Js ordner ist das Zwave-Log nicht mehr vorhanden, hier habe ich wohl eine änderung verpasst, bin mit der suchfunktion durch die vergangenen Threads aber auch nicht weiter gekommen.

Was ich bei dem Adapter wirklich vermisse ist ein Datenpunkt der sich gut für Vis eigenet.
z.B. hat man bei den Fibaro FGS223 (und so ziemlich allen anderen aktoren) Target Value und Current Value (oder ähnlich)
Wenn ich jetzt an einem normalen schalter den Aktor bediene wird dieser wert nicht ins Vis übernommen, weil sich nur der Current Value ändert. (Was ja wohl auch das erwartete Verhalten von openzwave ist). Aktuell synchronisiere ich das mit einem Skript, was leider auch ab und an zu Fehlauslösungen führt.
evtl kann man das hier dann noch mal anders implementieren? also einen Datenpunkt der sowohl den ist zustand zeit und sich schalten lässt?

Skript für die Status-Sync (ja aus blockly konvertiert )

on({id: "zwave2.1.Node_021.Binary_Switch.currentValue_001"/*Current value (Endpoint 1)*/, change: "ne"}, function (obj) {
  var value = obj.state.val;
  var oldValue = obj.oldState.val;
  setState("zwave2.1.Node_021.Binary_Switch.targetValue_001"/*Target value (Endpoint 1)*/, (obj.state ? obj.state.val : ""));
});

on({id: "zwave2.1.Node_020.Binary_Switch.currentValue_001"/*Current value (Endpoint 1)*/, change: "ne"}, function (obj) {
  var value = obj.state.val;
  var oldValue = obj.oldState.val;
  setState("zwave2.1.Node_020.Binary_Switch.targetValue_001"/*Target value (Endpoint 1)*/, (obj.state ? obj.state.val : ""));
});

on({id: "zwave2.1.Node_018.Multilevel_Switch.currentValue_001"/*Current value (Endpoint 1)*/, change: "ne"}, function (obj) {
  var value = obj.state.val;
  var oldValue = obj.oldState.val;
  setState("zwave2.1.Node_018.Multilevel_Switch.targetValue_001"/*Target value (Endpoint 1)*/, (obj.state ? obj.state.val : ""));
});

on({id: "zwave2.1.Node_014.Binary_Switch.currentValue_001"/*Current value (Endpoint 1)*/, change: "ne"}, function (obj) {
  var value = obj.state.val;
  var oldValue = obj.oldState.val;
  setState("zwave2.1.Node_014.Binary_Switch.targetValue_001"/*Target value (Endpoint 1)*/, (obj.state ? obj.state.val : ""));
});

on({id: "zwave2.1.Node_027.Binary_Switch.currentValue_001"/*Current value (Endpoint 1)*/, change: "ne"}, function (obj) {
  var value = obj.state.val;
  var oldValue = obj.oldState.val;
  setState("zwave2.1.Node_027.Binary_Switch.targetValue_001"/*Target value (Endpoint 1)*/, (obj.state ? obj.state.val : ""));
});
on({id: "zwave2.1.Node_037.Binary_Switch.currentValue"/*Current value (Endpoint 1)*/, change: "ne"}, function (obj) {
  var value = obj.state.val;
  var oldValue = obj.oldState.val;
  setState("zwave2.1.Node_037.Binary_Switch.targetValue"/*Target value (Endpoint 1)*/, (obj.state ? obj.state.val : ""));
});

on({id: "zwave2.1.Node_038.Binary_Switch.currentValue_001"/*Current value (Endpoint 1)*/, change: "ne"}, function (obj) {
  var value = obj.state.val;
  var oldValue = obj.oldState.val;
  setState("zwave2.1.Node_038.Binary_Switch.targetValue_001"/*Target value (Endpoint 1)*/, (obj.state ? obj.state.val : ""));
});

Beispiel aktuelle Vis Schaltfläche

hier nochmal die Logs
200915 Harry94.rar

[AlCalzone]

@Harry94 Das Log solltest du jetzt in /opt/iobroker/node_modules/iobroker.zwave2/build finden. Das brauche ich, um dein Problem zu identifizieren.

Wenn ich mehrere Schaltvorgänge hintereinander durchführte, sind Wartezeiten von ca. 10s keine Seltenheit.

Ich wette, da ist noch was faul.

Aktuell synchronisiere ich das mit einem Skript, was leider auch ab und an zu Fehlauslösungen führt.

Schau dir mal die Alias-Funktion an. Damit kannst du das wesentlich stabiler und flexibler machen (z.B. wenn du mal ein Gerät tauschen musst). Wurde auch schon in den Test-Threads hier diskutiert.
Dein Wunsch steht schon auf meiner Liste, für ältere Geräte ohne getrenntes Reporting der Werte kann das schon Sinn machen.

[Harry94]

@AlCalzone

Danke für den Hinweis,
hab den adapter sogar mal installiert, hatte aber bisher noch keine Zeit in richtig einzurichen. Das Skript habe ich mal zu zeiten von Version 0.7 oder so gemacht und seither nicht mehr angefasst

log anbei
zwave-2065.rar