FHEM Forum

FHEM => Anfängerfragen => Thema gestartet von: Motivierte linke Hände am 25 Oktober 2015, 09:20:33

Titel: possible freeze minütlich für 6 Sekunden debuggen
Beitrag von: Motivierte linke Hände am 25 Oktober 2015, 09:20:33
Hi - Ich muss nochmal bitte was zu den Basics fragen: Ich habe minütlich "possible freeze" Meldungen und würde gerne herausfinden, wodran das liegt:

2015.10.25 08:49:41 1: Perfmon: possible freeze starting at 08:49:35, delay is 6.003
2015.10.25 08:50:45 1: Perfmon: possible freeze starting at 08:50:39, delay is 6.004
2015.10.25 08:51:49 1: Perfmon: possible freeze starting at 08:51:43, delay is 6.004
2015.10.25 08:52:53 1: Perfmon: possible freeze starting at 08:52:47, delay is 6.003
2015.10.25 08:53:56 1: Perfmon: possible freeze starting at 08:53:51, delay is 5.999


Das Log von solchen Freezes (mit "attr global verbose 5") ist allerdings komplett nicht hilfreich für mich. Zum Beispiel 08:16:

2015.10.25 08:52:43 5: HMLAN_Parse: HMLAN2 R:E33B27B   stat:0000 t:05173700 d:FF r:FFBD     m:08 8610 33B27B 000000 0A24A90E0000
2015.10.25 08:52:43 5: HMLAN2 dispatch A0F08861033B27B0000000A24A90E0000::-67:HMLAN2
2015.10.25 08:52:43 4: CUL_HM Hzg_OG_links dupe: dont process
2015.10.25 08:52:53 1: Perfmon: possible freeze starting at 08:52:47, delay is 6.003
2015.10.25 08:52:53 5: HMLAN_Send:  HMLAN2 I:K
2015.10.25 08:52:53 5: HMLAN_Send:  HMLAN1 I:K
2015.10.25 08:52:53 5: HMLAN/RAW: /E2A7989,0000,05174AF5,FF,FFB8,4E86702A7989000000008A4A
2015.10.25 08:52:53 5: HMLAN_Parse: HMLAN2 R:E2A7989   stat:0000 t:05174AF5 d:FF r:FFB8     m:4E 8670 2A7989 000000 008A4A
2015.10.25 08:52:53 5: HMLAN2 dispatch A0C4E86702A7989000000008A4A::-72:HMLAN2
2015.10.25 08:52:53 5: Triggering Sens_Vorrat (0 changes)
2015.10.25 08:52:53 5: HMLAN_Parse: HMLAN2 R:E301926   stat:0000 t:05174BA8 d:FF r:FFB4     m:12 8610 301926 000000 0AA8E90D0900
2015.10.25 08:52:53 5: HMLAN2 dispatch A0F1286103019260000000AA8E90D0900::-76:HMLAN2
2015.10.25 08:52:53 5: Triggering Hzg_Schlafzimmer (1 changes)
2015.10.25 08:52:53 5: Notify loop for Hzg_Schlafzimmer measured-temp: 23.3
2015.10.25 08:52:53 5: rain_notify: devname=Hzg_Schlafzimmer rainname=rain_KS300, dev=Hzg_Schlafzimmer, dev_regex=KS300 rain_name=rain israining_name=israining
2015.10.25 08:52:53 4: Attribut matchs TimeCode DayChangeTime='06:50'
2015.10.25 08:52:53 5: battStatus: not on any display, ignoring notify
2015.10.25 08:52:53 5: rg_Hzg_EG: not on any display, ignoring notify
2015.10.25 08:52:53 5: rg_Meldungen: not on any display, ignoring notify
2015.10.25 08:52:53 5: Triggering Hzg_Schlafzimmer_Clima (2 changes)
2015.10.25 08:52:53 5: Notify loop for Hzg_Schlafzimmer_Clima measured-temp: 23.3
2015.10.25 08:52:53 5: rain_notify: devname=Hzg_Schlafzimmer_Clima rainname=rain_KS300, dev=Hzg_Schlafzimmer_Clima, dev_regex=KS300 rain_name=rain israining_name=israining
2015.10.25 08:52:53 4: Attribut matchs TimeCode DayChangeTime='06:50'
2015.10.25 08:52:53 5: battStatus: not on any display, ignoring notify
2015.10.25 08:52:53 5: rg_Hzg_EG: not on any display, ignoring notify
2015.10.25 08:52:53 5: rg_Meldungen: not on any display, ignoring notify
2015.10.25 08:52:53 5: Triggering Hzg_Schlafzimmer_Weather (2 changes)
2015.10.25 08:52:53 5: Notify loop for Hzg_Schlafzimmer_Weather measured-temp: 23.3
2015.10.25 08:52:53 5: rain_notify: devname=Hzg_Schlafzimmer_Weather rainname=rain_KS300, dev=Hzg_Schlafzimmer_Weather, dev_regex=KS300 rain_name=rain israining_name=israining
2015.10.25 08:52:53 4: Attribut matchs TimeCode DayChangeTime='06:50'
2015.10.25 08:52:53 5: battStatus: not on any display, ignoring notify
2015.10.25 08:52:53 5: rg_Meldungen: not on any display, ignoring notify
2015.10.25 08:52:53 5: HMLAN_Parse: HMLAN2 R:E2C7C23   stat:0000 t:05174D65 d:FF r:FFBD     m:AC 8670 2C7C23 000000 00D834
2015.10.25 08:52:53 5: HMLAN2 dispatch A0CAC86702C7C2300000000D834::-67:HMLAN2
2015.10.25 08:52:53 5: Triggering Sens_Bad (5 changes)
2015.10.25 08:52:53 5: Notify loop for Sens_Bad battery: ok
2015.10.25 08:52:53 5: rain_notify: devname=Sens_Bad rainname=rain_KS300, dev=Sens_Bad, dev_regex=KS300 rain_name=rain israining_name=israining
2015.10.25 08:52:53 4: Attribut matchs TimeCode DayChangeTime='06:50'
2015.10.25 08:52:53 5: Triggering Dew_Bad (1 changes)
2015.10.25 08:52:53 5: Notify loop for Dew_Bad 11.3284314466642
2015.10.25 08:52:53 5: rain_notify: devname=Dew_Bad rainname=rain_KS300, dev=Dew_Bad, dev_regex=KS300 rain_name=rain israining_name=israining
2015.10.25 08:52:53 4: Attribut matchs TimeCode DayChangeTime='06:50'
2015.10.25 08:52:53 5: battStatus: not on any display, ignoring notify
2015.10.25 08:52:53 5: rg_Meldungen: not on any display, ignoring notify
2015.10.25 08:52:53 5: Triggering Hum_Bad (1 changes)
2015.10.25 08:52:53 5: Notify loop for Hum_Bad 52
2015.10.25 08:52:53 5: rain_notify: devname=Hum_Bad rainname=rain_KS300, dev=Hum_Bad, dev_regex=KS300 rain_name=rain israining_name=israining
2015.10.25 08:52:53 4: Attribut matchs TimeCode DayChangeTime='06:50'
2015.10.25 08:52:53 5: battStatus: not on any display, ignoring notify
2015.10.25 08:52:53 5: rg_Meldungen: not on any display, ignoring notify
2015.10.25 08:52:53 5: battStatus: not on any display, ignoring notify
2015.10.25 08:52:53 5: Triggering n_Batteriewarnung
2015.10.25 08:52:53 4: n_Batteriewarnung exec { if("battery: ok" !~ m/ok/) { fhem ('set Pushbullet message Batteriewarnung Sens_Bad battery: ok | Batteriewarnung Sens_Bad')}}
2015.10.25 08:52:53 5: Cmd: >{ if("battery: ok" !~ m/ok/) { fhem ('set Pushbullet message Batteriewarnung Sens_Bad battery: ok | Batteriewarnung Sens_Bad')}}<
2015.10.25 08:52:53 5: rg_Meldungen: not on any display, ignoring notify
2015.10.25 08:52:53 5: HMLAN/RAW: /E301926,0000,037E493F,FF,FFC0,1286103019260000000AA8E90D0900
2015.10.25 08:52:53 5: HMLAN_Parse: HMLAN1 R:E301926   stat:0000 t:037E493F d:FF r:FFC0     m:12 8610 301926 000000 0AA8E90D0900
2015.10.25 08:52:53 5: HMLAN1 dispatch A0F1286103019260000000AA8E90D0900::-64:HMLAN1
2015.10.25 08:52:53 4: CUL_HM Hzg_Schlafzimmer dupe: dont process
2015.10.25 08:52:53 5: HMLAN_Parse: HMLAN1 R:E2C7C23   stat:0000 t:037E4AFC d:FF r:FFBE     m:AC 8670 2C7C23 000000 00D834
2015.10.25 08:52:53 5: HMLAN1 dispatch A0CAC86702C7C2300000000D834::-66:HMLAN1
2015.10.25 08:52:53 4: CUL_HM Sens_Bad dupe: dont process
2015.10.25 08:52:53 5: HMLAN_Parse: HMLAN1 V:03C4 sNo:LEQ0403722 d:2AEDE4 O:ABCABC t:037E5AE7 IDcnt:002F L:4 %
2015.10.25 08:52:53 5: Triggering HMLAN1 (1 changes)
2015.10.25 08:52:53 5: Notify loop for HMLAN1 loadLvl: low
2015.10.25 08:52:53 5: rain_notify: devname=HMLAN1 rainname=rain_KS300, dev=HMLAN1, dev_regex=KS300 rain_name=rain israining_name=israining
2015.10.25 08:52:53 4: Attribut matchs TimeCode DayChangeTime='06:50'
2015.10.25 08:52:53 5: battStatus: not on any display, ignoring notify
2015.10.25 08:52:53 5: rg_Meldungen: not on any display, ignoring notify
2015.10.25 08:52:53 5: HMLAN/RAW: /HHM-LAN-IF,03C4,LEQ0579692,2BA02F,ABCABC,05175D4F,0024,05
2015.10.25 08:52:53 5: HMLAN_Parse: HMLAN2 V:03C4 sNo:LEQ0579692 d:2BA02F O:ABCABC t:05175D4F IDcnt:0024 L:5 %
2015.10.25 08:52:53 5: Triggering HMLAN2 (1 changes)
2015.10.25 08:52:53 5: Notify loop for HMLAN2 loadLvl: low
2015.10.25 08:52:53 5: rain_notify: devname=HMLAN2 rainname=rain_KS300, dev=HMLAN2, dev_regex=KS300 rain_name=rain israining_name=israining
2015.10.25 08:52:53 4: Attribut matchs TimeCode DayChangeTime='06:50'
2015.10.25 08:52:53 5: battStatus: not on any display, ignoring notify
2015.10.25 08:52:53 5: rg_Meldungen: not on any display, ignoring notify
2015.10.25 08:52:55 5: HMLAN/RAW: /E301934,0000,037E6412,FF,FFBB,C686103019340000000AB0F90D0000


Es ist doch richtig, sich das Log der Sekunde nach der "possible freeze"-Meldung anzuschauen? Ich finde da absolut nichts Hilfreiches/Auffälliges.

Danke, Christian
Titel: Antw:possible freeze minütlich für 6 Sekunden debuggen
Beitrag von: Motivierte linke Hände am 25 Oktober 2015, 09:54:25
Ok, kaum fragt man... 8)

Also, das Problem war offenbar, dass mein über LAN angebundener CUL "DISCONNECTED" war. Das produziert offenbar minütlich freezes von 6 Sekunden...