FHEM Forum

FHEM => Anfängerfragen => Thema gestartet von: reibuehl am 11 Januar 2014, 18:31:53

Titel: FHEM reagiert teilweise mehrere Sekunden nicht
Beitrag von: reibuehl am 11 Januar 2014, 18:31:53
Ich habe FHEM auf einem RaspberryPI installiert und habe das Problem, dass die Weboberfläche nach einem klick auf einen Link meist bis zu 45 Sekunden braucht. So jeden 4. oder 5. klick geht es dann aber ein oder zwei mal blitzschnell.
Das Verhalten scheint unabhängig von der Art der Aktion zu sein, d.h. egal ob ich nur einen Raum anzeigen will oder ein Kommando absetze und auch gleiche Aktionen gehen mal sehr schnell und mal brauchen sie bis zu 45 Sekunden.
Laut Top ist das System nicht wirklich busy - load average ist immer so zwischen 0.10 und 0.25.

Gibt es eine Möglichkeit, herauszufinden, was diese temporären Verzögerungen auslößt?

Reiner
Titel: Antw:FHEM reagiert teilweise mehrere Sekunden nicht
Beitrag von: marvin78 am 11 Januar 2014, 18:40:37
Ich hatte das Problem auf meinem Pi, als ich DBLog probiert und für die MySQl Daten die SD-Karte verwendet habe. Jetzt habe ich für die MySQl Daten und die Logdatei eine externe USB Festplatte (SSD) angeschlossen und mein Pi läuft wie geschmiert.

Nutzt du DBLog?
Titel: Antw:FHEM reagiert teilweise mehrere Sekunden nicht
Beitrag von: thd am 11 Januar 2014, 18:42:06
Zitat von: Reiner am 11 Januar 2014, 18:31:53
Gibt es eine Möglichkeit, herauszufinden, was diese temporären Verzögerungen auslößt?
Vielleicht wäre strace hilfriech für Dich
sudo apt-get install strace
sudo strace -p $(pidof perl fhem.pl)

Gibt ein log der Kernel-Aufrufe des FHEM-Prozesses aus. Das ist aber sehr schnell sehr viel. Mit

sudo strace -p $(pidof perl fhem.pl) -o /tmp/strace.txt

Wird die Ausgabe in eine Datei /tmp/strace.txt umgeleitet.
Titel: Antw:FHEM reagiert teilweise mehrere Sekunden nicht
Beitrag von: reibuehl am 11 Januar 2014, 18:59:51
Ich verwende nur FileLogs, kein DBLog.

Ich werde es mal mit strace probieren...
Titel: Antw:FHEM reagiert teilweise mehrere Sekunden nicht
Beitrag von: reibuehl am 11 Januar 2014, 19:38:01
Ich hab mal strace gestartet und dann einen Link geklickt. Scheinbar verwendet das System 97% seiner Zeit für zwei "clone" aufrufe:

% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
96.87    0.005200        2600         2           clone
  3.13    0.000168           5        32           read
  0.00    0.000000           0        30           write
  0.00    0.000000           0         1           open
  0.00    0.000000           0         6           close
  0.00    0.000000           0         2         2 kill
  0.00    0.000000           0         2           brk
  0.00    0.000000           0        24        24 ioctl
  0.00    0.000000           0       194           gettimeofday
  0.00    0.000000           0        24        24 _llseek
  0.00    0.000000           0        52           select
  0.00    0.000000           0       119           stat64
  0.00    0.000000           0         2           getdents64
  0.00    0.000000           0        12           fcntl64
  0.00    0.000000           0        12           accept
------ ----------- ----------- --------- --------- ----------------
100.00    0.005368                   514        50 total


Das ganze scheint also wohl eher nicht mit der SD Karte zu tun zu haben, oder?
Titel: Antw:FHEM reagiert teilweise mehrere Sekunden nicht
Beitrag von: herrmannj am 11 Januar 2014, 20:24:49
Hallo Reiner,

welche fhem version ?

vg
Jörg
Titel: Antw:FHEM reagiert teilweise mehrere Sekunden nicht
Beitrag von: reibuehl am 11 Januar 2014, 20:32:34
Hallo Jörg,

die FHEM Version wurde zum letzten Mal gestern per update auf den neuesten Stand gebracht:


# $Id: fhem.pl 4565 2014-01-05 22:17:37Z rudolfkoenig $
# $Id: 00_CUL.pm 4530 2014-01-02 13:56:09Z rudolfkoenig $
# $Id: 09_CUL_FHTTK.pm 4229 2013-11-15 17:29:55Z rudolfkoenig $
# $Id: 10_CUL_HM.pm 4596 2014-01-09 19:16:20Z martinp876 $
# $Id: 57_Calendar.pm 4194 2013-11-09 18:58:18Z borisneubert $
# $Id: 01_FHEMWEB.pm 4586 2014-01-07 11:48:46Z rudolfkoenig $
# $Id: 10_FS20.pm 3764 2013-08-22 07:09:38Z rudolfkoenig $
# $Id: 92_FileLog.pm 4574 2014-01-06 14:12:42Z rudolfkoenig $
# $Id: 00_HMLAN.pm 4562 2014-01-05 15:22:54Z martinp876 $
# $Id: 73_PRESENCE.pm 4342 2013-12-08 09:39:25Z markusbloch $
# $Id: 99_SUNRISE_EL.pm 4537 2014-01-03 08:28:59Z rudolfkoenig $
# $Id: 98_SVG.pm 4503 2013-12-29 18:38:50Z rudolfkoenig $
# $Id: 45_TRX.pm 3784 2013-08-24 19:04:30Z wherzig $
# $Id: 46_TRX_WEATHER.pm 3874 2013-09-08 04:26:07Z wherzig $
# $Id: 99_Utils.pm 3595 2013-08-05 05:38:48Z tobiasfaust $
# $Id: 70_WS3600.pm 4100 2013-10-23 09:22:03Z joes1 $
# $Id: 98_autocreate.pm 4234 2013-11-17 10:19:41Z rudolfkoenig $
# $Id: 98_dummy.pm 3738 2013-08-18 14:13:59Z rudolfkoenig $
# $Id: 91_eventTypes.pm 2982 2013-03-24 17:47:28Z rudolfkoenig $
# $Id: 95_holiday.pm 3602 2013-08-07 13:06:49Z rudolfkoenig $
# $Id: 91_notify.pm 3738 2013-08-18 14:13:59Z rudolfkoenig $
# $Id: 98_telnet.pm 3738 2013-08-18 14:13:59Z rudolfkoenig $


Gruß,
Reiner.
Titel: Antw:FHEM reagiert teilweise mehrere Sekunden nicht
Beitrag von: herrmannj am 11 Januar 2014, 21:17:49
dann kann die dieses modul bei der suche helfen http://forum.fhem.de/index.php/topic,16347.msg106295.html#msg106295.

Den verbose level hochstellen damit du im log was siehst.

vg
jörg
Titel: Antw:FHEM reagiert teilweise mehrere Sekunden nicht
Beitrag von: reibuehl am 11 Januar 2014, 21:46:50
Ich habe das Modul geladen und sehe jetzt auch immer wieder Meldungen über mögliche freezes. Wenn ich im log nachschaue, was zur unter "possibly starting" Zeit drin steht, ist meist Einträge wie diese:

2014.01.11 21:29:21 4: FileLog_OG_Heizung get: Input file ./log/OG_Heizung-2014.log, from:2014-01-11_00:00:00  to:2014-01-12_00:00:01
2014.01.11 21:29:24 4: FileLog_OG_Heizung get: line 1, regexp:OG_BD_Thermostat_ClimRT_tr.measured-temp\x3a, col:3, output lines:89
2014.01.11 21:29:24 4: FileLog_OG_Heizung get: line 2, regexp:OG_BD_Thermostat_ClimRT_tr.ValvePosition\x3a, col:3, output lines:89
...
2014.01.11 21:29:28 1: Perfmon: possible freeze starting at 21:29:22, delay is 6.355


Es scheint meist im Zusammenhang mit FileLog Vorgängen von einem meiner vier HM-CC-RT-DN aufzutreten...
Titel: Antw:FHEM reagiert teilweise mehrere Sekunden nicht
Beitrag von: herrmannj am 11 Januar 2014, 22:03:29
sieht so aus. Kommt das vom laden eines plots ? Wie gross ist das filelog ?

vg
Jörg
Titel: Antw:FHEM reagiert teilweise mehrere Sekunden nicht
Beitrag von: reibuehl am 11 Januar 2014, 22:10:18
Die Hänger scheinen unabhängig davon aufzutreten, ob ich eine Seite mit einem plot aufrufe oder nicht. Das FileLog ist im Moment 288KB groß.
Titel: Antw:FHEM reagiert teilweise mehrere Sekunden nicht
Beitrag von: justme1968 am 11 Januar 2014, 22:48:03
wenn ich das richtig sehe hast du verbose global oder zumindest für das filelog auf 4 stehen. damit schreibt es jede zeile die aus dem log gelesen wird ins fhem log. das sind dann etwa 288k auf einen schlag vor jedem plot.

damit ist zum einen deine sd karte ruck zuck voll und zum anderen dauert es auf einer relativ langsamen sd karte eine weile.

du solltest verbose im normal betrieb höchstens auf 3 stehen haben.

gruss
  andre
Titel: Antw:FHEM reagiert teilweise mehrere Sekunden nicht
Beitrag von: herrmannj am 11 Januar 2014, 22:49:34
hmm, 300kB sind ja nicht die Welt.  Dem log nach liest er aus dem filelog - aber ob das dann wirklich die Ursache ist ???.

Hängt er auch wenn Du nicht per web/telnet/app etc drauf bist ?

vg
jörg
Titel: Antw:FHEM reagiert teilweise mehrere Sekunden nicht
Beitrag von: justme1968 am 11 Januar 2014, 22:55:58
sd karten sind aber zum einen nicht die schnelslten zum anderen wird concurrent das filelog zeilenweise gelesen und das fhem log geschrieben. je nach blockgrösse kann das locker 5 sekunden dauern.

zumindest wäre sehr einfach rauszufinden ob es das ist :)

gruss
  andre
Titel: Antw:FHEM reagiert teilweise mehrere Sekunden nicht
Beitrag von: reibuehl am 11 Januar 2014, 23:01:22
Die Hänger sind auch bei verbose 3 aufgetreten. Verbose 5 habe ich nur heute eingefügt, da Jörg dies für das Debugging mit dem Perfmon Modul empfohlen hat.

Die Perfmon ausgaben kommen auch immer wieder mal, wenn nicht per GUI auf FHEM zugegriffen wird.
Titel: Antw:FHEM reagiert teilweise mehrere Sekunden nicht
Beitrag von: herrmannj am 11 Januar 2014, 23:13:51
kannst Du testweise einzelne Funktionen später evtl Module deaktivieren ?

Neben den filelogs sind die üblichen Verdächtigen auch notifys - mit denen würde ich anfangen.  Notifys kannst Du disablen oder die regex die draufliegt auf irgendwas setzen was nicht kommt, allerdings dann darauf achten die regex einfach ist (damit die regex engine nicht erst lange backtracken muss)

vg
jörg
Titel: Antw:FHEM reagiert teilweise mehrere Sekunden nicht
Beitrag von: wkarl am 12 Januar 2014, 08:58:19
Hallo Reiner,

ein derartiges Perfomance-Problem hatte ich auch mal. Im Netz habe ich dann gelesen, dass der mmcqd Prozess sich als Flaschenhals ergeben kann. Da das System auf einer Partition lief und System-RW, fhem-log-RW und DBLog-RW darüber liefen schien dies mir logisch. Ich habe dann die fhem mit den logs und die die DBLog-DBs jeweils auf eigene Partitions gelegt - /, /opt/fhem und /opt/mysqldb - seitdem ist mein Performance-Problem gelöst.

ciao walter
Titel: Antw:FHEM reagiert teilweise mehrere Sekunden nicht
Beitrag von: reibuehl am 12 Januar 2014, 14:25:32
Zitat von: herrmannj am 11 Januar 2014, 23:13:51
kannst Du testweise einzelne Funktionen später evtl Module deaktivieren ?

Neben den filelogs sind die üblichen Verdächtigen auch notifys - mit denen würde ich anfangen.  Notifys kannst Du disablen oder die regex die draufliegt auf irgendwas setzen was nicht kommt, allerdings dann darauf achten die regex einfach ist (damit die regex engine nicht erst lange backtracken muss)

Ich habe in meiner Konfiguration nur ein Notify. Das habe ich mal auskommentiert, das System verhält sich aber nach wie vor gleich und hängt bei ca. 50% aller Klicks die beschriebenen 30-45 Sekunden.

Ich werde jetzt mal versuchen, /opt/fhem auf einen USB Memorystick zu verlegen. Mal sehen, ob das hilft.
Titel: Antw:FHEM reagiert teilweise mehrere Sekunden nicht
Beitrag von: wkarl am 12 Januar 2014, 16:24:53
Hallo Reiner,
Nur zum sicheren Verständnis. Ich habe eine eigene Partition angelegt und auf /opt/fhem eingehängt. dadurch gibte es einen weiteren mm* Prozess.
Ciao walter
Titel: Antw:FHEM reagiert teilweise mehrere Sekunden nicht
Beitrag von: Smooth am 12 Januar 2014, 16:51:00
Hallo Rainer...

Ich habe genau das gleiche Phänomen.  Bei mir konnte ich MAX dafür ausfindig machen....  Immer wenn die Daten über den Cube kommen hängt das System für einige Sekunden...

Hast du auch MAX in Einsatz?

Viele Grüße
Titel: Antw:FHEM reagiert teilweise mehrere Sekunden nicht
Beitrag von: reibuehl am 12 Januar 2014, 17:44:24
Also MAX verwende ich nicht und verschieben von /opt/fhem auf eine separate, auf einem USB Memory Stick liegende Partition hat auch nichts gebracht.
Titel: Antw:FHEM reagiert teilweise mehrere Sekunden nicht
Beitrag von: det. am 12 Januar 2014, 20:51:24
Hallo Reiner,
Vorschlag zur Radikalkur: nimm eine neue schnelle SD Karte, lade Dir ein aktuelles Debian für Deinen RPI aus dem Netz ( nimm nicht das File, was Du noch auf dem PC gespeichert hast! ), installiere Linux und FHEM neu jeweils mit allen aktuellen Updates. Die fhem.cfg von der bisherigen Installation vorher auf dem PC sichern, die kannst Du wieder einspielen wenn das neue System läuft.
Wenn es geholfen hat, lag es am Betriebssystem und nicht an der Anwendung - wenn nicht - sorry und weitersuchen.