HMUARTLGW HMUART_Keller: Device not initialized (state: 99, ok) but asked to send data. Dropping: As101CA011F14C231E3F630201C80000E101
HMUARTLGW HMUART_Grill unexpected info about Co_CPU_BL received (module crashed?), reopening
Geräte werden nicht geschaltet.
Diese Meldungen melden alle per WLAN eingebundenen 00_HMUARTLGW seit einem Update und Neustart heute morgen (kein Update der HM-Module). Alle sind Teil einer VCCU. Ich habe seit Ewigkeiten keine Änderungen am HM-System vorgenommen und kann mir nicht erklären, wo das herkommt.
Ein Beispiellist eines HMUART (disconnected, weil ich sie geschlossen habe, damit das Gesamtsystem nicht gestört wird-eigentlich zeigen sie Ok an, wenn sie offen sind):
Internals:
AssignedPeerCnt 6
CNT 49
Clients :CUL_HM:
DEF uart://10.x.x.161:23
DEVCNT 34
DevState 0
DevType UART
DeviceName 10.x.x.161:23
FUUID 5e7a08e8-f33f-be23-8eb8-173850010ed3fce4
FVERSION 00_HMUARTLGW.pm:0.252030/2021-11-08
LastOpen 1749823820.75863
NAME HMUART_Grill
NOTIFYDEV global
NR 1241
NTFY_ORDER 47-HMUART_Grill
RAWMSG 040200
RSSI -73
STATE closed
TYPE HMUARTLGW
XmitOpen 0
eventCount 6
model HM-MOD-UART
msgLoadCurrent 0
msgLoadHistory -/-/-/-/-/-/-/-/-/-/-/-
msgLoadHistoryAbs 0/-/-/-/-/-/-/-/-/-/-/-/-
owner_CCU CCU
Helper:
CreditTimer 8
Initialized 1
AckPending:
49:
cmd 03
dst 0
frame FD00030031033E09
time 1749823948.19413
LastSendLen:
3
3
Log:
IDs:
RoundTrip:
Delay 0.0834970474243164
loadLvl:
lastHistory 1749823833.07882
MatchList:
1:CUL_HM ^A......................
PeerQueue:
HASH(0x564353a523d8)
HASH(0x5643526372a0)
Peers:
20A659
241FA4
3268BE
3E6F7E +3E6F7E,00,01,00
5E13AB
62D6A1
665C6D
6A4A45
6A4B59
6D3091 +6D3091,00,01,00
6D3204 +6D3204,00,01,00
READINGS:
2025-06-13 15:30:09 D-HMIdAssigned XXXXXX
2025-06-13 15:30:09 D-HMIdOriginal 488B3F
2025-06-13 15:30:09 D-firmware 1.4.1
2025-06-13 16:10:27 D-serialNr
2025-06-13 16:09:42 D-type HM-MOD-UART
2025-06-13 16:12:28 cond disconnected
2025-06-13 16:12:28 load 0
2025-06-13 16:12:28 loadLvl suspended
2025-06-13 16:12:28 state closed
helper:
Attributes:
DbLogExclude .*
alias HMUART Grill
appOptions { "template": "hmlan", "system": "true", "connected": { "watcher": "ActionDetector" } }
event-on-change-reading state,loadLvl,cond
group IODevices
hmId XXXXXXX
icon hm_usb
room Verwaltung->Server
der open Zustand ist so:
2025-06-13 17:11:42 cond ok
2025-06-13 17:11:42 load 0
2025-06-13 17:11:42 loadLvl low
2025-06-13 17:11:38 state opened
Hat jemand eine Idee dazu?
Edit: mehrere Neustarts, reopen, close, open etc. haben natürlich nicht geholfen.
Es kommen außerdem mittlerweile noch folgende Meldung:
HMUARTLGW HMUART_Flur Adding peer 5E1752 failed! You have probably forced an unknown aesKey for this device.
HMUARTLGW HMUART_Flur invalid checksum received, dropping frame (FD0004010E0401B54C)!
Nun ist es aber so, dass der aesKey in der VCCU steht und dort vermutlich schon seit weit über 10 Jahren. Daran hat sich nichts geändert UND die 3 HLMANS können damit auch jedes Gerät weiterhin schalten. Tatsächlich bin ich aktuell ratlos.
hm...
spärliche Infos, ohne Kontext, zudem verfremdet.
"checksum" riecht nach schlechtem/gestörtem funk.
"crashed" kenne ich im zusammenhang mit virtuellen devices.
vielleicht mal "roundtrip delay" beobachten?
https://forum.fhem.de/index.php?msg=852060 (https://forum.fhem.de/index.php?msg=852060)
Danke aber "verfremdet" habe ich nur Daten, die ohnehin nicht relevant sein können (IP Adresse und HMID und ja, die sind alle korrekt). Welche Daten kann ich noch liefern?
Kontext.Eigentlich ist alles da.
Sehr alte HM Installation mit VCCU, 3 HM-LANS und 3 HMUART per Wifi. Alles tadellos bis zum genannten Neustart. Wir können da gerne ins Detail gehen. Erstmal wollte ich auf Leute hinaus, die schon ähnliche Probleme hatten und die Fehler kennen. Das scheint aber nicht der Fall zu sein. Im Forum gibt es genau einen Beitrag zum "Dropping" Fehler. Da lag es an einer falschen HMID als Attribut im UART. Das kann ich hier ausschließen. Zumal wirklich seit Jahren nichts am HM-Teil der Installation geändert wurde.
Das Wifi ist völlig in Ordnung. Keine Probleme. BidCos-Funk über die 3 etwas anders verteilten HMLANs funktioniert im gesamten Haus und im Garten so gut, dass ich aktuell sogar auf die 3 HMUART verzichten kann. Störungen schließe ich weitgehend aus. Alle 3 HMUART sind gut verteilt im Haus. Dass alle gleichzeitig gleich gestört sind, ist unwahrscheinlich. Virtuelle Devices nutze ich in HM nicht.
Ein Restore hat im Übrigen keine Besserung gebracht. Es liegt also nicht am Update. Die fhem.pl war aktualisiert, aber auch auf dem alten Stand gibt es keinen Unterschied.
Danke für den Tipp mit roundtrip delay. Werde ich mir ansehen. Als erstes baue ich einen neuen HMUART auf und teste den.
Ergänzung. Das aktivieren von logIDs sys in einem der UART füllt mein Log hiermit:
2025.06.16 15:11:23.066 0: HMUARTLGW HMUART_Keller roundtrip delay: 0.0054
2025.06.16 15:11:23.066 0: HMUARTLGW HMUART_Keller GetSet Ack: 02, state 98
2025.06.16 15:11:23.065 0: HMUARTLGW HMUART_Keller recv: 00 040200, state 98
2025.06.16 15:11:23.059 0: HMUARTLGW HMUART_Keller send: 00 08
2025.06.16 15:11:22.635 0: HMUARTLGW HMUART_Keller Ack with invalid/old counter received, dropping. We: 31, device: 38, state: 99, msg: 0 040200
2025.06.16 15:11:22.634 0: HMUARTLGW HMUART_Keller recv: 00 040200, state 99
2025.06.16 15:11:08.102 0: HMUARTLGW HMUART_Keller roundtrip delay: 0.0461
2025.06.16 15:11:08.102 0: HMUARTLGW HMUART_Keller GetSet Ack: 02, state 98
2025.06.16 15:11:08.102 0: HMUARTLGW HMUART_Keller recv: 00 040200, state 98
2025.06.16 15:11:08.055 0: HMUARTLGW HMUART_Keller send: 00 08
2025.06.16 15:11:07.613 0: HMUARTLGW HMUART_Keller Ack with invalid/old counter received, dropping. We: 30, device: 37, state: 99, msg: 0 040200
2025.06.16 15:11:07.613 0: HMUARTLGW HMUART_Keller recv: 00 040200, state 99
2025.06.16 15:11:06.529 0: HMUARTLGW HMUART_Keller GetSet Ack: 07, state 90
2025.06.16 15:11:06.528 0: HMUARTLGW HMUART_Keller recv: 01 040701010008, state 90
2025.06.16 15:11:06.483 0: HMUARTLGW HMUART_Keller GetSet Ack: 07, state 93
2025.06.16 15:11:06.483 0: HMUARTLGW HMUART_Keller recv: 01 040701010009FFFFFFFFFFFFFFFF, state 93
2025.06.16 15:11:06.424 0: HMUARTLGW HMUART_Keller GetSet Ack: 07, state 90
2025.06.16 15:11:06.423 0: HMUARTLGW HMUART_Keller recv: 01 040701010009FFFFFFFFFFFFFFFF, state 90
2025.06.16 15:11:06.210 1: HMUARTLGW HMUART_Keller: Device not initialized (state: 90, ok) but asked to send data. Dropping: As0DEA8002F14C233618B701017800
2025.06.16 15:11:06.180 1: HMUARTLGW HMUART_Keller: Device not initialized (state: 90, ok) but asked to send data. Dropping: As0DEB8002F14C233618B701017800
2025.06.16 15:10:52.822 0: HMUARTLGW HMUART_Keller roundtrip delay: 0.0254
2025.06.16 15:10:52.822 0: HMUARTLGW HMUART_Keller GetSet Ack: 02, state 98
2025.06.16 15:10:52.822 0: HMUARTLGW HMUART_Keller recv: 00 040200, state 98
2025.06.16 15:10:52.796 0: HMUARTLGW HMUART_Keller send: 00 08
2025.06.16 15:10:52.778 0: HMUARTLGW HMUART_Keller Ack with invalid/old counter received, dropping. We: 26, device: 36, state: 99, msg: 0 040200
2025.06.16 15:10:52.778 0: HMUARTLGW HMUART_Keller recv: 00 040200, state 99
moin marvin,
das log zeigt 3 saubere roundtrip messungen (5.4ms - 46.1ms), ohne probleme.
im vergleich mit den aussagen im verlinkten thread sind das für wlan sensationelle werte. allerdings nur eine momentaufnahme. die streuung über den tag wird sicher noch grösser sein. dein grill-uart zeigt im list zb 83.5ms.
die kommunikation bis zum hmuart scheint also ok zu sein.
die fehlermeldungen sind von anderen aktionen.
2025.06.16 15:11:23.066 0: HMUARTLGW HMUART_Keller roundtrip delay: 0.0054
2025.06.16 15:11:23.066 0: HMUARTLGW HMUART_Keller GetSet Ack: 02, state 98
2025.06.16 15:11:23.065 0: HMUARTLGW HMUART_Keller recv: 00 040200, state 98
2025.06.16 15:11:23.059 0: HMUARTLGW HMUART_Keller send: 00 08
anbei zum vergleich mal ein plot von meinem hmuart, der direkt am gpio auf einem pi3 sitzt.
############
ich habe den verdacht, dass die hmuarts eventuell ein problem mit ihrem eeprom haben. denn im list beim grill-uart, falls das list an der stelle original ist, sieht der "Peers:" abschnitt seltsam unvollständig aus.
das habe ich so noch nie gesehen.
Peers:
20A659
241FA4
3268BE
3E6F7E +3E6F7E,00,01,00
5E13AB
62D6A1
665C6D
6A4A45
6A4B59
6D3091 +6D3091,00,01,00
6D3204 +6D3204,00,01,00
was da genau passiert, würde ein log mit logIDs=sys,all plus verbose=5 zeigen, wenn man zb "set restart/reopen" macht. anschliessend jeweils mit einem list des hmuart vergleichen.
############
schon seltsam, dass scheinbar alle 3 hmuarts, das selbe problem haben sollen.
gab es eventuell gewitter, stromausfall oder ähnliches?
oder gab es einen korrupten hmip funkbefehl?
sind alle 3 identisch aufgebaut?
vielleicht mal 10 min stromlos machen und rebooten.
netzteil checken und/oder fw neu aufspielen?
elkos, falls vorhanden, tauschen?
Zitatschon seltsam, dass scheinbar alle 3 hmuarts, das selbe problem haben sollen
Genau das macht mich wahnsinnig. Es gab keinen Anlass und alle 3 haben bis zu dem besagten Neustart von FHEM einwandfrei funktioniert. Nun haben alle 3 das gleiche Problem. Und das schließt ja eigentlich viele der gängigen Lösungen aus. Wenn es einer wäre, wäre er vermutlich einfach raus geflogen und ich hätte nie wieder daran gedacht.
Ich wollte eigentlich testweise einen neuen aufbauen, bin aber nicht dazu gekommen und mir fehlt noch Hardware. Deinen Hinweis mit dem korrupten IP Befehl klingt interessant. Es passt zwar zeitlich nicht 100 Prozent zusammen aber ich habe neulich Geräte an die Raspberrymatic angelernt. Vermutlich teste ich nun ein neu aufspielen der FW als erstes.
Danke.