Problem in 00_ZWDongle.pm

Begonnen von gero, 22 Mai 2015, 10:41:13

Vorheriges Thema - Nächstes Thema

rudolfkoenig

Wie lange ist eigentlich die "Maximalzeit wach"? Ich dachte 1-2 Sekunden.
FHEM muesste abwarten, ob nicht via notify requests abgeschickt werden, aber dafuer wuerde auch 0.1 Sec reichen. Ich frag mich, ob es einen Unterschied macht.

Die ACK-Logik bin ich auch schon am umbauen, da bei der SEC-Inlusion mit der aktuellen Version komische Wiederholungen gibt.

krikan

Zitat von: rudolfkoenig am 09 Juni 2015, 08:25:14
Wie lange ist eigentlich die "Maximalzeit wach"? Ich dachte 1-2 Sekunden.
Aus der Erinnerung hätte ich 5-10 Sekunden behauptet.
Aber Paetz schreibt in der alten Auflage seines Buches auf S. 81, dass das erst ca. eine Minute nach dem letzten empfangenen und verarbeiteten Befehl geschieht, wenn keine wakeUpNoMoreInformation versandt wird. Eigentlich sollte der es wissen und dann verstehe ich auch, warum mein Philio-Sensor immer so viele Batterien schluckt. Dachte, das liegt an meinen Experimenten.

ZitatDie ACK-Logik bin ich auch schon am umbauen, da bei der SEC-Inlusion mit der aktuellen Version komische Wiederholungen gibt.
Prima. Obwohl ich dann wieder Tage/Wochen brauche um es halbwegs zu verstehen :-[.

Gegen die Wiederholungen von ZW_SEND_DATA bei callbacks mit Fehlermeldungen sprechen nach nochmaligen Überlegen auch die Explorer Frames. Explorer Frames sollen die Funklast deutlich erhöhen und werden selbst vom api beschränkt. Wenn Fhem dann Explorer Frames verschicken würde, sollten bei aktuellen Geräten ein NO_ACK aus callback ZW_SEND_DATA ausreichen, um hinreichend sicher zu sein, dass das Gerät nicht erreichbar ist. Wiederholungen würden die Funklast nur unnötig weiter hochtreiben. Also ich komme immer mehr zum Schluß, dass ich ZW_SEND_DATA-Wiederholungen bei Fehlern im callback nicht so gut finde und das lieber konfigurierbar hätte.

krikan

Zitat von: krikan am 09 Juni 2015, 09:15:38
Aber Paetz schreibt in der alten Auflage seines Buches auf S. 81, dass das erst ca. eine Minute nach dem letzten empfangenen und verarbeiteten Befehl geschieht, wenn keine wakeUpNoMoreInformation versandt wird.
Habe mir die aktuelle Auflage gegönnt und dort heißt es nun bei Pos. 1614 (Seite kann ich im Ebook nicht erkennen): "nach einer im Gerät individuell programmierten Zeit"
Also: mal so, mal so... aber wakeUpNoMoreInformation wäre mMn trotzdem immer sinnvoll

krikan

ZitatFHEM muesste abwarten, ob nicht via notify requests abgeschickt werden, aber dafuer wuerde auch 0.1 Sec reichen. Ich frag mich, ob es einen Unterschied macht.
Könnte 0.1 nicht Probleme bereiten, wenn andere Geräte mit dem wakeup-Gerät direkt assoziert sind, d.h. Controller schickt zu früh in den Schlaf bevor direkte Assoziations-Kommunikation bspw. zwischen Bewegungsmelder und Schaltaktor verarbeitet ist.
Openhab hat derzeit eine Pause von 1 Sek., bis vor kurzem noch 2 Sek.
Bei openzwave finde ich dazu auf Anhieb nichts.

rudolfkoenig

Na FHEM wuerde nur sagen, dass jetzt nichts mehr zu sagen gibt (wakeUpNoMoreInformation).
Die Kommunikation zw. batteriebetriebenes Geraet und Anderen sollte davon nicht betroffen sein, und ob das Geraet sich danach schlafen laegt oder nicht, ist ihm ueberlassen.

krikan


rudolfkoenig

Ab sofort wird nach einem wakeup:notification nach 0.1 Sekunde ein wakeupNoMoreInformation gesendet, falls der WakeUp Stack leer ist.

Habs nicht getestet, da ich z.Zt. kein WAKE_UP Geraet mit sinnvollen timeout habe.
-> Waere wg. feedback dankbar.

krikan

Habe per notify auf wakeup:.notification "get ZWave_Node_7 version" abgesetzt und dann manuell aufgeweckt.
Durch das manuelle Aufwecken wird nach meinem Verständnis wakeup:.notification 2x ausgelöst und die letzte Abfrage von "get ZWave_Node_7 version" läuft in NO_ACK.

2015.06.14 17:01:35 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 000400070d8f0101097105000000ff070300
2015.06.14 17:01:35 5: SW: 06
2015.06.14 17:01:35 5: ZWDongle_0 dispatch 000400070d8f0101097105000000ff070300
2015.06.14 17:01:35 4: ZWDongle_0 CMD:APPLICATION_COMMAND_HANDLER ID:07 ARG:0d8f0101097105000000ff070300
2015.06.14 17:01:37 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 00040007028407
2015.06.14 17:01:37 5: SW: 06
2015.06.14 17:01:37 5: ZWDongle_0 dispatch 00040007028407
2015.06.14 17:01:37 4: ZWDongle_0 CMD:APPLICATION_COMMAND_HANDLER ID:07 ARG:028407
2015.06.14 17:01:37 2: ZWave get ZWave_Node_7 version
2015.06.14 17:01:37 5: ZWDongle_Write 00 130702861105
2015.06.14 17:01:37 5: SW: 01080013070286110573
2015.06.14 17:01:37 4: ZWDongle_ReadAnswer arg:version regexp:^00040007..86
2015.06.14 17:01:37 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 00040407028407
2015.06.14 17:01:37 5: SW: 06
2015.06.14 17:01:37 5: ZWDongle_0 dispatch 00040407028407
2015.06.14 17:01:37 4: ZWDongle_0 CMD:APPLICATION_COMMAND_HANDLER ID:07 ARG:028407
2015.06.14 17:01:37 4: ZWDongle_Read ZWDongle_0: CAN received
2015.06.14 17:01:37 5: SW: 01080013070286110573
2015.06.14 17:01:37 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 011301
2015.06.14 17:01:37 5: SW: 06
2015.06.14 17:01:37 5: ZWDongle_0 dispatch 011301
2015.06.14 17:01:38 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 00130700
2015.06.14 17:01:38 5: SW: 06
2015.06.14 17:01:38 5: ZW_SEND_DATA:OK received, removing 01080013070286110573 from sendstack
2015.06.14 17:01:38 5: ZWDongle_0 dispatch 00130700
2015.06.14 17:01:38 4: ZWDongle_0 CMD:ZW_SEND_DATA ID:00 ARG:
2015.06.14 17:01:38 4: ZWDongle_0 transmit OK for 07
2015.06.14 17:01:38 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 000400070b861203035f01110101010f
2015.06.14 17:01:38 5: SW: 06
2015.06.14 17:01:38 4: ZWDongle_ReadAnswer for version: 000400070b861203035f01110101010f
2015.06.14 17:01:38 4: ZWDongle_0 CMD:APPLICATION_COMMAND_HANDLER ID:07 ARG:0b861203035f01110101010f
2015.06.14 17:01:38 3: test return value: version:Lib 3 Prot 3.95 App 1.17 HW 1 FWCounter 1 FW 1.15
2015.06.14 17:01:38 5: ZWDongle_Write 00 130702840805
2015.06.14 17:01:38 5: SW: 01080013070284080568
2015.06.14 17:01:38 5: ZWDongle_Write 00 130702840805
2015.06.14 17:01:38 5: ZWDongle_Write reordered sendStack
2015.06.14 17:01:38 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 011301
2015.06.14 17:01:38 5: SW: 06
2015.06.14 17:01:38 5: ZWDongle_0 dispatch 011301
2015.06.14 17:01:38 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 00130700
2015.06.14 17:01:38 5: SW: 06
2015.06.14 17:01:38 5: ZW_SEND_DATA:OK received, removing 01080013070284080568 from sendstack
2015.06.14 17:01:38 5: ZWDongle_0 dispatch 00130700
2015.06.14 17:01:38 4: ZWDongle_0 CMD:ZW_SEND_DATA ID:00 ARG:
2015.06.14 17:01:38 4: ZWDongle_0 transmit OK for 07
2015.06.14 17:01:38 5: SW: 01080013070284080568
2015.06.14 17:01:38 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 011301
2015.06.14 17:01:38 5: SW: 06
2015.06.14 17:01:38 5: ZWDongle_0 dispatch 011301
2015.06.14 17:01:39 2: ZWave_ProcessSendStack: no ACK, resending message
2015.06.14 17:01:39 5: SW: 01080013070284080568
2015.06.14 17:01:39 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 011301
2015.06.14 17:01:39 5: SW: 06
2015.06.14 17:01:39 5: ZWDongle_0 dispatch 011301
2015.06.14 17:01:39 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 00130701
2015.06.14 17:01:39 5: SW: 06
2015.06.14 17:01:39 5: ZWDongle_0 dispatch 00130701
2015.06.14 17:01:39 4: ZWDongle_0 CMD:ZW_SEND_DATA ID:01 ARG:
2015.06.14 17:01:39 2: ZWDongle_0 transmit NO_ACK for 07
2015.06.14 17:01:40 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 00130701
2015.06.14 17:01:40 5: SW: 06
2015.06.14 17:01:40 5: ZWDongle_0 dispatch 00130701
2015.06.14 17:01:40 4: ZWDongle_0 CMD:ZW_SEND_DATA ID:01 ARG:
2015.06.14 17:01:40 2: ZWDongle_0 transmit NO_ACK for 07
2015.06.14 17:01:40 2: ZWave_ProcessSendStack: no ACK, resending message
2015.06.14 17:01:40 5: SW: 01080013070284080568
2015.06.14 17:01:40 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 011301
2015.06.14 17:01:40 5: SW: 06
2015.06.14 17:01:40 5: ZWDongle_0 dispatch 011301
2015.06.14 17:01:41 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 00130701
2015.06.14 17:01:41 5: SW: 06
2015.06.14 17:01:41 5: ZWDongle_0 dispatch 00130701
2015.06.14 17:01:41 4: ZWDongle_0 CMD:ZW_SEND_DATA ID:01 ARG:
2015.06.14 17:01:41 2: ZWDongle_0 transmit NO_ACK for 07
2015.06.14 17:01:42 2: ZWave_ProcessSendStack: no ACK, resending message
2015.06.14 17:01:42 5: SW: 01080013070284080568
2015.06.14 17:01:42 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 011301
2015.06.14 17:01:42 5: SW: 06
2015.06.14 17:01:42 5: ZWDongle_0 dispatch 011301
2015.06.14 17:01:43 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 00130701
2015.06.14 17:01:43 5: SW: 06
2015.06.14 17:01:43 5: ZWDongle_0 dispatch 00130701
2015.06.14 17:01:43 4: ZWDongle_0 CMD:ZW_SEND_DATA ID:01 ARG:
2015.06.14 17:01:43 2: ZWDongle_0 transmit NO_ACK for 07
2015.06.14 17:01:43 2: ZWave_ProcessSendStack: no ACK, resending message
2015.06.14 17:01:43 1: ERROR: max send retries reached, removing 01080013070284080568 from sendstack


Was mir noch aufgefallen ist: Die Abarbeitung der wakeup-Sendeliste mit foreach führt häufiger zum Abbruch eines Befehls nach den max. Sendeversuchen mit CAN seit den Änderungen in 00_ZWDongle. Derzeit verliere ich bei 10 Befehlen im Schnitt 2 wegen max. CAN. Bei den Tests zur Einführung der Behandlungsänderung der WAKE_UP Geräte hatte ich (damals) keine solchen Verluste und dort hatte ich bis zu 80 Befehle in einem Rutsch. Unterschied in der Testhardware: damals Philio PSM02 und heute PST02; also 400er bzw. 500er Chipsatz.

rudolfkoenig

Habs wieder umgebaut :), diesmal mit dem KFOB und ZW_APPLICATION_UPDATE getestet (der schickt bei mir entgegen Doku kein wakeup:notification).

Konnte 4 gets vom Stack + 1 via notify abarbeiten. Auch wenn nichts auf dem Stack ist, klappt das get vom notify.
wakeupNoMoreInformation wird zum Schluss gesendet.

krikan

Danke für Deine wakeupNoMoreInformation-Änderungen.

Zitat von: rudolfkoenig am 06 Juni 2015, 15:21:42
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?
Schiebe das Thema der Wiederholungen ($hash->{MaxSendRetries}=3;) noch mal hoch, da mich das nach einer weiteren halben Stunde Dauertests nur noch stört: NO_ACK einmal reicht, Wiederholungen führen bei mir nur zu unnötigen Sendeversuchen, Verzögerungen und einem gut gefülltem Log.
Darum meine Bitte/Wunsch:
Kann das nicht bitte zumindest abschaltbar sein? Oder gibt es einen Grund, das so zu machen, den ich noch nicht erkannt habe?

rudolfkoenig

Den Grund kennt nur gero. Wir wiederholen jetzt bai CAN, NACK und ausbleiben von ACK.
Entweder bei CAN oder bei NACK sollte man nicht wiederholen, weiss nur nicht bei welchem.

Meinst du mit "NO_ACK einmal reicht", dass es im Fall von NACK kein resend passieren soll?

krikan

Hier ein Beispiel, wenn ich einen nicht errichbaren Aktor abfrage:
2015.06.15 19:25:49 2: ZWave get ZWave_SWITCH_MULTILEVEL_4 version
2015.06.15 19:25:49 5: ZWDongle_Write 00 130402861105
2015.06.15 19:25:49 5: SW: 01080013040286110570
2015.06.15 19:25:49 4: ZWDongle_ReadAnswer arg:version regexp:^00040004..86
2015.06.15 19:25:49 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 011301
2015.06.15 19:25:49 5: SW: 06
2015.06.15 19:25:49 5: ZWDongle_0 dispatch 011301
2015.06.15 19:25:49 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 00130501
2015.06.15 19:25:49 5: SW: 06
2015.06.15 19:25:49 5: ZWDongle_0 dispatch 00130501
2015.06.15 19:25:49 4: ZWDongle_0 CMD:ZW_SEND_DATA ID:01 ARG:
2015.06.15 19:25:49 2: ZWDongle_0 transmit NO_ACK for 05
2015.06.15 19:25:52 5: ZWDongle_ReadAnswer: select timeout
2015.06.15 19:25:52 2: ZWave_ProcessSendStack: no ACK, resending message
2015.06.15 19:25:52 5: SW: 01080013040286110570
2015.06.15 19:25:53 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 011301
2015.06.15 19:25:53 5: SW: 06
2015.06.15 19:25:53 5: ZWDongle_0 dispatch 011301
2015.06.15 19:25:53 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 00130501
2015.06.15 19:25:53 5: SW: 06
2015.06.15 19:25:53 5: ZWDongle_0 dispatch 00130501
2015.06.15 19:25:53 4: ZWDongle_0 CMD:ZW_SEND_DATA ID:01 ARG:
2015.06.15 19:25:53 2: ZWDongle_0 transmit NO_ACK for 05
2015.06.15 19:25:54 2: ZWave_ProcessSendStack: no ACK, resending message
2015.06.15 19:25:54 5: SW: 01080013040286110570
2015.06.15 19:25:54 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 011301
2015.06.15 19:25:54 5: SW: 06
2015.06.15 19:25:54 5: ZWDongle_0 dispatch 011301
2015.06.15 19:25:54 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 00130501
2015.06.15 19:25:54 5: SW: 06
2015.06.15 19:25:54 5: ZWDongle_0 dispatch 00130501
2015.06.15 19:25:54 4: ZWDongle_0 CMD:ZW_SEND_DATA ID:01 ARG:
2015.06.15 19:25:54 2: ZWDongle_0 transmit NO_ACK for 05
2015.06.15 19:25:55 2: ZWave_ProcessSendStack: no ACK, resending message
2015.06.15 19:25:55 5: SW: 01080013040286110570
2015.06.15 19:25:55 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 011301
2015.06.15 19:25:55 5: SW: 06
2015.06.15 19:25:55 5: ZWDongle_0 dispatch 011301
2015.06.15 19:25:56 4: ZWDongle_Read ZWDongle_0: sending ACK, processing 00130501
2015.06.15 19:25:56 5: SW: 06
2015.06.15 19:25:56 5: ZWDongle_0 dispatch 00130501
2015.06.15 19:25:56 4: ZWDongle_0 CMD:ZW_SEND_DATA ID:01 ARG:
2015.06.15 19:25:56 2: ZWDongle_0 transmit NO_ACK for 05
2015.06.15 19:25:57 2: ZWave_ProcessSendStack: no ACK, resending message
2015.06.15 19:25:57 1: ERROR: max send retries reached, removing 01080013040286110570 from sendstack

Nach meinem Verständnis kann ab diesem "transmit NO_ACK" (00130501)
2015.06.15 19:25:49 2: ZWDongle_0 transmit NO_ACK for 05
schon abgebrochen werden. Alles danach führt (bei mir) zum gleichen Ergebnis, da Aktor nicht antwortet bzw. ZW_SEND_DATA callback in Timeout läuft.

Kann auch gerne auf Gero warten, hatte verdrängt, dass er 2 Wochen weg ist 8).

rudolfkoenig

Hab dein Vorschlag eingebaut.

krikan

Danke für Deine Änderung.

Zitat von: krikan am 14 Juni 2015, 17:32:49
Was mir noch aufgefallen ist: Die Abarbeitung der wakeup-Sendeliste mit foreach führt häufiger zum Abbruch eines Befehls nach den max. Sendeversuchen mit CAN seit den Änderungen in 00_ZWDongle. Derzeit verliere ich bei 10 Befehlen im Schnitt 2 wegen max. CAN. Bei den Tests zur Einführung der Behandlungsänderung der WAKE_UP Geräte hatte ich (damals) keine solchen Verluste und dort hatte ich bis zu 80 Befehle in einem Rutsch. Unterschied in der Testhardware: damals Philio PSM02 und heute PST02; also 400er bzw. 500er Chipsatz.
Das Problem habe ich interessanterweise nach dieser Ändernung nicht mehr. Ich bin jetzt bis auf 40 Befehle mit notify hochgegangen und habe keine Befehlsverluste wegen zu vieler CAN mehr. Das läuft nun sauber durch.

gero

Hallo,

ich bin wieder da. Allerdings türmt sich auf meinem Schreibtisch die Arbeit und daher ist die Zeit etwas knapp. Ich werde versuchen die letzten Post nöglichst bald in Ruhe durchzulesen und die Änderungen zu testen.

Gruß,
Gero
Odroid C1 - CULV3-868, JeeLink
16 x TX 29 DTH
MAX!: 15x Heizkörperthermostat+, 2x Wandthermostat, 14x Fenserkontakt, 1x Ecotaster
FS20 S4A, FS20IRF, BSB-Heizungssteuerung über Atmega2560
Z-Wave: ZME_UZB1, Fibaro Wall Plug + Motion Sensor