Hallo zusammen,
ich habe vor ein paar Wochen 2 zusätzliche HMUARTS bei mir in FHEM integriert und seiter macht mein Homematic Lan-Gateway Probleme.
Alles läuft unter einer VCCU (davor auch schon, die beiden HMUARTS kamen als Ersatz für mein HMLAN)
Zuerst fing es langsam an, alle paar Tage mal eine Fehlermeldung.
Jetzt aber tauchen seit 2 Tagen folgende Meldungen alle 15 Minuten auf:
2017.11.15 17:12:58 3: HMUARTLGW myHmLGW:keepAlive KeepAlive-port opened
2017.11.15 17:12:57 3: HMUARTLGW myHmLGW BidCoS-port opened
2017.11.15 17:12:57 3: myHmLGW:keepAlive device opened
2017.11.15 17:12:57 1: 192.168.178.22:2000 reappeared (myHmLGW)
2017.11.15 17:12:57 3: Opening myHmLGW:keepAlive device 192.168.178.22:2001
2017.11.15 17:12:57 1: 192.168.178.22:2000 disconnected, waiting to reappear (myHmLGW)
2017.11.15 17:12:57 1: HMUARTLGW myHmLGW:keepAlive KeepAlive sent 5.462s too late, this might cause a disconnect!
2017.11.15 17:12:57 1: 192.168.178.22:2001 disconnected, waiting to reappear (myHmLGW:keepAlive)
2017.11.15 16:57:58 3: HMUARTLGW myHmLGW:keepAlive KeepAlive-port opened
2017.11.15 16:57:58 3: HMUARTLGW myHmLGW BidCoS-port opened
2017.11.15 16:57:58 3: myHmLGW:keepAlive device opened
2017.11.15 16:57:58 1: 192.168.178.22:2000 reappeared (myHmLGW)
2017.11.15 16:57:58 3: Opening myHmLGW:keepAlive device 192.168.178.22:2001
2017.11.15 16:57:57 1: 192.168.178.22:2000 disconnected, waiting to reappear (myHmLGW)
2017.11.15 16:57:57 1: HMUARTLGW myHmLGW:keepAlive KeepAlive sent 16.916s too late, this might cause a disconnect!
2017.11.15 16:57:47 1: 192.168.178.22:2001 disconnected, waiting to reappear (myHmLGW:keepAlive)
Bis auf das Todoits-Modul und den beiden neuen HMUARTS hab ich nichts weiter geändert, das Todoist-Modul hab ich auch schon auf inactiv mal gesetzt um Fehler auszuschließen.
Vorrübergehende Besserung bringt entweder den Stecker am Lan-Gatway mal zu ziehen oder FHEM neu zu starten, nach spätestens 2-3 Stunden geht es aber wieder los.
Wo kann ich anfangen mit der Fehlersuche?
Lists kann ich noch nachliefern wenn ich zuhause bin. Update von FHEM und Raspberry (Jessie) ist aktuell.
Gruß Cobra
was sagt apptime?
Danke, auf die Idee bin ich nicht gekommen, hab mich bisher mit apptime noch garnicht befasst.
Werd ich nachher wenn ich zuhause bin mal für ne halbe Stunde laufen lassen und dann hier posten.
Mit dem Aufruf von apptime total bekomme ich folgende Meldung jetzt:
name function max count total average maxDly TS Max call param Max call
tmr-SmarterCoffee_RunDiscoveryProcess HASH(0x4ad2178) 10051 6 40121 6686.83 9832 15.11. 19:10:07 HASH(KM.Kueche_Filterkaffee)
RM_HmUART_WZ HMUARTLGW_Read 2521 1103 32121 29.12 0 15.11. 19:00:14 HASH(RM_HmUART_WZ)
heatingInfo readingsGroup_Notify 130 2474 16678 6.74 0 15.11. 18:52:14 HASH(heatingInfo); HASH(HKT.Schlafzimmer_Clima)
myHmLGW HMUARTLGW_Read 260 677 13318 19.67 0 15.11. 18:42:03 HASH(myHmLGW)
Sonos SONOS_Read 667 245 10559 43.10 0 15.11. 19:01:50 HASH(Sonos)
WEB_192.168.178.9_43452 FW_Notify 38 2474 8460 3.42 0 15.11. 19:01:50 HASH(WEB_192.168.178.9_43452); HASH(Sonos_Wohnzimmer)
WEB_192.168.178.9_43454 FW_Notify 39 2474 7926 3.20 0 15.11. 18:58:04 HASH(WEB_192.168.178.9_43454); HASH(RPIWZ)
RM_HmUART_HZ HMUARTLGW_Read 603 958 7751 8.09 0 15.11. 19:10:18 HASH(RM_HmUART_HZ)
WEB FW_Read 211 24 3333 138.88 0 15.11. 18:38:06 HASH(WEB)
kodiwz KODI_Read 88 34 2452 72.12 0 15.11. 19:10:19 HASH(kodiwz)
n_BatteryWarnung notify_Exec 2348 2474 2452 0.99 0 15.11. 19:00:14 HASH(n_BatteryWarnung); HASH(FB.Timo)
kodisz KODI_Read 74 44 2448 55.64 0 15.11. 18:37:55 HASH(kodisz)
rgr_Residents RESIDENTStk_Notify 1822 113 2158 19.10 0 15.11. 18:59:49 HASH(rgr_Residents); HASH(rr_Sonja)
iPhoneSonja PRESENCE_Read 1941 50 2040 40.80 0 15.11. 18:59:49 HASH(iPhoneSonja)
di_SonjaStatus DOIF_Notify 1910 2474 1992 0.81 0 15.11. 18:59:49 HASH(di_SonjaStatus); HASH(iPhoneSonja)
rr_Sonja RESIDENTStk_Set 1877 71 1877 26.44 0 15.11. 18:59:49 HASH(rr_Sonja); rr_Sonja; home
di_HeizungSommerWinter DOIF_Notify 1745 2474 1836 0.74 0 15.11. 18:59:49 HASH(di_HeizungSommerWinter); HASH(rgr_Residents)
struc_VerbraucherKueche structure_Notify 105 2474 1808 0.73 0 15.11. 19:07:27 HASH(struc_VerbraucherKueche); HASH(LICHT.Kueche_Decke)
Heizungssteuerung dummy_Set 1713 3 1713 571.00 0 15.11. 18:59:49 HASH(Heizungssteuerung); Heizungssteuerung; anwesend
tmr-HUEBridge_GetUpdate HASH(0x1d1e810) 87 34 1696 49.88 19470 15.11. 18:37:48 HASH(hueBridge1)
n_HeizungsteuerungAenderung notify_Exec 1684 1 1684 1684.00 0 15.11. 18:59:49 HASH(n_HeizungsteuerungAenderung); HASH(Heizungssteuerung)
Kannst du was damit anfangen? Muss aber dazu sagen dass nur 2 Mal in der Zeit die Fehlermeldung kam während Apptime läuft. Hab jetzt nochmal auf Null gesetzt und lass es nochmal ne Weile laufen.
besser "apptime max". dann sieht man die funktionen, die fhem maximal verzögert haben.
tmr-SmarterCoffee_RunDiscoveryProcess HASH(0x4ad2178) 10051 6 40121 6686.83 9832 15.11. 19:10:07 HASH(KM.Kueche_Filterkaffee)
hier könnte schon die ursache liegen. einmal 10sek und im durchschnitt über 6 sek.
eigentlich sind alle verzögerungen über 1sek unschön.
Hier nun die Ausgabe während Apptime die ganze Nacht lief und ich auch wieder alle 15 Minuten die Meldungen hatte:
name function max count total average maxDly TS Max call param Max call
tmr-at_Exec HASH(0x337d040) 61218 1 61218 61218.00 4 16.11. 03:00:01 HASH(AT_Backup)
tmr-SmarterCoffee_RunDiscoveryProcess HASH(0x59cfc48) 10051 75 462263 6163.51 10109 15.11. 23:32:11 HASH(KM.Kueche_Filterkaffee)
tmr-harmony_connect HASH(0x4754220) 3020 7 6188 884.00 1535 16.11. 03:18:58 HASH(harmony)
KM.Kueche_Filterkaffee SmarterCoffee_Set 2510 110 2850 25.91 0 16.11. 07:08:39 HASH(KM.Kueche_Filterkaffee); KM.Kueche_Filterkaffee; start
KM.Kueche_Filterkaffee SmarterCoffee_Read 2178 16516 3624 0.22 0 16.11. 07:09:22 HASH(KM.Kueche_Filterkaffee)
KM.Kueche_Filterkaffee SmarterCoffee_Notify 2121 92 2122 23.07 0 16.11. 07:09:22 HASH(KM.Kueche_Filterkaffee); HASH(KM.Kueche_Filterkaffee)
Sonos SONOS_Read 1625 3908 172632 44.17 0 15.11. 23:43:49 HASH(Sonos)
kodiwz KODI_Ready 1478 2 1478 739.00 0 16.11. 03:00:04 HASH(kodiwz)
WEB_192.168.178.73_53297 FW_Read 1319 4 1367 341.75 0 16.11. 07:22:58 HASH(WEB_192.168.178.73_53297)
tmr-at_Exec HASH(0x57f4958) 987 1 987 987.00 205 16.11. 06:00:01 HASH(at_rr_Timo_wakeuptimer1)
rr_Timo_wakeuptimer1 dummy_Set 983 11 1391 126.45 0 16.11. 06:00:01 HASH(rr_Timo_wakeuptimer1); rr_Timo_wakeuptimer1; trigger
rr_Timo RESIDENTStk_Notify 945 51 1325 25.98 0 16.11. 06:00:01 HASH(rr_Timo); HASH(rr_Timo_wakeuptimer1)
tmr-watchdog_Trigger HASH(0x57fd0d0) 713 1 713 713.00 7 16.11. 07:09:46 HASH(wd_rr_Timo_awoken)
Macro_rr_Timo_awoken notify_Exec 690 1 690 690.00 0 16.11. 07:09:46 HASH(Macro_rr_Timo_awoken); HASH(Macro_rr_Timo_awoken)
tmr-HUEBridge_GetUpdate HASH(0x2bf1d18) 585 569 45262 79.55 49299 15.11. 23:47:32 HASH(hueBridge1)
tmr-at_Exec HASH(0x4be11c0) 535 19 9483 499.11 93 16.11. 00:16:46 HASH(at_FHEM.save)
Macro_rr_Timo_wakeuptimer1 notify_Exec 534 2 793 396.50 0 16.11. 06:00:00 HASH(Macro_rr_Timo_wakeuptimer1); HASH(Macro_rr_Timo_wakeuptimer1)
RM_HmUART_HZ HMUARTLGW_Read 522 11983 70195 5.86 0 16.11. 03:18:52 HASH(RM_HmUART_HZ)
myHmLGW HMUARTLGW_Read 516 12815 271133 21.16 0 16.11. 06:35:43 HASH(myHmLGW)
RM_HmUART_WZ HMUARTLGW_Read 491 13934 429526 30.83 0 16.11. 04:20:13 HASH(RM_HmUART_WZ)
tmr-watchdog_Trigger HASH(0x5804008) 490 1 490 490.00 6 15.11. 23:43:42 HASH(wd_rgr_Residents_asleep)
Verstehe ich das richtig? Der Wert Max bedeutet Verzögerung in Millisekunden und Average bedeutet durchschnittliche Verzögerung in Milliekunden? Oder ist Maxdly die maximalste Verzögerung?
Bei mir ist das gleiche Problem apptime lief auch die ganze Nacht.
[/name function max count total average maxDly TS Max call param Max call
Sonos SONOS_Read 53830 2392 2366865 989.49 0 15.11. 23:51:58 HASH(Sonos)
tmr-at_Exec HASH(0x3f93b28) 11047 1 11047 11047.00 5 16.11. 05:30:11 HASH(at_rr_Peter_wakeuptimer1)
rr_Peter_wakeuptimer1 dummy_Set 11032 5 13477 2695.40 0 16.11. 05:30:11 HASH(rr_Peter_wakeuptimer1); rr_Peter_wakeuptimer1; trigger
rr_Peter RESIDENTStk_Notify 10919 80 13599 169.99 0 16.11. 05:30:11 HASH(rr_Peter); HASH(rr_Peter_wakeuptimer1)
Macro_rr_Peter_wakeuptimer1 notify_Exec 8268 2 9956 4978.00 0 16.11. 05:30:08 HASH(Macro_rr_Peter_wakeuptimer1); HASH(Macro_rr_Peter_wakeuptimer1)
HMLAN1 HMLAN_Read 8130 5349 354467 66.27 0 15.11. 23:51:04 HASH(HMLAN1)
WEB_192.168.178.36_51135 FW_Read 6382 7 7532 1076.00 0 16.11. 08:34:18 HASH(WEB_192.168.178.36_51135)
HMLANGW HMUARTLGW_Read 5376 7878 1547918 196.49 0 15.11. 19:01:06 HASH(HMLANGW)
tmr-HMUARTLGW_CheckCmdResp HASH(0x439ec28) 3629 15 4351 290.07 47354 16.11. 07:14:55 HASH(HMLANGW)
RebootSonosBad_1OG DOIF_Notify 3546 25934 10160 0.39 0 15.11. 23:51:04 HASH(RebootSonosBad_1OG); HASH(Bad_1OG_Musik)
tmr-at_Exec HASH(0x4a2e9f8) 3231 1 3231 3231.00 15 16.11. 06:05:13 HASH(atTmp_6_Macro_rr_Peter_wakeuptimer1)
rr_Peter RESIDENTStk_Set 3168 6 8888 1481.33 0 16.11. 06:05:13 HASH(rr_Peter); rr_Peter; awoken
Haus HOMEMODE_Notify 3048 7526 750973 99.78 0 16.11. 07:28:44 HASH(Haus); HASH(1OG_Kueche_Balkon)
n_rr_Beate.location notify_Exec 3009 3 4408 1469.33 0 15.11. 18:43:11 HASH(n_rr_Beate.location); HASH(geofancy)
rr_Beate RESIDENTStk_Set 2943 7 6322 903.14 0 15.11. 18:43:11 HASH(rr_Beate); rr_Beate; location; home
n_rr_Peter.location notify_Exec 2794 3 2797 932.33 0 16.11. 07:56:31 HASH(n_rr_Peter.location); HASH(geofancy)
kg.WaschmaschineWattSet notify_Exec 2776 348 342131 983.14 0 15.11. 19:01:04 HASH(kg.WaschmaschineWattSet); HASH(kg_hr_steckdose_waschmaschine_Pwr)
kg.TrocknerWattSet notify_Exec 2689 350 344677 984.79 0 15.11. 19:17:12 HASH(kg.TrocknerWattSet); HASH(kg_hr_steckdose_trockner_Pwr)
tmr-at_Exec HASH(0x4bb2ad8) 2498 1 2498 2498.00 5 16.11. 06:00:12 HASH(at_rr_Peter_wakeuptimer1_stop)
jeelinkcross JeeLink_Read 2372 31741 1303699 41.07 0 16.11. 07:54:11 HASH(jeelinkcross)
tmr-SONOS_InitClientProcess HASH(0x28ab8e8) 2136 3 6224 2074.67 8 16.11. 00:14:11 HASH(Sonos) code]
Heute morgen hatte ich dann nur noch die Meldungen.
[code][/2017.11.16 08:36:54 4: HMUARTLGW HMLANGW:keepAlive ready: disconnected
2017.11.16 08:36:54 4: HMUARTLGW HMLANGW:keepAlive ready: disconnected
2017.11.16 08:36:54 4: HMUARTLGW HMLANGW:keepAlive ready: disconnected
2017.11.16 08:37:00 4: HMUARTLGW HMLANGW:keepAlive ready: disconnected
2017.11.16 08:37:01 4: HMUARTLGW HMLANGW:keepAlive ready: disconnected
2017.11.16 08:37:01 4: HMUARTLGW HMLANGW:keepAlive ready: disconnected
2017.11.16 08:37:01 4: HMUARTLGW HMLANGW:keepAlive ready: disconnected
2017.11.16 08:37:02 4: HMUARTLGW HMLANGW:keepAlive ready: disconnected
2017.11.16 08:37:04 4: HMUARTLGW HMLANGW:keepAlive ready: disconnected
2017.11.16 08:37:06 4: HMUARTLGW HMLANGW:keepAlive ready: disconnected
2017.11.16 08:37:06 4: HMUARTLGW HMLANGW:keepAlive ready: disconnected
2017.11.16 08:37:08 4: HMUARTLGW HMLANGW:keepAlive ready: disconnected
2017.11.16 08:37:08 4: HMUARTLGW HMLANGW:keepAlive ready: disconnected
2017.11.16 08:37:09 4: HMUARTLGW HMLANGW:keepAlive ready: disconnected
2017.11.16 08:37:09 4: HMUARTLGW HMLANGW:keepAlive ready: disconnected
2017.11.16 08:37:09 4: HMUARTLGW HMLANGW:keepAlive ready: disconnected
2017.11.16 08:37:10 4: HMUARTLGW HMLANGW:keepAlive ready: disconnected
2017.11.16 08:37:10 4: HMUARTLGW HMLANGW:keepAlive ready: disconnected
2017.11.16 08:37:11 4: HMUARTLGW HMLANGW:keepAlive ready: disconnected
2017.11.16 08:37:11 4: HMUARTLGW HMLANGW:keepAlive ready: disconnected
2017.11.16 08:37:13 4: HMUARTLGW HMLANGW:keepAlive ready: disconnected
2017.11.16 08:37:14 4: HMUARTLGW HMLANGW:keepAlive ready: disconnected
2017.11.16 08:37:16 4: HMUARTLGW HMLANGW:keepAlive ready: disconnected
2017.11.16 08:37:16 4: HMUARTLGW HMLANGW:keepAlive ready: disconnectedcode]
Gruß Peter
Zitat von: Cobra am 16 November 2017, 07:29:15
Verstehe ich das richtig? Der Wert Max bedeutet Verzögerung in Millisekunden und Average bedeutet durchschnittliche Verzögerung in Milliekunden? Oder ist Maxdly die maximalste Verzögerung?
https://wiki.fhem.de/wiki/Apptime (https://wiki.fhem.de/wiki/Apptime)
maxDly steht da allerdings nicht erklärt...
Danke, das Wiki hab ich auch schon gelesen aber dort ist ja leider nichts zu den Werten erklärt, daher war ja die Frage ob ich das so richtig interpretiere.
Habe übrigens die WLAN-Anbindung meiner Kaffeemaschine geprüft und festgestellt dass diese sich mit dem falschen AccessPoint verbunden hat und somit auch eine schlechte Verbindung hatte. Seit ich das heut morgen geändert habe tauchen die Fehler nicht mehr auf. Scheint also geholfen zu haben :-)
Danke
Zitat,
Wiki:
ZitatDie Felder haben folgende Bedeutung:
name: Entity, für die es ausgeführt wird
Wenn 'tmr-' vor dem Namen steht ist es durch einen Timer (InternalTimer) aufgerufen worden.
funktion: Name der Funktion, die ausgeführt wird
param max call: Input-Parameter an die Funktion beim längsten Aufruf
max: maximale Laufzeit in ms
count: Anzahl der Aufrufe
total: akkumulierte Laufzeit der Funktion in ms
average: durchschnittliche Laufzeit (total/count) in ms.
Ist doch eigentlich alles erklärt, oder?
maxdly sollte die maximale verzögerung sein, die eine funktion erfährt, bis sie endlich ausgeführt werden kann. die ausführung wurde also durch andere verzögert.
bei den anderen werten verzögert die funktion selbst fhem.
Zitat von: automatisierer am 16 November 2017, 11:52:07
Zitat,
Wiki:
Ist doch eigentlich alles erklärt, oder?
OK, der Groschen ist gefallen :-)
Laufzeit = Verzögerung
Danke euch beiden :-)