apache2 wird langsamer

rseffner

New Member
Hallo,

mein apache2 (Apache/2.2.9 (Debian) DAV/2 mod_python/3.3.1 Python/2.5.2 mod_ssl/2.2.9 OpenSSL/0.9.8g mod_perl/2.0.4 Perl/v5.10.0 Server at 127.0.0.1 Port 80) führt sein ein paar Tagen zum Nichtreagieren des Servers (debian lenny). Mein erster verdächtiger ist immer erstmal PHP, das läuft aber mittels suexec und fastcgi, so dass ich in der Prozessliste (top) sehen würde, wer da Ressourcen frisst. Ressourcen ist überhaupt ein gutes Stichwort, ich habe munin draufgepackt und selbst wenn der Server erst langsam und dann unerreichbar (ping geht aber noch ne Weile) wird, steigt weder load noch Speicherverbrauch, Anzahl der Prozesse oder der mysqld (die für suexec genutzten oser liegen im sql und sind mittels libnss ins System verlinkt) wird langsamer. Es muss der apache sein, bzw. eines der module.
Nun speichere ich mir aller Minute den server-status in ein file um ggf. etwas erkennen zu können. Bisher fällt dabei Folgendes auf:

- kurz nach apache2 restart, liefert der apache Seiten im Schnitt in 0,0x Sekunden aus (Spalte CPU)
- ca. eine Stunde nach diesem restart dauert das Mittel zur Auslieferung schon 2,8x Sekunden
= apache wird langsamer, aber in der load des Systemes ist das nicht zu bemerken

Nun hostet der Server reichlich 100 Domains, da wird es schwierig was zu finden aber zB. Folgendes taucht immer wieder auf (hier mal Auszüge, die je 10 Minuten auseinander liegen):

Code:
ns3:/var/log/apache2/monitor# grep yanone 2009-06-05_17:36:01.apache2
0-2 30015 58/  _ 1.85 104  0    0.0  0.41  2.59 82.242.207.135  yanone.de            GET /typedesign/kaffeesatz/bohnen/06.gif HTTP/1.1
0-2 30015 68/  _ 1.90 77   4    0.0  0.57  0.89 83.233.30.104   yanone.de            POST /guestbook/machine.php HTTP/1.0
0-2 30015 53/  _ 1.85 104  0    0.0  0.34  0.94 82.242.207.135  yanone.de            GET /typedesign/kaffeesatz/pdf_icon.gif HTTP/1.1
0-2 30015 41/  _ 1.85 104  0    0.0  0.31  0.81 82.242.207.135  yanone.de            GET /typedesign/kaffeesatz/bohnen/05.gif HTTP/1.1
0-2 30015 46/  _ 1.98 7    0    0.0  0.37  0.43 84.191.106.75   yanone.de            HTTP/1.1
1-2 30016 92/  _ 1.61 104  0    0.0  0.81  1.38 82.242.207.135  yanone.de            GET /typedesign/kaffeesatz/bohnen/04.gif HTTP/1.1
1-2 30016 51/  _ 1.61 104  0    0.0  0.44  0.66 82.242.207.135  yanone.de            GET /typedesign/kaffeesatz/bohnen/07.gif HTTP/1.1
1-2 30016 32/  _ 1.62 111  7    0.0  0.65  1.22 65.55.106.148   yanone.de            HTTP/1.0
1-2 30016 68/  _ 1.63 85   4    0.0  0.41  0.94 83.233.30.104   yanone.de            POST /guestbook/machine.php HTTP/1.0
1-2 30016 76/  _ 1.61 104  0    0.0  0.18  7.95 82.242.207.135  yanone.de            GET /typedesign/kaffeesatz/bohnen/03.gif HTTP/1.1
2-0 -     0/0/ . 1.46 2940 0    0.0  0.00  0.60 85.178.125.125  yanone.de            GET /favicon.ico HTTP/1.1
2-0 -     0/0/ . 1.46 2940 0    0.0  0.00  7.63 85.178.125.125  yanone.de            GET /home/background/5-5.gif HTTP/1.1
2-0 -     0/0/ . 1.40 2940 0    0.0  0.00  0.11 213.3.5.102     yanone.de            GET /home/background/zeilen.gif HTTP/1.1
2-0 -     0/0/ . 1.40 2940 0    0.0  0.00  0.07 62.216.21.20    yanone.de            GET /schriftgestaltung/kaffeesatz/namen_gross.gif
2-0 -     0/0/ . 1.45 2940 27   0.0  0.00  0.34 65.55.106.119   yanone.de            GET /blog/?SID=124792&seite=1 HTTP/1.0
2-0 -     0/0/ . 1.47 2940 0    0.0  0.00  0.54 85.178.163.36   yanone.de            GET /favicon.ico HTTP/1.0
2-0 -     0/0/ . 1.46 2940 231  0.0  0.00  0.60 65.55.209.22    yanone.de            GET /shop/
2-0 -     0/0/ . 1.44 2940 10   0.0  0.00  0.22 213.3.5.102     yanone.de            GET /typedesign/rahmen_checkitout.gif HTTP/1.1
ns3:/var/log/apache2/monitor# grep yanone 2009-06-05_17:46:01.apache2
0-2 30015 63/  _ 2.09 254  210 0.0  0.42  2.60 173.52.146.177  yanone.de            GET /gui/page/page_oben.gif HTTP/1.1
0-2 30015 97/  _ 2.15 70   0   0.0  0.70  1.39 95.102.42.170   yanone.de            GET /typedesign/alabdali8/preview_05.gif HTTP/1.1
0-2 30015 64/  _ 2.13 114  0   0.0  0.32  1.51 190.49.201.128  yanone.de            HTTP/1.1
0-2 30015 48/  _ 2.09 254  0   0.0  0.31  0.82 173.52.146.177  yanone.de            GET /gui/page/page_links.gif HTTP/1.1
1-2 30016 56/  _ 1.81 163  0   0.0  0.75  1.30 190.49.201.128  yanone.de            HTTP/1.1
1-2 30016 125/ _ 1.82 70   0   0.0  4.14  5.72 95.102.42.170   yanone.de            GET /typedesign/alabdali8/thumb_05.jpg HTTP/1.1
1-2 30016 58/  _ 1.80 254  0   0.0  0.46  0.68 173.52.146.177  yanone.de            GET /gui/page/page_unten.gif HTTP/1.1
1-2 30016 74/  _ 1.81 152  0   0.0  0.54  1.11 72.14.199.124   yanone.de            GET /blog/logrdf.php HTTP/1.1
1-2 30016 57/  _ 1.82 26   0   0.0  0.51  1.39 85.178.163.36   yanone.de            GET /favicon.ico HTTP/1.0
2-0 -     0/0/ . 1.46 3541 0   0.0  0.00  0.60 85.178.125.125  yanone.de            GET /favicon.ico HTTP/1.1
2-0 -     0/0/ . 1.46 3541 0   0.0  0.00  7.63 85.178.125.125  yanone.de            GET /home/background/5-5.gif HTTP/1.1
2-0 -     0/0/ . 1.40 3541 0   0.0  0.00  0.11 213.3.5.102     yanone.de            GET /home/background/zeilen.gif HTTP/1.1
2-0 -     0/0/ . 1.40 3541 0   0.0  0.00  0.07 62.216.21.20    yanone.de            GET /schriftgestaltung/kaffeesatz/namen_gross.gif
2-0 -     0/0/ . 1.45 3541 27  0.0  0.00  0.34 65.55.106.119   yanone.de            GET /blog/?SID=124792&seite=1 HTTP/1.0
2-0 -     0/0/ . 1.47 3541 0   0.0  0.00  0.54 85.178.163.36   yanone.de            GET /favicon.ico HTTP/1.0
2-0 -     0/0/ . 1.46 3541 231 0.0  0.00  0.60 65.55.209.22    yanone.de            GET /shop/
2-0 -     0/0/ . 1.44 3541 10  0.0  0.00  0.22 213.3.5.102     yanone.de            GET /typedesign/rahmen_checkitout.gif HTTP/1.1
ns3:/var/log/apache2/monitor# grep yanone 2009-06-05_17:56:01.apache2
0-2 30015 69/  _ 2.32 9    38     0.0  0.45  2.63  207.12.246.133  yanone.de            GET /cgi-bin/download.pl?file=kaffeesatzfont HTTP/1.1
0-2 30015 137/ _ 2.25 291  0      0.0  1.02  1.54  85.200.165.146  yanone.de            GET /favicon.ico HTTP/1.0
0-2 30015 43/  _ 2.31 9    64     0.0  0.48  0.91  65.55.106.159   yanone.de            GET /jordanien/fotos/index.php?datei=033.jpg HTTP/1.1
0-2 30015 69/  _ 2.33 8    19     0.0  0.38  0.98  207.12.246.133  yanone.de            GET /gui/navi/logotypes/60s.gif HTTP/1.1
0-2 30015 55/  _ 2.30 16   170    0.0  0.33  0.83  207.12.246.133  yanone.de            GET /gui/page/page_oben.gif HTTP/1.1
0-2 30015 85/  _ 2.30 37   0      0.0  6.02  6.50  65.55.104.158   yanone.de            GET /robots.txt HTTP/1.1
0-2 30015 51/  _ 2.28 144  4      0.0  0.39  0.44  83.233.30.104   yanone.de            POST /guestbook/machine.php HTTP/1.0
1-2 30016 105/ _ 2.52 37   39     0.0  0.84  1.41  65.55.104.158   yanone.de            GET /cgi-bin/download.pl?file=kaffeesatzfont HTTP/1.1
1-2 30016 92/  _ 2.53 8    6      0.0  0.50  0.85  207.12.246.133  yanone.de            www.schnellmussesgehenu
1-2 30016 77/  _ 2.50 51   0      0.0  0.77  1.16  85.147.121.243  yanone.de            GET /favicon.ico HTTP/1.0
1-2 30016 127/ _ 2.47 144  4      0.0  4.16  5.74  83.233.30.104   yanone.de            POST /guestbook/machine.php HTTP/1.0
1-2 30016 65/  _ 2.53 8    0      0.0  0.50  0.71  207.12.246.133  yanone.de            GET /typedesign/download/amazonde.gif HTTP/1.1
1-2 30016 46/  _ 2.41 277  0      0.0  0.74  1.48  96.30.167.212   yanone.de            HTTP/1.1
1-2 30016 66/  _ 2.53 8    0      0.0  0.53  1.41  207.12.246.133  yanone.de            1.1
2-0 -     0/0/ . 1.46 4140 0      0.0  0.00  0.60  85.178.125.125  yanone.de            GET /favicon.ico HTTP/1.1
2-0 -     0/0/ . 1.46 4140 0      0.0  0.00  7.63  85.178.125.125  yanone.de            GET /home/background/5-5.gif HTTP/1.1
2-0 -     0/0/ . 1.40 4140 0      0.0  0.00  0.11  213.3.5.102     yanone.de            GET /home/background/zeilen.gif HTTP/1.1
2-0 -     0/0/ . 1.40 4140 0      0.0  0.00  0.07  62.216.21.20    yanone.de            GET /schriftgestaltung/kaffeesatz/namen_gross.gif
2-0 -     0/0/ . 1.45 4140 27     0.0  0.00  0.34  65.55.106.119   yanone.de            GET /blog/?SID=124792&seite=1 HTTP/1.0
2-0 -     0/0/ . 1.47 4140 0      0.0  0.00  0.54  85.178.163.36   yanone.de            GET /favicon.ico HTTP/1.0
2-0 -     0/0/ . 1.46 4140 231    0.0  0.00  0.60  65.55.209.22    yanone.de            GET /shop/
2-0 -     0/0/ . 1.44 4140 10     0.0  0.00  0.22  213.3.5.102     yanone.de            GET /typedesign/rahmen_checkitout.gif HTTP/1.1

Das sind doch immer wieder die selben Anfragen oder? Man sieht auch, dass die Zeit zum Ausliefern stetig steigt. Verwenden wir mal die PID 30015 und 30016, so erfahren wir, dass der apache neben diesen auch noch unter 30014 und 30013 läuft.

Code:
ns3:/var/log/apache2/monitor# ps -ef | grep 3001
10011      580 30014  0 17:00 ?        00:00:00 /usr/bin/php-cgi -c /var/www/php-fcgi-scripts/plasticcon/schwarzes-hamburg.de/
10014     1067 30014  0 17:01 ?        00:00:00 /usr/bin/php-cgi -c /var/www/php-fcgi-scripts/direktform/direktform.de/
10043     1130 30014  0 17:02 ?        00:00:04 /usr/bin/php-cgi -c /var/www/php-fcgi-scripts/kreuzkirch/kreuzkirche-dresden.de/
10050     2074 30014  0 17:05 ?        00:00:00 /usr/bin/php-cgi -c /var/www/php-fcgi-scripts/wautomaten/wip-dresden.de/
10011     2329 30014  0 17:08 ?        00:00:07 /usr/bin/php-cgi -c /var/www/php-fcgi-scripts/plasticcon/brandfleck.de/
10033     3029 30014  0 17:10 ?        00:00:00 /usr/bin/php-cgi -c /var/www/php-fcgi-scripts/spdmeissen/spd-fraktion-meissen.de/
its       3263 30014  0 17:10 ?        00:00:00 /usr/bin/php-cgi -c /var/www/php-fcgi-scripts/its/i-t-sys.de/
10068     4490 30014  0 17:15 ?        00:00:00 /usr/bin/php-cgi -c /var/www/php-fcgi-scripts/hansebrand/j5media.de/
its       6318 30014  0 17:23 ?        00:00:00 /usr/bin/php-cgi -c /var/www/php-fcgi-scripts/its/seffner.de/
ptzdd    14049 30014  0 17:54 ?        00:00:00 /usr/bin/php-cgi -c /var/www/php-fcgi-scripts/ptzdd/ptz-prototypen.de/
root     19154 12551  0 18:14 pts/0    00:00:00 grep 3001
www-data 30013 10252  0 16:48 ?        00:00:00 /usr/sbin/apache2 -k start
www-data 30014 10252  0 16:48 ?        00:00:00 /usr/sbin/apache2 -k start
www-data 30015 10252  0 16:48 ?        00:00:02 /usr/sbin/apache2 -k start
www-data 30016 10252  0 16:48 ?        00:00:03 /usr/sbin/apache2 -k start
10008    30129 30014  0 16:48 ?        00:00:13 /usr/bin/php-cgi -c /var/www/php-fcgi-scripts/anglerverb/anglerverband-sachsen.de/
10007    30168 30014  0 16:49 ?        00:00:00 /usr/bin/php-cgi -c /var/www/php-fcgi-scripts/markenteam/markenteam-dresden.de/
yanone   30175 30014  0 16:49 ?        00:00:00 /usr/bin/php-cgi -c /var/www/php-fcgi-scripts/yanone/yanone.de/
10050    30392 30014  0 16:50 ?        00:00:00 /usr/bin/php-cgi -c /var/www/php-fcgi-scripts/wautomaten/wip-dresden.de/
10016    31623 30014  0 16:54 ?        00:00:00 /usr/bin/php-cgi -c /var/www/php-fcgi-scripts/kunsthande/dresden-kunstauktion.de/
its      32104 30014  0 16:55 ?        00:00:00 /usr/bin/php-cgi -c /var/www/php-fcgi-scripts/its/its-seffner.de/
martha   32483 30014  0 16:57 ?        00:00:00 /usr/bin/php-cgi -c /var/www/php-fcgi-scripts/martha/thp-liebeskind.de/

Warum scheint nur der Prozess 30014 sinnvoll zu arbeiten. Kann ich davon ausgehen, dass 30015 und 30016 irgendwie hängen geblieben sind? In den Ausgaben von server-status finden 30013 und 30014 nie Erwähnung.

Ich bin ratlos. In ein paar Stunden ist der Server dann nicht mehr bedienbar, geschweige denn, dass er Seiten ausliefert. Genauer gesagt merkt man erst die Verzögerung der Seitenauslieferungen und irgendwann (ca. nach einem Tag Laufzeit) kann man nichtmal mehr per ssh drauf, dann logt munin aber auch nichts mehr und die eigentlich minütlich geschriebenen server-status weisen große Lücken auf.

Ich bin für jede Hilfe dankbar, die mich auf die Spur führt.

Grüße

Ronny
 
so sieht es jetzt aus:

Code:
ns3:/var/log/apache2/monitor# cat 2009-06-06_11:25:01.apache2 | grep yanone
0-0 12664 432/ _ 10.61 126 66     0.0  3.95  3.95  65.55.209.31    yanone.de       product_reviews_write.php?products_id=35&language=de
0-0 12664 359/ _ 10.63 30  304    0.0  3.41  3.41  65.55.110.213   yanone.de       login.php?osCsid=dcb4c8d34adb2b8551fc1c5704a49331 HTT
0-0 12664 320/ _ 10.64 0   0      0.0  5.90  5.90  65.55.110.213   yanone.de       GET /gui/page/page_unten_rechts.gif HTTP/1.0
0-0 12664 309/ _ 10.54 473 4      0.0  5.77  5.77  83.233.30.104   yanone.de       POST /guestbook/machine.php HTTP/1.0
0-0 12664 340/ _ 10.61 66  0      0.0  11.48 11.48 122.104.207.38  yanone.de       GET /schriftgestaltung/kaffeesatz/namen_gross.gif HTTP/1.1
1-0 12665 345/ _ 11.38 297 376    0.0  12.68 12.68 123.125.64.38   yanone.de       GET / HTTP/1.1
1-0 12665 398/ _ 11.50 0   0      0.0  22.74 22.74 65.55.110.213   yanone.de       GET /gui/page/page_unten.gif HTTP/1.0
1-0 12665 329/ _ 11.49 13  63     0.0  11.22 11.22 208.115.111.242 yanone.de       product_info.php?cPath=26&products_id=44&language=en&
1-0 12665 353/ _ 11.41 191 371    0.0  3.47  3.47  123.125.66.103  yanone.de       GET / HTTP/1.1
1-0 12665 338/ _ 11.49 23  70     0.0  19.72 19.72 65.55.110.213   yanone.de       product_reviews_write.php?products_id=35&language=de
2-0 24925 306/ _ 8.83  183 20     0.0  2.45  2.45  72.14.199.124   yanone.de       GET /blog/blog.py/rss HTTP/1.1
2-0 24925 236/ _ 8.82  321 4      0.0  1.70  1.70  83.233.30.104   yanone.de       POST /guestbook/machine.php HTTP/1.0
2-0 24925 240/ _ 8.84  75  107    0.0  2.98  2.98  65.55.209.31    yanone.de       login.php?osCsid=e843ea710ccfa67fa549755b7ff5a297 HTT
2-0 24925 260/ _ 8.82  231 385    0.0  3.64  3.64  38.99.13.119    yanone.de       GET /home/bigscreen/monospasz-ani.gif HTTP/1.0
2-0 24925 254/ _ 8.84  60  24     0.0  2.65  2.65  38.99.44.102    yanone.de       GET /typedesign/monospasz/figures.gif HTTP/1.0
 
Back
Top