Hallo zusammen,
ich bin seit Tagen auf der Suche nach der Ursache für fhem-freezes, die bis auf Millisekunden Differenz in exaktem Minutenintervall auftreten.
Mein fhem läuft auf einem Intel NUC mit 8GB RAM und SSD unter Ubuntu LTS 16.04. Ich denke, Hardware Ressourcen Engpässe kann man weitestgehend ausschließen.
Apptime hat mir bisher noch keinen echten Hinweis geliefert, das kann aber an fehlerhafter Interpretation meinerseits liegen. Der apptime-output folgt am Ende des Beitrags.
Ein "list .* TYPE" liefert 754 devices mit allen Geräten, notifies usw.
AV_Receiver YAMAHA_AVR
ActionDetector CUL_HM
Activity_chk notify
AlarmStatus CUL_HM
Alarmanlage dummy
Alarmanlage_Motion dummy
Alarmsirene dummy
AlleFenster structure
AlleTueren structure
Allergie allergy
Altpapier_dummy dummy
AutoCancel dummy
AutoHeizung at
BS_SW_01 IT
BS_SW_02 IT
BS_SW_03 IT
Bewegungsmelder structure
Bozena_Laptop fronthemDevice
CUL433 CUL
Call_Notify notify
DOIF_FensterOffenMsg DOIF
DS SSCam
Desktop fronthemDevice
FB FB_CALLMONITOR
FBCallList FB_CALLLIST
FBLog dummy
Feiertage_NDS holiday
FileLog_ActionDetector FileLog
FileLog_AlarmStatus FileLog
FileLog_Alarmanlage FileLog
FileLog_Alarmanlage_Motion FileLog
FileLog_Alarmsirene FileLog
FileLog_BadLuefter FileLog
FileLog_FBLog FileLog
FileLog_HG_AZ_HZ FileLog
FileLog_HG_AZ_TH_01 FileLog
FileLog_HG_BM_1 FileLog
FileLog_HG_BM_Bad FileLog
FileLog_HG_BM_Einfahrt FileLog
FileLog_HG_BM_IT_01 FileLog
FileLog_HG_BM_WK FileLog
FileLog_HG_BZ_Fenster FileLog
FileLog_HG_BZ_HZ FileLog
FileLog_HG_BZ_HZ_WT FileLog
FileLog_HG_BZ_HZ_WT_Climate FileLog
FileLog_HG_BZ_HZ_WT_Weather FileLog
FileLog_HG_Display FileLog
FileLog_HG_FL_Muell FileLog
FileLog_HG_GWC_Fenster FileLog
FileLog_HG_GWC_HZ FileLog
FileLog_HG_IT_SW_01 FileLog
FileLog_HG_IT_SW_02 FileLog
FileLog_HG_IT_SW_03 FileLog
FileLog_HG_KE_Gasmelder FileLog
FileLog_HG_KE_Tuer FileLog
FileLog_HG_KE_TuerRiegel FileLog
FileLog_HG_KE_UP_SW_2 FileLog
FileLog_HG_KE_UP_SW_3 FileLog
FileLog_HG_KE_WC_Fenster FileLog
FileLog_HG_KT_TH_01 FileLog
FileLog_HG_KU_DunstabzugsHaube FileLog
FileLog_HG_KU_Fenster FileLog
FileLog_HG_KU_HZ FileLog
FileLog_HG_KU_TH_01 FileLog
FileLog_HG_MP3_Mobil FileLog
FileLog_HG_SS_TR FileLog
FileLog_HG_SZ_Fenster FileLog
FileLog_HG_SZ_Fenster_alt FileLog
FileLog_HG_SZ_HZ FileLog
FileLog_HG_SZ_RL_Fenster FileLog
FileLog_HG_TH_BM FileLog
FileLog_HG_TH_Klingel FileLog
FileLog_HG_TH_TH_01 FileLog
FileLog_HG_TR_SW FileLog
FileLog_HG_TR_TH_01 FileLog
FileLog_HG_TR_WT FileLog
FileLog_HG_WK_Fenster FileLog
FileLog_HG_WK_TH_01 FileLog
FileLog_HG_WZ_Fenster FileLog
FileLog_HG_WZ_Fenster_neu FileLog
FileLog_HG_WZ_HS_RL FileLog
FileLog_HG_WZ_HZ FileLog
FileLog_HG_WZ_HZ_WT FileLog
FileLog_HG_WZ_HZ_WT_Climate FileLog
FileLog_HG_WZ_RL_Fenster FileLog
FileLog_HG_WZ_RL_Tuer FileLog
FileLog_HG_WZ_TTuer FileLog
FileLog_HM_4423F3 FileLog
FileLog_HM_568966 FileLog
FileLog_HandsenderAlarm FileLog
FileLog_Heizung FileLog
FileLog_IT_00F000FFFF FileLog
FileLog_IT_0F0F0FFF0F FileLog
FileLog_IT_0F0F0FFFFF FileLog
FileLog_Motion FileLog
FileLog_NG_BZ_Fenster FileLog
FileLog_NG_BZ_HZ FileLog
FileLog_NG_BZ_HZ_Clima FileLog
FileLog_NG_BZ_HZ_ClimaTeam FileLog
FileLog_NG_BZ_HZ_Climate FileLog
FileLog_NG_BZ_HZ_Weather FileLog
FileLog_NG_BZ_HZ_WindowRec FileLog
FileLog_NG_BZ_HZ_remote FileLog
FileLog_NG_CP_TH_01 FileLog
FileLog_NG_MK_01 FileLog
FileLog_NG_MK_SW_01 FileLog
FileLog_NG_SZ_Fenster FileLog
FileLog_NG_VR_TH_01 FileLog
FileLog_NG_WZ_Fenster FileLog
FileLog_NG_WZ_SW_AQ FileLog
FileLog_PWR_SW_1 FileLog
FileLog_PWR_SW_1_Pwr FileLog
FileLog_PWR_SW_2 FileLog
FileLog_Presence FileLog
FileLog_Sirene FileLog
FileLog_Status_Alarmanlage FileLog
FileLog_Technik_IO FileLog
FileLog_TempSens1 FileLog
FileLog_TempSens2 FileLog
FileLog_myTwilight FileLog
FileLog_sysmon FileLog
Foscam SSCam
GelberSack_dummy dummy
Gruenschnitt_dummy dummy
HG_AZ_Fenster_rechts HMCCUDEV
HG_AZ_HZ CUL_HM
HG_AZ_HZ_Clima CUL_HM
HG_AZ_HZ_ClimaTeam CUL_HM
HG_AZ_HZ_Climate CUL_HM
HG_AZ_HZ_Weather CUL_HM
HG_AZ_HZ_WindowRec CUL_HM
HG_AZ_HZ_remote CUL_HM
HG_AZ_TH_01 LaCrosse
HG_BM_1 CUL_HM
HG_BM_Bad CUL_HM
HG_BM_Einfahrt CUL_HM
HG_BM_IT_01 IT
HG_BM_WK CUL_HM
HG_BZ_Fenster CUL_HM
HG_BZ_HZ CUL_HM
HG_BZ_HZ_Clima CUL_HM
HG_BZ_HZ_ClimaTeam CUL_HM
HG_BZ_HZ_Climate CUL_HM
HG_BZ_HZ_WT CUL_HM
HG_BZ_HZ_WT_Climate CUL_HM
HG_BZ_HZ_WT_SwitchTr CUL_HM
HG_BZ_HZ_WT_Weather CUL_HM
HG_BZ_HZ_WT_WindowRec CUL_HM
HG_BZ_HZ_WT_remote CUL_HM
HG_BZ_HZ_Weather CUL_HM
HG_BZ_HZ_WindowRec CUL_HM
HG_BZ_HZ_remote CUL_HM
HG_Display CUL_HM
HG_Display_01 CUL_HM
HG_Display_02 CUL_HM
HG_Display_03 CUL_HM
HG_Display_04 CUL_HM
HG_Display_05 CUL_HM
HG_Display_06 CUL_HM
HG_Display_07 CUL_HM
HG_Display_08 CUL_HM
HG_Display_09 CUL_HM
HG_Display_10 CUL_HM
HG_FL_Muell CUL_HM
HG_FL_Muell_Sw_01 CUL_HM
HG_FL_Muell_Sw_02 CUL_HM
HG_FL_Muell_Sw_03 CUL_HM
HG_FL_Muell_Sw_04 CUL_HM
HG_FL_Muell_Sw_05 CUL_HM
HG_FL_Muell_Sw_06 CUL_HM
HG_FL_Muell_Sw_07 CUL_HM
HG_FL_Muell_Sw_08 CUL_HM
HG_GWC_Fenster CUL_HM
HG_GWC_HZ CUL_HM
HG_GWC_HZ_Clima CUL_HM
HG_GWC_HZ_ClimaTeam CUL_HM
HG_GWC_HZ_Climate CUL_HM
HG_GWC_HZ_Weather CUL_HM
HG_GWC_HZ_WindowRec CUL_HM
HG_GWC_HZ_remote CUL_HM
HG_IT_SW_01 IT
HG_IT_SW_02 IT
HG_IT_SW_03 IT
HG_KE_Gasmelder CUL_HM
HG_KE_Tuer CUL_HM
HG_KE_TuerRiegel CUL_HM
HG_KE_UP_SW_2 CUL_HM
HG_KE_UP_SW_2_1 CUL_HM
HG_KE_UP_SW_2_2 CUL_HM
HG_KE_UP_SW_3 CUL_HM
HG_KE_UP_SW_3_Sw_01 CUL_HM
HG_KE_UP_SW_3_Sw_02 CUL_HM
HG_KE_WC_Fenster CUL_HM
HG_KE_Wassersensor HMCCUDEV
HG_KT_TH_01 LaCrosse
HG_KU_DunstabzugsHaube CUL_HM
HG_KU_Fenster CUL_HM
HG_KU_HZ CUL_HM
HG_KU_HZ_Clima CUL_HM
HG_KU_HZ_ClimaTeam CUL_HM
HG_KU_HZ_Climate CUL_HM
HG_KU_HZ_Weather CUL_HM
HG_KU_HZ_WindowRec CUL_HM
HG_KU_HZ_remote CUL_HM
HG_KU_TH_01 LaCrosse
HG_MP3_Mobil CUL_HM
HG_MP3_Mobil_Led CUL_HM
HG_MP3_Mobil_Mp3 CUL_HM
HG_SS_TR CUL_HM
HG_SZ_Fenster CUL_HM
HG_SZ_Fenster_alt CUL_HM
HG_SZ_HZ CUL_HM
HG_SZ_HZ_Clima CUL_HM
HG_SZ_HZ_ClimaTeam CUL_HM
HG_SZ_HZ_Climate CUL_HM
HG_SZ_HZ_Weather CUL_HM
HG_SZ_HZ_WindowRec CUL_HM
HG_SZ_HZ_remote CUL_HM
HG_SZ_RL_Fenster CUL_HM
HG_TH_BM CUL_HM
HG_TH_BM_Btn_01 CUL_HM
HG_TH_BM_Btn_02 CUL_HM
HG_TH_BM_Motion CUL_HM
HG_TH_Klingel CUL_HM
HG_TH_TH_01 LaCrosse
HG_TR_SW CUL_HM
HG_TR_TH_01 LaCrosse
HG_TR_WT CUL_HM
HG_TR_WT_Btn_01 CUL_HM
HG_TR_WT_Btn_02 CUL_HM
HG_WK_Fenster CUL_HM
HG_WK_TH_01 LaCrosse
HG_WZ_Fenster CUL_HM
HG_WZ_HS_RL CUL_HM
HG_WZ_HS_RL_Btn_01 CUL_HM
HG_WZ_HS_RL_Btn_02 CUL_HM
HG_WZ_HS_RL_Btn_03 CUL_HM
HG_WZ_HS_RL_Btn_04 CUL_HM
HG_WZ_HZ CUL_HM
HG_WZ_HZ_Clima CUL_HM
HG_WZ_HZ_ClimaTeam CUL_HM
HG_WZ_HZ_Climate CUL_HM
HG_WZ_HZ_WT CUL_HM
HG_WZ_HZ_WT_Climate CUL_HM
HG_WZ_HZ_WT_SwitchTr CUL_HM
HG_WZ_HZ_WT_Weather CUL_HM
HG_WZ_HZ_WT_WindowRec CUL_HM
HG_WZ_HZ_WT_remote CUL_HM
HG_WZ_HZ_Weather CUL_HM
HG_WZ_HZ_WindowRec CUL_HM
HG_WZ_HZ_remote CUL_HM
HG_WZ_Hue HUEBridge
HG_WZ_Hue_HUEDevice1 HUEDevice
HG_WZ_Hue_HUEDevice13 HUEDevice
HG_WZ_Hue_HUEDevice2 HUEDevice
HG_WZ_Hue_HUEDevice3 HUEDevice
HG_WZ_Hue_HUEGroup0 HUEDevice
HG_WZ_RL_Fenster CUL_HM
HG_WZ_RL_Tuer CUL_HM
HG_WZ_TTuer CUL_HM
HM HMinfo
HUEDevice10 HUEDevice
HUEDevice11 HUEDevice
HUEDevice12 HUEDevice
HUEDevice14 HUEDevice
HUEDevice5 HUEDevice
HUEDevice6 HUEDevice
HUEDevice7 HUEDevice
HUEDevice8 HUEDevice
HUEDevice9 HUEDevice
HUEGroup1 HUEDevice
HUEGroup10 HUEDevice
HUEGroup11 HUEDevice
HUEGroup12 HUEDevice
HUEGroup13 HUEDevice
HUEGroup14 HUEDevice
HUEGroup2 HUEDevice
HUEGroup3 HUEDevice
HUEGroup4 HUEDevice
HUEGroup5 HUEDevice
HUEGroup7 HUEDevice
HUEGroup8 HUEDevice
HUEGroup9 HUEDevice
HV fronthemDevice
HandsenderAlarm CUL_HM
HandsenderAlarm_armExt CUL_HM
HandsenderAlarm_armInt CUL_HM
HandsenderAlarm_disarm CUL_HM
HandsenderAlarm_light CUL_HM
Handy_VPN fronthemDevice
HarmonyHub1 harmony
Heizungswerte readingsGroup
Hikvision SSCam
HmUART1 HMUARTLGW
HmUART2 HMUARTLGW
HmUART3 HMUARTLGW
Kalender Calendar
Laptop fronthemDevice
LaptopRemote fronthemDevice
Logfile FileLog
LuefterDummy dummy
Luftfeuchte readingsGroup
ModBusLine Modbus
MuellabfuhrGroupDummy dummy
MyWeatherWeblink weblink
N308 fronthemDevice
NG_BZ_Fenster CUL_HM
NG_BZ_HZ CUL_HM
NG_BZ_HZ_Clima CUL_HM
NG_BZ_HZ_ClimaTeam CUL_HM
NG_BZ_HZ_Climate CUL_HM
NG_BZ_HZ_Weather CUL_HM
NG_BZ_HZ_WindowRec CUL_HM
NG_BZ_HZ_remote CUL_HM
NG_CP_TH_01 LaCrosse
NG_HZ_BZ_SliderDummy dummy
NG_MK_01 CUL_HM
NG_MK_SW_01 CUL_HM
NG_MK_SW_01_Btn_01 CUL_HM
NG_MK_SW_01_Btn_02 CUL_HM
NG_MK_SW_01_Btn_03 CUL_HM
NG_MK_SW_01_Btn_04 CUL_HM
NG_SZ_Fenster CUL_HM
NG_VR_TH_01 LaCrosse
NG_WZ_Fenster CUL_HM
NG_WZ_SW_AQ CUL_HM
PWR_SW_1 CUL_HM
PWR_SW_1_Pwr CUL_HM
PWR_SW_1_SenF CUL_HM
PWR_SW_1_SenI CUL_HM
PWR_SW_1_SenPwr CUL_HM
PWR_SW_1_SenU CUL_HM
PWR_SW_1_Sw CUL_HM
PWR_SW_2 CUL_HM
PWR_SW_2_Pwr CUL_HM
PWR_SW_2_SenF CUL_HM
PWR_SW_2_SenI CUL_HM
PWR_SW_2_SenPwr CUL_HM
PWR_SW_2_SenU CUL_HM
PWR_SW_2_Sw CUL_HM
Pollenflug HTTPMOD
RSSI_Chart dummy
RSSI_ClearAllRSSIValues notify
RSSI_Save_old_values notify
RSSI_SetUpAverage dummy
RSSI_SetUpAverageSaveOldValues dummy
RSSI_SetUpBestCol dummy
RSSI_SetUpClearRSSIValues dummy
RSSI_SetUpColorSchemeDark dummy
RSSI_SetUpHighlight dummy
RSSI_SetUpInternals dummy
RSSI_SetUpLastActive dummy
RSSI_SetUpShowOldValues dummy
Restmuell_dummy dummy
SSCam.cam4.snapgallery weblink
SSCamSTRM.Hikvision.snapgallery SSCamSTRM
SSCamSTRM.cam4.snapgallery SSCamSTRM
SVG_FHT_fbbf SVG
SVG_FileLog_HG_AZ_HZ_1 SVG
SVG_FileLog_HG_AZ_TH_01_1 SVG
SVG_FileLog_HG_BM_1_1 SVG
SVG_FileLog_HG_BM_Bad_1 SVG
SVG_FileLog_HG_BM_IT_01_1 SVG
SVG_FileLog_HG_BM_WK_1 SVG
SVG_FileLog_HG_BZ_HZ_2 SVG
SVG_FileLog_HG_BZ_HZ_WT_Climate_1 SVG
SVG_FileLog_HG_KT_TH_01_1 SVG
SVG_FileLog_HG_KU_HZ_1 SVG
SVG_FileLog_HG_KU_TH_01_1 SVG
SVG_FileLog_HG_TH_TH_01_1 SVG
SVG_FileLog_HG_TR_TH_01_2 SVG
SVG_FileLog_HG_WK_TH_01_1 SVG
SVG_FileLog_HG_WZ_HZ_1 SVG
SVG_FileLog_Heizung_1 SVG
SVG_FileLog_Motion_1 SVG
SVG_FileLog_NG_BZ_HZ_1 SVG
SVG_FileLog_NG_VR_TH_01_1 SVG
SVG_FileLog_Technik_IO_1 SVG
SVG_KS300 SVG
SVG_KS300_2 SVG
SVG_WZ_HZ_Log_2 SVG
SVG_myDbLog_1 SVG
SVG_myDbLog_2 SVG
SVG_myDbLog_3 SVG
SVG_sunDummyLog_1 SVG
Sirene CUL_HM
Sonnenaufgang at
Sonnenaufgang_Indoor dummy
Sonnenaufgang_Twilight dummy
Sonnenuntergang at
Sonnenuntergang_Indoor dummy
Sonnenuntergang_Twilight dummy
Status_Alarmanlage dummy
SysValues weblink
TABLETUI HTTPSRV
TFClose.warn dummy
TFOpen.check dummy
TFOpen.warn dummy
Tab fronthemDevice
TagTemp at
Telegram.Alarm dummy
TempSens1 CUL_HM
TempSens1_Event CUL_HM
TempSens1_T1 CUL_HM
TempSens1_T1_T2 CUL_HM
TempSens1_T2 CUL_HM
TempSens1_T2_T1 CUL_HM
TempSens2 CUL_HM
TempSens2_Event CUL_HM
TempSens2_T1 CUL_HM
TempSens2_T1_T2 CUL_HM
TempSens2_T2 CUL_HM
TempSens2_T2_T1 CUL_HM
Termin_Alarm notify
Termin_Ende notify
Termin_Loeschen notify
Termin_Start notify
Test dummy
UnifiController Unifi
Urlaub_dummy dummy
VCCU CUL_HM
VU ENIGMA2
VUDUO ENIGMA2
VURG readingsGroup
WEB FHEMWEB
WEB_127.0.0.1_51218 FHEMWEB
WEB_88.128.80.24_59564 FHEMWEB
WEB_88.128.80.24_59949 FHEMWEB
WEB_88.128.80.24_59951 FHEMWEB
WEBhabridge FHEMWEB
WEBhook FHEMWEB
WEBphone FHEMWEB
WEBtablet FHEMWEB
WZ_HZ_Log FileLog
Wetter_ weblink
Wetter_Hameln Weather
Wetter_Proplanta PROPLANTA
_SmartVisuHandy fronthemDevice
a_AlarmOn at
a_LuefterWZNord at
a_hmlan_internals at
a_muell at
alarm0.arm.N notify
alarm0.disarm.N notify
alarm0.off.N notify
alarm0.on.N notify
alarm1.off.N notify
alarm1.on.N notify
alarm2.arm.N notify
alarm2.disarm.N notify
alarm2.off.N notify
alarm2.on.N notify
alarm3.arm.N notify
alarm3.disarm.N notify
alarm3.off.N notify
alarm3.on.N notify
alarm4.off.N notify
alarm6.off.N notify
alarm6.on.N notify
alarm7.off.N notify
alarm7.on.N notify
alexaFHEMlog FileLog
allowedWEBhook allowed
allowed_WEB allowed
allowed_WEBphone allowed
allowed_WEBtablet allowed
autocreate autocreate
battStatus readingsGroup
cam1 IPCAM
cam2 IPCAM
cam4 SSCam
d_Abwesend dummy
d_AlarmStatus dummy
d_Alarmswitch0 dummy
d_Alarmswitch1 dummy
d_Alarmswitch2 dummy
d_Alarmswitch3 dummy
d_Alarmswitch4 dummy
d_Alarmswitch5 dummy
d_Alarmswitch6 dummy
d_Alarmswitch7 dummy
d_AlexaLichtHell dummy
d_AlexaMusik dummy
d_AlexaRolloFenster dummy
d_AlexaRolloStop dummy
d_AlexaRolloTuer dummy
d_AlexaTVLicht dummy
d_AnsageDelay dummy
d_AutoHeizung dummy
d_AutoHeizungTimestamp dummy
d_AutoTrack dummy
d_Bewegung dummy
d_FHEM.Alexa dummy
d_FHEM.Alexa.Status dummy
d_Fernsehen dummy
d_FrostiAlarmTriggered dummy
d_FrostiWarningTriggered dummy
d_Motion_AZ dummy
d_Motion_BZ dummy
d_Motion_IT dummy
d_Motion_TH dummy
d_Motion_TR dummy
d_Motion_WK dummy
d_OnOff dummy
d_Pollen dummy
d_PresenceSimErlaubt dummy
d_ShockTS dummy
d_TTuerRollo dummy
d_TV dummy
d_TVOnOff dummy
d_TVTime dummy
d_WMHighPower dummy
d_WMPower dummy
d_WMRunning dummy
d_WZHeizung dummy
d_Weihnachtslicht dummy
d_muell dummy
d_rpcBidCos_RF HMCCURPCPROC
d_rpcHmIP_RF HMCCURPCPROC
d_slider dummy
dbRep.TempAussen DbRep
di_AquaLicht DOIF
di_Aussenbeleuchtung DOIF
di_AutoHeizung DOIF
di_BadLicht DOIF
di_BadLuefter DOIF
di_FHEM.Alexa DOIF
di_KellerAlarm DOIF
di_KellerLicht DOIF
di_KellerTuerOffenMsg DOIF
di_KellerlichtTK DOIF
di_Klingel DOIF
di_LuefterKellertreppe DOIF
di_PresenceBozena DOIF
di_PresenceRoland DOIF
di_Rolladen_Hoch DOIF
di_Rolladen_Runter DOIF
di_Test DOIF
di_Weihnachtslicht DOIF
di_WinOpnAlarm DOIF
di_Zirkulation DOIF
dp_HG_BZ dewpoint
dp_HG_WZ dewpoint
dummy_Fenster dummy
dummy_Tuer dummy
eq3 HTTPMOD
eventTypes eventTypes
freezemon_log FileLog
fronthem fronthem
geofancy GEOFANCY
global Global
harmony:discovery harmony
harmony_46077683 harmony
harmony_46077684 harmony
harmony_46077686 harmony
harmony_46077687 harmony
harmony_46077688 harmony
harmony_59602135 harmony
heatingInfo readingsGroup
homelog FileLog
initialUsbCheck notify
ipcam weblink
ipcam2 weblink
ls_Alert LightScene
mqttGeneric MQTT_GENERIC_BRIDGE
myAbfall ABFALL
myAlarm Alarm
myAlarm_weblink weblink
myAlexa alexa
myAstro Astro
myCalView CALVIEW
myDbLog DbLog
myDbRep DbRep
myFreezemon freezemon
myHMCCU HMCCU
myJeeLink JeeLink
myMQTT MQTT
myTeleBot TelegramBot
myTwilight Twilight
myView CALVIEW
n_AVReceiver notify
n_AbsenceSim notify
n_AbsentAlarmOff notify
n_AbsentAlarmOn notify
n_AlarmBM_off notify
n_AlarmBM_on notify
n_AlarmCheck notify
n_AlarmFull_off notify
n_AlarmFull_on notify
n_AlarmOff notify
n_AlarmOn notify
n_AlarmStateChange notify
n_AlarmSwitch notify
n_Alarm_Motion_on_per_HS notify
n_Alarm_Statussignal notify
n_Alarm_off_per_HS notify
n_Alarm_on notify
n_Alarm_on_per_HS notify
n_Alarmswitch0 notify
n_Alarmswitch1 notify
n_Alarmswitch2 notify
n_Alarmswitch3 notify
n_Alarmswitch4 notify
n_Alarmswitch5 notify
n_Alarmswitch6 notify
n_Alarmswitch7 notify
n_AlexaFernsehen notify
n_AlexaLichtHell notify
n_AlexaMusik notify
n_AlexaRolloFenster notify
n_AlexaRolloStop notify
n_AlexaRolloTuer notify
n_AlexaTVLicht notify
n_AlleWeg notify
n_AutoHeizung notify
n_AutotrackingOnOff notify
n_BTCheck notify
n_BewegungAnbau notify
n_CarportSnapTelegram notify
n_EnergyBackup notify
n_FoscamOff notify
n_GasAlarm notify
n_GefrierschrankAlarm notify
n_HS_FeRolloDownL notify
n_HS_FeRolloDownLR notify
n_HS_FeRolloDownS notify
n_HS_FeRolloUpL notify
n_HS_FeRolloUpLR notify
n_HS_FeRolloUpS notify
n_HS_TuerRolloDownL notify
n_HS_TuerRolloDownLR notify
n_HS_TuerRolloDownS notify
n_HS_TuerRolloUpL notify
n_HS_TuerRolloUpLR notify
n_HS_TuerRolloUpS notify
n_HandyPresence notify
n_KellerLicht notify
n_KlingelVideo notify
n_MotionEinfahrt notify
n_MotionGarten notify
n_MotionTS notify
n_MotionTerrasse notify
n_Motion_Message notify
n_Muell notify
n_NG_HZ_BZ_SliderNotify notify
n_PWR_Switch notify
n_Presence notify
n_PresenceSim notify
n_RolloHarmony notify
n_RolloHoch notify
n_RolloRunter notify
n_SeqTest notify
n_ShockSensor notify
n_ShockSensor_Cam notify
n_Sirene_off notify
n_TVLicht notify
n_TVOff notify
n_TVOn notify
n_TerrasseSnapTelegram notify
n_Terrassentuer notify
n_Twilight notify
n_ViewAll notify
n_WMFinished notify
n_WMHighPowerOff notify
n_WMHighPowerOn notify
n_WMPowerSet notify
n_WMRunningOn notify
n_WTTimeSet notify
n_WasserAlarm notify
n_Weihnachtslicht notify
n_WindowOpenMsg notify
n_armExt_l notify
n_armExt_s notify
n_armInt_l notify
n_armInt_s notify
n_batt_chk notify
n_disarm_l notify
n_disarm_s notify
n_light_l notify
n_light_s notify
n_myAlarm notify
n_reboot notify
n_rr_Bozena.location notify
n_rr_Roland.location notify
n_setAlarmState notify
n_winClose notify
n_winOpen notify
nanoCUL CUL
notify_hm_display notify
presenceUC_Bozena_S8_2 PRESENCE
presenceUC_Maya_iPad PRESENCE
presenceUC_Maya_iPhone PRESENCE
presenceUC_Roland_S8 PRESENCE
pushmsg Pushover
res_FamZerche RESIDENTS
rg_AnnaG GUEST
rg_Bewohner readingsGroup
rg_Cams readingsGroup
rg_Klima readingsGroup
rg_Lee GUEST
rg_Maya GUEST
rg_Schalter readingsGroup
rg_View_Abfall readingsGroup
rg_battery readingsGroup
rg_batteryLevel readingsGroup
rg_motion readingsGroup
rr_Bozena ROOMMATE
rr_Roland ROOMMATE
rr_VU ROOMMATE
rssi_read_from_device notify
rt_AbsenceSim RandomTimer
s_AbsentAlarm sequence
s_AbsentAlarmOff sequence
s_Bewegung structure
s_ShockSensor sequence
s_Test3 sequence
s_Weihnachtslicht structure
sunDummy dummy
sunDummyLog FileLog
sunMarker at
sysmon SYSMON
systemCommands weblink
telnetPort telnet
telnetPort_192.168.1.223_48030 telnet
telnetPort_192.168.1.223_48032 telnet
userCfg notify
v_ArmExt CUL_HM
v_ArmInt CUL_HM
v_armExt_l dummy
v_armExt_s dummy
v_armInt_l dummy
v_armInt_s dummy
v_disarm CUL_HM
v_disarm_l dummy
v_disarm_s dummy
v_light CUL_HM
v_light_l dummy
v_light_s dummy
wd_AlarmAnzeigeOff watchdog
wd_AlarmAnzeigeOn watchdog
wd_AlarmOn watchdog
wd_AlarmTest watchdog
wd_Foscam watchdog
wd_HG_BM_1.MotionDetect watchdog
wd_HG_WK_BM watchdog
wd_HG_WZ_Stehlampe watchdog
wd_JeeLinkDown watchdog
wd_LuefterKellertreppe watchdog
wd_NG_BM_Motion watchdog
wd_WMAutoStandby watchdog
window_close_check notify
window_open_check notify
wl_sysmon_cpustatT SVG
wl_sysmon_temp SVG
Ich habe mit perfmon/freezemon und "global verbose 5" gearbeitet. Im Log habe ich dann gesehen, daß im fraglichen Zeitraum ("starting at ..." minus "delay") immer das Modul YAMAHA_AVR und zwei ENIGMA2-devices tätig waren.
Ich habe daraufhin die devices disabled, die freezes bleiben aber. Die Pingzeiten vom fhem-NUC zum AV-Reveiver bzw. den beiden VU+-Enigma Boxen liegen im Schnitt bei 0.3ms, auch während des freeze. Meiner Meinung nach
sind die drei devices unschuldig.
Hier ein grep-gefilterter perfmon-Logausschnitt von gestern, der das regelmäßige Intervall verdeutlicht:
2019.01.17 14:14:23.454 1: Perfmon: possible freeze starting at 14:14:20, delay is 3.454
2019.01.17 14:15:23.119 1: Perfmon: possible freeze starting at 14:15:20, delay is 3.119
2019.01.17 14:16:23.005 1: Perfmon: possible freeze starting at 14:16:20, delay is 3.005
2019.01.17 14:17:23.064 1: Perfmon: possible freeze starting at 14:17:20, delay is 3.064
2019.01.17 14:18:23.382 1: Perfmon: possible freeze starting at 14:18:21, delay is 2.381
2019.01.17 14:19:23.260 1: Perfmon: possible freeze starting at 14:19:20, delay is 3.26
2019.01.17 14:20:24.139 1: Perfmon: possible freeze starting at 14:20:21, delay is 3.139
2019.01.17 14:21:23.481 1: Perfmon: possible freeze starting at 14:21:21, delay is 2.481
2019.01.17 14:21:50.108 1: Perfmon: possible freeze starting at 14:21:49, delay is 1.108
2019.01.17 14:22:23.616 1: Perfmon: possible freeze starting at 14:22:21, delay is 2.616
2019.01.17 14:23:23.220 1: Perfmon: possible freeze starting at 14:23:21, delay is 2.219
2019.01.17 14:24:23.143 1: Perfmon: possible freeze starting at 14:24:21, delay is 2.143
2019.01.17 14:25:23.188 1: Perfmon: possible freeze starting at 14:25:21, delay is 2.188
2019.01.17 14:26:23.147 1: Perfmon: possible freeze starting at 14:26:20, delay is 3.147
2019.01.17 14:27:23.164 1: Perfmon: possible freeze starting at 14:27:21, delay is 2.164
2019.01.17 14:28:23.282 1: Perfmon: possible freeze starting at 14:28:21, delay is 2.281
2019.01.17 14:29:23.095 1: Perfmon: possible freeze starting at 14:29:21, delay is 2.095
2019.01.17 14:30:23.173 1: Perfmon: possible freeze starting at 14:30:21, delay is 2.173
2019.01.17 14:31:23.105 1: Perfmon: possible freeze starting at 14:31:20, delay is 3.105
2019.01.17 14:32:23.253 1: Perfmon: possible freeze starting at 14:32:21, delay is 2.253
2019.01.17 14:33:23.336 1: Perfmon: possible freeze starting at 14:33:21, delay is 2.336
2019.01.17 14:34:23.229 1: Perfmon: possible freeze starting at 14:34:21, delay is 2.229
2019.01.17 14:35:23.304 1: Perfmon: possible freeze starting at 14:35:21, delay is 2.304
2019.01.17 14:36:23.293 1: Perfmon: possible freeze starting at 14:36:20, delay is 3.293
2019.01.17 14:37:23.704 1: Perfmon: possible freeze starting at 14:37:21, delay is 2.704
2019.01.17 14:38:23.212 1: Perfmon: possible freeze starting at 14:38:21, delay is 2.211
2019.01.17 14:39:23.025 1: Perfmon: possible freeze starting at 14:39:20, delay is 3.025
2019.01.17 14:40:23.046 1: Perfmon: possible freeze starting at 14:40:20, delay is 3.046
2019.01.17 14:41:23.098 1: Perfmon: possible freeze starting at 14:41:20, delay is 3.098
2019.01.17 14:42:23.624 1: Perfmon: possible freeze starting at 14:42:21, delay is 2.624
2019.01.17 14:43:23.428 1: Perfmon: possible freeze starting at 14:43:21, delay is 2.427
2019.01.17 14:44:23.188 1: Perfmon: possible freeze starting at 14:44:21, delay is 2.187
Korrespondierend dazu sehe ich mit htop auf dem fhem-NUC exakt im Zeittakt, kurz bevor freezemon den Logeintrag schreibt, daß der fhem-Prozess einen CPU-Kern für die (geschätzte) Freeze-Dauer auf 100% zieht.
Gestern habe ich noch Hinweise gefunden, daß man im freezemon die Attribute "fm_CatchCmds=1" und "fm_CatchFnCalls=1" setzen kann. Damit wird freezemon gesprächiger und liefert einen potentiellen Schuldigen.
2019.01.18 09:33:07.711 1: [Freezemon] myFreezemon: Long function call detected ReadFn:telnetPort_127.0.0.1_52722 - 3.426169 seconds
2019.01.18 09:33:07.712 1: [Freezemon] myFreezemon: possible freeze starting at 09:33:05, delay is 2.712 possibly caused by: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_52722)
2019.01.18 09:33:11.236 1: [Freezemon] myFreezemon: Long function call detected ReadFn:HmUART1 - 0.628369 seconds
2019.01.18 09:33:12.264 3: CUL_HM set AlarmStatus statusRequest
2019.01.18 09:33:18.035 1: [Freezemon] myFreezemon: Long function call detected ReadFn:HmUART2 - 0.647303 seconds
2019.01.18 09:33:22.588 3: CUL_HM set HG_KE_UP_SW_2_1 statusRequest
2019.01.18 09:33:36.370 3: CUL_HM set HG_KE_UP_SW_2_2 statusRequest
2019.01.18 09:33:39.494 3: CUL_HM set NG_MK_01 statusRequest
2019.01.18 09:34:07.580 1: [Freezemon] myFreezemon: Long running Command detected jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector:telnetPort - 3.30997 seconds
2019.01.18 09:34:07.657 1: [Freezemon] myFreezemon: Long function call detected ReadFn:telnetPort_127.0.0.1_52854 - 3.386588 seconds
2019.01.18 09:34:07.660 1: [Freezemon] myFreezemon: possible freeze starting at 09:34:05, delay is 2.659 possibly caused by: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_52854) tmr-SSCam_getstreamformat(Foscam) tmr-SSCam_getsvsinfo(Foscam) tmr-SSCam_getsnapinfo(N/A)
2019.01.18 09:34:39.961 1: [Freezemon] myFreezemon: Long function call detected ReadFn:HmUART2 - 0.628803 seconds
2019.01.18 09:34:57.377 1: [Freezemon] myFreezemon: Long function call detected ReadFn:HmUART1 - 0.635772 seconds
2019.01.18 09:35:04.263 1: [Freezemon] myFreezemon: Long function call detected ReadFn:HmUART1 - 0.642917 seconds
2019.01.18 09:35:08.127 1: [Freezemon] myFreezemon: Long running Command detected jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector:telnetPort - 3.317705 seconds
2019.01.18 09:35:08.203 1: [Freezemon] myFreezemon: Long function call detected ReadFn:telnetPort_127.0.0.1_52982 - 3.393922 seconds
2019.01.18 09:35:08.204 1: [Freezemon] myFreezemon: possible freeze starting at 09:35:05, delay is 3.204 possibly caused by: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_52982)
2019.01.18 09:35:15.747 1: [Freezemon] myFreezemon: Long function call detected ReadFn:HmUART2 - 0.635553 seconds
Hier bin ich jetzt mit meinem Latein am Ende. Kann mir bitte jemand bei der Interpretation helfen, was fhem mit telnet auf localhost mit hochzählenden Ports macht - und scheinbar immer steckenbleibt?
Ich weiß leider nicht mal sicher, seit wann das auftritt. Mir ist schon seit einiger Zeit aufgefallen, daß einige Geräte (Licht, Rollos...) sporadisch verzögert oder im schlimmsten Fall gar nicht schalten.
Gezielt bin ich jetzt seit einigen Tagen mit [perfmon|freezemon]/apptime/global verbose 5 hinterher, weil das Verhalten stört und auch den WAF drückt.
Was kann ich tun, um die Hänger abzustellen? Hat jemand Tips, wo ich nochmal genauer hinschauen kann/muß?
list ActionDetector:
Internals:
CHANGED
DEF 000000
IODev
NAME ActionDetector
NOTIFYDEV global
NR 160
NTFY_ORDER 50-ActionDetector
STATE alive:31 dead:0 unkn:0 off:0
TYPE CUL_HM
READINGS:
2019-01-18 09:31:32 state alive:31 dead:0 unkn:0 off:0
2019-01-18 09:31:32 status_HG_AZ_HZ alive
2019-01-18 09:31:32 status_HG_BM_1 alive
2019-01-18 09:31:32 status_HG_BM_Bad alive
2019-01-18 09:31:32 status_HG_BM_Einfahrt alive
2019-01-18 09:31:32 status_HG_BZ_Fenster alive
2019-01-18 09:31:32 status_HG_BZ_HZ alive
2019-01-18 09:31:32 status_HG_BZ_HZ_WT alive
2019-01-18 09:31:32 status_HG_GWC_Fenster alive
2019-01-18 09:31:32 status_HG_GWC_HZ alive
2019-01-18 09:31:32 status_HG_KE_Tuer alive
2019-01-18 09:31:32 status_HG_KE_TuerRiegel alive
2019-01-18 09:31:32 status_HG_KE_WC_Fenster alive
2019-01-18 09:31:32 status_HG_KU_Fenster alive
2019-01-18 09:31:32 status_HG_KU_HZ alive
2019-01-18 09:31:32 status_HG_SS_TR alive
2019-01-18 09:31:32 status_HG_SZ_Fenster alive
2019-01-18 09:31:32 status_HG_SZ_Fenster_alt alive
2019-01-18 09:31:32 status_HG_SZ_HZ alive
2019-01-18 09:31:32 status_HG_WK_Fenster alive
2019-01-18 09:31:32 status_HG_WZ_Fenster alive
2019-01-18 09:31:32 status_HG_WZ_HZ alive
2019-01-18 09:31:32 status_HG_WZ_HZ_WT alive
2019-01-18 09:31:32 status_HG_WZ_TTuer alive
2019-01-18 09:31:32 status_NG_BZ_Fenster alive
2019-01-18 09:31:32 status_NG_BZ_HZ alive
2019-01-18 09:31:32 status_NG_SZ_Fenster alive
2019-01-18 09:31:32 status_NG_WZ_Fenster alive
2019-01-18 09:31:32 status_PWR_SW_1 alive
2019-01-18 09:31:32 status_PWR_SW_2 alive
2019-01-18 09:31:32 status_TempSens1 alive
2019-01-18 09:31:32 status_TempSens2 alive
helper:
HM_CMDNR 68
actCycle 600
mId
peers 221C69,22BBAA,24D474,2702B3,2C5221,2C89C0,2E6681,2E668E,32E877,35ADEF,35E1D4,374036,374058,3CD91E,3D5409,3E4AE2,3F3F9E,40A03D,43BADF,43BB96,4423F3,4482AF,4A3360,4DEE28,4DEE33,4ECE3F,53CE86,568966,58096D,59B62F,5A1C3E
221C69:
start 2019-01-17 17:21:21
22BBAA:
start 2019-01-17 17:21:24
24D474:
start 2019-01-17 17:21:24
2702B3:
start 2019-01-17 17:21:22
2C5221:
start 2019-01-17 17:21:21
2C89C0:
start 2019-01-17 17:21:25
2E6681:
start 2019-01-17 17:21:23
2E668E:
start 2019-01-17 17:21:24
32E877:
start 2019-01-17 17:21:22
35ADEF:
start 2019-01-17 17:21:23
35E1D4:
start 2019-01-17 17:21:21
374036:
start 2019-01-17 17:21:25
374058:
start 2019-01-17 17:21:25
3CD91E:
start 2019-01-17 17:21:22
3D5409:
start 2019-01-17 17:21:22
3E4AE2:
start 2019-01-17 17:21:21
3F3F9E:
start 2019-01-17 17:21:24
40A03D:
start 2019-01-17 17:21:22
43BADF:
start 2019-01-17 17:21:23
43BB96:
start 2019-01-17 17:21:23
4423F3:
start 2019-01-17 17:21:24
4482AF:
start 2019-01-17 17:21:21
4A3360:
start 2019-01-17 17:21:25
4DEE28:
start 2019-01-17 17:21:25
4DEE33:
start 2019-01-17 17:21:25
4ECE3F:
start 2019-01-17 17:21:23
53CE86:
start 2019-01-17 17:21:23
568966:
start 2019-01-17 17:21:23
58096D:
start 2019-01-17 17:21:23
59B62F:
start 2019-01-17 17:21:22
5A1C3E:
start 2019-01-17 17:21:24
bm:
CUL_HM_Set:
cnt 1
dmx -1000
dtot 0
dtotcnt 0
mTS 18.01. 09:31:11
max 0.0165939331054688
tot 0.0165939331054688
mAr:
HASH(0x2db7b20)
ActionDetector
?
io:
newChn +000000,00,00,00
prefIO
rxt 0
vccu
p:
000000
00
00
00
mRssi:
mNo
prt:
bErr 0
sProc 0
q:
qReqConf
qReqStat
role:
tmpl:
Attributes:
event-on-change-reading .*
model ActionDetector
room Technikraum
apptime:
[code]active-timers: 86; max-active timers: 103; max-timer-load: 12 min-tmrHandlingTm: 0.0ms; max-tmrHandlingTm: 575.5ms; totAvgDly: 76.9ms
name function max count total average maxDly avgDly TS Max call param Max call
rg_batteryLevel readingsGroup_Notify 3342 6866 38269.38 [/cod
Kann Dir ejtzt nicht direkt helfen, aber Anregungen geben ...
telnet wird auch für "non-Blockin-Module" verwendet.
Was mich wundert:
2019.01.18 09:35:08.204 1: [Freezemon] myFreezemon: possible freeze starting at 09:35:05, delay is 3.204 possibly caused by: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_52982)
Das Kommando "cmd-jsonlist2" bnraucht so lange.
Meine Frage: Kommt in der Zeit irgendetwas, welches JSON verwendet, vor? z.B. mqtt??
Oder hast Du selber routinen mit JSON programmiert?
Hallo Wernieman,
selbst programmiert habe ich da nix.
Ich habe auf dem NUC einen lokalen mqtt broker laufen für die Visualisierung einiger devices in IOBroker. Die Homematic Fensterkontakte liefern nur open/closed, damit können die IOBroker-Widgets nicht um, die wollen 0/1 bzw. true/false. Das betrifft aber nur die Fensterkontakte. Mqtt-Aufrufe sehe ich im fraglichen Zeitraum nicht im Log.
Der fragliche telnet-Aufruf betrifft doch aber den ActionDetector, oder verstehe ich das falsch?
Sammelt ActionDetector den state der devices mit telnet ein?
Gruß Roland
Zitat von: hauwech am 18 Januar 2019, 10:41:45
Der fragliche telnet-Aufruf betrifft doch aber den ActionDetector, oder verstehe ich das falsch?
Vielleicht habe ich nicht genau genug geschaut, aber woher nimmst Du an, dass der Aufruf vom Actiondetector kommt?
Was ich erkennen kann ist, dass eine device liste erzeugt wird mit folgenden Angaben:
TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector
Also alle devices mit nichtleerem state ausser CCU-FHEM oder ActionDetector (modell) also eigentlich eine sehr weitgehenda Abfrage aller devices mit wenigen Ausnahmen.
deine apptime ausgabe im post kann man leider nicht sehen.
wo wird dieser fhem ausdruck bei dir benutzt?
TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector:telnetPort
vielleicht mal fhem.cfg durchsuchen.
der "normale" actiondetector an sich kann nicht das problem sein.
freezemon mit der log option, zeigt am besten den verursacher.
Da kommt der zweite Teil meines Satzes zum Tragen.
ICH habe nicht genau genug geschaut. Ein list mit TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector
liefert 510 devices.
Was ich noch nicht verstehe:
2019.01.18 09:35:08.204 1: [Freezemon] myFreezemon: possible freeze starting at 09:35:05, delay is 3.204 possibly caused by: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_52982)
Sind cmd-jsonlist2 und fn-ReadFn zwei unterschiedliche Funktionen, die laut freezemon verdächtig sind?
Oder wird cmd-jsonlist2 mit fn-ReadFn-telnet lokal aufgerufen?
Aber selbst, wenn ich das wüßte, ich könnte das Problem nicht auflösen, weil mir zuviel Wissen um die Interna und JSON generell fehlt.
Gruß Roland
Hallo Frank,
ich denke, das ist ein fhem-interner Aufruf, der zyklisch ausgeführt wird.
apptime:
active-timers: 86; max-active timers: 110; max-timer-load: 14 min-tmrHandlingTm: 0.0ms; max-tmrHandlingTm: 575.5ms; totAvgDly: 87.2ms
name function max count total average maxDly avgDly TS Max call param Max call
rg_batteryLevel readingsGroup_Notify 3400 26044 130885.07 5.03 0.00 0.00 18.01. 10:23:22 HASH(rg_batteryLevel); HASH(Wetter_Hameln)
HmUART1 HMUARTLGW_Read 2260 2747 129520.23 47.15 0.00 0.00 18.01. 09:22:47 HASH(HmUART1)
HmUART3 HMUARTLGW_Read 1395 3012 183638.79 60.97 0.00 0.00 18.01. 09:22:50 HASH(HmUART3)
HmUART2 HMUARTLGW_Read 1340 3784 228500.42 60.39 0.00 0.00 18.01. 09:22:48 HASH(HmUART2)
WEBtablet FW_Read 1000 3 1133.37 377.79 0.00 0.00 18.01. 11:15:31 HASH(WEBtablet)
myCalView CALVIEW_Notify 708 26044 1703.58 0.07 0.00 0.00 18.01. 09:21:31 HASH(myCalView); HASH(Kalender)
myView CALVIEW_Notify 617 26044 1409.61 0.05 0.00 0.00 18.01. 09:21:32 HASH(myView); HASH(Kalender)
n_MotionEinfahrt notify_Exec 529 4 766.64 191.66 0.00 0.00 18.01. 09:03:17 HASH(n_MotionEinfahrt); HASH(HG_BM_Einfahrt)
tmr-HMUARTLGW_CheckCmdResp HASH(0x5d90fe8) 507 51 625.76 12.27 3591.02 255.66 18.01. 09:22:38 HASH(HmUART2)
tmr-at_Exec HASH(0x6c4fc70) 468 10 2748.94 274.89 567.78 59.25 18.01. 10:06:16 HASH(a_LuefterWZNord)
BS_SW_03 IT_Set 449 191 7876.83 41.24 0.00 0.00 18.01. 10:06:16 HASH(BS_SW_03); BS_SW_03; on-for-timer; 300
tmr-DOIF_TimerTrigger REF(0xab68668) 445 1 445.67 445.67 80.20 80.20 18.01. 10:00:00 REF(0xab68668)
tmr-SetExtensionsFn SE BS_SW_03 on-for-timer 440 6 2557.64 426.27 4.24 3.12 18.01. 10:41:17 SE BS_SW_03 on-for-timer
mqttGeneric MQTT::GENERIC_BRIDGE::Notify 426 26044 148148.73 5.69 0.00 0.00 18.01. 09:10:04 HASH(mqttGeneric); HASH(HG_KU_HZ)
tmr-Twilight_sunpos HASH(0xb980728) 422 1 422.20 422.20 3.05 3.05 18.01. 09:36:09 HASH(myTwilight_sunpos)
AlleFenster structure_Notify 412 26044 7083.36 0.27 0.00 0.00 18.01. 09:22:48 HASH(AlleFenster); HASH(HG_GWC_Fenster)
tmr-Twilight_sunpos HASH(0xb502e70) 410 1 410.67 410.67 1.63 1.63 18.01. 09:26:09 HASH(myTwilight_sunpos)
tmr-Twilight_sunpos HASH(0xacce0d8) 406 1 406.40 406.40 2.72 2.72 18.01. 09:51:09 HASH(myTwilight_sunpos)
tmr-Twilight_sunpos HASH(0xc85ead0) 397 1 397.37 397.37 116.49 116.49 18.01. 11:06:09 HASH(myTwilight_sunpos)
WEB_127.0.0.1_51218 FW_Notify 395 26044 133073.25 5.11 0.00 0.00 18.01. 09:22:48 HASH(WEB_127.0.0.1_51218); HASH(AlleFenster)
tmr-Twilight_sunpos HASH(0xb4faa38) 393 1 393.53 393.53 2.69 2.69 18.01. 09:46:09 HASH(myTwilight_sunpos)
tmr-Twilight_sunpos HASH(0xbd0c4e0) 392 1 392.38 392.38 2.55 2.55 18.01. 11:01:09 HASH(myTwilight_sunpos)
tmr-Twilight_sunpos HASH(0xc948a08) 391 1 391.33 391.33 2.09 2.09 18.01. 10:56:09 HASH(myTwilight_sunpos)
tmr-Twilight_sunpos HASH(0xaca6600) 390 1 390.69 390.69 2.91 2.91 18.01. 10:31:09 HASH(myTwilight_sunpos)
tmr-Twilight_sunpos HASH(0xc6b0e88) 390 1 390.57 390.57 3.18 3.18 18.01. 10:01:09 HASH(myTwilight_sunpos)
tmr-Twilight_sunpos HASH(0xb4e5b80) 390 1 390.39 390.39 3.67 3.67 18.01. 09:56:09 HASH(myTwilight_sunpos)
tmr-Twilight_sunpos HASH(0xaebaf38) 389 1 389.85 389.85 2.22 2.22 18.01. 10:41:09 HASH(myTwilight_sunpos)
tmr-Twilight_sunpos HASH(0xbb2cc50) 389 1 389.32 389.32 4.23 4.23 18.01. 09:31:09 HASH(myTwilight_sunpos)
tmr-Twilight_sunpos HASH(0xa7e4c10) 388 1 388.73 388.73 3.72 3.72 18.01. 09:16:09 HASH(myTwilight_sunpos)
tmr-Twilight_sunpos HASH(0xb610d30) 388 1 388.44 388.44 2.50 2.50 18.01. 10:06:09 HASH(myTwilight_sunpos)
tmr-Twilight_sunpos HASH(0xb754260) 388 1 388.12 388.12 4.23 4.23 18.01. 10:36:09 HASH(myTwilight_sunpos)
tmr-Twilight_sunpos HASH(0x622ba50) 387 1 387.91 387.91 2.65 2.65 18.01. 11:11:09 HASH(myTwilight_sunpos)
tmr-Twilight_sunpos HASH(0xbf830a0) 387 1 387.84 387.84 2.71 2.71 18.01. 10:11:09 HASH(myTwilight_sunpos)
tmr-Twilight_sunpos HASH(0xc89e710) 387 1 387.39 387.39 4.21 4.21 18.01. 09:41:09 HASH(myTwilight_sunpos)
tmr-Twilight_sunpos HASH(0xa8419d8) 387 1 387.32 387.32 2.40 2.40 18.01. 09:11:09 HASH(myTwilight_sunpos)
tmr-Twilight_sunpos HASH(0xcbe9660) 386 1 386.10 386.10 3.91 3.91 18.01. 11:26:09 HASH(myTwilight_sunpos)
tmr-Twilight_sunpos HASH(0xaed4550) 385 1 385.56 385.56 4.65 4.65 18.01. 09:06:09 HASH(myTwilight_sunpos)
AlleFenster structure_Set 382 196 7544.17 38.49 0.00 0.00 18.01. 09:22:48 HASH(AlleFenster); AlleFenster; ?
nanoCUL CUL_Get 382 12 4503.20 375.27 0.00 0.00 18.01. 10:06:16 HASH(nanoCUL); ; raw; is0F0F0FF0FFFF
tmr-Twilight_sunpos HASH(0xacabac8) 380 1 380.68 380.68 1.47 1.47 18.01. 09:21:09 HASH(myTwilight_sunpos)
tmr-Twilight_sunpos HASH(0xad690f8) 379 1 379.14 379.14 1.76 1.76 18.01. 10:46:09 HASH(myTwilight_sunpos)
Den apptime-output hatte ich in der Vorschau noch gesehen, vielleicht wurde das abgeschnitten, weil der Post zu lang war.
Gruß Roland
in der apptime ausgabe sehe ich direkt keine regelmässigen freezes. allerdings sind ein paar einträge auffällig, die alle eine sehr hohe anzahl von 26044 aufweisen.
je nachdem, wie lange apptime gesammelt hat, ist dieser wert zu hoch. eventuell werden diese funktionen bei jedem event aufgerufen. muss das sein?
die avg werte sind aber sehr niedrig.
Apptime lief ein paar Stunden. Die calview Aufrufe sehe ich so auffällig zum ersten Mal. Die werde ich mal untersuchen.
Soo, myView und myCalView waren doppelte Definitionen, von denen ich eine gar nicht genutzt hatte. Das hatte ich bisher gar nicht gemerkt. Beide standen auf Interval=43200, also zwölf Stunden. Da hing aber noch ein notify dran, welches die Readingsgroup aktualisiert. Der state des notify steht auf "2019-01-18 09:21:30", das hat also offenbar im vorgesehenen Intervall ausgelöst. Ich habe dem myCalView trotzdem mal ein event-on-change-reading .* verpaßt.
Gruß Roland
ZitatApptime lief ein paar Stunden.
dann vermute ich bei dir grundsätzlich zu viele events.
vielleicht zur eindämmung erst mal bei allen devices "attr event-on-change-reading .*" setzen. die readings, die wirklich bei jedem update ein event erzeugen müssen, kann man dann zusätzlich mit "attr event-on-update-reading" setzen.
Die Readingsgroup rg_batteryLevel fällt auch mit vielen counts auf. Auf diese Übersicht möchte ich auch nicht verzichten. Offenbar wird die Readingsgroup jedes Mal aktualisiert, wenn ein device mit einem battery reading *:<{batDeviceIndicator($DEVICE)}>,<{batLevelIndicator($DEVICE)}>,<{batTimestampIndicator($DEVICE)}>
aktualisiert wird. Zudem werden die Werte noch mit sub-Aufrufen aus myUtils aufbereitet.
Ich werde jetzt mal allen devices mit battery.* ein event-on-change-reading verpassen.
Gruß Roland
Das Attribut event-on-change-reading .* habe ich auf alle devices mit reading battery oder batteryLevel gesetzt. Das sind Optimierungen, die jetzt quasi nebenher mit anfallen. Die freezes gehen aber unbeeindruckt weiter. Ich hänge mal das freezemon-log über etwa 8 Minuten mit dran. Sicher sieht jemand, der Ahnung hat, viel mehr als ich.
2019.01.18 13:59:07.539 5: [Freezemon] myFreezemon: ----------- Starting Freeze handling at 2019.01.18 13:59:07.539 ---------------------
[Freezemon] myFreezemon: possible freeze starting at 13:59:05, delay is 2.539 possibly caused by: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_36156)
2019-01-18_14:00:08 myFreezemon s:14:00:05 e:14:00:08 f:3.38 d:cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_36294) tmr-SSCam_getsvsinfo(Hikvision) tmr-HMUARTLGW_CheckCmdResp(HmUART2) tmr-HMUARTLGW_CheckCredits(N/A) tmr-SSCam_getcapabilities(Hikvision)
2019-01-18_14:00:08 myFreezemon freezeTime: 3.38
2019-01-18_14:00:08 myFreezemon fcDay: 891
2019-01-18_14:00:08 myFreezemon ftDay: 2399.723
2019-01-18_14:00:08 myFreezemon freezeDevice: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_36294) tmr-SSCam_getsvsinfo(Hikvision) tmr-HMUARTLGW_CheckCmdResp(HmUART2) tmr-HMUARTLGW_CheckCredits(N/A) tmr-SSCam_getcapabilities(Hikvision)
=========================================================
[Freezemon] myFreezemon: possible freeze starting at 14:00:05, delay is 3.38 possibly caused by: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_36294) tmr-SSCam_getsvsinfo(Hikvision) tmr-HMUARTLGW_CheckCmdResp(HmUART2) tmr-HMUARTLGW_CheckCredits(N/A) tmr-SSCam_getcapabilities(Hikvision)
2019.01.18 14:00:04.017 5: JeeLink/RAW: /OK 9 25
2019.01.18 14:00:04.033 5: JeeLink/RAW: OK 9 25 /1 4 0 78
2019.01.18 14:00:04.123 4: http://192.168.1.82:5000/webapi/entry.cgi?api="SYNO.SurveillanceStation.Camera.Event"&version="1"&method="MotionEnum"&camId="7"&_sid="xxxxxxxxxxxxxxxxxxxxxxxx": HTTP response code 200
2019.01.18 14:00:04.123 5: HttpUtils http://192.168.1.82:5000/webapi/entry.cgi?api="SYNO.SurveillanceStation.Camera.Event"&version="1"&method="MotionEnum"&camId="7"&_sid="xxxxxxxxxxxxxxxxxxxxxxxx": Got data, length: 1917
2019.01.18 14:00:04.123 5: HttpUtils response header:
HTTP/1.1 200 OK
Server: nginx
Date: Fri, 18 Jan 2019 13:00:04 GMT
Content-Type: application/json; charset="UTF-8"
Connection: close
Vary: Accept-Encoding
X-Content-Type-Options: nosniff
X-XSS-Protection: 1; mode=block
Cache-Control: max-age=0, no-cache, no-store, must-revalidate
Pragma: no-cache
Expires: 0
2019.01.18 14:00:04.124 5: Hikvision - JSON returned: $VAR1 = {
.
.
.
2019.01.18 14:00:04.125 4: Hikvision - Enumerate motion detection parameters of camera Terrasse retrieved
2019.01.18 14:00:04.155 4: Hikvision - ####################################################
2019.01.18 14:00:04.155 4: Hikvision - ### start cam operation getsvsinfo
2019.01.18 14:00:04.155 4: Hikvision - ####################################################
2019.01.18 14:00:04.155 4: Hikvision - --- Begin Function SSCam_getapisites nonblocking ---
2019.01.18 14:00:04.155 4: Hikvision - API hashvalues already set - ignore get apisites
2019.01.18 14:00:04.155 4: Hikvision - --- Begin Function SSCam_getcamid nonblocking ---
2019.01.18 14:00:04.155 4: Hikvision - CAMID already set - ignore get camid
2019.01.18 14:00:04.155 4: Hikvision - --- Begin Function getsvsinfo nonblocking ---
2019.01.18 14:00:04.155 5: Hikvision - HTTP-Call will be done with httptimeout-Value: 4 s
2019.01.18 14:00:04.155 4: Hikvision - Call-Out now: http://192.168.1.82:5000/webapi/entry.cgi?api="SYNO.SurveillanceStation.Info"&version="6"&method="GetInfo"&_sid="xxxxxxxxxxxxxxxxxxxxxxxx"
2019.01.18 14:00:04.155 5: HttpUtils url=http://192.168.1.82:5000/webapi/entry.cgi?api="SYNO.SurveillanceStation.Info"&version="6"&method="GetInfo"&_sid="xxxxxxxxxxxxxxxxxxxxxxxx"
2019.01.18 14:00:04.156 4: IP: 192.168.1.82 -> 192.168.1.82
2019.01.18 14:00:04.157 5: HttpUtils request header:
GET /webapi/entry.cgi?api="SYNO.SurveillanceStation.Info"&version="6"&method="GetInfo"&_sid="xxxxxxxxxxxxxxxxxxxxxxxx" HTTP/1.0
Host: 192.168.1.82:5000
User-Agent: fhem
Accept-Encoding: gzip,deflate
Accept: application/json
2019.01.18 14:00:04.350 4: http://192.168.1.82:5000/webapi/entry.cgi?api="SYNO.SurveillanceStation.Info"&version="6"&method="GetInfo"&_sid="xxxxxxxxxxxxxxxxxxxxxxxx": HTTP response code 200
2019.01.18 14:00:04.350 5: HttpUtils http://192.168.1.82:5000/webapi/entry.cgi?api="SYNO.SurveillanceStation.Info"&version="6"&method="GetInfo"&_sid="xxxxxxxxxxxxxxxxxxxxxxxx": Got data, length: 873
2019.01.18 14:00:04.350 5: HttpUtils response header:
HTTP/1.1 200 OK
Server: nginx
Date: Fri, 18 Jan 2019 13:00:04 GMT
Content-Type: application/json; charset="UTF-8"
Connection: close
Vary: Accept-Encoding
X-Content-Type-Options: nosniff
X-XSS-Protection: 1; mode=block
Cache-Control: max-age=0, no-cache, no-store, must-revalidate
Pragma: no-cache
Expires: 0
2019.01.18 14:00:04.352 5: Hikvision - JSON returned: $VAR1 = {
.
.
.
2019.01.18 14:00:04.353 4: Hikvision - Informations related to Surveillance Station retrieved
2019.01.18 14:00:04.428 5: HMUARTLGW HmUART2 checking credits (from timer)
2019.01.18 14:00:04.428 5: HMUARTLGW HmUART2 send: 00 08
2019.01.18 14:00:04.428 5: HMUARTLGW HmUART2 send: (8): fd00030046080c35
2019.01.18 14:00:04.428 5: SW: fd00030046080c35
2019.01.18 14:00:04.431 5: HMUARTLGW HmUART2 read raw (8): fd00050046040205
2019.01.18 14:00:04.433 5: HMUARTLGW HmUART2 read raw (2): 3456
2019.01.18 14:00:04.433 5: HMUARTLGW HmUART2 read (9): fd000500460402053456 crc OK
2019.01.18 14:00:04.433 5: HMUARTLGW HmUART2 recv: 00 040205, state 98
2019.01.18 14:00:04.433 5: HMUARTLGW HmUART2 GetSet Ack: 02, state 98
2019.01.18 14:00:04.434 5: HMUARTLGW HmUART2 roundtrip delay: 0.0045
2019.01.18 14:00:04.453 4: Hikvision - ####################################################
2019.01.18 14:00:04.453 4: Hikvision - ### start cam operation Getcapabilities
2019.01.18 14:00:04.453 4: Hikvision - ####################################################
2019.01.18 14:00:04.453 4: Hikvision - --- Begin Function SSCam_getapisites nonblocking ---
2019.01.18 14:00:04.453 4: Hikvision - API hashvalues already set - ignore get apisites
2019.01.18 14:00:04.453 4: Hikvision - --- Begin Function SSCam_getcamid nonblocking ---
2019.01.18 14:00:04.453 4: Hikvision - CAMID already set - ignore get camid
2019.01.18 14:00:04.454 4: Hikvision - --- Begin Function Getcapabilities nonblocking ---
2019.01.18 14:00:04.454 5: Hikvision - HTTP-Call will be done with httptimeout-Value: 4 s
2019.01.18 14:00:04.454 4: Hikvision - Call-Out now: http://192.168.1.82:5000/webapi/entry.cgi?api=SYNO.SurveillanceStation.Camera&version=8&method="GetCapabilityByCamId"&cameraId=7&_sid="xxxxxxxxxxxxxxxxxxxxxxxx"
2019.01.18 14:00:04.454 5: HttpUtils url=http://192.168.1.82:5000/webapi/entry.cgi?api=SYNO.SurveillanceStation.Camera&version=8&method="GetCapabilityByCamId"&cameraId=7&_sid="xxxxxxxxxxxxxxxxxxxxxxxx"
2019.01.18 14:00:04.454 4: IP: 192.168.1.82 -> 192.168.1.82
2019.01.18 14:00:04.456 5: HttpUtils request header:
GET /webapi/entry.cgi?api=SYNO.SurveillanceStation.Camera&version=8&method="GetCapabilityByCamId"&cameraId=7&_sid="xxxxxxxxxxxxxxxxxxxxxxxx" HTTP/1.0
Host: 192.168.1.82:5000
User-Agent: fhem
Accept-Encoding: gzip,deflate
Accept: application/json
2019.01.18 14:00:04.869 4: http://192.168.1.82:5000/webapi/entry.cgi?api=SYNO.SurveillanceStation.Camera&version=8&method="GetCapabilityByCamId"&cameraId=7&_sid="xxxxxxxxxxxxxxxxxxxxxxxx": HTTP response code 200
2019.01.18 14:00:04.869 5: HttpUtils http://192.168.1.82:5000/webapi/entry.cgi?api=SYNO.SurveillanceStation.Camera&version=8&method="GetCapabilityByCamId"&cameraId=7&_sid="xxxxxxxxxxxxxxxxxxxxxxxx": Got data, length: 271
2019.01.18 14:00:04.870 5: HttpUtils response header:
HTTP/1.1 200 OK
Server: nginx
Date: Fri, 18 Jan 2019 13:00:04 GMT
Content-Type: application/json; charset="UTF-8"
Connection: close
Vary: Accept-Encoding
X-Content-Type-Options: nosniff
X-XSS-Protection: 1; mode=block
Cache-Control: max-age=0, no-cache, no-store, must-revalidate
Pragma: no-cache
Expires: 0
2019.01.18 14:00:04.870 5: Hikvision - JSON returned: $VAR1 = {
'data' => {
'ptzPan' => 0,
'ptzDirection' => 0,
'ptzAutoPanType' => 0,
'ptzSpeed' => bless( do{\(my $o = 0)}, 'JSON::PP::Boolean' ),
'ptzPresetNumber' => 0,
'ptzHasObjTracking' => $VAR1->{'data'}{'ptzSpeed'},
'ptzHome' => $VAR1->{'data'}{'ptzSpeed'},
'ptzZoom' => 0,
'fisheyeParam' => {},
'ptzFocus' => 0,
'ptzTilt' => 0,
'ptzAutoFocus' => $VAR1->{'data'}{'ptzSpeed'},
'ptzAbs' => $VAR1->{'data'}{'ptzSpeed'},
'audioOut' => $VAR1->{'data'}{'ptzSpeed'},
'ptzIris' => 0
},
'success' => bless( do{\(my $o = 1)}, 'JSON::PP::Boolean' )
};
2019.01.18 14:00:04.871 4: Hikvision - Capabilities of camera Terrasse retrieved
2019.01.18 14:00:04.895 5: JeeLink/RAW: /OK 9 35 1 4 115 56
2019.01.18 14:00:04.924 4: Connection accepted from telnetPort_127.0.0.1_36294
2019.01.18 14:00:04.925 5: Cmd: >jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector<
2019.01.18 14:00:05.065 5: YAMAHA_AVR (AV_Receiver) - set AV_Receiver ?
--- log skips 3.019 secs.
2019.01.18 14:00:08.084 5: ENIGMA2 VU: called function ENIGMA2_Set()
2019.01.18 14:00:08.086 5: ENIGMA2 VUDUO: called function ENIGMA2_Set()
2019.01.18 14:00:08.203 5: GEOFANCY geofancy: called function GEOFANCY_Set()
2019.01.18 14:00:08.221 5: myFreezemon Coming with command ?
2019.01.18 14:00:08.221 5: myFreezemon leaving with Unknown argument ?, choose one of active:noArg inactive:noArg clear:noArg
2019.01.18 14:00:08.302 1: [Freezemon] myFreezemon: Long running Command detected jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector:telnetPort - 3.376943 seconds
2019.01.18 14:00:08.379 1: [Freezemon] myFreezemon: Long function call detected ReadFn:telnetPort_127.0.0.1_36294 - 3.453507 seconds
2019.01.18 14:00:08.380 5: [Freezemon] myFreezemon: ----------- Starting Freeze handling at 2019.01.18 14:00:08.380 ---------------------
[Freezemon] myFreezemon: possible freeze starting at 14:00:05, delay is 3.38 possibly caused by: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_36294) tmr-SSCam_getsvsinfo(Hikvision) tmr-HMUARTLGW_CheckCmdResp(HmUART2) tmr-HMUARTLGW_CheckCredits(N/A) tmr-SSCam_getcapabilities(Hikvision)
2019-01-18_14:01:07 myFreezemon s:14:01:05 e:14:01:07 f:2.629 d:cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_36444)
2019-01-18_14:01:07 myFreezemon freezeTime: 2.629
2019-01-18_14:01:07 myFreezemon fcDay: 892
2019-01-18_14:01:07 myFreezemon ftDay: 2402.352
2019-01-18_14:01:07 myFreezemon freezeDevice: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_36444)
=========================================================
[Freezemon] myFreezemon: possible freeze starting at 14:01:05, delay is 2.629 possibly caused by: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_36444)
2019.01.18 14:01:04.069 5: JeeLink/RAW: /OK 9 49 1 4 16 75
2019.01.18 14:01:04.155 4: Connection accepted from telnetPort_127.0.0.1_36444
2019.01.18 14:01:04.157 5: Cmd: >jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector<
2019.01.18 14:01:04.300 5: YAMAHA_AVR (AV_Receiver) - set AV_Receiver ?
--- log skips 3.033 secs.
2019.01.18 14:01:07.333 5: ENIGMA2 VU: called function ENIGMA2_Set()
2019.01.18 14:01:07.336 5: ENIGMA2 VUDUO: called function ENIGMA2_Set()
2019.01.18 14:01:07.452 5: GEOFANCY geofancy: called function GEOFANCY_Set()
2019.01.18 14:01:07.470 5: myFreezemon Coming with command ?
2019.01.18 14:01:07.470 5: myFreezemon leaving with Unknown argument ?, choose one of active:noArg inactive:noArg clear:noArg
2019.01.18 14:01:07.551 1: [Freezemon] myFreezemon: Long running Command detected jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector:telnetPort - 3.394111 seconds
2019.01.18 14:01:07.628 1: [Freezemon] myFreezemon: Long function call detected ReadFn:telnetPort_127.0.0.1_36444 - 3.471351 seconds
2019.01.18 14:01:07.629 5: [Freezemon] myFreezemon: ----------- Starting Freeze handling at 2019.01.18 14:01:07.629 ---------------------
[Freezemon] myFreezemon: possible freeze starting at 14:01:05, delay is 2.629 possibly caused by: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_36444)
2019-01-18_14:02:07 myFreezemon s:14:02:05 e:14:02:07 f:2.626 d:cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_36566) tmr-SSCam_getsvsinfo(Foscam) tmr-Unifi_DoUpdate(UnifiController) tmr-SSCam_getcapabilities(Foscam) tmr-SSCam_getsnapinfo(N/A) tmr-SSCam_getstreamformat(Foscam) tmr-SSCam_getsnapinfo(N/A) tmr-SSCam_getptzlistpreset(Foscam) tmr-SSCam_getptzlistpatrol(Foscam)
2019-01-18_14:02:07 myFreezemon freezeTime: 2.626
2019-01-18_14:02:07 myFreezemon fcDay: 893
2019-01-18_14:02:07 myFreezemon ftDay: 2404.978
2019-01-18_14:02:07 myFreezemon freezeDevice: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_36566) tmr-SSCam_getsvsinfo(Foscam) tmr-Unifi_DoUpdate(UnifiController) tmr-SSCam_getcapabilities(Foscam) tmr-SSCam_getsnapinfo(N/A) tmr-SSCam_getstreamformat(Foscam) tmr-SSCam_getsnapinfo(N/A) tmr-SSCam_getptzlistpreset(Foscam) tmr-SSCam_getptzlistpatrol(Foscam)
=========================================================
[Freezemon] myFreezemon: possible freeze starting at 14:02:05, delay is 2.626 possibly caused by: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_36566) tmr-SSCam_getsvsinfo(Foscam) tmr-Unifi_DoUpdate(UnifiController) tmr-SSCam_getcapabilities(Foscam) tmr-SSCam_getsnapinfo(N/A) tmr-SSCam_getstreamformat(Foscam) tmr-SSCam_getsnapinfo(N/A) tmr-SSCam_getptzlistpreset(Foscam) tmr-SSCam_getptzlistpatrol(Foscam)
2019.01.18 14:02:04.108 4: http://192.168.1.82:5000/webapi/entry.cgi?api="SYNO.SurveillanceStation.Camera.Event"&version="1"&method="MotionEnum"&camId="7"&_sid="xxxxxxxxxxxxxxxxxxxxxxxx": HTTP response code 200
2019.01.18 14:02:04.108 5: HttpUtils http://192.168.1.82:5000/webapi/entry.cgi?api="SYNO.SurveillanceStation.Camera.Event"&version="1"&method="MotionEnum"&camId="7"&_sid="xxxxxxxxxxxxxxxxxxxxxxxx": Got data, length: 1917
2019.01.18 14:02:04.108 5: HttpUtils response header:
HTTP/1.1 200 OK
Server: nginx
Date: Fri, 18 Jan 2019 13:02:04 GMT
Content-Type: application/json; charset="UTF-8"
Connection: close
Vary: Accept-Encoding
X-Content-Type-Options: nosniff
X-XSS-Protection: 1; mode=block
Cache-Control: max-age=0, no-cache, no-store, must-revalidate
Pragma: no-cache
Expires: 0
2019.01.18 14:02:04.109 5: Hikvision - JSON returned: $VAR1 = {
.
.
.
2019.01.18 14:02:04.109 4: Hikvision - Enumerate motion detection parameters of camera Terrasse retrieved
2019.01.18 14:02:04.169 4: Connection accepted from telnetPort_127.0.0.1_36566
2019.01.18 14:02:04.171 5: Cmd: >jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector<
2019.01.18 14:02:04.313 5: YAMAHA_AVR (AV_Receiver) - set AV_Receiver ?
--- log skips 3.014 secs.
2019.01.18 14:02:07.327 5: ENIGMA2 VU: called function ENIGMA2_Set()
2019.01.18 14:02:07.329 5: ENIGMA2 VUDUO: called function ENIGMA2_Set()
2019.01.18 14:02:07.446 5: GEOFANCY geofancy: called function GEOFANCY_Set()
2019.01.18 14:02:07.464 5: myFreezemon Coming with command ?
2019.01.18 14:02:07.464 5: myFreezemon leaving with Unknown argument ?, choose one of active:noArg inactive:noArg clear:noArg
2019.01.18 14:02:07.545 1: [Freezemon] myFreezemon: Long running Command detected jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector:telnetPort - 3.374191 seconds
2019.01.18 14:02:07.621 1: [Freezemon] myFreezemon: Long function call detected ReadFn:telnetPort_127.0.0.1_36566 - 3.450253 seconds
2019.01.18 14:02:07.622 5: UnifiController (Unifi_DoUpdate) - executed.
2019.01.18 14:02:07.622 5: UnifiController (Unifi_GetAccesspoints_Send) - executed.
2019.01.18 14:02:07.622 5: IP: 192.168.1.223 -> 192.168.1.223
2019.01.18 14:02:07.624 4: Hikvision - ####################################################
2019.01.18 14:02:07.624 4: Hikvision - ### start cam operation getsnapgallery
2019.01.18 14:02:07.624 4: Hikvision - ####################################################
2019.01.18 14:02:07.624 4: Hikvision - --- Begin Function SSCam_getapisites nonblocking ---
2019.01.18 14:02:07.624 4: Hikvision - API hashvalues already set - ignore get apisites
2019.01.18 14:02:07.624 4: Hikvision - --- Begin Function SSCam_getcamid nonblocking ---
2019.01.18 14:02:07.624 4: Hikvision - CAMID already set - ignore get camid
2019.01.18 14:02:07.624 4: Hikvision - --- Begin Function getsnapgallery nonblocking ---
2019.01.18 14:02:07.624 5: Hikvision - HTTP-Call will be done with httptimeout-Value: 4 s
2019.01.18 14:02:07.624 4: Hikvision - Call getsnapinfo with params: Image numbers => 10, Image size => 1, Keyword => Terrasse
2019.01.18 14:02:07.624 4: Hikvision - Call-Out now: http://192.168.1.82:5000/webapi/entry.cgi?api="SYNO.SurveillanceStation.SnapShot"&method="List"&version="1"&keyword="Terrasse"&imgSize="1"&limit="10"&_sid="xxxxxxxxxxxxxxxxxxxxxxxx"
2019.01.18 14:02:07.624 5: HttpUtils url=http://192.168.1.82:5000/webapi/entry.cgi?api="SYNO.SurveillanceStation.SnapShot"&method="List"&version="1"&keyword="Terrasse"&imgSize="1"&limit="10"&_sid="xxxxxxxxxxxxxxxxxxxxxxxx"
2019.01.18 14:02:07.624 4: IP: 192.168.1.82 -> 192.168.1.82
2019.01.18 14:02:07.627 5: [Freezemon] myFreezemon: ----------- Starting Freeze handling at 2019.01.18 14:02:07.626 ---------------------
[Freezemon] myFreezemon: possible freeze starting at 14:02:05, delay is 2.626 possibly caused by: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_36566) tmr-SSCam_getsvsinfo(Foscam) tmr-Unifi_DoUpdate(UnifiController) tmr-SSCam_getcapabilities(Foscam) tmr-SSCam_getsnapinfo(N/A) tmr-SSCam_getstreamformat(Foscam) tmr-SSCam_getsnapinfo(N/A) tmr-SSCam_getptzlistpreset(Foscam) tmr-SSCam_getptzlistpatrol(Foscam)
2019-01-18_14:03:07 myFreezemon s:14:03:05 e:14:03:07 f:2.664 d:cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_36726)
2019-01-18_14:03:07 myFreezemon freezeTime: 2.664
2019-01-18_14:03:07 myFreezemon fcDay: 894
2019-01-18_14:03:07 myFreezemon ftDay: 2407.642
2019-01-18_14:03:07 myFreezemon freezeDevice: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_36726)
=========================================================
[Freezemon] myFreezemon: possible freeze starting at 14:03:05, delay is 2.664 possibly caused by: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_36726)
2019.01.18 14:03:04.218 4: Connection accepted from telnetPort_127.0.0.1_36726
2019.01.18 14:03:04.222 5: Cmd: >jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector<
2019.01.18 14:03:04.360 5: YAMAHA_AVR (AV_Receiver) - set AV_Receiver ?
--- log skips 3.009 secs.
2019.01.18 14:03:07.369 5: ENIGMA2 VU: called function ENIGMA2_Set()
2019.01.18 14:03:07.371 5: ENIGMA2 VUDUO: called function ENIGMA2_Set()
2019.01.18 14:03:07.487 5: GEOFANCY geofancy: called function GEOFANCY_Set()
2019.01.18 14:03:07.505 5: myFreezemon Coming with command ?
2019.01.18 14:03:07.505 5: myFreezemon leaving with Unknown argument ?, choose one of active:noArg inactive:noArg clear:noArg
2019.01.18 14:03:07.586 1: [Freezemon] myFreezemon: Long running Command detected jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector:telnetPort - 3.364415 seconds
2019.01.18 14:03:07.662 1: [Freezemon] myFreezemon: Long function call detected ReadFn:telnetPort_127.0.0.1_36726 - 3.440746 seconds
2019.01.18 14:03:07.664 5: [Freezemon] myFreezemon: ----------- Starting Freeze handling at 2019.01.18 14:03:07.664 ---------------------
[Freezemon] myFreezemon: possible freeze starting at 14:03:05, delay is 2.664 possibly caused by: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_36726)
2019-01-18_14:04:07 myFreezemon s:14:04:05 e:14:04:07 f:2.688 d:cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_36858) tmr-SSCam_getstreamformat(Hikvision) tmr-SSCam_getsnapinfo(N/A)
2019-01-18_14:04:07 myFreezemon freezeTime: 2.688
2019-01-18_14:04:07 myFreezemon fcDay: 895
2019-01-18_14:04:07 myFreezemon ftDay: 2410.33
2019-01-18_14:04:07 myFreezemon freezeDevice: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_36858) tmr-SSCam_getstreamformat(Hikvision) tmr-SSCam_getsnapinfo(N/A)
=========================================================
[Freezemon] myFreezemon: possible freeze starting at 14:04:05, delay is 2.688 possibly caused by: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_36858) tmr-SSCam_getstreamformat(Hikvision) tmr-SSCam_getsnapinfo(N/A)
2019.01.18 14:04:04.206 4: Connection accepted from telnetPort_127.0.0.1_36858
2019.01.18 14:04:04.208 5: Cmd: >jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector<
2019.01.18 14:04:04.346 5: YAMAHA_AVR (AV_Receiver) - set AV_Receiver ?
--- log skips 3.039 secs.
2019.01.18 14:04:07.385 5: ENIGMA2 VU: called function ENIGMA2_Set()
2019.01.18 14:04:07.387 5: ENIGMA2 VUDUO: called function ENIGMA2_Set()
2019.01.18 14:04:07.506 5: GEOFANCY geofancy: called function GEOFANCY_Set()
2019.01.18 14:04:07.525 5: myFreezemon Coming with command ?
2019.01.18 14:04:07.525 5: myFreezemon leaving with Unknown argument ?, choose one of active:noArg inactive:noArg clear:noArg
2019.01.18 14:04:07.605 1: [Freezemon] myFreezemon: Long running Command detected jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector:telnetPort - 3.397437 seconds
2019.01.18 14:04:07.682 1: [Freezemon] myFreezemon: Long function call detected ReadFn:telnetPort_127.0.0.1_36858 - 3.474353 seconds
2019.01.18 14:04:07.683 5: JeeLink/RAW: /OK 9 35 1 4 116 58
OK 9 3 1 4 154 56
OK 9 28 1 4 98 60
2019.01.18 14:04:07.688 5: [Freezemon] myFreezemon: ----------- Starting Freeze handling at 2019.01.18 14:04:07.688 ---------------------
[Freezemon] myFreezemon: possible freeze starting at 14:04:05, delay is 2.688 possibly caused by: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_36858) tmr-SSCam_getstreamformat(Hikvision) tmr-SSCam_getsnapinfo(N/A)
2019-01-18_14:05:08 myFreezemon s:14:05:05 e:14:05:08 f:3.321 d:cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_37004)
2019-01-18_14:05:08 myFreezemon freezeTime: 3.321
2019-01-18_14:05:08 myFreezemon fcDay: 896
2019-01-18_14:05:08 myFreezemon ftDay: 2413.651
2019-01-18_14:05:08 myFreezemon freezeDevice: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_37004)
=========================================================
[Freezemon] myFreezemon: possible freeze starting at 14:05:05, delay is 3.321 possibly caused by: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_37004)
2019.01.18 14:05:04.035 5: JeeLink/RAW: /OK 9 35 1 4 116 58
2019.01.18 14:05:04.043 5: battStatus: not on any display, ignoring notify
2019.01.18 14:05:04.047 4: DbLog myDbLog -> ################################################################
2019.01.18 14:05:04.047 4: DbLog myDbLog -> ### start of new Logcycle ###
2019.01.18 14:05:04.047 4: DbLog myDbLog -> ################################################################
2019.01.18 14:05:04.047 4: DbLog myDbLog -> number of events received: 2 for device: HG_WK_TH_01
2019.01.18 14:05:04.047 4: DbLog myDbLog -> check Device: HG_WK_TH_01 , Event: humidity: 58
2019.01.18 14:05:04.048 5: DbLog myDbLog -> parsed Event: HG_WK_TH_01 , Event: humidity: 58
2019.01.18 14:05:04.048 4: DbLog myDbLog -> added event - Timestamp: 2019-01-18 14:05:04, Device: HG_WK_TH_01, Type: LACROSSE, Event: humidity: 58, Reading: humidity, Value: 58, Unit: %
2019.01.18 14:05:04.048 4: DbLog myDbLog -> check Device: HG_WK_TH_01 , Event: state: T: 14 H: 58
2019.01.18 14:05:04.063 4: DbLog myDbLog -> ################################################################
2019.01.18 14:05:04.063 4: DbLog myDbLog -> ### start of new Logcycle ###
2019.01.18 14:05:04.063 4: DbLog myDbLog -> ################################################################
2019.01.18 14:05:04.063 4: DbLog myDbLog -> number of events received: 1 for device: rg_Klima
2019.01.18 14:05:04.063 4: DbLog myDbLog -> check Device: rg_Klima , Event: HG_WK_TH_01.humidity: <html><svg class="icon humidity 6FD9FB" data-txt="58" xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:cc="http://creativecommons.org/ns#" xmlns:rdf="http://www.w3.org/1999/02/22-rdf-syntax-ns#" xmlns:svg="http://www.w3.org/2000/svg" xmlns="http://www.w3.org/2000/svg" xmlns:sodipodi="http://sodipodi.sourceforge.net/DTD/sodipodi-0.dtd" xmlns:inkscape="http://www.inkscape.org/namespaces/inkscape" version="1.0" width="550" height="550" viewBox="0 0 440 440" id="svg2985" inkscape:version="0.48.5 r10040" sodipodi:docname="my_humidity.svg"> <sodipodi:namedview pagecolor="#ffffff" bordercolor="#666666" borderopacity="1" objecttolerance="10" gridtolerance="10" guidetolerance="10" inkscape:pageopacity="0" inkscape:pageshadow="2" inkscape:window-width="1920" inkscape:window-height="1125" id="namedview2995" showgrid="false" inkscape:zoom="0.42909091" inkscape:cx="275" inkscape:cy="275" inkscape:window-x="-9" inkscape:window-y="-9" inkscape:window-maximized="1" inkscape:current-layer="svg2985" /> <defs id="defs3001" /> <metadata id="metadata2987"> Created by potrace 1.8, written by Peter Selinger 2001-2007 <rdf:RDF> <cc:Work rdf:about=""> <dc:format>image/svg+xml</dc:format> <dc:type rdf:resource="http://purl.org/dc/dcmitype/StillImage" /> <dc:title></dc:title> </cc:Work> </rdf:RDF> </metadata> <path inkscape:connector-curvature="0" id="path2995-4" style="fill:#6FD9FB;fill-opacity:1;stroke:none" d="M 200.13536,3.2421883 C 179.24395,23.324867 168.89215,32.628932 152.26847,59.716615 134.58498,86.206146 115.32611,103.21287 88.728441,173.76683 c -14.278904,37.79676 -14.834126,44.69386 -15.114069,71.57155 0,33.87712 5.04406,46.7498 26.602058,69.70768 17.42773,18.43461 38.56476,28.35414 60.01578,31.12618 -0.24193,-4.09049 -0.35585,-8.52144 -0.35585,-13.38576 0.10801,-10.3673 0.2743,-17.75294 1.23694,-25.09407 -5.74996,-0.94057 -11.016,-2.42427 -14.97851,-4.40545 -25.19796,-12.87903 -36.11663,-30.23095 -35.83664,-57.94858 0,-16.51859 0.49233,-26.95834 11.69138,-56.35582 22.1181,-57.67506 39.29077,-85.47187 56.47445,-105.595147 4.03843,37.595607 23.25555,65.228097 39.32705,92.768527 6.85109,-9.82179 13.24358,-17.95975 19.43479,-27.04266 -4.54579,-7.04199 -9.8056,-16.17869 -20.72254,-39.02209 C 205.6892,84.403383 190.0365,51.324363 200.13536,3.2421883 z" /> <path d="m 235.28584,147.27425 c -17.68362,26.48954 -36.93428,43.48334 -63.532,114.0373 -14.27878,37.79676 -14.83873,44.69117 -15.11871,71.56886 0,33.8771 5.03957,46.756 26.59772,69.71404 62.99461,66.63429 174.42506,22.1181 174.14508,-69.71404 0,-15.67865 -2.23981,-26.03776 -11.47901,-52.35551 -26.08719,-50.65778 -20.985,-29.73719 -46.38577,-82.88764 -10.81408,-25.6878 -26.45027,-58.76307 -16.35143,-106.845246 -20.89143,20.082676 -31.2523,29.394556 -47.87588,56.482236 z m 88.63496,181.75649 c 0,24.07794 -21.69814,55.36526 -44.65617,64.3245 -12.8789,5.03956 -37.79677,3.63968 -50.11571,-2.51979 -25.19784,-12.87889 -36.1169,-30.23741 -35.83693,-57.95504 0,-16.51858 0.48995,-26.94769 11.689,-56.34517 22.1181,-57.67506 39.30394,-85.47972 56.48747,-105.603 7.04127,65.54842 60.21141,100.81978 62.43234,158.0985 z" id="path2995" style="fill:#6FD9FB;fill-opacity:1;stroke:none" inkscape:connector-curvature="0" /> <path d="m 268.27128,385.41831 c -5.53994,-2.88673 -8.20927,-9.72645 -6.5001,-15.66497 1.74343,-7.90364 8.67075,-13.17084 15.49534,-16.68062 5.23422,-2.85917 11.0305,-4.57901 16.16687,-7.60832 4.30983,-3.9377 7.78937,-8.72121 11.24691,-13.40454 3.64095,-5.48925 5.07806,-12.11481 6.09074,-18.52992 0.29004,-1.45031 0.53057,-7.18784 1.1697,-2.70671 1.18061,8.43397 2.10666,16.96095 1.88965,25.48719 -0.66304,4.86792 -3.04751,9.30778 -4.8364,13.83864 -2.70736,6.00076 -5.16237,12.29822 -9.77751,17.14489 -5.13592,5.75303 -10.49291,11.40429 -16.61249,16.12044 -4.0655,2.70977 -9.74586,4.50662 -14.33271,2.00392 z" id="path3059" style="fill:#6FD9FB;fill-opacity:1;stroke:none" inkscape:connector-curvature="0" /> </svg> 58 % RH</html>
2019.01.18 14:05:04.071 5: End notify loop for rg_Klima
2019.01.18 14:05:04.072 5: rg_battery: not on any display, ignoring notify
2019.01.18 14:05:04.080 5: End notify loop for HG_WK_TH_01
2019.01.18 14:05:04.110 5: Cmd: >jsonlist2 rg_Klima<
2019.01.18 14:05:04.817 5: JeeLink/RAW: /OK 9 28 1 4 98 60
2019.01.18 14:05:04.830 4: Connection accepted from telnetPort_127.0.0.1_37004
2019.01.18 14:05:04.831 5: Cmd: >jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector<
2019.01.18 14:05:04.972 5: YAMAHA_AVR (AV_Receiver) - set AV_Receiver ?
--- log skips 3.050 secs.
2019.01.18 14:05:08.022 5: ENIGMA2 VU: called function ENIGMA2_Set()
2019.01.18 14:05:08.024 5: ENIGMA2 VUDUO: called function ENIGMA2_Set()
2019.01.18 14:05:08.143 5: GEOFANCY geofancy: called function GEOFANCY_Set()
2019.01.18 14:05:08.161 5: myFreezemon Coming with command ?
2019.01.18 14:05:08.161 5: myFreezemon leaving with Unknown argument ?, choose one of active:noArg inactive:noArg clear:noArg
2019.01.18 14:05:08.242 1: [Freezemon] myFreezemon: Long running Command detected jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector:telnetPort - 3.410454 seconds
2019.01.18 14:05:08.319 1: [Freezemon] myFreezemon: Long function call detected ReadFn:telnetPort_127.0.0.1_37004 - 3.487755 seconds
2019.01.18 14:05:08.321 5: [Freezemon] myFreezemon: ----------- Starting Freeze handling at 2019.01.18 14:05:08.321 ---------------------
[Freezemon] myFreezemon: possible freeze starting at 14:05:05, delay is 3.321 possibly caused by: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_37004)
2019-01-18_14:06:07 myFreezemon s:14:06:05 e:14:06:07 f:2.757 d:cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_37140) tmr-SSCam_getsvsinfo(Foscam) tmr-SSCam_getstreamformat(Hikvision) tmr-SSCam_getcapabilities(Foscam) tmr-SSCam_getstreamformat(Foscam) tmr-SSCam_getsnapinfo(N/A) tmr-SSCam_getsnapinfo(N/A) tmr-SSCam_getptzlistpreset(Foscam) tmr-SSCam_getptzlistpatrol(Foscam)
2019-01-18_14:06:07 myFreezemon freezeTime: 2.757
2019-01-18_14:06:07 myFreezemon fcDay: 897
2019-01-18_14:06:07 myFreezemon ftDay: 2416.408
2019-01-18_14:06:07 myFreezemon freezeDevice: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_37140) tmr-SSCam_getsvsinfo(Foscam) tmr-SSCam_getstreamformat(Hikvision) tmr-SSCam_getcapabilities(Foscam) tmr-SSCam_getstreamformat(Foscam) tmr-SSCam_getsnapinfo(N/A) tmr-SSCam_getsnapinfo(N/A) tmr-SSCam_getptzlistpreset(Foscam) tmr-SSCam_getptzlistpatrol(Foscam)
=========================================================
[Freezemon] myFreezemon: possible freeze starting at 14:06:05, delay is 2.757 possibly caused by: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_37140) tmr-SSCam_getsvsinfo(Foscam) tmr-SSCam_getstreamformat(Hikvision) tmr-SSCam_getcapabilities(Foscam) tmr-SSCam_getstreamformat(Foscam) tmr-SSCam_getsnapinfo(N/A) tmr-SSCam_getsnapinfo(N/A) tmr-SSCam_getptzlistpreset(Foscam) tmr-SSCam_getptzlistpatrol(Foscam)
2019.01.18 14:06:04.241 4: http://192.168.1.82:5000/webapi/entry.cgi?api="SYNO.SurveillanceStation.Camera"&version="8"&method="GetInfo"&cameraIds="6"&deviceOutCap="true"&streamInfo="true"&ptz="true"&basic="true"&camAppInfo="true"&optimize="true"&fisheye="true"&eventDetection="true"&_&_sid="xxxxxxxxxxxxxxxxxxxxxxxx": HTTP response code 200
2019.01.18 14:06:04.241 5: HttpUtils http://192.168.1.82:5000/webapi/entry.cgi?api="SYNO.SurveillanceStation.Camera"&version="8"&method="GetInfo"&cameraIds="6"&deviceOutCap="true"&streamInfo="true"&ptz="true"&basic="true"&camAppInfo="true"&optimize="true"&fisheye="true"&eventDetection="true"&_&_sid="xxxxxxxxxxxxxxxxxxxxxxxx": Got data, length: 7251
2019.01.18 14:06:04.241 5: HttpUtils response header:
HTTP/1.1 200 OK
Server: nginx
Date: Fri, 18 Jan 2019 13:06:04 GMT
Content-Type: application/json; charset="UTF-8"
Connection: close
Vary: Accept-Encoding
X-Content-Type-Options: nosniff
X-XSS-Protection: 1; mode=block
Cache-Control: max-age=0, no-cache, no-store, must-revalidate
Pragma: no-cache
Expires: 0
2019.01.18 14:06:04.259 5: Foscam - JSON returned: $VAR1 = {
'success' => bless( do{\(my $o = 1)}, 'JSON::PP::Boolean' ),
.
.
.
2019.01.18 14:06:04.270 5: battStatus: not on any display, ignoring notify
2019.01.18 14:06:04.275 4: DbLog myDbLog -> ################################################################
2019.01.18 14:06:04.275 4: DbLog myDbLog -> ### start of new Logcycle ###
2019.01.18 14:06:04.275 4: DbLog myDbLog -> ################################################################
2019.01.18 14:06:04.275 4: DbLog myDbLog -> number of events received: 2 for device: Foscam
2019.01.18 14:06:04.275 4: DbLog myDbLog -> check Device: Foscam , Event: LastUpdateTime: 18.01.2019 / 14:06:04
2019.01.18 14:06:04.275 4: DbLog myDbLog -> check Device: Foscam , Event: UsedSpaceMB: 145.132
2019.01.18 14:06:04.279 5: rg_Cams: not on any display, ignoring notify
2019.01.18 14:06:04.279 5: rg_battery: not on any display, ignoring notify
2019.01.18 14:06:04.288 5: End notify loop for Foscam
2019.01.18 14:06:04.288 4: Foscam - Informations of camera Garten retrieved
2019.01.18 14:06:04.312 4: Connection accepted from telnetPort_127.0.0.1_37140
2019.01.18 14:06:04.313 5: Cmd: >jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector<
2019.01.18 14:06:04.451 5: YAMAHA_AVR (AV_Receiver) - set AV_Receiver ?
--- log skips 3.000 secs.
2019.01.18 14:06:07.450 5: ENIGMA2 VU: called function ENIGMA2_Set()
2019.01.18 14:06:07.453 5: ENIGMA2 VUDUO: called function ENIGMA2_Set()
2019.01.18 14:06:07.567 5: GEOFANCY geofancy: called function GEOFANCY_Set()
2019.01.18 14:06:07.585 5: myFreezemon Coming with command ?
2019.01.18 14:06:07.585 5: myFreezemon leaving with Unknown argument ?, choose one of active:noArg inactive:noArg clear:noArg
2019.01.18 14:06:07.669 1: [Freezemon] myFreezemon: Long running Command detected jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector:telnetPort - 3.356211 seconds
2019.01.18 14:06:07.752 1: [Freezemon] myFreezemon: Long function call detected ReadFn:telnetPort_127.0.0.1_37140 - 3.439358 seconds
2019.01.18 14:06:07.754 4: Foscam - ####################################################
2019.01.18 14:06:07.754 4: Foscam - ### start cam operation Getcapabilities
2019.01.18 14:06:07.754 4: Foscam - ####################################################
2019.01.18 14:06:07.754 4: Foscam - --- Begin Function SSCam_getapisites nonblocking ---
2019.01.18 14:06:07.754 4: Foscam - API hashvalues already set - ignore get apisites
2019.01.18 14:06:07.754 4: Foscam - --- Begin Function SSCam_getcamid nonblocking ---
2019.01.18 14:06:07.754 4: Foscam - CAMID already set - ignore get camid
2019.01.18 14:06:07.754 4: Foscam - --- Begin Function Getcapabilities nonblocking ---
2019.01.18 14:06:07.754 5: Foscam - HTTP-Call will be done with httptimeout-Value: 4 s
2019.01.18 14:06:07.754 4: Foscam - Call-Out now: http://192.168.1.82:5000/webapi/entry.cgi?api=SYNO.SurveillanceStation.Camera&version=8&method="GetCapabilityByCamId"&cameraId=6&_&_sid="xxxxxxxxxxxxxxxxxxxxxxxx"
2019.01.18 14:06:07.754 5: HttpUtils url=http://192.168.1.82:5000/webapi/entry.cgi?api=SYNO.SurveillanceStation.Camera&version=8&method="GetCapabilityByCamId"&cameraId=6&_&_sid="xxxxxxxxxxxxxxxxxxxxxxxx"
2019.01.18 14:06:07.755 4: IP: 192.168.1.82 -> 192.168.1.82
2019.01.18 14:06:07.757 5: [Freezemon] myFreezemon: ----------- Starting Freeze handling at 2019.01.18 14:06:07.757 ---------------------
[Freezemon] myFreezemon: possible freeze starting at 14:06:05, delay is 2.757 possibly caused by: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_37140) tmr-SSCam_getsvsinfo(Foscam) tmr-SSCam_getstreamformat(Hikvision) tmr-SSCam_getcapabilities(Foscam) tmr-SSCam_getstreamformat(Foscam) tmr-SSCam_getsnapinfo(N/A) tmr-SSCam_getsnapinfo(N/A) tmr-SSCam_getptzlistpreset(Foscam) tmr-SSCam_getptzlistpatrol(Foscam)
2019-01-18_14:07:07 myFreezemon s:14:07:05 e:14:07:07 f:2.758 d:cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_37304) tmr-CUL_HM_respPendTout(N/A)
2019-01-18_14:07:07 myFreezemon freezeTime: 2.758
2019-01-18_14:07:07 myFreezemon fcDay: 898
2019-01-18_14:07:07 myFreezemon ftDay: 2419.166
2019-01-18_14:07:07 myFreezemon freezeDevice: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_37304) tmr-CUL_HM_respPendTout(N/A)
=========================================================
[Freezemon] myFreezemon: possible freeze starting at 14:07:05, delay is 2.758 possibly caused by: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_37304) tmr-CUL_HM_respPendTout(N/A)
2019.01.18 14:07:04.272 4: CUL_HM_Resend: NG_MK_01 nr 4
2019.01.18 14:07:04.272 5: HMUARTLGW HmUART1 HMUARTLGW_Write: As0BE1A001272DDE5DC955010E
2019.01.18 14:07:04.273 5: HMUARTLGW HmUART1 send: 01 02 00 00 00 msg: E1 A0 01 272DDE 5DC955 010E
2019.01.18 14:07:04.273 5: HMUARTLGW HmUART1 send: (22): fd0011014902000000e1a001272dde5dc955010e23de
2019.01.18 14:07:04.273 5: SW: fd0011014902000000e1a001272dde5dc955010e23de
2019.01.18 14:07:04.300 5: HMUARTLGW HmUART3 read raw (8): fd001101b8050000
2019.01.18 14:07:04.300 5: HMUARTLGW HmUART2 read raw (16): fd0011013205000042e1a001272dde5d
2019.01.18 14:07:04.301 5: HMUARTLGW HmUART3 read raw (14): 57e1a001272dde5dc955010e5981
2019.01.18 14:07:04.301 5: HMUARTLGW HmUART3 read (21): fd001101b805000057e1a001272dde5dc955010e5981 crc OK
2019.01.18 14:07:04.301 5: HMUARTLGW HmUART3 recv: 01 05 00 00 57 msg: E1 A0 01 272DDE 5DC955 010E
2019.01.18 14:07:04.301 5: HMUARTLGW HmUART3 Dispatch: A0BE1A001272DDE5DC955010E::-87:HmUART3
2019.01.18 14:07:04.302 4: CUL_HM VCCU dupe: dont process
2019.01.18 14:07:04.303 5: HMUARTLGW HmUART2 read raw (6): c955010ea0cc
2019.01.18 14:07:04.303 5: HMUARTLGW HmUART2 read (21): fd0011013205000042e1a001272dde5dc955010ea0cc crc OK
2019.01.18 14:07:04.303 5: HMUARTLGW HmUART2 recv: 01 05 00 00 42 msg: E1 A0 01 272DDE 5DC955 010E
2019.01.18 14:07:04.303 5: HMUARTLGW HmUART2 Dispatch: A0BE1A001272DDE5DC955010E::-66:HmUART2
2019.01.18 14:07:04.304 4: CUL_HM VCCU dupe: dont process
2019.01.18 14:07:04.312 4: Connection accepted from telnetPort_127.0.0.1_37304
2019.01.18 14:07:04.314 5: Cmd: >jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector<
2019.01.18 14:07:04.450 5: YAMAHA_AVR (AV_Receiver) - set AV_Receiver ?
--- log skips 3.016 secs.
2019.01.18 14:07:07.466 5: ENIGMA2 VU: called function ENIGMA2_Set()
2019.01.18 14:07:07.468 5: ENIGMA2 VUDUO: called function ENIGMA2_Set()
2019.01.18 14:07:07.582 5: GEOFANCY geofancy: called function GEOFANCY_Set()
2019.01.18 14:07:07.600 5: myFreezemon Coming with command ?
2019.01.18 14:07:07.600 5: myFreezemon leaving with Unknown argument ?, choose one of active:noArg inactive:noArg clear:noArg
2019.01.18 14:07:07.681 1: [Freezemon] myFreezemon: Long running Command detected jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector:telnetPort - 3.367351 seconds
2019.01.18 14:07:07.757 1: [Freezemon] myFreezemon: Long function call detected ReadFn:telnetPort_127.0.0.1_37304 - 3.443215 seconds
2019.01.18 14:07:07.758 5: [Freezemon] myFreezemon: ----------- Starting Freeze handling at 2019.01.18 14:07:07.758 ---------------------
[Freezemon] myFreezemon: possible freeze starting at 14:07:05, delay is 2.758 possibly caused by: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_37304) tmr-CUL_HM_respPendTout(N/A)
2019-01-18_14:08:07 myFreezemon s:14:08:05 e:14:08:07 f:2.586 d:cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_37440) tmr-SSCam_getstreamformat(Hikvision) tmr-SSCam_getsnapinfo(N/A)
2019-01-18_14:08:07 myFreezemon freezeTime: 2.586
2019-01-18_14:08:07 myFreezemon fcDay: 899
2019-01-18_14:08:07 myFreezemon ftDay: 2421.752
2019-01-18_14:08:07 myFreezemon freezeDevice: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_37440) tmr-SSCam_getstreamformat(Hikvision) tmr-SSCam_getsnapinfo(N/A)
Die langen data-Blöcke der Kamera-Abfragen im Log mußte ich rausschneiden, weil sonst die code-Tags hier beim Senden verloren gehen, obwohl sie in der Vorschau angezeigt werden.
Mir ist die Zeile "X-XSS-Protection: 1; mode=block" bei den httputils-Aufrufen aufgefallen. Obwohl die Kameras zum Teil sehr viele Properties haben, denke ich, daß das SSCam Modul nicht für die freezes verantwortlich ist, weil die Poll-Intervalle auf 120 bzw. 240 gestellt sind.
Ich freue mich weiterhin über jeden Hinweis.
Danke und Gruß
Roland
Wie rufst Du denn die Kamera auf?
Mit Httpmod??
Dann hättest Du einen Kandidaten für Freez, es gibt ein "non-blocking-http"
Das macht das SSCam Modul, ich weiß nicht, wie das intern gelöst ist. Aber vielleicht stolpert Heiko (alias DS_Starter: Modulautor SSCam) über diesen thread und kann was dazu sagen. Aber wenn die Poll-Intervalle auf 120 bzw 240 stehen (Die Syno-API kann kein push), wäre es ein sehr großer Zufall, wenn bei drei Kameras exakt alle 60 Sekunden ein freeze ausgelöst wird.
Dann geh doch mal einen anderen Weg:
Was wird bei Dir alle Stunde aufgerufen?
Eine Stunde ist jetzt nicht gerade ein Wert, der in allen Modulen zu finden ist.
Das Intervall ist eine Minute. Ich habe nur ein einziges "at", das jede Minute aufgerufen wird:
Internals:
COMMAND {
# my $traffic = InternalVal("HMLAN1","msgLoadCurrent","???");
my $UART1traffic = InternalVal("HmUART1","msgLoadCurrent","???");
my $UART2traffic = InternalVal("HmUART2","msgLoadCurrent","???");
my $UART3traffic = InternalVal("HmUART3","msgLoadCurrent","???");
# fhem("setreading HMLAN1 hmTrf ".$traffic." %" );
fhem("setreading HmUART1 Uart1Trf ".$UART1traffic." %" );
fhem("setreading HmUART2 Uart2Trf ".$UART2traffic." %" );
fhem("setreading HmUART3 Uart3Trf ".$UART3traffic." %" );
}
DEF +*00:01:00 {
# my $traffic = InternalVal("HMLAN1","msgLoadCurrent","???");
my $UART1traffic = InternalVal("HmUART1","msgLoadCurrent","???");
my $UART2traffic = InternalVal("HmUART2","msgLoadCurrent","???");
my $UART3traffic = InternalVal("HmUART3","msgLoadCurrent","???");
# fhem("setreading HMLAN1 hmTrf ".$traffic." %" );
fhem("setreading HmUART1 Uart1Trf ".$UART1traffic." %" );
fhem("setreading HmUART2 Uart2Trf ".$UART2traffic." %" );
fhem("setreading HmUART3 Uart3Trf ".$UART3traffic." %" );
}
NAME a_hmlan_internals
NR 642
NTM 19:08:10
PERIODIC yes
RELATIVE yes
REP -1
STATE Next: 19:08:10
TIMESPEC 00:01:00
TRIGGERTIME 1547834890.29296
TRIGGERTIME_FMT 2019-01-18 19:08:10
TYPE at
READINGS:
2019-01-18 19:07:10 state Next: 19:08:10
helper:
bm:
at_Attr:
cnt 2
dmx -1000
dtot 0
dtotcnt 0
mTS 18.01. 18:42:30
max 0.0308651924133301
tot 0.0501031875610352
mAr:
set
a_hmlan_internals
disable
1
at_Set:
cnt 704
dmx -1000
dtot 0
dtotcnt 0
mTS 18.01. 14:32:10
max 0.000527858734130859
tot 0.0281474590301514
mAr:
HASH(a_hmlan_internals)
a_hmlan_internals
?
Attributes:
room Funktionen
Das macht aber keinen großartigen zeitfressenden Zauber. Das schreibt nur ein reading und ein FileLog für einen Plot zur Überwachung der Funklast. Den auskommentierten HMLAN habe ich aus dem System entfernt, weil der auf Grund der Situation andauernd auf "disconnect" ging.
Wenn ich das "a_hmlan_internals" auf disabled=1 setze, gehen die freezes aber zuverlässig weiter.
Ich fürchte daher, daß es sich um einen Modul- oder fhem-Internen Timer handelt, der zyklisch alle 60 Sekunden aufgerufen wird. Da fehlen mir leider die Kenntnisse zur weiteren Analyse.
Ich werde aber alle Hinweise verfolgen, so es in meiner Macht steht.
Gruß Roland
Guten Morgen zusammen,
hier ein aktueller Log-Auszug von freezemon.
Wenn man herausbekommen könnte, was der Logeintrag "telnetPort_127.0.0.1_xxxxx" ff. bedeutet und welche Routine das aufruft, sollte man doch den Verursacher ermitteln können, oder? Wie kann man dem beikommen? Kann man den fhem Prozess während der Laufzeit debuggen? Ein Blick auf htop zeigt IMMER genau kurz vor diesem (Log-)Zeitpunkt, daß der fhem Prozess einen CPU Core für die Dauer des freeze auf 100% zieht.
Ich habe derweil noch ein HueBridge device mit Interval=60 gefunden. Aber disable=1 darauf bewirkt ... keine Änderung der freezes :'(
roland@fhem-nuc:~$ tail -f /opt/fhem/log/fhem-2019-01.log -n 100|grep Freeze
2019.01.19 09:48:08.035 1: [Freezemon] myFreezemon: Long running Command detected jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector:telnetPort - 3.925146 seconds
2019.01.19 09:48:08.113 1: [Freezemon] myFreezemon: Long function call detected ReadFn:telnetPort_127.0.0.1_48322 - 4.002883 seconds
2019.01.19 09:48:08.115 1: [Freezemon] myFreezemon: possible freeze starting at 09:48:05, delay is 3.114 possibly caused by: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_48322)
2019.01.19 09:48:29.069 1: [Freezemon] myFreezemon: Long function call detected ReadFn:WEB_192.168.1.83_51075 - 0.887619 seconds
2019.01.19 09:49:08.018 1: [Freezemon] myFreezemon: Long running Command detected jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector:telnetPort - 3.484754 seconds
2019.01.19 09:49:08.094 1: [Freezemon] myFreezemon: Long function call detected ReadFn:telnetPort_127.0.0.1_48504 - 3.561685 seconds
2019.01.19 09:49:08.097 1: [Freezemon] myFreezemon: possible freeze starting at 09:49:05, delay is 3.096 possibly caused by: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_48504)
2019.01.19 09:50:09.399 1: [Freezemon] myFreezemon: Long running Command detected jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector:telnetPort - 3.495356 seconds
2019.01.19 09:50:09.476 1: [Freezemon] myFreezemon: Long function call detected ReadFn:telnetPort_127.0.0.1_48610 - 3.572047 seconds
2019.01.19 09:50:09.477 1: [Freezemon] myFreezemon: possible freeze starting at 09:50:06, delay is 3.477 possibly caused by: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_48610)
2019.01.19 09:51:07.750 1: [Freezemon] myFreezemon: Long running Command detected jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector:telnetPort - 3.503531 seconds
2019.01.19 09:51:07.826 1: [Freezemon] myFreezemon: Long function call detected ReadFn:telnetPort_127.0.0.1_48776 - 3.580046 seconds
2019.01.19 09:51:07.828 1: [Freezemon] myFreezemon: possible freeze starting at 09:51:05, delay is 2.827 possibly caused by: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_48776)
2019.01.19 09:52:07.705 1: [Freezemon] myFreezemon: Long running Command detected jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector:telnetPort - 3.48264 seconds
2019.01.19 09:52:07.781 1: [Freezemon] myFreezemon: Long function call detected ReadFn:telnetPort_127.0.0.1_48894 - 3.55872 seconds
2019.01.19 09:52:07.783 1: [Freezemon] myFreezemon: possible freeze starting at 09:52:05, delay is 2.783 possibly caused by: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_48894)
2019.01.19 09:53:07.524 1: [Freezemon] myFreezemon: Long running Command detected jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector:telnetPort - 3.473134 seconds
2019.01.19 09:53:07.600 1: [Freezemon] myFreezemon: Long function call detected ReadFn:telnetPort_127.0.0.1_49066 - 3.548868 seconds
2019.01.19 09:53:07.601 1: [Freezemon] myFreezemon: possible freeze starting at 09:53:05, delay is 2.601 possibly caused by: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_49066)
2019.01.19 09:54:07.649 1: [Freezemon] myFreezemon: Long running Command detected jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector:telnetPort - 3.472348 seconds
2019.01.19 09:54:07.733 1: [Freezemon] myFreezemon: Long function call detected ReadFn:telnetPort_127.0.0.1_49178 - 3.556689 seconds
2019.01.19 09:54:07.736 1: [Freezemon] myFreezemon: possible freeze starting at 09:54:05, delay is 2.735 possibly caused by: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_49178)
2019.01.19 09:55:08.367 1: [Freezemon] myFreezemon: Long running Command detected jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector:telnetPort - 3.480753 seconds
2019.01.19 09:55:08.445 1: [Freezemon] myFreezemon: Long function call detected ReadFn:telnetPort_127.0.0.1_49360 - 3.55863 seconds
2019.01.19 09:55:08.447 1: [Freezemon] myFreezemon: possible freeze starting at 09:55:05, delay is 3.446 possibly caused by: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_49360)
2019.01.19 09:55:18.505 1: [Freezemon] myFreezemon: Long function call detected ReadFn:HmUART3 - 0.975321 seconds
Schönen Gruß
Roland
Vielleicht mal ein anderer Ansatz - Hast du mal versucht mit grep o.ä. herauszufinden, ob irgendetwas auf deinem Rechner "jsonlist2" aufruft?
Ich habe noch nicht "außerhalb" von fhem gekuckt, weil der fhem Prozess exakt in diesem Intervall, zeitlich und von der Dauer korrespondierend einen CPU Kern auf 100% zieht.
Ich werde das aber morgen trotzdem nachholen, für heute bin ich platt.
Ich überlege sogar schon, ob ich in einer VM mal eine neue, frische fhem Instanz aufsetze und step by step umziehe. Aber das ist der letzte Strohhalm, mit 754 fhem devices bin ich da wahrscheinlich wochenlang beschäftigt, weil ich bei einem Umzug auch alle Abhängigkeiten (IOs, notifies, subs usw.) auflösen müßte.
Gruß Roland
Zitat von: hauwech am 19 Januar 2019, 21:21:30
Ich habe noch nicht "außerhalb" von fhem gekuckt, weil der fhem Prozess exakt in diesem Intervall, zeitlich und von der Dauer korrespondierend einen CPU Kern auf 100% zieht.
Das heißt ja nicht, dass nicht der FHEM-Prozess "von außen" ausgelöst werden könnte. Irgendein Amok laufendes Siri-Skript o.ä.
Danke, dem Gedanken gehe ich mal nach. Die einzige Instanz, die - für mich bewußt - von außen auf fhem zugreift, ist der IOBroker Adapter. Den hatte ich im Verlauf der Fehlersuche als Verdächtigen schon mal deaktiviert, die Freezes laufen weiter. Ich habe es eben nochmal gegengecheckt: IOBroker fhem Adapter aus -> freezes laufen zuverlässig weiter.
Ich teste - leider erste heute abend - die restlichen Kandidaten Alexa, HueBridge, Harmony... Da könnten möglicherweise Prozesse laufen, die in fhem etwas triggern, auch wenn meine Vorstellung, was da abgeht, nur sehr vage ist. Die hat aber mein Kumpel und Kollege auch alle am Laufen - und der hat keine Freezes.
Das bringt mich auf den nächsten Gedanken: Wir werden mal abgleichen, welche Module ich laufen habe, die er nicht im Einsatz hat.
Gruß Roland
Edit: Gerade mal geschaut, minütliche cron Jobs gibts auch nicht...
Ich hatte leider das ganze Wochenende keine Zeit zum Weitersuchen.
Ich habe heute alle meine eigenen 99_myUtils... rausgeschmissen, fhem neu gestartet -> freezes kommen zuverlässig in der erwarteten Sekunde.
Dann habe ich der Reihe nach (nicht gleichzeitig) die Devices der Module ProPlanta, Pollenflug, Alexa, Hue, Harmony und HMCCU disabled und jeweils mind. 3 Minuten gewartet.
Völlig egal: die freezes kommen exakt alle 60 Sekunden.
Ich habe mir auf meiner Syno neben dem normalen Backup noch einen rsync Spiegel des fhem-Verzeichnisses angelegt. Dort suche ich derzeit nach den strings "telnetPort" und "jsonlist2", um vielleicht über Fundstellen im Code Erkenntnisse zu gewinnen. Da ich kein Perl-Experte bin, würde ich mich über Eure Hilfe freuen, wenn's soweit ist.
Der Abgleich der fhem Instanzen mit meinem Kollegen hat ergeben, daß er außer Pollenflug und ProPlanta auch alles auf einem Zotac am Laufen hat - ohne nennenswerte oder gar zyklische freezes.
Nachdem ich nun alle devices der Module, die nach meiner bescheidenen Ansicht in Frage kommen _könnten_, schon mal disabled hatte, frage ich mich:
Wird bei disabled=1 tatsächlich die Tätigkeit des Moduls/devices eingestellt, oder sind die vielleicht trotzdem noch (teil-?)aktiv?
Oder anders gefragt:
Kann ich mit dem "Disablen" eines devices erwarten, daß eventuell vom Modul dieses devices generierte freezes ausbleiben?
Gruß Roland
Mal ein Lösungsansatz von mir - der sich mit Deinem durchaus deckt und mir letztendlich geholfen hat, freezefrei zu werden:
1. Apptime nochmal neu starten und ~alle 60 sec. aufrufen. Schauen, welche Einträge ebenfalls im Minutentakt Last erzeugen
2. Ich habe bei mir am Ende alle (!!) Devices gelöscht - auch welche, von denen ich ausging, dass sie es nicht sein können.
Was ich dabei gelernt habe:
a) XBMC sollte unbedingt mit "fork = enable" betrieben werden...
b) Selbst bei einer umfangreichen FHEM-Installation geht das löschen der Devices schnell, sofern man eine gute Sicherung der cfg (oder configdb) verwendet.
Ich habe in der Tat nach zögerlichem Beginn ganze "Räume" gelöscht. Angefangen mit der gesamten Fußbodenheizung, dann sämtliche Rollladen usw, dann die jeweiligen Interfaces... Um am Ende bei einem Device zu landen, das in "unsorted" vor sich hinvegetierte und das ich mal zu Testzwecken angelegt hatte.
Seitdem ist mein FHEm Freeze-Frei - mit einer Ausnahme, die ich aber nur zu gut kenne und toleriere.
HTH Tom
Uiuiuiui, das kommt doch einem Neuanfang gleich, oder?
Das Löschen eines devices geht freilich schnell, aber die Neuanlage inkl. Auflösung aller Abhängigkeiten, subs, notifies, doif's, die ganzen Schaltlogiken...?
Oder hast Du alles rausgeschmissen und dann die Definitionen direkt wieder in die fhem.cfg kopiert?
Ich fürchte, für eine so radikale Lösung müßte ich drei Wochen Urlaub nehmen.
Ich hoffe immer noch, den - für mich - rätselhaften telnet- und jsonlist2-Aufrufen auf die Schliche zu kommen. Parallel dazu gehe ich mal den unsorted room durch, da gibt's bestimmt Potential zum Aufräumen. Mal sehen, wann der Verzweiflungslevel eine Radikallösung weiter in den Fokus rückt.
Gruß Roland
Mach dir doch ein Backup, lösch dann nach und nach alles raus was dir verdächtig erscheint und spiele hinterher das Backup wieder ein, um den Ursprungszustand zu erhalten.
Radikal - vielleicht. Neuanfang: Nein.
Wie mumpitzstuff geschrieben hat: Dazu gibt es doch das Backup.
Ich habe halt "nie" beim Löschen auf "SAVE" gedrückt - somit kein Problem. Darüberhinaus verwende ich configDB - aber das sollte keinen Unterschied machen. Die fhem.cfg editiere ich nie (habe ich nie gemacht), auch nie was reinkopiert. Da nähme ich dann einfach das Backup, dazu ist es ja da.
Der ganze Spaß hat bei mir vielleicht zwei Stunden gedauert - und ich behaupte jetzt mal, dass ich eine mittelgroße Installation habe.
Bei spaßeshalber: Gerade mal ein find -type f | xargs fgrep jsonlist2|less
im FHEM-Verzeichnis gemacht, um alle Vorkommnisse von jsonlist2 zu entdecken. Vielleicht ist das ja auch ein Ansatzpunkt.
Aber wie gesagt: Meine Freezes waren in einer guten Stunde identifiziert. Und den Tipp mit Apptime nicht vergessen, irgendwann taucht der Freeze dort genau richtig auf... Muss ja ein Eintrag sein, der minütlich hochzählt!
Gruß, Tom
Hallo Tom,
der Tip mit dem minütlichen apptime Aufruf war gut. Ich habe jetzt 4x kurz nach dem Freeze-Log-Eintrag "apptime count" aufgerufen. Auf den ersten Blick habe ich möglicherweise Verursacher eingefangen. Hier tauchen zumindest die telnet-Aufrufe auf. Was ich aber nicht verstehe: Laut apptime haben 0.00 delay-Werte??? Ich kriege die Ergebnisse von freezemon und apptime nicht übereinander. Minütlich zählen die aber auch nicht hoch, das sind ja ~500 calls pro Minute.
Eigentlich möchte ich auf die allowed-devices nicht verzichten. Ich habe die drei Kandidaten temporär disabled, aber an den freezes ändert sich nix.
Hier der apptime output:
name function max count total average maxDly avgDly TS Max call param Max call
allowedWEBhook allowed_Authorize 0 514 6.00 0.01 0.00 0.00 22.01. 09:52:25 HASH(allowedWEBhook); HASH(telnetPort_127.0.0.1_55220); cmd; perl
allowed_WEB allowed_Authorize 0 514 5.43 0.01 0.00 0.00 22.01. 09:53:24 HASH(allowed_WEB); HASH(WEB_88.xxx.xxx.xxx_59372); cmd; apptime
allowed_WEBphone allowed_Authorize 0 514 5.45 0.01 0.00 0.00 22.01. 09:53:19 HASH(allowed_WEBphone); HASH(telnetPort_127.0.0.1_55350); devicename; HG_FL_Muell
allowed_WEBtablet allowed_Authorize 0 514 5.40 0.01 0.00 0.00 22.01. 09:53:24 HASH(allowed_WEBtablet); HASH(WEB_88.xxx.xxx.xxx_59372); cmd; apptime
CUL433 CUL_Ready 2 504 82.05 0.16 0.00 0.00 22.01. 09:53:19 HASH(CUL433)
Activity_chk notify_Exec 1 149 41.47 0.28 0.00 0.00 22.01. 09:52:52 HASH(Activity_chk); HASH(HG_BM_IT_01)
AlleFenster structure_Notify 0 149 6.51 0.04 0.00 0.00 22.01. 09:53:13 HASH(AlleFenster); HASH(rg_AnnaG)
AlleTueren structure_Notify 0 149 5.13 0.03 0.00 0.00 22.01. 09:52:47 HASH(AlleTueren); HASH(Foscam)
Bewegungsmelder structure_Notify 0 149 2.88 0.02 0.00 0.00 22.01. 09:53:13 HASH(Bewegungsmelder); HASH(heatingInfo)
Bozena_Laptop fronthemDevice_Notify 0 149 6.23 0.04 0.00 0.00 22.01. 09:52:52 HASH(Bozena_Laptop); HASH(Foscam)
Desktop fronthemDevice_Notify 0 149 4.88 0.03 0.00 0.00 22.01. 09:52:41 HASH(Desktop); HASH(HG_AZ_TH_01)
FileLog_BadLuefter FileLog_Log 2 149 27.45 0.18 0.00 0.00 22.01. 09:52:42 HASH(FileLog_BadLuefter); HASH(rg_Bewohner)
FileLog_HG_WZ_Fenster_neu FileLog_Log 0 149 20.07 0.13 0.00 0.00 22.01. 09:53:16 HASH(FileLog_HG_WZ_Fenster_neu); HASH(NG_CP_TH_01)
FileLog_HM_4423F3 FileLog_Log 0 149 18.97 0.13 0.00 0.00 22.01. 09:53:11 HASH(FileLog_HM_4423F3); HASH(myDbLog)
FileLog_HM_568966 FileLog_Log 0 149 18.29 0.12 0.00 0.00 22.01. 09:52:54 HASH(FileLog_HM_568966); HASH(rr_Roland)
FileLog_IT_00F000FFFF FileLog_Log 0 149 18.51 0.12 0.00 0.00 22.01. 09:52:48 HASH(FileLog_IT_00F000FFFF); HASH(Foscam)
FileLog_IT_0F0F0FFF0F FileLog_Log 0 149 18.23 0.12 0.00 0.00 22.01. 09:52:52 HASH(FileLog_IT_0F0F0FFF0F); HASH(HG_BM_IT_01)
FileLog_IT_0F0F0FFFFF FileLog_Log 0 149 17.91 0.12 0.00 0.00 22.01. 09:53:15 HASH(FileLog_IT_0F0F0FFFFF); HASH(HG_KT_TH_01)
HM HMinfo_Notify 0 149 2.29 0.02 0.00 0.00 22.01. 09:52:52 HASH(HM); HASH(Foscam)
HV fronthemDevice_Notify 0 149 4.93 0.03 0.00 0.00 22.01. 09:52:53 HASH(HV); HASH(HG_TH_TH_01)
Handy_VPN fronthemDevice_Notify 0 149 4.12 0.03 0.00 0.00 22.01. 09:52:53 HASH(Handy_VPN); HASH(HG_TH_TH_01)
Heizungswerte readingsGroup_Notify 0 149 15.60 0.10 0.00 0.00 22.01. 09:52:52 HASH(Heizungswerte); HASH(HG_BM_IT_01)
Laptop fronthemDevice_Notify 0 149 4.52 0.03 0.00 0.00 22.01. 09:53:11 HASH(Laptop); HASH(myDbLog)
LaptopRemote fronthemDevice_Notify 0 149 4.50 0.03 0.00 0.00 22.01. 09:52:52 HASH(LaptopRemote); HASH(Foscam)
Logfile FileLog_Log 0 149 17.76 0.12 0.00 0.00 22.01. 09:53:16 HASH(Logfile); HASH(NG_CP_TH_01)
Luftfeuchte readingsGroup_Notify 1 149 10.73 0.07 0.00 0.00 22.01. 09:52:33 HASH(Luftfeuchte); HASH(heatingInfo)
N308 fronthemDevice_Notify 0 149 4.90 0.03 0.00 0.00 22.01. 09:52:42 HASH(N308); HASH(rg_Bewohner)
Tab fronthemDevice_Notify 0 149 4.06 0.03 0.00 0.00 22.01. 09:53:11 HASH(Tab); HASH(myDbLog)
Termin_Alarm notify_Exec 1 149 31.51 0.21 0.00 0.00 22.01. 09:52:52 HASH(Termin_Alarm); HASH(HG_BM_IT_01)
Termin_Ende notify_Exec 0 149 26.06 0.17 0.00 0.00 22.01. 09:53:13 HASH(Termin_Ende); HASH(HG_BM_IT_01)
Termin_Loeschen notify_Exec 0 149 24.98 0.17 0.00 0.00 22.01. 09:52:52 HASH(Termin_Loeschen); HASH(HG_BM_IT_01)
Termin_Start notify_Exec 1 149 25.15 0.17 0.00 0.00 22.01. 09:52:52 HASH(Termin_Start); HASH(HG_BM_IT_01)
VURG readingsGroup_Notify 0 149 8.91 0.06 0.00 0.00 22.01. 09:52:57 HASH(VURG); HASH(UnifiController)
WEB FW_Notify 0 149 1.84 0.01 0.00 0.00 22.01. 09:53:22 HASH(WEB); HASH(HG_BM_IT_01)
WEB_127.0.0.1_33816 FW_Notify 21 149 475.56 3.19 0.00 0.00 22.01. 09:52:35 HASH(WEB_127.0.0.1_33816); HASH(HG_WZ_HZ_WT_Weather)
WEB_88.xxx.xxx.xxx__58755 FW_Notify 1 149 4.22 0.03 0.00 0.00 22.01. 09:52:49 HASH(WEB_88.xxx.xxx.xxx_58755); HASH(rg_Bewohner)
WEBhabridge FW_Notify 0 149 1.08 0.01 0.00 0.00 22.01. 09:52:45 HASH(WEBhabridge); HASH(HG_TH_TH_01)
WEBhook FW_Notify 0 149 1.01 0.01 0.00 0.00 22.01. 09:52:48 HASH(WEBhook); HASH(Foscam)
WEBphone FW_Notify 0 149 1.06 0.01 0.00 0.00 22.01. 09:52:52 HASH(WEBphone); HASH(Foscam)
WEBtablet FW_Notify 0 149 1.12 0.01 0.00 0.00 22.01. 09:52:53 HASH(WEBtablet); HASH(HG_TH_TH_01)
_SmartVisuHandy fronthemDevice_Notify 0 149 4.33 0.03 0.00 0.00 22.01. 09:53:00 HASH(_SmartVisuHandy); HASH(TempSens2_T2)
name function max count total average maxDly avgDly TS Max call param Max call
CUL433 CUL_Ready 2 1058 178.46 0.17 0.00 0.00 22.01. 09:54:19 HASH(CUL433)
allowedWEBhook allowed_Authorize 0 1025 12.09 0.01 0.00 0.00 22.01. 09:52:25 HASH(allowedWEBhook); HASH(telnetPort_127.0.0.1_55220); cmd; perl
allowed_WEB allowed_Authorize 0 1025 10.94 0.01 0.00 0.00 22.01. 09:54:25 HASH(allowed_WEB); HASH(WEB_88.xxx.xxx.xxx__59372); cmd; apptime
allowed_WEBphone allowed_Authorize 0 1025 10.95 0.01 0.00 0.00 22.01. 09:54:25 HASH(allowed_WEBphone); HASH(WEB_88.xxx.xxx.xxx__59372); cmd; apptime
allowed_WEBtablet allowed_Authorize 0 1025 10.86 0.01 0.00 0.00 22.01. 09:54:19 HASH(allowed_WEBtablet); HASH(telnetPort_127.0.0.1_55518); devicename; HG_GWC_Fenster
Activity_chk notify_Exec 1 289 73.50 0.25 0.00 0.00 22.01. 09:52:52 HASH(Activity_chk); HASH(HG_BM_IT_01)
AlleFenster structure_Notify 0 289 12.49 0.04 0.00 0.00 22.01. 09:53:13 HASH(AlleFenster); HASH(rg_AnnaG)
AlleTueren structure_Notify 0 289 9.60 0.03 0.00 0.00 22.01. 09:52:47 HASH(AlleTueren); HASH(Foscam)
Bewegungsmelder structure_Notify 0 289 5.31 0.02 0.00 0.00 22.01. 09:53:13 HASH(Bewegungsmelder); HASH(heatingInfo)
Bozena_Laptop fronthemDevice_Notify 0 289 11.58 0.04 0.00 0.00 22.01. 09:52:52 HASH(Bozena_Laptop); HASH(Foscam)
Desktop fronthemDevice_Notify 0 289 9.10 0.03 0.00 0.00 22.01. 09:52:41 HASH(Desktop); HASH(HG_AZ_TH_01)
FileLog_BadLuefter FileLog_Log 2 289 48.75 0.17 0.00 0.00 22.01. 09:52:42 HASH(FileLog_BadLuefter); HASH(rg_Bewohner)
FileLog_HG_WZ_Fenster_neu FileLog_Log 0 289 37.72 0.13 0.00 0.00 22.01. 09:53:16 HASH(FileLog_HG_WZ_Fenster_neu); HASH(NG_CP_TH_01)
FileLog_HM_4423F3 FileLog_Log 0 289 35.81 0.12 0.00 0.00 22.01. 09:53:45 HASH(FileLog_HM_4423F3); HASH(HG_TH_TH_01)
FileLog_HM_568966 FileLog_Log 0 289 34.95 0.12 0.00 0.00 22.01. 09:52:54 HASH(FileLog_HM_568966); HASH(rr_Roland)
FileLog_IT_00F000FFFF FileLog_Log 0 289 35.24 0.12 0.00 0.00 22.01. 09:52:48 HASH(FileLog_IT_00F000FFFF); HASH(Foscam)
FileLog_IT_0F0F0FFF0F FileLog_Log 0 289 35.43 0.12 0.00 0.00 22.01. 09:52:52 HASH(FileLog_IT_0F0F0FFF0F); HASH(HG_BM_IT_01)
FileLog_IT_0F0F0FFFFF FileLog_Log 0 289 34.06 0.12 0.00 0.00 22.01. 09:53:45 HASH(FileLog_IT_0F0F0FFFFF); HASH(HG_TH_TH_01)
HM HMinfo_Notify 0 289 4.34 0.02 0.00 0.00 22.01. 09:53:48 HASH(HM); HASH(Foscam)
HV fronthemDevice_Notify 0 289 9.25 0.03 0.00 0.00 22.01. 09:53:45 HASH(HV); HASH(HG_TH_TH_01)
Handy_VPN fronthemDevice_Notify 0 289 7.90 0.03 0.00 0.00 22.01. 09:54:04 HASH(Handy_VPN); HASH(HG_TR_TH_01)
Heizungswerte readingsGroup_Notify 12 289 40.88 0.14 0.00 0.00 22.01. 09:53:26 HASH(Heizungswerte); HASH(NG_BZ_HZ)
Laptop fronthemDevice_Notify 0 289 8.56 0.03 0.00 0.00 22.01. 09:54:04 HASH(Laptop); HASH(HG_TR_TH_01)
LaptopRemote fronthemDevice_Notify 0 289 8.60 0.03 0.00 0.00 22.01. 09:52:52 HASH(LaptopRemote); HASH(Foscam)
Logfile FileLog_Log 0 289 33.60 0.12 0.00 0.00 22.01. 09:53:16 HASH(Logfile); HASH(NG_CP_TH_01)
Luftfeuchte readingsGroup_Notify 1 289 18.79 0.07 0.00 0.00 22.01. 09:52:33 HASH(Luftfeuchte); HASH(heatingInfo)
N308 fronthemDevice_Notify 0 289 8.90 0.03 0.00 0.00 22.01. 09:52:42 HASH(N308); HASH(rg_Bewohner)
Tab fronthemDevice_Notify 0 289 7.62 0.03 0.00 0.00 22.01. 09:53:11 HASH(Tab); HASH(myDbLog)
Termin_Alarm notify_Exec 1 289 55.65 0.19 0.00 0.00 22.01. 09:52:52 HASH(Termin_Alarm); HASH(HG_BM_IT_01)
Termin_Ende notify_Exec 0 289 46.38 0.16 0.00 0.00 22.01. 09:53:13 HASH(Termin_Ende); HASH(HG_BM_IT_01)
Termin_Loeschen notify_Exec 0 289 44.95 0.16 0.00 0.00 22.01. 09:52:52 HASH(Termin_Loeschen); HASH(HG_BM_IT_01)
Termin_Start notify_Exec 1 289 44.76 0.15 0.00 0.00 22.01. 09:52:52 HASH(Termin_Start); HASH(HG_BM_IT_01)
VURG readingsGroup_Notify 0 289 17.27 0.06 0.00 0.00 22.01. 09:53:37 HASH(VURG); HASH(PWR_SW_1_Pwr)
WEB FW_Notify 0 289 3.53 0.01 0.00 0.00 22.01. 09:53:22 HASH(WEB); HASH(HG_BM_IT_01)
WEB_127.0.0.1_33816 FW_Notify 21 289 971.28 3.36 0.00 0.00 22.01. 09:52:35 HASH(WEB_127.0.0.1_33816); HASH(HG_WZ_HZ_WT_Weather)
WEB_88.xxx.xxx.xxx_58755 FW_Notify 1 289 6.61 0.02 0.00 0.00 22.01. 09:52:49 HASH(WEB_88.xxx.xxx.xxx_58755); HASH(rg_Bewohner)
WEBhabridge FW_Notify 0 289 2.05 0.01 0.00 0.00 22.01. 09:52:45 HASH(WEBhabridge); HASH(HG_TH_TH_01)
WEBhook FW_Notify 0 289 1.93 0.01 0.00 0.00 22.01. 09:53:41 HASH(WEBhook); HASH(myDbLog)
WEBphone FW_Notify 0 289 1.99 0.01 0.00 0.00 22.01. 09:52:52 HASH(WEBphone); HASH(Foscam)
WEBtablet FW_Notify 0 289 2.11 0.01 0.00 0.00 22.01. 09:52:53 HASH(WEBtablet); HASH(HG_TH_TH_01)
_SmartVisuHandy fronthemDevice_Notify 0 289 8.33 0.03 0.00 0.00 22.01. 09:53:37 HASH(_SmartVisuHandy); HASH(PWR_SW_1_Pwr)
name function max count total average maxDly avgDly TS Max call param Max call
allowedWEBhook allowed_Authorize 0 1533 18.05 0.01 0.00 0.00 22.01. 09:52:25 HASH(allowedWEBhook); HASH(telnetPort_127.0.0.1_55220); cmd; perl
allowed_WEB allowed_Authorize 0 1533 16.46 0.01 0.00 0.00 22.01. 09:55:24 HASH(allowed_WEB); HASH(WEB_88.xxx.xxx.xxx_59372); cmd; apptime
allowed_WEBphone allowed_Authorize 0 1533 16.40 0.01 0.00 0.00 22.01. 09:55:24 HASH(allowed_WEBphone); HASH(WEB_88.xxx.xxx.xxx_59372); cmd; apptime
allowed_WEBtablet allowed_Authorize 0 1533 16.28 0.01 0.00 0.00 22.01. 09:55:24 HASH(allowed_WEBtablet); HASH(WEB_88.xxx.xxx.xxx_59372); cmd; apptime
CUL433 CUL_Ready 2 1496 248.55 0.17 0.00 0.00 22.01. 09:54:19 HASH(CUL433)
Activity_chk notify_Exec 2 489 128.22 0.26 0.00 0.00 22.01. 09:55:07 HASH(Activity_chk); HASH(HG_BM_IT_01)
AlleFenster structure_Notify 0 489 21.18 0.04 0.00 0.00 22.01. 09:53:13 HASH(AlleFenster); HASH(rg_AnnaG)
AlleTueren structure_Notify 0 489 16.61 0.03 0.00 0.00 22.01. 09:54:34 HASH(AlleTueren); HASH(HG_TR_TH_01)
Bewegungsmelder structure_Notify 0 489 9.14 0.02 0.00 0.00 22.01. 09:54:56 HASH(Bewegungsmelder); HASH(HmUART1)
Bozena_Laptop fronthemDevice_Notify 0 489 19.90 0.04 0.00 0.00 22.01. 09:52:52 HASH(Bozena_Laptop); HASH(Foscam)
Desktop fronthemDevice_Notify 0 489 15.76 0.03 0.00 0.00 22.01. 09:55:08 HASH(Desktop); HASH(Foscam)
FileLog_BadLuefter FileLog_Log 2 489 82.64 0.17 0.00 0.00 22.01. 09:52:42 HASH(FileLog_BadLuefter); HASH(rg_Bewohner)
FileLog_HG_WZ_Fenster_neu FileLog_Log 0 489 64.92 0.13 0.00 0.00 22.01. 09:55:00 HASH(FileLog_HG_WZ_Fenster_neu); HASH(HG_KT_TH_01)
FileLog_HM_4423F3 FileLog_Log 0 489 61.08 0.12 0.00 0.00 22.01. 09:53:45 HASH(FileLog_HM_4423F3); HASH(HG_TH_TH_01)
FileLog_HM_568966 FileLog_Log 0 489 60.22 0.12 0.00 0.00 22.01. 09:52:54 HASH(FileLog_HM_568966); HASH(rr_Roland)
FileLog_IT_00F000FFFF FileLog_Log 0 489 60.06 0.12 0.00 0.00 22.01. 09:54:49 HASH(FileLog_IT_00F000FFFF); HASH(rr_Bozena)
FileLog_IT_0F0F0FFF0F FileLog_Log 0 489 60.43 0.12 0.00 0.00 22.01. 09:55:11 HASH(FileLog_IT_0F0F0FFF0F); HASH(HG_BM_IT_01)
FileLog_IT_0F0F0FFFFF FileLog_Log 0 489 58.10 0.12 0.00 0.00 22.01. 09:55:10 HASH(FileLog_IT_0F0F0FFFFF); HASH(Foscam)
HM HMinfo_Notify 0 489 7.34 0.02 0.00 0.00 22.01. 09:55:23 HASH(HM); HASH(NG_CP_TH_01)
HV fronthemDevice_Notify 0 489 15.78 0.03 0.00 0.00 22.01. 09:55:09 HASH(HV); HASH(Foscam)
Handy_VPN fronthemDevice_Notify 0 489 13.29 0.03 0.00 0.00 22.01. 09:54:04 HASH(Handy_VPN); HASH(HG_TR_TH_01)
Heizungswerte readingsGroup_Notify 12 489 61.54 0.13 0.00 0.00 22.01. 09:53:26 HASH(Heizungswerte); HASH(NG_BZ_HZ)
Laptop fronthemDevice_Notify 0 489 14.39 0.03 0.00 0.00 22.01. 09:54:04 HASH(Laptop); HASH(HG_TR_TH_01)
LaptopRemote fronthemDevice_Notify 0 489 14.34 0.03 0.00 0.00 22.01. 09:52:52 HASH(LaptopRemote); HASH(Foscam)
Logfile FileLog_Log 0 489 57.02 0.12 0.00 0.00 22.01. 09:54:49 HASH(Logfile); HASH(rr_Bozena)
Luftfeuchte readingsGroup_Notify 1 489 30.32 0.06 0.00 0.00 22.01. 09:52:33 HASH(Luftfeuchte); HASH(heatingInfo)
N308 fronthemDevice_Notify 0 489 14.64 0.03 0.00 0.00 22.01. 09:52:42 HASH(N308); HASH(rg_Bewohner)
Tab fronthemDevice_Notify 0 489 12.96 0.03 0.00 0.00 22.01. 09:53:11 HASH(Tab); HASH(myDbLog)
Termin_Alarm notify_Exec 1 489 95.48 0.20 0.00 0.00 22.01. 09:55:11 HASH(Termin_Alarm); HASH(HG_BM_IT_01)
Termin_Ende notify_Exec 1 489 79.49 0.16 0.00 0.00 22.01. 09:55:11 HASH(Termin_Ende); HASH(HG_BM_IT_01)
Termin_Loeschen notify_Exec 0 489 77.34 0.16 0.00 0.00 22.01. 09:52:52 HASH(Termin_Loeschen); HASH(HG_BM_IT_01)
Termin_Start notify_Exec 1 489 76.68 0.16 0.00 0.00 22.01. 09:52:52 HASH(Termin_Start); HASH(HG_BM_IT_01)
VURG readingsGroup_Notify 0 489 29.30 0.06 0.00 0.00 22.01. 09:53:37 HASH(VURG); HASH(PWR_SW_1_Pwr)
WEB FW_Notify 0 489 6.07 0.01 0.00 0.00 22.01. 09:54:47 HASH(WEB); HASH(rg_Klima)
WEB_127.0.0.1_33816 FW_Notify 21 489 1477.78 3.02 0.00 0.00 22.01. 09:52:35 HASH(WEB_127.0.0.1_33816); HASH(HG_WZ_HZ_WT_Weather)
WEBhabridge FW_Notify 0 489 3.46 0.01 0.00 0.00 22.01. 09:52:45 HASH(WEBhabridge); HASH(HG_TH_TH_01)
WEBhook FW_Notify 0 489 3.26 0.01 0.00 0.00 22.01. 09:55:01 HASH(WEBhook); HASH(Foscam)
WEBphone FW_Notify 0 489 3.38 0.01 0.00 0.00 22.01. 09:52:52 HASH(WEBphone); HASH(Foscam)
WEBtablet FW_Notify 0 489 3.57 0.01 0.00 0.00 22.01. 09:52:53 HASH(WEBtablet); HASH(HG_TH_TH_01)
_SmartVisuHandy fronthemDevice_Notify 0 489 14.07 0.03 0.00 0.00 22.01. 09:53:37 HASH(_SmartVisuHandy); HASH(PWR_SW_1_Pwr)
alarm0.on.N notify_Exec 6 489 256.76 0.53 0.00 0.00 22.01. 09:53:27 HASH(alarm0.on.N); HASH(heatingInfo)
name function max count total average maxDly avgDly TS Max call param Max call
allowedWEBhook allowed_Authorize 0 2047 24.26 0.01 0.00 0.00 22.01. 09:55:26 HASH(allowedWEBhook); HASH(telnetPort_127.0.0.1_55644); cmd; perl
allowed_WEB allowed_Authorize 0 2047 22.08 0.01 0.00 0.00 22.01. 09:55:24 HASH(allowed_WEB); HASH(WEB_88.xxx.xxx.xxx_59372); cmd; apptime
allowed_WEBphone allowed_Authorize 0 2047 21.93 0.01 0.00 0.00 22.01. 09:55:24 HASH(allowed_WEBphone); HASH(WEB_88.xxx.xxx.xxx_59372); cmd; apptime
allowed_WEBtablet allowed_Authorize 0 2047 21.72 0.01 0.00 0.00 22.01. 09:55:24 HASH(allowed_WEBtablet); HASH(WEB_88.xxx.xxx.xxx_59372); cmd; apptime
CUL433 CUL_Ready 4 2034 348.59 0.17 0.00 0.00 22.01. 09:56:19 HASH(CUL433)
Activity_chk notify_Exec 2 640 165.90 0.26 0.00 0.00 22.01. 09:55:07 HASH(Activity_chk); HASH(HG_BM_IT_01)
AlleFenster structure_Notify 0 640 27.49 0.04 0.00 0.00 22.01. 09:53:13 HASH(AlleFenster); HASH(rg_AnnaG)
AlleTueren structure_Notify 0 640 21.80 0.03 0.00 0.00 22.01. 09:55:40 HASH(AlleTueren); HASH(Foscam)
Bewegungsmelder structure_Notify 0 640 11.91 0.02 0.00 0.00 22.01. 09:54:56 HASH(Bewegungsmelder); HASH(HmUART1)
Bozena_Laptop fronthemDevice_Notify 0 640 25.89 0.04 0.00 0.00 22.01. 09:55:26 HASH(Bozena_Laptop); HASH(HG_TH_TH_01)
Desktop fronthemDevice_Notify 0 640 20.27 0.03 0.00 0.00 22.01. 09:55:08 HASH(Desktop); HASH(Foscam)
FileLog_BadLuefter FileLog_Log 2 640 106.57 0.17 0.00 0.00 22.01. 09:52:42 HASH(FileLog_BadLuefter); HASH(rg_Bewohner)
FileLog_HG_WZ_Fenster_neu FileLog_Log 0 640 84.60 0.13 0.00 0.00 22.01. 09:55:00 HASH(FileLog_HG_WZ_Fenster_neu); HASH(HG_KT_TH_01)
FileLog_HM_4423F3 FileLog_Log 0 640 79.60 0.12 0.00 0.00 22.01. 09:53:45 HASH(FileLog_HM_4423F3); HASH(HG_TH_TH_01)
FileLog_HM_568966 FileLog_Log 0 640 78.46 0.12 0.00 0.00 22.01. 09:52:54 HASH(FileLog_HM_568966); HASH(rr_Roland)
FileLog_IT_00F000FFFF FileLog_Log 0 640 78.24 0.12 0.00 0.00 22.01. 09:54:49 HASH(FileLog_IT_00F000FFFF); HASH(rr_Bozena)
FileLog_IT_0F0F0FFF0F FileLog_Log 0 640 79.09 0.12 0.00 0.00 22.01. 09:55:11 HASH(FileLog_IT_0F0F0FFF0F); HASH(HG_BM_IT_01)
FileLog_IT_0F0F0FFFFF FileLog_Log 0 640 75.77 0.12 0.00 0.00 22.01. 09:55:10 HASH(FileLog_IT_0F0F0FFFFF); HASH(Foscam)
HM HMinfo_Notify 0 640 9.63 0.02 0.00 0.00 22.01. 09:55:26 HASH(HM); HASH(HG_TH_TH_01)
HV fronthemDevice_Notify 0 640 20.59 0.03 0.00 0.00 22.01. 09:55:09 HASH(HV); HASH(Foscam)
Handy_VPN fronthemDevice_Notify 0 640 17.21 0.03 0.00 0.00 22.01. 09:54:04 HASH(Handy_VPN); HASH(HG_TR_TH_01)
Heizungswerte readingsGroup_Notify 12 640 76.29 0.12 0.00 0.00 22.01. 09:53:26 HASH(Heizungswerte); HASH(NG_BZ_HZ)
Laptop fronthemDevice_Notify 0 640 18.63 0.03 0.00 0.00 22.01. 09:54:04 HASH(Laptop); HASH(HG_TR_TH_01)
LaptopRemote fronthemDevice_Notify 0 640 18.57 0.03 0.00 0.00 22.01. 09:52:52 HASH(LaptopRemote); HASH(Foscam)
Logfile FileLog_Log 1 640 76.37 0.12 0.00 0.00 22.01. 09:56:22 HASH(Logfile); HASH(HG_KU_TH_01)
Luftfeuchte readingsGroup_Notify 1 640 38.90 0.06 0.00 0.00 22.01. 09:52:33 HASH(Luftfeuchte); HASH(heatingInfo)
N308 fronthemDevice_Notify 0 640 18.80 0.03 0.00 0.00 22.01. 09:52:42 HASH(N308); HASH(rg_Bewohner)
Tab fronthemDevice_Notify 0 640 16.85 0.03 0.00 0.00 22.01. 09:53:11 HASH(Tab); HASH(myDbLog)
Termin_Alarm notify_Exec 4 640 127.34 0.20 0.00 0.00 22.01. 09:56:19 HASH(Termin_Alarm); HASH(VUDUO)
Termin_Ende notify_Exec 1 640 103.64 0.16 0.00 0.00 22.01. 09:55:37 HASH(Termin_Ende); HASH(HG_BM_IT_01)
Termin_Loeschen notify_Exec 0 640 100.54 0.16 0.00 0.00 22.01. 09:52:52 HASH(Termin_Loeschen); HASH(HG_BM_IT_01)
Termin_Start notify_Exec 1 640 99.50 0.16 0.00 0.00 22.01. 09:52:52 HASH(Termin_Start); HASH(HG_BM_IT_01)
VURG readingsGroup_Notify 0 640 38.71 0.06 0.00 0.00 22.01. 09:56:06 HASH(VURG); HASH(NG_BZ_HZ_Clima)
WEB FW_Notify 0 640 8.02 0.01 0.00 0.00 22.01. 09:54:47 HASH(WEB); HASH(rg_Klima)
WEB_127.0.0.1_33816 FW_Notify 21 640 1872.01 2.93 0.00 0.00 22.01. 09:52:35 HASH(WEB_127.0.0.1_33816); HASH(HG_WZ_HZ_WT_Weather)
WEBhabridge FW_Notify 0 640 4.54 0.01 0.00 0.00 22.01. 09:52:45 HASH(WEBhabridge); HASH(HG_TH_TH_01)
WEBhook FW_Notify 0 640 4.31 0.01 0.00 0.00 22.01. 09:55:49 HASH(WEBhook); HASH(Hikvision)
WEBphone FW_Notify 0 640 4.45 0.01 0.00 0.00 22.01. 09:52:52 HASH(WEBphone); HASH(Foscam)
WEBtablet FW_Notify 0 640 4.67 0.01 0.00 0.00 22.01. 09:52:53 HASH(WEBtablet); HASH(HG_TH_TH_01)
...
Mir ist nicht ganz klar, weshalb du count verwendest. Es ist doch völlig egal wie oft etwas aufgerufen wird, wenn es keine Laufzeit in Anspruch nimmt. Schau doch mal nach max und such nach Langläufern. Vermutlich findest du da eher einen Kandidaten.
...und dabei fiel mir zumindest dieser
Zitatalarm0.on.N notify_Exec 6 489 256.76 0.53
auf. Ein notify aus dem Alarmanlagen-Modul.
Die Sortierung nach count hatte ich verwendet, weil ich minütlich Hochzählende gesucht habe.
Der Alarm-notify braucht aber "nur" eine halbe Sekunde. Mich würde mehr derWEB_127.0.0.1_33816 FW_Notify 21 489 1477.78 3.02 0.00 0.00 22.01. 09:52:35 HASH(WEB_127.0.0.1_33816); HASH(HG_WZ_HZ_WT_Weather)
mit 3 Sekunden average stören, aber delay ist da auch 0.00.
Am Alarm-notify könnte ich auch schlecht optimieren - der wird vom Modul zusammengebaut - außer weniger Devices reinzunehmen. Das ist aber nicht im Sinne meiner Alarmanlage.
Gruß Roland
Zitat von: hauwech am 22 Januar 2019, 13:07:23
Die Sortierung nach count hatte ich verwendet, weil ich minütlich Hochzählende gesucht habe.
Du willst aber die minütlichen mit "Auswirkungen" - daher passt das schon - ich habe ganz ohne Parameter genommen.
Wenn Du mit apptime "frisch" anfängst, dann siehst Du die Minutenkandidaten bei denen mit delay ja ganz einfach - die zählen von 1,2,3,4,5 ganz langsam hoch - eben im Minutentakt. Die anderen interessieren Dich ja erstmal nicht.
Gruß,
Tom
3.02
das sind 3 milli sekunden, nicht sekunden.
delay ist die zeit, um die die ausführung der funktion verzögert wird. als kein freeze, sondern die auswirkung zb eines freezes.
Ahh, Milli Sekunden... das ist gut. "Delay" habe ich jetzt auch verstanden. Ich habe derzeit ein Brett vor'm Kopp, wahrscheinlich muß ich die Suche mal einen Tag pausieren, um wieder Platz für Logik zu machen.
Ich habe vorhin nach einem "apptime clean" nochmal im Minutentakt apptime aufgerufen. Da habe ich folgendes gesehen:
name function max count total average maxDly avgDly TS Max call param Max call
nach 1 Minute: tmr-at_Exec HASH(0x519c910) 127 1 127.95 127.95 2.90 2.90 22.01. 14:21:56 HASH(a_hmlan_internals)
nach 2 Minuten: tmr-at_Exec HASH(0x519c910) 127 2 255.00 127.50 3.38 3.14 22.01. 14:21:56 HASH(a_hmlan_internals)
nach 3 Minuten: tmr-at_Exec HASH(0x519c910) 127 3 361.18 120.39 3.38 2.60 22.01. 14:21:56 HASH(a_hmlan_internals)
nach 4 Minuten: tmr-at_Exec HASH(0x519c910) 127 4 488.28 122.07 3.38 2.72 22.01. 14:21:56 HASH(a_hmlan_internals)
nach 5 Minuten: tmr-at_Exec HASH(0x519c910) 127 5 612.21 122.44 3.38 2.70 22.01. 14:21:56 HASH(a_hmlan_internals)
Den Rest habe ich weggelassen, weil die Forensoftware bei zu langen Posts den Rest abschneidet, obwohl in der Beitrags-Vorschau alles ordentlich zu sehen ist.
Der Timestamp ist exakt gleich. Heißt das, daß apptime ein und denselben Aufruf 5 mal loggt?
a_hmlan_internals wurde um 14:21:56 aufgerufen, aber um 2.9/3.38 ms verzögert?
Wenn ich den groben Zeitraum im freezemon-log anschaue, sehe ich ich keinen freeze. Das scheint also nicht der Verursacher zu sein, obwohl das der einzige "at" ist, der ein Minutenintervall hat. Wenn ich das Intervall auf 00:02:00 stelle, kommen die freezes trotzdem alle 60 Sekunden.
2019-01-22_14:21:22 myFreezemon s:14:21:20 e:14:21:22 f:2.576 d:cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_35860)
2019-01-22_14:21:22 myFreezemon freezeTime: 2.576
2019-01-22_14:21:22 myFreezemon fcDay: 887
2019-01-22_14:21:22 myFreezemon ftDay: 2330.614
2019-01-22_14:21:22 myFreezemon freezeDevice: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_35860)
=========================================================
[Freezemon] myFreezemon: possible freeze starting at 14:21:20, delay is 2.576 possibly caused by: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_35860)
2019.01.22 14:21:19.233 4: Connection accepted from telnetPort_127.0.0.1_35860
2019.01.22 14:21:19.235 5: Cmd: >jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector<
2019.01.22 14:21:19.369 5: YAMAHA_AVR (AV_Receiver) - set AV_Receiver ?
--- log skips 2.925 secs.
2019.01.22 14:21:22.294 5: ENIGMA2 VU: called function ENIGMA2_Set()
2019.01.22 14:21:22.296 5: ENIGMA2 VUDUO: called function ENIGMA2_Set()
2019.01.22 14:21:22.406 5: GEOFANCY geofancy: called function GEOFANCY_Set()
2019.01.22 14:21:22.424 5: myFreezemon Coming with command ?
2019.01.22 14:21:22.424 5: myFreezemon leaving with Unknown argument ?, choose one of active:noArg inactive:noArg clear:noArg
2019.01.22 14:21:22.501 1: [Freezemon] myFreezemon: Long running Command detected jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector:telnetPort - 3.266186 seconds
2019.01.22 14:21:22.576 1: [Freezemon] myFreezemon: Long function call detected ReadFn:telnetPort_127.0.0.1_35860 - 3.34117 seconds
2019.01.22 14:21:22.577 5: [Freezemon] myFreezemon: ----------- Starting Freeze handling at 2019.01.22 14:21:22.576 ---------------------
2019.01.22 14:21:22.577 5: [Freezemon] myFreezemon logging: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_35860) in all mode, because telnetPort_127.0.0.1_35860 is not ignored
[Freezemon] myFreezemon: possible freeze starting at 14:21:20, delay is 2.576 possibly caused by: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_35860)
2019-01-22_14:22:22 myFreezemon s:14:22:20 e:14:22:22 f:2.772 d:cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_36018)
2019-01-22_14:22:22 myFreezemon freezeTime: 2.772
2019-01-22_14:22:22 myFreezemon fcDay: 888
2019-01-22_14:22:22 myFreezemon ftDay: 2333.386
2019-01-22_14:22:22 myFreezemon freezeDevice: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_36018)
=========================================================
[Freezemon] myFreezemon: possible freeze starting at 14:22:20, delay is 2.772 possibly caused by: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_36018)
2019.01.22 14:22:19.291 4: Connection accepted from telnetPort_127.0.0.1_36018
2019.01.22 14:22:19.293 5: Cmd: >jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector<
2019.01.22 14:22:19.427 5: YAMAHA_AVR (AV_Receiver) - set AV_Receiver ?
--- log skips 3.024 secs.
2019.01.22 14:22:22.451 5: ENIGMA2 VU: called function ENIGMA2_Set()
2019.01.22 14:22:22.453 5: ENIGMA2 VUDUO: called function ENIGMA2_Set()
2019.01.22 14:22:22.577 5: GEOFANCY geofancy: called function GEOFANCY_Set()
2019.01.22 14:22:22.595 5: myFreezemon Coming with command ?
2019.01.22 14:22:22.595 5: myFreezemon leaving with Unknown argument ?, choose one of active:noArg inactive:noArg clear:noArg
2019.01.22 14:22:22.686 1: [Freezemon] myFreezemon: Long running Command detected jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector:telnetPort - 3.393913 seconds
2019.01.22 14:22:22.771 1: [Freezemon] myFreezemon: Long function call detected ReadFn:telnetPort_127.0.0.1_36018 - 3.478458 seconds
2019.01.22 14:22:22.772 5: [Freezemon] myFreezemon: ----------- Starting Freeze handling at 2019.01.22 14:22:22.772 ---------------------
2019.01.22 14:22:22.772 5: [Freezemon] myFreezemon logging: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_36018) in all mode, because telnetPort_127.0.0.1_36018 is not ignored
[Freezemon] myFreezemon: possible freeze starting at 14:22:20, delay is 2.772 possibly caused by: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_36018)
Irgendwie stehe ich auf'm Schlauch und sehe den Wald nicht mehr :-\
Gruß Roland
Ich mag Dich zwar nicht noch mehr verwirren und vielleicht steht es auch schon erklärt auf den 2 Seiten vorher...
Wenn ich mir das freeze log ansehe, fallen Yamaha u. Enigma ins Auge. 2 devices, die vermutlich für den Status mit einem internaltimer von 60 arbeiten und wenn die OFF sind und der call blocking ist..... :-\
Zitat von: KölnSolar am 22 Januar 2019, 16:55:00
Ich mag Dich zwar nicht noch mehr verwirren und vielleicht steht es auch schon erklärt auf den 2 Seiten vorher...
Wenn ich mir das freeze log ansehe, fallen Yamaha u. Enigma ins Auge. 2 devices, die vermutlich für den Status mit einem internaltimer von 60 arbeiten und wenn die OFF sind und der call blocking ist..... :-\
Womit wir bei meinem Beispiel von XBMC / Kodi weiter oben im Thread wären - ähnliche Situation.
Yamaha und Enigma waren mir auch schon aufgefallen, die hatte ich aber schon mal eine Zeit lang disabled, ohne daß sich an den freezes was ändert.
Deswegen hatte ich weiter oben schon mal die Frage aufgeworfen, ob das Attribut "disable=1" möglicherweise nicht ausreicht, sondern vielleicht einen fhem Neustart braucht, oder das device tatsächlich gelöscht werden muß, um es vollständig kalt zu stellen. Wahrscheinlich ist das disable-handling auch modulabhängig.
Gruß Roland
ZitatWahrscheinlich ist das disable-handling auch modulabhängig.
Genau und deshalb würd ich mich nicht drauf verlassen. Lieber einfach mal ein delete(ohne save) und schlimmstenfalls machst Du nach ein Paar Minuten einen shutdown/restart und sie sind wieder da.
Oder vorher mal die Config wegsichern ... (wobei Backup immer gut ist)
Zitat von: Wernieman am 22 Januar 2019, 18:51:56
Oder vorher mal die Config wegsichern ... (wobei Backup immer gut ist)
Ich wiederhole mich gern, FHEM sichert beim save automatisch die alte config weg! Vorausgesetzt das letzte Update ist nicht älter als 1,5 Jahre (https://forum.fhem.de/index.php?topic=85801.0) ;)
Trotzdem ist backup immer gut!
Ich bin Konservativ ... im Zweifelsfalle lieber ein Backup zu viel als zu wenig
(wobei .. kann man Backups zu viel haben ;o) )
Ich taste mich langsam ran. Ich habe jetzt systematisch Räume oder Gruppen gelöscht und das Log beobachtet. Heute hatte ich den ersten Treffer.
Was habe ich gemacht:
- fhem Backup
- sicherheitshalber noch rsync von /opt/fhem auf das NAS-Spiegelverzeichnis aktualisiert
- fhem update auf den neuesten Stand (incl. fhem-Neustart)
- alle readingsGroups gelöscht (die haben bei mir alle den Präfix "rg_")
Vorher hatte ich alle 60 Sekunden 3 freezes im Log, nach dem Löschen der readingsGroups kommt nur noch 1 freeze.
Jetzt kommt der Knüller...:
Nach dem shutdown/restart von fhem sind die readingsGroups wieder da, aber es kommt trotzdem nur noch 1 freeze...
Nicht, daß ich mich nicht freue, aber ich würde das Verhalten auch gern verstehen. Ist es möglich, daß die mit dem fhem-update neu hinzugekommene UUID für jedes device an dieser Stelle etwas bewirkt? Ich habe aber nicht beachtet, ob die readingsGroups vor dem Löschen auch schon eine UUID hatten.
Gruß Roland
Hallo Roland,
sag niemals nie ;D - aber die UUID ist nur eine Nummer im Device, die wird erzeugt gesetzt und fertig. Kann ich mir nicht vorstellen.
Im Update kann aber was anderes gewesen sein.
Gruß Otto
Hi Otto,
ich kann mir eigentlich auch nicht vorstellen, daß sowas an der UUID hängt, aber wenn man tagelang sucht, ohne eine vernünftige Erklärung zu finden, kommt man auf die komischsten Gedanken.
Ich frage mich nach dem Verlauf jetzt zum Beispiel: Was haben die readingGroups mit "telnetPort_127.0.0.1_xxxxx" zu tun? Wenn ich die vor dem fhem-update gelöscht hätte, wüßte ich wenigstens, ob's mit dem update zu tun hat. Aber Backup zurückspielen und nochmal probieren - und das unerklärliche Ausbleiben der freezes möglicherweise wieder einzufangen - mache ich auch nicht. :)
Gruß Roland
du weisst aber schon, dass die readingsgroups zusätzlich einen haufen events erzeugen können.
und zwar immer dann, wenn sie irgendwo
angezeigt werden.
ganz schlecht ist das folgende attribut:
ZitatalwaysTrigger
1 -> alwaysTrigger update events. even if not visible.
2 -> trigger events for calculated values.
wie schon weiter oben geschrieben, hast du scheinbar weiterhin ein eventproblem.
ein letztes mal empfehle ich dir "attr event-on-change .*" in möglichst
jedem device.
Zitatein letztes mal empfehle ich dir "attr event-on-change .*" in möglichst jedem device.
Das sollte meines Erachtens durch FHEM als Standard gesetzt werden und eher abschaltbar sein als anschaltbar... Soll nicht heissen das FHEM das heute so macht, meiner Meinung nach, sollte FHEM das aber so tun und es würde viele Freeze Probleme gar nicht erst auftreten lassen.
Hallo Frank,
daß readingsGroups events erzeugen war mir bisher nicht wirklich bewußt aufgefallen im Eventmonitor. AlwaysTrigger habe ich aber nirgends gesetzt.
Ich habe im Verlauf dieser Fehlersuche zusätzlich zu denen, wo es schon gesetzt war, auf alle Devices mit einem battery oder batteryLevel reading das event-on-change-reading .* gesetzt, weil da eine readingsGroup existiert, die alle Battery Stati einfängt. Vorher hatte ich vermieden, das auf alle devices zu setzen, weil das viele Plots unschön aussehen läßt.
Da werde ich weiter optimieren, Performance hat höhere Prio als Plots. Ich denke, ich setze bei den betroffenen devices (meist Heizthermostate) ein event-min-interval auf die wichtigen readings. Damit habe ich schon die LaCrosse Temperatursensoren gebändigt, die alle paar Sekunden melden.
Macht es Sinn, event-on-change-reading .* und z.B. event-min-interval measured-temp=600, [humidity=600,] actuator=600 zu setzen? Hat das den Effekt, daß alle readings bei geänderten Werten und measured-temp, humidity und actuator trotzdem alle 10 Minuten ein event werfen? Oder gewinnt event-on-change-reading?
Gruß Roland
vom prinzip her sollte es so funktionieren.
kannst du doch auch sehr komfortabel im eventmonitor live verfolgen.
zusätzlich könntest du auch noch mit event-on-update einige readings auf maximale event generierung schalten.
Update:
Ich habe nun immer wenn ich Zeit hatte, devices und auch komplette rooms mit Verdachtigen gelöscht. Der letzte freeze blieb aber hartnäckig.
Jetzt habe ich mir überlegt, wozu ich das vor langer Zeit angelegte device "telnetPort" eigentlich brauche, was in 99% aller freezes als Verursacher auftaucht. Aktiv genutzt habe ich es eigentlich nur im IOBroker-fhem-Adapter. Den hatte ich auf IOBroker-Seite aber schon abgeschaltet gehabt, ohne daß sich im freeze-Verhalten auf fhem-Seite was ändert.
Jetzt habe ich - nach einem Backup - das telnet-device in fhem gelöscht. Damit ist der letzte freeze auch weg. Ich habe dann mit shutdown restart das device wiederbelebt - der freeze ist wieder da. Das Wunder wie mit den wiederbelebten readingsGroups hat sich leider nicht wiederholt. Nochmal gelöscht - freeze wieder weg. Mit neuem Namen, aber gleichem DEF (7072 global) wieder angelegt - freeze kommt mit dem neuen Namen wieder. Damit dürfte der Verursacher feststehen und freezemon hat Recht gehabt.
Abgesehen von meinem IOBroker-Problem bleibt nun die Frage: Wird telnet doch von fhem oder diversen Modulen gebraucht, wenn es intern mit 60s Intervall aufgerufen wird?
Ich werde das jetzt mal beobachten. Vielleicht kennt aber jemand die Nebenwirkungen, wenn das fhem-telnet-device fehlt.
IOBroker könnte ich notfalls mit MQTT füttern, wenn telnet nicht gebraucht würde. Das ist dank des schlanken MQTT Protokolls wahrscheinlich auch deutlich performanter, als sämtliche fhem devices und sämtliche readings mit dem fhem-Adapter nach IOBroker zu pumpen.
Danke an Frank:
Die Kombination von event-on-change-reading und event-min-interval funktioniert wie erwartet. Die event-Flut ist eingedämmt und die Plots sehen auch wieder ordentlich aus.
Gruß Roland
Dann hast Du irgendeinen Job auf Deinem Rechner/Netz, der jede Minute per telnet an Dein fhem geht. Dann schaue mal ins syslog, ob da irgendetwas auffällt ...
Ich bin nicht so der große Linux-Guru. cat /var/log/syslog|grep telnet
bringt null Fundstellen, das log geht bis heute morgen 6:29 Uhr zurück, da gab's die freezes noch.
Ein sudo grep -R im Verzeichnis /var/log
bringt auch nur roland@fhem-nuc:/var/log$ sudo grep -R telnet
Übereinstimmungen in Binärdatei btmp
installer/syslog:Nov 17 17:15:43 in-target: squashfs-tools ssh-import-id strace tcpd tcpdump tdb-tools telnet time tmux
installer/syslog:Nov 17 17:15:46 in-target: Holen:177 cdrom://Ubuntu-Server 16.04.1 LTS _Xenial Xerus_ - Release amd64 (20160719) xenial/main amd64 telnet amd64 0.17-40 [63,5 kB]
installer/syslog:Nov 17 17:16:15 in-target: Vormals nicht ausgewähltes Paket telnet wird gewählt.^M
installer/syslog:Nov 17 17:16:15 in-target: Vorbereitung zum Entpacken von .../telnet_0.17-40_amd64.deb ...^M
installer/syslog:Nov 17 17:16:15 in-target: Entpacken von telnet (0.17-40) ...^M
installer/syslog:Nov 17 17:17:06 in-target: telnet (0.17-40) wird eingerichtet ...
installer/syslog:Nov 17 17:17:06 in-target: update-alternatives: /usr/bin/telnet.netkit wird verwendet, um /usr/bin/telnet (telnet) im automatischen Modus bereitzustellen^M
auth.log:Jan 29 20:02:58 fhem-nuc sudo: roland : TTY=pts/0 ; PWD=/var/log ; USER=root ; COMMAND=/bin/grep -R telnet
Alles alter Kram.
Gibt's noch andere logs, wo man fündig werden könnte?
Gruß Roland
schau ma hier ...
https://help.joyent.com/hc/en-us/articles/226687427-Watching-active-IP-connections-Linux
da gibt es ein paar Wege zum Monitoren der aktiven Netzwerkverbindungen ...
oder setzt mal den verbose Level auf 5 vom telnet Device
Danke, das sind interessante tools, die ich noch nicht kenne.
Ich habe in einer VM ein fhem neu installiert, das kann man als cold standby immer mal gebrauchen.
Im leeren fhem habe ich eine freezemon Instanz und ein telnet device angelegt. Das hält so alleine die Füße still und verursacht wie erwartet keine freezes.
Ich schließe daraus, daß das Kern-fhem selbst keine internen telnet-Aufrufe macht und die Probleme somit aus einem Modul heraus initiiert werden müssen.
Mit dem Löschen des telnet devices bin ich zwar die freezes losgeworden, habe aber die Ursache nicht beseitigt.
Ich habe eben den Tip "telnet device auf verbose 5" verfolgt, und siehe da: Kurz vor dem freeze werden alle devices durchgegangen. Ich habe hier nur einen Teil herausgeschnitten. Das "... returned dont care" interpretiere ich als "macht nix...". Aber die Tatsache, daß zyklisch ALLE devices angefaßt werden, könnte doch zu diesen Verzögerungen führen, oder??? Loglevel 4 heißt ja nur, daß sie mit verbose 5 geloggt werden, ausgeführt werden sie aber immer.
2019.01.30 10:56:28.362 4: Connection accepted from telnetPort_127.0.0.1_38504
2019.01.30 10:56:28.363 4: authorize telnetPort/cmd/jsonlist2: allowedWEBhook returned dont care
2019.01.30 10:56:28.363 4: authorize telnetPort/cmd/jsonlist2: allowed_WEB returned dont care
2019.01.30 10:56:28.364 4: authorize telnetPort/cmd/jsonlist2: allowed_WEBphone returned dont care
2019.01.30 10:56:28.364 4: authorize telnetPort/cmd/jsonlist2: allowed_WEBtablet returned dont care
2019.01.30 10:56:28.393 4: authorize telnetPort/devicename/AV_Receiver: allowedWEBhook returned dont care
2019.01.30 10:56:28.393 4: authorize telnetPort/devicename/AV_Receiver: allowed_WEB returned dont care
2019.01.30 10:56:28.393 4: authorize telnetPort/devicename/AV_Receiver: allowed_WEBphone returned dont care
2019.01.30 10:56:28.393 4: authorize telnetPort/devicename/AV_Receiver: allowed_WEBtablet returned dont care
2019.01.30 10:56:28.394 4: authorize telnetPort/devicename/Activity_chk: allowedWEBhook returned dont care
....
2019.01.30 10:56:28.629 4: authorize telnetPort/devicename/v_armInt_s: allowed_WEB returned dont care
2019.01.30 10:56:28.629 4: authorize telnetPort/devicename/v_armInt_s: allowed_WEBphone returned dont care
2019.01.30 10:56:28.629 4: authorize telnetPort/devicename/v_armInt_s: allowed_WEBtablet returned dont care
2019.01.30 10:56:31.563 1: [Freezemon] myFreezemon: Long running Command detected jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector:telnetPort - 3.199874 seconds
2019.01.30 10:56:31.639 1: [Freezemon] myFreezemon: Long function call detected ReadFn:telnetPort_127.0.0.1_38504 - 3.275956 seconds
2019.01.30 10:56:31.641 1: [Freezemon] myFreezemon: possible freeze starting at 10:56:29, delay is 2.639 possibly caused by: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_38504)
2019.01.30 10:57:28.159 4: Connection accepted from telnetPort_127.0.0.1_38592
2019.01.30 10:57:28.161 4: authorize telnetPort/cmd/jsonlist2: allowedWEBhook returned dont care
2019.01.30 10:57:28.161 4: authorize telnetPort/cmd/jsonlist2: allowed_WEB returned dont care
2019.01.30 10:57:28.162 4: authorize telnetPort/cmd/jsonlist2: allowed_WEBphone returned dont care
2019.01.30 10:57:28.162 4: authorize telnetPort/cmd/jsonlist2: allowed_WEBtablet returned dont care
....
2019.01.30 10:57:28.433 4: authorize telnetPort/devicename/sunMarker: allowedWEBhook returned dont care
2019.01.30 10:57:28.433 4: authorize telnetPort/devicename/sunMarker: allowed_WEB returned dont care
2019.01.30 10:57:28.433 4: authorize telnetPort/devicename/sunMarker: allowed_WEBphone returned dont care
2019.01.30 10:57:28.433 4: authorize telnetPort/devicename/sunMarker: allowed_WEBtablet returned dont care
2019.01.30 10:57:28.433 4: authorize telnetPort/devicename/telnetForBlockingFn_1548771227: allowedWEBhook returned dont care
2019.01.30 10:57:28.433 4: authorize telnetPort/devicename/telnetForBlockingFn_1548771227: allowed_WEB returned dont care
2019.01.30 10:57:28.433 4: authorize telnetPort/devicename/telnetForBlockingFn_1548771227: allowed_WEBphone returned dont care
2019.01.30 10:57:28.433 4: authorize telnetPort/devicename/telnetForBlockingFn_1548771227: allowed_WEBtablet returned dont care
2019.01.30 10:57:28.434 4: authorize telnetPort/devicename/telnetPort: allowedWEBhook returned dont care
2019.01.30 10:57:28.434 4: authorize telnetPort/devicename/telnetPort: allowed_WEB returned dont care
2019.01.30 10:57:28.434 4: authorize telnetPort/devicename/telnetPort: allowed_WEBphone returned dont care
2019.01.30 10:57:28.434 4: authorize telnetPort/devicename/telnetPort: allowed_WEBtablet returned dont care
2019.01.30 10:57:28.434 4: authorize telnetPort/devicename/telnetPort_127.0.0.1_38592: allowedWEBhook returned dont care
2019.01.30 10:57:28.434 4: authorize telnetPort/devicename/telnetPort_127.0.0.1_38592: allowed_WEB returned dont care
2019.01.30 10:57:28.434 4: authorize telnetPort/devicename/telnetPort_127.0.0.1_38592: allowed_WEBphone returned dont care
2019.01.30 10:57:28.434 4: authorize telnetPort/devicename/telnetPort_127.0.0.1_38592: allowed_WEBtablet returned dont care
2019.01.30 10:57:28.435 4: authorize telnetPort/devicename/userCfg: allowedWEBhook returned dont care
2019.01.30 10:57:28.435 4: authorize telnetPort/devicename/userCfg: allowed_WEB returned dont care
....
2019.01.30 10:57:28.436 4: authorize telnetPort/devicename/v_armInt_l: allowed_WEBphone returned dont care
2019.01.30 10:57:28.436 4: authorize telnetPort/devicename/v_armInt_l: allowed_WEBtablet returned dont care
2019.01.30 10:57:28.437 4: authorize telnetPort/devicename/v_armInt_s: allowedWEBhook returned dont care
2019.01.30 10:57:28.437 4: authorize telnetPort/devicename/v_armInt_s: allowed_WEB returned dont care
2019.01.30 10:57:28.437 4: authorize telnetPort/devicename/v_armInt_s: allowed_WEBphone returned dont care
2019.01.30 10:57:28.437 4: authorize telnetPort/devicename/v_armInt_s: allowed_WEBtablet returned dont care
2019.01.30 10:57:31.113 1: [Freezemon] myFreezemon: Long running Command detected jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector:telnetPort - 2.951947 seconds
2019.01.30 10:57:31.194 1: [Freezemon] myFreezemon: Long function call detected ReadFn:telnetPort_127.0.0.1_38592 - 3.03339 seconds
2019.01.30 10:57:31.197 1: [Freezemon] myFreezemon: possible freeze starting at 10:57:29, delay is 2.195 possibly caused by: cmd-jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector(telnetPort) fn-ReadFn(telnetPort_127.0.0.1_38592) tmr-Unifi_DoUpdate(UnifiController)
Oder habe ich die allowed_Web.* Instanzen falsch konfiguriert?
Internals:
FUUID xxxxxxxxx-f33f-af18-4e61-xxxxxxxxxxxxxxxxxxxx
NAME allowed_WEB
NR 71
STATE validFor:WEB
TYPE allowed
validFor WEB
READINGS:
2019-01-29 15:09:19 lastAuthExpires xxxxxxxxxxxx
2019-01-29 15:09:19 lastAuthExpiresFmt xxx, xx xxx xxxx 14:09:19 GMT
2019-01-29 15:09:19 lastAuthUser xxxxxxxx
2019-01-29 15:08:54 state validFor:WEB
helper:
bm:
allowed_Authenticate:
cnt 46
dmx -1000
dtot 0
dtotcnt 0
mTS 30.01. 09:38:32
max 0.000462055206298828
tot 0.00591206550598145
mAr:
HASH(allowed_WEB)
HASH(WEB)
HASH(0x1929928)
allowed_Authorize:
cnt 30
dmx -1000
dtot 0
dtotcnt 0
mTS 30.01. 09:40:58
max 7.60555267333984e-05
tot 0.000606536865234375
mAr:
HASH(allowed_WEB)
HASH(WEB_88.xxx.xx.xx_51631)
cmd
apptime
Attributes:
basicAuth xxxxxxxxxxxxxxx
basicAuthExpiry xx
validFor WEB
Internals:
FUUID xxxxxxxxxxxx-f33f-af18-dea2-xxxxxxxxxxxxxxxxx
NAME allowedWEBhook
NR 725
STATE validFor:WEBhook
TYPE allowed
allowedCommands ,
allowedDevices ,
validFor WEBhook
READINGS:
2019-01-29 15:08:58 state validFor:WEBhook
helper:
bm:
allowed_Authenticate:
cnt 46
dmx -1000
dtot 0
dtotcnt 0
mTS 30.01. 09:39:30
max 0.000255823135375977
tot 0.00468230247497559
mAr:
HASH(allowedWEBhook)
HASH(WEB)
HASH(0xa150008)
allowed_Authorize:
cnt 30
dmx -1000
dtot 0
dtotcnt 0
mTS 30.01. 09:39:55
max 0.000185012817382812
tot 0.00183892250061035
mAr:
HASH(allowedWEBhook)
HASH(telnetForBlockingFn_1548771227_127.0.0.1_36040)
cmd
perl
Attributes:
allowedCommands ,
allowedDevices ,
basicAuth { "$user:$password" eq "xxxxxx:xxxxxxxxxx" }
validFor WEBhook
Internals:
FUUID xxxxxxxxx-f33f-af18-1c9c-xxxxxxxxxxxxxxxxxxx
NAME allowed_WEBphone
NR 78
STATE validFor:WEBphone
TYPE allowed
validFor WEBphone
READINGS:
2019-01-29 15:08:54 state validFor:WEBphone
helper:
bm:
allowed_Authenticate:
cnt 35
dmx -1000
dtot 0
dtotcnt 0
mTS 30.01. 09:38:32
max 0.000112056732177734
tot 0.00136947631835938
mAr:
HASH(allowed_WEBphone)
HASH(WEB)
HASH(0x1929928)
allowed_Authorize:
cnt 30
dmx -1000
dtot 0
dtotcnt 0
mTS 30.01. 09:40:58
max 4.00543212890625e-05
tot 0.000430822372436523
mAr:
HASH(allowed_WEBphone)
HASH(WEB_88.xxx.xx.xx_51631)
cmd
apptime
Attributes:
basicAuth xxxxxxxxxxxxxxx
validFor WEBphone
Internals:
FUUID xxxxxxxxxx-f33f-af18-5354-xxxxxxxxxxxxxx
NAME allowed_WEBtablet
NR 83
STATE validFor:WEBtablet
TYPE allowed
validFor WEBtablet
READINGS:
2019-01-29 15:08:54 state validFor:WEBtablet
helper:
bm:
allowed_Authenticate:
cnt 35
dmx -1000
dtot 0
dtotcnt 0
mTS 30.01. 09:38:32
max 0.000107049942016602
tot 0.00133299827575684
mAr:
HASH(allowed_WEBtablet)
HASH(WEB)
HASH(0x1929928)
allowed_Authorize:
cnt 30
dmx -1000
dtot 0
dtotcnt 0
mTS 30.01. 09:40:58
max 7.89165496826172e-05
tot 0.000463962554931641
mAr:
HASH(allowed_WEBtablet)
HASH(WEB_88.xxx.xx.xx_51631)
cmd
apptime
Attributes:
basicAuth xxxxxxxxxxxxxxxxxx
validFor WEBtablet
Gruß Roland
Ich bin gerade auf eine möglicherweise heiße Spur gestoßen:
Pro:
- die fhem-devices in Check_MK stehen seit gestern auf "stale"
- das Check_MK Plugin für fhem macht lokales telnet
- in der Datei /usr/lib/check_mk_agent/plugins/mk_fhem steht:
my $fhem_outpout = `/opt/fhem/fhem.pl 7072 "jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector"`;
- das paßt exakt zu:
2019.01.18 09:34:07.580 1: [Freezemon] myFreezemon: Long running Command detected jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector:telnetPort - 3.30997 seconds
Contra:
- mein Kollege hat das so auch im Einsatz, aber ohne freezes.
Was habe ich daraufhin gemacht:
- das check_mk Plugin aus /usr/lib/check_mk_agent/plugins entfernt
- define telnetPort telnet 7072 global
- tail -f /opt/fhem/log/fhem-2019-01.log -n 100
..... Trommelwirbel ..........
KEIN FREEZE :D :D :D
Heureka!
Ich hoffe, das war's jetzt, die Geschichte hat mich doch ganz schön gewurmt.
Dankeschön an alle Mitwirkenden!
Erleichterter Gruß
Roland
Sorry aber was ist "Check_MK"?
Übrigens hatte ich Dir am Anfang (glaub ich) geschrieben, das telnet von einem externen Device stammen könnte ....
Aber gut, das es jetzt funzt!
Zitat von: Wernieman am 31 Januar 2019, 12:16:17
Sorry aber was ist "Check_MK"?
Übrigens hatte ich Dir am Anfang (glaub ich) geschrieben, das telnet von einem externen Device stammen könnte ....
Aber gut, das es jetzt funzt!
Check_MK ist ein Monitoring-System, ich habe hierzu ein FHEM-Plugin geschrieben.
Siehe https://forum.fhem.de/index.php/topic,63723.0.html
Das Freezes dadurch entstehen ist mir stand jetzt aber nicht bekannt.
Edit:
Zu Abfrage wird der befehl benutzt:
/opt/fhem/fhem.pl 7072 "jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector
@hauwech:
ich seh grad das du noch einen alten Agent benutzt.
teste doch bitte mal den Neuen! Ich habe hier mehr Sachen ausgefiltert ...
https://github.com/erdoking/mk_fhem/blob/master/local/share/check_mk/agents/mk_fhem
interessant wäre auch die Laufzeit der beiden Abfragen - einmal aus dem Kopf...
Alt:
time /opt/fhem/fhem.pl 7072 "jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector
Neu:
time /opt/fhem/fhem.pl 7072 "jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=TYPE!=CCU-FHEM|ActionDetector|at|notify|statistics|DOIF"
jsonlist2 ist bekannt dafür längere Laufzeiten zu haben - eben weil viele Module "angefasst" werden. Ich würde nach Alternativen suchen.
Generell bauen Architekturen die jsonlist benutzen auch darauf auf fhem zu pollen, oft zyklisch. Eine andere Möglichkeit besteht darin events bei der Entstehung abgreifen und an externe Systeme pushen, quasi nur das was von Interesse ist zu übertragen.
Zitat von: Wernieman am 31 Januar 2019, 12:16:17
Übrigens hatte ich Dir am Anfang (glaub ich) geschrieben, das telnet von einem externen Device stammen könnte ....
Aber gut, das es jetzt funzt!
Ja, hast Du :)
"extern" hatte ich nach allen Versuchen mit IObroker, alexa, SSCam & Co. soweit ausgeschlossen, weil der Aufruf lt. freezemon auf TelnetPort_
127.0.0.1... ging, das mußte nach meinem Ermessen etwas Lokales sein.
Ich hatte aber auch meine String-Suche in den files auf /opt/fhem begrenzt. Das Check-mk Plugin liegt aber unter /usr/lib/....
@erdo:
Die Ausführungszeiten unterscheiden sich leider nur marginal:
time /opt/fhem/fhem.pl 7072 "jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector"
real 0m4.662s
user 0m0.228s
sys 0m0.200s
time /opt/fhem/fhem.pl 7072 "jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=TYPE!=CCU-FHEM|ActionDetector|at|notify|statistics|DOIF"
real 0m4.657s
user 0m0.240s
sys 0m0.188s
Gruß Roland
Ich bin um einiges flotter unterwegs:
time /opt/fhem/fhem.pl 7072 "jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector "
real 0m1.991s
user 0m0.520s
sys 0m0.130s
time /opt/fhem/fhem.pl 7072 "jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=TYPE!=CCU-FHEM|ActionDetector|at|notify|statistics|DOIF"
real 0m1.834s
user 0m0.460s
sys 0m0.110s
Das sind natürlich keine Spitzenwerte, aber eine Verzögerung von unter 2 Sekunden sehe ich als akzeptabel an ;)
Ich muss mir mal anschauen welche alternativen es bei der Abfrage gibt und ggf. was neues basteln ...
Als Hardware kommt bei mir übrigens ein Raspberry Pi 3 zum Einsatz...
Für dich eine kurzfristige Lösung:
Schieb das Plugin nach /usr/lib/check_mk_agent/plugins/600/ damit wird fhem nur noch alle 10 Minuten abgefragt (oder /900/ für alle 15min)
Solange man keine "echte" Überwachung macht die Zeitkritisch ist sollte das erstmal reichen.
Ich setze mein Plugin vor allem für Konfigurationsüberwachung, Geräteüberwachung und Graphen ein ;)
Bringt das eigentlich etwas, wenn Du anstatt fhem ein "telnet-Ersatz" wie nc nimmst?
also wie:
time echo "jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector " | nc <fhem-server> 7072
Hallo Wernieman,
das kommt im Schnitt auch auf über 4s:
real 0m4.365s
user 0m0.008s
sys 0m0.120s
Wenn ich den output (ohne time) in eine Datei pipe, kommt die auf 2.1MB mit 19.162 Zeilen.
Gruß Roland
Am Ende bleibt für Installationen mit vielen devices wohl nur eine wie von Jörg angesprochene event-basierte Architektur, wo einzelne readings pro event gepusht werden. Aber da kann ich leider nix konkretes beitragen, nur gescheit daherreden. :-[
Gruß Roland
Wenn das wirklich notwendig ist, dann würde ich die Daten erst mal non blocking generieren. Und im zweiten Schritt die Daten per telnet transferieren. Wenn ich das richtig verstanden habe, dann läuft ja momentan das sammeln der Daten blockierend ab. Eventuell kann man ja einfach dieses jsonlist Plugin um einen non blocking Modus erweitern?
der nonBlocking Mode wäre (für diesen Fall) natürlich schon die Beste Lösung ...
nc scheint echt schneller zu sein wie die direkte abfrage über fhem.pl... Interessant!
Ich verfolge aber aktuell einen anderen Ansatz, da könnt ihr mir vielleicht helfen.
Aktuell liefert die Abfrage DEUTLICH mehr Werte wie ausgewertet werden.
Das liegt schlicht daran, dass ich nicht weiß wie ich die Abfrage weiter Filtern kann.
Beispiel:
jsonlist2 TYPE=CUL_HM geht schneller wie jsonlist2 TYPE=.*
Wir sind zwar nur im Millisekundenbereich, aber schneller ist schneller ;)
Wie kann ich zB. die PossibleAttrs und die PossibleSets rausfiltern?
Im Grunde Interessieren mich hier an erster Stelle die Readings, Attributes und Internals (inkl. aller Channel!)
Vielleicht ist es auch Sinnvoll einzelne Reading auszunahmen, zB "RegL_*" bei HomeMatic-Devices ...
edit:
fhem:# /opt/fhem/fhem.pl 7072 "jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=TYPE!=CCU-FHEM|ActionDetector|at|notify|statistics|DOIF" > /tmp/1
fhem:# du -h /tmp/1
676K /tmp/1
fhem:# wc -l /tmp/1
6220 /tmp/1
du kannst nur auf device ebene filtern.
normalerweise macht man die jsonlist2 anfrage nur ein mal beim starten und hängt sich dann an die events um alle änderungen mit zu bekommen
per telnet mit inform oder per web über longpoll oder websocket.
erdo hat mich per PM aufgefordert hier Stellung zu nehmen:
ZitatJsonList2 wird per Telnet (bzw. über fhem.pl) abgesprochen und generiert Freezes von mehreren Sekunden.
Die gelieferte Datenmenge ist einfach gigantisch ...
jsonlist2 bietet als Option an, nur bestimmte Werte abzufragen, aber es gibt keine Option "alles, aber X,Y,Z nicht". Selbst damit wuerde man das Problem nur halbieren, aber nicht loesen.
Stattdessen sollte man, wie justme1968 das schreibt, jsonlist2 fuer alle Geraete nur selten aufrufen, und mit vernuenftigen Methoden auf dem Laufenden bleiben.
Zitatper telnet mit form oder per web über lingpoll oder websocket.
Typo: "per telnet mit inform oder per web ueber longpoll oder websocket."
P.S.: ueber wie viele Geraete und wieviel MB reden wir?
@rudolfkoenig: Danke für deine Stellungsname, ich weiß das Plugin ist hier nur indirekt Mitschuld ;)
Zitatjsonlist2 bietet als Option an, nur bestimmte Werte abzufragen, aber es gibt keine Option "alles, aber X,Y,Z nicht". Selbst damit wuerde man das Problem nur halbieren, aber nicht loesen.
Mein Problem:
ich weiß vorab nicht welche Geräte/Werte es gibt, im Grunde hole ich alle und Werte im Anschluss nur die Unterstützen aus.
Das hat den Vorteil, das auch bei (mir) unbekannten Geräten etliche Werte ausgewertet werden.
Beispiel ein Wassersensor aus einem Aquarium (habe ich nicht) würde mindestens die Temperatur auswerten und einen entsprechenden Graphen generieren ...
Ich könnte dem CheckMK-Agent-Plugin (im Grunde ein perl-Script) eine laaaaaange Liste aller abzufragenden Parameter mitgeben.
Allerdings ist das von der Wartung/Pflege her ein ziemlicher Aufwand und aus Versions-Gründen nicht erstrebenswert. Und ob das schneller läuft?
Um die Daten "live" abzufragen wäre im Grunde ein paralleler Deamon notwendig, was in meinen Augen ein zu hoher Aufwand ist, nur um ein paar Daten alle X Minuten zu holen.
ZitatP.S.: ueber wie viele Geraete und wieviel MB reden wir?
BEI MIR!
Größe: 676K
Zeilen:
Laufzeit: 1.66 Sekunden
Hinweis: Leider brauchen wir auch einige HomeMatic-Channel, da hier teilweise relevante Daten drin stehen...
time /opt/fhem/fhem.pl 7072 "jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=TYPE!=CCU-FHEM|ActionDetector|at|notify|statistics|DOIF" | grep 'TYPE":' | sort |uniq -c|sort -nr
61 "TYPE": "CUL_HM",
15 "TYPE": "dummy"
11 "TYPE": "TRAFFIC",
6 "TYPE": "LaCrosse",
5 "TYPE": "Heating_Control"
4 "TYPE": "ESPEasy",
3 "TYPE": "XiaomiBTLESens",
3 "TYPE": "PRESENCE"
3 "TYPE": "FHEMWEB"
3 "SUBTYPE": "device",
2 "TYPE": "XBMC"
2 "TYPE": "WifiLight"
2 "TYPE": "telnet"
2 "TYPE": "CUL",
2 "TYPE": "Calendar"
2 "TYPE": "ABFALL"
2 "LEDTYPE": "White",
1 "TYPE": "Verkehrsinfo",
1 "TYPE": "UWZ",
1 "TYPE": "telnet",
1 "TYPE": "structure"
1 "TYPE": "speedtest"
1 "TYPE": "Revolt"
1 "TYPE": "PROPLANTA",
1 "TYPE": "MQTT_DEVICE"
1 "TYPE": "MQTT",
1 "TYPE": "LightScene"
1 "TYPE": "JeeLink",
1 "TYPE": "harmony",
1 "TYPE": "FRITZBOX",
1 "TYPE": "freezemon",
1 "TYPE": "fakeRoku",
1 "TYPE": "dash_dhcp"
1 "TYPE": "Dashboard",
1 "TYPE": "CUL_HM"
1 "TYPE": "allowed",
1 "SUBTYPE": "bridge",
real 0m1.666s
user 0m0.500s
sys 0m0.040s
@hauwech: kannst du dieselbe Auswertung bitte bei dir machen.
Hallo erdo,
roland@fhem-nuc:~$ time /opt/fhem/fhem.pl 7072 "jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=TYPE!=CCU-FHEM|ActionDetector|at|notify|statistics|DOIF" | grep 'TYPE":' | sort |uniq -c|sort -nr
156 "TYPE": "CUL_HM",
60 "TYPE": "dummy"
14 "TYPE": "HUEDevice",
9 "TYPE": "fronthemDevice"
8 "TYPE": "LaCrosse",
7 "TYPE": "IT",
5 "TYPE": "FHEMWEB"
4 "TYPE": "structure"
4 "TYPE": "SSCam",
4 "TYPE": "sequence"
4 "TYPE": "PRESENCE"
4 "TYPE": "allowed",
3 "TYPE": "ROOMMATE"
3 "TYPE": "HMUARTLGW",
3 "TYPE": "FHEMWEB",
3 "TYPE": "CUL_HM"
2 "TYPE": "telnet"
2 "TYPE": "SSCamSTRM",
2 "TYPE": "HMCCURPCPROC",
2 "TYPE": "HMCCUDEV",
2 "TYPE": "ENIGMA2",
2 "TYPE": "DbRep",
2 "TYPE": "CUL",
1 "TYPE": "YAMAHA_AVR",
1 "TYPE": "Weather"
1 "TYPE": "Unifi",
1 "TYPE": "Twilight",
1 "TYPE": "telnet",
1 "TYPE": "RESIDENTS"
1 "TYPE": "RandomTimer"
1 "TYPE": "PROPLANTA",
1 "TYPE": "MQTT",
1 "TYPE": "LightScene"
1 "TYPE": "JeeLink",
1 "TYPE": "HUEBridge",
1 "TYPE": "holiday"
1 "TYPE": "HMCCU",
1 "TYPE": "harmony",
1 "TYPE": "GEOFANCY"
1 "TYPE": "freezemon",
1 "TYPE": "FB_CALLMONITOR"
1 "TYPE": "DbLog",
1 "TYPE": "CALVIEW"
1 "TYPE": "Calendar"
1 "TYPE": "Astro",
1 "TYPE": "Alarm",
1 "TYPE": "ABFALL"
real 0m3.996s
user 0m0.268s
sys 0m0.048s
Mit
echo "jsonlist2 TYPE=.*:FILTER=state=..*:FILTER=model!=CCU-FHEM:FILTER=model!=ActionDetector " | nc <fhem-server> 7072
komme ich wie in Beitrag #62 beschrieben:
ZitatWenn ich den output (ohne time) in eine Datei pipe, kommt die auf 2.1MB mit 19.162 Zeilen.
Gruß Roland
ZitatBeispiel ein Wassersensor aus einem Aquarium (habe ich nicht) würde mindestens die Temperatur auswerten und einen entsprechenden Graphen generieren
Das regelmaessige Abfragen aller Werte ist ineffizient, und wenn die Installation groesser wird, dann merkt man das auch.
Das kann man (begrenzt) mit mehr Hardware oder (besser) mit intelligenteren Algorithmen loesen.
FHEM bietet etliche Moeglichkeiten fuer solche Algorithmen an (inform bei telnet, longpoll oder websocket bei HTTP).
Alternativ koennte die externe Instanz die Daten aus dem von FHEM geloggten Dateien oder Datenbanken lesen.
Zitatich weiß vorab nicht welche Geräte/Werte es gibt, im Grunde hole ich alle und Werte im Anschluss nur die Unterstützen aus.
[...]
... nur um ein paar Daten alle X Minuten zu holen.
Ich sehe hier einen gewissen Widerspruch.
Okay stand jetzt ich 3 Lösungsansätze...
- Die auszulesende Attribute manuell in dem Agent pflegen und die Abfrage entsprechend einzuschränken.
- Beim Start eine SQLite DB zu erstellen und diese per Live-Abfrage zu aktualisieren.
- Beim Start alle Daten auszulesen, diese in einen Hash schreiben (passiert jetzt auch schon) und diesen Live zu aktualisieren.
Mein Favorit ist derzeit die 3, hab nur noch keine Idee wie ich das dem CheckMK Agent "unterjubel".
Vielleicht durch Manipulation der Caching-Dateien ...
2/3 sind im Grunde ein weiterer Deamon der parallel läuft ... Ich weiß noch nicht wie begeistert ich davon bin...
Frage: gibt es eine Möglichkeit, dass FHEM die Daten - aufbereitet - in eine Datei schreibt und dort regelmäßig aktualisiert?
Du meinst FileLog?
Im Grunde ja - aber ich fürchte dass die Konfiguration bei jedem Update meines Checks angepasst werden müsste -> und zwar manuell bei allen die ihn einsetzen ...
War nur ein Gedankengang - aktuell weiß ich selbst noch nicht wohin ich möchte ::)
Mir ist noch der Ansatz eines eigenen FHEM-Modules eingefallen, dann könnte ich über das GitHub steuern welche Daten ausgeliefert werden... Das Ganze würde auf deinem jsonlist2 basieren und eben nur die für die Auswertung relevanten Daten liefern. Damit sollte die Auslieferung deutlich schneller gehen.
Das hätte den Vorteil, dass Leute die kein externes Modul einbinden möchten immer noch jsonlist2 einsetzen könnten - und dann mit der Laufzeit leben müssten ;)
Ich denke mit einem Freeze von unter einer Sekunde kann man ganz gut leben.
oder eventuell das ganze via mqtt pushen und dann von check_mk wieder rausholen