Probleme bei "set <device> configRequestAll"

[krikan]

Hallo Rudi,

habe ein paar Tests mit dem neuen Kommando und netzbetriebenen Geräten gemacht. Folgende Auffälligkeiten bei mir:

• Fibaro FGRM222: Es gibt Telegrammverluste beim Versand; d.h. einzelene Abfragen gehen verloren. Hier tritt mMn das im SECURITY-Thread angesprochene Thema der fehlenden Überwachung auf fehlgeschlagenen Versand 011300 als Problem auf. Neben zu häufigen CANs. Überlege auch schon, ob nicht doch noch eine zusätzliche Überwachung von 0013.... auf Node-Ebene notwendig ist. Also 3Stufig, bei 0013xx01=Fehler keine Resends, sondern den Node sperren. Log anbei. Ist reproduzierbar.
• AEOTEC LED:Hier kannst Du im list erkennen, dass nicht alle Readings aktualisiert sind. 6 aktualisierte configXY-Readings, aber deutliche mehr verschickte Telegramme. Problemursache erkenne ich nicht. Es fehlen auch reproduzierbar einzelne Readings. Habe den Fall nur vorab beigefügt. Wollte mir das XML noch mal  auf Fehler anschauen. Wobei immer verschiedene zuvor aktualisierte configXY bei folgenden Abfragen fehlen, was für mich gegen ein alleiniges Problem mit dem XML spricht. list und log anbei.

Mich wundert, dass ich solche Telegrammverluste mit netzbetriebenen Aktoren zuvor nie hatte. Und ich habe das System auch vor eineiger Zeit bei diversen Tests mit Abfragen überzogen; tlw. mit for each -Konstruktionen. Daher kann ich ein Problem hier nicht ausschließen. Stelle aber sonst nichts fest und das kommt aus dem Produktivsystem, wo Beschwerden kommen würden. Dennoch wäre Gegentest von anderen nicht schlecht.

Wenn Du mehr brauchst, bitte anfordern.

Gruß, Christian

[krikan]

Beim batteriebtriebenen FGMS-001 auch Telegrammverluste mit:

Code Auswählen Erweitern

2015.08.31 18:57:03 5: SW: 06
2015.08.31 18:57:03 5: ZWDongle_0 dispatch 011300
2015.08.31 18:57:03 2: ERROR: cannot SEND_DATA: 00
Verzichte erst einmal auf das ausführliche Log, da es für mich gleich zum FGRM222 aussieht. Wenn mehr gebraucht wird, liefere ich es nach.

Beim Absetzen von "set <device> configRequestAll" wird der Hinweis "Scheduled for sending after WAKEUP" nicht wie sonst am Bildschirm angezeigt. Im Log ist er vorhanden.

[krikan]

Das callback = 0013xx vor Versand der nächsten Nachricht abgewartet werden soll, ergibt sich mMn aus NOTE zu "completeFunc callback" in ins*.
Nur warum tritt das jetzt erst bei mir als Problem auf !?

[rudolfkoenig]

Hallo Christian,

bitte solche logs mit "attr global mseclog" machen.

Was mir beim AOTECLED auffaellt ist, dass dein System 2-3 Sekunden benoetigt, um 10 Abfragen in die Warteschlange zu stellen, mein System hat gestern 19 Abfragen fuer ein FGS221 in 0.06 Sekunden in die Warteschlange gestellt. Da ich nicht vorstellen kann, dass mein Rechner 63 bis 95-mal schneller ist, muss hier noch was anderes am Werk sein. Auf was fuer ein Prozessor/OS laeuft FHEM bei dir? Meins war ein 8-9 Jahre altes 2GHz Core2 mit Ubuntu 12.04. Das verwendete ZWDongle ist das Goodway WD6001, auch nicht das neueste/beste.

Weiterhin komisch, dass selbst die allererste Nachricht erst nach dem dritten resend mit ACK bestaetigt wird, die anderen sind hier noch alle brav in der Schlange. Hier liegt wohl ein Problem vor, was unabhaengig vom configRequestAll ist, und das sollten wir zunaechst loesen. Obwohl die "2 Sekunden lang keine Antwort vom Dongle" mich etwas ideenlos zuruecklaesst.
configRequestAll macht nichts anderes, als alle moeglichen config Abfragen, die man sonst per get absetzt, per set abzusetzen (set dev configXXX request), als nix Weltbewegendes, das gleiche kriegt man mit Massen-Schalt-Befehlen (set ZWave.* off) auch hin.

Hast du mit associationRequestAll aehnliche Probleme? Batteriebetrieben konnte ich nur das testen, da mein KFOB2 kein config Eintrag hat. Lief aber ohne Probleme ab. Btw. versionClassRequest ist auch nichts anderes, als eine Reihe von Befehlen, und das klappt mit dem KFOB fuer die 19 Klassen der KFOB ohne Verlust in 1.45 Sekunden. Allerdings wird der N+1-te erst dann losgeschickt, wenn die Antwort auf die Frage Nr N angekommen ist. Genau so wie beim associationRequestAll. Vlt. muss configRequestAll auch auf diese Muster umgestellt werden, allerdings haben wir das Problem mit "set Zwave.* off" immer noch nicht geloest.

Gruss,
  Rudi

[krikan]

Hallo Rudi!

bitte solche logs mit "attr global mseclog" machen.

Sorry, vergesse ich jedes Mal. Habe auch von "SECURITY"-Andreas schon einen Rüffel bekommen  .

Auf was fuer ein Prozessor/OS laeuft FHEM bei dir? Meins war ein 8-9 Jahre altes 2GHz Core2 mit Ubuntu 12.04. Das verwendete ZWDongle ist das Goodway WD6001, auch nicht das neueste/beste.

Raspi B+ mit Raspian (Jessie). Ich gebe zu der ist belastungsmäßig am Anschlag (durchschittl. 50 % Systemlast), zeigt aber im Alltagsbetrieb keine für mich/uns erkennbaren Ausfälle. Log ist sauber. Dongle ist der Vision, der zeitweise keine Bestätigungen lieferte (vielleicht erinnerst Du Dich noch). Habe den mit mehreren Resets wiederbelebt. Vielleicht hat der doch eine bleibende Macke und sollte ausgetauscht werden; habe daran aber kein Vergnügen.

Also werde ich mal auf meinem Testsystem (i7, UZB1, aber Win10) probieren und berichten. Dort sind nur andere Geräte eingebunden.

Hast du mit associationRequestAll aehnliche Probleme?

Keine Auffälligkeiten.

versionClassRequest

Klappt auch bei allen problemlos.

Im Fazit auch ideenlos.

allerdings haben wir das Problem mit "set Zwave.* off" immer noch nicht geloest

Lässt sich das nicht über die 3stufige Prüfung lösen:
Controller-Ablage bis ACK
dann erst warten bis 011301 und resends bei Fehler (011300)
dann erst warten bis 0013xx00 und dann erst nächstes Telegramm. Bei Fehler (0013xx01) Node für weitere Telegramme sperren und keine Resends.
-> Folgerung aus ins*?

Gruß, Christian

[krikan]

Was mir im nachhinein zum Aeotec LED einfällt:
Der ist das Gerät mit der größten Entfernung vom Controller und ich habe ihn erst kurz vorher eingeschaltet und keine Befehle hingeschickt. Spekulation: Evtl. waren Routen noch nicht optimal.

[krikan]

Habe bei mir auch mit noExplorerFrames 1 in Anlehnung an http://forum.fhem.de/index.php/topic,40537.0.html getestet. Ändert nichts; gleiche Problem wie zuvor.

[krikan]

Auf meinem Testsystem (i7, Win10, UZB1, nur Philio PST02-1A und nur 1m vom Dongle entfernt) erhalte ich alle configXY-Werte. Aber es wimmelt nur so von CAN; zum Schluß gibt es im 1.Log ein für mich nicht verständliches TRANSMIT_NO_ACK. Habe Dir mal neben dem 1. Log mit Inklusionsprozeß und configRequestAll zum Vergleich ein Log von einer weiteren configRequestAll-Abfrage des Sensors ein paar Sekunden später angehängt.

Aus meiner Sicht sind es bei diesem Test Optimalbedingungen: Controller und Gerät mit 500er Chipsatz. Keine störenden Einflüsse von anderen Geräten. Schneller Rechner,..
Wenn jetzt noch weitere ZWave-Geräte senden würden, gehe ich fast von Verlusten wegen zu vieler CANs aus. Jedoch ist das mMn ein anderes Problem als in meinem Produktivsystem. Dort treten mMn die Telegrammverluste eine Stufe später bei 011300 auf.

[rudolfkoenig]

CANs sind an sich kein Problem, zeigt aber, dass wir zu frueh versuchen zu senden.
Die Alternative waere, auf Sende oder Empfangsbestaetigung zu warten, allerdings ist das deiner Ansicht nach zu langsam. Findest noch die Diskussion dazu, oder kannst du noch konkretes dazu sagen? Ich habe das Problem nicht klar behalten.
Waere die Loesung eine eigene Schlange je Zielgeraet, und dabei den naechsten Telegramm nur senden, falls eine Empfangs- oder Sendebestaetigung vorliegt? Damit bremsen langsame Geraete nicht die schnellen aus, wir haben aber eine bessere Flusskontrolle.

[krikan]

CANs sind an sich kein Problem, zeigt aber, dass wir zu frueh versuchen zu senden.

Genau das sehe ich auch so. Verstehe nur nicht, warum das vorher nicht so war, selbst nicht mit for-each bei wakeup-Sendstack. Ist aber letztlich Geschichte.

Die Alternative waere, auf Sende oder Empfangsbestaetigung zu warten, allerdings ist das deiner Ansicht nach zu langsam. Findest noch die Diskussion dazu, oder kannst du noch konkretes dazu sagen? Ich habe das Problem nicht klar behalten.
Waere die Loesung eine eigene Schlange je Zielgeraet, und dabei den naechsten Telegramm nur senden, falls eine Empfangs- oder Sendebestaetigung vorliegt? Damit bremsen langsame Geraete nicht die schnellen aus, wir haben aber eine bessere Flusskontrolle.

Habe das "zu langsam" mehrfach angebracht, aber in verschiedenen Stufen des Versandprozesses.
Grundlegend im Zusammenhang mit geros Änderungen:
http://forum.fhem.de/index.php/topic,37418.0.html (ab ca. Antwort #49)
Dort war aber das u.a. Problem, dass in der 3. Stufe (0013xx01) mehrere Versandvorgänge vorgenommen wurden, was mMn falsch ist und blockierte. Bei Fehler muss NodeId mMn "gesperrt" werden.
Du hast Dich nach meiner Erinnerung an der gegensätzlichen Bedeutung von 00/01 in Stufe 2 (011301 =OK) und 3 (0013xx01=Fehler) gestört und deshalb die mehrstufige Prüfung ausgebaut.
Mein derzeitiger Meinungsstand siehe Antwort #4, wobei ich noch nicht sicher bin, ob Warten auf 3. Stufe notwendig ist. Jedoch verstehe ich genau diese aus ins* (siehe Antwort #2) und meine openzwave löst das auch so.
Hoffe, das ist noch verständlich. Sonst muss ich meiner "Gedankenwelt" in Ruhe zusammenfassen.
Befürchte sowieso wir müssen einfach probieren.

@A.Harrenberg: Andreas hattest Du Dir das Thema Flußkontrolle bei openzwave schon angeschaut und kannst hierzu etwas schreiben?

[krikan]

Waere die Loesung eine eigene Schlange je Zielgeraet, und dabei den naechsten Telegramm nur senden, falls eine Empfangs- oder Sendebestaetigung vorliegt? Damit bremsen langsame Geraete nicht die schnellen aus, wir haben aber eine bessere Flusskontrolle.

Dazu: Ja.

[A.Harrenberg]

Hi Krikan,

Das callback = 0013xx vor Versand der nächsten Nachricht abgewartet werden soll, ergibt sich mMn aus NOTE zu "completeFunc callback" in ins*.
Nur warum tritt das jetzt erst bei mir als Problem auf !?

habe das Problem jetzt auch mal bei mir "nachgestellt" und dafür sogar die Sirene mit SECURITY genutzt. Ich bekomme da auch 7 CAN Messages bei einer Abfrage.

Ich habe mir mal "spaßeshalber" einen einfachen Zähler gebaut und damit Callback-ID gesetzt. Damit kann ich jetzt zumindest die "Transmit OK" Meldung aus ZWDongle eindeutig der versendeten Nachricht zuordnen, momentan blicke ich da aber dennoch noch nicht so wirklich durch. Mit den Controller-Messages stehe ich nach wie vor irgendwie auf Kriegsfuß...

Sind die Nachrichten mit 01 vorne vom Controller, die mit 00 vorne von der Node?

Code Auswählen Erweitern

2015.09.02 21:20:27.802 1: ZWave_SWITCH_BINARY_152: CallBackID 06
2015.09.02 21:20:27.802 5: ZWDongle_Write 00 13980298402506
2015.09.02 21:20:27.802 5: SW: 0109001398029840250684
2015.09.02 21:20:27.803 4: ZWDongle_ReadAnswer arg:secNonce regexp:^00040098..98
2015.09.02 21:20:28.688 5: ACK received, removing 0109001398029840250684 from sendstack
2015.09.02 21:20:28.700 4: ZWDongle_Read ZWDongle_0: sending ACK, data = 0104011301e8
2015.09.02 21:20:28.700 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 011301
2015.09.02 21:20:28.700 5: SW: 06
2015.09.02 21:20:28.701 5: ZWDongle_0 dispatch 011301
2015.09.02 21:20:28.701 2: ZWave_Parse: msg: 011301
2015.09.02 21:20:28.729 4: ZWDongle_Read ZWDongle_0: sending ACK, data = 0107001306000002ef
2015.09.02 21:20:28.729 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 001306000002
2015.09.02 21:20:28.729 5: SW: 06
2015.09.02 21:20:28.730 5: ZWDongle_0 dispatch 001306000002
2015.09.02 21:20:28.730 2: ZWave_Parse: msg: 001306000002
2015.09.02 21:20:28.730 4: ZWDongle_0 CMD:ZW_SEND_DATA ID:00 ARG:0002
2015.09.02 21:20:28.730 4: ZWDongle_0 transmit OK for 06

Die CallBack-ID taucht jedenfalls nur in der 0013 Nachricht wieder auf.

Code Auswählen Erweitern

2015.09.02 21:20:28.779 4: ZWDongle_Read ZWDongle_0: sending ACK, data = 0110000400980a98809c80c6eb829c252942
2015.09.02 21:20:28.779 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 000400980a98809c80c6eb829c2529
2015.09.02 21:20:28.779 5: SW: 06
2015.09.02 21:20:28.780 4: ZWDongle_ReadAnswer for secNonce: 000400980a98809c80c6eb829c2529
2015.09.02 21:20:28.780 2: ZWave_Parse: msg: 000400980a98809c80c6eb829c2529
2015.09.02 21:20:28.780 4: ZWDongle_0 CMD:APPLICATION_COMMAND_HANDLER ID:98 ARG:0a98809c80c6eb829c2529
2015.09.02 21:20:28.780 3: ZWave_SWITCH_BINARY_152 SECURITY: 7005fc retrieved for encryption
2015.09.02 21:20:28.781 2: ZWave set ZWave_SWITCH_BINARY_152 secEncap 81ccc3bfb28a989c9b42b271519c9b6b587eb27a1265
2015.09.02 21:20:28.781 1: ZWave_SWITCH_BINARY_152: CallBackID 07
2015.09.02 21:20:28.781 5: ZWDongle_Write 00 1398179881ccc3bfb28a989c9b42b271519c9b6b587eb27a12652507
2015.09.02 21:20:28.781 5: SW: 011e001398179881ccc3bfb28a989c9b42b271519c9b6b587eb27a1265250774
2015.09.02 21:20:28.782 2: ZWave set ZWave_SWITCH_BINARY_152 configPartnerID request
2015.09.02 21:20:28.782 1: ZWave_SWITCH_BINARY_152: CallBackID 08
2015.09.02 21:20:28.782 3: ZWave_SWITCH_BINARY_152 SECURITY: 7005c8 stored for encryption
2015.09.02 21:20:28.783 2: ZWave get ZWave_SWITCH_BINARY_152 secNonce
2015.09.02 21:20:28.783 1: ZWave_SWITCH_BINARY_152: CallBackID 09
2015.09.02 21:20:28.783 5: ZWDongle_Write 00 13980298402509
2015.09.02 21:20:28.783 4: ZWDongle_ReadAnswer arg:secNonce regexp:^00040098..98
2015.09.02 21:20:28.787 5: ACK received, removing 011e001398179881ccc3bfb28a989c9b42b271519c9b6b587eb27a1265250774 from sendstack
2015.09.02 21:20:28.787 5: SW: 010900139802984025098b
2015.09.02 21:20:28.803 4: ZWDongle_Read ZWDongle_0: sending ACK, data = 0104011301e8
2015.09.02 21:20:28.803 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 011301
2015.09.02 21:20:28.803 5: SW: 06
2015.09.02 21:20:28.804 5: ZWDongle_0 dispatch 011301
2015.09.02 21:20:28.804 2: ZWave_Parse: msg: 011301
2015.09.02 21:20:28.804 4: ZWDongle_Read ZWDongle_0: CAN received
2015.09.02 21:20:28.804 5: SW: 010900139802984025098b
2015.09.02 21:20:28.806 5: ACK received, removing 010900139802984025098b from sendstack
2015.09.02 21:20:28.826 4: ZWDongle_Read ZWDongle_0: sending ACK, data = 0104011301e8
2015.09.02 21:20:28.826 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 011301
2015.09.02 21:20:28.827 5: SW: 06
2015.09.02 21:20:28.828 5: ZWDongle_0 dispatch 011301
2015.09.02 21:20:28.828 2: ZWave_Parse: msg: 011301
2015.09.02 21:20:28.850 4: ZWDongle_Read ZWDongle_0: sending ACK, data = 0107001309000001e3
2015.09.02 21:20:28.851 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 001309000001
2015.09.02 21:20:28.851 5: SW: 06
2015.09.02 21:20:28.852 5: ZWDongle_0 dispatch 001309000001
2015.09.02 21:20:28.852 2: ZWave_Parse: msg: 001309000001
2015.09.02 21:20:28.852 4: ZWDongle_0 CMD:ZW_SEND_DATA ID:00 ARG:0001
2015.09.02 21:20:28.852 4: ZWDongle_0 transmit OK for 09
Im nachfolgenden kommt es dann zur CAN-Message, der Re-Send scheint jedoch angekommen zu sein.

Diese Nachricht wird verschickt
2015.09.02 21:20:28.781 5: SW: 011e001398179881ccc3bfb28a989c9b42b271519c9b6b587eb27a1265250774

Diese Nachricht dann bevor es eine RM vom Controller oder der Node gegeben hat:
2015.09.02 21:20:28.787 5: SW: 010900139802984025098b

Damit wäre schon mal geklärt das es eine CAN Message gibt wenn man vorher noch was sendet...

Gruß,
Andreas.

[A.Harrenberg]

Hi Krikan,

@A.Harrenberg: Andreas hattest Du Dir das Thema Flußkontrolle bei openzwave schon angeschaut und kannst hierzu etwas schreiben?

jein...

Ich habe das zwangsläufig bei der Analyse des Codes und in den Logs gesehen, mir aber  nicht im Detail angesehen. Vor allem nicht den Umgang mit CAN, NO_ACK etc.

Soweit ich das gesehen (und verstanden) habe, verwaltet OZW so ca. 5 verschiedene Queues pro Node und unterscheidet dabei nach verschiedenen Stadien im Versand, einer WakeUp-Queue, einer Queue in der die Nachrichten aus der WakeUp-Queue zum Versenden zwischengespeichert werden und so weiter. Nachrichten werden da "lustig" von einer Queue in die andere übertragen.

Jeder Nachricht wird eine Callback-ID zugeordnert und es wird bei jeder Nachricht die Klasse und der erwartete Befehl der Antwort abgelegt. Eintreffende Antworten werden dann mit den gespeicherten Callback-IDs verglichen, wobei ich das anhand des Verhaltens von FHEM-ZWave nicht nachvollziehen kann, da ich hier die CallBack-ID nicht in der Antwort finde.

Code Auswählen Erweitern

2015.09.02 22:33:41.651 2: ZWave get ZWave_SWITCH_BINARY_152 zwavePlusInfo
2015.09.02 22:33:41.651 1: ZWave_SWITCH_BINARY_152: CallBackID 14
2015.09.02 22:33:41.651 5: ZWDongle_Write 00 1398025e012514
2015.09.02 22:33:41.652 5: SW: 0109001398025e01251411
2015.09.02 22:33:41.653 4: ZWDongle_ReadAnswer arg:zwavePlusInfo regexp:^00040098..5e
2015.09.02 22:33:42.314 5: ACK received, removing 0109001398025e01251411 from sendstack
2015.09.02 22:33:42.330 4: ZWDongle_Read ZWDongle_0: sending ACK, data = 0104011301e8
2015.09.02 22:33:42.330 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 011301
2015.09.02 22:33:42.330 5: SW: 06
2015.09.02 22:33:42.331 5: ZWDongle_0 dispatch 011301
2015.09.02 22:33:42.332 2: ZWave_Parse: msg: 011301
2015.09.02 22:33:42.361 4: ZWDongle_Read ZWDongle_0: sending ACK, data = 0107001314000002fd
2015.09.02 22:33:42.361 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 001314000002
2015.09.02 22:33:42.361 5: SW: 06
2015.09.02 22:33:42.362 5: ZWDongle_0 dispatch 001314000002
2015.09.02 22:33:42.363 2: ZWave_Parse: msg: 001314000002
2015.09.02 22:33:42.363 4: ZWDongle_0 CMD:ZW_SEND_DATA ID:00 ARG:0002
2015.09.02 22:33:42.363 4: ZWDongle_0 transmit OK for 14
2015.09.02 22:33:42.411 4: ZWDongle_Read ZWDongle_0: sending ACK, data = 010f00040098095e020105000f000f003d
2015.09.02 22:33:42.411 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 00040098095e020105000f000f00
2015.09.02 22:33:42.411 5: SW: 06
2015.09.02 22:33:42.412 4: ZWDongle_ReadAnswer for zwavePlusInfo: 00040098095e020105000f000f00
2015.09.02 22:33:42.412 2: ZWave_Parse: msg: 00040098095e020105000f000f00
2015.09.02 22:33:42.412 4: ZWDongle_0 CMD:APPLICATION_COMMAND_HANDLER ID:98 ARG:095e020105000f000f00

Hier taucht die "14" als CallBack-ID nur in der Controllerantwort auf, in der empfangenen Antwort ist davon nichts zu finden, ich habe mir sogar mal eine Log-Meldung mit der ganzen Nachricht (data = ) in ZWDongle gebaut. Eigentlich würde ich ja erwarten das auch die Antwort die CallBack-ID trägt. Zumindest habe ich das aus OZW so "mitgenommen".

Etwas ratlos,
Andreas.

[A.Harrenberg]

Hallo Rudi,

Waere die Loesung eine eigene Schlange je Zielgeraet, und dabei den naechsten Telegramm nur senden, falls eine Empfangs- oder Sendebestaetigung vorliegt? Damit bremsen langsame Geraete nicht die schnellen aus, wir haben aber eine bessere Flusskontrolle.

ich bin mir nicht ganz sicher ob dies ausreichend für Security ist. Wenn auf die Empfangs- oder Sendebstätigung gewartet wird ist damit ja nur Sichergestellt das der Befehl angekommen ist und das keine CAN-Message durch zu frühes Senden einer weiteren Nachricht provoziert wird.

So wie ich Dich im Security-Thread verstanden habe, wird bei GET-Befehlen anschliessend gewartet bis eine Antwort eingetroffen ist. (Ist dies eigentlich "irgendeine" Nachricht von der betreffenden Node?) Wenn das die richtige Antwort ist, wäre soweit alles gut, falls nicht, was passiert dann?

Ich sehe momentan zwei mögliche Probleme für Security "nur" auf die Bestätigung zu warten:

a.) mMn muss die gesamte Kette aus bis zu 8 Nachrichten zwischen Controller und Node ohne Unterbrechung durch eine anderen Nachricht erfolgen. Nur auf die Bestätigung zu warten dürfte zwar gegen die CAN-Messages wirken, verhindert aber nicht das die Nachrichtenkette unterbrochen wird.

b.) Der "Trick" bei den GET-Befehlen auf eine Antwort zu warten funktioniert bei SECURITY nicht mehr so einfach. Was in einer verschlüsselten Nachricht steckt sieht man von außen nicht mehr, hier müsste man irgendwie parallel zum codierten Befehl den Typ (Set oder Get) speichern.

Eine Lösung für a.) habe ich jetzt auch nicht direkt parat, vielleicht müssen wir auch erst mal gezielt versuchen, so eine Kommunikationskette mit einem anderen Befehl zu unterbrechen, um zu sehen was dann passiert.

@Rudi: (leicht Off-Topic) Siehst Du eine Chance Security in den aktuellen Code zu übernehmen BEVOR hier größere Umbaumaßnahmen beginnen? Ich denke wir sollten erst mal sehen was sich hieraus noch an Anforderungen für eine Flusskontrolle ergeben. Ich hätte sonst Angst das da jetzt mit viel Aufwand was umgebaut wird, das dann mit Security doch nicht richtig läuft.

Gruß,
Andreas.

P.S.: Von den Timern in Security rede ich jetzt noch nicht mal...

[rudolfkoenig]

Ich habe die Warteschlangen neu gebaut:
- ZWDongle prueft nun nicht mehr auf wakeupNoMoreInformation, der SendStack ist da einfacher geworden
- alle ZWave Geraete (ob mit oder ohne WAKE_UP) haben ein SendStack (ehemals WakeUp)
- Bei WAKE_UP Geraeten kommen die Befehle auf diesem Stack (wie frueher auf WakeUp), das erste Kommando wird losgeschickt, falls ein wakeup:notification eintrifft oder ein ZW_APPLICATION_UPDATE (auch wie bisher). Nachfolgende Kommandos werden erst losgeschickt, falls ein 0013..00 eintrifft (Antwort vom Geraet, habe Nachricht erhalten), oder ein 011300 (Nachricht vom ZWDongle, konnte Nachricht _nicht_ senden). Beim Letzteren bin ich unsicher.
- Bei Geraeten ohne WAKE_UP wird das erste Befehl sofort geschickt, die weiteren werden genauso behandelt, wie bei WAKE_UP. Ausnahme: falls beim Senden eines neuen Befehls festgestellt wurde, dass auf dem Stack unbestaetigte Befehle seit ueber 10 Sekunden rumgammeln, dann werden die alten Daten entfernt, und es wird mit einem leeren SendStack angefangen
- Es gibt ein neues ZWdongle Attribut delayNeeded (default ist 1), was bewirkt, dass nach einem 0013 das naechste Befehl erst mit einem delay von 0.3s versendet wird. Mein Goodway braucht das, das KFOB2 nicht (delayNeeded 0). Damit kann ich configRequestAll auf dem Goodway ohne Probleme absetzen.

Security habe ich nicht getestet, das bleibt erstmal fuer Andreas.

[krikan]

netzbetriebene Geräte auf meinem "langsamen" Produktivsystem:
Bei "set <device> configRequestAll" endet das erste versandte Telegramm bei allen meinen ZWave-Geräten reproduzierbar mit "ZWDongle_ProcessSendStack: no ACK, resending message". In der Anlage Log mit 2x configRequestAll hintereinander. Beim 1. configRequestAll wird nach meinem Verständnis nach 8xCan der Sendstack für das Gerät komplett abgebrochen und anschließend geleert. Das dürfte doch eigentlichen nicht so sein!? Kann man nach x CANs die Pause nicht ggfs. erhöhen?
Das waren -wie immer- die Negativbeispiele, ansonsten habe ich den Eindruck, das die Probleme deutlich weniger geworden sind. Danke.

[krikan]

Wakeup-Geräte auf "schnellem" Testsystem:
Hier habe ich leider mehr Probleme. Während der Inklusion laufen die Komfortfunktionen "set-associationAdd" und "get-model" nicht mehr korrekt durch. Beide Befehle landen im WakeUp-Sendstack und müssen durch manuelles Aufwecken abgearbeitet werden. Das verursacht evtl. auch die Probleme bei SECURITY. Zudem häufen sich im Log die NO_ACK - Meldungen im laufenden Betrieb über die Zeit, was ich nicht nachvollziehen kann.

[A.Harrenberg]

Hi Krikan,

das Log sieht wirklich merkwürdig aus, da ist ja noch gar nichts "los" und es gibt ein NO_ACK? Was passiert denn wenn Du den ersten Befehl aus der Kette "set ZWave_SWITCH_MULTILEVEL_4 configEnergyReports request" manuel einzeln aufrufst?

Code Auswählen Erweitern

2015.09.06 09:49:07.845 2: ZWave set ZWave_SWITCH_MULTILEVEL_4 configEnergyReports request
2015.09.06 09:49:07.849 5: ZWDongle_Write 00 13040370052b2504
2015.09.06 09:49:07.853 5: SW: 010a0013040370052b25049e
2015.09.06 09:49:08.139 2: ZWave set ZWave_SWITCH_MULTILEVEL_4 configForcedRollerShutterCalibration request
...
2015.09.06 09:49:12.754 2: ZWave set ZWave_SWITCH_MULTILEVEL_4 configSwitchType request
2015.09.06 09:49:12.993 2: ZWDongle_ProcessSendStack: no ACK, resending message
2015.09.06 09:49:12.995 5: SW: 010a0013040370052b25049e
2015.09.06 09:49:13.444 5: ACK received, removing 010a0013040370052b25049e from dongle sendstack
2015.09.06 09:49:13.450 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 011301
2015.09.06 09:49:13.452 5: SW: 06
2015.09.06 09:49:13.458 5: ZWDongle_0 dispatch 011301
2015.09.06 09:49:13.463 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 011301
2015.09.06 09:49:13.466 5: SW: 06
2015.09.06 09:49:13.473 5: ZWDongle_0 dispatch 011301
2015.09.06 09:49:13.479 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 011301
2015.09.06 09:49:13.482 5: SW: 06
2015.09.06 09:49:13.487 5: ZWDongle_0 dispatch 011301
2015.09.06 09:49:13.494 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 011301
2015.09.06 09:49:13.496 5: SW: 06
2015.09.06 09:49:13.502 5: ZWDongle_0 dispatch 011301
2015.09.06 09:49:13.508 4: ZWDongle_Read ZWDongle_0: CAN received
Ich habe diese ganzen 0013, 0113 ja immer noch nicht verstanden, aber mir ist nicht klar wie nach 1x senden, 1xNO_ACK und 1x Re-send da 4x 011301 ankommen kann.

Ansonsten muss ich Dir zustimmen, die SendStacks scheinen gut zu funktionieren. Habe händisch ein paar "Stresstests" gemacht und bisher keine (CAN-) Fehler provozieren können!
@Rudi: Chapeau!

Gruß,
Andreas.

[A.Harrenberg]

Hi Krikan,

Wakeup-Geräte auf "schnellem" Testsystem:
Hier habe ich leider mehr Probleme. Während der Inklusion laufen die Komfortfunktionen "set-associationAdd" und "get-model" nicht mehr korrekt durch. Beide Befehle landen im WakeUp-Sendstack und müssen durch manuelles Aufwecken abgearbeitet werden. Das verursacht evtl. auch die Probleme bei SECURITY. Zudem häufen sich im Log die NO_ACK - Meldungen im laufenden Betrieb über die Zeit, was ich nicht nachvollziehen kann.

es scheint ein Problem mit der ReadAnswerFn zu geben, wodurch teilweise 3 Sekunden gewartet wird, in der Zeit schlägt dann wahrscheinlich der WakeUp-TImeout zu...

Du könntest übergangsweise den ganzen Block mal deaktivieren (in der Funktion ZWave_Cmd, Zeile 707)

Code Auswählen Erweitern

  my $val;
  if($type eq "get_disabled") {
    no strict "refs";
und mal sehen ob dann die set-associatoinAdd und get-model wieder laufen.

Bei NO_ACK habe ich aber auch so gar keine Idee...

Gruß,
Andreas.

[rudolfkoenig]

Ich habe diese ganzen 0013, 0113 ja immer noch nicht verstanden,

0113XX kommt, wenn der Dongle die Nachwirch versendet hat. 01 heisst erfolgreich, sonst wohl nicht.
Z.Zt. wird bei XX != 01 der SendStack weiter abgearbeitet, sonst passiert nix.

0013idXXYYYY kommt, falls der Dongle vom Geraet per Funk ein ACK bekommen hat (XX==00), oder falls es nach Timeout keins bekommen hat (XX!=00). Bei XX==00 wird die naechste Nachricht aus dem Stack geschickt (das sollte normallfall sein), bei XX!=00 wird erstmal nichts gemacht, was nach 10s vermutlich zum wegwerfen des Stacks fuehrt.

configRequestAll_9205

Da ist vieles merkwuerdig:
- der Ack vom Dongle kommt 450ms(!) nach Schreiben der Nachricht.
- danach komme 011301 3x
- das 0013id00 kommt erst 1040ms nach senden. Da hat der WU_NMI-Timer schon zugeschlagen, und hat das Geraet fuer schlafend erklaert (delete $hash->{wakeupAlive}).

Der erste Punkt ist mAn Dongle-Fehler, weiss noch nicht wie ich darauf reagieren soll. Der zweite Punkt ist vmtl. noch ein Verstaendnisproblem bei mir. Der dritte Punkt wird vermutlich durch Meshing verursacht, und wir sollten den Timer erhoehen. Christian: kannst du bitte in ZWave_wakeupTimer die Zeitdifferenz mit 2 oder 3 statt 1 vergleichen? Vermutlich waere es sinnvoll rauszufinden, ob ein Geraet schnell oder langsam antwortet, und diesen Timeout dementsprechend setzen (Attribut?).

Die CAN's werden ab sofort anders behandelt, siehe den E5/Danfoss-Thread.

Die anderen Probleme wuerde ich erst nach klaeren dieser angehen, sonst aendern wir zuviel auf einmal, und die Verwirrung ist gross.

[A.Harrenberg]

Hallo Rudi,

noch was: je nach Konfiguration verschickt das Gerät von Krikan ZWEI WU-Notifications kurz hintereinander. Das war der ursprünglichste Grund für meine "presumed_State" Variable, damit hatte ich auf "awake" getestet und diese 2.te WU-Notification weggeworfen. Im Log von Krikan taucht das aktuell auch wieder auf. Bei meiner Lösung hat das dann einen zweiten Timer zur Abarbeitung des Stacks gestartet, was wieder zu Kollisionen geführt hat.

Im aktuellen Code wird ja hier auch ähnlich ein ZWave_processSendStack angestossen, der dann "parallel" zu dem ersten läuft, oder?

Code Auswählen Erweitern

  if($arg =~ m/^028407/) { # wakeup:notification
    ZWave_wakeupTimer($hash);
    ZWave_processSendStack($hash, undef, 0);
  }

Gruß,
Andreas.

[krikan]

Mein derzeitiges Produktivsystem werde ich zukünftig bis zum Umzug auf leistungsfähigere Hardware nicht mehr zum Testen einsetzen. Insgesamt scheint es Limit zu sein (6 Gateways, Sonos, mehrere HTTOMOD) und verfälscht evtl. Tests. Mit der heutigen SVN-Version geht es zwar besser, aber erst nachdem ich verbose 3, mscelog 0 und EnOcean-Gateway disabled gesetzt ist, wird das Log deutlich besser aber nicht optimal.

Demnächst also alles vom Testsystem, komme aber zu weiteren Tests vermutlich heute nicht mehr.

[krikan]

Auf Testsystem i7 mit Win10, UZB1, PST02-1A meine ich folgende Merkwürdigkeit zu erkennen:

Nach einem WU-NMI wird noch eine WU-NMI-Nachricht an den PST02-1A verschickt, die logischerweise in NO_ACK endet.
Hängt das damit zusammen, dass der Sensor beim manuellen Wakeup -so wie Andreas schrieb- 2x WU-N schickt? Log und list anbei.
Zudem akzeptiert Fhem nach meinem Eindruck auch manuelle get-/set-Abfragen innerhalb des Timer-Zeitraums und verschickt sie sofort mit NO_ACK-Ergebnis, obwohl WU-NMI-Nachricht bereits versandt wurde. Kann das sein?

ZWave_wakeupTimer die Zeitdifferenz mit 2 oder 3 statt 1

Habe ich testweise gemacht, aber keine wirkliche Änderung feststellen können. In diesem Testsetup reichen mMn die 1 Sek reproduzierbar aus.

[rudolfkoenig]

Angepasst:
- ZWDongle hat jetzt wieder ein "set timeouts". Muss wohl gepennt haben, waehrend ich das zu den gets geschoben habe.
- CAN wird waehrend der init Phase wieder so behandelt wie frueher: vor init_done funktioniert InternalTimer nicht.
- ZWave_wakeupTimer sollte ab sofort den doppelten Aufruf (wg. 2x wakeup:notification oder aehnliches) mitkriegen, und nur einen Timer starten
- Bei der Inclusion wird wakeupTimer auch gestartet

-> FHEM-Start ist jetzt ohne Fehlermeldungen, 3s Startupzeit ist wieder 1s, Inclusion mit KFOB2 funktioniert.

[krikan]

Mache gerade einige Stresstests, in dem ich 4 Aktoren mit insgesamt über 60 configXY-Werten mit folgendem Befehl abfrage:

Code Auswählen Erweitern

set ZWave_SWITCH.* configRequestAll
Der Befehl läuft grds. komplett durch. Eine Merkwürdigkeit gibt es, die ich mir nicht erklären kann. Wenn der erste "set configXY"-Befehle auf den Sendstack für einen Aktor gelegt wird, kommt häufig im Anschluß die Meldung "ERROR: ZWave_XY: cleaning commands without ack after 10s". Teilweise, aber nicht immer, wird das configX-Reading  vor der Meldung dann nicht aktualisiert. Im nachfolgenden Log tritt die Meldung zwar gehäuft auf, aber ich kann keine fehlenden configXY-Readings feststellen. Unbestätigte Nachrichten auf dem Sendstack von vor der Befehlsabsetzung kann ich mir nicht vorstellen.
Wie kann ich am Besten vorgehen, um die Ursache zu finden?

Code Auswählen Erweitern

2015.09.07 19:22:18.172 2: ZWave set ZWave_SWITCH_BINARY_6 configPartnerID request
2015.09.07 19:22:18.177 2: ZWave set ZWave_SWITCH_BINARY_6 configResetDefaultConfiguration request
2015.09.07 19:22:18.182 2: ZWave set ZWave_SWITCH_BINARY_6 configSendNotifications request
2015.09.07 19:22:18.186 2: ZWave set ZWave_SWITCH_BINARY_6 configSirenSoundAndVolume request
2015.09.07 19:22:18.194 2: ZWave set ZWave_SWITCH_MULTILEVEL_26 configEnergyReports request
2015.09.07 19:22:18.194 2: ERROR: ZWave_SWITCH_MULTILEVEL_26: cleaning commands without ack after 10s
2015.09.07 19:22:18.195 5: ZWDongle_Write 00 131a0370052b251a
2015.09.07 19:22:18.201 2: ZWave set ZWave_SWITCH_MULTILEVEL_26 configForcedRollerShutterCalibration request
2015.09.07 19:22:18.207 2: ZWave set ZWave_SWITCH_MULTILEVEL_26 configInRollerBlindModeOrVenetianBlind17 request
2015.09.07 19:22:18.215 2: ZWave set ZWave_SWITCH_MULTILEVEL_26 configInVenetianBlindModeTheParameter12 request
2015.09.07 19:22:18.223 2: ZWave set ZWave_SWITCH_MULTILEVEL_26 configLocalProtection request
2015.09.07 19:22:18.230 2: ZWave set ZWave_SWITCH_MULTILEVEL_26 configManagingLamellasInResponseTo35 request
2015.09.07 19:22:18.235 2: ZWave set ZWave_SWITCH_MULTILEVEL_26 configMotorOperationDetection request
2015.09.07 19:22:18.241 2: ZWave set ZWave_SWITCH_MULTILEVEL_26 configMotorOperationTime request
2015.09.07 19:22:18.247 2: ZWave set ZWave_SWITCH_MULTILEVEL_26 configPeriodicPowerOrEnergyReports request
2015.09.07 19:22:18.253 2: ZWave set ZWave_SWITCH_MULTILEVEL_26 configPowerReports request
2015.09.07 19:22:18.259 2: ZWave set ZWave_SWITCH_MULTILEVEL_26 configRFProtectionRadioProtection request
2015.09.07 19:22:18.265 2: ZWave set ZWave_SWITCH_MULTILEVEL_26 configReportsType request
2015.09.07 19:22:18.271 2: ZWave set ZWave_SWITCH_MULTILEVEL_26 configResponseToFloodingAlarm request
2015.09.07 19:22:18.278 2: ZWave set ZWave_SWITCH_MULTILEVEL_26 configResponseToGeneralAlarm request
2015.09.07 19:22:18.284 2: ZWave set ZWave_SWITCH_MULTILEVEL_26 configResponseToSmokeCOOrCO2Alarm request
2015.09.07 19:22:18.289 2: ZWave set ZWave_SWITCH_MULTILEVEL_26 configResponseToTemperatureAlarm request
2015.09.07 19:22:18.296 2: ZWave set ZWave_SWITCH_MULTILEVEL_26 configRollerShutterOperatingModes request
2015.09.07 19:22:18.302 2: ZWave set ZWave_SWITCH_MULTILEVEL_26 configScenesAssociationsActivation request
2015.09.07 19:22:18.309 2: ZWave set ZWave_SWITCH_MULTILEVEL_26 configSelfMeasurement request
2015.09.07 19:22:18.314 2: ZWave set ZWave_SWITCH_MULTILEVEL_26 configSetLamellasBackToPrevious13 request
2015.09.07 19:22:18.320 2: ZWave set ZWave_SWITCH_MULTILEVEL_26 configSwitchType request
2015.09.07 19:22:18.328 2: ZWave set ZWave_SWITCH_MULTILEVEL_27 configEnergyReports request
2015.09.07 19:22:18.328 2: ERROR: ZWave_SWITCH_MULTILEVEL_27: cleaning commands without ack after 10s
2015.09.07 19:22:18.329 5: ZWDongle_Write 00 131b0370052b251b
2015.09.07 19:22:18.334 2: ZWave set ZWave_SWITCH_MULTILEVEL_27 configForcedRollerShutterCalibration request
2015.09.07 19:22:18.340 2: ZWave set ZWave_SWITCH_MULTILEVEL_27 configInRollerBlindModeOrVenetianBlind17 request
2015.09.07 19:22:18.348 2: ZWave set ZWave_SWITCH_MULTILEVEL_27 configInVenetianBlindModeTheParameter12 request
2015.09.07 19:22:18.356 2: ZWave set ZWave_SWITCH_MULTILEVEL_27 configLocalProtection request
2015.09.07 19:22:18.363 2: ZWave set ZWave_SWITCH_MULTILEVEL_27 configManagingLamellasInResponseTo35 request
2015.09.07 19:22:18.368 2: ZWave set ZWave_SWITCH_MULTILEVEL_27 configMotorOperationDetection request
2015.09.07 19:22:18.375 2: ZWave set ZWave_SWITCH_MULTILEVEL_27 configMotorOperationTime request
2015.09.07 19:22:18.382 2: ZWave set ZWave_SWITCH_MULTILEVEL_27 configPeriodicPowerOrEnergyReports request
2015.09.07 19:22:18.388 2: ZWave set ZWave_SWITCH_MULTILEVEL_27 configPowerReports request
2015.09.07 19:22:18.393 2: ZWave set ZWave_SWITCH_MULTILEVEL_27 configRFProtectionRadioProtection request
2015.09.07 19:22:18.399 2: ZWave set ZWave_SWITCH_MULTILEVEL_27 configReportsType request
2015.09.07 19:22:18.405 2: ZWave set ZWave_SWITCH_MULTILEVEL_27 configResponseToFloodingAlarm request
2015.09.07 19:22:18.411 2: ZWave set ZWave_SWITCH_MULTILEVEL_27 configResponseToGeneralAlarm request
2015.09.07 19:22:18.417 2: ZWave set ZWave_SWITCH_MULTILEVEL_27 configResponseToSmokeCOOrCO2Alarm request
2015.09.07 19:22:18.422 2: ZWave set ZWave_SWITCH_MULTILEVEL_27 configResponseToTemperatureAlarm request
2015.09.07 19:22:18.428 2: ZWave set ZWave_SWITCH_MULTILEVEL_27 configRollerShutterOperatingModes request
2015.09.07 19:22:18.434 2: ZWave set ZWave_SWITCH_MULTILEVEL_27 configScenesAssociationsActivation request
2015.09.07 19:22:18.440 2: ZWave set ZWave_SWITCH_MULTILEVEL_27 configSelfMeasurement request
2015.09.07 19:22:18.445 2: ZWave set ZWave_SWITCH_MULTILEVEL_27 configSetLamellasBackToPrevious13 request
2015.09.07 19:22:18.451 2: ZWave set ZWave_SWITCH_MULTILEVEL_27 configSwitchType request
2015.09.07 19:22:18.458 2: ZWave set ZWave_SWITCH_MULTILEVEL_4 configEnergyReports request
2015.09.07 19:22:18.458 2: ERROR: ZWave_SWITCH_MULTILEVEL_4: cleaning commands without ack after 10s
2015.09.07 19:22:18.458 5: ZWDongle_Write 00 13040370052b2504
2015.09.07 19:22:18.465 2: ZWave set ZWave_SWITCH_MULTILEVEL_4 configForcedRollerShutterCalibration request
2015.09.07 19:22:18.470 2: ZWave set ZWave_SWITCH_MULTILEVEL_4 configInRollerBlindModeOrVenetianBlind17 request
2015.09.07 19:22:18.476 2: ZWave set ZWave_SWITCH_MULTILEVEL_4 configInVenetianBlindModeTheParameter12 request
2015.09.07 19:22:18.482 2: ZWave set ZWave_SWITCH_MULTILEVEL_4 configLocalProtection request
2015.09.07 19:22:18.488 2: ZWave set ZWave_SWITCH_MULTILEVEL_4 configManagingLamellasInResponseTo35 request
2015.09.07 19:22:18.493 2: ZWave set ZWave_SWITCH_MULTILEVEL_4 configMotorOperationDetection request
2015.09.07 19:22:18.500 2: ZWave set ZWave_SWITCH_MULTILEVEL_4 configMotorOperationTime request
2015.09.07 19:22:18.505 2: ZWave set ZWave_SWITCH_MULTILEVEL_4 configPeriodicPowerOrEnergyReports request
2015.09.07 19:22:18.512 2: ZWave set ZWave_SWITCH_MULTILEVEL_4 configPowerReports request
2015.09.07 19:22:18.517 2: ZWave set ZWave_SWITCH_MULTILEVEL_4 configRFProtectionRadioProtection request
2015.09.07 19:22:18.522 2: ZWave set ZWave_SWITCH_MULTILEVEL_4 configReportsType request
2015.09.07 19:22:18.530 2: ZWave set ZWave_SWITCH_MULTILEVEL_4 configResponseToFloodingAlarm request
2015.09.07 19:22:18.535 2: ZWave set ZWave_SWITCH_MULTILEVEL_4 configResponseToGeneralAlarm request
2015.09.07 19:22:18.541 2: ZWave set ZWave_SWITCH_MULTILEVEL_4 configResponseToSmokeCOOrCO2Alarm request
2015.09.07 19:22:18.548 2: ZWave set ZWave_SWITCH_MULTILEVEL_4 configResponseToTemperatureAlarm request
2015.09.07 19:22:18.553 2: ZWave set ZWave_SWITCH_MULTILEVEL_4 configRollerShutterOperatingModes request
2015.09.07 19:22:18.559 2: ZWave set ZWave_SWITCH_MULTILEVEL_4 configScenesAssociationsActivation request
2015.09.07 19:22:18.565 2: ZWave set ZWave_SWITCH_MULTILEVEL_4 configSelfMeasurement request
2015.09.07 19:22:18.570 2: ZWave set ZWave_SWITCH_MULTILEVEL_4 configSetLamellasBackToPrevious13 request
2015.09.07 19:22:18.576 2: ZWave set ZWave_SWITCH_MULTILEVEL_4 configSwitchType request

[A.Harrenberg]

Hallo Rudi,

steige noch nicht so ganz durch Deinen Code, aber müsste es am Ende ZWave_addToSendStack nicht ein >=1 sein, anstatt ein ==1??

Code Auswählen Erweitern

ZWave_processSendStack($hash, $now, 0) if(@{$ss} >= 1);

Mit ==1 wird bei mir der Stack immer "länger", es wird nichts gesendet und irgendwann werden dann alte Nachrichten (>10 sekunden) weggeworfen.

Gruß,
Andreas.

[krikan]

batteriebetriebener Sensor PST02-1A:
Mit der aktuellen SVN-Version bekomme ich den Sensor nicht mehr vernünftig in FHEM eingebunden. Die Inklusion stockt bei den Komfortfunktionen und schlimmer noch, es kommen keine Werte vom Sensor mehr an. Es sieht so aus, als ob unmittelbar nach WU-N die WU-NMI verschickt wird, ohne den Sendstack abzuarbeiten.
Ich habe jetzt mehrfach Sensor und Gateway resetet. Das Ergebnis ist immer gleich. List und Log anbei.

[A.Harrenberg]

Hi,

Nachtrag: die Probleme treten unter SECURITY auf, mit >=1 wird es aber dann doch nicht wirklich besser, dort wird dann zwar mehr gesendet, dafür häufen sich dann die CAN und NO_ACK.

Aber der "Normal"-Betrieb sollte erst Mal vorrang haben bei der Problemlösung. Also wenn das mit der >=1 Blödsinn war bitte einfach ignorieren.

Gruß,
Andreas.

[rudolfkoenig]

Andreas: nein. Die Nachricht soll nur dann raus (bzw. auf dem Dongle-Stack), falls die gerade hinzugefuegte der Einzige auf dem Stack ist, d.h. alle vorherigen wurden bestaetigt.
Man beachte: nach dem Senden bleibt de Nachricht als "sent:XXX" noch auf dem SendStack, bis der ACK eintrifft.

Christian/4-Aktoren: Stehe auf dem Schlauch. Kannst du bitte mit "list" pruefen, ob vor dem Senden im SendStack was ist? SendStack sollte eigentlich nur fuer WAKE_UP Geraete sichtbar sein, bei Stationaeren sollte es schnell abgearbeitet und dann geloescht werden. Ich gehe davon aus, dass deine Aktoren kein WAKE_UP haben.

Christian/PST02-1A: Die Inklusion ist stehengeblieben, weil im Step "ZW_ADD_NODE_TO_NETWORK ID:03" kein Geraet per autocreate erzeugt wurde, weiss nicht genau wieso. Entweder funktioniert delete nicht richtig, oder du hast das Geraet nicht entfernt. Damit wurde das Geraet auch nicht mit WAKE_UP angelegt, usw, usf. Wie gesagt alles nur Theorie. Ich kann ein KFOB ohne Fehler inkludieren, habs jetzt zweimal durchgefuehrt, mit und ohne deleteNode vorher. Wenn jemand hier Ideen hat...

[krikan]

Christian/4-Aktoren: Stehe auf dem Schlauch. Kannst du bitte mit "list" pruefen, ob vor dem Senden im SendStack was ist? SendStack sollte eigentlich nur fuer WAKE_UP Geraete sichtbar sein, bei Stationaeren sollte es schnell abgearbeitet und dann geloescht werden. Ich gehe davon aus, dass deine Aktoren kein WAKE_UP haben.

Keine WAKE_UP-Geräte, sondern normale netzbetriebene Aktoren. Deshalb verstehe ich es nicht. Schaue ich mir mit "list" noch mal an systematisch an.

Christian/PST02-1A: Die Inklusion ist stehengeblieben, weil im Step "ZW_ADD_NODE_TO_NETWORK ID:03" kein Geraet per autocreate erzeugt wurde, weiss nicht genau wieso. Entweder funktioniert delete nicht richtig, oder du hast das Geraet nicht entfernt. Damit wurde das Geraet auch nicht mit WAKE_UP angelegt, usw, usf. Wie gesagt alles nur Theorie. Ich kann ein KFOB ohne Fehler inkludieren, habs jetzt zweimal durchgefuehrt, mit und ohne deleteNode vorher. Wenn jemand hier Ideen hat...

Das ist das Gerät mit 2x WU-N hintereinander. Vielleicht liegt es daran. Ich habe es jetzt so oft mit Controller/Aktor-Reset und anderen Experimenten probiert, dass mir die Ideen ausgehen. In der Fassung vor den Änderungen aus Deiner Antowort #23 ging es noch; vielleicht sollte ich mit der Vorversion noch mal testen, damit ich hier Probleme ausschließen kann.

[krikan]

Christian/4-Aktoren: Stehe auf dem Schlauch. Kannst du bitte mit "list" pruefen, ob vor dem Senden im SendStack was ist? SendStack sollte eigentlich nur fuer WAKE_UP Geraete sichtbar sein, bei Stationaeren sollte es schnell abgearbeitet und dann geloescht werden. Ich gehe davon aus, dass deine Aktoren kein WAKE_UP haben.

Hier ein list eines FGRM222 mit einem riesigen Sendstack. Der dürfte doch gar nicht existieren. Die anderen lists enthalten so etwas gerade nicht. Frag mich nicht wie ich das geschafft habe..

Das Problem habe ich unter Linux und Window.

Code Auswählen Erweitern

   CHANGED
   DEF        e345c452 27
   IODev      ZWDongle_0
   LASTInputDev ZWDongle_0
   MSGCNT     18
   NAME       ZWave_SWITCH_MULTILEVEL_27
   NR         271
   STATE      Blind 0 Slat 0
   TYPE       ZWave
   ZWDongle_0_MSGCNT 18
   ZWDongle_0_RAWMSG 0004001b0a32022144000000000000
   ZWDongle_0_TIME 2015-09-07 22:12:55
   homeId     e345c452
   id         1b
   lastMsgSent 1441648204.46713
   Readings:
     2015-09-07 02:39:29   assocGroup_01   Max 10 Nodes 01
     2015-09-07 02:39:29   assocGroup_02   Max 10 Nodes
     2015-09-07 02:39:30   assocGroup_03   Max 01 Nodes 01
     2015-09-07 02:39:28   assocGroups     3
     2015-09-06 15:18:50   configEnergyReports 10
     2015-09-06 15:18:51   configForcedRollerShutterCalibration Default
     2015-09-06 15:18:51   configInRollerBlindModeOrVenetianBlind17 10
     2015-09-06 15:18:52   configInVenetianBlindModeTheParameter12 150
     2015-09-06 15:18:53   configManagingLamellasInResponseTo35 SetLamellasToTheirExtreme1
     2015-09-06 15:18:53   configMotorOperationDetection 10
     2015-09-06 15:18:54   configMotorOperationTime 240
     2015-09-06 15:18:54   configPeriodicPowerOrEnergyReports 3600
     2015-09-06 15:18:55   configPowerReports 10
     2015-09-06 15:18:55   configReportsType BlindPositionReportsSentToThe1
     2015-09-06 15:18:56   configResponseToFloodingAlarm NoReaction
     2015-09-06 15:18:56   configResponseToGeneralAlarm CloseBlind
     2015-09-06 15:18:57   configResponseToSmokeCOOrCO2Alarm OpenBlind
     2015-09-06 15:18:57   configResponseToTemperatureAlarm OpenBlind
     2015-09-06 15:18:57   configRollerShutterOperatingModes VenetianBlindModeWithPositioning
     2015-09-06 15:18:58   configScenesAssociationsActivation AssociationsActivation
     2015-09-06 15:18:58   configSelfMeasurement SelfMeasurementInactive
     2015-09-06 15:18:58   configSetLamellasBackToPrevious13 LamellasReturnToPreviouslySet1
     2015-09-06 15:18:59   configSwitchType MomentarySwitches
     2015-09-07 22:12:55   energy           0 kWh
     2015-09-06 15:14:06   model           FIBARO System FGRM222 Roller Shutter Controller 2
     2015-09-06 15:14:06   modelConfig     fibaro/fgrm222.xml
     2015-09-06 15:14:06   modelId         010f-0301-1001
     2015-09-06 15:26:33   position        Blind 0 Slat 0
     2015-09-07 21:26:30   power           0.0 W
     2015-09-07 19:50:10   state           configSwitchType request
     2015-09-07 02:40:25   transmit        OK
   SendStack:
     sent:131b0370052b251b
     131b0370051d251b
     131b03700511251b
     131b0370050c251b
     131b03700501251b
     131b03700523251b
     131b03700512251b
     131b03700516251b
     131b0370052a251b
     131b03700528251b
     131b03700502251b
     131b03700503251b
     131b0370051f251b
     131b0370051e251b
     131b03700520251b
     131b03700521251b
     131b0370050a251b
     131b03700532251b
     131b0370052c251b
     131b0370050d251b
     131b0370050e251b
Attributes:
   IODev      ZWDongle_0
   classes    MANUFACTURER_SPECIFIC VERSION CONFIGURATION ASSOCIATION SWITCH_BINARY POWERLEVEL METER SENSOR_MULTILEVEL FIRMWARE_UPDATE_MD SWITCH_BINARY MANUFACTURER_PROPRIETARY PROTECTION MARK METER SENSOR_MULTILEVEL MANUFACTURER_PROPRIETARY SCENE_ACTIVATION SWITCH_MULTILEVEL SWITCH_BINARY
   event-on-change-reading .*
   room       ZWave
   stateFormat position

[krikan]

Sendstack bei netzbetriebenen, nicht WAKE_UP-Aktoren:
Habe ein "configRequestAll" an einen ausgeschalteten Aktor verschickt. Dann bleiben alle Telegramme nach dem ersten TRANSMIT_NO_ACK im Sendstack stehen und werden nicht gelöscht. Vielleicht ein Hinweis?

[A.Harrenberg]

Hallo Rudi,
ok, soweit verstanden, irgendwas stimmt da aber dennoch nicht. Irgendwie läuft der Sendstack und die ReadAnswerFn da "auseinander".

Ist bei mir wie gesagt mit SECURITY, bedeutet aber erstmal nur das recht viele get-Nonce Befehle erzeugt werden.

(Test mit ConfigRequestAll)
Erste Abfrage für ConfigRequestAll wird von Security abgefangen und es wird ein GET-Nonce erzeugt/gesendet. Dieser erste GET-Nonce läuft durch, Transmit Ok, aber der Sendstack geht in die 0.3 Sekunden verzögerungen. Inzwischen trifft Antwort auf das GET ein. Hierdurch wird ein neuer SET-Befehl  ausgelöst der auf dem Stack landet. Über das ConfigRequestAll wird die nächste Abfrage verschickt, von Security abgefangen und wieder ein Get-Nonce erzeugt.

Hierfür wird nur die ReadAnswerFn aufgerufen die auf das Ergebnis warten will, ProcessSendStack ist aber noch in der 0.3 Sekunden Delay und der Befehl auf dessen Antwort gewartet werden soll wurde noch gar nicht versendet. -> Timeout 3 sekunden.

Während dieser Zeit hätte eigentlich ProcessSendStack über den Timer wieder aufgerufen werden müssen, ist aber NICHT passiert -> die Nachricht der ersten Get-Nonce liegt noch immer mit "sent:" auf dem Stack.

Durch irgendwas wird anscheinend der Timeraufruf der ProcessSendStack gestört.

Ich habe jetzt leider keine Zeit mehr das ohne das Delay nachzustellen ob es sich dann anders verhält.

Gruß,
Andreas.

[krikan]

Christian/PST02-1A: Die Inklusion ist stehengeblieben, weil im Step "ZW_ADD_NODE_TO_NETWORK ID:03" kein Geraet per autocreate erzeugt wurde, weiss nicht genau wieso. Entweder funktioniert delete nicht richtig, oder du hast das Geraet nicht entfernt. Damit wurde das Geraet auch nicht mit WAKE_UP angelegt, usw, usf. Wie gesagt alles nur Theorie. Ich kann ein KFOB ohne Fehler inkludieren, habs jetzt zweimal durchgefuehrt, mit und ohne deleteNode vorher. Wenn jemand hier Ideen hat...

Habe noch mal resetet und inkludiert: Es kommen immer nur WU-N und direkt WU-NMI im Log. Ein set-/get-Befehl landet im WakeUp-Sendstack. Wenn ich WU-N auslöse, steht im list vor dem Rohtelegramm  "sent:" aber es wird nichts per Dongle verschickt. Direkt nach WU-N kommt im log WU-NMI. Im Wakeup-Sendstack bleibt das Rohtelegramm mit "sent:" stehen, bis ich den nächsten Befehl im wakeup-Sendstack lege und 10s zuschlägt. Das Log hilft hier vermutlich wenig, habe es daher nicht beigefügt.

[A.Harrenberg]

Hallo Rudi,

nachdem ich nun die halbe Nacht darüber gegrübelt habe bin ich zu dem Schluß gekommen das die ReadAnswerFn an der jetzigen Stellen bzw. in der jetzigen Form nicht mehr richtig funktionieren kann. Das ist noch eine Funktionalität aus dem Stand ohne Sendstack im "alive" Betrieb. Da wurde der Befehl mit IOWrite verschickt und dann ReadAnswerFn aufgerufen. Das kam immer in der richtigen Reihenfolge und Zuordnung zueinander.

Jetzt werden die Befehle per addToSendStack an den SendStack übergeben und direkt danach wird die ReadAnswerFn aufgerufen. Das kann mit dem neuen System nicht mehr "synchron" laufen. Sobald ein neuer Get-Befehl so ausgelöst wird, aber noch ein anderer Befehl im Stack abgearbeitet wird, wird der ganze Ablauf asynchron und führt mindestens zu den TimeOuts bei der ReadAnswerFn.

Für Krikans Problem dürfte ausschlaggebend, sein das der "erneute" Aufruf durch das "delayNeeded" von processSendStack per InternalTimer irgendwie verlorengeht. Bei mir hätte es in dem einen Fall passieren müssen während (vergeblich) auf eine Antwort gewartet wurde. Ob dies mit ReadAnswerFn zu tun hat oder die Timer durch irgendetwas anderes fehlschlagen kann ich aber nicht sagen. Vielleicht ist das aber schon mal ein Hinweis auf weitere Debug Aktivitäten. Ich würde da heute abend auch noch mal weiter in dieser Richtung testen wenn Du da nicht bereits andere Ideen hast.

@Krikan: Kannst Du das ganze vielleicht mal wiederholen indem Du im Dongledevice das Attribut "delayNeeded" auf 0 setzt (default ist ja 1). Wenn meine Theorie stimmt müsste dann processSendStack abgearbeitet werden und dabei dann auch die "sent:xxx" Message entfernt werden.

Meiner Meinung nach müsste man die RegExp für die Antworten mit in den SendStack oder einen parallelen Stack legen und die ReadAnswerFn dann wieder synchron aufrufen. Damit wären wir dann ja fast schon bei den "Expected Answers" von OZW ,-)
Dann noch die CallBack-Ids zur besseren Unterscheidung und (fast) fertig... B-)

Gruß,
Andreas.

[A.Harrenberg]

Hallo Rudi,

noch mal ich (diesmal kein langer Post sonder zwei kürzere) ,-)

Falls Du Dir für Sendstack / ReadAnswerFn was überlegst: für Security bräuchte ich irgendwie die Möglichkeit bei Eintreffen meiner Antwort (z.B. Nonce), den Sendstack "anzuhalten", meine verschlüsselte Nachricht zu erzeugen und OBEN auf dem Sendstack zu platzieren und danach den SendStack wieder zu starten.

Das "Problem" mit Security ist das ich einen Befehl "abfange", daraus dann aber bis zu 5 Befehle gemacht werden müssen.

Wobei ich auch hier bereits Szenarien kenne in denen das schieflaufen kann: Falls ich z.B. auf einen Nonce-Report vom Gerät warte, wird die regExp ja ^000400<id>..98 sein. Falls zu dem Zeitpunkt das Gerät z.B. eine Bewegung melden möchte, schickt es mir einen Get-Nonce Befehl der auf die regExp "passt", aber nicht die erwartete Antwort erhält. Ob man das dann anhand der Callback-ID unterscheiden kann müsste man dann ausprobieren oder noch mal genauer bei OZW abschauen.

Gruß,
Andreas.

[krikan]

Christian/PST02-1A: Die Inklusion ist stehengeblieben, weil im Step "ZW_ADD_NODE_TO_NETWORK ID:03" kein Geraet per autocreate erzeugt wurde, weiss nicht genau wieso. Entweder funktioniert delete nicht richtig, oder du hast das Geraet nicht entfernt. Damit wurde das Geraet auch nicht mit WAKE_UP angelegt, usw, usf. Wie gesagt alles nur Theorie. Ich kann ein KFOB ohne Fehler inkludieren, habs jetzt zweimal durchgefuehrt, mit und ohne deleteNode vorher. Wenn jemand hier Ideen hat...

Hallo Rudi,

Bin jetzt bis 9204 zurückgegangen bis mir eine Merkwürdigkeit aufgefallen ist. Seit gestern habe ich 2 ZWDongle-Device (ZWDongle_0, ZW_Dongle_1). Das Device, für das nicht angeschlossene Gateway, habe ich mit Attribut disable 1 versehen. In den Internals des Fhem-Device für den PST02-1A taucht aber das disable-ZWDongle immer wieder auf (LastInputDev). Darum: Kann es sein, dass es hier Zuordnungsprobleme gibt und das falsche ZWDongle-Device angesprochen wird und deshalb nur WU-N und WU-NMI im Log auftauchen?

Bei 9204 bleiben auch keine "sent:"- Reste im Wakeup-Sendstack.
Werde noch weiterprobieren und Ursache suchen. Heute morgen bin ich nicht zu mehr gekommen, wollte nur falsche Ursachensuche deinerseits verhindern. Wenn Du bestimmte Anlaysewünsche hast, dann gerne. Ansonsten bastel ich weiter.

Gruß, Christian

@Andreas: Bitte auch beachten. Meine SECURITY-Tests gestern mit dem PST02-1A sind daher wohl nicht aussagefähig

[krikan]

@Krikan: Kannst Du das ganze vielleicht mal wiederholen indem Du im Dongledevice das Attribut "delayNeeded" auf 0 setzt (default ist ja 1). Wenn meine Theorie stimmt müsste dann processSendStack abgearbeitet werden und dabei dann auch die "sent:xxx" Message entfernt werden.

Habe ich auf beiden Systemen schon mit probiert, kann bei mir aber keine Auswirkung erkennen. Bitte beachte unbedingt meinen letzten Beitrag zu den Problemen mit dem PST02-1A mit 2 ZWDongle-Devices.

[A.Harrenberg]

Hallo Krikan,

ich habe auf meinem Testsystem nur das eine Dongle definiert, daher denke ich nicht das bei mir das was mit verschiedenen Dongles schief laufen kann, werde heute abend aber mal genauer in das Log schauen.

Gruß,
Andreas.

[krikan]

Christian/PST02-1A: Die Inklusion ist stehengeblieben, weil im Step "ZW_ADD_NODE_TO_NETWORK ID:03" kein Geraet per autocreate erzeugt wurde, weiss nicht genau wieso. Entweder funktioniert delete nicht richtig, oder du hast das Geraet nicht entfernt. Damit wurde das Geraet auch nicht mit WAKE_UP angelegt, usw, usf. Wie gesagt alles nur Theorie. Ich kann ein KFOB ohne Fehler inkludieren, habs jetzt zweimal durchgefuehrt, mit und ohne deleteNode vorher. Wenn jemand hier Ideen hat...

Das Problem ist -nicht zufriedenstellend- geklärt:
Hatte in der Fhem Instanz ein ZWDongle_0 und ZWDongle_1. ZWDongle_0 ist nicht angeschlossen und disabled.
Wenn ich Inklusion mit ZWDongle_1 starte läuft diese nicht komplett durch, sondern bricht ab. In den Internals wird dann das IODEV ZWDongle_0 angezeigt.
WU-I werden von ZWDongle_1 empfangen (LASTInputDev) und die WU-NMI von ZWDongle_1 versandt. Alles was dazwischen an Nachrichten liegt wird scheinbar über ZWDongle_0 versandt/empfangen und landet im Nirwana. Ich kann zwar über Attribut iodev das angeschlossene ZWDongle_1 vorbelegen, dann funktioniert die Kommunikation korrekt. Jedoch stirbt Perl/Fhem nach kurzer Zeit mit "PERL WARNING: Terminating on signal SIGINT(2)" unter Win10, so dass ich die Funktionsfähigkeit nicht genau testen kann. Im Fazit habe ich wohl iodev nicht verstanden. Ich hatte vorausgesetzt, dass Fhem die Nachrichten automatisch dem korrekten ZWDongle zuordnet. In ZWave gibt es ja nur die direkte Zuordnung von Gerät zu einem speziellen Dongle. Habe aber mich dann aber erinnert, dass mit klaus.schauer bei EnOcean ein ähnliches Problem diskutiert wurde http://forum.fhem.de/index.php?topic=35118.0. Daraus schließe ich, dass 2 ZWdongle-Devices in Fhem wohl nicht ideal sind; was mich bei nicht angeschlossenem und disabled Device aber wundert.

Jetzt kann ich mich dem nächsten Problem, das noch besteht (sendstack bei netzbetriebenen Aktoren) widmen.

[krikan]

Christian/4-Aktoren: Stehe auf dem Schlauch. Kannst du bitte mit "list" pruefen, ob vor dem Senden im SendStack was ist? SendStack sollte eigentlich nur fuer WAKE_UP Geraete sichtbar sein, bei Stationaeren sollte es schnell abgearbeitet und dann geloescht werden. Ich gehe davon aus, dass deine Aktoren kein WAKE_UP haben.

3 FGRM222 mit "set ZWave_SWITCH.* configRequestAll" abgefragt. Am Beginn (nach Fhem-Start) waren die Sendstacks bei allen Aktor-Devices leer. Dann habe ich den Befehl 3x hintereinander im Abstand von mehreren Minuten ausgeführt. Bei wechselnden Devices stoppt die Abarbeitung/Versand der Einzel-Config-Befehle, obwohl der letzte Befehle mMn problemlos durchlief. In list stehen die nicht abgearbeiteten Befehle. Ich erkenne derzeit kein System. In der Anlage Log anschließend zugehörige List usw. Beim ersten Mal sind die Lists leider unvollständig. Test auf Win-System; auf Raspi habe ich das auch, aber wohl -geschwindigkeitsbedingt- mit noch extremer Sendstack-Resten.
Ich hatte kein 2. ZWDongle-Fhem-Device im Testsystem

[rudolfkoenig]

ZWDongle_0 ist nicht angeschlossen und disabled.

An sowas habe ich bisher nicht gedacht. Beim Neuanlegen eines Geraetes wird das zuletzt definierte Geraet als IODev angenommen, das kann man mit einem Attribut zwar aendern, das ist aber beim Inclusion natuerlich nicht moeglich. AssignIoPort hat bisher IsDisabled nicht geprueft, das habe ich jetzt eingebaut. Ist aber eigentlich auch nicht die richtige Loesung, da die Suche nach den bekannten homeId gehen sollte, das habe ich jetzt auch eingebaut (war mit FIXME versehen). Alles in allem: dieses Problem war schon "immer" vorhanden, und hat nix mit dem Umbau zu tun.

FHEM geht davon aus, dass Nachrichten von mehreren Geraeten empfangen werden koennen, gesendet werden koennen sie aber nur ueber den per IODev zugewiesenen.

Da eine Nachricht aber nur im Zusammenhang mit homeId eindeutig ist, zieht beim Identifikation des ZWave-Geraetes das ZWave Modul die homeId des Empfaenger-ZWDongle heran. Es sollte kein Problem sein, beliebig viele ZWave Dongles in FHEM einzusetzen, insb. jetzt, da die initial ZWDongle Zuweisung gefixt wurde.

Deinen letzten Log kann ich vmtl. erst uebermorgen analysieren.

[krikan]

An sowas habe ich bisher nicht gedacht.

Ich auch nicht, darum hatte ich erst die aktuellen Änderungen verdächtigt. Sorry.

FHEM geht davon aus, dass Nachrichten von mehreren Geraeten empfangen werden koennen, gesendet werden koennen sie aber nur ueber den per IODev zugewiesenen.

Da eine Nachricht aber nur im Zusammenhang mit homeId eindeutig ist, zieht beim Identifikation des ZWave-Geraetes das ZWave Modul die homeId des Empfaenger-ZWDongle heran. Es sollte kein Problem sein, beliebig viele ZWave Dongles in FHEM einzusetzen, insb. jetzt, da die initial ZWDongle Zuweisung gefixt wurde.

Muss man IODev bei mehreren ZWDongle jetzt noch manuell per Attribut zuweisen oder macht FHEM das nach der Änderung automatisch richtig (nicht nur für Inklusion)?

Deinen letzten Log kann ich vmtl. erst uebermorgen analysieren.

Hat Zeit. Der Test ist recht extrem und ich hoffe, es liegt nicht nur am Nutzer...

[rudolfkoenig]

Muss man IODev bei mehreren ZWDongle jetzt noch manuell per Attribut zuweisen oder macht FHEM das nach der Änderung automatisch richtig (nicht nur für Inklusion)?

Mehrere ZWDongles sollten jetzt automatisch funktionieren. Habe auch FHEM2FHEM eingebaut, aber das ist nach etwas nachdenken Mumpitz: Inkludieren und Secure funktioniert ueber FHEM2FHEM sicher nicht.
Fuer diesen Zweck muss man socat verwenden, ist eh die bessere Loesung.

[rudolfkoenig]

Letzter Fall, SendStack:
  sent:13040370051d2504
  ...
die zu diesem Befehl dazugehoerigen Logs (restliche Meldungen entfernt):

2015.09.08 20:33:24.725 5: ZWDongle_Write 00 13040370051d2504
2015.09.08 20:33:27.491 5: SW: 010a0013040370051d2504a8
2015.09.08 20:33:27.632 4: ZWDongle_Read ZWDongle_0: CAN received
2015.09.08 20:33:28.960 2: ZWDongle_ProcessSendStack: no ACK, resending message
2015.09.08 20:33:28.960 5: SW: 010a0013040370051d2504a8
2015.09.08 20:33:28.977 5: ACK received, removing 010a0013040370051d2504a8 from dongle sendstack
2015.09.08 20:33:28.978 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 011301

D.h. der Dongle hat das Befehl zwar losgeschickt, hat aber verpennt die Quittung oder dessen Ausbleiben, also  irgendetwas mit 001304xx, weiterzugeben. Bei dem viel Verkehr koennte mir das auch passieren . Da wir im ZWave noch keinen Timer haben, bleibt die Abarbeitung stehen.

Moeglichkeiten (alle erfordern einen Timer):
- Fehlermeldung/event: kann Befehl soundso nicht wegschicken.
- Befehl erneut schicken, dabei Zaehler pflegen, und falls es nach X-mal nicht
  ging, Fehlermeldung/event.
- Timer startet bei 0113xx, der ZWDongle SendStack generiert selbst sowas, falls die Antwort vom Dongle komplett ausbleibt.

Wie lang sollte die Wartezeit sein? Wie hoch soll X sein?
Bei den obigen Log macht muss die Wartezeit 5+ Sekunden sein, was heftig ist. Wenn die Loesung mit X, dann sollte X 3 sein.
Mein Favorit: Timer (10sek) startet bei der Weitergabe der Daten an ZWDongle, falls nix kommt, Fehlermeldung+Event, ohne "X".
Meinungen? Argumente?

[krikan]

In ZWDongle_DoInit($) wird der timeout mMn auf 1 Sekunde festgelegt. Also gibt es einen Timer, so dass ausbleibende Bestätigungen vom Gerät an Controller nach einer Sekunde als Timeout in 0113xx01 enden sollten. Das, was bei mir auftritt darf doch dann nicht entstehen!?

Meine Gedanken:
Mein System hat einen Fehler.
Kann das Problem noch jemand reproduzieren?
Falls ja, dann:
Controller kommt bei der Vielzahl von Nachrichten durcheinander: Er kann wegen gleicher CallbackId die Antwort nicht der korrekten Nachricht zuordnen und verwirft etwas falsches automatisch.
Es gibt mehrfach einen 1 Sekunden-Timer im Modul; hier kommt es eventuell zu Überschneidungen und den Problemen.

Zur Not:
Dein Favorit, ohne Wiederholungen. Zufrieden bin ich damit aber nicht wirklich. Meiner Meinung nach haben wir dannnicht die Ursache gefunden, da es wegen des gesetzten Timeouts nicht vorkommen darf.

[rudolfkoenig]

In ZWDongle_DoInit($) wird der timeout mMn auf 1 Sekunde festgelegt.

Ja, aber der wartet nur auf dem ACK, und beruecksichtigt nicht den weiteren Werdegang eines Paketes.

Er kann wegen gleicher CallbackId die Antwort nicht der korrekten Nachricht zuordnen

Nice try , gilt aber nicht: seit der Einfuehrung der ZWave-SendStacks (nicht ZWDongle) gibt es jeweils nur eine ausstehende Nachricht von einem Geraet, und damit ist die GeraeteId als CallBackId nicht schlechter, als eine fortlaufende.

Es gibt mehrfach einen 1 Sekunden-Timer im Modul

Welchen meinst Du? Ich sehe nur eins im ZWDongle, und keins (was in diesem Fall aktiviert waere) in ZWave.

da es wegen des gesetzten Timeouts nicht vorkommen darf.

Das habe ich nicht verstanden, ich versuch morgen nochmal

[krikan]

Ja, aber der wartet nur auf dem ACK, und beruecksichtigt nicht den weiteren Werdegang eines Paketes.

Dann habe ich das Problem vielleicht nicht verstanden.
Durch ZWDongle_DoInit($) und Festlegen des timeout auf 1 Sekunde, sollte mMn die maximale Wartezeit des Dongle auf das ACK des Gerätes mit 001304xx festgelegt werden. Wenn die ACK (00130400) vom Gerät an Dongle ausbleibt, muss Dongle nach Timeout Fehler mit 00130401 an Fhem melden. Also dürfte doch nie der Zustand eintreten, dass die Antwort 001304xx (=callback) an Fhem fehlt? Darum befürchte ich Macke in meinem System, wenn das Problem nicht bei anderen reproduzierbar ist.

PS: In meiner letzten Antwort habe ich statt 0013xx01 mal wieder 01 verwendet. Evtl. hat das verwirrt.

Also gibt es einen Timer, so dass ausbleibende Bestätigungen vom Gerät an Controller nach einer Sekunde als Timeout in 0113xx01 enden sollten.

[rudolfkoenig]

Den timeout aus DoInit habe ich schon ganz vergessen. Ich habe nur im ZWave-Dokument INS11095 (such in google nach ZWave INS11095) Hinweise dazu gelesen (such nach FUNC_ID_SERIAL_API_SET_TIMEOUT), und da gehts um die Dongle <-> Host (d.h. FHEM) Kommunikation.
D.h. wenn wir (FHEM) nach 1s kein ACK (SW:06) geschickt haben, dann kriegen wir vom Dongle die Daten nochmal gesendet. Kannst mich aber gerne korrigieren. Apropos: CANs gibts erst ab SerialApi 4.0. Mein Goodway sagt was von 3.28, sendet aber trotzdem CANs. Wo war nochmal die Versionsmapping Tabelle? Und ich haette gerne irgendwo eine Doku der 011301/0013XXYY Telegramme, habe aber nix gefunden.

Bin noch der Ansicht, dass wir auch "kaputte" Dongles unterstuetzen sollten, auch wenn das wg. mehreren zusaetzlichen Timer etwas Performance kostet. Evtl. zunaechst nur per Attribut optional?

[krikan]

Ich habe nur im ZWave-Dokument INS11095 (such in google nach ZWave INS11095) Hinweise dazu gelesen (such nach FUNC_ID_SERIAL_API_SET_TIMEOUT), und da gehts um die Dongle <-> Host (d.h. FHEM) Kommunikation.
D.h. wenn wir (FHEM) nach 1s kein ACK (SW:06) geschickt haben, dann kriegen wir vom Dongle die Daten nochmal gesendet. Kannst mich aber gerne korrigieren.

Grundsätzlich für die 1. Stufe, d.h. 0113xx = Versand, verstehe ich es auch so, wenn das Dongle kein CAN unterstützt (Kann mir aber nicht vorstellen, dass es User mit so alten Dongles gibt). Dann muss auf Ebene der Software durch einen zusätzlichen Timer eine Überwachung stattfinden.
Aber bei ZW_SendData ist der Timer nach meinem Verständnis auch für die Überwachung der zusätzlichen Rückgbe aus der callbackFunc/completedFunc (0013[callbackId]xx) zuständig. Wenn innerhalb Timout kein ACK vom ZWave-Endgerät, dann TRANSMIT_COMPLETE_NO_ACK = 0013[callbackId]01 (siehe Erläuterung Normalerweise kommt immer die 0013[callbackId]01-Fehlermeldung, wenn man etwas an einen toten Node schickt. Wann sollte ohne Bestimmung der Überwachungszeit diese Meldung generiert werden. Die Ausführungen zu "state machine" interpretiere ich auch in diese Richtung.

ZWave-Dokument INS11095 (such in google nach ZWave INS11095)

btw: google liefert auch Treffer für das aktuellere INS10682-9 400

Mein Goodway sagt was von 3.28

Das ist SDK 5.03. Tabelle -> sdkids.xml z-way

Doku der 011301/0013XXYY Telegramme

beseres für 0013[callbackID][xx] als http://svn.linuxmce.org/trac/browser/trunk/src/ZWave/ZW_SerialAPI.h?rev=7415 kenne ich nicht.
Letztlich ist das bei 0113 und 0013 auch Schlußfolgerung aus Beobachtung und Erläuterung zu ZW_SendData in INS*

Bin noch der Ansicht, dass wir auch "kaputte" Dongles unterstuetzen sollten, auch wenn das wg. mehreren zusaetzlichen Timer etwas Performance kostet. Evtl. zunaechst nur per Attribut optional?

Grundsätzlich stimme ich auch hier zu. Aber ich habe Zweifel, ob mein Dongle wirklich kaputt ist und befürchte eher, dass unter Last irgendetwas noch anzupassen ist.

[krikan]

Wenn innerhalb Timout kein ACK vom ZWave-Endgerät, dann TRANSMIT_COMPLETE_NO_ACK = 0013[callbackId]01 (siehe Erläuterung

"siehe Erläuterungen zu (ZW_SendData, callbackFunc und TRANSMIT_COMPLETE_NO_ACK)"
sollte es weitergehen

[krikan]

Habe versucht mein Verständnis mit praktischen Tests mit verschiedenen Timeouts zu prüfen. Leider nicht gelungen. Die NO_ACK-Meldungen treten teilweise erst nach 8 Sekunden bei toten Nodes auf, obwohl Timeout niedriger liegt. Dann verstehe ich die Ausführungen zu TRANSMIT_COMPLETE_NO_ACK bzgl Timwouts in INS* überhaupt nicht mehr.....

[rudolfkoenig]

Habe jetzt eine Version mit ZWave timer (10s) eingecheckt.

Ich habe "dein" Problem auch mit meinem Goodway reproduzieren koennen: ich habe auch fuer 3 Geraete configRequestAll abgesetzt. Die angeforderten Daten sind zwar alle angekommen (zweimal sogar doppelt), aber einmal ist ein 0013XXYY verlorengegangen.

Ich habe das 3-mal wiederholt: 2x ging ein 0013 verloren, einmal war alles da. Wg. dem neuen Timer verklemmt sich das System aber nicht mehr.

[krikan]

Ich habe "dein" Problem auch mit meinem Goodway reproduzieren koennen: ich habe auch fuer 3 Geraete configRequestAll abgesetzt.

"Leicht" OffTopic: Dann hat der Goodway trotz SDK 5.03 keine Probleme mit der TRANSMIT_OPTION Explorer Frames. Hast Du eventuell auch schon einmal probiert, ob bei Nutzung von "set <ZWdongle> addNode nwOn" ein Inklusion durchläuft? Dann brächten wir evtl. die 2 addNode-Varianten nicht zwingend.

[rudolfkoenig]

Habs gerade probiert, ich merke keinen Unterschied, scheint zu funktionieren.

[krikan]

Habs gerade probiert, ich merke keinen Unterschied, scheint zu funktionieren.

Sollen dann überhaupt noch nwOn und on als separate addNode-Varianten erhalten bleiben?
Oder sollen wir netzwerkweite Inklusion nwOn als (umbenanntes) on zum Standard machen und Standardinklusion, low power-Inklusion, ... per Attribut einschaltbar machen?

[rudolfkoenig]

Attribut finde ich doof, lieber Argumente zu addNode, wie lowPower, direct. Wenn jemand bessere Namen hat, her damit.

[krikan]

lieber Argumente zu addNode, wie lowPower, direct.

Das finde ich zwar auch besser, habe aber noch ein Einbindungsproblem (Attribute kann ich schon ). Findest Du das überhaupt sinnvoll?
Bei "set <ZWDongle> addnode on sec" ist jetzt schon die Unschönheit, dass das nicht per Dropdown bzw. Eingabefeld auswählbar/ergänzbar ist, sondern man/ich alles eintippen muss.

[rudolfkoenig]

Stimmt. d.h. wir brauchen alle Varianten mit und ohne sec: on, onSec, direct, directSec, lowPower, lowPowerSec
Nicht ganz schick, aber auch nicht unmoeglich.

[krikan]

Stimmt. d.h. wir brauchen alle Varianten mit und ohne sec: on, onSec, direct, directSec, lowPower, lowPowerSec
Nicht ganz schick, aber auch nicht unmoeglich.

Wegen "schick" wollte ich eigentlich nwOn rausnehmen und nur noch on haben. Die Ergänzung (sec, direct) hätte ich dann lieber in zusätzlichem Auswahlfeld/Testbox. Das bedeutet aber vermutlich einen größeren Umbau, der in keinem Verhältnis zum Nutzen steht!? Also doch unschick. Dann schiebe ich das in meiner Dringlichkeit nach hinten und versuche xFailedNode-Befehle besser einzubinden.

[eddy242]

Hallo zusammen,

ich finde in meinem Log ähnliche Einträge:

Code Auswählen Erweitern

2020.05.26 14:07:48 2: ZWDongle_ProcessSendStack: no ACK, resending message 0109001321028408257f10 Stick ist ein Sigma Designs, Inc. Aeotec Z-Stick Gen5 (ZW090). Ist remote angeschlossen an einem RPI, der sonst eigentlich nicht viel zu tun hat. Ich kann die Remote-Connectivity als Fehlerquelle ausschließen, vorher war der Stick lokal angeschlossen, u.a. um genau diese Symptomatik auszuschließen. In meinem ZWave Netz habe ich im Wesentlichen Fibaro Multisensoren und EUROtronic EUR_SPIRIT Funkthermostate, die sind allerdings momentan saisonal disabled. Ich habe mit den letzgenannten auch immer wieder solche Logeinträge:

Code Auswählen Erweitern

2020.04.29 19:28:06 2: ERROR: cannot SEND_DATA to Funkthermostat_Bernhard: transmit queue overflow Kann ich was tun um das zu debuggen?

Code Auswählen Erweitern


Internals:
   CallbackNr 0
   Clients    :ZWave:
   DEF        192.168.178.8:3001
   DeviceName 192.168.178.8:3001
   FD         32
   FUUID      5e64050f-f33f-0759-0961-8b838f80623e1aca
   MaxSendRetries 3
   NAME       ZWDongle_RPi
   NR         403
   PARTIAL   
   RAWMSG     0004002d06310504220040
   ReadTime   1590506452.11447
   STATE      Initialized
   SendRetries 0
   SendTime   1590505469.11224
   TYPE       ZWDongle
   WaitForAck 0
   ZWDongle_RPi_MSGCNT 36075
   ZWDongle_RPi_TIME 2020-05-26 17:20:52
   homeId     <deleted>
   nodeIdHex  01
   nrNAck     0
   showSetInState 1
   MatchList:
     1:ZWave    .*
   READINGS:
     2020-05-25 13:53:31   caps            Vers:4 Rev:36 ManufID:0000 ProductType:0001 ProductID:0001 SERIAL_API_GET_INIT_DATA SERIAL_API_APPL_NODE_INFORMATION APPLICATION_COMMAND_HANDLER ZW_GET_CONTROLLER_CAPABILITIES SERIAL_API_SET_TIMEOUTS SERIAL_API_GET_CAPABILITIES SERIAL_API_SOFT_RESET UNKNOWN_09 ZW_SET_R_F_RECEIVE_MODE ZW_SET_SLEEP_MODE ZW_SEND_NODE_INFORMATION ZW_SEND_DATA ZW_SEND_DATA_MULTI ZW_GET_VERSION ZW_SEND_DATA_ABORT ZW_R_F_POWER_LEVEL_SET ZW_SEND_DATA_META ZW_GET_RANDOM MEMORY_GET_ID MEMORY_GET_BYTE MEMORY_PUT_BYTE MEMORY_GET_BUFFER MEMORY_PUT_BUFFER FLASH_AUTO_PROG_SET ZW_NVR_GET_VALUE NVM_GET_ID NVM_EXT_READ_LONG_BUFFER NVM_EXT_WRITE_LONG_BUFFER NVM_EXT_READ_LONG_BYTE NVM_EXT_WRITE_LONG_BYTE ZW_GET_NODE_PROTOCOL_INFO ZW_SET_DEFAULT ZW_REPLICATION_COMMAND_COMPLETE ZW_REPLICATION_SEND_DATA ZW_ASSIGN_RETURN_ROUTE ZW_DELETE_RETURN_ROUTE ZW_REQUEST_NODE_NEIGHBOR_UPDATE ZW_APPLICATION_UPDATE ZW_ADD_NODE_TO_NETWORK ZW_REMOVE_NODE_FROM_NETWORK ZW_CREATE_NEW_PRIMARY ZW_CONTROLLER_CHANGE ZW_SET_LEARN_MODE ZW_ASSIGN_SUC_RETURN_ROUTE ZW_REQUEST_NETWORK_UPDATE ZW_SET_SUC_NODE_ID ZW_DELETE_SUC_RETURN_ROUTE ZW_GET_SUC_NODE_ID ZW_SEND_SUC_ID ZW_EXPLORE_REQUEST_INCLUSION ZW_REQUEST_NODE_INFO ZW_REMOVE_FAILED_NODE_ID ZW_IS_FAILED_NODE ZW_REPLACE_FAILED_NODE UNKNOWN_66 UNKNOWN_67 ZW_FIRMWARE_UPDATE_NVM GET_ROUTING_TABLE_LINE LOCK_ROUTE_RESPONSE ZW_GET_PRIORITY_ROUTE ZW_SET_PRIORITY_ROUTE UNKNOWN_98 ZW_SET_WUT_TIMEOUT ZW_WATCHDOG_ENABLE ZW_WATCHDOG_DISABLE ZW_WATCHDOG_CHECK ZW_SET_EXT_INT_LEVEL ZW_RF_POWERLEVEL_GET ZW_TYPE_LIBRARY ZW_SEND_TEST_FRAME ZW_GET_PROTOCOL_STATUS WATCHDOG_START WATCHDOG_STOP ZW_SET_ROUTING_MAX UNKNOWN_ee UNKNOWN_ef
     2020-05-25 13:53:31   ctrlCaps       
     2020-05-25 13:53:31   homeId          HomeId:<deleted> CtrlNodeIdHex:01
     2020-05-25 13:53:31   random          <deleted>
     2020-05-25 13:53:31   state           Initialized
     2020-05-25 13:53:31   sucNodeId       no
   SendStack:
Attributes:
   DbLogExclude .*
   DbLogInclude .*
   alias      ZWave Dongle (an RaspPi)
   group      Communication
   homeId     <deleted>
   networkKey <deleted>
   room       Server
   showSetInState 1
   verbose    3

[rudolfkoenig]

Die wahrscheinlichste Ursache von "no ACK" ist ein Funkproblem, configRequestAll erzeugt eine starke Funklast, da kann schon mal was schiefgehen.
"transmit queue overflow" zeigt, dass der Stick schlechte Laune hat, vmtl. auch wegen Funkproblemen. Es kann aber auch sein, dass das FHEM Modul fehlerhaft ist, insb. wenn man mehrere Geraeten parallel abfragen will.
Batteriebetriebene Geraete sind eine Herausforderung, da sie meist schlafen, und nicht zum Mesh beitragen.

Wegen debuggen kann man mit neighborUpdate anfangen, danach FHEM verbose Logging hochdrehen, ZWave Doku lesen, und mit einem ZWCUL die Funktelegramme einzeln verfolgen.

[eddy242]

Ich hätte erwähnen sollen, dass ich diesen Thread misbraucht habe weil er am nächsten zu meiner Situation bzgl. der Logeinträge ist. Ich setze keine "set <device> configRequestAll" Befehle ab, das habe ich schon früh gelernt, dass es Unglück bringt. D.h. wir sprechen in meinem Netz nur über gelegentlich Set-Befehle und Rückmeldungen der Sensoren (Temp, Luminosity, Presence). Ich konnte und kann mir kaum vorstellen, dass das die Transmit Queue sprengen könnte.

Nach Deiner Beschreibung hätte mein Stick eigentlich immer schlechte Laune. Aber ja, ich sehe an den Logeinträgen dass eigentlich die Laune nur bei den batteriebetriebenen Geräten schlecht ist, bei den Fibaro Wallplugs mit permanenter Stromversorgung scheint es keine Einträge zu geben. ZWCUL scheidet für mich persönlich aus, da reicht die Bastel-Energie nicht.

[krikan]

Gleichzeitige set-Befehle (bspw. über devspec oder structure) insbesondere an mehrere FliRS-Geräte (Spirit ist eines) führen tendenziell zu "transmit queue overflow. Die Befehle muss man durch Pausen entzerren.

Um die Ursache Deines Problems zu finden, würde ich erst mal mit Rudis verbose-Ratschlag anfangen.

Vereinzelte resending sind übrigens nicht tragisch, so lange das Resending funktioniert.