Mahlzeit!
Ich hatte vor einiger Zeit häufige Disconnects meines HM-CFG-LAN-Adapters. Nach einer ausgiebigen Performanceoptimierung trat das Problem über Monate nicht mehr auf. Inzwischen ist das Problem wieder aktuell und scheint mit einer Performanceoptimierung nicht mehr behebbar zu sein:
2015.08.22 18:03:25.192 5: HMLAN_Send: HMLAN1 I:K
2015.08.22 18:03:25.194 5: HMLAN/RAW: /HHM-LAN-IF,03C4,KEQ0852354,23A665,23A665,0E5A2071,003B,02
2015.08.22 18:03:25.195 5: HMLAN_Parse: HMLAN1 V:03C4 sNo:KEQ0852354 d:23A665 O:23A665 t:0E5A2071 IDcnt:003B L:2 %
2015.08.22 18:03:25.740 5: HMLAN/RAW: /E2398FF,0000,0E5A2289,FF,FFC1,2886702398FF000000010A2E
2015.08.22 18:03:25.740 5: HMLAN_Parse: HMLAN1 R:E2398FF stat:0000 t:0E5A2289 d:FF r:FFC1 m:28 8670 2398FF 000000 010A2E
2015.08.22 18:03:25.740 5: HMLAN1 dispatch A0C2886702398FF000000010A2E::-63:HMLAN1
2015.08.22 18:03:26.737 5: HMLAN/RAW: /E22261F,0000,0E5A266E,FF,FFC7,DD861022261F0000000AB1050B0018
2015.08.22 18:03:26.737 5: HMLAN_Parse: HMLAN1 R:E22261F stat:0000 t:0E5A266E d:FF r:FFC7 m:DD 8610 22261F 000000 0AB1050B0018
2015.08.22 18:03:26.737 5: HMLAN1 dispatch A0FDD861022261F0000000AB1050B0018::-57:HMLAN1
2015.08.22 18:03:29.731 5: HMLAN/RAW: /E206DFC,0000,0E5A3221,FF,FFD7,97A440206DFC1111110C0F
2015.08.22 18:03:29.732 5: HMLAN_Parse: HMLAN1 R:E206DFC stat:0000 t:0E5A3221 d:FF r:FFD7 m:97 A440 206DFC 111111 0C0F
2015.08.22 18:03:29.732 5: HMLAN1 dispatch A0B97A440206DFC1111110C0F::-41:HMLAN1
2015.08.22 18:03:29.821 5: HMLAN_Send: HMLAN1 S:S56268894 stat: 00 t:00000000 d:01 r:56268894 m:97 8002 111111 206DFC 010C0000
2015.08.22 18:03:29.831 1: N_R_OG.WZ.RC19B_1 Name: OG.WZ.RC19B_1Btn_12, Event: Short (to OG.WZ.RC19B_1), button:12, event:Short
2015.08.22 18:03:29.835 3: CUL_HM set OG.WZ.LadegeraetSessel on-for-timer 10800
2015.08.22 18:03:29.836 5: HMLAN_Send: HMLAN1 S:+22A8DA,00,01,00
2015.08.22 18:03:29.836 5: HMLAN_Send: HMLAN1 S:S562688FA stat: 00 t:00000000 d:01 r:562688FA m:03 A011 23A665 22A8DA 0201C80000D2E6
2015.08.22 18:03:34.114 5: HMLAN_Send: HMLAN1 S:S562699B1 stat: 00 t:00000000 d:01 r:562699B1 m:03 A011 23A665 22A8DA 0201C80000D2E6
2015.08.22 18:03:39.002 5: HMLAN_Send: HMLAN1 S:S5626ACC8 stat: 00 t:00000000 d:01 r:5626ACC8 m:03 A011 23A665 22A8DA 0201C80000D2E6
2015.08.22 18:03:44.723 5: HMLAN_Send: HMLAN1 S:S5626C321 stat: 00 t:00000000 d:01 r:5626C321 m:03 A011 23A665 22A8DA 0201C80000D2E6
2015.08.22 18:03:50.192 5: HMLAN_Send: HMLAN1 I:K
2015.08.22 18:03:51.193 5: HMLAN_Send: HMLAN1 I:K
2015.08.22 18:03:52.193 5: HMLAN_Send: HMLAN1 I:K
2015.08.22 18:03:53.194 5: HMLAN_Send: HMLAN1 I:K
2015.08.22 18:03:54.195 1: HMLAN_Parse: HMLAN1 new condition timeout
2015.08.22 18:03:54.203 1: hmcfglan1:1000 disconnected, waiting to reappear (HMLAN1)
2015.08.22 18:03:54.204 1: HMLAN_Parse: HMLAN1 new condition disconnected
2015.08.22 18:03:54.728 1: hmcfglan1:1000 reappeared (HMLAN1)
2015.08.22 18:03:54.728 5: HMLAN_Send: HMLAN1 I:A23A665
2015.08.22 18:03:54.728 5: HMLAN_Send: HMLAN1 I:C
2015.08.22 18:03:54.728 5: HMLAN_Send: HMLAN1 I:+2624F1,00,01,00
2015.08.22 18:03:54.728 5: HMLAN_Send: HMLAN1 I:+208424,00,01,00
2015.08.22 18:03:54.728 5: HMLAN_Send: HMLAN1 I:+20CE4D,00,01,00
2015.08.22 18:03:54.728 5: HMLAN_Send: HMLAN1 I:+238B31,00,01,00
2015.08.22 18:03:54.728 5: HMLAN_Send: HMLAN1 I:+22F005,00,01,00
2015.08.22 18:03:54.729 5: HMLAN_Send: HMLAN1 I:+2589BD,00,01,00
2015.08.22 18:03:54.729 5: HMLAN_Send: HMLAN1 I:+222CED,00,01,00
2015.08.22 18:03:54.729 5: HMLAN_Send: HMLAN1 I:+2640D1,00,01,00
Das Keep-Alive vor dem Disconnect scheint pünktlich nach 25 Sekunden statt zu finden.
Hier der Vollständigkeit halber die Ausgabe von Apptime:
name function max count total average maxDly
HMLAN1 HMLAN_Read 6915 78217 679044 8.68 0 HASH(HMLAN1)
DbLog DbLog_Log 6909 102677 188234 1.83 0 HASH(DbLog); HASH(OG.BZ.Heizung_Clima)
tmr-HMLAN_KeepAlive keepAlive:HMLAN1 4660 12764 39909 3.13 4786 keepAlive:HMLAN1
HMLAN1 HMLAN_Ready 3002 332 3040 9.16 0 HASH(HMLAN1)
OG.WZ.Harmony harmony_Read 1923 6595 2142 0.32 0 HASH(OG.WZ.Harmony)
OG.WO.VR100 VORWERK_VR100_Read 1635 16783 15343 0.91 0 HASH(OG.WO.VR100)
tmr-at_Exec HASH(0x22a64e0) 1058 3 2712 904.00 5 HASH(A_TempListSave)
D_hminfo_err DOIF_Notify 1044 102677 7530 0.07 0 HASH(D_hminfo_err); HASH(hminfo)
Pushover_pr Pushover_Set 1038 27 7497 277.67 0 HASH(Pushover_pr); Pushover_pr; msg; "HMInfo"; "OK"; ""; 0; ""
tmr-HMinfo_autoUpdate sUpdt:hminfo 871 532 10139 19.06 535 sUpdt:hminfo
tmr-Calendar_Wakeup HASH(0x2b8b120) 857 178 3774 21.20 808 HASH(CAL_pr)
N_OG.BZ.WaschmaschineInBetrieb notify_Exec 813 102677 1983 0.02 0 HASH(N_OG.BZ.WaschmaschineInBetrieb); HASH(OG.BZ.Waschmaschine_Pwr)
Pushover_jv Pushover_Set 807 3 807 269.00 0 HASH(Pushover_jv); Pushover_jv; msg; "Waschmaschine"; "Fertig!"; ""; 0; "bike"
tmr-Calendar_Wakeup HASH(0x2a18f28) 782 177 3225 18.22 928 HASH(CAL_prjv)
FensterTuerenX structure_Notify 614 102677 1989 0.02 0 HASH(FensterTuerenX); HASH(OG.AZ.Fenster)
OG.WZ.Lampen structure_Notify 573 102677 673 0.01 0 HASH(OG.WZ.Lampen); HASH(OG.WZ.Stehlampe2)
Presence_pr PRESENCE_Read 542 5324 631 0.12 0 HASH(Presence_pr)
FensterTueren structure_Notify 529 102677 1049 0.01 0 HASH(FensterTueren); HASH(OG.WO.Eingangstuer)
tmr-Weather_GetUpdateTimer HASH(0x2b16f28) 243 355 6200 17.46 815 HASH(XX.XX.Wetter)
RG_Heizung readingsGroup_Notify 90 102677 17408 0.17 0 HASH(RG_Heizung); HASH(OG.SZ.Thermostat_Climate)
N_OG.BZ.Steckdose notify_Exec 89 25 351 14.04 0 HASH(N_OG.BZ.Steckdose); HASH(OG.BZ.Steckdose)
Das Problem tritt sporadisch auf, jedoch ausschließlich bei Verwendung meiner RC19B-Fernbedienung. Das Setup ist wie folgt: Die Kanäle der Fernbedienung (OG.WZ.RC19B_1, 206DFC) sind mit Kanälen eines virtuellen Homematic-Geräts (OG.WZ.RC19B_1V, 111111) gepeert. Wird einer der Knopfdrücke erkannt löst ein Notify einen Schaltvorgang eines Homematic-Geräts aus. Bei der Fehlersituation leuchtet die rote LED der Fernbedienung und es erscheint CO-ER.
Hier noch der erste Teil von list HMLAN1:
Internals:
CHANGED
DEF hmcfglan1:1000
DeviceName hmcfglan1:1000
FD 10
HMLAN1_MSGCNT 70678
HMLAN1_TIME 2015-08-25 20:28:43
NAME HMLAN1
NR 60
NTFY_ORDER 50-HMLAN1
PARTIAL
RAWMSG E2642EA,0000,0F4BB317,FF,FFCC,0A84702642EA000000010032
RSSI -52
STATE opened
TYPE HMLAN
XmitOpen 1
assignedIDsCnt 59
msgKeepAlive dlyMax:4.786 bufferMin:0
msgLoadCurrent 1
msgLoadHistory 5min steps: 0/0/0/1/0/0/0/0/-1/0/0/0
msgParseDly min:-18 max:6804 last:17 cnt:70527
owner 23A665
owner_CCU vccu
uptime 002 71:16:59.287
CHANGETIME:
Helper:
Dblog:
Xmit-events:
Dblog:
TIME 1440270791.12364
VALUE disconnected:3 init:3 ok:3 timeout:2
Cond:
Dblog:
TIME 1440270791.12364
VALUE ok
Loadlvl:
Dblog:
TIME 1440238665.28969
VALUE low
State:
Dblog:
TIME 1440270791.01883
VALUE CONNECTED
Readings:
2015-08-21 20:21:08 D-HMIdAssigned 23A665
2015-08-21 20:21:08 D-HMIdOriginal 23A665
2015-08-21 20:21:08 D-firmware 0.964
2015-08-21 20:21:08 D-serialNr KEQ0852354
2015-08-22 21:13:11 Xmit-Events disconnected:3 init:3 ok:3 timeout:2
2015-08-22 21:13:11 cond ok
2015-08-25 20:28:21 loadLvl low
2014-03-01 16:40:37 prot_ERROR-Overload last
2014-03-11 00:00:54 prot_Warning-HighLoad last
2015-08-22 21:12:07 prot_disconnected last
2015-08-22 21:13:11 prot_init last
2014-10-10 22:01:56 prot_keepAlive last
2015-08-22 21:13:11 prot_ok last
2015-08-22 21:12:07 prot_timeout last
2015-08-22 21:13:11 state opened
Für einen Tipp zur Lösung des WAF-senkenden Problems wäre ich sehr dankbar. Gerne liefere ich auch weitere Logs/Daten nach.
Patrick
Diese Sequenz
2015.08.22 18:03:50.192 5: HMLAN_Send: HMLAN1 I:K
2015.08.22 18:03:51.193 5: HMLAN_Send: HMLAN1 I:K
2015.08.22 18:03:52.193 5: HMLAN_Send: HMLAN1 I:K
2015.08.22 18:03:53.194 5: HMLAN_Send: HMLAN1 I:K
2015.08.22 18:03:54.195 1: HMLAN_Parse: HMLAN1 new condition timeout
2015.08.22 18:03:54.203 1: hmcfglan1:1000 disconnected, waiting to reappear (HMLAN1)
2015.08.22 18:03:54.204 1: HMLAN_Parse: HMLAN1 new condition disconnected
2015.08.22 18:03:54.728 1: hmcfglan1:1000 reappeared (HMLAN1)
entsteht nach meiner Erfahrung durch einen Reboot des HMLAN was auch dies hier zeigt Internals:
HMLAN1_TIME 2015-08-25 20:28:43
uptime 002 71:16:59.287
ich habe bei meinem HMLAN Reboots im Abstand von wenigen Minuten bis maximal 1-2 Tagen ... der Grund ist unklar. ELV hat schon vor einiger Zeit dazu ein Ticket bei e-Q3 erstellt, bisher leider ohne Ergebnis >:(
Netzwerk kontrollieren! Den HMLAN mal direkt mit dem Router verbinden und deine fhem Instanz auch direkt auf den Router legen. Ich habe 3 hmlan im Einsatz und immer gesucht, warum der hmlan1 oft auf disconnect geht, es lag am Netzwerk. Der hmlan1 war über einen extra Switch zusammen mit meinen 3 fhem Instanzen verbunden, nachdem ich den hmlan1 direkt auf den Router gelegt hatte sind diese disconnects verschwunden.
Vielleicht bringt´s ja was :)
VG
Frank
Zitat von: franky08 am 26 August 2015, 00:01:42
Netzwerk kontrollieren! [...]
Vielleicht bringt´s ja was :)
Leider nein. Habe den HMLAN an den zentralen Switch gehängt. Neues CAT6A Patchkabel, keine Errors auf dem Port. Dennoch ist gerade wieder der Disconnect aufgetreten.
Hatte die Hoffnung, dass das Log Aufschluss gibt.
Patrick
Dann starte mal apptime, vlt. Bekommst du dann Antwort, was den hmlan zum disconnect bringt. Keep Alive passiert alle 30 sec. Und wenn der hmlan in dieser Zeit nicht antwortet dann kommt ein disconnect.
VG
Frank
Zitat von: franky08 am 28 August 2015, 00:24:35
Dann starte mal apptime, vlt. Bekommst du dann Antwort, was den hmlan zum disconnect bringt. Keep Alive passiert alle 30 sec. Und wenn der hmlan in dieser Zeit nicht antwortet dann kommt ein disconnect.
Schau mal in mein Eröffnungsposting. Das "I" kommt exakt nach 25s, wie eingestellt.
Patrick
Sorry, hab ich nicht gesehen.
ZitatDas "I" kommt exakt nach 25s, wie eingestellt.
genau genommen "geht" das "I". ob es beim hmlan angekommen ist, kannst du daraus nicht erkennen. wenn keine antwort kommt, ist was faul und es gibt wiederholungen. und ob die logzeiten exakt zu den sendezeiten passen, würde ich nicht drauf wetten. ;)
wenn du genau weisst, was los ist, verstehe ich deine aussagen nicht.
Zitat von: PatrickR am 28 August 2015, 00:17:25
Leider nein. Habe den HMLAN an den zentralen Switch gehängt. Neues CAT6A Patchkabel, keine Errors auf dem Port. Dennoch ist gerade wieder der Disconnect aufgetreten.
Hatte die Hoffnung, dass das Log Aufschluss gibt.
Patrick
und was sagt jetzt die uptime des HMLAN? Neu gebootet? Hast du IP-TV, z.B. Entertain, in deinem Netz?
Zitatund was sagt jetzt die uptime des HMLAN? Neu gebootet?
neu booten kann man ggf auch sehr schön an der load erkennen, da diese beim booten auf 0 gesetzt wird. bei mir geschieht dies immer im zusammenhang mit condition=timeout.
Zitat von: frank am 28 August 2015, 09:23:01
neu booten kann man ggf auch sehr schön an der load erkennen, da diese beim booten auf 0 gesetzt wird. bei mir geschieht dies immer im zusammenhang mit condition=timeout.
das ist aber m.E. eine Folge des disconnects ... ob der HMLAN gebootet hat erkennt man an der uptime diese wird bei jedem Datenpakte vom HMLAN mit gesendet
OK, es ist tatsächlich ein Reboot. Sorry, hatte die Info mit der Uptime komplett übersehen.
Die Frage ist, wie ich mit das Problem in den Griff bekomme.
Mir fallen ein:
-CUL/hmland
-2. HMLAN in Unkenntnis, ob beim Disconnect der verbleibende HMLAN einspringt.
-diverse gtässliche Workarounds
Wie geht Ihr anderen Reboot-Geplagten damit um? Auf eq3 zu warten halte ich für nicht sehr aussichtsreich. Schließlich muss der HMLAN ja lediglich mit der eq3-Software laufen.
Von unterwegs gesendet.
@nobby
bei einfachen disconnects wird die load nicht zurueck gesetzt. nur beim reboot.
@patrick
freezes in fhem reduzieren. mit hilfe apptime und perfmon. eventuell saemtliche lan aktivitaeten in zweite fhem instanz auslagern. lan zwischen fhem und hmlan sauber halten. ich nutze zusaetzlich ein hmusb, der ueber die vccu die aufgaben des hmlan im problemfall uebernimmt. extra 2 unterschiedliche interfaces um interfaceprobleme zu umgehen.
es gibt auch problemdevices. beim sync der zeit meiner hm-cc-tc, kurz nach mitternacht, hat der hmlan fast immer einen timeout/reboot gemacht. der hmusb noch nie. es gibt auch user, die mehr disconnects mit. dem hmusb haben. ein bisschen voodoo ist schon im spiel.
ach so... dein apptime zeigt doch ziehmlich eindeutig 7 sec im zusammenhang mit dblog. schon mal untersucht warum? ein "sauberes" fhem, sollte nichts ueber 1 sek zeigen. vielleicht sogar weniger?
wenn es an dblog liegt schau
mal ob du das DbLogType attribut gesetzt hast. die beste performance bekommst du wenn du es auf History setzt.
gruss
andre
Nach meinen Erfahrungen haben die Reboots des HMLAN nichts mit Fhem zu tun ... ich habe inzwischen den 3. HMLAN im Einsatz weil natürlich die erste Antwort (auch von ELV) immer auf ein Hardwareproblem hindeutet ... nur das neue Gerät zeigt dann genau dasselbe Verhalten und bei mehreren HMLANs im Netz booten die zwar nicht absolut gleichzeitig aber im selben Rhythmus.
Ich habe dann ein eigenes Programm geschrieben, das die Daten vom HMLAN liest, gleiches Verhalten ... das heißt: Reboots
Auch ein Wechsel des LAN-Anschlusses, direkt am Router, über verschiedene Switche, brachte keine Verbesserung. Erst als ich den HMLAN direkt mit einem freien Port an einem Client verbunden habe, also quasi eine Mini-Netz mit 2 Geräten aufgebaut, waren die Probleme beseitigt, nur läuft jetzt hier natürlich kein Fhem.
Das war der Punkt wo ELV bei eQ-3 das Ticket eröffnet hat. Ich habe danach selbst noch ein bisschen weiter "geforscht" und bin im Moment der Meinung, dass der Netzwerk-Stack des HMLAN ein Problem mit Multicasts hat
zum weiterforschen: :)
der hmlan lässt sich auch remote rebooten http://forum.fhem.de/index.php/topic,38708.msg308916.html#msg308916 (http://forum.fhem.de/index.php/topic,38708.msg308916.html#msg308916). zb in die eingabezeile
{HMLAN_SimpleWrite($defs{'hmlan'}, "Y05")}
eingeben und 'hmlan' anpassen. das bedeutet, auch bei falschen befehlen, kommt der hmlan ghörig ins straucheln. wer weiss, was ihn noch alles rebootet.
bei meinen erfahrungen mit der synchronisation der tc-zeit habe ich einen entsprechenden verdacht. eventuell sogar über funk.
Da ich ja momentan ebenfalls davon geplagt bin (und es vorher in dieser Form nicht war)...
Bei mir ist ebenfalls kein Problem mit dem keepalive erkennbar.
Interessanterweise bleibt der HMLAN dann disconnected, ist aber per LAN ansprechbar.
Ursache konnte ich bisher nicht erkennen (ich warte mal auf den Herbst -> weil Dachboden).
Erneutes Flashen der Firmware (lt. Wiki) hat subjektiv auch keine Änderung gebracht.
Netzwerk ist eigentlich sauber (wer weiss das schon genau); habe diverse Varianten probiert.
P.S.:
In dem Zusammenhang kann ich Unterschiede im Zeitverhalten von FHEM gut am Refresh meines Infotablets erkennen;
und da hat sich in den letzten Wochen wieder eine Verschlechterung ergeben.
ZitatInteressanterweise bleibt der HMLAN dann disconnected, ist aber per LAN ansprechbar.
über ping? der disconnect ist dann nur über steckerziehen zu beenden? versuch doch in dem fall mal den "remote-reboot".
es gibt auf alle fälle diverse disconnect ursachen und eine vielzahl der disconnects haben mit freezes in fhem zu tun.
Hi!
Zitat von: frank am 28 August 2015, 11:28:45
ach so... dein apptime zeigt doch ziehmlich eindeutig 7 sec im zusammenhang mit dblog. schon mal untersucht warum? ein "sauberes" fhem, sollte nichts ueber 1 sek zeigen. vielleicht sogar weniger?
Ja, das war ich leider selbst. Ich hatte parallel zu FHEM ein Aufräumquery abgesetzt.
Zitat von: justme1968 am 28 August 2015, 12:27:41
wenn es an dblog liegt schau
mal ob du das DbLogType attribut gesetzt hast. die beste performance bekommst du wenn du es auf History setzt.
Danke für den Tipp. Hatte das Attribut bisher ignoriert, da es nicht dokumentiert war und mich über die current-Tabelle in der DB gewundert. Habe es nun gesetzt.
Patrick
Hi!
Zitat von: frank am 28 August 2015, 11:18:18
[...]
@patrick
[...]
ich nutze zusaetzlich ein hmusb, der ueber die vccu die aufgaben des hmlan im problemfall uebernimmt. extra 2 unterschiedliche interfaces um interfaceprobleme zu umgehen.
[...]
Wie sind da Deine Erfahrungen mit dem Failover? Muss der erste HMLAN erst auf disconnected gehen bevor der zweite einspringt oder wird eine Nachricht an den 2. weitergegeben, wenn der erste sie nicht korrekt bestätigt?
Muss ich bei der Einbindung etwas beachten?
Patrick
ZitatWie sind da Deine Erfahrungen mit dem Failover? Muss der erste HMLAN erst auf disconnected gehen bevor der zweite einspringt oder wird eine Nachricht an den 2. weitergegeben, wenn der erste sie nicht korrekt bestätigt?
Muss ich bei der Einbindung etwas beachten?
es geht dabei immer nur um das senden. empfangen tun immer alle, sollte klar sein. je nachdem wie attr iogrp im device gesetzt ist, wird der erste in einer "rangliste" zum senden gewählt. ist er nicht verfügbar (disconnected, overload, ...) wird der nächst mögliche gewählt. so mein verständnis. es scheint wunderbar zu funktionieren. sollte im wiki und commandref gut beschrieben sein.
Zitates scheint wunderbar zu funktionieren.
Kann ich voll bestätigen, habe 3 HMLAN in der vccu.
VG
Frank
Zitat von: frank am 28 August 2015, 13:49:25
über ping? der disconnect ist dann nur über steckerziehen zu beenden? versuch doch in dem fall mal den "remote-reboot".
es gibt auf alle fälle diverse disconnect ursachen und eine vielzahl der disconnects haben mit freezes in fhem zu tun.
Ja, der HMLAN ist dann im Netz erreichbar; sowohl Ping als auch Homematic-Soft wg. Firmware.
Kurzer Reboot reicht meist nicht, probiere das aber noch mal aus.
Momentan hab ich ne Funksteckdose davor, mit der ich das Ding dann 5 Minuten ausschalte. Meist geht es dann wieder.
Mein System läuft mittlerweile Dank HM-CFG-USB und VCCU weiter.