Onderwerp: Probleem apache, lastig te lokaliseren

We hebben de laatste 2 weken een zeer raar probleem op één van onze webservers, wat ik tot op heden nog niet heb weten op te lossen..

Het gaat om een Dual-Xeon 2.8ghz met 4GB intern geheugen (Dell poweredge 1850).

Hierop is geinstalleerd een Debian 3.1. Alle packages zijn handmatig gecompiled van de source door een voorganger die niet van documenteren hield.. Maar goed, we draaien 1 apache met php4 en 1 apache met php5 + 1 mysql versie 4 en 1 mysql5 (draait bijna niets op).

Het draaide altijd perfect, draaien wel 300-400 websites op maar eigenlijk altijd zonder problemen qua snelheid e.d. en de snelheid is nu in 1 klap zo ontiechelijk omlaag gegaan dat ik niet denk dat het aantal websites het probleem is, maar mochten jullie daar anders over denken hoor ik het natuurlijk graag..

Het probleem is dat het op willekeurige tijdstippen enorm traag wordt. Niet echt een regelmaat in te vinden. Echter waarom het traag wordt kan ik in geen enkel log-bestand terugvinden.

"top" geeft vaak per proces 0-1 % cpu op (httpd en mysql), geheugen voor elke httpd deamon zo rond de 3-4% en mysql 30% (de mysql4 die vooral gebruikt word). De CPU's (SMP) zien er zo uit (nu in dit overzicht is het snel, maar met ongeveer dezelfde waarden kan het ook traag zijn):

Cpu0 : 37.8% us, 8.7% sy, 0.3% ni, 52.2% id, 0.0% wa, 0.3% hi, 0.7% si
Cpu1 : 20.2% us, 10.1% sy, 1.0% ni, 68.7% id, 0.0% wa, 0.0% hi, 0.0% si
Cpu2 : 27.9% us, 16.5% sy, 2.7% ni, 52.9% id, 0.0% wa, 0.0% hi, 0.0% si
Cpu3 : 30.4% us, 34.4% sy, 0.3% ni, 34.8% id, 0.0% wa, 0.0% hi, 0.0% si

Ik heb ook de module server-status van apache maar eens geïnstalleerd, maar kan daar eigenlijk niet veel relevante informatie uit opmaken. Lijken allemaal vrij normale connecties, alleen de overzichten geven wat rare waarden aan soms (340% cpu...). Zodra hij weer even traag word zal ik dat overzicht hier ook even posten.

Omdat deze standaard commando's me niet veel wisten te vertellen ben ik met apt-get nog wat meer check-tools tegengekomen. Met name "atop" wist mij te vertellen als ik sorteerde op cpu dat httpd wel degelijk veel cpu gebruikte (dit zag ik dus niet in top..):

30963 100% httpd
11698 9% httpd
31262 2% mysqld
31552 1% httpd
11704 1% httpd
31561 1% httpd
25802 0% mysqld

Ik heb uiteraard de apache error-logs uitgebreid bekeken, zie ik niets raars. De mysql lijkt ook allemaal niet enorme queries te moeten behandelen. Dmesg geeft geen rare fouten aan. Ook heb ik gekeken naar de disk en network traffic, beiden maximaal 1-2MB/s dus zou ook voor geen problemen moeten veroorzaken dacht ik zo..

Nog even wat versies van belangrijke componenten:

Apache: 2.0.54

Mysql: 4.1.14-standard

Kernel: Linux *.*.nl 2.6.8-11-em64t-p4-smp #1 SMP Wed Jun 1 01:23:42 CEST 2005 x86_64 GNU/Linux

Ik vroeg me metname af of er een mogelijkheid is om te achterhalen of er een slecht geschreven php script draait. Die misschien de resources opslurpt (vind het dan alleen wel vreemd dat ik dit nergens terugzie..). Of een tool waarmee ik kan kijken waarme een httpd PID zo druk mee is (het is ook maar 1 deamon van de zoveel..). Ook andere suggesties om te lokaliseren waar de traagheid ontstaat zijn enorm welkom, ik heb zo'n beetje alles wat in mij opkomt nu wel geprobeerd..

Ik hoop dat iemand mij uit de brand kan helpen, in ieder geval super bedankt voor het meedenken..

Via server-status moet je kunnen zien welke bestand veel resources verbruikt, maar daar had je al naar gekeken geloof ik ?

Je kunt checken welke bestanden het httpd proces open heeft met

lsof -p 30963

Kun je ook eens de output van "vmstat 5 3" posten?

dat ik niet denk dat het aantal websites het probleem is, maar mochten jullie daar anders over denken hoor ik het natuurlijk graag..

Wij draaien ook 400 websites op een Dell PE 1850 dat moet makkelijk kunnen (er van uitgaande dat het gemiddelde MKB sites zijn) dus dit zal het probleem niet zijn. Draait er een CP?

Wij hebben dit probleem ook gehad, hebben het gehad met apache 1.3.XX in combinatie met MySQL 4.XX.

Hebben toen Apache geupgrade naar 2.XX en de laatste MySQL 4.XX versie geinstalleerd, hierdoor is het nu opgelost, helaas zijn er nu wel andere problemen onstaan die we langzaam aan de kop aan het indrukken zijn.

apache 2.0.x i.c.m. mysql 4.1 zorgt voor een goede performance.

Bedankt voor alle reacties tot nu toe, helaas (tja ...) is de server nog niet weer traag geweest. Maar ik zal al wel vast de gevraagde info posten:

vmstat 5 3:
procs -----------memory---------- ---swap-- -----io---- --system-- ----cpu----
r b swpd free buff cache si so bi bo in cs us sy id wa
1 0 7724 11512 70300 1295348 1 1 88 140 6 2 22 19 58 1
0 0 7724 15864 70292 1291140 0 0 12 60 1140 549 4 1 94 0
0 0 7724 17888 70300 1291132 0 0 5 83 1051 391 1 0 98 1

Die lsof -p 30963 kende ik niet, super handig bedankt! Echter nu is er dus nog niets aan de hand, alles wat open is klopt wel qua modules.

Zodra hij weer traag is, zal wel in de loop van de dag zijn morgen, post ik de rest. Alvast bedankt voor de hulp!

Hij was weer traag en heb snel van alles een output opgeslagen, inmiddels natuurlijk apache gerestart.

- Outputs gescheiden door +++++++
- Comments onderaan de output tussen **( .... )**
- Helaas geen <pre> opmaak mogelijkheid in dit forum, sorry.

++++++++++++++++++
Outputs:
webserver:~# vmstat 5 3
procs -----------memory---------- ---swap-- -----io---- --system-- ----cpu----
r b swpd free buff cache si so bi bo in cs us sy id wa
27 0 7724 109464 48812 349568 1 1 89 143 1 3 22 19 58 1
29 1 7724 109488 48832 350024 0 0 114 118 1050 5303 47 52 1 0
31 0 7724 96568 48836 353284 0 0 654 58 1128 4939 48 52 1 0

+++++++++++++

ATOP - webserver 06/20/2006 12:03:26 3 seconds elapsed
PRC | sys 5530 ms | user 5340 ms | #thr 224 | #exits 3 | #zombie 0 |
CPU | sys 203% | user 195% | irq 0% | idle 4% | wait 0% |
cpu | sys 53% | user 46% | irq 0% | idle 0% | cpu002 w 0% |
cpu | sys 50% | user 49% | irq 0% | idle 1% | cpu003 w 0% |
cpu | sys 50% | user 49% | irq 0% | idle 1% | cpu001 w 0% |
cpu | sys 49% | user 50% | irq 0% | idle 1% | cpu000 w 0% |
MEM | tot 2.9G | free 44.6M | cache 353.6M | buff 47.7M | slab 396.6M |
SWP | tot 2.8G | free 2.8G | vmcom 5.4G | swin 0 | swout 0 |
DSK | sda | busy 1% | read 5 | write 0 | avio 3 ms |
NET | transport | tcpi 41 | tcpo 41 | udpi 4 | udpo 4 |
NET | network | ipi 46 | ipo 46 | ipfrw 0 | deliv 46 |
NET | dev eth0 | pcki 48 | pcko 46 | in 5K | out 22K |

PID CPU COMMAND-LINE 1/8
3844 54% /usr/local/httpd_2.0.54/bin/httpd -k start
29008 52% /usr/local/httpd_2.0.54/bin/httpd -k start
3936 38% trivial-rewrite -n rewrite -t unix -u
3842 38% httpd
16012 32% httpd
3937 32% /usr/local/httpd_2.0.54/bin/httpd -k start
28776 31% /usr/local/httpd_2.0.54/bin/httpd -k start
16015 21% /usr/local/httpd_2.0.54/bin/httpd -k start
15997 20% httpd
3915 18% /usr/local/httpd_2.0.54/bin/httpd -k start
15998 15% httpd
16185 5% /usr/local/httpd_2.0.54/bin/httpd -k start
16019 4% /usr/local/httpd_2.0.54/bin/httpd -k start
16199 4% httpd
16207 4% /usr/local/httpd_2.0.54/bin/httpd -k start
28762 4% httpd
28779 4% /usr/local/httpd_2.0.54/bin/httpd -k start
16011 4% /usr/local/httpd_2.0.54/bin/httpd -k start
10555 3% httpd
10572 3% httpd
11274 2% httpd
10348 1% httpd
11275 1% httpd
10351 1% httpd
14789 1% atop
32737 1% mysqld
1830 1% mysqld
4073 1% mysqld
5731 1% mysqld
7470 1% mysqld
** ( De trivial rewrite komt eens in zoveel tijd langs, logisch, staat maar op 3-4 domeinen. Willen we wel binnenkort geheel uitrollen ivm nieuw systeem) **

+++++++++++++++++++++++++
Apache-status (heb niet de details gepost, ivm privacy klanten/server)

Apache Server Status for www.***.nl
Server Version: Apache
Server Built: Oct 11 2005 17:00:01

--------------------------------------------------------------------------------

Current Time: Tuesday, 20-Jun-2006 12:03:07 CEST
Restart Time: Monday, 19-Jun-2006 14:11:52 CEST
Parent Server Generation: 0
Server uptime: 21 hours 51 minutes 15 seconds
Total accesses: 700833 - Total Traffic: 4.6 GB
CPU Usage: u83.5 s5.13 cu1.99 cs0 - .115% CPU load
8.91 requests/sec - 61.5 kB/second - 6.9 kB/request
16 requests currently being processed, 59 idle workers

** ( de processen lijst hieronder heeft veel processen met 20%. Soms een simpel plaatje ophalen, soms een webpagina en soms een php script, geen overeenkomsten in te vinden. Alleen dus veel processen die allemaal claimen 20% cpu te gebruiken) **

++++++++++++++++++++++++++++++++++++++++++
DSTAT output:

usr sys idl wai hiq siq|_read write|_recv _send|__in_ _out_|_int_ _csw_
22 19 58 1 0 0| 0 0 | 0 0 | 0 0 | 0 0
87 12 1 0 0 0| 640k 508k|7403B 60.5k| 0 0 |1134 3265
59 40 1 0 0 0| 0 4096B|26.6k 85.8k| 0 0 |1163 4874
53 46 0 0 0 0|4096B 0 |14.6k 96.8k| 0 0 |1199 4376
49 50 1 0 0 0| 0 28k|32.1k 438k| 0 0 |1425 5005
54 45 1 0 0 0| 0 0 |5731B 23.0k| 0 0 |1052 5523
46 53 1 0 0 0| 0 688k|6334B 33.4k| 0 0 |1137 4276
46 54 0 0 0 0| 128k 0 |3278B 2687B| 0 0 |1023 4740
45 53 1 0 0 0| 84k 0 |13.4k 132k| 0 0 |1167 4334
44 55 0 0 0 0| 0 776k|23.3k 11.7k| 0 0 |1280 4297
47 52 1 0 0 0| 256k 0 |26.9k 29.1k| 0 0 |1137 5076
48 52 0 0 0 0| 296k 0 |12.5k 230k| 0 0 |1228 4939
47 51 1 0 0 0| 0 492k|13.1k 78.0k| 0 0 |1174 5509
55 44 1 0 0 0|8192B 0 |4667B 36.0k| 0 0 |1093 5450
48 51 1 0 0 0| 132k 12k|3589B 32.7k| 0 0 |1092 4824
45 54 1 0 0 0| 0 0 |1004B 560B| 0 0 |1029 4678
47 52 1 0 0 0| 0 0 |3056B 8816B| 0 0 |1058 4867
64 35 1 0 0 0| 84k 332k|11.3k 76.1k| 0 0 |1166 5377
45 54 1 0 0 0|4096B 0 |3949B 15.8k| 0 0 |1056 5374
54 46 0 0 0 0| 64k 0 |21.6k 204k| 0 0 |1299 6201
59 40 0 0 0 0| 796k 0 |62.8k 289k| 0 0 |1489 4675
47 53 1 0 0 0| 0 188k|7182B 53.0k| 0 0 |1091 4980
60 39 1 0 0 0| 196k 408k|20.7k 249k| 0 0 |1328 4222
47 51 1 0 0 0| 136k 0 |12.0k 225k| 0 0 |1222 4350
55 44 0 0 0 0| 60k 0 |36.2k 221k| 0 0 |1392 4297
69 30 1 0 0 0| 48k 0 |17.1k 140k| 0 0 |1213 4409
45 54 1 0 0 0| 0 0 |1462B 653B| 0 0 |1022 5741
50 48 1 0 0 0| 12k 656k|4199B 57.3k| 0 0 |1124 5943
52 47 0 0 0 0|4096B 0 |23.2k 214k| 0 0 |1322 5310
54 46 1 0 0 0| 0 12k|1515B 1220B| 0 0 |1027 5842
50 50 0 0 0 0| 24k 0 |10.8k 44.6k| 0 0 |1091 5718
49 51 1 0 0 0| 76k 0 |11.0k 64.9k| 0 0 |1216 4894
45 54 1 0 0 0| 0 544k|1377B 6956B| 0 0 |1071 5011
62 38 0 0 0 0| 132k 0 | 618B 8856B| 0 0 |1016 4279
57 42 0 0 0 0| 388k 0 |7699B 115k| 0 0 |1148 4530
57 43 1 0 0 0| 0 0 |5156B 55.9k| 0 0 |1093 4525
58 40 1 0 0 0| 180k 0 |15.5k 117k| 0 0 |1153 4708
49 50 1 0 0 0| 100k 600k|14.5k 236k| 0 0 |1288 5569
48 51 1 0 0 0|8192B 28k|7075B 28.4k| 0 0 |1114 5650
47 52 1 0 0 0| 144k 0 | 640B 728B| 0 0 |1026 4450
54 45 1 0 0 0|2652k 0 |10.7k 168k| 0 0 |1203 4654
51 48 0 0 0 0| 0 0 |7870B 80.4k| 0 0 |1135 4192
77 22 0 0 0 0| 0 516k|8053B 53.6k| 0 0 |1151 4333
+++++++++++++++++++++++++++

Ik heb ook de output van alle "lsof" bekeken. Er was niets raars of groots open behalve alle logfiles van de domeinen. Er zit ook een error_log bij van 1.6GB (nooit geleegd denk ik), deze heb ik nu geleegd. Maar dit zal toch niet verantwoordelijk zijn voor de plotselinge traagheid die onverwachts inzet..

Ik hoop dat iemand misschien suggesties heeft, in ieder geval al heel veel dank als je de moeite neemt om dit allemaal te lezen..