Hey Leute
also ich habe mal wieder eine frage an Euch. Ich habe leider das Problem, das mein Fhem immer wieder Aussetzer hat also in Form von Freez, habe nun mal "perfmon" und dann "apptime" laufen lassen, mir sind da erst mal, wie auf dem Bild zu sehen sind, ein Paar Einträge mit sehr Hoher ms ins Auge gesprungen, meine frage nun an Euch was kann ich machen, um das zu beheben??
Die SD-Karte hatte ich heute schon mal ausgetauscht gegen eine neue und Größere das brachte aber kein Erfolg.
Gruß Caleus
Du siehst nur ein Symptom, nicht die Ursache. Versuch es mal mit freezemon.
Hallo,
der Screenshot ist ein bisschen schlecht zu lesen, besser den Output in code tags posten. Statt perfmon/apptime kannst du auch mal freezemon probieren.
Kann es sein, dass deine Logfiles einfach zu groß sind? Entweder weil sie einen sehr langen Zeitraum beinhalten oder weil du einfach zu viel loggst (Stichwort event-on-change-reading)?
Kurz, weil mobil
Hey danke schon mal
Also so sieht nach kurzer zeit das Freezemon aus:
1 - 2019-01-12: s:12:53:09 e:12:53:14 f:5.022 d:tmr-FW_closeInactiveClients(N/A) tmr-Twilight_Midnight(myTwilight_Midnight) tmr-perfmon_ProcessTimer(N/A)
1 - 2019-01-12: s:12:58:23 e:12:58:34 f:11.041 d:no bad guy found :-(
1 - 2019-01-12: s:12:58:53 e:12:58:59 f:6.271 d:tmr-perfmon_ProcessTimer(N/A)
1 - 2019-01-12: s:13:00:04 e:13:00:14 f:10.588 d:tmr-perfmon_ProcessTimer(N/A)
und log´s sind ja schon eigentlich alle "event-on-change-reading".
Perfmon bitte ausschalten wenn freezemon aktiv ist. Sonst kommt alles doppelt
Kurz, weil mobil
Ja ist jetzt aus, aber leider sind es immer noch recht hohe ms die im Log stehen.
1 - 2019-01-12: s:13:14:00 e:13:14:01 f:1.684 d:tmr-perfmon_ProcessTimer(N/A)
1 - 2019-01-12: s:13:14:35 e:13:14:36 f:1.554 d:tmr-perfmon_ProcessTimer(N/A)
1 - 2019-01-12: s:13:18:46 e:13:18:50 f:4.603 d:tmr-perfmon_ProcessTimer(N/A) tmr-Weather_GetUpdate(MyWeather) tmr-Shelly_status(Bad.Decke.Licht)
1 - 2019-01-12: s:13:21:51 e:13:21:55 f:4.728 d:tmr-perfmon_ProcessTimer(N/A) tmr-Weather_GetUpdate(MyWeather) tmr-Shelly_status(Bad.Decke.Licht)
1 - 2019-01-12: s:13:22:14 e:13:22:15 f:1.569 d:tmr-perfmon_ProcessTimer(N/A)
1 - 2019-01-12: s:13:22:56 e:13:23:00 f:4.787 d:tmr-perfmon_ProcessTimer(N/A) tmr-Weather_GetUpdate(MyWeather) tmr-PRESENCE_StartLocalScan(Patrick) tmr-Shelly_status(Bad.Decke.Licht) tmr-PRESENCE_StartLocalScan(NalaBT)
1 - 2019-01-12: s:13:27:40 e:13:27:44 f:4.574 d:tmr-perfmon_ProcessTimer(N/A)
1 - 2019-01-12: s:13:29:27 e:13:29:31 f:4.8 d:tmr-perfmon_ProcessTimer(N/A) tmr-PRESENCE_StartLocalScan(PatrickBT)
1 - 2019-01-12: s:13:33:02 e:13:33:06 f:4.303 d:tmr-perfmon_ProcessTimer(N/A) tmr-Weather_GetUpdate(MyWeather) tmr-Shelly_status(Bad.Decke.Licht) tmr-PRESENCE_StartLocalScan(Patrick)
1 - 2019-01-12: s:13:37:03 e:13:37:04 f:1.94 d:tmr-perfmon_ProcessTimer(N/A) tmr-SYSMON_Update(sysmon)
1 - 2019-01-12: s:13:40:07 e:13:40:11 f:4.664 d:tmr-perfmon_ProcessTimer(N/A) tmr-Weather_GetUpdate(MyWeather) tmr-Shelly_status(Bad.Decke.Licht) tmr-PRESENCE_StartLocalScan(Larissa)
1 - 2019-01-12: s:13:47:12 e:13:47:14 f:2.872 d:tmr-perfmon_ProcessTimer(N/A) tmr-CometBlueBTLE::StateRequestTimer(Wohnzimmer) tmr-Weather_GetUpdate(MyWeather)
1 - 2019-01-12: s:13:53:58 e:13:54:03 f:5.285 d:tmr-Weather_GetUpdate(MyWeather) tmr-FRITZBOX_Readout_Start(N/A)
1 - 2019-01-12: s:14:02:39 e:14:02:44 f:5.02 d:tmr-PRESENCE_StartLocalScan(PatrickBT) tmr-PRESENCE_StartLocalScan(Nala) tmr-Twilight_Midnight(myTwilight_Midnight)
1 - 2019-01-12: s:14:08:37 e:14:08:38 f:1.239 d:tmr-PRESENCE_StartLocalScan(NalaBT)
1 - 2019-01-12: s:14:10:23 e:14:10:27 f:4.661 d:tmr-PRESENCE_StartLocalScan(NalaBT)
1 - 2019-01-12: s:14:13:49 e:14:13:52 f:3.359 d:tmr-SIGNALduino_KeepAlive(MYSDUINO) tmr-PRESENCE_StartLocalScan(LarissaBT)
1 - 2019-01-12: s:14:21:27 e:14:21:32 f:5.179 d:tmr-PRESENCE_StartLocalScan(LarissaBT)
1 - 2019-01-12: s:14:29:13 e:14:29:17 f:4.125 d:no bad guy found :-(
1 - 2019-01-12: s:14:36:48 e:14:36:52 f:4.084 d:no bad guy found :-(
Caleus
Der Perfmon läuft immernoch. Du musst die Datei umbenennen (so dass sie nicht mit 99 anfängt) oder aus /FHEM entfernen und einen shutdown restart machen, sonst wird perfmon immer wieder geladen
Kurz, weil mobil
Ich hatte sie gelöscht und ein "Shutdown restart" gemacht.
Das muss beim Löschen was shief gegangen sein, bitte überprüfe das nochmal. Die Einträge zeigen eindeutig, dass perfmon noch läuft:
perfmon_ProcessTimer(N/A)
und schonmal auf die Schnelle: Dein MyWeather device aktualisiert sich alle 3 Minuten... das ist ein bisschen arg häufig, zudem dauert es recht lange... hast du in global das Attribut dnsServer gesetzt?
MyWeather ist/war Yahoo und hatte ich vorhin gelöscht, und nein der dnsServer ist im Global nicht gesetzt.
Caleus
dnsServer zu setzen sorgt dafür, dass DNS-Aufrufe non-blocking sind, daher würde ich das empfehlen. Ist der Perfmon jetzt weg? Wie sieht das log jetzt aus?
ja scheint weg zu sein. auf was sollte ich denn dnsServer setzen ?
1 - 2019-01-12: s:15:13:23 e:15:13:28 f:5.039 d:tmr-Twilight_Midnight(myTwilight_Midnight)
1 - 2019-01-12: s:15:14:28 e:15:14:33 f:5.023 d:tmr-Twilight_Midnight(myTwilight_Midnight)
1 - 2019-01-12: s:15:15:33 e:15:15:34 f:1.182 d:tmr-Twilight_Midnight(myTwilight_Midnight)
1 - 2019-01-12: s:15:16:54 e:15:16:55 f:1.063 d:no bad guy found :-(
1 - 2019-01-12: s:15:18:10 e:15:18:14 f:4.954 d:tmr-FW_closeInactiveClients(N/A)
1 - 2019-01-12: s:15:23:21 e:15:23:26 f:5.078 d:no bad guy found :-(
1 - 2019-01-12: s:15:25:07 e:15:25:11 f:4.932 d:tmr-PRESENCE_StartLocalScan(LarissaBT)
1 - 2019-01-12: s:15:31:06 e:15:31:11 f:5.719 d:tmr-PRESENCE_StartLocalScan(NalaBT)
1 - 2019-01-12: s:15:32:48 e:15:32:53 f:5.016 d:tmr-Twilight_WeatherTimerUpdate(myTwilight_Midnight)
1 - 2019-01-12: s:15:35:53 e:15:36:03 f:10.179 d:tmr-PRESENCE_StartLocalScan(PatrickBT) tmr-Twilight_WeatherTimerUpdate(myTwilight_Midnight)
1 - 2019-01-12: s:15:37:06 e:15:37:07 f:1.797 d:tmr-CometBlueBTLE::StateRequestTimer(Bad)
1 - 2019-01-12: s:15:40:29 e:15:40:33 f:4.817 d:tmr-PRESENCE_StartLocalScan(PatrickBT)
1 - 2019-01-12: s:15:49:56 e:15:50:00 f:4.952 d:tmr-PRESENCE_StartLocalScan(PatrickBT)
1 - 2019-01-12: s:15:53:22 e:15:53:23 f:1.254 d:no bad guy found :-(
1 - 2019-01-12: s:16:01:52 e:16:01:56 f:4.333 d:no bad guy found :-(
1 - 2019-01-12: s:16:06:58 e:16:06:59 f:1.89 d:tmr-PRESENCE_StartLocalScan(LarissaBT)
1 - 2019-01-12: s:16:11:16 e:16:11:18 f:2.464 d:tmr-SYSMON_Update(sysmon) tmr-PRESENCE_StartLocalScan(NalaBT)
1 - 2019-01-12: s:16:13:05 e:16:13:09 f:4.853 d:no bad guy found :-(
1 - 2019-01-12: s:16:19:55 e:16:19:59 f:4.496 d:no bad guy found :-(
1 - 2019-01-12: s:16:21:42 e:16:21:46 f:4.692 d:no bad guy found :-(
Caleus
Zitat von: Caleus am 12 Januar 2019, 16:24:21
ja scheint weg zu sein. auf was sollte ich denn dnsServer setzen ?
Caleus
die ip Deiner Fritzbox (oder was auch immer)
Twilight scheint im Minutentakt etwas zu machen.
Für die ,,no bad guy found" bitte Attribut fm_logFile setzen und dann ins Log von freezemon schauen (auf Log in der get freeze Ansicht klicken)
Kurz, weil mobil
Guten Morgen
also ich habe nun mal ein paar logs aufgezeichnet und das letzte von "no bad guy found" wäre das hier
=========================================================
[Freezemon] myFreezemon: possible freeze starting at 05:31:44, delay is 1.242 possibly caused by: no bad guy found :-(
2019.01.13 05:31:43.953 4: : HTTP response code 200
2019.01.13 05:31:43.953 5: HttpUtils : Got data, length: 23
2019.01.13 05:31:43.953 5: HttpUtils response header:
HTTP/1.1 200 OK
Server: nginx/1.12.2
Date: Sun, 13 Jan 2019 04:31:43 GMT
Content-Type: application/json
Content-Length: 23
Connection: close
Access-Control-Allow-Origin: *
Access-Control-Allow-Methods: GET, POST, OPTIONS
Access-Control-Expose-Headers: Content-Length,Content-Type,Date,Server,Connection
Strict-Transport-Security: max-age=31536000; includeSubDomains; preload
2019.01.13 05:31:43.953 5: TelegramBot_Callback HomeBot: called from Polling
2019.01.13 05:31:43.953 5: TelegramBot_Callback HomeBot: data returned :{"ok":true,"result":[]}:
2019.01.13 05:31:43.954 5: TelegramBot_Deepencode HomeBot: encoded a String from :1: to :1:
2019.01.13 05:31:43.954 5: TelegramBot_Deepencode HomeBot: found an ARRAY
2019.01.13 05:31:43.954 5: TelegramBot_Deepencode HomeBot: found a HASH
2019.01.13 05:31:43.954 5: TelegramBot_Callback HomeBot: after encoding
2019.01.13 05:31:43.954 5: TelegramBot_Callback HomeBot: polling returned result? 0
2019.01.13 05:31:43.954 5: UpdatePoll HomeBot: number of results 0
2019.01.13 05:31:43.954 5: TelegramBot_UpdatePoll HomeBot: called
2019.01.13 05:31:43.954 5: TelegramBot_UpdatePoll HomeBot: - Initiate non blocking polling - With callback set
2019.01.13 05:31:43.955 5: TelegramBot_readToken: Read Telegram API token from file
2019.01.13 05:31:43.956 4: TelegramBot_UpdatePoll HomeBot: initiate polling with nonblockingGet with 120s
2019.01.13 05:31:43.956 5: HttpUtils url=
2019.01.13 05:31:43.957 4: IP: api.telegram.org -> 149.154.167.220
2019.01.13 05:31:43.958 5: TelegramBot_UpdatePoll HomeBot: - Ende > next polling started
2019.01.13 05:31:43.958 4: TelegramBot_Callback HomeBot: resulted in SUCCESS from Polling
2019.01.13 05:31:43.958 5: TelegramBot_Callback HomeBot: - Ende > Control back to FHEM
--- log skips 1.283 secs.
2019.01.13 05:31:45.241 5: HttpUtils request header:
GET /bot588317852:AAEF7WqdNa97iPKMLCVu6yVrrW9gVFOzVm4/getUpdates?offset=11174092&limit=5&timeout=120 HTTP/1.0
Host: api.telegram.org
Accept-Encoding: gzip,deflate
agent: TelegramBot/1.0
User-Agent: TelegramBot/1.0
Accept: application/json
Accept-Charset: utf-8
2019.01.13 05:31:45.242 5: [Freezemon] myFreezemon: ----------- Starting Freeze handling at 2019.01.13 05:31:45.242 ---------------------
[Freezemon] myFreezemon: possible freeze starting at 05:31:44, delay is 1.242 possibly caused by: no bad guy found :-(
Caleus
Hmmm... da kann man gut sehen, dass der TelegramBot erfolgreich gepollt hat und FHEM dann erstmal ein Weilchen nichts mehr macht -zumindest keine Logeinträge mehr schreibt, d.h. es wird irgendetwas verarbeitet.
Wenn du die Catch*-Attribute noch aktivierdt, finder man möglicherweise mehr Details.
Freezemon kann leider nur Hinweise geben, wer einen Freeze verursacht hat. Das ,,warum" ist dann Handarbeit :-(
global dnsServer hattest du gesetzt, oder?
Kurz, weil mobil
Ja also global dnsServer habe ich nun gestern gesetzt auf die Fritzbox IP, welche Einstellung für fm_CatchCmds
und fm_CatchFnCalls soll es den sein 0 bis 5 habe ich ?
Caleus
0 bedeutet inaktiv, alles größer 0 bedeautet aktiv und gibt den Loglevel an... also 3 oder so...
Kurz, weil mobil
so hier mal ein log mit gestztem fm_CatchCmds und fm_CatchFnCalls beides auf 5 (hoffe ich)
=========================================================
[Freezemon] myFreezemon: possible freeze starting at 14:07:51, delay is 4.376 possibly caused by: no bad guy found :-(
2019.01.13 14:07:50.048 4: : HTTP response code 200
2019.01.13 14:07:50.048 5: HttpUtils : Got data, length: 23
2019.01.13 14:07:50.048 5: HttpUtils response header:
HTTP/1.1 200 OK
Server: nginx/1.12.2
Date: Sun, 13 Jan 2019 13:07:50 GMT
Content-Type: application/json
Content-Length: 23
Connection: close
Access-Control-Allow-Origin: *
Access-Control-Allow-Methods: GET, POST, OPTIONS
Access-Control-Expose-Headers: Content-Length,Content-Type,Date,Server,Connection
Strict-Transport-Security: max-age=31536000; includeSubDomains; preload
2019.01.13 14:07:50.049 5: TelegramBot_Callback HomeBot: called from Polling
2019.01.13 14:07:50.049 5: TelegramBot_Callback HomeBot: data returned :{"ok":true,"result":[]}:
2019.01.13 14:07:50.049 5: TelegramBot_Deepencode HomeBot: found an ARRAY
2019.01.13 14:07:50.049 5: TelegramBot_Deepencode HomeBot: encoded a String from :1: to :1:
2019.01.13 14:07:50.049 5: TelegramBot_Deepencode HomeBot: found a HASH
2019.01.13 14:07:50.049 5: TelegramBot_Callback HomeBot: after encoding
2019.01.13 14:07:50.049 5: TelegramBot_Callback HomeBot: polling returned result? 0
2019.01.13 14:07:50.049 5: UpdatePoll HomeBot: number of results 0
2019.01.13 14:07:50.050 5: TelegramBot_UpdatePoll HomeBot: called
2019.01.13 14:07:50.050 5: TelegramBot_UpdatePoll HomeBot: - Initiate non blocking polling - With callback set
2019.01.13 14:07:50.051 5: TelegramBot_readToken: Read Telegram API token from file
2019.01.13 14:07:50.052 4: TelegramBot_UpdatePoll HomeBot: initiate polling with nonblockingGet with 120s
2019.01.13 14:07:50.052 5: HttpUtils url=
2019.01.13 14:07:50.053 4: IP: api.telegram.org -> 149.154.167.220
2019.01.13 14:07:50.054 5: TelegramBot_UpdatePoll HomeBot: - Ende > next polling started
2019.01.13 14:07:50.054 4: TelegramBot_Callback HomeBot: resulted in SUCCESS from Polling
2019.01.13 14:07:50.054 5: TelegramBot_Callback HomeBot: - Ende > Control back to FHEM
2019.01.13 14:07:50.073 4: GHoma_d33aa0 RX: 5A A5 00 16 90 01 0A E0 35 23 D3 3A A0 FF FE 01 81 39 00 00 01 01 20 00 02 90 13 5B B5
2019.01.13 14:07:50.080 5: rg_battery: not on any display, ignoring notify
2019.01.13 14:07:50.088 5: End notify loop for GHoma_d33aa0
--- log skips 5.287 secs.
2019.01.13 14:07:55.375 5: HttpUtils request header:
GET /bot588317852:AAEF7WqdNa97iPKMLCVu6yVrrW9gVFOzVm4/getUpdates?offset=11174092&limit=5&timeout=120 HTTP/1.0
Host: api.telegram.org
Accept-Encoding: gzip,deflate
agent: TelegramBot/1.0
User-Agent: TelegramBot/1.0
Accept: application/json
Accept-Charset: utf-8
2019.01.13 14:07:55.376 5: [Freezemon] myFreezemon: ----------- Starting Freeze handling at 2019.01.13 14:07:55.376 ---------------------
[Freezemon] myFreezemon: possible freeze starting at 14:07:51, delay is 4.376 possibly caused by: no bad guy found :-(
Caleus
Hat keiner eine Idee?