Fehlermeldung von ZWDongle

PNinBB · 27 November 2017, 09:40:18

Aus bestimmten Gründen habe ich einige Parameter des Fibaro Moduls FGS223 Double Relay geändert und damit vermutlich zu viel "Verkehr" erzeugt.
Im Log sehe ich Meldungen der folgenden Art:

Code Auswählen


. . .
2017.11.27 08:58:27.792 2: ZWDongle_ProcessSendStack: no ACK, resending message 010a00131f032601002519e1
2017.11.27 08:58:28.669 2: ZWDongle_ProcessSendStack: no ACK, resending message 010a00131f032601002519e1
2017.11.27 08:58:29.447 2: ZWave: No ACK from SZ_RL_FL after 5s for sentset:131f032601002519
2017.11.27 08:58:29.740 2: ZWDongle_ProcessSendStack: no ACK, resending message 010a00131f032601002519e1
2017.11.27 08:58:30.441 2: ZWave: No ACK from SZ_RL_FR after 5s for sentset:131e03260100251a
2017.11.27 08:58:30.713 2: ZWDongle_ProcessSendStack: no ACK, resending message 010a00131f032601002519e1
2017.11.27 08:58:30.713 1: ERROR: max send retries reached, removing 010a00131f032601002519e1 from dongle sendstack
2017.11.27 08:58:31.721 2: ZWDongle_ProcessSendStack: no ACK, resending message 010a00131e03260100251ae3
2017.11.27 08:58:32.740 2: ZWDongle_ProcessSendStack: no ACK, resending message 010a00131e03260100251ae3
2017.11.27 08:58:33.715 2: ZWDongle_ProcessSendStack: no ACK, resending message 010a00131e03260100251ae3
2017.11.27 08:58:34.740 2: ZWDongle_ProcessSendStack: no ACK, resending message 010a00131e03260100251ae3
2017.11.27 08:58:35.716 2: ZWDongle_ProcessSendStack: no ACK, resending message 010a00131e03260100251ae3
2017.11.27 08:58:36.716 2: ZWDongle_ProcessSendStack: no ACK, resending message 010a00131e03260100251ae3
2017.11.27 08:58:37.716 2: ZWDongle_ProcessSendStack: no ACK, resending message 010a00131e03260100251ae3
2017.11.27 08:58:37.849 3: ZWave set WZ_RL_FT off 
2017.11.27 08:58:38.730 2: ZWDongle_ProcessSendStack: no ACK, resending message 010a00131e03260100251ae3
2017.11.27 08:58:38.731 1: ERROR: max send retries reached, removing 010a00131e03260100251ae3 from dongle sendstack
. . .

Meine Frage und Bitte ist: gibt es ein Hilfsprogramm oder geeignete (kurze) Dokumentation, damit ich mehr erfahre, was beispielsweise "010a00131e03260100251ae3" bedeutet, z.B. welches Gerät, welcher Parameter den Ärger verursacht. Vermutlich ist es die interne Darstellung des Befehls. Vor allem: was bedeuted "removing . . . from dongle sendstack"; das Gerät oder "nur" das Kommando ?
Momentan habe ich die "alten" Werte wieder hergestellt und FHEM läuft so wie bisher.
Besten Dank im Voraus für einen Hinweis.
Peter

rudolfkoenig · 27 November 2017, 09:56:32

"ZWDongle_ProcessSendStack: no ACK" bedeutet, dass der USB-Controller (vulgo Dongle) die Daten, was FHEM vie USB gesendet hat, nicht bestaetigt hat (also noch nicht per Funk rausgeschickt, das kommt danach). Als Ursache vermute ich einen kaputten Kabel/Anschluss oder USB-Controller. Evtl. hilft ein reset des Controllers (abziehen/anstecken).

Erklaerung fuer die Raw-Messages (010a00131f032601002519e1) gibt es hier im Forum oefters. Kurz:
01: Nachricht an dem Controller
0a: Laenge
0013: Funknachricht
1f: Ziel-NodeId
03: Laenge der Nutzdaten
26: Klasse der Nutzdaten (siehe %zwave_class in 10_ZWave.pm, SWITCH_MULTILEVEL)
0100: off
2519e1: Arte der Routing, CallbackId, Checksum

PNinBB · 28 November 2017, 09:14:53

Zuallererst vielen Dank an Rudi für die schnelle Reaktion.
Das Problem ist allerdings noch nicht gelöst.
Ich gehe momentan davon aus, dass hardwaremäßig alles in Ordnung ist.
Wenn der weiter unten beschriebene Effekt nicht auftritt, läuft alles so wie bisher. Ich hatte den Pi 3 neu gestartet, Fhem ist aktuell und ich habe über die "zw-Software" auch problemlos die neueste Firmware des zwave-Moduls eingespielt. Danach lief FHEM wie es bisher lief.
Wenn der Effekt eintritt, kann ich folgendes registrieren:
1. htop zeigt für den fhem-Prozess um die 50 % CPU-Last, sonst zwischen 0,0.. und 1.0 %).
2. Das Webinterface zu FHEM braucht extrem lange Wartezeiten zum Aufbau der Seite.
3. Der Eventmonitor zeigt permanent eine Flut von Events, die sich immer wiederholen.

Code Auswählen


. . .
2017-11-28 08:35:14.353 structure WZ_RL_Alle rauf
2017-11-28 08:35:14.385 structure WZ_RL_FA rauf
2017-11-28 08:35:14.418 structure WZ_RL_TS rauf
2017-11-28 08:35:14.454 ZWave WZ_RL_FT power: 0.7 W
2017-11-28 08:35:14.491 structure WZ_RL_Alle rauf
2017-11-28 08:35:14.524 structure WZ_RL_FA rauf
2017-11-28 08:35:14.556 structure WZ_RL_TS rauf
2017-11-28 08:35:14.592 ZWave WZ_RL_FT energy:  2.99 kWh
2017-11-28 08:35:15.347 structure WZ_RL_Alle rauf
2017-11-28 08:35:15.397 structure WZ_RL_FA rauf
2017-11-28 08:35:15.429 structure WZ_RL_TS rauf
2017-11-28 08:35:15.465 ZWave WZ_RL_FT power: 0.7 W
2017-11-28 08:35:15.503 structure WZ_RL_Alle rauf
2017-11-28 08:35:15.535 structure WZ_RL_FA rauf
2017-11-28 08:35:15.568 structure WZ_RL_TS rauf
2017-11-28 08:35:15.604 ZWave WZ_RL_FT energy:  2.99 kWh
2017-11-28 08:35:16.347 structure WZ_RL_Alle rauf
2017-11-28 08:35:16.397 structure WZ_RL_FA rauf
2017-11-28 08:35:16.429 structure WZ_RL_TS rauf
2017-11-28 08:35:16.465 ZWave WZ_RL_FT power: 0.7 W
2017-11-28 08:35:16.502 structure WZ_RL_Alle rauf
2017-11-28 08:35:16.535 structure WZ_RL_FA rauf
2017-11-28 08:35:16.567 structure WZ_RL_TS rauf
2017-11-28 08:35:16.603 ZWave WZ_RL_FT energy:  2.99 kWh
. . .

Nach einigen Minuten hört dieses "Bombardement" auf und alles ist wieder normal.
Dieser Ereignissstrom führt dann vermutlich zu den Problemen zwischen FHEM und dem Controller.
Momentan habe ich keine Idee, wer für diesen Ereignisstrom verantwortlich ist.
Die Strukturdefinitionen habe ich schon lange, der "Effekt" begann allerdings am Montag. Die Strukturen betreffen Rollladen (RL) im Wohnzimmer (WZ). An diesem Tag habe ich auch das letzte Update gemacht (?)
Ich suche weiter und bin natürlich für jeden Hinweis dankbar.
Peter

rudolfkoenig · 28 November 2017, 09:28:22

Kannst du bitte die betroffenen Strukturdefinitionen (samt Attribut) zeigen?
Wieviele notify/FileLog/DOIF Instanzen hat die Installation?

PNinBB · 28 November 2017, 10:19:16

Ich konnte gerade die Zeit zwischen den "Bombardements" nutzen, um die Daten zu bekommen.
In meiner Installation sind:
DOIFs: 8 x,
FileLogs: > 9 x; ich bin mir aber nicht sicher, da ich DBLog benutze,
notify: 29 x,
at: 10 x.
Nachfolgend die Details zu den Stukturen:
WZ_RL_Alle:

Code Auswählen

Internals: 
   ATTR       Wohnzimmer 
   CFGFN 
   CHANGEDCNT 21 
   DEF        Wohnzimmer WZ_RL_FS WZ_RL_FT WZ_RL_TT 
   NAME       WZ_RL_Alle 
   NR         141 
   NTFY_ORDER 50-WZ_RL_Alle 
   STATE      rauf 
   TYPE       structure 
   CONTENT: 
     WZ_RL_FS   off 
     WZ_RL_FT   off 
     WZ_RL_TT   off 
   READINGS: 
     2017-11-28 10:02:47   LastDevice      WZ_RL_FT 
     2017-11-28 10:02:47   LastDevice_Abs  WZ_RL_FT 
     2017-11-28 10:02:47   state           off 
Attributes: 
   eventMap   on:runter off:rauf 
   icon       fts_shutter_automatic 
   room       Strukturen 
   sortby     22

WZ_RL_FA:

Code Auswählen

   Internals: 
   ATTR       Wohnzimmer 
   CFGFN 
   CHANGEDCNT 21 
   DEF        Wohnzimmer WZ_RL_FS WZ_RL_FT 
   NAME       WZ_RL_FA 
   NR         143 
   NTFY_ORDER 50-WZ_RL_FA 
   STATE      rauf 
   TYPE       structure 
   CONTENT: 
     WZ_RL_FS   off 
     WZ_RL_FT   off 
   READINGS: 
     2017-11-28 10:02:47   LastDevice      WZ_RL_FT 
     2017-11-28 10:02:47   LastDevice_Abs  WZ_RL_FT 
     2017-11-28 10:02:47   state           off 
Attributes: 
   eventMap   on:runter off:rauf 
   icon       fts_shutter_automatic 
   room       Strukturen 
   sortby     24

WZ_RL_TS:

Code Auswählen

   Internals: 
   ATTR       Wohnzimmer 
   CFGFN 
   CHANGEDCNT 21 
   DEF        Wohnzimmer WZ_RL_FT WZ_RL_TT 
   NAME       WZ_RL_TS 
   NR         142 
   NTFY_ORDER 50-WZ_RL_TS 
   STATE      rauf 
   TYPE       structure 
   CONTENT: 
     WZ_RL_FT   off 
     WZ_RL_TT   off 
   READINGS: 
     2017-11-28 10:02:47   LastDevice      WZ_RL_FT 
     2017-11-28 10:02:47   LastDevice_Abs  WZ_RL_FT 
     2017-11-28 10:02:47   state           off 
Attributes: 
   eventMap   on:runter off:rauf 
   icon       fts_shutter_automatic 
   room       Strukturen 
   sortby     26

Besten Dank im Voraus !
Peter

Ergänzung 12:01:
Die Situation ist fast reproduzierbar:
1. Ausgangszustand: System läuft normal.
2. Es wird irgendein FHEM-Befehl über das Webinterface ausgegeben ("Irgendein" ist zu allgemein; ich habe es mit Ein/Ausschalten von Lampen und Rollladen (auch welchen, die nicht in den erwähnten Strukturen sind) probiert. Anzahl: 5 Versuche.
3. Das "Bombardement" geht los: Im Eventmonitor erscheint die schon oben erwähnte Folge:

Code Auswählen

2017-11-28 11:22:53.102 structure WZ_RL_Alle rauf
2017-11-28 11:22:53.134 structure WZ_RL_FA rauf
2017-11-28 11:22:53.166 structure WZ_RL_TS rauf
2017-11-28 11:22:53.203 ZWave WZ_RL_FT power: 0.7 W
2017-11-28 11:22:53.244 structure WZ_RL_Alle rauf
2017-11-28 11:22:53.276 structure WZ_RL_FA rauf
2017-11-28 11:22:53.308 structure WZ_RL_TS rauf
2017-11-28 11:22:53.344 ZWave WZ_RL_FT energy:  2.99 kWh
2017-11-28 11:22:54.184 structure WZ_RL_Alle rauf
2017-11-28 11:22:54.245 structure WZ_RL_FA rauf
2017-11-28 11:22:54.277 structure WZ_RL_TS rauf
2017-11-28 11:22:54.314 ZWave WZ_RL_FT power: 0.7 W
2017-11-28 11:22:54.355 structure WZ_RL_Alle rauf
2017-11-28 11:22:54.387 structure WZ_RL_FA rauf
2017-11-28 11:22:54.420 structure WZ_RL_TS rauf
2017-11-28 11:22:54.456 ZWave WZ_RL_FT energy:  2.99 kWh
. . . .

Der Vorgang kommt von selbst zu Ende:

Code Auswählen


. . . .
2017-11-28 11:30:43.021 structure WZ_RL_Alle rauf
2017-11-28 11:30:43.054 structure WZ_RL_FA rauf
2017-11-28 11:30:43.087 structure WZ_RL_TS rauf
2017-11-28 11:30:43.128 ZWave WZ_RL_FT energy:  2.99 kWh
2017-11-28 11:30:43.165 structure WZ_RL_Alle rauf
2017-11-28 11:30:43.198 structure WZ_RL_FA rauf
2017-11-28 11:30:43.231 structure WZ_RL_TS rauf
2017-11-28 11:30:43.272 ZWave WZ_RL_FT power: 0.7 W
2017-11-28 11:30:43.309 structure WZ_RL_Alle rauf
2017-11-28 11:30:43.342 structure WZ_RL_FA rauf
2017-11-28 11:30:43.375 structure WZ_RL_TS rauf
2017-11-28 11:30:43.416 ZWave WZ_RL_FT power: 0.7 W
2017-11-28 11:30:43.453 structure WZ_RL_Alle rauf
2017-11-28 11:30:43.488 structure WZ_RL_FA rauf
2017-11-28 11:30:43.521 structure WZ_RL_TS rauf
2017-11-28 11:30:43.562 ZWave WZ_RL_FT power: 0.7 W
2017-11-28 11:30:43.600 structure WZ_RL_Alle rauf
2017-11-28 11:30:43.633 structure WZ_RL_FA rauf
2017-11-28 11:30:43.666 structure WZ_RL_TS rauf
2017-11-28 11:30:43.707 ZWave WZ_RL_FT power: 0.7 W
2017-11-28 11:30:43.744 DbLog myDbLog background_processing_time: 1.3473
2017-11-28 11:30:43.744 DbLog myDbLog sql_processing_time: 1.2830
2017-11-28 11:30:49.498 DbLog myDbLog background_processing_time: 0.4481
2017-11-28 11:30:49.498 DbLog myDbLog sql_processing_time: 0.3531

Die Dauer ist immer ca. 8 Minuten.
In dieser Zeit ist der FHEM-Prozess bei ca. 50 % Last. Einige Kommandos werden auch zwischendurch entgegengenommen und verarbeitet. Man findet beispielsweise 'notification', eingelesene Temperatur- und Batteriewerte im Eventmonitor.
Im fhem.log ist nichts relevantes zu finden.
Und noch etwas: in zwei Fällen tauchte ein zweiter FHEM-Prozess auf.

Code Auswählen

root@xxxxxxServer4 28.11.2017;10:52:48 / 136>ps -A | grep perl
26562 ?        00:08:51 perl
27263 ?        00:00:00 perl
root@xxxxxxServer4 28.11.2017;10:52:51 / 137>

In diesen Fällen musste ich alle beiden Prozesse 'killen' und FHEM neu starten.
Peter

rudolfkoenig · 29 November 2017, 21:58:29

Was nicht in Ordnung ist, sind die vielen Nachrichten vom WZ_RL_FT. Kannst du bitte versuchen den dazugehoerigen ZWDongle mit verbose 5 zu versehen, und im Problemfall ein paar Sekunden mitzuschneiden? Es ist nicht normal, die gleiche Nachricht 10-mal die Sekunde zu bekommen. Das mit sowas dein FHEM dann 50% ausgelastet ist, ist plausibel.

Wg. doppelten perl: bitte mit "ps -elf" pruefen. Mehrfache FHEM-Prozesse sind nicht unbedingt Hinweis auf einen Fehler, da viele Module BlockingCall verwenden, um nicht FHEM zu verklemmen.

PNinBB · 30 November 2017, 18:36:15

Ich habe in der Zwischenzeit die Sache weiter untersucht.
Wenn ich die Strukturen lösche und einem einzelnen Rolladen (beispielsweise WZ_WL_TT) ein Kommando sende, dann zeigt sich im Prinzip das gleiche Verhalten, es wird dann eben von WZ_R_TT 'power' und 'energy' in einer ähnlichen Schleife ausgelesen. Der Befehl selbst wird ausgeführt.
Auch andere Aktionen werden während eines "Bombardements" ausgeführt. Nach immer so ca. 8 Minuten ist der Spuck vorbei !!
Nachfolgend die Auszüge aus dem Logfile und Eventmonitor mit 'ZWDongle verbose 5'; ich habe nur jeweils den Anfang hier angegeben; falls es nicht reicht zur Analyse, dann kann ich nachliefern.
Logfile:

Code Auswählen


2017.11.30 17:34:17.010 3: ZWave set WZ_RL_TT off 
2017.11.30 17:34:17.012 5: ZWDongle_Write 001304032501002502 (ed70b42b)
2017.11.30 17:34:17.013 5: SW: 010a001304032501002502e2
2017.11.30 17:34:17.178 5: ACK received, WaitForAck=>2 for 010a001304032501002502e2
2017.11.30 17:34:17.178 4: ZWDongle_Read ZWAVE: rcvd 011301 (answer ZW_SEND_DATA), sending ACK
2017.11.30 17:34:17.179 5: SW: 06
2017.11.30 17:34:17.180 5: ZWAVE: dispatch 011301
2017.11.30 17:34:17.182 4: ZWDongle_Read ZWAVE: rcvd 0004000306310504220007 (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.11.30 17:34:17.182 5: SW: 06
2017.11.30 17:34:17.184 5: ZWAVE: dispatch 0004000306310504220007
2017.11.30 17:34:17.184 4: CMD:APPLICATION_COMMAND_HANDLER ID:03 ARG:06310504220007 CB:00
2017.11.30 17:34:17.448 4: ZWDongle_Read ZWAVE: rcvd 0004000306310504220007 (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.11.30 17:34:17.448 5: SW: 06
2017.11.30 17:34:17.450 5: ZWAVE: dispatch 0004000306310504220007
2017.11.30 17:34:17.451 4: CMD:APPLICATION_COMMAND_HANDLER ID:03 ARG:06310504220007 CB:00
2017.11.30 17:34:17.714 4: ZWDongle_Read ZWAVE: rcvd 0004000306310504220007 (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.11.30 17:34:17.714 5: SW: 06
2017.11.30 17:34:17.716 5: ZWAVE: dispatch 0004000306310504220007
2017.11.30 17:34:17.717 4: CMD:APPLICATION_COMMAND_HANDLER ID:03 ARG:06310504220007 CB:00
2017.11.30 17:34:17.980 4: ZWDongle_Read ZWAVE: rcvd 0004000306310504220007 (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.11.30 17:34:17.980 5: SW: 06
2017.11.30 17:34:17.982 5: ZWAVE: dispatch 0004000306310504220007
2017.11.30 17:34:17.983 4: CMD:APPLICATION_COMMAND_HANDLER ID:03 ARG:06310504220007 CB:00
2017.11.30 17:34:18.249 4: ZWDongle_Read ZWAVE: rcvd 0004000306310504220007 (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.11.30 17:34:18.249 5: SW: 06
2017.11.30 17:34:18.251 5: ZWAVE: dispatch 0004000306310504220007
2017.11.30 17:34:18.252 4: CMD:APPLICATION_COMMAND_HANDLER ID:03 ARG:06310504220007 CB:00
2017.11.30 17:34:18.516 4: ZWDongle_Read ZWAVE: rcvd 00040004063105042203b7 (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.11.30 17:34:18.516 5: SW: 06
2017.11.30 17:34:18.518 5: ZWAVE: dispatch 00040004063105042203b7
2017.11.30 17:34:18.518 4: CMD:APPLICATION_COMMAND_HANDLER ID:04 ARG:063105042203b7 CB:00
2017.11.30 17:34:18.728 4: ZWDongle_Read ZWAVE: rcvd 000400030a320221440000012c0000 (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.11.30 17:34:18.729 5: SW: 06
2017.11.30 17:34:18.730 5: ZWAVE: dispatch 000400030a320221440000012c0000
2017.11.30 17:34:18.731 4: CMD:APPLICATION_COMMAND_HANDLER ID:03 ARG:0a320221440000012c0000 CB:00
2017.11.30 17:34:19.151 4: ZWDongle_Read ZWAVE: rcvd 0004000306310504220007 (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.11.30 17:34:19.152 5: SW: 06
2017.11.30 17:34:19.153 5: ZWAVE: dispatch 0004000306310504220007
2017.11.30 17:34:19.154 4: CMD:APPLICATION_COMMAND_HANDLER ID:03 ARG:06310504220007 CB:00
2017.11.30 17:34:19.417 4: no response from device, removing 010a001304032501002502e2 from dongle sendstack
2017.11.30 17:34:19.421 4: ZWDongle_Read ZWAVE: rcvd 000400030a320221440000012c0000 (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.11.30 17:34:19.421 5: SW: 06
2017.11.30 17:34:19.423 5: ZWAVE: dispatch 000400030a320221440000012c0000
2017.11.30 17:34:19.423 4: CMD:APPLICATION_COMMAND_HANDLER ID:03 ARG:0a320221440000012c0000 CB:00
2017.11.30 17:34:20.219 4: ZWDongle_Read ZWAVE: rcvd 0004000306310504220007 (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.11.30 17:34:20.220 5: SW: 06
2017.11.30 17:34:20.222 5: ZWAVE: dispatch 0004000306310504220007
2017.11.30 17:34:20.222 4: CMD:APPLICATION_COMMAND_HANDLER ID:03 ARG:06310504220007 CB:00
2017.11.30 17:34:20.486 4: ZWDongle_Read ZWAVE: rcvd 000400030a320221440000012c0000 (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.11.30 17:34:20.487 5: SW: 06
2017.11.30 17:34:20.489 5: ZWAVE: dispatch 000400030a320221440000012c0000
2017.11.30 17:34:20.489 4: CMD:APPLICATION_COMMAND_HANDLER ID:03 ARG:0a320221440000012c0000 CB:00
2017.11.30 17:34:21.151 4: ZWDongle_Read ZWAVE: rcvd 0004000306310504220007 (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.11.30 17:34:21.152 5: SW: 06
2017.11.30 17:34:21.154 5: ZWAVE: dispatch 0004000306310504220007
2017.11.30 17:34:21.154 4: CMD:APPLICATION_COMMAND_HANDLER ID:03 ARG:06310504220007 CB:00
2017.11.30 17:34:21.422 4: ZWDongle_Read ZWAVE: rcvd 000400030a320221440000012c0000 (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.11.30 17:34:21.423 5: SW: 06
2017.11.30 17:34:21.425 5: ZWAVE: dispatch 000400030a320221440000012c0000
2017.11.30 17:34:21.425 4: CMD:APPLICATION_COMMAND_HANDLER ID:03 ARG:0a320221440000012c0000 CB:00
2017.11.30 17:34:22.086 4: ZWDongle_Read ZWAVE: rcvd 00040012033003ff (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.11.30 17:34:22.089 5: SW: 06
2017.11.30 17:34:22.091 5: ZWAVE: dispatch 00040012033003ff
2017.11.30 17:34:22.092 4: CMD:APPLICATION_COMMAND_HANDLER ID:12 ARG:033003ff CB:00
2017.11.30 17:34:22.165 3: ZWave set FL_SK_D1 on 
2017.11.30 17:34:22.166 5: ZWDongle_Write 00130b07600d00012501FF2503 (ed70b42b)
2017.11.30 17:34:22.167 5: SW: 010e00130b07600d00012501FF25037f
2017.11.30 17:34:22.308 4: ZWDongle_Read ZWAVE: rcvd 00040012032001ff (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.11.30 17:34:22.309 5: SW: 06
2017.11.30 17:34:22.311 5: ZWAVE: dispatch 00040012032001ff
2017.11.30 17:34:22.311 4: CMD:APPLICATION_COMMAND_HANDLER ID:12 ARG:032001ff CB:00
2017.11.30 17:34:22.380 4: ZWDongle_Read ZWAVE: CAN received
2017.11.30 17:34:22.382 4: ZWDongle_Read ZWAVE: rcvd 0004001207600d01012001ff (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.11.30 17:34:22.383 5: SW: 06
2017.11.30 17:34:22.385 5: ZWAVE: dispatch 0004001207600d01012001ff
2017.11.30 17:34:22.385 4: CMD:APPLICATION_COMMAND_HANDLER ID:12 ARG:07600d01012001ff CB:00
2017.11.30 17:34:22.451 2: ZWDongle_ProcessSendStack: no ACK, resending message 010e00130b07600d00012501FF25037f
2017.11.30 17:34:22.452 5: SW: 010e00130b07600d00012501FF25037f
2017.11.30 17:34:22.454 4: ZWDongle_Read ZWAVE: rcvd 0004000306310504220007 (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.11.30 17:34:22.455 5: SW: 06
2017.11.30 17:34:22.457 5: ZWAVE: dispatch 0004000306310504220007
2017.11.30 17:34:22.457 4: CMD:APPLICATION_COMMAND_HANDLER ID:03 ARG:06310504220007 CB:00
2017.11.30 17:34:22.718 4: ZWDongle_Read ZWAVE: CAN received
2017.11.30 17:34:22.721 4: ZWDongle_Read ZWAVE: rcvd 000400030a320221440000012c0000 (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.11.30 17:34:22.721 5: SW: 06
2017.11.30 17:34:22.723 5: ZWAVE: dispatch 000400030a320221440000012c0000
2017.11.30 17:34:22.724 4: CMD:APPLICATION_COMMAND_HANDLER ID:03 ARG:0a320221440000012c0000 CB:00
2017.11.30 17:34:22.984 2: ZWDongle_ProcessSendStack: no ACK, resending message 010e00130b07600d00012501FF25037f
2017.11.30 17:34:22.985 5: SW: 010e00130b07600d00012501FF25037f
2017.11.30 17:34:22.988 5: ACK received, WaitForAck=>2 for 010e00130b07600d00012501FF25037f
2017.11.30 17:34:22.992 4: ZWDongle_Read ZWAVE: rcvd 011301 (answer ZW_SEND_DATA), sending ACK
2017.11.30 17:34:22.992 5: SW: 06
2017.11.30 17:34:22.994 5: ZWAVE: dispatch 011301
2017.11.30 17:34:23.007 4: ZWDongle_Read ZWAVE: rcvd 001303000002 (request ZW_SEND_DATA), sending ACK
2017.11.30 17:34:23.007 5: SW: 06
2017.11.30 17:34:23.008 5: device ack reveived, removing 010e00130b07600d00012501FF25037f from dongle sendstack
2017.11.30 17:34:23.009 5: ZWAVE: dispatch 001303000002
2017.11.30 17:34:23.010 4: CMD:ZW_SEND_DATA ID:00 ARG:0002 CB:03
2017.11.30 17:34:23.010 4: ZWAVE transmit OK for CB 03, target FL_AB_RM
2017.11.30 17:34:23.152 4: ZWDongle_Read ZWAVE: rcvd 0004000306310504220007 (request APPLICATION_COMMAND_HANDLER), sending ACK
. . . .

Eventmonitor:

Code Auswählen


2017-11-30 17:34:17.098 structure WZ_RL_Alle undefined
2017-11-30 17:34:17.139 structure WZ_RL_TS undefined
2017-11-30 17:34:17.172 ZWave WZ_RL_TT rauf
2017-11-30 17:34:17.254 structure WZ_RL_Alle undefined
2017-11-30 17:34:17.318 structure WZ_RL_FA runter
2017-11-30 17:34:17.382 structure WZ_RL_TS undefined
2017-11-30 17:34:17.446 ZWave WZ_RL_FT power: 0.7 W
2017-11-30 17:34:17.520 structure WZ_RL_Alle undefined
2017-11-30 17:34:17.584 structure WZ_RL_FA runter
2017-11-30 17:34:17.648 structure WZ_RL_TS undefined
2017-11-30 17:34:17.711 ZWave WZ_RL_FT power: 0.7 W
2017-11-30 17:34:17.786 structure WZ_RL_Alle undefined
2017-11-30 17:34:17.850 structure WZ_RL_FA runter
2017-11-30 17:34:17.914 structure WZ_RL_TS undefined
2017-11-30 17:34:17.977 ZWave WZ_RL_FT power: 0.7 W
2017-11-30 17:34:18.052 structure WZ_RL_Alle undefined
2017-11-30 17:34:18.116 structure WZ_RL_FA runter
2017-11-30 17:34:18.180 structure WZ_RL_TS undefined
2017-11-30 17:34:18.244 ZWave WZ_RL_FT power: 0.7 W
2017-11-30 17:34:18.321 structure WZ_RL_Alle undefined
2017-11-30 17:34:18.386 structure WZ_RL_FA runter
2017-11-30 17:34:18.450 structure WZ_RL_TS undefined
2017-11-30 17:34:18.513 ZWave WZ_RL_FT power: 0.7 W
2017-11-30 17:34:18.588 structure WZ_RL_Alle undefined
2017-11-30 17:34:18.654 structure WZ_RL_TS undefined
2017-11-30 17:34:18.717 ZWave WZ_RL_TT power: 95.1 W
2017-11-30 17:34:18.799 structure WZ_RL_Alle undefined
2017-11-30 17:34:18.864 structure WZ_RL_FA runter
2017-11-30 17:34:18.928 structure WZ_RL_TS undefined
2017-11-30 17:34:18.991 ZWave WZ_RL_FT energy:  3 kWh
2017-11-30 17:34:19.223 structure WZ_RL_Alle undefined
2017-11-30 17:34:19.288 structure WZ_RL_FA runter
2017-11-30 17:34:19.352 structure WZ_RL_TS undefined
2017-11-30 17:34:19.416 ZWave WZ_RL_FT power: 0.7 W
2017-11-30 17:34:19.491 structure WZ_RL_Alle undefined
2017-11-30 17:34:19.555 structure WZ_RL_FA runter
2017-11-30 17:34:19.619 structure WZ_RL_TS undefined
2017-11-30 17:34:19.682 ZWave WZ_RL_FT energy:  3 kWh
2017-11-30 17:34:20.292 structure WZ_RL_Alle undefined
2017-11-30 17:34:20.356 structure WZ_RL_FA runter
2017-11-30 17:34:20.420 structure WZ_RL_TS undefined
2017-11-30 17:34:20.484 ZWave WZ_RL_FT power: 0.7 W
2017-11-30 17:34:20.536 structure WZ_RL_Alle undefined
2017-11-30 17:34:20.569 structure WZ_RL_FA runter
2017-11-30 17:34:20.602 structure WZ_RL_TS undefined
2017-11-30 17:34:20.655 ZWave WZ_RL_FT energy:  3 kWh
2017-11-30 17:34:21.225 structure WZ_RL_Alle undefined
2017-11-30 17:34:21.289 structure WZ_RL_FA runter
2017-11-30 17:34:21.354 structure WZ_RL_TS undefined
2017-11-30 17:34:21.420 ZWave WZ_RL_FT power: 0.7 W
2017-11-30 17:34:21.494 structure WZ_RL_Alle undefined
2017-11-30 17:34:21.558 structure WZ_RL_FA runter
2017-11-30 17:34:21.623 structure WZ_RL_TS undefined
2017-11-30 17:34:21.687 ZWave WZ_RL_FT energy:  3 kWh
2017-11-30 17:34:22.298 readingsGroup rg_Steckdosen FL_SK_D1.state: on
2017-11-30 17:34:22.299 ZWave FL_SK_D1 ein
2017-11-30 17:34:22.306 ZWave FL_DS_SM Bewegung
2017-11-30 17:34:22.306 ZWave FL_DS_SM reportedState: Bewegung
2017-11-30 17:34:22.379 ZWave FL_DS_SM basicSet: 255
2017-11-30 17:34:22.450 ZWave FL_DS_S2 basicSet: 255
2017-11-30 17:34:22.527 structure WZ_RL_Alle undefined
2017-11-30 17:34:22.591 structure WZ_RL_FA runter
2017-11-30 17:34:22.655 structure WZ_RL_TS undefined
2017-11-30 17:34:22.718 ZWave WZ_RL_FT power: 0.7 W
2017-11-30 17:34:22.792 structure WZ_RL_Alle undefined
2017-11-30 17:34:22.856 structure WZ_RL_FA runter
2017-11-30 17:34:22.920 structure WZ_RL_TS undefined
2017-11-30 17:34:22.983 ZWave WZ_RL_FT energy:  3 kWh
2017-11-30 17:34:23.225 structure WZ_RL_Alle undefined
2017-11-30 17:34:23.289 structure WZ_RL_FA runter
2017-11-30 17:34:23.355 structure WZ_RL_TS undefined
2017-11-30 17:34:23.419 ZWave WZ_RL_FT power: 0.7 W
2017-11-30 17:34:23.496 structure WZ_RL_Alle undefined
2017-11-30 17:34:23.550 structure WZ_RL_FA runter
2017-11-30 17:34:23.584 structure WZ_RL_TS undefined
2017-11-30 17:34:23.617 ZWave WZ_RL_FT energy:  3 kWh
. . . .

Bezüglich mehrerer fhem-Prozesse:

ZitatWg. doppelten perl: bitte mit "ps -elf" pruefen. Mehrfache FHEM-Prozesse sind nicht unbedingt Hinweis auf einen Fehler, da viele Module BlockingCall verwenden, um nicht FHEM zu verklemmen.

Ich vermute mal, dass du 'NonblockingCall' meinst; wobei ich dachte, dass dies mit seperaten Threads im gleichen Prozess erledigt wird. Vermutlich irre ich mich da aber; was mich momentan aber weniger beschäftigt !!??
Auf jeden Fall danke für deine Hilfe.
Peter

rudolfkoenig · 30 November 2017, 19:29:45

Habs etwas gefiltert und umformatiert:

Code Auswählen


2017.11.30 17:34:17.184 5: ZWAVE: dispatch 000400 03 06310504220007            nodeId  3: power
2017.11.30 17:34:17.450 5: ZWAVE: dispatch 000400 03 06310504220007            nodeId  3: power
2017.11.30 17:34:17.716 5: ZWAVE: dispatch 000400 03 06310504220007            nodeId  3: power
2017.11.30 17:34:17.982 5: ZWAVE: dispatch 000400 03 06310504220007            nodeId  3: power
2017.11.30 17:34:18.251 5: ZWAVE: dispatch 000400 03 06310504220007            nodeId  3: power
2017.11.30 17:34:18.518 5: ZWAVE: dispatch 000400 04 063105042203b7            nodeId  4: power
2017.11.30 17:34:18.730 5: ZWAVE: dispatch 000400 03 0a320221440000012c0000    nodeId  3: meter
2017.11.30 17:34:19.153 5: ZWAVE: dispatch 000400 03 06310504220007            nodeId  3: power
2017.11.30 17:34:19.423 5: ZWAVE: dispatch 000400 03 0a320221440000012c0000    nodeId  3: meter
2017.11.30 17:34:20.222 5: ZWAVE: dispatch 000400 03 06310504220007            nodeId  3: power
2017.11.30 17:34:20.489 5: ZWAVE: dispatch 000400 03 0a320221440000012c0000    nodeId  3: meter
2017.11.30 17:34:21.154 5: ZWAVE: dispatch 000400 03 06310504220007            nodeId  3: power
2017.11.30 17:34:21.425 5: ZWAVE: dispatch 000400 03 0a320221440000012c0000    nodeId  3: meter
2017.11.30 17:34:22.091 5: ZWAVE: dispatch 000400 12 033003ff                  nodeId 18: sensor_binary
2017.11.30 17:34:22.311 5: ZWAVE: dispatch 000400 12 032001ff                  nodeId 18: basic
2017.11.30 17:34:22.385 5: ZWAVE: dispatch 000400 12 07600d01012001ff          nodeId 18: multichannel/basic
2017.11.30 17:34:22.457 5: ZWAVE: dispatch 000400 03 06310504220007            nodeId  3: power
2017.11.30 17:34:22.723 5: ZWAVE: dispatch 000400 03 0a320221440000012c0000    nodeId  3: meter

=> nodeId 3 stoert, ich vermute es ist kaputt oder falsch konfiguriert. Kann auch an verwirrten Repeater oder kaputen zwdongle liegen. Ich glaube z.Zt. nicht an einem FHEM Bug.

PNinBB · 02 Dezember 2017, 12:44:39

Zuerst die gute Nachricht: es funktioniert alles wieder so wie vorher !
Was habe ich gemacht (in Kurzfassung):
1. Den FIBARO System FGRM222 Roller Shutter Controller 2 per B-Taster am Gerät zurück gesetzt. Danach liess er sich aber nicht wieder inkludieren.
2. Den Modul für ca. 20 min vom Netz genommen.
3. Das erneute Inkludieren ging problemlos.
4. Nach Kalibrierung ging alles so wie früher.
Der Modul war vermutlich durch irgendwelche Störeffekte in einen inkonsisten Status gekommen.
Viel Dank an Rudi und einen schönen 1. Advent !
Peter