HMLAN: Regelmässiger Timeout zur Geisterstunde

frank · 15 April 2014, 14:05:52

seit einigen wochen beobachte ich kurz nach mitternacht ein timeout des hmlan. das kommt nicht jeden tag vor, kann aber ein paar tage am stück vorkommen. wenn es passiert, dann findet es in den ersten 3 minuten nach mitternacht statt.

ein regelmässiges einschalten von global verbose5 während dieser zeitspanne hat mir keine besonderen erkenntnisse verschafft. der wdtimer kommt meistens pünktlich, wird 3 mal wiederholt, bleibt ohne antwort und löst dann ein timeout aus. nach disconnect, reappear und connect ist alles wieder im lot.

welche "geister" machen hier party?

hat jemand ähnliche erfahrungen gemacht?
gibt es ein tool, das auf der fritzbox hinweisdienliche informationen loggen kann?

gruss frank

martinp876 · 15 April 2014, 15:04:25

schon einmal apptime probiert?
was sagen die reading und anzeigen in HMLAN?
was läuft auf deinem Rechner, wenn die Geister kommen - ausser fhem?

Bennemannc · 15 April 2014, 15:23:08

Hallo,

Glaskugel reiben .... - tägliche Trennung der DSL Verbindung ? Fritze ist mit neuabgleich der DSL Leitung beschäftigt ?

Gruß Christoph

frank · 15 April 2014, 15:44:38

hallo martin, christoph,

Zitatschon einmal apptime probiert?

ich war noch nicht live dabei. kann ich denn die aktuellen apptime-daten nach timeout irgendwie loggen/ausgeben? wenn ich apptime um 00:00 cleare und irgendwann später reinschaue sind die relevanten daten ja schlecht ersichtlich.

Zitatwas sagen die reading und anzeigen in HMLAN?

Code Auswählen

2014-04-14_23:57:28 HMLAN1 hmDelay: min:-10 max:59 last:0 cnt:293
2014-04-14_23:58:27 HMLAN1 hmDelay: min:-10 max:59 last:8 cnt:300
2014-04-14_23:59:27 HMLAN1 hmDelay: min:-10 max:673 last:2 cnt:309
2014-04-15_00:00:27 HMLAN1 hmTrfHour: 13 %
2014-04-15_00:00:27 HMLAN1 hmDelay: min:-10 max:673 last:5 cnt:311
2014-04-15_00:01:27 HMLAN1 hmTrfHour: 14 %
2014-04-15_00:01:27 HMLAN1 hmDelay: min:-10 max:673 last:258 cnt:319
2014-04-15_00:01:27 HMLAN1 hmAlive: dlyMax:2.972 bufferMin:2
2014-04-15_00:01:32 HMLAN1 cond: timeout
2014-04-15_00:01:32 HMLAN1 DISCONNECTED
2014-04-15_00:02:36 HMLAN1 cond: init
2014-04-15_00:02:36 HMLAN1 CONNECTED
2014-04-15_00:02:37 HMLAN1 cond: ok

Zitatwas läuft auf deinem Rechner, wenn die Geister kommen - ausser fhem?

auf meiner fritzbox 7390 sollte meines wissens nach nur fhem laufen ausser dem normalen betriebssystem. daher meine frage nach entsprechenden tools zum verifizieren. vielleicht tummeln sich hier nsa, bnd, mad, ... .

anbei das fhem log vom letzten beantworteten wdtimer bis zum timeout

Zitattägliche Trennung der DSL Verbindung ? Fritze ist mit neuabgleich der DSL Leitung beschäftigt ?

kommt erst später zwischen 3:00 und 4:00.

gruss frank

martinp876 · 15 April 2014, 16:04:16

apptime selbst hat keinen timer. Du kannst es mit einem notify erledigen - schreiben, speichern,rücksetzen.
ggf geben a) alles aus oder b) einmal die Langläufer und dann die delays.
Will sages - sortiere es ggf korrekt

Wenn das Problem von ausserhalb kommt wird apptime es nicht sehen.

Gruss Martin

frank · 15 April 2014, 16:46:12

Zitatapptime selbst hat keinen timer. Du kannst es mit einem notify erledigen - schreiben, speichern,rücksetzen.

wie kann ich die ausgabe speichern?

gruss frank

martinp876 · 15 April 2014, 17:44:07

{Log 1,apptime_CommandDispTiming("","")}

frank · 15 April 2014, 19:29:20

hallo martin,

Zitat von: martinp876 am 15 April 2014, 17:44:07
{Log 1,apptime_CommandDispTiming("","")}

funktioniert gut.
beim 2. string kann ich ja zb "max all" eingeben. wozu dient der 1. string?

gruss frank

martinp876 · 16 April 2014, 06:46:08

FHEM default - wird hier nicht benötigt

frank · 16 April 2014, 11:23:04

hallo martin,

hier jetzt mal der apptime log von heute nacht. um 00:00 uhr ein clear gemacht und um 00:03 uhr gespeichert. nach meinem verständnis ein paar nicht so schöne zahlen dabei, wohl aber kein grund für ein timeout.

Code Auswählen

                                name             function    max  count    total  average maxDly
                         tmr-at_Exec       HASH(0xf66c30)   5111      1     5111  5111.00     10 HASH(0xf66c30)
                              addLog          notify_Exec   5043      1     5043  5043.00      0 HASH(0xf66700); HASH(0xf66700)
                              HMLAN1          HMLAN_Ready   3010    161     3269    20.30      0 HASH(0xc35d08)
                              HMLAN1           HMLAN_Read    617     17     2332   137.18      0 HASH(0xc35d08)
                  tmr-HCS_checkState      HASH(0x1298f88)    546      3     1227   409.00     15 HASH(0x1298f88)
               tmr-Weather_GetUpdate       HASH(0xe8ee90)    514      1      514   514.00      8 HASH(0xe8ee90)
               tmr-Twilight_Midnight       HASH(0xf057a8)    388      1      388   388.00      6 HASH(0xf057a8)
                           n_set_hzg          notify_Exec    378      8     1358   169.75      0 HASH(0x12eba40); HASH(0x1298f88)
                      tmr-PID20_Calc             PID20.AZ    356      3      402   134.00    541 PID20.AZ
                         tmr-at_Exec       HASH(0xd8f088)    310      3      547   182.33      8 HASH(0xd8f088)
            tmr-HMLAN_KeepAliveCheck   keepAliveCk:HMLAN1    257      8      273    34.13    273 keepAliveCk:HMLAN1
        VentilControler.AZ.Nord_Btn1           CUL_HM_Set    232      3      256    85.33      0 HASH(0x1292aa8); VentilControler.AZ.Nord_Btn1; valvePos; 0
                tmr-CUL_HM_sndIfOpen     sndIfOpen:HMLAN1    224     31      285     9.19    220 sndIfOpen:HMLAN1
               n_control_TCControler          notify_Exec    219    127      514     4.05      0 HASH(0x1250458); HASH(0x124f290)
             tmr-CUL_HM_respPendTout      respPend:B2B2B2    166      1      166   166.00      7 respPend:B2B2B2
              tmr-CUL_HM_valvePosTmr    valveTmr:B2B2B201    140      1      140   140.00     11 valveTmr:B2B2B201
             tmr-CUL_HM_valvePosUpdt    valvePos:B4B4B401    138      2      141    70.50      8 valvePos:B4B4B401
             tmr-CUL_HM_valvePosUpdt    valvePos:B1B1B101    120      1      120   120.00      8 valvePos:B1B1B101
                              cul433             CUL_Read    106     20      716    35.80      0 HASH(0xd306d8)
                 tmr-Twilight_sunpos      HASH(0x13d7a60)     82      1       82    82.00      8 HASH(0x13d7a60)
                         tmr-at_Exec      HASH(0x12f24a0)     72      1       72    72.00      8 HASH(0x12f24a0)
             tmr-CUL_HM_valvePosUpdt    valvePos:B2B2B201     64      1       64    64.00      9 valvePos:B2B2B201
                     n_valveCtrl_chk          notify_Exec     62    127      163     1.28      0 HASH(0x12ebb40); HASH(0x1251e00)
         tmr-PRESENCE_StartLocalScan      HASH(0x12f2720)     57      3      133    44.33      8 HASH(0x12f2720)
                           n_ITT1500          notify_Exec     36      5      173    34.60      0 HASH(0xe8cb50); HASH(0xd306d8)
               FileLog_Thermostat.SZ          FileLog_Log     35    127      390     3.07      0 HASH(0x124bab8); HASH(0xc35d08)
                  FileLog_Technik_IO          FileLog_Log     33    127      546     4.30      0 HASH(0xbcf308); HASH(0x1298ce8)
                     FileLog_Broetje          FileLog_Log     28    127      380     2.99      0 HASH(0x1297da0); HASH(0x1264f18)
                      tmr-PID20_Calc            PID20.Bad     27      3       76    25.33    536 PID20.Bad
                      tmr-PID20_Calc         PID20.Kueche     25      3       72    24.00    539 PID20.Kueche
                          n_batt_chk          notify_Exec     24    127      435     3.43      0 HASH(0x12f2470); HASH(0x1298bb8)
                 tmr-CUL_HM_ActCheck       ActionDetector     23      1       23    23.00      8 ActionDetector
                      tmr-PID20_Calc             PID20.WZ     23      3       69    23.00    541 PID20.WZ
                        n_alarmgeber          notify_Exec     23    127      186     1.46      0 HASH(0x1341518); HASH(0x1293558)
                     n_Broetje_alarm          notify_Exec     22    127      117     0.92      0 HASH(0x1298410); HASH(0xc35d08)
           FHEMWEB:192.168.1.23:1936            FW_Notify     21    127      548     4.31      0 HASH(0x15a3190); HASH(0x1292808)
            tmr-CUL_HM_complConfigTO CUL_HM_complConfigTO     21      1       21    21.00      8 CUL_HM_complConfigTO
                      FileLog_cul433          FileLog_Log     20    127      357     2.81      0 HASH(0xd94540); HASH(0xc35d08)
           FileLog_Thermostat.Kueche          FileLog_Log     19    127      333     2.62      0 HASH(0x12457d0); HASH(0x1298bb8)
               FileLog_Thermostat.AZ          FileLog_Log     18    127      308     2.43      0 HASH(0x124b458); HASH(0xc35d08)
                           PID20.Bad         PID20_Notify     18    127       39     0.31      0 HASH(0x124fe28); HASH(0xc35d08)
                       n_set_desired          notify_Exec     17    127      155     1.22      0 HASH(0x12ebc50); HASH(0x1298ea8)
                             BROETJE              HCS_Get     15      3       45    15.00      0 HASH(0x1298f88); BROETJE; values
                      Ventil.AZ.Nord           CUL_HM_Set     15      3       43    14.33      0 HASH(0x1292808); Ventil.AZ.Nord; ?
                           Ventil.SZ           CUL_HM_Set     15      2       29    14.50      0 HASH(0x1251810); Ventil.SZ; ?
                          telnetPort          telnet_Read     15      3       40    13.33      0 HASH(0x7653a0)
              FileLog_Thermostat.Bad          FileLog_Log     14    127      333     2.62      0 HASH(0x1244718); HASH(0xe8ee90)
               FileLog_Thermostat.WZ          FileLog_Log     14    127      312     2.46      0 HASH(0x124f7a8); HASH(0xe8ee90)
                          Ventil.Bad           CUL_HM_Set     14      2       28    14.00      0 HASH(0x12744c0); Ventil.Bad; ?
                       Ventil.Kueche           CUL_HM_Set     14      2       28    14.00      0 HASH(0x12655d8); Ventil.Kueche; ?
                           Ventil.WZ           CUL_HM_Set     14      2       28    14.00      0 HASH(0x1288950); Ventil.WZ; ?
                      FileLog_cul868          FileLog_Log     12    127      149     1.17      0 HASH(0xddf918); HASH(0xe8ee90)
             VentilControler.SZ_Btn1           CUL_HM_Set     12      1       12    12.00      0 HASH(0x1251e00); VentilControler.SZ_Btn1; ?
               tmr-HTTPMOD_GetUpdate      HASH(0x12958c8)     11      1       11    11.00      8 HASH(0x12958c8)
                      tmr-PID20_Calc      HASH(0x1251a00)     11      3       32    10.67      8 HASH(0x1251a00)
                      tmr-PID20_Calc      HASH(0x128ea08)     11      3       31    10.33      9 HASH(0x128ea08)
                      Thermostat.Bad           CUL_HM_Set     10      6       46     7.67      0 HASH(0x12443d8); Thermostat.Bad; ?
                      tmr-PID20_Calc             PID20.SZ     10      3       29     9.67    552 PID20.SZ
                 tmr-holiday_refresh               events     10      1       10    10.00      7 events
                  FileLog_MeinWetter          FileLog_Log      9      1        9     9.00      0 HASH(0xe92310); HASH(0xe8ee90)
                        PID20.Kueche         PID20_Notify      8    127       27     0.21      0 HASH(0x128ea08); HASH(0x1245520)
                   Thermostat.Kueche           CUL_HM_Set      8      6       45     7.50      0 HASH(0x1245520); Thermostat.Kueche; ?
                       Thermostat.WZ           CUL_HM_Set      8      5       36     7.20      0 HASH(0x124f4b0); Thermostat.WZ; ?
                       Thermostat.SZ           CUL_HM_Set      7      5       35     7.00      0 HASH(0x124b838); Thermostat.SZ; ?
                              HMLAN1         HMLAN_Notify      6    127        6     0.05      0 HASH(0xc35d08); HASH(0xc35d08)
                 tmr-HMLAN_KeepAlive     keepAlive:HMLAN1      6      6       26     4.33      9 keepAlive:HMLAN1
                               n_Bxx          notify_Exec      6    127       51     0.40      0 HASH(0xe8bd68); HASH(0xe8ee90)
                            PID20.AZ         PID20_Notify      5    127        9     0.07      0 HASH(0x1288780); HASH(0xfb55b0)
                  FileLog_myTwilight          FileLog_Log      4      2        7     3.50      0 HASH(0xf05808); HASH(0xea8688)
                            PID20.SZ         PID20_Notify      4    127       17     0.13      0 HASH(0x1251a00); HASH(0x124b838)
                            PID20.WZ         PID20_Notify      4    127       19     0.15      0 HASH(0x1289380); HASH(0x124f4b0)
              tmr-FW_closeOldClients                           4      3       12     4.00    191 
               BROETJEDemandRaumTemp            dummy_Set      3      1        3     3.00      0 HASH(0x1298dc8); BROETJEDemandRaumTemp; 17.4
           FHEMWEB:192.168.1.23:1934            FW_Notify      3    127        3     0.02      0 HASH(0x15a7e30); HASH(0xf66700)
           FileLog_Thermostat.Bad.OG          FileLog_Log      3      2        5     2.50      0 HASH(0x13413d8); HASH(0x13410d8)
                             Logfile          FileLog_Log      3    127       67     0.53      0 HASH(0xaaaf08); HASH(0xe8ee90)
             tmr-CUL_HM_valvePosUpdt    valvePos:B3B3B301      3      1        3     3.00      8 valvePos:B3B3B301
             tmr-CUL_HM_valvePosUpdt    valvePos:B5B5B501      3      1        3     3.00     11 valvePos:B5B5B501
            tmr-perfmon_ProcessTimer       HASH(0x9b18a8)      3    173       10     0.06   4364 HASH(0x9b18a8)
                                  et    eventTypes_Notify      2    127        2     0.02      0 HASH(0xb31478); HASH(0x1298ea8)
                                 WEB            FW_Notify      1    127        1     0.01      0 HASH(0x9bee18); HASH(0xe8ee90)
              tmr-CUL_HM_valvePosTmr    valveTmr:B1B1B101      1      1        1     1.00      8 valveTmr:B1B1B101
              tmr-CUL_HM_valvePosTmr    valveTmr:B3B3B301      1      1        1     1.00      8 valveTmr:B3B3B301
                tmr-HMLAN_UpdtMsgCnt       UpdtMsg:HMLAN1      1      2        2     1.00     23 UpdtMsg:HMLAN1
                            PID20.AZ            PID20_Set      0      2        0     0.00      0 
                     TCControler.Bad          CUL_HM_Attr      0      1        0     0.00      0 
                  TCControler.Kueche          CUL_HM_Attr      0      1        0     0.00      0 
                            WEBphone            FW_Notify      0    127        0     0.00      0 
                           WEBtablet            FW_Notify      0    127        0     0.00      0 
                          GlobalAttr                           0      2        0     0.00      0 
                    tmr-BlockingKill      HASH(0x15f4118)      0      1        0     0.00      8 
                    tmr-BlockingKill      HASH(0x15ff6b8)      0      1        0     0.00      8 
                    tmr-BlockingKill      HASH(0x160dbf0)      0      1        0     0.00      8 
                    tmr-BlockingKill      HASH(0x1623790)      0      1        0     0.00      5 
              tmr-CUL_HM_valvePosTmr    valveTmr:B4B4B401      0      1        0     0.00      7 
              tmr-CUL_HM_valvePosTmr    valveTmr:B5B5B501      0      1        0     0.00      8 
               tmr-HttpUtils_ConnErr      HASH(0x12958c8)      0      1        0     0.00   4273 
               tmr-HttpUtils_ConnErr      HASH(0x15d2fd8)      0      1        0     0.00      9 
               tmr-HttpUtils_ReadErr      HASH(0x12958c8)      0      1        0     0.00   4267 
               tmr-HttpUtils_ReadErr      HASH(0x15d2fd8)      0      1        0     0.00      8 
                         tmr-at_Exec      HASH(0x1310730)      0      1        0     0.00      9

demnach müsste ich den netzwerkverkehr zur besagten zeit unter die lupe nehmen. habe gestern schon entdeckt, dass die fritzbox unter http://fritz.box/html/capture.html ein tool zur analyse des netzwerkverkehrs bereitstellt.
kennt vielleicht jemand eine möglichkeit das starten/stoppen zu automatisieren?

gruss frank

martinp876 · 16 April 2014, 12:16:04

5 sec sind erst einmal zu lang und können einen timeout hervorrufen.

in diesen 3 min sind einige Tasks zu finden, die zwischen 0,5 und 5 sec dauern. Das ist viel.

HMLAN_Ready wurde 160 mal aufgerufen... Möglich, das dies eine Folge des Disconnect ist.
mit

Code Auswählen

{my @a;;my $t = fhem "apptime";;\
 push @a,$defs{$_}.":$_" foreach ( keys %defs);;join("\n",sort @a);;\
 foreach (@a){\
   my ($h,$n) = split(":",$_);;\
   $h =~ s/[HASH\(\)]//g;;$t =~ s/$h/$n/g;; }\
 return $t;;}

kannst du die hashes gegen namen tauschen. Wäre für das at interessant.

frank · 17 April 2014, 13:28:42

hallo martin,

ich habe meine apptime aufzeichnung noch mal modifiziert. um 00:00 wiederum ein clear gemacht, aber nun über ein notify auf das timeout die ausgabe gespeichert. ausserdem attr logIDs während dieser zeit auf sys,all gesetzt.

Code Auswählen

2014.04.17 00:00:03.157 0: HMLAN_Parse: HMLAN1 R:E1DFDA5   stat:0000 t:0525F2FC d:FF r:FFC1     m:41 A258 1DFDA5 D2D2D2 0071
2014.04.17 00:00:03.255 0: HMLAN_Send:  HMLAN1 S:S6C8DCCE8 stat:  00 t:00000000 d:01 r:6C8DCCE8 m:41 8002 D2D2D2 1DFDA5 0101580000
2014.04.17 00:00:03.595 0: HMLAN_Parse: HMLAN1 R:R6C8DCCE8 stat:0002 t:00000000 d:FF r:7FFF     m:41 8002 D2D2D2 1DFDA5 0101580000
2014.04.17 00:00:22.245 0: HMLAN_Send:  HMLAN1 I:K
2014.04.17 00:00:22.256 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:JEQ0315335 d:1C671E O:123ABC t:05263D9B IDcnt:000E
2014.04.17 00:00:40.036 0: HMLAN_Parse: HMLAN1 R:E1BF81B   stat:0000 t:0526830E d:FF r:FFD2     m:DD 8670 1BF81B 000000 00BB3B
2014.04.17 00:00:40.226 0: HMLAN_Parse: HMLAN1 R:E1BF81B   stat:0000 t:052683CE d:FF r:FFD2     m:DE A03F 1BF81B 123ABC 
2014.04.17 00:00:40.325 0: HMLAN_Send:  HMLAN1 S:+1BF81B,00,01,1E
2014.04.17 00:00:40.327 0: HMLAN_Send:  HMLAN1 S:S6C8E5DAD stat:  00 t:00000000 d:01 r:6C8E5DAD m:21 803F 123ABC 1BF81B 02041AE1BA08
2014.04.17 00:00:40.398 0: HMLAN_Parse: HMLAN1 R:E1BF81B   stat:0000 t:052683CE d:FF r:FFD2     m:DE A03F 1BF81B 123ABC 
2014.04.17 00:00:40.622 0: HMLAN_Parse: HMLAN1 R:R6C8E5DAD stat:0002 t:00000000 d:FF r:7FFF     m:21 803F 123ABC 1BF81B 02041AE1BA08
2014.04.17 00:00:47.256 0: HMLAN_Send:  HMLAN1 I:K
2014.04.17 00:00:47.268 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:JEQ0315335 d:1C671E O:123ABC t:05269F52 IDcnt:000E
2014.04.17 00:01:03.911 0: HMLAN_Parse: HMLAN1 R:E1BF81B   stat:0000 t:0526D190 d:FF r:FFD2     m:DD A258 1BF81B D4D4D4 0000
2014.04.17 00:01:03.985 0: HMLAN_Send:  HMLAN1 S:+1BF81B,00,01,1E
2014.04.17 00:01:03.988 0: HMLAN_Send:  HMLAN1 S:S6C8EBA35 stat:  00 t:00000000 d:01 r:6C8EBA35 m:DD 8002 D4D4D4 1BF81B 0101000000
2014.04.17 00:01:04.325 1: Perfmon: possible freeze starting at 00:01:01, delay is 3.324
2014.04.17 00:01:04.333 0: HMLAN_Parse: HMLAN1 R:R6C8EBA35 stat:0002 t:00000000 d:FF r:7FFF     m:DD 8002 D4D4D4 1BF81B 0101000000
2014.04.17 00:01:12.266 0: HMLAN_Send:  HMLAN1 I:K
2014.04.17 00:01:12.278 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:JEQ0315335 d:1C671E O:123ABC t:05270107 IDcnt:000E
2014.04.17 00:01:21.209 0: HMLAN_Parse: HMLAN1 R:E1D252E   stat:0000 t:052723EA d:FF r:FFC2     m:D6 8670 1D252E 000000 00B23D
2014.04.17 00:01:21.409 0: HMLAN_Parse: HMLAN1 R:E1D252E   stat:0000 t:052724B3 d:FF r:FFC2     m:D7 A03F 1D252E 123ABC 
2014.04.17 00:01:21.511 0: HMLAN_Send:  HMLAN1 S:+1D252E,00,01,1E
2014.04.17 00:01:21.512 0: HMLAN_Send:  HMLAN1 S:S6C8EFE8B stat:  00 t:00000000 d:01 r:6C8EFE8B m:22 803F 123ABC 1D252E 02041AE1BA31
2014.04.17 00:01:37.277 0: HMLAN_Send:  HMLAN1 I:K
2014.04.17 00:01:38.289 0: HMLAN_Send:  HMLAN1 I:K
2014.04.17 00:01:39.300 0: HMLAN_Send:  HMLAN1 I:K
2014.04.17 00:01:40.311 0: HMLAN_Send:  HMLAN1 I:K
2014.04.17 00:01:41.321 1: HMLAN_Parse: HMLAN1 new condition timeout
2014.04.17 00:01:41.553 1: 
                                name             function    max  count    total  average maxDly
                         tmr-at_Exec       HASH(a_midnight3)   3896      1     3896  3896.00      9 HASH(a_midnight3)
                              addLog          notify_Exec   3840      1     3840  3840.00      0 HASH(addLog); HASH(addLog)
                              HMLAN1           HMLAN_Read    426     13     1492   114.77      0 HASH(HMLAN1)
               tmr-Twilight_Midnight      HASH(0x13cea38)    364      1      364   364.00      7 HASH(0x13cea38)
                  tmr-HCS_checkState      HASH(BROETJE)    331      2      599   299.50      8 HASH(BROETJE)
                      tmr-PID20_Calc            PID20.Bad    274      2      297   148.50    309 PID20.Bad
                      tmr-PID20_Calc             PID20.AZ    272      2      295   147.50    511 PID20.AZ
                           n_set_hzg          notify_Exec    250      7      826   118.00      0 HASH(n_set_hzg); HASH(BROETJE)
                         tmr-at_Exec       HASH(a_hmlan_internals)    179      2      260   130.00      7 HASH(a_hmlan_internals)
            VentilControler.Bad_Btn1           CUL_HM_Set    170      1      170   170.00      0 HASH(VentilControler.Bad_Btn1); VentilControler.Bad_Btn1; valvePos; 0
        VentilControler.AZ.Nord_Btn1           CUL_HM_Set    166      1      166   166.00      0 HASH(VentilControler.AZ.Nord_Btn1); VentilControler.AZ.Nord_Btn1; valvePos; 0
               n_control_TCControler          notify_Exec    138    103      377     3.66      0 HASH(n_control_TCControler); HASH(TCControler.SZ_Btn1)
                              cul433             CUL_Read     93      2      157    78.50      0 HASH(cul433)
               BROETJEDemandRaumTemp            dummy_Set     49      1       49    49.00      0 HASH(BROETJEDemandRaumTemp); BROETJEDemandRaumTemp; 17.9
         tmr-PRESENCE_StartLocalScan      HASH(laptop)     34      1       34    34.00      8 HASH(laptop)
                      tmr-PID20_Calc         PID20.Kueche     26      2       50    25.00    510 PID20.Kueche
                      tmr-PID20_Calc             PID20.WZ     25      2       49    24.50    509 PID20.WZ
                          n_batt_chk          notify_Exec     19    103      309     3.00      0 HASH(n_batt_chk); HASH(Ventil.Kueche)
                        n_alarmgeber          notify_Exec     18    104      150     1.44      0 HASH(n_alarmgeber); HASH(Tuer.WZ.Terrasse)
                             BROETJE              HCS_Get     16      2       31    15.50      0 HASH(BROETJE); BROETJE; values
                      tmr-PID20_Calc             PID20.SZ     11      2       21    10.50    322 PID20.SZ
                      tmr-PID20_Calc      HASH(PID20.SZ)     10      2       20    10.00      8 HASH(PID20.SZ)
                      tmr-PID20_Calc      HASH(PID20.WZ)     10      2       20    10.00    774 HASH(PID20.WZ)
                      tmr-PID20_Calc      HASH(PID20.Kueche)     10      2       20    10.00    774 HASH(PID20.Kueche)
                 tmr-holiday_refresh               events     10      1       10    10.00      7 events
               FileLog_Thermostat.WZ          FileLog_Log      8    104      247     2.38      0 HASH(FileLog_Thermostat.WZ); HASH(VentilControler.Bad_Btn1)
               tmr-HTTPMOD_GetUpdate      HASH(Broetje)      8      1        8     8.00      8 HASH(Broetje)
                     FileLog_Broetje          FileLog_Log      7    104      276     2.65      0 HASH(FileLog_Broetje); HASH(Thermostat.SZ)
                  FileLog_Technik_IO          FileLog_Log      7    104      336     3.23      0 HASH(FileLog_Technik_IO); HASH(Thermostat.SZ)
                      FileLog_cul433          FileLog_Log      7    104      252     2.42      0 HASH(FileLog_cul433); HASH(BROETJEDemandKomfTemp)
                             Logfile          FileLog_Log      7    104       62     0.60      0 HASH(Logfile); HASH(HMLAN1)
              FileLog_Thermostat.Bad          FileLog_Log      6    104      254     2.44      0 HASH(FileLog_Thermostat.Bad); HASH(myTwilight)
                 tmr-HMLAN_KeepAlive     keepAlive:HMLAN1      6      4       22     5.50      8 keepAlive:HMLAN1
               FileLog_Thermostat.AZ          FileLog_Log      5    104      232     2.23      0 HASH(FileLog_Thermostat.AZ); HASH(myTwilight)
           FileLog_Thermostat.Kueche          FileLog_Log      5    104      229     2.20      0 HASH(FileLog_Thermostat.Kueche); HASH(myTwilight)
               FileLog_Thermostat.SZ          FileLog_Log      5    104      240     2.31      0 HASH(FileLog_Thermostat.SZ); HASH(myTwilight)
            tmr-HMLAN_KeepAliveCheck   keepAliveCk:HMLAN1      5      7       15     2.14    414 keepAliveCk:HMLAN1
                      FileLog_cul868          FileLog_Log      4    104      114     1.10      0 HASH(FileLog_cul868); HASH(myTwilight)
                  FileLog_myTwilight          FileLog_Log      4      1        4     4.00      0 HASH(FileLog_myTwilight); HASH(myTwilight)
             tmr-CUL_HM_valvePosUpdt    valvePos:B1B1B101      4      1        4     4.00      8 valvePos:B1B1B101
              tmr-FW_closeOldClients                           4      2        8     4.00      9 
                            PID20.AZ         PID20_Notify      3    104        8     0.08      0 HASH(PID20.AZ); HASH(Thermostat.AZ)
                        PID20.Kueche         PID20_Notify      3    104       10     0.10      0 HASH(PID20.Kueche); HASH(Thermostat.Kueche)
                       n_set_desired          notify_Exec      3    103      107     1.04      0 HASH(n_set_desired); HASH(myTwilight)
                          telnetPort          telnet_Read      3      1        3     3.00      0 HASH(telnetPort)
                           PID20.Bad         PID20_Notify      2    104        7     0.07      0 HASH(PID20.Bad); HASH(Thermostat.Bad)
                            PID20.WZ         PID20_Notify      2    104        6     0.06      0 HASH(PID20.WZ); HASH(Thermostat.WZ)
            tmr-perfmon_ProcessTimer       HASH(0x9b19b0)      2     98        3     0.03   3324 HASH(0x9b19b0)
                     n_Broetje_alarm          notify_Exec      2    104       75     0.72      0 HASH(n_Broetje_alarm); HASH(myTwilight)
                               n_Bxx          notify_Exec      2    104       39     0.38      0 HASH(n_Bxx); HASH(myTwilight)
                     n_valveCtrl_chk          notify_Exec      2    103       86     0.83      0 HASH(n_valveCtrl_chk); HASH(myTwilight)
                              HMLAN1           HMLAN_Attr      1      2        2     1.00      0 set; HMLAN1; logIDs; sys,all
                              HMLAN1         HMLAN_Notify      1    104        1     0.01      0 HASH(HMLAN1); HASH(Thermostat.AZ)
                            PID20.SZ         PID20_Notify      1    104        5     0.05      0 HASH(PID20.SZ); HASH(Thermostat.SZ)
              tmr-CUL_HM_valvePosTmr    valveTmr:B1B1B101      1      1        1     1.00      7 valveTmr:B1B1B101
              tmr-CUL_HM_valvePosTmr    valveTmr:B3B3B301      1      1        1     1.00      7 valveTmr:B3B3B301
              tmr-CUL_HM_valvePosTmr    valveTmr:B5B5B501      1      1        1     1.00      6 valveTmr:B5B5B501
             tmr-CUL_HM_valvePosUpdt    valvePos:B3B3B301      1      1        1     1.00      7 valvePos:B3B3B301
                tmr-HMLAN_UpdtMsgCnt       UpdtMsg:HMLAN1      1      1        1     1.00     18 UpdtMsg:HMLAN1
                           n_apptime          notify_Exec      1     15        7     0.47      0 HASH(n_apptime); HASH(HMLAN1)
                      TCControler.SZ          CUL_HM_Attr      0      1        0     0.00      0 
                      TCControler.WZ          CUL_HM_Attr      0      1        0     0.00      0 
                                 WEB            FW_Notify      0    104        0     0.00      0 
                            WEBphone            FW_Notify      0    104        0     0.00      0 
                           WEBtablet            FW_Notify      0    104        0     0.00      0 
                                  et    eventTypes_Notify      0    104        0     0.00      0 
                    tmr-BlockingKill      HASH(0x15f8a58)      0      1        0     0.00      8 
                    tmr-BlockingKill      HASH(0x163be68)      0      1        0     0.00      8 
               tmr-HttpUtils_ConnErr      HASH(Broetje)      0      1        0     0.00      8 
               tmr-HttpUtils_ConnErr      HASH(0x1584508)      0      1        0     0.00      7 
               tmr-HttpUtils_ReadErr      HASH(Broetje)      0      1        0     0.00      3 
               tmr-HttpUtils_ReadErr      HASH(0x1584508)      0      1        0     0.00     12

die 3 einträge mit über 3 sekunden (2xmax, 1xmaxdly) beziehen sich auf die gleiche aktion um 00:01:00, wo ich über ein at ein addlog starte. die durch addlog entstehenden verzögerungen gefallen mir auch nicht, habe aber noch keine bessere lösung gefunden. als ursache für das timeout fallen sie aus, da anschliessend um 00:01:12 der wdtimer korrekt beantwortet wird. erst beim folgenden wdtimer um 00:01:37 kommt es zum timeout. bei weiteren 47 addlog pro tag habe ich auch noch kein timeout feststellen können.

seltsam finde ich, dass die letzte aktion des hmlan mit der systemzeiteinstellung eines hm-cc-tc (1D252E) zu tun hat. gestern war das auch genau so. aber ein anderer tc. vielleicht auch nur zufall.

kurze verständnisfrage zum keepalife. sendet wirklich der hmlan das I:K und beantwortet selber, oder sendet fhem an den hmlan?

gruss frank

frank · 18 April 2014, 11:00:11

hallo martin,

die indizien verdichten sich, dass die ursache meiner timeouts in der kommunikation mit den hm-cc-tc zu suchen ist. speziell das setzen der systemzeit, wie gestern bereits vermutet.

heute nacht hatte ich bei meinen 4 tc im zeitraum zwischen 00:00 und 00:10 das attribut ignore auf 1 gesetzt. als ergebnis gab es dann keinen timeout.

auch der genaue zeitpunkt meiner timeouts lässt darauf schliessen. im zeitraum vom 21. februar bis zum 9. april konnte ich ca 20 timeout feststellen. sämtliche timeout zeitpunkte finden zwischen 00:00:12 und 00:02:55 statt. das korreliert mit dem 1. wakeup cycle der tc nach mitternacht.

Code Auswählen

2014.04.18 00:00:14.721 0: HMLAN_Parse: HMLAN1 R:E1BF81B   stat:0000 t:0525361A d:FF r:FFD3     m:16 A258 1BF81B D4D4D4 0000
2014.04.18 00:00:25.002 0: HMLAN_Send:  HMLAN1 I:K
2014.04.18 00:00:25.016 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:JEQ0315335 d:1C671E O:123ABC t:05255E51 IDcnt:000D
2014.04.18 00:00:50.010 0: HMLAN_Send:  HMLAN1 I:K
2014.04.18 00:00:50.023 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:JEQ0315335 d:1C671E O:123ABC t:0525C004 IDcnt:000D
2014.04.18 00:01:04.067 1: Perfmon: possible freeze starting at 00:01:01, delay is 3.066
2014.04.18 00:01:10.558 0: HMLAN_Parse: HMLAN1 R:E1936FF   stat:0000 t:0526103E d:FF r:FFAE     m:3E 8670 1936FF 000000 009947
2014.04.18 00:01:10.747 0: HMLAN_Parse: HMLAN1 R:E1936FF   stat:0000 t:052610FC d:FF r:FFAE     m:3F A03F 1936FF 123ABC 
2014.04.18 00:01:10.871 0: HMLAN_Parse: HMLAN1 R:E1936FF   stat:0000 t:052610FC d:FF r:FFAE     m:3F A03F 1936FF 123ABC 
2014.04.18 00:01:13.094 0: HMLAN_Parse: HMLAN1 R:E1D252E   stat:0000 t:05261A27 d:FF r:FFC2     m:0E 8670 1D252E 000000 00A73A
2014.04.18 00:01:13.295 0: HMLAN_Parse: HMLAN1 R:E1D252E   stat:0000 t:05261AF0 d:FF r:FFC2     m:0F A03F 1D252E 123ABC 
2014.04.18 00:01:13.420 0: HMLAN_Parse: HMLAN1 R:E1D252E   stat:0000 t:05261AF0 d:FF r:FFC2     m:0F A03F 1D252E 123ABC 
2014.04.18 00:01:15.032 0: HMLAN_Send:  HMLAN1 I:K
2014.04.18 00:01:15.044 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:JEQ0315335 d:1C671E O:123ABC t:052621C5 IDcnt:000D
2014.04.18 00:01:30.651 0: HMLAN_Parse: HMLAN1 R:E1936FF   stat:0000 t:05265EBE d:FF r:FFAE     m:3E A258 1936FF D3D3D3 0000
2014.04.18 00:01:31.571 0: HMLAN_Parse: HMLAN1 R:E1DFDA5   stat:0000 t:05266254 d:FF r:FFBE     m:7C 8670 1DFDA5 000000 00AE3A
2014.04.18 00:01:31.762 0: HMLAN_Parse: HMLAN1 R:E1DFDA5   stat:0000 t:05266315 d:FF r:FFBE     m:7D A03F 1DFDA5 123ABC 
2014.04.18 00:01:31.885 0: HMLAN_Parse: HMLAN1 R:E1DFDA5   stat:0000 t:05266315 d:FF r:FFBE     m:7D A03F 1DFDA5 123ABC 
2014.04.18 00:01:33.201 0: HMLAN_Parse: HMLAN1 R:E1D252E   stat:0000 t:052668B4 d:FF r:FFC1     m:0E A258 1D252E D1D1D1 0000
2014.04.18 00:01:40.043 0: HMLAN_Send:  HMLAN1 I:K
2014.04.18 00:01:40.057 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:JEQ0315335 d:1C671E O:123ABC t:0526837C IDcnt:000D
2014.04.18 00:01:43.305 0: HMLAN_Send:  HMLAN1 S:S71B5AFCD stat:  00 t:00000000 d:01 r:71B5AFCD m:E3 A258 B5B5B5 1C4E25 0000
2014.04.18 00:01:43.487 0: HMLAN_Parse: HMLAN1 R:E1C4E25   stat:0000 t:052690D0 d:FF r:FFC1     m:E3 8202 1C4E25 B5B5B5 010100883E
2014.04.18 00:01:43.869 0: HMLAN_Parse: HMLAN1 R:R71B5AFCD stat:0008 t:00000000 d:FF r:7FFF     m:E3 A258 B5B5B5 1C4E25 0000
2014.04.18 00:01:43.874 0: HMLAN_Parse: HMLAN1 no ACK from 1C4E25
2014.04.18 00:01:51.666 0: HMLAN_Parse: HMLAN1 R:E1DFDA5   stat:0000 t:0526B0D8 d:FF r:FFBD     m:7C A258 1DFDA5 D2D2D2 0034
2014.04.18 00:01:58.936 0: HMLAN_Parse: HMLAN1 R:E24AF1D   stat:0000 t:0526CD3D d:FF r:FFC0     m:CA 845E 24AF1D 000000 800FEE0000000000095FF8
2014.04.18 00:02:05.054 0: HMLAN_Send:  HMLAN1 I:K
2014.04.18 00:02:05.066 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:JEQ0315335 d:1C671E O:123ABC t:0526E532 IDcnt:000D
2014.04.18 00:02:16.273 0: HMLAN_Send:  HMLAN1 S:S71B63095 stat:  00 t:00000000 d:01 r:71B63095 m:0F A258 B3B3B3 193A9A 0000
2014.04.18 00:02:16.456 0: HMLAN_Parse: HMLAN1 R:E193A9A   stat:0000 t:0527119E d:FF r:FFC0     m:0F 8202 193A9A B3B3B3 010100003F
2014.04.18 00:02:16.836 0: HMLAN_Parse: HMLAN1 R:R71B63095 stat:0008 t:00000000 d:FF r:7FFF     m:0F A258 B3B3B3 193A9A 0000
2014.04.18 00:02:16.839 0: HMLAN_Parse: HMLAN1 no ACK from 193A9A
2014.04.18 00:02:30.065 0: HMLAN_Send:  HMLAN1 I:K
2014.04.18 00:02:30.076 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:JEQ0315335 d:1C671E O:123ABC t:052746E8 IDcnt:000D
2014.04.18 00:02:52.729 0: HMLAN_Parse: HMLAN1 R:E1BF81B   stat:0000 t:05279F65 d:FF r:FFD2     m:17 8670 1BF81B 000000 00AF38
2014.04.18 00:02:52.920 0: HMLAN_Parse: HMLAN1 R:E1BF81B   stat:0000 t:0527A025 d:FF r:FFD2     m:18 A03F 1BF81B 123ABC 
2014.04.18 00:02:53.043 0: HMLAN_Parse: HMLAN1 R:E1BF81B   stat:0000 t:0527A025 d:FF r:FFD2     m:18 A03F 1BF81B 123ABC 
2014.04.18 00:02:55.076 0: HMLAN_Send:  HMLAN1 I:K
2014.04.18 00:02:55.088 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:JEQ0315335 d:1C671E O:123ABC t:0527A89F IDcnt:000D
2014.04.18 00:03:12.824 0: HMLAN_Parse: HMLAN1 R:E1BF81B   stat:0000 t:0527EDE9 d:FF r:FFD2     m:17 A258 1BF81B D4D4D4 0000
2014.04.18 00:03:19.403 0: HMLAN_Parse: HMLAN1 R:E1936FF   stat:0000 t:0528079D d:FF r:FFAE     m:3F 8670 1936FF 000000 009946
2014.04.18 00:03:20.086 0: HMLAN_Send:  HMLAN1 I:K
2014.04.18 00:03:20.099 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:JEQ0315335 d:1C671E O:123ABC t:05280A54 IDcnt:000D
2014.04.18 00:03:28.905 0: HMLAN_Send:  HMLAN1 S:S71B74C4D stat:  00 t:00000000 d:01 r:71B74C4D m:03 A258 B1B1B1 1BFC52 0000
2014.04.18 00:03:29.090 0: HMLAN_Parse: HMLAN1 R:E1BFC52   stat:0000 t:05282D61 d:FF r:FFD2     m:03 8202 1BFC52 B1B1B1 010100002D
2014.04.18 00:03:29.470 0: HMLAN_Parse: HMLAN1 R:R71B74C4D stat:0008 t:00000000 d:FF r:7FFF     m:03 A258 B1B1B1 1BFC52 0000
2014.04.18 00:03:29.473 0: HMLAN_Parse: HMLAN1 no ACK from 1BFC52
2014.04.18 00:03:39.403 0: HMLAN_Parse: HMLAN1 R:E1936FF   stat:0000 t:052855BF d:FF r:FFAF     m:3F A258 1936FF D3D3D3 0000
2014.04.18 00:03:45.097 0: HMLAN_Send:  HMLAN1 I:K
2014.04.18 00:03:45.109 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:JEQ0315335 d:1C671E O:123ABC t:05286C0B IDcnt:000D
2014.04.18 00:03:52.423 0: HMLAN_Parse: HMLAN1 R:E1DFDA5   stat:0000 t:0528889C d:FF r:FFBC     m:7D 8670 1DFDA5 000000 00AE3A
2014.04.18 00:03:57.460 0: HMLAN_Parse: HMLAN1 R:E1D252E   stat:0000 t:05289C47 d:FF r:FFC1     m:0F 8670 1D252E 000000 00A73A
2014.04.18 00:04:01.962 0: HMLAN_Send:  HMLAN1 S:S71B7CD6E stat:  00 t:00000000 d:01 r:71B7CD6E m:EF A258 B4B4B4 1CE9F5 0000
2014.04.18 00:04:02.146 0: HMLAN_Parse: HMLAN1 R:E1CE9F5   stat:0000 t:0528AE86 d:FF r:FFD4     m:EF 8202 1CE9F5 B4B4B4 010100002D
2014.04.18 00:04:02.527 0: HMLAN_Parse: HMLAN1 R:R71B7CD6E stat:0008 t:00000000 d:FF r:7FFF     m:EF A258 B4B4B4 1CE9F5 0000
2014.04.18 00:04:02.529 0: HMLAN_Parse: HMLAN1 no ACK from 1CE9F5
2014.04.18 00:04:10.108 0: HMLAN_Send:  HMLAN1 I:K
2014.04.18 00:04:10.121 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:JEQ0315335 d:1C671E O:123ABC t:0528CDC1 IDcnt:000D
2014.04.18 00:04:12.422 0: HMLAN_Parse: HMLAN1 R:E1DFDA5   stat:0000 t:0528D6BE d:FF r:FFBE     m:7D A258 1DFDA5 D2D2D2 0034
2014.04.18 00:04:17.456 0: HMLAN_Parse: HMLAN1 R:E1D252E   stat:0000 t:0528EA69 d:FF r:FFC1     m:0F A258 1D252E D1D1D1 0000
2014.04.18 00:04:35.119 0: HMLAN_Send:  HMLAN1 I:K
2014.04.18 00:04:35.137 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:JEQ0315335 d:1C671E O:123ABC t:05292F77 IDcnt:000D
2014.04.18 00:04:54.687 0: HMLAN_Parse: HMLAN1 R:E24AF1D   stat:0000 t:05297BDA d:FF r:FFC1     m:CB 845E 24AF1D 000000 800FEE0000000000095BFD
2014.04.18 00:05:00.130 0: HMLAN_Send:  HMLAN1 I:K
2014.04.18 00:05:00.141 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:JEQ0315335 d:1C671E O:123ABC t:0529912D IDcnt:000D
2014.04.18 00:05:25.141 0: HMLAN_Send:  HMLAN1 I:K
2014.04.18 00:05:25.153 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:JEQ0315335 d:1C671E O:123ABC t:0529F2E3 IDcnt:000D
2014.04.18 00:05:36.330 0: HMLAN_Parse: HMLAN1 R:E1BF81B   stat:0000 t:052A1E8D d:FF r:FFD2     m:18 8670 1BF81B 000000 00AE37
2014.04.18 00:05:50.151 0: HMLAN_Send:  HMLAN1 I:K
2014.04.18 00:05:50.164 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:JEQ0315335 d:1C671E O:123ABC t:052A5499 IDcnt:000D
2014.04.18 00:05:56.330 0: HMLAN_Parse: HMLAN1 R:E1BF81B   stat:0000 t:052A6CB0 d:FF r:FFD2     m:18 A258 1BF81B D4D4D4 0000
2014.04.18 00:05:58.676 0: HMLAN_Parse: HMLAN1 R:E1DFDA5   stat:0000 t:052A75DB d:FF r:FFBD     m:7E 8670 1DFDA5 000000 00AE3A
2014.04.18 00:06:15.162 0: HMLAN_Send:  HMLAN1 I:K
2014.04.18 00:06:15.175 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:JEQ0315335 d:1C671E O:123ABC t:052AB64F IDcnt:000D
2014.04.18 00:06:17.907 0: HMLAN_Parse: HMLAN1 R:E1936FF   stat:0000 t:052AC0FC d:FF r:FFAF     m:40 8670 1936FF 000000 009846
2014.04.18 00:06:18.677 0: HMLAN_Parse: HMLAN1 R:E1DFDA5   stat:0000 t:052AC3FE d:FF r:FFBD     m:7E A258 1DFDA5 D2D2D2 0034
2014.04.18 00:06:27.191 0: HMLAN_Send:  HMLAN1 S:+1BFC52,00,01,1E
2014.04.18 00:06:27.195 0: HMLAN_Send:  HMLAN1 S:S71BA04BA stat:  00 t:00000000 d:01 r:71BA04BA m:04 A258 B1B1B1 1BFC52 0300
2014.04.18 00:06:27.580 0: HMLAN_Parse: HMLAN1 R:E1BFC52   stat:0000 t:052AE6B2 d:FF r:FFD2     m:04 8202 1BFC52 B1B1B1 010100002D
2014.04.18 00:06:27.760 0: HMLAN_Parse: HMLAN1 R:R71BA04BA stat:0008 t:00000000 d:FF r:7FFF     m:04 A258 B1B1B1 1BFC52 0300
2014.04.18 00:06:27.762 0: HMLAN_Parse: HMLAN1 no ACK from 1BFC52
2014.04.18 00:06:37.906 0: HMLAN_Parse: HMLAN1 R:E1936FF   stat:0000 t:052B0F1E d:FF r:FFAE     m:40 A258 1936FF D3D3D3 0000
2014.04.18 00:06:40.328 0: HMLAN_Send:  HMLAN1 I:K
2014.04.18 00:06:40.390 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:JEQ0315335 d:1C671E O:123ABC t:052B18A0 IDcnt:000D
2014.04.18 00:06:47.211 0: HMLAN_Parse: HMLAN1 R:E1D252E   stat:0000 t:052B3378 d:FF r:FFC2     m:10 A258 1D252E D1D1D1 0000
2014.04.18 00:06:53.807 0: HMLAN_Send:  HMLAN1 S:S71BA6CB2 stat:  00 t:00000000 d:01 r:71BA6CB2 m:01 A258 B2B2B2 1DFC2F 00FD
2014.04.18 00:06:53.991 0: HMLAN_Parse: HMLAN1 R:E1DFC2F   stat:0000 t:052B4DE1 d:FF r:FFD3     m:01 8202 1DFC2F B2B2B2 0101C6002A
2014.04.18 00:06:54.371 0: HMLAN_Parse: HMLAN1 R:R71BA6CB2 stat:0008 t:00000000 d:FF r:7FFF     m:01 A258 B2B2B2 1DFC2F 00FD
2014.04.18 00:06:54.373 0: HMLAN_Parse: HMLAN1 no ACK from 1DFC2F
2014.04.18 00:07:05.339 0: HMLAN_Send:  HMLAN1 I:K
2014.04.18 00:07:05.351 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:JEQ0315335 d:1C671E O:123ABC t:052B7A56 IDcnt:000D
2014.04.18 00:07:30.350 0: HMLAN_Send:  HMLAN1 I:K
2014.04.18 00:07:30.362 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:JEQ0315335 d:1C671E O:123ABC t:052BDC0D IDcnt:000D
2014.04.18 00:07:35.936 0: HMLAN_Parse: HMLAN1 R:E24AF1D   stat:0000 t:052BF1D1 d:FF r:FFC1     m:CC 845E 24AF1D 000000 800FEE0000000000095AFD
2014.04.18 00:07:55.361 0: HMLAN_Send:  HMLAN1 I:K
2014.04.18 00:07:55.373 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:JEQ0315335 d:1C671E O:123ABC t:052C3DC4 IDcnt:000D
2014.04.18 00:08:05.585 0: HMLAN_Parse: HMLAN1 R:E1BF81B   stat:0000 t:052C65A8 d:FF r:FFD2     m:19 8670 1BF81B 000000 00AE37
2014.04.18 00:08:20.372 0: HMLAN_Send:  HMLAN1 I:K
2014.04.18 00:08:20.384 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:JEQ0315335 d:1C671E O:123ABC t:052C9F7A IDcnt:000D
2014.04.18 00:08:25.584 0: HMLAN_Parse: HMLAN1 R:E1BF81B   stat:0000 t:052CB3CA d:FF r:FFD2     m:19 A258 1BF81B D4D4D4 0000
2014.04.18 00:08:42.467 0: HMLAN_Parse: HMLAN1 R:E1D252E   stat:0000 t:052CF5BF d:FF r:FFC1     m:11 8670 1D252E 000000 00A63A
2014.04.18 00:08:45.383 0: HMLAN_Send:  HMLAN1 I:K
2014.04.18 00:08:45.395 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:JEQ0315335 d:1C671E O:123ABC t:052D0130 IDcnt:000D
2014.04.18 00:08:54.686 0: HMLAN_Parse: HMLAN1 R:E1DFDA5   stat:0000 t:052D257A d:FF r:FFBD     m:7F 8670 1DFDA5 000000 00AE3A
2014.04.18 00:09:01.911 0: HMLAN_Parse: HMLAN1 R:E1936FF   stat:0000 t:052D41B5 d:FF r:FFAE     m:41 8670 1936FF 000000 009846
2014.04.18 00:09:02.466 0: HMLAN_Parse: HMLAN1 R:E1D252E   stat:0000 t:052D43E1 d:FF r:FFC2     m:11 A258 1D252E D1D1D1 0000
2014.04.18 00:09:10.395 0: HMLAN_Send:  HMLAN1 I:K
2014.04.18 00:09:10.407 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:JEQ0315335 d:1C671E O:123ABC t:052D62E7 IDcnt:000D
2014.04.18 00:09:12.562 0: HMLAN_Send:  HMLAN1 S:+1C4E25,00,01,1E
2014.04.18 00:09:12.564 0: HMLAN_Send:  HMLAN1 S:S71BC8AB6 stat:  00 t:00000000 d:01 r:71BC8AB6 m:E6 A258 B5B5B5 1C4E25 0300
2014.04.18 00:09:12.745 0: HMLAN_Parse: HMLAN1 R:E1C4E25   stat:0000 t:052D6BF6 d:FF r:FFC1     m:E6 8202 1C4E25 B5B5B5 010100883E
2014.04.18 00:09:13.125 0: HMLAN_Parse: HMLAN1 R:R71BC8AB6 stat:0008 t:00000000 d:FF r:7FFF     m:E6 A258 B5B5B5 1C4E25 0300
2014.04.18 00:09:13.128 0: HMLAN_Parse: HMLAN1 no ACK from 1C4E25
2014.04.18 00:09:14.684 0: HMLAN_Parse: HMLAN1 R:E1DFDA5   stat:0000 t:052D739C d:FF r:FFBE     m:7F A258 1DFDA5 D2D2D2 0034
2014.04.18 00:09:21.908 0: HMLAN_Parse: HMLAN1 R:E1936FF   stat:0000 t:052D8FD6 d:FF r:FFAE     m:41 A258 1936FF D3D3D3 0000
2014.04.18 00:09:35.406 0: HMLAN_Send:  HMLAN1 I:K
2014.04.18 00:09:35.418 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:JEQ0315335 d:1C671E O:123ABC t:052DC49E IDcnt:000D
2014.04.18 00:09:41.532 0: HMLAN_Send:  HMLAN1 S:+193A9A,00,01,1E
2014.04.18 00:09:41.534 0: HMLAN_Send:  HMLAN1 S:S71BCFBDF stat:  00 t:00000000 d:01 r:71BCFBDF m:12 A258 B3B3B3 193A9A 0300
2014.04.18 00:09:41.717 0: HMLAN_Parse: HMLAN1 R:E193A9A   stat:0000 t:052DDD26 d:FF r:FFC0     m:12 8202 193A9A B3B3B3 010100003F
2014.04.18 00:09:42.098 0: HMLAN_Parse: HMLAN1 R:R71BCFBDF stat:0008 t:00000000 d:FF r:7FFF     m:12 A258 B3B3B3 193A9A 0300
2014.04.18 00:09:42.101 0: HMLAN_Parse: HMLAN1 no ACK from 193A9A
2014.04.18 00:10:00.220 1: 
                                name             function    max  count    total  average maxDly
                         tmr-at_Exec       HASH(a_midnight3)   4034      1     4034  4034.00     10 HASH(a_midnight3)
                              addLog          notify_Exec   3978      1     3978  3978.00      0 HASH(addLog); HASH(addLog)
                  tmr-HCS_checkState      HASH(BROETJE)    736     10     2443   244.30      9 HASH(BROETJE)
               tmr-Twilight_Midnight       HASH(0xf33970)    410      1      410   410.00      7 HASH(0xf33970)
                      tmr-PID20_Calc         PID20.Kueche    338     10      642    64.20    724 PID20.Kueche
                           n_set_hzg          notify_Exec    322     16     1843   115.19      0 HASH(n_set_hzg); HASH(BROETJE)
                      tmr-PID20_Calc            PID20.Bad    284     10      584    58.40    724 PID20.Bad
                      tmr-PID20_Calc             PID20.AZ    283     10      581    58.10    807 PID20.AZ
                         tmr-at_Exec       HASH(a_hmlan_internals)    235     10     1184   118.40      9 HASH(a_hmlan_internals)
         VentilControler.Kueche_Btn1           CUL_HM_Set    230      1      230   230.00      0 HASH(VentilControler.Kueche_Btn1); VentilControler.Kueche_Btn1; valvePos; 0
        VentilControler.AZ.Nord_Btn1           CUL_HM_Set    176      1      176   176.00      0 HASH(VentilControler.AZ.Nord_Btn1); VentilControler.AZ.Nord_Btn1; valvePos; 0
            VentilControler.Bad_Btn1           CUL_HM_Set    173      1      173   173.00      0 HASH(VentilControler.Bad_Btn1); VentilControler.Bad_Btn1; valvePos; 0
             tmr-CUL_HM_valvePosUpdt    valvePos:B1B1B101    163      4      345    86.25      9 valvePos:B1B1B101
                              HMLAN1           HMLAN_Read    154     80     1571    19.64      0 HASH(HMLAN1)
             tmr-CUL_HM_valvePosUpdt    valvePos:B4B4B401    154      4      212    53.00      9 valvePos:B4B4B401
                 tmr-CUL_HM_ActCheck       ActionDetector    141      1      141   141.00     15 ActionDetector
             tmr-CUL_HM_valvePosUpdt    valvePos:B5B5B501    127      4      317    79.25     20 valvePos:B5B5B501
             tmr-CUL_HM_valvePosUpdt    valvePos:B3B3B301    122      4      301    75.25     14 valvePos:B3B3B301
             tmr-CUL_HM_valvePosUpdt    valvePos:B2B2B201    121      4      274    68.50      9 valvePos:B2B2B201
                      tmr-PID20_Calc             PID20.WZ    105     10      402    40.20    726 PID20.WZ
                 tmr-Twilight_sunpos      HASH(0x16c64e8)     75      1       75    75.00      8 HASH(0x16c64e8)
                 tmr-Twilight_sunpos      HASH(0x16c2cd8)     74      1       74    74.00      8 HASH(0x16c2cd8)
                              cul433             CUL_Read     67     20      374    18.70      0 HASH(cul433)
                       BROETJEDemand            dummy_Set     60      1       60    60.00      0 HASH(BROETJEDemand); BROETJEDemand; off
               tmr-HttpUtils_ConnErr      HASH(0x16b82b8)     54      1       54    54.00      4 HASH(0x16b82b8)
         tmr-PRESENCE_StartLocalScan      HASH(laptop)     38      8      283    35.38      9 HASH(laptop)
                          n_batt_chk          notify_Exec     21    156      371     2.38      0 HASH(n_batt_chk); HASH(Fenster.Bad)
                        n_alarmgeber          notify_Exec     19    156      213     1.37      0 HASH(n_alarmgeber); HASH(Tuer.WZ.Terrasse)
                             BROETJE              HCS_Get     17     10      155    15.50      0 HASH(BROETJE); BROETJE; values
           FileLog_Thermostat.Kueche          FileLog_Log     14    156      404     2.59      0 HASH(FileLog_Thermostat.Kueche); HASH(Thermostat.AZ)
                      tmr-PID20_Calc      HASH(PID20.SZ)     14     10      107    10.70      9 HASH(PID20.SZ)
                      FileLog_cul433          FileLog_Log     12    156      421     2.70      0 HASH(FileLog_cul433); HASH(BROETJEDemand)
                      tmr-PID20_Calc      HASH(PID20.WZ)     12     10      107    10.70    822 HASH(PID20.WZ)
                      tmr-PID20_Calc             PID20.SZ     12     10      106    10.60    737 PID20.SZ
                     FileLog_Broetje          FileLog_Log     11    156      465     2.98      0 HASH(FileLog_Broetje); HASH(BROETJE)
                      tmr-PID20_Calc      HASH(PID20.Kueche)     11     10      103    10.30    822 HASH(PID20.Kueche)
                 tmr-holiday_refresh               events     11      1       11    11.00      6 events
               tmr-HTTPMOD_GetUpdate      HASH(Broetje)     10      4       35     8.75     10 HASH(Broetje)
                  FileLog_Technik_IO          FileLog_Log      9    156      541     3.47      0 HASH(FileLog_Technik_IO); HASH(Ventil.WZ)
               FileLog_Thermostat.AZ          FileLog_Log      8    156      378     2.42      0 HASH(FileLog_Thermostat.AZ); HASH(VentilControler.Kueche_Btn1)
               FileLog_Thermostat.SZ          FileLog_Log      8    156      401     2.57      0 HASH(FileLog_Thermostat.SZ); HASH(Broetje)
               FileLog_Thermostat.WZ          FileLog_Log      8    156      408     2.62      0 HASH(FileLog_Thermostat.WZ); HASH(Broetje)
                     n_Broetje_alarm          notify_Exec      8    156      172     1.10      0 HASH(n_Broetje_alarm); HASH(Thermostat.Kueche)
                 tmr-HMLAN_KeepAlive     keepAlive:HMLAN1      7     23      136     5.91    162 keepAlive:HMLAN1
                          telnetPort          telnet_Read      7      8       43     5.38      0 HASH(telnetPort)
              FileLog_Thermostat.Bad          FileLog_Log      6    156      422     2.71      0 HASH(FileLog_Thermostat.Bad); HASH(BROETJE)
              tmr-CUL_HM_valvePosTmr    valveTmr:B1B1B101      6      4       12     3.00      8 valveTmr:B1B1B101
              tmr-CUL_HM_valvePosTmr    valveTmr:B3B3B301      6      4       13     3.25      9 valveTmr:B3B3B301
              tmr-CUL_HM_valvePosTmr    valveTmr:B4B4B401      6      4        6     1.50      9 valveTmr:B4B4B401
              tmr-CUL_HM_valvePosTmr    valveTmr:B5B5B501      6      4       14     3.50      8 valveTmr:B5B5B501
              tmr-FW_closeOldClients                           6     10       42     4.20     10 
              tmr-CUL_HM_valvePosTmr    valveTmr:B2B2B201      5      4        6     1.50      9 valveTmr:B2B2B201
                      FileLog_cul868          FileLog_Log      4    156      177     1.13      0 HASH(FileLog_cul868); HASH(myTwilight)
                  FileLog_myTwilight          FileLog_Log      4      3       10     3.33      0 HASH(FileLog_myTwilight); HASH(myTwilight)
                            PID20.AZ         PID20_Notify      3    156        8     0.05      0 HASH(PID20.AZ); HASH(Thermostat.AZ)
                       n_set_desired          notify_Exec      3    156      159     1.02      0 HASH(n_set_desired); HASH(myTwilight)
                     n_valveCtrl_chk          notify_Exec      3    156      183     1.17      0 HASH(n_valveCtrl_chk); HASH(BROETJE)
               BROETJEDemandRaumTemp            dummy_Set      2      1        2     2.00      0 HASH(BROETJEDemandRaumTemp); BROETJEDemandRaumTemp; 17.5
                           PID20.Bad         PID20_Notify      2    156        8     0.05      0 HASH(PID20.Bad); HASH(Thermostat.Bad)
                            PID20.SZ         PID20_Notify      2    156        6     0.04      0 HASH(PID20.SZ); HASH(Thermostat.SZ)
                tmr-HMLAN_UpdtMsgCnt       UpdtMsg:HMLAN1      2      6        7     1.17     18 UpdtMsg:HMLAN1
            tmr-perfmon_ProcessTimer       HASH(0x9b19b0)      2    596        8     0.01   3066 HASH(0x9b19b0)
                               n_Bxx          notify_Exec      2    156       74     0.47      0 HASH(n_Bxx); HASH(myTwilight)
               n_control_TCControler          notify_Exec      2    156      158     1.01      0 HASH(n_control_TCControler); HASH(myTwilight)
                             Logfile          FileLog_Log      1    156      113     0.72      0 HASH(Logfile); HASH(HMLAN1)
                        PID20.Kueche         PID20_Notify      1    156        6     0.04      0 HASH(PID20.Kueche); HASH(Thermostat.Kueche)
                            PID20.WZ         PID20_Notify      1    156        5     0.03      0 HASH(PID20.WZ); HASH(Thermostat.WZ)
                           n_apptime          notify_Exec      1     31       18     0.58      0 HASH(n_apptime); HASH(HMLAN1)
                              HMLAN1           HMLAN_Attr      0      2        0     0.00      0 
                              HMLAN1         HMLAN_Notify      0    156        0     0.00      0 
                      Thermostat.Bad          CUL_HM_Attr      0      2        0     0.00      0 
                   Thermostat.Kueche          CUL_HM_Attr      0      2        0     0.00      0 
                       Thermostat.SZ          CUL_HM_Attr      0      2        0     0.00      0 
                       Thermostat.WZ          CUL_HM_Attr      0      2        0     0.00      0 
                                 WEB            FW_Notify      0    156        0     0.00      0 
                            WEBphone            FW_Notify      0    156        0     0.00      0 
                           WEBtablet            FW_Notify      0    156        0     0.00      0 
                                  et    eventTypes_Notify      0    156        0     0.00      0 
                    tmr-BlockingKill      HASH(0x13fe650)      0      1        0     0.00      9 
                    tmr-BlockingKill      HASH(0x15b5350)      0      1        0     0.00      8 
                    tmr-BlockingKill      HASH(0x163c328)      0      1        0     0.00      9 
                    tmr-BlockingKill      HASH(0x16c66d8)      0      1        0     0.00      7 
                    tmr-BlockingKill      HASH(0x16dcaf8)      0      1        0     0.00      8 
                    tmr-BlockingKill      HASH(0x16dcb68)      0      1        0     0.00     11 
                    tmr-BlockingKill      HASH(0x16eb5c0)      0      1        0     0.00      8 
                    tmr-BlockingKill      HASH(0x16f27c8)      0      1        0     0.00      8 
                    tmr-BlockingKill       HASH(0xdea4a8)      0      1        0     0.00      8 
            tmr-HMLAN_KeepAliveCheck   keepAliveCk:HMLAN1      0     24        0     0.00     19 
               tmr-HttpUtils_ConnErr      HASH(Broetje)      0      4        0     0.00      8 
               tmr-HttpUtils_ConnErr      HASH(0x16b18a8)      0      1        0     0.00      8 
               tmr-HttpUtils_ReadErr      HASH(Broetje)      0      4        0     0.00      3 
               tmr-HttpUtils_ReadErr      HASH(0x16b18a8)      0      1        0     0.00     64 
               tmr-HttpUtils_ReadErr      HASH(0x16b82b8)      0      1        0     0.00      8 
                         tmr-at_Exec      HASH(a_verbose1)      0      1        0     0.00      9

was genau ist die ursache, dass bei apptime nicht alle hashes mit namen versehen werden?

gruss frank

frank · 18 April 2014, 12:07:34

hallo martin,

beim durchschauen vergangener timestamp kommunikationen ist mir noch aufgefallen, dass die msgnummer von frage/antwort fast immer unterschiedlich ist. ich dachte die sollten gleich sein.

Code Auswählen

2014-04-17_00:01:21 HMLAN1 RCV L:09 N:D7 F:A0 CMD:3F SRC:Thermostat.Kueche DST:123ABC  (TimeStamp) (,BIDI,RPTEN)
2014-04-17_00:01:21 HMLAN1 SND L:0F N:22 F:80 CMD:3F SRC:123ABC DST:Thermostat.Kueche 02041AE1BA31 (TimeStamp UNKNOWN:0x0204 TIME:0x1A) (,RPTEN)

gruss frank

martinp876 · 18 April 2014, 12:50:31

Im ersten Fall antwortet der HMLAN nicht

Zitat00:01:21.409 0: HMLAN_Parse: HMLAN1 R:E1D252E stat:0000 t:052724B3 d:FF r:FFC2 m:D7 A03F 1D252E 123ABC
00:01:21.512 0: HMLAN_Send: HMLAN1 S:S6C8EFE8B stat: 00 t:00000000 d:01 r:6C8EFE8B m:22 803F 123ABC 1D252E 02041AE1BA31
00:01:37.277 0: HMLAN_Send: HMLAN1 I:K
00:01:38.289 0: HMLAN_Send: HMLAN1 I:K
00:01:39.300 0: HMLAN_Send: HMLAN1 I:K
00:01:40.311 0: HMLAN_Send: HMLAN1 I:K
00:01:41.321 1: HMLAN_Parse: HMLAN1 new condition timeout

ein timestamp request zur davor.

Die Sequenz-nummer habe ich korrigiert - da hast du recht, das war falsch... einen Disconnect deshalb kann ich mich aber nicht herleiten.... wer weiss...

Gib bitte bescheid, es das Problem behebt