[wiregate] "Power"-Plugins -> wiregated.pl Neustart

[JuMi2006]

Ich kämpfe seit einiger Zeit mit der Stabilität meines Wiregates.
Ein paar Plugins hatte ich für Probleme in Verdacht und zeitweise deaktiviert.
So war das Squeezebox-Plugin was den Speicherbedarf des wiregated.pl ein richtiger Speicherfresser.
Logitechmediaserver und Squeezebox-Plugin sind schon eine Weile deaktiviert.

Daneben ist mein Plugin "Zirklulationspumpe" -> Hier auch so ein Speicherfresser.
Nun hab ich den Neustart mal im Log untersucht (siehe unten) und stelle fest dass sowohl wiregated als eibd für gute 20 Minuten nicht laufen oder ständig neu gestartet werden.

Woran liegt das ?

Sep 10 20:35:44 wiregate403 monit[2985]: 'localhost' loadavg(1min) of 4.1 matches resource limit [loadavg(1min)>4.0]
Sep 10 20:36:44 wiregate403 monit[2985]: 'localhost' loadavg(5min) of 2.3 matches resource limit [loadavg(5min)>2.0]
Sep 10 20:36:44 wiregate403 monit[2985]: 'localhost' resource passed
Sep 10 20:36:44 wiregate403 monit[2985]: 'eibd' loadavg(5min) of 2.3 matches resource limit [loadavg(5min)>2.0]
Sep 10 20:37:44 wiregate403 monit[2985]: 'localhost' loadavg(5min) of 2.5 matches resource limit [loadavg(5min)>2.0]
Sep 10 20:37:44 wiregate403 monit[2985]: 'eibd' loadavg(5min) of 2.5 matches resource limit [loadavg(5min)>2.0]
Sep 10 20:37:44 wiregate403 monit[2985]: 'eibd' trying to restart
Sep 10 20:37:44 wiregate403 monit[2985]: 'eibd' stop: /etc/init.d/eibd
Sep 10 20:37:45 wiregate403 /usr/sbin/wiregated.pl: INFO - eibd connection lost - retrying
Sep 10 20:37:51 wiregate403 monit[2985]: 'eibd' start: /etc/init.d/eibd
Sep 10 20:37:52 wiregate403 init: Id "log9" respawning too fast: disabled for 5 minutes
Sep 10 20:38:51 wiregate403 monit[2985]: 'wiregated.alive' timestamp test failed for /tmp/wiregated.alive
Sep 10 20:38:51 wiregate403 monit[2985]: 'localhost' loadavg(5min) of 2.8 matches resource limit [loadavg(5min)>2.0]
Sep 10 20:38:51 wiregate403 monit[2985]: 'eibd' loadavg(5min) of 2.8 matches resource limit [loadavg(5min)>2.0]
Sep 10 20:38:51 wiregate403 monit[2985]: 'eibd' trying to restart
Sep 10 20:38:51 wiregate403 monit[2985]: 'eibd' stop: /etc/init.d/eibd
Sep 10 20:39:08 wiregate403 /usr/sbin/wiregated.pl: INFO - *** reading config
Sep 10 20:39:22 wiregate403 monit[2985]: 'eibd' start: /etc/init.d/eibd
Sep 10 20:39:28 wiregate403 collectd[2584]: processes plugin: Failed to open `/proc/1911/cmdline': No such file or directory.
Sep 10 20:40:23 wiregate403 monit[2985]: 'wiregated.pl' process PID changed to 1037
Sep 10 20:40:23 wiregate403 monit[2985]: 'wiregated.alive' timestamp test failed for /tmp/wiregated.alive
Sep 10 20:40:23 wiregate403 monit[2985]: 'localhost' loadavg(5min) of 3.8 matches resource limit [loadavg(5min)>2.0]
Sep 10 20:40:23 wiregate403 monit[2985]: 'localhost' loadavg(1min) of 6.3 matches resource limit [loadavg(1min)>4.0]
Sep 10 20:40:23 wiregate403 monit[2985]: 'eibd' loadavg(5min) of 3.8 matches resource limit [loadavg(5min)>2.0]
Sep 10 20:40:23 wiregate403 monit[2985]: 'eibd' trying to restart
Sep 10 20:40:23 wiregate403 monit[2985]: 'eibd' stop: /etc/init.d/eibd
Sep 10 20:40:29 wiregate403 collectd[2584]: processes plugin: Failed to open `/proc/5750/cmdline': No such file or directory.
Sep 10 20:40:29 wiregate403 monit[2985]: 'eibd' start: /etc/init.d/eibd
Sep 10 20:40:37 wiregate403 /usr/sbin/wiregated.pl: INFO - *** reading config
Sep 10 20:40:37 wiregate403 /usr/sbin/wiregated.pl: INFO - connected to eibd local:/tmp/eib
Sep 10 20:41:29 wiregate403 monit[2985]: 'wiregated.pl' process PID changed to 5983
Sep 10 20:41:29 wiregate403 monit[2985]: 'wiregated.alive' timestamp passed
Sep 10 20:41:29 wiregate403 monit[2985]: 'localhost' loadavg(5min) of 4.0 matches resource limit [loadavg(5min)>2.0]
Sep 10 20:41:29 wiregate403 monit[2985]: 'localhost' loadavg(1min) of 4.9 matches resource limit [loadavg(1min)>4.0]
Sep 10 20:41:29 wiregate403 monit[2985]: 'eibd' loadavg(5min) of 4.0 matches resource limit [loadavg(5min)>2.0]
Sep 10 20:41:29 wiregate403 monit[2985]: 'eibd' trying to restart
Sep 10 20:41:29 wiregate403 monit[2985]: 'eibd' stop: /etc/init.d/eibd
Sep 10 20:41:29 wiregate403 /usr/sbin/wiregated.pl: INFO - eibd connection lost - retrying
Sep 10 20:41:42 wiregate403 monit[2985]: 'eibd' start: /etc/init.d/eibd
Sep 10 20:42:42 wiregate403 monit[2985]: 'wiregated.pl' PID has not changed
Sep 10 20:42:42 wiregate403 monit[2985]: 'wiregated.alive' timestamp test failed for /tmp/wiregated.alive
Sep 10 20:42:42 wiregate403 monit[2985]: 'localhost' loadavg(5min) of 3.9 matches resource limit [loadavg(5min)>2.0]
Sep 10 20:42:42 wiregate403 monit[2985]: 'localhost' resource passed
Sep 10 20:42:42 wiregate403 monit[2985]: 'eibd' loadavg(5min) of 3.9 matches resource limit [loadavg(5min)>2.0]
Sep 10 20:42:42 wiregate403 monit[2985]: 'eibd' trying to restart
Sep 10 20:42:42 wiregate403 monit[2985]: 'eibd' stop: /etc/init.d/eibd
Sep 10 20:42:53 wiregate403 /usr/sbin/wiregated.pl: INFO - *** reading config
Sep 10 20:43:04 wiregate403 monit[2985]: 'eibd' start: /etc/init.d/eibd
Sep 10 20:43:04 wiregate403 init: Id "log9" respawning too fast: disabled for 5 minutes
Sep 10 20:44:04 wiregate403 monit[2985]: 'wiregated.pl' process PID changed to 12320
Sep 10 20:44:04 wiregate403 monit[2985]: 'wiregated.alive' timestamp test failed for /tmp/wiregated.alive
Sep 10 20:44:04 wiregate403 monit[2985]: 'localhost' loadavg(5min) of 3.7 matches resource limit [loadavg(5min)>2.0]
Sep 10 20:44:04 wiregate403 monit[2985]: 'eibd' loadavg(5min) of 3.7 matches resource limit [loadavg(5min)>2.0]
Sep 10 20:44:04 wiregate403 monit[2985]: 'eibd' trying to restart
Sep 10 20:44:04 wiregate403 monit[2985]: 'eibd' stop: /etc/init.d/eibd
Sep 10 20:44:05 wiregate403 monit[2985]: 'eibd' start: /etc/init.d/eibd
Sep 10 20:44:16 wiregate403 /usr/sbin/wiregated.pl: INFO - *** reading config
Sep 10 20:44:16 wiregate403 /usr/sbin/wiregated.pl: INFO - connected to eibd local:/tmp/eib
Sep 10 20:44:38 wiregate403 collectd[2584]: processes plugin: Failed to open `/proc/16680/cmdline': No such file or directory.
Sep 10 20:45:05 wiregate403 monit[2985]: 'wiregated.pl' process PID changed to 15478
Sep 10 20:45:05 wiregate403 monit[2985]: 'wiregated.alive' timestamp passed
Sep 10 20:45:05 wiregate403 monit[2985]: 'localhost' loadavg(5min) of 3.6 matches resource limit [loadavg(5min)>2.0]
Sep 10 20:45:05 wiregate403 monit[2985]: 'eibd' loadavg(5min) of 3.6 matches resource limit [loadavg(5min)>2.0]
Sep 10 20:45:05 wiregate403 monit[2985]: 'eibd' trying to restart
Sep 10 20:45:05 wiregate403 monit[2985]: 'eibd' stop: /etc/init.d/eibd
Sep 10 20:45:06 wiregate403 /usr/sbin/wiregated.pl: INFO - eibd connection lost - retrying
Sep 10 20:45:35 wiregate403 monit[2985]: 'eibd' start: /etc/init.d/eibd
Sep 10 20:46:35 wiregate403 monit[2985]: 'wiregated.pl' PID has not changed
Sep 10 20:46:35 wiregate403 monit[2985]: 'wiregated.alive' timestamp test failed for /tmp/wiregated.alive
Sep 10 20:46:35 wiregate403 monit[2985]: 'localhost' loadavg(5min) of 3.3 matches resource limit [loadavg(5min)>2.0]
Sep 10 20:46:35 wiregate403 monit[2985]: 'eibd' loadavg(5min) of 3.3 matches resource limit [loadavg(5min)>2.0]
Sep 10 20:46:35 wiregate403 monit[2985]: 'eibd' trying to restart
Sep 10 20:46:35 wiregate403 monit[2985]: 'eibd' stop: /etc/init.d/eibd
Sep 10 20:46:36 wiregate403 monit[2985]: 'eibd' start: /etc/init.d/eibd
Sep 10 20:46:42 wiregate403 /usr/sbin/wiregated.pl: INFO - *** reading config
Sep 10 20:46:43 wiregate403 /usr/sbin/wiregated.pl: INFO - connected to eibd local:/tmp/eib
Sep 10 20:47:36 wiregate403 monit[2985]: 'wiregated.pl' process PID changed to 21148
Sep 10 20:47:36 wiregate403 monit[2985]: 'wiregated.alive' timestamp passed
Sep 10 20:47:36 wiregate403 monit[2985]: 'localhost' loadavg(5min) of 2.8 matches resource limit [loadavg(5min)>2.0]
Sep 10 20:47:36 wiregate403 monit[2985]: 'eibd' loadavg(5min) of 2.8 matches resource limit [loadavg(5min)>2.0]
Sep 10 20:47:36 wiregate403 monit[2985]: 'eibd' trying to restart
Sep 10 20:47:36 wiregate403 monit[2985]: 'eibd' stop: /etc/init.d/eibd
Sep 10 20:47:37 wiregate403 /usr/sbin/wiregated.pl: INFO - eibd connection lost - retrying
Sep 10 20:47:41 wiregate403 monit[2985]: 'eibd' start: /etc/init.d/eibd
Sep 10 20:47:47 wiregate403 /usr/sbin/wiregated.pl: INFO - connected to eibd local:/tmp/eib
Sep 10 20:48:41 wiregate403 monit[2985]: 'wiregated.pl' PID has not changed
Sep 10 20:48:41 wiregate403 monit[2985]: 'localhost' loadavg(5min) of 2.3 matches resource limit [loadavg(5min)>2.0]
Sep 10 20:48:41 wiregate403 monit[2985]: 'eibd' loadavg(5min) of 2.3 matches resource limit [loadavg(5min)>2.0]
Sep 10 20:48:41 wiregate403 monit[2985]: 'eibd' trying to restart
Sep 10 20:48:41 wiregate403 monit[2985]: 'eibd' stop: /etc/init.d/eibd
Sep 10 20:48:42 wiregate403 /usr/sbin/wiregated.pl: INFO - eibd connection lost - retrying
Sep 10 20:48:56 wiregate403 init: Id "log9" respawning too fast: disabled for 5 minutes
Sep 10 20:48:56 wiregate403 monit[2985]: 'eibd' start: /etc/init.d/eibd
Sep 10 20:49:56 wiregate403 monit[2985]: 'wiregated.alive' timestamp test failed for /tmp/wiregated.alive
Sep 10 20:49:56 wiregate403 monit[2985]: 'localhost' loadavg(5min) of 2.5 matches resource limit [loadavg(5min)>2.0]
Sep 10 20:49:56 wiregate403 monit[2985]: 'eibd' loadavg(5min) of 2.5 matches resource limit [loadavg(5min)>2.0]
Sep 10 20:49:56 wiregate403 monit[2985]: 'eibd' trying to restart
Sep 10 20:49:56 wiregate403 monit[2985]: 'eibd' stop: /etc/init.d/eibd
Sep 10 20:50:06 wiregate403 /usr/sbin/wiregated.pl: INFO - *** reading config
Sep 10 20:50:16 wiregate403 monit[2985]: 'eibd' start: /etc/init.d/eibd
Sep 10 20:51:16 wiregate403 monit[2985]: 'wiregated.pl' process PID changed to 28969
Sep 10 20:51:16 wiregate403 monit[2985]: 'wiregated.alive' timestamp test failed for /tmp/wiregated.alive
Sep 10 20:51:16 wiregate403 monit[2985]: 'localhost' loadavg(5min) of 2.5 matches resource limit [loadavg(5min)>2.0]
Sep 10 20:51:16 wiregate403 monit[2985]: 'eibd' loadavg(5min) of 2.5 matches resource limit [loadavg(5min)>2.0]
Sep 10 20:51:16 wiregate403 monit[2985]: 'eibd' trying to restart
Sep 10 20:51:16 wiregate403 monit[2985]: 'eibd' stop: /etc/init.d/eibd
Sep 10 20:51:26 wiregate403 /usr/sbin/wiregated.pl: INFO - *** reading config
Sep 10 20:51:28 wiregate403 monit[2985]: 'eibd' start: /etc/init.d/eibd
Sep 10 20:52:28 wiregate403 monit[2985]: 'wiregated.pl' process PID changed to 31578
Sep 10 20:52:28 wiregate403 monit[2985]: 'wiregated.alive' timestamp test failed for /tmp/wiregated.alive
Sep 10 20:52:28 wiregate403 monit[2985]: 'localhost' loadavg(5min) of 2.5 matches resource limit [loadavg(5min)>2.0]
Sep 10 20:52:28 wiregate403 monit[2985]: 'eibd' loadavg(5min) of 2.5 matches resource limit [loadavg(5min)>2.0]
Sep 10 20:52:28 wiregate403 monit[2985]: 'eibd' trying to restart
Sep 10 20:52:28 wiregate403 monit[2985]: 'eibd' stop: /etc/init.d/eibd
Sep 10 20:52:36 wiregate403 /usr/sbin/wiregated.pl: INFO - *** reading config
Sep 10 20:52:47 wiregate403 monit[2985]: 'eibd' start: /etc/init.d/eibd
Sep 10 20:53:47 wiregate403 monit[2985]: 'wiregated.pl' process PID changed to 1235
Sep 10 20:53:47 wiregate403 monit[2985]: 'wiregated.alive' timestamp test failed for /tmp/wiregated.alive
Sep 10 20:53:47 wiregate403 monit[2985]: 'localhost' loadavg(5min) of 2.4 matches resource limit [loadavg(5min)>2.0]
Sep 10 20:53:47 wiregate403 monit[2985]: 'eibd' loadavg(5min) of 2.4 matches resource limit [loadavg(5min)>2.0]
Sep 10 20:53:47 wiregate403 monit[2985]: 'eibd' trying to restart
Sep 10 20:53:47 wiregate403 monit[2985]: 'eibd' stop: /etc/init.d/eibd
Sep 10 20:53:48 wiregate403 monit[2985]: 'eibd' start: /etc/init.d/eibd
Sep 10 20:53:52 wiregate403 /usr/sbin/wiregated.pl: INFO - *** reading config
Sep 10 20:53:52 wiregate403 /usr/sbin/wiregated.pl: INFO - connected to eibd local:/tmp/eib
Sep 10 20:54:48 wiregate403 monit[2985]: 'wiregated.pl' process PID changed to 3182
Sep 10 20:54:48 wiregate403 monit[2985]: 'wiregated.alive' timestamp passed
Sep 10 20:54:48 wiregate403 monit[2985]: 'localhost' resource passed
Sep 10 20:54:48 wiregate403 monit[2985]: 'eibd' resource passed
Sep 10 20:55:48 wiregate403 monit[2985]: 'wiregated.pl' PID has not changed

EDIT:
Wozu braucht es eigentlich den collectd oder kann man den abschalten ?

[kleinklausi]

Daran wäre ich auch sehr interessiert! Mein Wiregated startet zwar ca. 1x am Tag durch, aber wenn das zu einer blöden Uhrzeit ist, ist das schon nervig.

gruß

[makki]

Der collectd ist nicht das Problem sondern nur die Wirkung. (und die einzige Chance es nachzuvollziehen!)

Das Problem ist meist schlicht überlastung; es ist halt kein Core i7, wenn man beim starten der Visu bspw. 15 drraw und 50 RRD's holt, nebenbei mpd &Co + ein paar unperfekte Plugins rennen sollen, kommt die Kiste halt irgendwann in Performance-Engpässe.
Alle bisherigen Verdachtsfälle liessen sich jedenfalls darauf reduzieren, das es einfach gnadenlos übertrieben wurde..

Makki

[JuMi2006]

Die Speicherauslastung nach Neustart liegt bei unter 100 MB. Außer smsd und 2 cronjobs fûr die Zählerauslesung läuft nix weiter auf dem Wiregate.
Ich bin bloß auf den collectd gekommen weil er einfach ein Speichermonster ist (65MB) im Vergleich zu den sonstigen Diensten.

Zieht der eibd dann den wiregated mit runter ?

[makki]

Der collectd braucht keine 65MB.. Der läuft auf Dreamboxen, IPE mit 32MB RAM und vielen,vielen WG's..

Der eibd ist auch nicht das Thema..

Makki

[JuMi2006]

Also bei mir braucht er die komischerweise, zumindest sagt das das webmin ... wobei mir die Summe immernoch nicht ganz klar ist ... die kann ja nicht stimmen.

[greentux]

Auch mein TOP sagt ähnliche Zahlen. Allerdings startet der wiregated hier nicht re.

Mittlerweile denke ich, das das, was Webmin da anzeigt nicht stimmen kann...

ein

ps -e -orss=,args= | sort -b -k1,1n

zeigt da anderes...

[JuMi2006]

Das sieht schon schlüssiger aus

[do13]

Der collectd braucht keine 65MB.. Der läuft auf Dreamboxen, IPE mit 32MB RAM und vielen,vielen WG's..

Die Größenordnung vom collectd stimmt schon:

root@wiregate:~# pmap `pidof collectd`
27005:   collectd -C /etc/collectd/collectd.conf -f
08048000    140K r-x--  /usr/sbin/collectd
0806b000      4K rw---  /usr/sbin/collectd
082bc000    260K rw---    [ anon ]
b3700000    132K rw---    [ anon ]
b3721000    892K -----    [ anon ]
b38be000     48K r-x--  /lib/libgcc_s.so.1
b38ca000      4K rw---  /lib/libgcc_s.so.1
b38cb000      4K -----    [ anon ]
b38cc000   8188K rw---    [ anon ]
b40cb000      4K -----    [ anon ]
b40cc000   8188K rw---    [ anon ]
b48cb000      4K -----    [ anon ]
b48cc000   8188K rw---    [ anon ]
b50cb000      4K -----    [ anon ]
b50cc000   8188K rw---    [ anon ]
b58cb000      4K -----    [ anon ]
b58cc000   8188K rw---    [ anon ]
b60cb000      4K -----    [ anon ]
b60cc000   8188K rw---    [ anon ]
b68cb000      4K -----    [ anon ]
b68cc000   8188K rw---    [ anon ]
b70cb000     36K r-x--  /lib/libnss_files-2.7.so
.....
bff54000     84K rw---    [ stack ]
 total    67224K

Auffällig sind hier die 7 [anon] Bereiche mit 8MB (8188K+4K).
Dieser Speicher lässt sich jetzt gut mit den Threads erklären.

root@wiregate:~# ls /proc/`pidof collectd`/task
27005  27006  27008  27009  27010  27011  27012

Hier sieht man schön der collectd benutzt 7 Threads und per default hat jeder Thread eine Stacksize von 8MB.

Bei einer Stacksize von 128KB sieht der totale Speicherverbrauch dann schon ganz anders aus:

root@wiregate:~# ulimit -s 128
root@wiregate:~# /etc/init.d/collectd restart
root@wiregate:~# pmap `pidof collectd`
4890:   collectd -C /etc/collectd/collectd.conf -f
...
bff6a000     84K rw---    [ stack ]
 total     9752K

Ob der collectd damit stabil funktioniert habe ich jetzt nicht getested. Da müssen noch mehr Tests her. Evtl. sind die 128KB zu wenig.

Ich vermute mal die Dreambox und IPE haben eine andere Defaultstacksize.
Was sagt auf solch einem System ulimit -s

Der eibd ist auch nicht das Thema..

Eibd ist kein Problem, der hat durch pthsem nur einen Thread. Aber owfs ist noch so ein Kandidat.

Dirk

[JuMi2006]

ulimit -s bringt: 8192

Leider splittet sich mein Problem ein wenig in 2 Threads hier, das war nicht meine Absicht und verwirrt hoffentlich nicht zu sehr.

Was für eine Auslastung (CPU) hat denn bei euch /usr/bin/owserver -uall -uscan... mit top ?
Ich liege mit dem owserver bei deutlich >> 35% CPU ... damit schlägt dann irgendwann immer der monit zu "localhost' loadavg(5min)..."

Vergleiche hier: https://knx-user-forum.de/wiregate-b...atester-3.html
Irgendwann muss da irgendwas schief gelaufen sein


Gruß Mirko

[JuMi2006]

Darf ich nochmal in die Runde fragen wie eure Prozessorlast vom owserver aussieht? Der monit ist auch über ein Web-Interface erreichbar: http://wiregatexxx:2812 (user: admin passwort: monit)

Bei mir zeigt er durchgehend mehr als 35% CPU-Last für den owserver an. Meist etwas um die 40-50%. Meine load bekomme ich nur knapp unter 2 gehalten damit der monit mir dann nicht den eibd killt. Wenn es doch schief geht dann ist erstmal für ne Weile alles außer Gefecht.

Ich bräuchte jetzt wirklich mal Hilfe.

Vielen Dank!!!

Im syslog sieht das dann so aus:

Sep 14 02:44:46 wiregate403 monit[2937]: 'localhost' loadavg(5min) of 2.2 matches resource limit [loadavg(5min)>2.0]
Sep 14 02:44:46 wiregate403 monit[2937]: 'eibd' loadavg(5min) of 2.2 matches resource limit [loadavg(5min)>2.0]
Sep 14 02:44:46 wiregate403 monit[2937]: 'eibd' trying to restart
Sep 14 02:44:46 wiregate403 monit[2937]: 'eibd' stop: /etc/init.d/eibd
Sep 14 02:44:47 wiregate403 /usr/sbin/wiregated.pl: INFO - eibd connection lost - retrying
Sep 14 02:44:47 wiregate403 monit[2937]: 'eibd' start: /etc/init.d/eibd

[kleinklausi]

Hi,
hier also mal meinen Werte. Die load und die Prozessorauslastung finde ich auch etwas unangenehm. Ich bin mir nicht bewusst irgendwas verrücktes auf meinem Wiregate laufen zu haben.

Für den owserver sehen meine Werte allerdings ok aus.

Anbei monit und top jeweils nach Speicher und CPU Auslastung

Gruß

[JuMi2006]

Vielen Dank! Das beruhigt mich (eher unangenehm) dass ich sehe dass dort irgendwas mit meinem owserver nicht stimmt

[kleinklausi]

warum bei mir ein Perl-Prozess aber so dermassen den Prozessor auslastet, würde mich schon interessieren...

[JuMi2006]

Einfach mal killen ... Hab ich so bei mir noch nie gesehen ... vielleicht aus irgendeiner Entwicklung mal hängengeblieben?

Ich wüsste auch nicht mal am owserver gespielt zu haben ... von dem 1-wire-Zeug lass ich immer die Finger, das versteht ja kaum einer