Neues Modul: Performance Monitor

Begonnen von herrmannj, 10 November 2013, 12:49:13

Vorheriges Thema - Nächstes Thema

P.A.Trick

Frage: Kann ich perfmon auch deaktivieren wenn ich es nicht mehr benötige oder muss ich deinstallieren?
Cubietruck,RPI,QNAP Ts-419p+, FS20, FRITZ!DECT200, 7 MAX! Thermostate, 3 MAX! Fensterkontakte, Kodi, CUL V3.3, EM1000S, LW12, LD382, HUE, HM-CFG-USB-2, 1x HM-LC-SW1-FM, 2x HM-LC-SW2-FM, 2x HM-LC-Sw1PBU-FM, 3xHM-LC-Bl1PBU-FM,HM-SEC-RHS, 2xHM-SEC-SD,HM-WDS30-T-O, 3x HM-LC-Dim1TPBU-FM, RPI+AddOn

herrmannj

deinstallieren (löschen). Oder laufen lassen, frisst kaum Brot

vg
Jörg



P.A.Trick

Cubietruck,RPI,QNAP Ts-419p+, FS20, FRITZ!DECT200, 7 MAX! Thermostate, 3 MAX! Fensterkontakte, Kodi, CUL V3.3, EM1000S, LW12, LD382, HUE, HM-CFG-USB-2, 1x HM-LC-SW1-FM, 2x HM-LC-SW2-FM, 2x HM-LC-Sw1PBU-FM, 3xHM-LC-Bl1PBU-FM,HM-SEC-RHS, 2xHM-SEC-SD,HM-WDS30-T-O, 3x HM-LC-Dim1TPBU-FM, RPI+AddOn

blueberry63

Hallo,

ich würde gerne die Meldungen von "perfmon" in DBLog schreiben. Ich habe den Thread gelesen, aber nichts gefunden, was mir weiterhilft. Oder ist es so einfach, daß ich vor lauter Bäumen den Wald nicht sehe?

Gruß
Blueberry63
FHEM auf BBB mit Wheezy: 1x CUL_HM_HM_SCI_3_FM, 1x INSTAR CAM3010, 1x HM-LC-SW1-PL2, 1x HM-LC-Bl1PBU-FM, 1x HM-Sen-MDIR-O, Viessmann Heizung, Gaszähler via GPIO, Klingel via HM-LC-Bl1PBU-FM an FBox, Mailcheck, AVR, XBMC, NanoCUL 433+668 an Raspi per Ethernet, Funksteckdosen (Pollin, IT), Automower

Tobias

Wenn es readings gibt werden diese automatisch weg geschrieben in die dB. Ansonsten kannst du per notify o.a. die interne  dblog_push Methode benutzen.

Gesendet von meinem ALCATEL ONE TOUCH 997D mit Tapatalk

Maintainer: Text2Speech, TrashCal, MediaList

Meine Projekte: https://github.com/tobiasfaust
* PumpControl v2: allround Bewässerungssteuerung mit ESP und FHEM
* Ein Modbus RS485 zu MQTT Gateway für SolarWechselrichter

AHA1805

Hallo
habe das Modul jetzt auch mal kurzer Hand getestet.


5 16:05:35 2: NONE
2014.04.15 16:05:35 0: Server started with 306 defined entities (version $Id: fhem.pl 5340 2014-03-27 16:19:53Z rudolfkoenig $, os linux, user fhem, pid 1918)
2014.04.15 16:05:35 1: Perfmon: possible freeze starting at 16:05:23, delay is 12.863
2014.04.15 16:05:40 3: Device DEV_SW_Briefkasten added to ActionDetector with 028:00 time
2014.04.15 16:05:40 3: Device DEV_bd_Heizung added to ActionDetector with 000:10 time
2014.04.15 16:05:40 3: Device DEV_ke_Heizung added to ActionDetector with 000:10 time
2014.04.15 16:05:40 3: Device DEV_wc_Heizung added to ActionDetector with 000:10 time
2014.04.15 16:05:40 3: Device DEV_wz_Heizung added to ActionDetector with 000:10 time
2014.04.15 16:05:40 3: Device DEV_wz_Heizung_TC added to ActionDetector with 000:10 time
2014.04.15 16:05:40 3: Device TH_Aus added to ActionDetector with 000:10 time
2014.04.15 16:05:40 3: Device TH_Inn added to ActionDetector with 000:10 time
2014.04.15 16:05:40 3: Device bd_sw_Fenster added to ActionDetector with 028:00 time
2014.04.15 16:05:40 3: Device eg_sw_Tuer added to ActionDetector with 028:00 time
2014.04.15 16:05:40 3: Device ke_Wassermelder added to ActionDetector with 028:00 time
2014.04.15 16:05:40 3: Device le_Rauchmelder added to ActionDetector with 028:00 time
2014.04.15 16:05:41 3: Device lu_Rauchmelder added to ActionDetector with 028:00 time
2014.04.15 16:05:41 3: Device po_smoke_2 added to ActionDetector with 028:00 time
2014.04.15 16:05:41 3: Device po_sw_Fenster added to ActionDetector with 028:00 time
2014.04.15 16:05:41 3: Device wc_sw_Fenster added to ActionDetector with 028:00 time
2014.04.15 16:05:41 3: Device wz_sw_tresen added to ActionDetector with 028:00 time
2014.04.15 16:05:41 1: Perfmon: possible freeze starting at 16:05:36, delay is 5.721
2014.04.15 16:05:53 1: OWCOUNT: model attribute of ow_Counter set to DS2423eold because no memory found
2014.04.15 16:05:55 1: HMLAN_Parse: HMLAN1 new condition ok
2014.04.15 16:05:55 1: Perfmon: possible freeze starting at 16:05:42, delay is 13.097
2014.04.15 16:05:55 3: CUL_HM set DEV_az_Powerbox statusRequest
2014.04.15 16:05:59 1: OWX: 1-Wire devices found on bus OWio1 (ow_2,ow_1,ow_3,ow_m,ow_Counter)
2014.04.15 16:05:59 1: Perfmon: possible freeze starting at 16:05:56, delay is 3.979
2014.04.15 16:06:00 3: CUL_HM set DEV_ku_Schrank statusRequest
2014.04.15 16:06:01 3: CUL_HM set DEV_wz_Licht_CT statusRequest
2014.04.15 16:06:02 3: CUL_HM set DEV_wz_Licht_Tresen statusRequest
2014.04.15 16:06:03 3: CUL_HM set DEV_wz_Steckdose_Terasse statusRequest
2014.04.15 16:06:04 3: CUL_HM set eg_Km_Tuer statusRequest
2014.04.15 16:06:05 3: CUL_HM set ke_Licht_Treppenhaus statusRequest
2014.04.15 16:06:06 3: CUL_HM set ku_Licht_Decke statusRequest
2014.04.15 16:06:07 3: CUL_HM set le_Rauchmelder statusRequest
2014.04.15 16:06:08 3: CUL_HM set lu_Rauchmelder statusRequest
2014.04.15 16:06:09 3: CUL_HM set po_1k_0237444 statusRequest
2014.04.15 16:06:10 3: CUL_HM set po_SW2_KEQ0254147 statusRequest
2014.04.15 16:06:11 3: CUL_HM set po_smoke_2 statusRequest
2014.04.15 16:06:12 3: CUL_HM set po_sw_KEQ0237448 statusRequest
2014.04.15 16:06:13 3: CUL_HM set wz_Licht_Eingang statusRequest
2014.04.15 16:06:14 3: CUL_HM set wz_Licht_Vitrine statusRequest
2014.04.15 16:10:43 1: Perfmon: possible freeze starting at 16:10:42, delay is 1.04
2014.04.15 16:10:46 1: Perfmon: possible freeze starting at 16:10:44, delay is 2.584


Das System ist beim starten schon ganz schön am kämpfen.

Gruß Hannes

Gesendet von Unterwegs mit Tapatalk 4

AHA 1805 RIP 29.08.2016 --> RUHE IN FRIEDEN
In Gedanken Bei dir HANNES
Dein Bruder Gerd (Inputsammler) Vermisst dich Hannes (AHA1805)

Joachim

Das System hat nicht zu kämpfen, nur OWX macht bei jedem Neustart eine komplette Suche auf dem Bus, die physikalisch diese Zeit benötigt, da es eine serielle Kommunikation ist, und OWX das System erst wieder freigibt, wenn die Suche beendet ist.

Gruß Joachim
FHEM aktuellste Version auf FB 7570 und 7390 mit Zebradem Toolbox Freetz
FHEM auf Raspberry
1-Wire mit LinkUSBi und Rs-Pi ds2482-800  1-Wire-9 Board; Max mit Cube, HMLAN
div. 1-Wire Sensoren; MAX-Thermostaten; Homematic-Komponenten, Zehnder KWL über RS-232

Navigator

#52
Mahlzeit...

dank des Moduls konnte ich ein einziges Freeze ausmachen und zwar beim abschicken einer Mail über sendEmail. Eingerichtet ist die ganze Sache über die 99_myUtils, wie in der Wiki beschrieben. Kann ich hier noch Hand anlegen oder besteht deswegen keine Optimierungsbedarf.

2014.05.12 12:47:30 1: sendEmail returned: May 12 12:47:30 cubietruck sendEmail[17781]: Email was sent successfully!
2014.05.12 12:47:30 1: Perfmon: possible freeze starting at 12:47:29, delay is 1.285
Gruß aus Sachsen. FHEM auf Cubietruck. Vormals EZControl XS1 User.

herrmannj

Hi Dittel,

die "pause" ist so gering (und vermutlich auch selten). Da wäre ich jetzt völlig unbesorgt.

vg
Jörg

Tobias

was ist eigentlich der Unterschied zu 99_wdUtils.pm und 99_perfmon.pm?

Wie ist der Königsweg um den Freezes mit einem relativ vollen FHEM-Produktivsystem auf die Spur zu kommen? Ein globales verbose=5?
Maintainer: Text2Speech, TrashCal, MediaList

Meine Projekte: https://github.com/tobiasfaust
* PumpControl v2: allround Bewässerungssteuerung mit ESP und FHEM
* Ein Modbus RS485 zu MQTT Gateway für SolarWechselrichter

herrmannj

Hi Tobias,

perfmon ist die Weiterentwicklung, ist aktuell.

ZitatWie ist der Königsweg um den Freezes mit einem relativ vollen FHEM-Produktivsystem auf die Spur zu kommen? Ein globales verbose=5?
am Ende: ja -> shit Arbeit.

Erstmal ist es (denk ich) wichtig vom "gefühlten es klemmt" zu belastbaren Angaben über Hänger zu kommen. Primär dafür ist perfmon da.

Mit Chance schaffst Du es mithilfe von perfmon und geringerem verbose Ursache und Wirkung in Zusammenhang zu bringen. Also zB: Modul A schreibt ins log das es Daten von einem device/Dienst holt, gleichzeitig / kurz danach auftretender freeze: Modul liest blockend. Die dicken Dinger bekommt man so.

Teilweise treten kleine freeze aber bei mir auch in der normalen event loop auf, teilweise halt auch fhem Design.

Wenn Du tiefer rein musst ist apptime gut, danach hilft nur noch perl profiling ...

viel Glück  ;)
Jörg

Tobias

#56
vielen dank. Habe jetzt 99_wdutils gelöscht und stattdessen 99_perfmon eingebaut.
Ein global verbose 5 erzeugt schon arg viel Logs...Jetzt muss ich noch den kleinen und großen Freezes auf die Spur kommen...

Edit: ist das zb eine Auswirkung von blockierendem 1wire?
2014.06.15 07:17:59.907 5: TRX_Read END
2014.06.15 07:18:01.244 5: Triggering 1wire_Hub_1 (71969 changes)
2014.06.15 07:18:01.244 5: A: 0.344 V B: 4.472 V C: 0.495 V D: 4.501 V
2014.06.15 07:18:01.245 1: Perfmon: possible freeze starting at 07:18:00, delay is 1.245
Maintainer: Text2Speech, TrashCal, MediaList

Meine Projekte: https://github.com/tobiasfaust
* PumpControl v2: allround Bewässerungssteuerung mit ESP und FHEM
* Ein Modbus RS485 zu MQTT Gateway für SolarWechselrichter

herrmannj

#57
schönes Ding  :) & schwer zu sagen

Ich glaube aber eher nicht, ich denke das liegt vor dem 1wire. TRX wäre möglich: erzeugt bei mir auch manchmal delays, fast "out-of-the-blue".

fhem und die module loggen ja "leider" auch nicht alles. Irgendwann nach 07:17:00 ist mindestens TRX aktiv gewesen. Zwischen "TRX_Read_END" und "Triggering 1wire..." war fhem auch mit "irgendwas" beschäftigt, womit sieht man nicht im log aber es hat den perfmon Aufruf verhindert. 1one (danach) sieht mir mit 1ms sogar extrem fix aus.

Ich hab einige von diesen "mini freeze" untersucht und dabei festgestellt das es oft keine single source gibt sondern halt einfach modul a xxx ms braucht das event zu processen, dann die eigenen notifys kommen, dann filellog kommt usw. Wenn dann gleichzeitig noch ein zweites oder drittes event reinkommt dann ist es eben so.

Als Ergebnis hab ich dann überall wo möglich/sinnvoll event-on-xxx draufgesetzt, das loggen minimiert, in eigenen notifys alle regex überarbeitet, diesen fhem "eventsammler" (weiß grad nicht wie der heist) abgeschaltet usw. Außerdem alle Module aussortiert die blockend lesen (die bekommt man mit perfmon schön zu fassen)

Das bringt einiges, die freeze sind schon selten, der Rest ist imho eben "by-design".

edith: vor allem die blockenden Module die lange freeze erzeugen. Diese 1200ms Dinger sind gerade noch so tolerierbar (PIR-> licht oder Schalter auf Licht oder so ist aber eben die Grenze...)

vg
jörg

Spezialtrick

Hallo zusammen. :)

Ich habe das Modul heute auch mal ausprobiert, weil ich häufiger das Problem habe, dass Befehle von FHEM nicht ausgeführt werden. Und es sieht grausam aus. Wenn ich alles richtig deutet, hängt mein FHEM mindestens einmal pro Minute. Nachfolgend ein Auszug aus meinem Log:

Zitat2014.07.09 09:18:00 1: Perfmon: possible freeze starting at 09:17:57, delay is 3.012
2014.07.09 09:19:03 1: Perfmon: possible freeze starting at 09:19:00, delay is 3.048
2014.07.09 09:20:06 1: Perfmon: possible freeze starting at 09:20:03, delay is 3.008
2014.07.09 09:21:09 1: Perfmon: possible freeze starting at 09:21:06, delay is 3.017
2014.07.09 09:21:37 1: Perfmon: possible freeze starting at 09:21:36, delay is 1.128
2014.07.09 09:22:12 1: Perfmon: possible freeze starting at 09:22:09, delay is 3.002
2014.07.09 09:23:14 1: Perfmon: possible freeze starting at 09:23:11, delay is 3.012
2014.07.09 09:24:17 1: Perfmon: possible freeze starting at 09:24:14, delay is 3.017
2014.07.09 09:25:20 1: Perfmon: possible freeze starting at 09:25:17, delay is 3.017
2014.07.09 09:26:23 1: Perfmon: possible freeze starting at 09:26:20, delay is 3.028
2014.07.09 09:26:37 1: Perfmon: possible freeze starting at 09:26:36, delay is 1.128
2014.07.09 09:26:43 1: Perfmon: possible freeze starting at 09:26:42, delay is 1.125
2014.07.09 09:27:26 1: Perfmon: possible freeze starting at 09:27:23, delay is 3.028
2014.07.09 09:28:29 1: Perfmon: possible freeze starting at 09:28:26, delay is 3.012
2014.07.09 09:29:32 1: Perfmon: possible freeze starting at 09:29:29, delay is 3.018
2014.07.09 09:30:00 1: Perfmon: possible freeze starting at 09:29:58, delay is 2.104
2014.07.09 09:30:35 1: Perfmon: possible freeze starting at 09:30:32, delay is 3.017
2014.07.09 09:31:38 1: Perfmon: possible freeze starting at 09:31:35, delay is 3.002
2014.07.09 09:32:41 1: Perfmon: possible freeze starting at 09:32:38, delay is 3.017
2014.07.09 09:33:44 1: Perfmon: possible freeze starting at 09:33:41, delay is 3.017
2014.07.09 09:34:47 1: Perfmon: possible freeze starting at 09:34:44, delay is 3.017
2014.07.09 09:35:02 1: Perfmon: possible freeze starting at 09:35:01, delay is 1.257
2014.07.09 09:35:50 1: Perfmon: possible freeze starting at 09:35:47, delay is 3.017
2014.07.09 09:36:39 1: Perfmon: possible freeze starting at 09:36:38, delay is 1.13
2014.07.09 09:36:43 1: Perfmon: possible freeze starting at 09:36:42, delay is 1.126
2014.07.09 09:36:46 1: Perfmon: possible freeze starting at 09:36:45, delay is 1.129
2014.07.09 09:36:53 1: Perfmon: possible freeze starting at 09:36:50, delay is 3.012
2014.07.09 09:37:56 1: Perfmon: possible freeze starting at 09:37:53, delay is 3.008
2014.07.09 09:38:59 1: Perfmon: possible freeze starting at 09:38:56, delay is 3.017
2014.07.09 09:40:02 1: Perfmon: possible freeze starting at 09:39:59, delay is 3.012
2014.07.09 09:40:04 1: Perfmon: possible freeze starting at 09:40:03, delay is 1.819
2014.07.09 09:41:05 1: Perfmon: possible freeze starting at 09:41:02, delay is 3.362
2014.07.09 09:41:43 1: Perfmon: possible freeze starting at 09:41:42, delay is 1.127
2014.07.09 09:41:46 1: Perfmon: possible freeze starting at 09:41:45, delay is 1.128
2014.07.09 09:42:08 1: Perfmon: possible freeze starting at 09:42:05, delay is 3.012
2014.07.09 09:43:11 1: Perfmon: possible freeze starting at 09:43:08, delay is 3.017
2014.07.09 09:44:14 1: Perfmon: possible freeze starting at 09:44:11, delay is 3.017
2014.07.09 09:45:06 1: Perfmon: possible freeze starting at 09:45:05, delay is 1.877
2014.07.09 09:45:17 1: Perfmon: possible freeze starting at 09:45:14, delay is 3.012
2014.07.09 09:46:20 1: Perfmon: possible freeze starting at 09:46:17, delay is 3.017
2014.07.09 09:46:39 1: Perfmon: possible freeze starting at 09:46:38, delay is 1.129
2014.07.09 09:46:46 1: Perfmon: possible freeze starting at 09:46:45, delay is 1.127
2014.07.09 09:47:23 1: Perfmon: possible freeze starting at 09:47:20, delay is 3.032
2014.07.09 09:48:26 1: Perfmon: possible freeze starting at 09:48:23, delay is 3.012
2014.07.09 09:49:29 1: Perfmon: possible freeze starting at 09:49:26, delay is 3.018
2014.07.09 09:50:08 1: Perfmon: possible freeze starting at 09:50:07, delay is 1.979
2014.07.09 09:50:32 1: Perfmon: possible freeze starting at 09:50:29, delay is 3.007
2014.07.09 09:51:35 1: Perfmon: possible freeze starting at 09:51:32, delay is 3.002
2014.07.09 09:51:39 1: Perfmon: possible freeze starting at 09:51:38, delay is 1.128
2014.07.09 09:52:38 1: Perfmon: possible freeze starting at 09:52:35, delay is 3.017
2014.07.09 09:53:41 1: Perfmon: possible freeze starting at 09:53:38, delay is 3.012
2014.07.09 09:54:44 1: Perfmon: possible freeze starting at 09:54:41, delay is 3.012
2014.07.09 09:55:10 1: Perfmon: possible freeze starting at 09:55:09, delay is 1.987
2014.07.09 09:55:47 1: Perfmon: possible freeze starting at 09:55:44, delay is 3.012
2014.07.09 09:56:39 1: Perfmon: possible freeze starting at 09:56:38, delay is 1.129
2014.07.09 09:56:43 1: Perfmon: possible freeze starting at 09:56:42, delay is 1.126
2014.07.09 09:56:46 1: Perfmon: possible freeze starting at 09:56:45, delay is 1.131
2014.07.09 09:56:50 1: Perfmon: possible freeze starting at 09:56:47, delay is 3.012
2014.07.09 09:57:53 1: Perfmon: possible freeze starting at 09:57:50, delay is 3.017
2014.07.09 09:58:56 1: Perfmon: possible freeze starting at 09:58:53, delay is 3.012
2014.07.09 09:59:59 1: Perfmon: possible freeze starting at 09:59:56, delay is 3.012
2014.07.09 10:00:13 1: Perfmon: possible freeze starting at 10:00:11, delay is 2.042
2014.07.09 10:01:02 1: Perfmon: possible freeze starting at 10:00:59, delay is 3.012
2014.07.09 10:02:05 1: Perfmon: possible freeze starting at 10:02:02, delay is 3.237
2014.07.09 10:03:08 1: Perfmon: possible freeze starting at 10:03:05, delay is 3.017
2014.07.09 10:04:11 1: Perfmon: possible freeze starting at 10:04:08, delay is 3.012
2014.07.09 10:05:14 1: Perfmon: possible freeze starting at 10:05:11, delay is 3.007
2014.07.09 10:05:16 1: Perfmon: possible freeze starting at 10:05:15, delay is 1.406
2014.07.09 10:06:17 1: Perfmon: possible freeze starting at 10:06:14, delay is 3.012
2014.07.09 10:07:20 1: Perfmon: possible freeze starting at 10:07:17, delay is 3.017
2014.07.09 10:08:23 1: Perfmon: possible freeze starting at 10:08:20, delay is 3.011
2014.07.09 10:09:26 1: Perfmon: possible freeze starting at 10:09:23, delay is 3.017
2014.07.09 10:10:18 1: Perfmon: possible freeze starting at 10:10:17, delay is 1.459
2014.07.09 10:10:29 1: Perfmon: possible freeze starting at 10:10:26, delay is 3.017
2014.07.09 10:11:32 1: Perfmon: possible freeze starting at 10:11:29, delay is 3.012
2014.07.09 10:11:39 1: Perfmon: possible freeze starting at 10:11:38, delay is 1.13
2014.07.09 10:11:46 1: Perfmon: possible freeze starting at 10:11:45, delay is 1.131
2014.07.09 10:12:35 1: Perfmon: possible freeze starting at 10:12:32, delay is 3.017
2014.07.09 10:13:38 1: Perfmon: possible freeze starting at 10:13:35, delay is 3.012
2014.07.09 10:14:41 1: Perfmon: possible freeze starting at 10:14:38, delay is 3.018
2014.07.09 10:15:20 1: Perfmon: possible freeze starting at 10:15:19, delay is 1.612
2014.07.09 10:15:44 1: Perfmon: possible freeze starting at 10:15:41, delay is 3.017
2014.07.09 10:16:47 1: Perfmon: possible freeze starting at 10:16:44, delay is 3.002
2014.07.09 10:17:50 1: Perfmon: possible freeze starting at 10:17:47, delay is 3.012
2014.07.09 10:18:53 1: Perfmon: possible freeze starting at 10:18:50, delay is 3.017

Woran kann das liegen und wie finde ich den/die Übeltäter?
FHEM - Debmatic - Zigbee2MQTT - Homekit

herrmannj

Hi,

richtig. Die 3 Sekunden Dinger kommen exakt jede Minute (plus 3 Sekunden).

Schritt 1: kurz überdenken welches Deiner Module "jede Minute irgendwas pollen" könnte. Wird eher ein "Exot" (sorry) sein.
sonst
Schritt 2: (global) verbose hochsetzen und schauen ob das betreffende Modul anhand von Einträgen im log identifiziert werden kann.
sonst
Schritt 3: Modul für Modul disablen (oder entfernen) bis die Meldungen verschwinden.

vg
Jörg