Timing-Fehler in CUL-Firmware verursacht rf_Error

John · 12 Februar 2013, 20:01:42

rfError kommt sehr häufig bei den Fensterkontakten.

Ablauf mit aktueller CUL-Firmware:


Fenster auf (LED vom Fensterkontakt blinkt 3x)
Fenster zu (LED vom Fensterkontakt blinkt 3x)

Code Auswählen


inform raw
fhem> 
CUL CUL Z0B620002123456019D400000
CUL_MAX CULMAX0 MAX,1,ShutterContactState,019d40,12
CUL CUL Z0B620630019D401234560012
CUL CUL Z0B620002123456019D400000
CUL_MAX CULMAX0 MAX,1,ShutterContactState,019d40,52
CUL CUL Z0B620630019D401234560052
CUL CUL Z0B630002123456019D400000
CUL_MAX CULMAX0 MAX,1,ShutterContactState,019d40,10
CUL CUL Z0B630630019D401234560010
CUL CUL Z0B630002123456019D400000
CUL_MAX CULMAX0 MAX,1,ShutterContactState,019d40,50
CUL CUL Z0B630630019D401234560050
CUL CUL Z0B630002123456019D400000
CUL_MAX CULMAX0 MAX,1,ShutterContactState,019d40,50
CUL CUL Z0B630630019D401234560050
CUL CUL Z0B630002123456019D400000
CUL_MAX CULMAX0 MAX,1,ShutterContactState,019d40,50
CUL CUL Z0B630630019D401234560050
CUL CUL Z0B630002123456019D400000
CUL_MAX CULMAX0 MAX,1,ShutterContactState,019d40,50
CUL CUL Z0B630630019D401234560050

Ablauf mit alter Firmware
siehe Link

Code Auswählen

Fenster auf (LED vom Fensterkontakt blinkt 1x)
Fenster zu (LED vom Fensterkontakt[b] blinkt 1x)

Code Auswählen


CUL_MAX CULMAX0 MAX,1,ShutterContactState,019d40,12
CUL CUL Z0B640630019D401234560012
CUL CUL Z0B650002123456019D400000
CUL_MAX CULMAX0 MAX,1,ShutterContactState,019d40,10
CUL CUL Z0B650630019D401234560010

Mit der alten Firmware habe ich rfError nie gesehen.
Mit der neuen Firmware taucht er sehr oft auf.
3x Blinken weisst darauf hin, dass der Sensor kein ACK vom CUL erhält

Kann es sein, dass das ACK-Telegramm verzögert gesendet wird, so dass der Sensor
dies als Timeout wertet ?

Matthias Gehre · 13 Februar 2013, 02:16:34

Tatsächlich, beim nochmaligen Durchschauen meiner letzten Änderung ist mir ein Fehler aufgefallen.
Probier doch mal angehängte Version.

John · 13 Februar 2013, 21:21:00

Es hat sich gebessert.

Code Auswählen

CUL_MAX CULMAX0 MAX,1,ShutterContactState,019d40,12
CUL CUL Z0B6A0630019D401234560012
CUL CUL Z0B6B0002123456019D400000
CUL_MAX CULMAX0 MAX,1,ShutterContactState,019d40,10
CUL CUL Z0B6B0630019D401234560010
CUL CUL Z0B4B0002123456005CED0000

LED blinkt nur noch 1x statt 3x

Matthias Gehre · 13 Februar 2013, 21:31:16

Ist commited.

John · 13 Februar 2013, 21:39:03

Allerdings gibt es ein neues Problem mit LOVF:

Code Auswählen


2013.02.13 21:08:03 3: CUL_MAX_BroadcastTime: payload 0d0d150883 
2013.02.13 21:08:03 3: broadcast time to 05de1c
2013.02.13 21:08:03 3: CUL_MAX_Send: enqueuing 0f6f040312345605de1c000d0d150883
2013.02.13 21:08:03 3: CUL_MAX_SendQueueHandler: 1 items in queue
2013.02.13 21:08:03 3: SW: Zs0f6f040312345605de1c000d0d150883 (CUL)
2013.02.13 21:08:03 3: broadcast time to 05de22
2013.02.13 21:08:03 3: CUL_MAX_Send: enqueuing 0f5f040312345605de22000d0d150883
2013.02.13 21:08:03 3: broadcast time to 063cce
2013.02.13 21:08:03 3: CUL_MAX_Send: enqueuing 0f750403123456063cce000d0d150883
2013.02.13 21:08:03 3: Not sending to 005b55, type ShutterContact, CULMAX0
2013.02.13 21:08:03 3: broadcast time to 05de6b
2013.02.13 21:08:03 3: CUL_MAX_Send: enqueuing 0f7b040312345605de6b000d0d150883
2013.02.13 21:08:03 3: broadcast time to 05dc36
2013.02.13 21:08:03 3: CUL_MAX_Send: enqueuing 0f7b040312345605dc36000d0d150883
2013.02.13 21:08:03 3: broadcast time to 05de78
2013.02.13 21:08:03 3: CUL_MAX_Send: enqueuing 0f2b040312345605de78000d0d150883
2013.02.13 21:08:03 3: Not sending to 005ced, type ShutterContact, CULMAX0
2013.02.13 21:08:03 3: Not sending to 019d40, type ShutterContact, CULMAX0
2013.02.13 21:08:04 3: CUL: Z0E6F020205DE1C1234560001590D28 -68.5
2013.02.13 21:08:04 3: CUL_MAX_Parse: len 14, msgcnt 6F, msgflag 02, msgTypeRaw Ack, src 05de1c, dst 123456, groupid 0, payload 01590D28
2013.02.13 21:08:04 3: Got matching ack
2013.02.13 21:08:06 3: CUL_MAX_SendQueueHandler: 6 items in queue
2013.02.13 21:08:06 3: CUL_MAX_SendQueueHandler: 5 items in queue
2013.02.13 21:08:06 3: SW: Zs0f5f040312345605de22000d0d150883 (CUL)
2013.02.13 21:08:07 3: CUL: Z0E5F020205DE221234560001190926 -59.5
2013.02.13 21:08:07 3: CUL_MAX_Parse: len 14, msgcnt 5F, msgflag 02, msgTypeRaw Ack, src 05de22, dst 123456, groupid 0, payload 01190926
2013.02.13 21:08:07 3: Got matching ack
2013.02.13 21:08:09 3: CUL_MAX_SendQueueHandler: 5 items in queue
2013.02.13 21:08:09 3: CUL_MAX_SendQueueHandler: 4 items in queue
2013.02.13 21:08:09 3: SW: Zs0f750403123456063cce000d0d150883 (CUL)
2013.02.13 21:08:09 3: CUL: LOVF
2013.02.13 21:08:09 3: CUL: unknown message LOVF
2013.02.13 21:08:12 3: CUL_MAX_SendQueueHandler: 4 items in queue
2013.02.13 21:08:12 2: CUL_MAX_Resend: Missing ack from 063cce for 0f750403123456063cce000d0d150883
2013.02.13 21:08:12 3: CUL_MAX_SendQueueHandler: 3 items in queue
2013.02.13 21:08:12 3: SW: Zs0f7b040312345605de6b000d0d150883 (CUL)
2013.02.13 21:08:12 3: CUL: LOVF
2013.02.13 21:08:12 3: CUL: unknown message LOVF
2013.02.13 21:08:15 3: CUL_MAX_SendQueueHandler: 3 items in queue
2013.02.13 21:08:15 2: CUL_MAX_Resend: Missing ack from 05de6b for 0f7b040312345605de6b000d0d150883
2013.02.13 21:08:15 3: CUL_MAX_SendQueueHandler: 2 items in queue
2013.02.13 21:08:15 3: SW: Zs0f7b040312345605dc36000d0d150883 (CUL)
2013.02.13 21:08:15 3: CUL: LOVF
2013.02.13 21:08:15 3: CUL: unknown message LOVF
2013.02.13 21:08:18 3: CUL_MAX_SendQueueHandler: 2 items in queue
2013.02.13 21:08:18 2: CUL_MAX_Resend: Missing ack from 05dc36 for 0f7b040312345605dc36000d0d150883
2013.02.13 21:08:18 3: CUL_MAX_SendQueueHandler: 1 items in queue
2013.02.13 21:08:18 3: SW: Zs0f2b040312345605de78000d0d150883 (CUL)
2013.02.13 21:08:18 3: CUL: LOVF
2013.02.13 21:08:18 3: CUL: unknown message LOVF
2013.02.13 21:08:21 3: CUL_MAX_SendQueueHandler: 1 items in queue
2013.02.13 21:08:21 2: CUL_MAX_Resend: Missing ack from 05de78 for 0f2b040312345605de78000d0d150883

Die Einträge hier kommen von der Zeitsynchronisation nach einem Neustart richtig ?

Die werden jede Stunde geschickt ?

Kann sich FHEM merken, wann zuletzt ein Timesync realisiert wurde, dann wären wohl die LOVL weniger.
Also z.B. max. 1x pro Stunde.

Matthias Gehre · 13 Februar 2013, 23:25:59

Die werden alle 6 Stunden verschickt. Und mit dem nächsten Update wartet CUL_MAX bis genug
Sendezeit übrig ist, sodass nie wieder ein LOVF kommen sollte. Die Pakete werden dann eben später gesendet.
(Mir fällt gerade auf, dass "später Senden" bei Zeitsynchronisation keine gute Idee ist...)

mimue · 14 Oktober 2014, 06:37:50

Zitat von: Matthias Gehre am 13 Februar 2013, 23:25:59
Und mit dem nächsten Update wartet CUL_MAX bis genug
Sendezeit übrig ist, sodass nie wieder ein LOVF kommen sollte.

Hallo Matthias, die Heizperiode ist bei uns eingeläutet, die MAX! Thermostate erwachen aus dem Sommerschlaf.

Ich habe gerade folgendes im Log gefunden:

Code Auswählen

2014.10.14 03:59:09 2: CUL_MAX_SendQueueHandler: Not enough credit! credit10ms is 1, but we need 110. Waiting 109 seconds.
2014.10.14 03:59:15 2: CUL_MAX: unknown message LOVF

Das ist vorher noch nie aufgetreten ( oder ich habe es übersehen. ) Was mich wundert, ist, daß der CUL_MAX das als "unbekannte" Nachricht abtut. Wenn ich die Beiträge und Statements zu LOVF richtig vertsanden habe, versucht die CUL Firmware dem CUL_MAX Modul zu sagen: Mach mal nicht so schnell !

Oder sehe ich das verkehrt ?

mimue