Hallo,
seit ein paar Tagen bleiben die Nachrichten zu zwei Heizkörperthermostaten in der SendQueue des CUL_MAX hängen und blockieren Nachrichten an andere HT. Leere ich die Queue, wird normal mit den anderen HT kommuniziert, bis wieder eine Nachricht an diese beiden problematischen HT rausgeht und in der Queue oben landet. Die Kommunikation ist inzwischen mit allen HT eingestellt. Mein Eindruck vorhin und gestern täuschte. Ich kann mit FHEM mit dem CUL kommunizieren und mir mit den GET-Befehlen des CUL-Devices die Readings aktualisieren lassen (uptime, ...).
Die problematischen HT haben Batterien, die ich erst im Sommer ausgetauscht hat und funktionieren manuell bei Tastenbedienung auch normal. Sie kommunizieren lediglich nicht mehr mit dem CUL. Auch ein neues Pairing gerade hat nichts geändert.
FHEM neugestartet habe ich auch seit Freitag einige Male. Die initial leere Queue füllt sich in Abhängigkeit meiner Heizkörpersteuerung mit neuen Befehlen, die nicht abgearbeitet werden.
Die letzten Readingupdates gab es z.B. für batteryState und desiredTemperature am Freitag um 23:39 Uhr. Da habe ich schon längst geschlafen und war (im Urlaub) auch die Stunden davor nicht auf dem System irgendwie aktiv.
Im EventLog sehe ich mit Verbose=5 "CUL cul UNKNOWNCODE Z0F00046015A6AC0000000019182400D0". Wer sendet den und weshalb ist der unbekannt?
10mCredits sollte es genug geben, da ich keine zusätzlichen Geräte in Betrieb genommen habe und auch an der Kommunikation (Max Scanner, ...) nichts verändert habe. Ich sehe aber gerade bei längerer Betrachtung des Eventlog, dass es wohl doch fehlende 10mCredits sind. Direkt nach dem Leeren der Queue (bzw. Neustart) landet ein Befehl von mir in der Queue und wartet auf Abarbeitung, weil nicht genug Credits vorhanden sind. Wie bekomme ich raus, wer die aufbraucht? Über diesen CUL laufen die Heizkörperthermostate und einige Fensterkontakte (wobei alle Fenster seit Stunden geschlossen sind).
Wo könnte noch eine Fehlerquelle sein, die ich gerade übersehe?
Gruß
Christian
wie immer :
1. list vom CUL und cm Device
2. verbose 5 am cm Device und Log posten
Internals:
CMDS BbCFiAZNkGMKUYRTVWXefmLltux
Clients :FS20:FHT.*:KS300:USF1000:BS:HMS:FS20V: :CUL_EM:CUL_WS:CUL_FHTTK:CUL_HOERMANN: :ESA2000:CUL_IR:CUL_TX:Revolt:IT:UNIRoll:SOMFY: :STACKABLE_CC:TSSTACKED:STACKABLE:CUL_RFR::CUL_TCM97001:CUL_REDIRECT:
DEF cul.fritz.box:2000 1234
DeviceName cul.fritz.box:2000
FD 22
FHTID 1234
FUUID 5c446f66-f33f-ae1f-dc37-f7c68ebc74768fde
NAME cul.maxcul
NR 69
NR_CMD_LAST_H 33
PARTIAL
RAWMSG Z0EAE020215A549123456000119001E04
RSSI -72
STATE Initialized
TYPE CUL
VERSION V 1.66 CUL868
cul.maxcul_MSGCNT 1444
cul.maxcul_TIME 2020-10-28 06:51:13
initString X21
Helper:
DBLOG:
credit10ms:
DbLog:
TIME 1603862518.16814
VALUE 114
state:
DbLog:
TIME 1603864273.43187
VALUE UNKNOWNCODE Z0EAE020215A549123456000119001E
MatchList:
0:FS20V ^81..(04|0c)..0101a001......00[89a-f]...
1:USF1000 ^81..(04|0c)..0101a001a5ceaa00....
2:BS ^81..(04|0c)..0101a001a5cf
3:FS20 ^81..(04|0c)..0101a001
4:FHT ^81..(04|09|0d)..(0909a001|83098301|c409c401)..
5:KS300 ^810d04..4027a001
6:CUL_WS ^K.....
7:CUL_EM ^E0.................$
8:HMS ^810e04......a001
9:CUL_FHTTK ^T[A-F0-9]{8}
A:CUL_RFR ^[0-9A-F]{4}U.
B:CUL_HOERMANN ^R..........
C:ESA2000 ^S................................$
D:CUL_IR ^I............
E:CUL_TX ^TX[A-F0-9]{10}
F:Revolt ^r......................$
G:IT ^i......
H:STACKABLE_CC ^\*
I:UNIRoll ^[0-9A-F]{5}(B|D|E)
J:SOMFY ^Y[r|t|s]:?[A-F0-9]+
K:CUL_TCM97001 ^s[A-F0-9]+
L:CUL_REDIRECT ^o+
M:TSSTACKED ^\*
N:STACKABLE ^\*
OLDREADINGS:
READINGS:
2020-10-27 19:27:07 ccconf freq:868.300MHz bWidth:101KHz rAmpl:33dB sens:8dB
2020-10-27 19:27:30 cmds B b C F i A Z N k G M K U Y R T V W X e f m L l t u x
2020-10-28 06:51:18 credit10ms 8
2020-10-28 06:51:13 state Initialized
2020-10-27 19:10:41 uptime 72 06:54:08
2020-10-27 19:10:49 version V 1.66 CUL868
XMIT_TIME:
1603860759.23991
1603860868.27702
1603860977.79729
1603861087.31308
1603861196.87762
1603861306.14936
1603861415.66329
1603861525.17842
1603861634.69297
1603861743.78724
1603861853.30723
1603861962.82279
1603862072.33832
1603862181.85614
1603862294.87006
1603862406.13118
1603862518.30351
1603862630.7677
1603862962.96783
1603862968.98111
1603862975.49725
1603863069.01098
1603863322.07343
1603863328.58574
1603863397.10092
1603863506.6358
1603863862.26063
1603863868.7727
1603863875.28658
1603863945.30186
1603864054.31739
1603864162.83513
1603864272.35204
powerMap:
readingsDesc:
pM_consumption:
rtype w
pM_energy:
rtype whr
Attributes:
DbLogExclude .*
DbLogInclude credit10ms,state
event-min-interval credit10ms:1800
icon cul_max
model CUL
rfmode MAX
room CUL
Die SendQueue war um 06:55:00 Uhr leer.
2020.10.28 06:55:25 4 : cul.max, send -> cmd:SetTemperature, msgcnt:f1, flags:00, Cmd2id:40, src:MAX_123456 , dst:og.arbeitszimmer.heizung , gid:00 , payload:66 , cul:none
2020.10.28 06:55:25 5 : cul.max, send packet: 0bf100401234561507380066
2020.10.28 06:55:25 5 : cul.max, Send Queue 1 packet in queue
2020.10.28 06:55:25 5 : cul.max, Send Queue cul.maxcul -> needPreamble: 1, necessaryCredit: 110, credit10ms: 145, cul.maxcul CMD_LAST_H: 33
2020.10.28 06:55:25 4 : cul.max, Send Queue packet send : Zs0bf100401234561507380066 to og.arbeitszimmer.heizung with cul.maxcul
2020.10.28 06:55:26 5 : cul.max, Send Queue 1 packet in queue
2020.10.28 06:55:26 5 : cul.max, Send Queue 1 packet in queue
2020.10.28 06:55:27 5 : cul.max, Send Queue 1 packet in queue
2020.10.28 06:55:27 5 : cul.max, Send Queue 1 packet in queue
2020.10.28 06:55:28 5 : cul.max, Send Queue 1 packet in queue
2020.10.28 06:55:28 4 : cul.max, Send Queue retry og.arbeitszimmer.heizung for SetTemperature count: 3
2020.10.28 06:55:31 5 : cul.max, Send Queue 1 packet in queue
2020.10.28 06:55:31 5 : cul.max, Send Queue cul.maxcul -> needPreamble: 1, necessaryCredit: 110, credit10ms: 42, cul.maxcul CMD_LAST_H: 33
2020.10.28 06:55:31 2 : cul.max, cul.maxcul not enough credit! credit10ms is 42, but we need 110. Waiting 68 seconds. Currently 1 messages are waiting to be sent
2020.10.28 06:55:33 4 : cul.max, send -> cmd:SetTemperature, msgcnt:81, flags:00, Cmd2id:40, src:MAX_123456 , dst:eg.wohnzimmer.heizung.esszimmerfenster , gid:00 , payload:65 , cul:none
2020.10.28 06:55:33 5 : cul.max, send packet: 0b81004012345614100d0065
2020.10.28 06:55:42 4 : cul.max, send -> cmd:SetTemperature, msgcnt:b5, flags:00, Cmd2id:40, src:MAX_123456 , dst:og.kinderschlafzimmer.heizung , gid:00 , payload:64 , cul:none
2020.10.28 06:55:42 5 : cul.max, send packet: 0bb5004012345615a5f70064
2020.10.28 06:56:40 5 : cul.max, Send Queue 3 packets in queue
2020.10.28 06:56:40 5 : cul.max, Send Queue cul.maxcul -> needPreamble: 1, necessaryCredit: 110, credit10ms: 111, cul.maxcul CMD_LAST_H: 33
2020.10.28 06:56:40 4 : cul.max, Send Queue packet send : Zs0bf100401234561507380066 to og.arbeitszimmer.heizung with cul.maxcul
2020.10.28 06:56:41 5 : cul.max, Send Queue 3 packets in queue
2020.10.28 06:56:42 5 : cul.max, Send Queue 3 packets in queue
2020.10.28 06:56:42 5 : cul.max, Send Queue 3 packets in queue
2020.10.28 06:56:43 5 : cul.max, Send Queue 3 packets in queue
2020.10.28 06:56:43 5 : cul.max, Send Queue 3 packets in queue
2020.10.28 06:56:43 4 : cul.max, Send Queue retry og.arbeitszimmer.heizung for SetTemperature count: 2
2020.10.28 06:56:46 5 : cul.max, Send Queue 3 packets in queue
2020.10.28 06:56:46 5 : cul.max, Send Queue cul.maxcul -> needPreamble: 1, necessaryCredit: 110, credit10ms: 7, cul.maxcul CMD_LAST_H: 33
2020.10.28 06:56:46 2 : cul.max, cul.maxcul not enough credit! credit10ms is 7, but we need 110. Waiting 103 seconds. Currently 3 messages are waiting to be sent
2020.10.28 06:58:30 5 : cul.max, Send Queue 3 packets in queue
2020.10.28 06:58:30 5 : cul.max, Send Queue cul.maxcul -> needPreamble: 1, necessaryCredit: 110, credit10ms: 111, cul.maxcul CMD_LAST_H: 33
2020.10.28 06:58:30 4 : cul.max, Send Queue packet send : Zs0bf100401234561507380066 to og.arbeitszimmer.heizung with cul.maxcul
2020.10.28 06:58:31 5 : cul.max, Send Queue 3 packets in queue
2020.10.28 06:58:32 5 : cul.max, Send Queue 3 packets in queue
2020.10.28 06:58:32 5 : cul.max, Send Queue 3 packets in queue
2020.10.28 06:58:33 5 : cul.max, Send Queue 3 packets in queue
2020.10.28 06:58:33 5 : cul.max, Send Queue 3 packets in queue
2020.10.28 06:58:33 4 : cul.max, Send Queue retry og.arbeitszimmer.heizung for SetTemperature count: 1
2020.10.28 06:58:36 5 : cul.max, Send Queue 3 packets in queue
2020.10.28 06:58:36 5 : cul.max, Send Queue cul.maxcul -> needPreamble: 1, necessaryCredit: 110, credit10ms: 8, cul.maxcul CMD_LAST_H: 33
2020.10.28 06:58:36 2 : cul.max, cul.maxcul not enough credit! credit10ms is 8, but we need 110. Waiting 102 seconds. Currently 3 messages are waiting to be sent
2020.10.28 07:00:00 4 : cul.max, send -> cmd:SetTemperature, msgcnt:b6, flags:00, Cmd2id:40, src:MAX_123456 , dst:og.kinderschlafzimmer.heizung , gid:00 , payload:67 , cul:none
2020.10.28 07:00:00 5 : cul.max, send packet: 0bb6004012345615a5f70067
2020.10.28 07:00:00 4 : cul.max, send -> cmd:SetTemperature, msgcnt:e2, flags:00, Cmd2id:40, src:MAX_123456 , dst:og.kinderzimmer.heizung , gid:00 , payload:67 , cul:none
2020.10.28 07:00:00 5 : cul.max, send packet: 0be2004012345615a6ac0067
2020.10.28 07:00:19 5 : cul.max, Send Queue 5 packets in queue
2020.10.28 07:00:19 5 : cul.max, Send Queue cul.maxcul -> needPreamble: 1, necessaryCredit: 110, credit10ms: 102, cul.maxcul CMD_LAST_H: 33
2020.10.28 07:00:19 2 : cul.max, cul.maxcul not enough credit! credit10ms is 102, but we need 110. Waiting 8 seconds. Currently 5 messages are waiting to be sent
2020.10.28 07:00:28 5 : cul.max, Send Queue 5 packets in queue
2020.10.28 07:00:28 5 : cul.max, Send Queue cul.maxcul -> needPreamble: 1, necessaryCredit: 110, credit10ms: 112, cul.maxcul CMD_LAST_H: 33
2020.10.28 07:00:28 4 : cul.max, Send Queue packet send : Zs0bf100401234561507380066 to og.arbeitszimmer.heizung with cul.maxcul
2020.10.28 07:00:29 5 : cul.max, Send Queue 5 packets in queue
2020.10.28 07:00:30 5 : cul.max, Send Queue 5 packets in queue
2020.10.28 07:00:30 5 : cul.max, Send Queue 5 packets in queue
2020.10.28 07:00:31 5 : cul.max, Send Queue 5 packets in queue
2020.10.28 07:00:31 5 : cul.max, Send Queue 5 packets in queue
2020.10.28 07:00:32 5 : cul.max, Send Queue 5 packets in queue
2020.10.28 07:00:32 3 : cul.max, Send Queue missing ack from og.arbeitszimmer.heizung for SetTemperature, removing from queue
2020.10.28 07:00:32 5 : cul.max, Send Queue 4 packets in queue
2020.10.28 07:00:32 5 : cul.max, Send Queue cul.maxcul -> needPreamble: 1, necessaryCredit: 110, credit10ms: 6, cul.maxcul CMD_LAST_H: 33
2020.10.28 07:00:32 2 : cul.max, cul.maxcul not enough credit! credit10ms is 6, but we need 110. Waiting 104 seconds. Currently 4 messages are waiting to be sent
2020.10.28 07:01:48 5 : cul.max, BroadcastTime payload : 141c0781b0
2020.10.28 07:01:48 5 : cul.max, Broadcast time to 15a6ac
2020.10.28 07:01:48 4 : cul.max, send -> cmd:TimeInformation, msgcnt:e3, flags:04, Cmd2id:03, src:MAX_123456 , dst:og.kinderzimmer.heizung , gid:00 , payload:141c0781b0 , cul:none
2020.10.28 07:01:48 5 : cul.max, send packet: 0fe3040312345615a6ac00141c0781b0
2020.10.28 07:01:48 4 : cul.max, periodical TimeInformation sent to og.kinderzimmer.heizung
2020.10.28 07:02:17 5 : cul.max, Send Queue 5 packets in queue
2020.10.28 07:02:17 5 : cul.max, Send Queue cul.maxcul -> needPreamble: 1, necessaryCredit: 110, credit10ms: 111, cul.maxcul CMD_LAST_H: 33
2020.10.28 07:02:17 4 : cul.max, Send Queue packet send : Zs0b81004012345614100d0065 to eg.wohnzimmer.heizung.esszimmerfenster with cul.maxcul
2020.10.28 07:02:18 5 : cul.max, Send Queue 5 packets in queue
2020.10.28 07:02:18 5 : cul.max, Send Queue 5 packets in queue
2020.10.28 07:02:19 5 : cul.max, Send Queue 5 packets in queue
2020.10.28 07:02:19 5 : cul.max, Send Queue 5 packets in queue
2020.10.28 07:02:20 5 : cul.max, Send Queue 5 packets in queue
2020.10.28 07:02:20 4 : cul.max, Send Queue retry eg.wohnzimmer.heizung.esszimmerfenster for SetTemperature count: 3
2020.10.28 07:02:23 5 : cul.max, Send Queue 5 packets in queue
2020.10.28 07:02:23 5 : cul.max, Send Queue cul.maxcul -> needPreamble: 1, necessaryCredit: 110, credit10ms: 8, cul.maxcul CMD_LAST_H: 33
2020.10.28 07:02:23 2 : cul.max, cul.maxcul not enough credit! credit10ms is 8, but we need 110. Waiting 102 seconds. Currently 5 messages are waiting to be sent
2020.10.28 07:04:07 5 : cul.max, Send Queue 5 packets in queue
2020.10.28 07:04:07 5 : cul.max, Send Queue cul.maxcul -> needPreamble: 1, necessaryCredit: 110, credit10ms: 111, cul.maxcul CMD_LAST_H: 33
2020.10.28 07:04:07 4 : cul.max, Send Queue packet send : Zs0b81004012345614100d0065 to eg.wohnzimmer.heizung.esszimmerfenster with cul.maxcul
2020.10.28 07:04:08 5 : cul.max, Send Queue 5 packets in queue
2020.10.28 07:04:08 5 : cul.max, Send Queue 5 packets in queue
2020.10.28 07:04:09 5 : cul.max, Send Queue 5 packets in queue
2020.10.28 07:04:09 5 : cul.max, Send Queue 5 packets in queue
2020.10.28 07:04:10 5 : cul.max, Send Queue 5 packets in queue
2020.10.28 07:04:10 5 : cul.max, Send Queue 5 packets in queue
2020.10.28 07:04:10 4 : cul.max, Send Queue retry eg.wohnzimmer.heizung.esszimmerfenster for SetTemperature count: 2
2020.10.28 07:04:13 5 : cul.max, Send Queue 5 packets in queue
2020.10.28 07:04:13 5 : cul.max, Send Queue cul.maxcul -> needPreamble: 1, necessaryCredit: 110, credit10ms: 8, cul.maxcul CMD_LAST_H: 33
2020.10.28 07:04:13 2 : cul.max, cul.maxcul not enough credit! credit10ms is 8, but we need 110. Waiting 102 seconds. Currently 5 messages are waiting to be sent
Dein Problem hat starke Ähnlichkeit mit https://forum.fhem.de/index.php/topic,115314.0.html -> Stichwort initString.
Wobei bei dir der CUL durchaus MAX Telegramme empfängt -> Z0EAE020215A549123456000119001E04
aber weder der initString passt noch bei dir die Clients / MatchList.
Die Frage ist nun gab es in letzter Zeit Änderungen am 00_CUL Modul das deine und des anderen Users Merkwürdigkeiten erklären ?
Wie alt ist deine 00_CUL.pm bzw. wenn sie neu ist hast du noch eine ältere Version ?
Hallo,
die 00_CUL ist vom 16. Juni 2020. Da hat sich also "in letzter Zeit" nichts geändert.
Gruß
Christian
stimmt, habe mir eben auf dem Testsystem via update die letzte 00_CUL.pm geholt.
Geh doch mal beim CUL auf Details und ändere den rfmode. Bei mir aktualisiert sich je nach Auswahl sofort die Client Liste.
Die muß bei rfmode MAX umspringen auf
:CUL_MAX:HMS:CUL_IR:STACKABLE_CC:TSSTACKED:STACKABLE:
Hallo,
ich habe im CUL den rfmode auf einen anderen Wert gestellt und danach wieder auf MAX zurück geändert. Die Client Liste hat sich entsprechend korrigiert (war vorher anders) und jetzt auch nach 30 Minuten sieht es gut aus und ich bekommen Reading Updates in meinen Heizkörper Devices.
Danke für den Hinweis!
Gruß
Christian
Bleibt halt nur die Frage offen wie so etwas überhaupt passieren kann und wie es nach einem FHEM Neustart aussieht.
Hallo,
nach einem Neustart (zuvor hatte ich vor Tagen die Einstellungen gespeichert) steht der rfmode zwar weiterhin auf MAX, die Clients sehen aber wieder merkwürdig aus und die SendQueue leert sich auch nicht.
Nachdem ich erneut den rfmode umgestellt und wieder auf MAX gesetzt habe, läuft es wieder.
Wie werden die Clients bei einem Neustart ermittelt? Beim Ursprungsposting gab es ganz sicher keinen Neustart kurz vor dem Beginn des Hängenbleibens. Die Ursache da muss eine andere gewesen sein als heute der Neustart.
Gruß
Christian
00_CUL.pm liegt in der Hand von Rudi, ich selbst habe mich mit dem Modul recht wenig beschäftigt.
D.h. ich bin da eigentlich auch nur User, was einem aber nie hindern sollte ruhig der älteren Dame mal unter den Rock zu schauen :)
Mal schauen ob ich den Automatismus verstehe der hinter der Umschaltung der Client Liste steckt beim setzen/wechseln des rfmodes.
Ich könnte jetzt natürlich auch in 14_CUL_MAX die bestehende Prüfung auf den richtigen rfmode erweitern und die Client Liste mit prüfen,
aber IMHO gehört diese Punkt ins 00_CUL Modul. Ich bin kein Freund von Symptomen behandeln statt der Ursache.
ich habe mir das mal genau angeschaut und auch etwas hin und her getestet.
Die Umschaltung der Client/Match List findet statt sobald das 00_CUL Modul auf das Attribut rfmode trifft,
also i.d.R. direkt beim FHEM Neustart. Allerdings gibt es hier eine Bedingung die erfüllt sein muß :
Der CUL muß sich bereits gemeldet haben und das Internal CMDS muß ein "Z" im String haben (Z = MAX)
Meine Theorie bis jetzt :
Das Modul trifft beim Neustart auf das Attribut rfmode = MAX aber der CUL hat seine Init Infos noch nicht gesendet ( Timing Problem ? )
Das sollte sich aber im Log nachlesen lassen, hier mal ein Beispiel wie es richtig ist :
2020.11.08 07:53:16 3: Opening CUL device /dev/serial/by-id/usb-busware.de_CUL868-if00
2020.11.08 07:53:16 3: CUL: Possible commands: BbCFiAZEGMKUYRTVWXefmltux
2020.11.08 07:53:16 3: CUL device opened
2020.11.08 07:53:16 2: Switched CUL rfmode to MAX
man sieht open-> CMDS -> opened -> rfmode
liegt die Meldung Possible commands: BbCFiAZEGMKUYRTVWXefmltux nicht vor müsste laut Code in 00_CUL eine not supported Meldung erscheinen.
Kannst du bitte mal dein Log auf diesen Abschnitt checken wenn das Problem wieder auftritt ?