Sporadisch keine ZWAVE Kommunikation mehr

[HGButte]

Habe ursprünglich mein Problem beim Fibaro Motionsensor vermutet, was sich aber als falsch herausgestellt hat.
(siehe https://forum.fhem.de/index.php/topic,73696.0.html)

Aufgefallen ist mir das Problem dadurch, dass mir meine Batterie getriebenen Devices (POPP Z-Weather und Fibaro FGMS001) irgendwann unter Tage keine Messwerte mehr liefern. Passiert so alle 3-7 Tage.

Problem trat heute um 9:55Uhr auf. Seitdem keinerlei ZWAVE Kommunikation mehr im LogFile zu sehen.
Bis ich um 16:36:54 dann absichtlich einen meiner Rollos per Fibaro Aktor über das FHEMWEB geschlossen habe.
Sofort danach habe ich auch Daten vom Popp Z-Weather bekommen. Evtl. waren die noch in der Empfangsqueue.

LogFile:

Code Auswählen Erweitern


2017.08.31 09:55:03.570 4: ZWDongle_Read ZWAVE1: rcvd 0004000e053105060102 (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.08.31 09:55:03.571 5: SW: 06
2017.08.31 09:55:03.573 5: ZWAVE1: dispatch 0004000e053105060102
2017.08.31 09:55:03.573 4: CMD:APPLICATION_COMMAND_HANDLER ID:0e ARG:053105060102 CB:00
2017.08.31 09:55:03.724 4: ZWDongle_Read ZWAVE1: rcvd 0004000e063105012200be (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.08.31 09:55:03.724 5: SW: 06
2017.08.31 09:55:03.726 5: ZWAVE1: dispatch 0004000e063105012200be
2017.08.31 09:55:03.726 4: CMD:APPLICATION_COMMAND_HANDLER ID:0e ARG:063105012200be CB:00
2017.08.31 09:55:03.875 4: ZWDongle_Read ZWAVE1: rcvd 0004000e053105030164 (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.08.31 09:55:03.876 5: SW: 06
2017.08.31 09:55:03.878 5: ZWAVE1: dispatch 0004000e053105030164
2017.08.31 09:55:03.878 4: CMD:APPLICATION_COMMAND_HANDLER ID:0e ARG:053105030164 CB:00
2017.08.31 09:55:04.033 4: ZWDongle_Read ZWAVE1: rcvd 0004000e063105050164be (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.08.31 09:55:04.033 5: SW: 06
2017.08.31 09:55:04.035 5: ZWAVE1: dispatch 0004000e063105050164be
2017.08.31 09:55:04.036 4: CMD:APPLICATION_COMMAND_HANDLER ID:0e ARG:063105050164be CB:00
2017.08.31 09:55:04.182 4: ZWDongle_Read ZWAVE1: rcvd 0004000e063105092203de (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.08.31 09:55:04.182 5: SW: 06
2017.08.31 09:55:04.184 5: ZWAVE1: dispatch 0004000e063105092203de
2017.08.31 09:55:04.185 4: CMD:APPLICATION_COMMAND_HANDLER ID:0e ARG:063105092203de CB:00
2017.08.31 09:55:18.976 4: ZWDongle_Read ZWAVE1: rcvd 0004000e0631050b2200bb (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.08.31 09:55:18.976 5: SW: 06
2017.08.31 09:55:18.978 5: ZWAVE1: dispatch 0004000e0631050b2200bb
2017.08.31 09:55:18.978 4: CMD:APPLICATION_COMMAND_HANDLER ID:0e ARG:0631050b2200bb CB:00
2017.08.31 09:55:19.129 4: ZWDongle_Read ZWAVE1: rcvd 0004000e0631050b2200bb (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.08.31 09:55:19.129 5: SW: 06
2017.08.31 09:55:19.130 5: ZWAVE1: dispatch 0004000e0631050b2200bb
2017.08.31 09:55:19.131 4: CMD:APPLICATION_COMMAND_HANDLER ID:0e ARG:0631050b2200bb CB:00
2017.08.31 09:55:19.302 4: ZWDongle_Read ZWAVE1: rcvd 0004000e0631050b2200bb (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.08.31 09:55:19.302 5: SW: 06
2017.08.31 09:55:19.304 5: ZWAVE1: dispatch 0004000e0631050b2200bb
2017.08.31 09:55:19.304 4: CMD:APPLICATION_COMMAND_HANDLER ID:0e ARG:0631050b2200bb CB:00
2017.08.31 09:55:19.474 4: ZWDongle_Read ZWAVE1: rcvd 0004000e0631050b2200bb (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.08.31 09:55:19.474 5: SW: 06
2017.08.31 09:55:19.476 5: ZWAVE1: dispatch 0004000e0631050b2200bb
2017.08.31 09:55:19.476 4: CMD:APPLICATION_COMMAND_HANDLER ID:0e ARG:0631050b2200bb CB:00
2017.08.31 09:55:19.633 4: ZWDongle_Read ZWAVE1: rcvd 0004000e0e3202411c0017a9d8010c0017a9d2 (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.08.31 09:55:19.633 5: SW: 06
2017.08.31 09:55:19.634 5: ZWAVE1: dispatch 0004000e0e3202411c0017a9d8010c0017a9d2
2017.08.31 09:55:19.635 4: CMD:APPLICATION_COMMAND_HANDLER ID:0e ARG:0e3202411c0017a9d8010c0017a9d2 CB:00
2017.08.31 09:55:19.786 4: ZWDongle_Read ZWAVE1: rcvd 0004000e0e3202411c0017a9d8010c0017a9d2 (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.08.31 09:55:19.786 5: SW: 06
2017.08.31 09:55:19.788 5: ZWAVE1: dispatch 0004000e0e3202411c0017a9d8010c0017a9d2
2017.08.31 09:55:19.788 4: CMD:APPLICATION_COMMAND_HANDLER ID:0e ARG:0e3202411c0017a9d8010c0017a9d2 CB:00
2017.08.31 09:55:19.937 4: ZWDongle_Read ZWAVE1: rcvd 0004000e0e3202411c0017a9d8010c0017a9d2 (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.08.31 09:55:19.937 5: SW: 06
2017.08.31 09:55:19.939 5: ZWAVE1: dispatch 0004000e0e3202411c0017a9d8010c0017a9d2
2017.08.31 09:55:19.939 4: CMD:APPLICATION_COMMAND_HANDLER ID:0e ARG:0e3202411c0017a9d8010c0017a9d2 CB:00
2017.08.31 09:55:20.093 4: ZWDongle_Read ZWAVE1: rcvd 0004000e0e3202411c0017a9d8010c0017a9d2 (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.08.31 09:55:20.093 5: SW: 06
2017.08.31 09:55:20.095 5: ZWAVE1: dispatch 0004000e0e3202411c0017a9d8010c0017a9d2
2017.08.31 09:55:20.096 4: CMD:APPLICATION_COMMAND_HANDLER ID:0e ARG:0e3202411c0017a9d8010c0017a9d2 CB:00
2017.08.31 09:55:20.240 4: ZWDongle_Read ZWAVE1: rcvd 0004000e0e320241a401f07495010c01f072b6 (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.08.31 09:55:20.240 5: SW: 06
2017.08.31 09:55:20.242 5: ZWAVE1: dispatch 0004000e0e320241a401f07495010c01f072b6
2017.08.31 09:55:20.242 4: CMD:APPLICATION_COMMAND_HANDLER ID:0e ARG:0e320241a401f07495010c01f072b6 CB:00
2017.08.31 09:55:20.387 4: ZWDongle_Read ZWAVE1: rcvd 0004000e0e320241a401f07495010c01f072b6 (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.08.31 09:55:20.387 5: SW: 06
2017.08.31 09:55:20.389 5: ZWAVE1: dispatch 0004000e0e320241a401f07495010c01f072b6
2017.08.31 09:55:20.390 4: CMD:APPLICATION_COMMAND_HANDLER ID:0e ARG:0e320241a401f07495010c01f072b6 CB:00
2017.08.31 09:55:20.544 4: ZWDongle_Read ZWAVE1: rcvd 0004000e0e320241a401f07495010c01f072b6 (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.08.31 09:55:20.544 5: SW: 06
2017.08.31 09:55:20.546 5: ZWAVE1: dispatch 0004000e0e320241a401f07495010c01f072b6
2017.08.31 09:55:20.547 4: CMD:APPLICATION_COMMAND_HANDLER ID:0e ARG:0e320241a401f07495010c01f072b6 CB:00
2017.08.31 09:55:20.701 4: ZWDongle_Read ZWAVE1: rcvd 0004000e0e320241a401f07495010c01f072b6 (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.08.31 09:55:20.701 5: SW: 06
2017.08.31 09:55:20.703 5: ZWAVE1: dispatch 0004000e0e320241a401f07495010c01f072b6
2017.08.31 09:55:20.703 4: CMD:APPLICATION_COMMAND_HANDLER ID:0e ARG:0e320241a401f07495010c01f072b6 CB:00
2017.08.31 16:36:54.094 5: ZWDongle_Write 001305032601FF2513 (f352ded4)
2017.08.31 16:36:54.095 5: SW: 010a001305032601FF25130e
2017.08.31 16:36:54.192 5: ACK received, WaitForAck=>2 for 010a001305032601FF25130e
2017.08.31 16:36:54.192 4: ZWDongle_Read ZWAVE1: rcvd 011301 (answer ZW_SEND_DATA), sending ACK
2017.08.31 16:36:54.193 5: SW: 06
2017.08.31 16:36:54.194 5: ZWAVE1: dispatch 011301
2017.08.31 16:36:54.196 4: ZWDongle_Read ZWAVE1: rcvd 00040006063105012200ed (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.08.31 16:36:54.196 5: SW: 06
2017.08.31 16:36:54.198 5: ZWAVE1: dispatch 00040006063105012200ed
2017.08.31 16:36:54.198 4: CMD:APPLICATION_COMMAND_HANDLER ID:06 ARG:063105012200ed CB:00
2017.08.31 16:36:54.212 4: ZWDongle_Read ZWAVE1: rcvd 0004000e053105060102 (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.08.31 16:36:54.212 5: SW: 06
2017.08.31 16:36:54.214 5: ZWAVE1: dispatch 0004000e053105060102
2017.08.31 16:36:54.214 4: CMD:APPLICATION_COMMAND_HANDLER ID:0e ARG:053105060102 CB:00
2017.08.31 16:36:54.374 4: ZWDongle_Read ZWAVE1: rcvd 0004000e063105012200be (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.08.31 16:36:54.374 5: SW: 06
2017.08.31 16:36:54.376 5: ZWAVE1: dispatch 0004000e063105012200be
2017.08.31 16:36:54.376 4: CMD:APPLICATION_COMMAND_HANDLER ID:0e ARG:063105012200be CB:00
2017.08.31 16:36:56.171 4: ZWDongle_Read ZWAVE1: rcvd 000400050891010f2603036363 (request APPLICATION_COMMAND_HANDLER), sending ACK
2017.08.31 16:36:56.172 5: SW: 06
2017.08.31 16:36:56.174 5: ZWAVE1: dispatch 000400050891010f2603036363
2017.08.31 16:36:56.174 4: CMD:APPLICATION_COMMAND_HANDLER ID:05 ARG:0891010f2603036363 CB:00
2017.08.31 16:36:56.261 4: no response from device, removing 010a001305032601FF25130e from dongle sendstack
2017.08.31 16:37:13.048 5: ZWDongle_Write 001305032601002514 (f352ded4)
2017.08.31 16:37:13.049 5: SW: 010a001305032601002514f6
2017.08.31 16:37:13.136 5: ACK received, WaitForAck=>2 for 010a001305032601002514f6
2017.08.31 16:37:13.136 4: ZWDongle_Read ZWAVE1: rcvd 011301 (answer ZW_SEND_DATA), sending ACK
2017.08.31 16:37:13.137 5: SW: 06
2017.08.31 16:37:13.139 5: ZWAVE1: dispatch 011301
2017.08.31 16:37:13.141 4: ZWDongle_Read ZWAVE1: rcvd 001314000001 (request ZW_SEND_DATA), sending ACK
2017.08.31 16:37:13.141 5: SW: 06
2017.08.31 16:37:13.143 5: device ack reveived, removing 010a001305032601002514f6 from dongle sendstack
2017.08.31 16:37:13.143 5: ZWAVE1: dispatch 001314000001
2017.08.31 16:37:13.143 4: CMD:ZW_SEND_DATA ID:00 ARG:0001 CB:14
2017.08.31 16:37:13.143 4: ZWAVE1 transmit OK for CB 14, target EG_WO_RAFF_02
2017.08.31 16:37:14.391 5: ZWDongle_Write 001305032601FF2515 (f352ded4)
2017.08.31 16:37:14.392 5: SW: 010a001305032601FF251508
2017.08.31 16:37:14.473 5: ACK received, WaitForAck=>2 for 010a001305032601FF251508
2017.08.31 16:37:14.474 4: ZWDongle_Read ZWAVE1: rcvd 011301 (answer ZW_SEND_DATA), sending ACK
2017.08.31 16:37:14.474 5: SW: 06
2017.08.31 16:37:14.476 5: ZWAVE1: dispatch 011301
2017.08.31 16:37:14.478 4: ZWDongle_Read ZWAVE1: rcvd 001315000002 (request ZW_SEND_DATA), sending ACK
2017.08.31 16:37:14.478 5: SW: 06
2017.08.31 16:37:14.480 5: device ack reveived, removing 010a001305032601FF251508 from dongle sendstack
2017.08.31 16:37:14.481 5: ZWAVE1: dispatch 001315000002
2017.08.31 16:37:14.481 4: CMD:ZW_SEND_DATA ID:00 ARG:0002 CB:15
2017.08.31 16:37:14.482 4: ZWAVE1 transmit OK for CB 15, target EG_WO_RAFF_02




LogFile Popp Z-Weather:

Was mir hier auffällt, ist dass öfters die gleichen Parameter 2-3 hintereinander auftauchen.
Ist hier schon was falsch ?

Code Auswählen Erweitern


2017-08-31_09:55:03 GA_WIND_01 velocity: 2 m/s
2017-08-31_09:55:03 GA_WIND_01 temperature: 19.0 C
2017-08-31_09:55:03 GA_WIND_01 luminance: 100 %
2017-08-31_09:55:04 GA_WIND_01 humidity: 100 %
2017-08-31_09:55:04 GA_WIND_01 barometricPressure: 99.0 kPa
2017-08-31_09:55:18 GA_WIND_01 dewpoint: 18.7 C
2017-08-31_09:55:19 GA_WIND_01 dewpoint: 18.7 C
2017-08-31_09:55:19 GA_WIND_01 dewpoint: 18.7 C
2017-08-31_09:55:19 GA_WIND_01 dewpoint: 18.7 C
2017-08-31_09:55:19 GA_WIND_01 energy:  1550808 pulseCount previous: 1550802 delta_time: 268 s
2017-08-31_09:55:19 GA_WIND_01 energy:  1550808 pulseCount previous: 1550802 delta_time: 268 s
2017-08-31_09:55:19 GA_WIND_01 energy:  1550808 pulseCount previous: 1550802 delta_time: 268 s
2017-08-31_09:55:20 GA_WIND_01 energy:  1550808 pulseCount previous: 1550802 delta_time: 268 s
2017-08-31_09:55:20 GA_WIND_01 energy:  325.35701 kWh previous: 325.35222 delta_time: 268 s
2017-08-31_09:55:20 GA_WIND_01 energy:  325.35701 kWh previous: 325.35222 delta_time: 268 s
2017-08-31_09:55:20 GA_WIND_01 energy:  325.35701 kWh previous: 325.35222 delta_time: 268 s
2017-08-31_09:55:20 GA_WIND_01 energy:  325.35701 kWh previous: 325.35222 delta_time: 268 s
2017-08-31_16:36:54 GA_WIND_01 velocity: 2 m/s
2017-08-31_16:36:54 GA_WIND_01 temperature: 19.0 C
2017-08-31_16:40:47 GA_WIND_01 velocity: 3 m/s
2017-08-31_16:40:47 GA_WIND_01 temperature: 20.6 C
2017-08-31_16:40:47 GA_WIND_01 luminance: 100 %
2017-08-31_16:40:47 GA_WIND_01 humidity: 63 %
2017-08-31_16:40:48 GA_WIND_01 barometricPressure: 99.4 kPa
2017-08-31_16:40:48 GA_WIND_01 dewpoint: 13.2 C
2017-08-31_16:40:48 GA_WIND_01 energy:  1552145 pulseCount previous: 1552133 delta_time: 268 s
2017-08-31_16:40:48 GA_WIND_01 energy:  325.68426 kWh previous: 325.68066 delta_time: 268 s
2017-08-31_16:40:48 GA_WIND_01 battery: 98 %


LogFile Fibaro FGMS001

Code Auswählen Erweitern


2017-08-31_08:16:39 EG_WO_AUGE_1 closed
2017-08-31_08:16:39 EG_WO_AUGE_1 reportedState: closed
2017-08-31_08:32:26 EG_WO_AUGE_1 temperature: 23.7 C
2017-08-31_09:02:16 EG_WO_AUGE_1 temperature: 23.6 C
2017-08-31_09:32:05 EG_WO_AUGE_1 temperature: 23.7 C
2017-08-31_16:36:54 EG_WO_AUGE_1 temperature: 23.7 C
2017-08-31_16:39:00 EG_WO_AUGE_1 open
2017-08-31_16:39:00 EG_WO_AUGE_1 reportedState: open
2017-08-31_16:40:55 EG_WO_AUGE_1 closed
2017-08-31_16:40:55 EG_WO_AUGE_1 reportedState: closed
2017-08-31_16:42:30 EG_WO_AUGE_1 open
2017-08-31_16:42:30 EG_WO_AUGE_1 reportedState: open
2017-08-31_16:43:42 EG_WO_AUGE_1 closed


[rudolfkoenig]

Bis ich um 16:36:54 dann absichtlich einen meiner Rollos per Fibaro Aktor über das FHEMWEB geschlossen habe.
Sofort danach habe ich auch Daten vom Popp Z-Weather bekommen.

Ich vermute einen Firmware Fehler im USB-Cotroller (bzw. Razberry). Um diese Theorie zu verifizieren koennte man regelmaessig ein get zu einen der Aktoren absetzen.

Was mir hier auffällt, ist dass öfters die gleichen Parameter 2-3 hintereinander auftauchen.

Das ist nicht ueblich/normal. Moegliche Ursachen, die mir einfallen:
- Beim Sensor ist der Controller in mehrere Assoziationsgruppen eingetragen
- schwer erreichbarer Sensor, der seine Daten ueber mehrere Router schickt, und der USB-Controller schafft es nicht die Duplikate zu filtern (Controller Bug).

[HGButte]

Ich habe jetzt erstmal alles aktualisiert. Btw ist ein razberry.
Ich schaue mal ob das was ändert.

Danke für die Info zunächst.

[HGButte]

Habe mir dann z-way installation das Problem geholt, dass ich nun UNKNOWN Devices in den AssocGroups meine Zwave Geräte habe.

z.B. ein Fibaro Roller Shutter:

Code Auswählen Erweitern


assocGroup_1 Max 16 Nodes UNKNOWN_179 UNKNOWN_0
assocGroup_2 Max 16 Nodes UNKNOWN_177 UNKNOWN_0
assocGroup_3 Max 1 Nodes ZWAVE1 UNKNOWN_179 UNKNOWN_0


Habe versucht damit die Unknowns zu entfernen:

Code Auswählen Erweitern

set Shutter associationDel 1 179 0

Frage ich die Assoziationen dann erneut ab

Code Auswählen Erweitern


assocGroup_1 Max 16 Nodes UNKNOWN_182 UNKNOWN_0
assocGroup_2 Max 16 Nodes UNKNOWN_177 UNKNOWN_0
assocGroup_3 Max 1 Nodes ZWAVE1 UNKNOWN_179 UNKNOWN_0


D.h. 179 wechselt auf 182.
Das geht endlos so weiter. Mal wechselt es auf 181, dann wieder 182, etc.

Wie bekomme ich diese wieder weg?

In der nodeList des Zwave Ctrl tauchen keine UNKOWNs auf.

[HGButte]

Ich kann in die assocGroup1 existierende Nodes hinzufügen, die UNKOWN_ Einträge tauchen immer am Ende der Auflistung auf.

Habe ich mir evtl. mit dem letzten FHEM Update einen Bug geholt ?

[HGButte]

Habe mal die mca readings abgefragt.
Jetzt habe ich 255 mca_xxx readings

Code Auswählen Erweitern


mcaGroups 176128
mcaSupportedGroupings 2
mca_1 Max 7 Nodes ZWAVE1:1 UNKNOWN_177:0
mca_10 Max 0 Nodes UNKNOWN_165
mca_100 Max 0 Nodes UNKNOWN_179
...
mca_2 Max 7 Nodes ZWAVE1:2 UNKNOWN_177:0
mca_20 Max 0 Nodes UNKNOWN_168


[rudolfkoenig]

Habe ich mir evtl. mit dem letzten FHEM Update einen Bug geholt ?

Ich finde das bei den Symptomen sehr unwahrscheinlich. Ich tippe immer noch auf einem Hardware-Fehler.

[HGButte]

Mittlerweile glaube ich du hast wirklich Recht.

Habe jetzt wechselweise mit z-way und mit fhem herumprobiert.
z-way zeigt mir im Experten Modus in den Statistiken ca. 8-10% CRC Fehler. Desweiteren läuft z-way auch nicht astrein.

Firmware des Razberry ist die aktuellste 5.23.
Meinst du ein Factory Reset könnte helfen?

Oder hilft nur eine neu Anschaffung?

Btw hatte zu Beginn meiner Fhem Zeit noch einen raspi 1 mit razberry. Hatte allerdings zunehmend Probleme als ich immer mehr fibaro roller shutter eingebunden habe. Habe dann irgendwann einen raspi 3 angeschafft, dann lief die ganze Sache wieder deutlich besser.
Bin mir nicht sicher ob das Problem von Anfang an existiert.

[HGButte]

Ich hatte meinen Razberry etwas versteckt hinterm HIFI Rack eingebaut. Habe ihn jetzt eine Weile mal etwas zugänglicher platziert und nun auch keine Probleme mehr mit hängender ZWAVE Kommunikation mehr gehabt.

Leider bekomme ich diese UNKNOWN Devices nicht mehr aus den Assoc Listen raus.