Problem in 00_ZWDongle.pm

[krikan]

Genauso interessant waere zu wissen, was genau 011301 zu bedeuten hat.

01= Antwort auf
13= ZW_SEND_DATA
01= vermutlich OK, wenn 00=FALSE
Dokumentiert ist nur FALSE: "If transmit queue overflow"

Die bei meinem Vision fehlende Nachricht 0013..00 (00 13 [callbackID] [txStatus]) kommt erst, wenn Telegrammübermittlung komplett. callback soll immer überprüft werden, um festzustellen, wann das nächste Telegramm verschickt werden soll; ansonsten "will overflow the transmit queue and eventually fail". Ob das wirklich Ursache für mein Problem mit Vision Stick wage ich zu bezweifeln.

CAN/SOF/NCK müssten mMn noch eine Ebene tiefer liegen.

[rudolfkoenig]

Ich haette es gerne genauer. Dass 0113 Anwer/ZW_SEND_DATA ist, das habe ich schon geahnt, aber wer schickt es wann genau? Bei 0013..XX ist XX=00 OK, und XX=01 NO_ACK (siehe ZWave.pm) Wieso ist es bei 0113XX andersrum? Kann ich SendQueue auch bei einem 0113 abhaken oder erst bei dem 0013? In deinem Fall muesste 011301 den Eintrag entfernen, die Frage ist, ob das immer richtig ist, oder nur bei bestimmten Sticks. Oder haengt es mit deinem lokalen EF Modifikation zusammen?

[krikan]

Ich haette es gerne genauer.

Schwierig, da ich keine genaueren Infos als die INS* kenne. Habe das daraus (bruckstückhaft) zitiert. Vermutlich hast Du dort auch schon reingeschaut.
0113 Anwer/ZW_SEND_DATA ist Return-Wert der Funktion ZW_SEND_DATA, der sofort kommt. 0013 ist die Antwort aus callback, die irgendwann kommt.

Wieso ist es bei 0113XX andersrum?

Die Aussage zu 00/01 war nur eine Vermutung, da wir bisher immer 01 hatten. Hoffe das ist nicht alles FALSE gewesen.
In der alten ZENSYS ZW_transport_api.h http://svn.linuxmce.org/trac/browser/trunk/src/ZWave/ZW_transport_api.h?rev=7476 habe ich auch keine definitiven Anhaltspunkte erkannt.

Kann ich SendQueue auch bei einem 0113 abhaken oder erst bei dem 0013? In deinem Fall muesste 011301 den Eintrag entfernen, die Frage ist, ob das immer richtig ist, oder nur bei bestimmten Sticks. Oder haengt es mit deinem lokalen EF Modifikation zusammen?

So wie es in Fhem eingebaut ist, ist es nach meinem Verständnis korrekt. Nur über die Wiederholungen sollten wir noch nachdenken.

Das mein Stick 0013 seit einigen Tagen nicht mehr liefert ist der Fehler. Wie der entstanden ist, verstehe ich nicht. An EF sollte es nicht liegen, da ich das Problem mit unmodifiziertem Fhem habe und mit neu aufgesetztem Fhem noch mal gegengecheckt habe.

[rudolfkoenig]

Nur über die Wiederholungen sollten wir noch nachdenken.

Bin ganz offen, und unentschlossen:
- 1-mal wie frueher? Es wuerde aber eine Meldung auf Log 1 nach sich ziehen.
- oder per Attribut ganz abschaltbar?
- oder per Attribut 011301 mit 0013..00 gleichsetzen?

[krikan]

Bin ganz offen, und unentschlossen:
- 1-mal wie frueher? Es wuerde aber eine Meldung auf Log 1 nach sich ziehen.
- oder per Attribut ganz abschaltbar?
- oder per Attribut 011301 mit 0013..00 gleichsetzen?

Ich auch. Letztes würde ich aber erst mal ausschließen, da bei meinem Controller anscheinend etwas kaputt ist und das kann nicht Grundlage sein.
Irgendwie stört mich nur das mehrfache Senden. Dies verschleiert nur schlechte oder fehlerhafte Systeme/Kommunikation; so oder ähnlich hat das nach meiner Erinnerung hier auch mal ein Entwickler geschrieben  . Vielleicht sollten wir auf Gero warten und ich suche bei Gelegenheit noch mal Infos zur automatischen Wiederholung von Telegrammen durch Controller.

[krikan]

Code Auswählen Erweitern

00 13 [callbackID] [txStatus]
btw.: Gibt es eigentlich einen Grund dafür, dass die callbackID in Zeile 638 10_ZWave.pm nur bei set-Befehlen für Geräte auf die nodeId gesetzt wird und nicht auch bei get-Befehlen (->Reading "transmit") ?

[rudolfkoenig]

Da die CallBackId in FHEM nicht ausgewertet wird, habe ich es zunaechst nur da eingefuehrt, wo es mir unerlaesslich schien. Insb. wollte ich nicht alles nochmal durchtesten, falls die Antwort einen anderen Format haben sollte.

[krikan]

callbackId bei set wird doch als Kontrolle für korrekten Versand genutzt und setzt Reading "transmit" beim Geräte-Device bzw. "state" bei Problemen. Darum irritiert mich Deine Aussage, dass callbackId in FHEM nicht ausgewertet wird. Habe ich das falsch verstanden?

Bei get-Befehlen wird derzeit immer die TRANSMIT_OPTION 05 als callbackId genutzt. Setzt das nicht immer bei nodeId 05 das Reading "transmit" bei get-Befehlen, egal welche nodeId abgefragt wird (habe keine nodeId 5)? Habe gestern abend if-Abfrage in der besagten Zeile rausgenommen. Probleme sehe ich auf Anhieb nicht, nur den Vorteil, das "transmit" auch bei "get" gesetzt wird und die Zuordnung zum Gerät passt. Fände ich so auch sinnvoller. Beim funktionierenden Testcontroller habe ich aber nur 2 Nodes und meinen Produktivcontroller habe ich noch nicht wieder im Griff .

[krikan]

Bei get-Befehlen wird derzeit immer die TRANSMIT_OPTION 05 als callbackId genutzt.

DIe Aussage von mir ist nach nochmaligen Test falsch. Es ist nicht immer callbackId 05. Nach einem reboot ist es derzeit 06. Da ich die nodeid 06 habe, sieht man auch, dass get-Befehle von anderen nodeId das Reading "transmit" setzen. Bsp.: "get nodeid4 version" führt zur Aktualisierung Reading "transmit" nodeid6.
System erkenne ich derzeit nicht. Nur bringt mich das zur Schlußfolgerung, dass Setzen der callbackId bei get auch zwingend ist. Es wäre schön, wenn das jemand noch mal gegentesten könnte.

PS: Nach erneutem reboot ist callbackId bei get wieder immer 05.

[rudolfkoenig]

Nach etwas Code-Inspizieren:
- get und set sind gleich, da beide durch ZWave_Cmd realisiert wurden.
- falls das Geraet kein WAKE_UP hat, dann bekommen alle Befehle ein callbackId.
- das callbackId ist immer das nodeId des Geraetes, der angesprochen werden soll.
- callbackid wird nur bei den ZW_SEND_DATA Befehlen geprueft, um das transmit Reading zu setzen.

[krikan]

Das heißt: Bei meinem Setup stimmt etwas nicht? Ich müsste bei allen get-Befehlen auch in 00 13 xx 00 xx=nodeId haben?

[rudolfkoenig]

Ich war bei meinem vorigen Analyse geistig nicht bei der Sache:
- callbackid wird bei Geraeten ohne WAKE_UP nur bei set gesetzt.
- bei  Geraeten mit WAKE_UP nur dann, falls das Befehl nicht sofort gesendet wird (da Geraet schlaeft).

Ich meine diese Sonderfaelle gehoeren abgeschafft.

[krikan]

Beruhigt mich enorm.

Ja, die Sonderfälle müssten raus. Insbesondere, da das bei get zu falschen transmit-Readings führt und ich auch andere Nebenwirkungen bei fehlenden Callbacks befürchte. Ich hatte hierzu -wie geschrieben- Zeile 638 von 10_ZWave.pm so geändert, dass überall die nodeId=callbackId und keine Probleme festgestellt. Überlege nur noch, welche Nach-/Vorteile eine separate CallbackId-Liste (callbackId => nodeId) hätte.

WAKE_UP Geräte hatte ich mir in dem Zusammenhang noch nicht angeschaut, aber die sollten auch callbackIds nutzen.

[krikan]

Beim Anschauen der WAKE_UP-Geräte fällt mir nebenbei auf:
bei leerem Sendstack wird keine wakeUpNoMoreInformation-Nachricht an die Geräte verschickt -> Geräte bleiben mit geräteabhängige Maximalzeit wach und Batterie wird nicht geschont. Besser wäre es doch bei leerem Sendstack nach 1-2 Sekunden automatisch eine wakeUpNoMoreInformation-Nachricht an das Gerät zu schicken. Nur gibt es schon einen InternalTimer in 10_ZWave.pm und irgendwie scheinen sich bei meinen Versuchen 2 nicht zu vertragen!?

Zurück zu 00_ZWDongle und Wiederholungen:
Schickt man eine Nachricht an ein nicht-reagierendes Gerät, wird trotz erhaltener NO_ACK von ZW_SEND_DATA-callback gewartet und gewartet, dann 2x wiederholt gesendet mit den gleichen Wartezeiten bis dann endlich abgebrochen wird. Ergibt eine Laufzeit von 9 Sekunden. Das finde ich nicht optimal. Eigentlich müsste doch zumindest nach NO_ACK sofort wiederholt gesendet werden und nicht weiter auf ein (nie eintretendes) ACK von ZW_SEND_DATA-callback gewartet werden:

Code Auswählen Erweitern

2015.06.08 20:40:18 2: ZWave get ZWave_SWITCH_MULTILEVEL_4 swbStatus
2015.06.08 20:40:18 5: ZWDongle_Write msg 13040225020504
2015.06.08 20:40:18 5: ZWave_ProcessSendStack: 1 items on stack, waitForAck 0
2015.06.08 20:40:18 5: ZWave_ProcessSendStack: sending msg 01090013040225020504c5
2015.06.08 20:40:18 5: SW: 01090013040225020504c5
2015.06.08 20:40:18 4: ZWDongle_ReadAnswer arg:swbStatus regexp:^00040004..25
2015.06.08 20:40:18 5: ZWDongle_ReadAnswer: read 1 bytes
2015.06.08 20:40:18 5: ZWDongle RAW buffer: 06
2015.06.08 20:40:18 5: ZWDongle_0: ACK received
2015.06.08 20:40:18 5: ZWave_ProcessSendStack: 1 items on stack, waitForAck 1
2015.06.08 20:40:18 5: ZWave_ProcessSendStack: waiting for ACK -> check again
2015.06.08 20:40:18 5: ZWDongle_Read returning local msg undef hash PARTIAL:
2015.06.08 20:40:18 5: ZWDongle_ReadAnswer: read 6 bytes
2015.06.08 20:40:18 5: ZWDongle RAW buffer: 0104011301e8
2015.06.08 20:40:18 5: ZWDongle_Read ZWDongle_0: ACK, processing 011301
2015.06.08 20:40:18 5: SW: 06
2015.06.08 20:40:18 5: ZWDongle_0 dispatch 011301
2015.06.08 20:40:18 5: ZWave_ProcessSendStack: 1 items on stack, waitForAck 1
2015.06.08 20:40:18 5: ZWave_ProcessSendStack: waiting for ACK -> check again
2015.06.08 20:40:18 5: ZWDongle_Read returning local msg undef hash PARTIAL:
2015.06.08 20:40:19 5: ZWDongle_ReadAnswer: read 7 bytes
2015.06.08 20:40:19 5: ZWDongle RAW buffer: 010500130401ec
2015.06.08 20:40:19 5: ZWDongle_Read ZWDongle_0: ACK, processing 00130401
2015.06.08 20:40:19 5: SW: 06
2015.06.08 20:40:19 5: ZWDongle_0 dispatch 00130401
2015.06.08 20:40:19 4: ZWDongle_0 CMD:ZW_SEND_DATA ID:01 ARG:
2015.06.08 20:40:19 2: ZWDongle_0 transmit NO_ACK for 04
2015.06.08 20:40:19 5: ZWave_ProcessSendStack: 1 items on stack, waitForAck 1
2015.06.08 20:40:19 2: ZWave_ProcessSendStack: timeout sending message -> trigger resend
2015.06.08 20:40:19 5: ZWave_ProcessSendStack: sending msg 01090013040225020504c5
2015.06.08 20:40:19 5: SW: 01090013040225020504c5
2015.06.08 20:40:19 5: ZWDongle_Read returning local msg undef hash PARTIAL:
2015.06.08 20:40:19 5: ZWDongle_ReadAnswer: read 1 bytes
2015.06.08 20:40:19 5: ZWDongle RAW buffer: 06
2015.06.08 20:40:19 5: ZWDongle_0: ACK received
2015.06.08 20:40:19 5: ZWave_ProcessSendStack: 1 items on stack, waitForAck 1
2015.06.08 20:40:19 5: ZWave_ProcessSendStack: waiting for ACK -> check again
2015.06.08 20:40:19 5: ZWDongle_Read returning local msg undef hash PARTIAL:
2015.06.08 20:40:19 5: ZWDongle_ReadAnswer: read 6 bytes
2015.06.08 20:40:19 5: ZWDongle RAW buffer: 0104011301e8
2015.06.08 20:40:19 5: ZWDongle_Read ZWDongle_0: ACK, processing 011301
2015.06.08 20:40:19 5: SW: 06
2015.06.08 20:40:19 5: ZWDongle_0 dispatch 011301
2015.06.08 20:40:19 5: ZWave_ProcessSendStack: 1 items on stack, waitForAck 1
2015.06.08 20:40:19 5: ZWave_ProcessSendStack: waiting for ACK -> check again
2015.06.08 20:40:19 5: ZWDongle_Read returning local msg undef hash PARTIAL:
2015.06.08 20:40:20 5: ZWDongle_ReadAnswer: read 7 bytes
2015.06.08 20:40:20 5: ZWDongle RAW buffer: 010500130401ec
2015.06.08 20:40:20 5: ZWDongle_Read ZWDongle_0: ACK, processing 00130401
2015.06.08 20:40:20 5: SW: 06
2015.06.08 20:40:20 5: ZWDongle_0 dispatch 00130401
2015.06.08 20:40:20 4: ZWDongle_0 CMD:ZW_SEND_DATA ID:01 ARG:
2015.06.08 20:40:20 2: ZWDongle_0 transmit NO_ACK for 04
2015.06.08 20:40:20 5: ZWave_ProcessSendStack: 1 items on stack, waitForAck 1
2015.06.08 20:40:20 5: ZWave_ProcessSendStack: waiting for ACK -> check again
2015.06.08 20:40:20 5: ZWDongle_Read returning local msg undef hash PARTIAL:
2015.06.08 20:40:23 5: ZWDongle_ReadAnswer: select timeout
2015.06.08 20:40:23 5: ZWave_ProcessSendStack: 1 items on stack, waitForAck 1
2015.06.08 20:40:23 2: ZWave_ProcessSendStack: timeout sending message -> trigger resend
2015.06.08 20:40:23 5: ZWave_ProcessSendStack: sending msg 01090013040225020504c5
2015.06.08 20:40:23 5: SW: 01090013040225020504c5
2015.06.08 20:40:23 5: ZWDongle RAW buffer: 06
2015.06.08 20:40:23 5: ZWDongle_0: ACK received
2015.06.08 20:40:23 5: ZWave_ProcessSendStack: 1 items on stack, waitForAck 1
2015.06.08 20:40:23 5: ZWave_ProcessSendStack: waiting for ACK -> check again
2015.06.08 20:40:23 5: ZWDongle RAW buffer: 0104011301e8
2015.06.08 20:40:23 5: ZWDongle_Read ZWDongle_0: ACK, processing 011301
2015.06.08 20:40:23 5: SW: 06
2015.06.08 20:40:23 5: ZWDongle_0 dispatch 011301
2015.06.08 20:40:23 5: ZWave_ProcessSendStack: 1 items on stack, waitForAck 1
2015.06.08 20:40:23 5: ZWave_ProcessSendStack: waiting for ACK -> check again
2015.06.08 20:40:24 5: ZWDongle RAW buffer: 010500130401ec
2015.06.08 20:40:24 5: ZWDongle_Read ZWDongle_0: ACK, processing 00130401
2015.06.08 20:40:24 5: SW: 06
2015.06.08 20:40:24 5: ZWDongle_0 dispatch 00130401
2015.06.08 20:40:24 4: ZWDongle_0 CMD:ZW_SEND_DATA ID:01 ARG:
2015.06.08 20:40:24 2: ZWDongle_0 transmit NO_ACK for 04
2015.06.08 20:40:24 5: ZWave_ProcessSendStack: 1 items on stack, waitForAck 1
2015.06.08 20:40:24 5: ZWave_ProcessSendStack: waiting for ACK -> check again
2015.06.08 20:40:25 5: ZWave_ProcessSendStack: 1 items on stack, waitForAck 1
2015.06.08 20:40:25 2: ZWave_ProcessSendStack: timeout sending message -> trigger resend
2015.06.08 20:40:25 5: ZWave_ProcessSendStack: sending msg 01090013040225020504c5
2015.06.08 20:40:25 5: SW: 01090013040225020504c5
2015.06.08 20:40:25 5: ZWDongle RAW buffer: 06
2015.06.08 20:40:25 5: ZWDongle_0: ACK received
2015.06.08 20:40:25 5: ZWave_ProcessSendStack: 1 items on stack, waitForAck 1
2015.06.08 20:40:25 5: ZWave_ProcessSendStack: waiting for ACK -> check again
2015.06.08 20:40:25 5: ZWDongle RAW buffer: 0104011301e8
2015.06.08 20:40:25 5: ZWDongle_Read ZWDongle_0: ACK, processing 011301
2015.06.08 20:40:25 5: SW: 06
2015.06.08 20:40:25 5: ZWDongle_0 dispatch 011301
2015.06.08 20:40:25 5: ZWave_ProcessSendStack: 1 items on stack, waitForAck 1
2015.06.08 20:40:25 5: ZWave_ProcessSendStack: waiting for ACK -> check again
2015.06.08 20:40:25 5: ZWDongle RAW buffer: 010500130401ec
2015.06.08 20:40:25 5: ZWDongle_Read ZWDongle_0: ACK, processing 00130401
2015.06.08 20:40:25 5: SW: 06
2015.06.08 20:40:25 5: ZWDongle_0 dispatch 00130401
2015.06.08 20:40:25 4: ZWDongle_0 CMD:ZW_SEND_DATA ID:01 ARG:
2015.06.08 20:40:25 2: ZWDongle_0 transmit NO_ACK for 04
2015.06.08 20:40:26 5: ZWave_ProcessSendStack: 1 items on stack, waitForAck 1
2015.06.08 20:40:26 5: ZWave_ProcessSendStack: waiting for ACK -> check again
2015.06.08 20:40:27 5: ZWave_ProcessSendStack: 1 items on stack, waitForAck 1
2015.06.08 20:40:27 2: ZWave_ProcessSendStack: timeout sending message -> trigger resend
2015.06.08 20:40:27 1: ZWave_ProcessSendStack: max send retrys reached -> cancel sending

Bei der Recherche habe ich noch folgende Infos gefunden:
Der mit "set ZW_Dongle timeouts" gesetzte Timeout soll beim Warten im Programm wegen Telegrammlaufzeiten etwas größer sein. Bsp.: Dongle: 1,5 / Programm: 2,0 Sek. In Fhem ist das jetzt jeweils 1 Sek.
Das Dongle verschickt korrekt im transmit queue eingestellte Telegramme bei Fehlern in der Route/Erreichbarkeit des Nodes automatisch mehrfach über mehrere Ausweichrouten (bei TRANSMIT_OPTION 05 bzw. bei Einschluß Explorer Frames) ohne Mitwirkung des Programms. NO_ACK über"transmit complete callback" von ZW_SEND_DATA kommt, wenn keine Antwort bei allen Versuchen kommt bzw. dass beim Dongle festgelegte timeout überschritten wird.

[krikan]

@gero und Rudi:
Meine Spekulationen/Aussagen haben keine Eile. Ich  halte das nur hier fest bevor ich es wieder vergesse , da ich gerade die geänderte Fassungen der ZWave-Module mit Unmengen Log-Aufrufen für mein Verständnis versehe...