Apache hängt sich unnachvollziehbar immer und immer wieder auf

Dawn

Registered User
Guten Tag,

Ich kämpfe nun seit Monaten mit meinem Indianer. Aus für mich unerklärlichen Gründen stürzt mein Apache-Server immer und immer wieder ab. Die folgend aufgeführte Fehlermeldung ist das einzige was zu diesen Zeitpunkten im Apache-Error-Log zu finden ist - manchmals allerdings mehrmals hintereinander:

Code:
Invalid argument: couldn't grab the accept mutex

Wie auch schon hier im Forum behandelt stehe ich mit meinem Problem nicht alleine da. Man findet mit Google zig Leute mit dem gleichen Problem - jedoch meistens V-Server Benutzer mit zu wenig Speicher. Ich aber habe einen Root-Server mit 3GB Ram :) Ich nutze Debian Etch mit der aktuellsten stabilen Version von Apache2. Zudem ist auch Plesk auf diesem Server installiert.

Folgende Werte verwende ich in meiner Apache2-Config (/etc/apache2/apache2.conf):
Code:
<IfModule mpm_prefork_module>
    StartServers          5
    ServerLimit         256
    MinSpareServers       5
    MaxSpareServers      10
    MaxClients          256
    MaxRequestsPerChild   2000
</IfModule>

Via htop erhalte ich die Angaben dass zwischen 600MB und 1GB Speicher genutzt wird. Swap-Space wird keiner benötigt.

"df -k" ergibt:
Code:
Filesystem           1K-blocks      Used Available Use% Mounted on
/dev/md0             306603832 142465224 148564000  49% /
tmpfs                  1684532         0   1684532   0% /lib/init/rw
udev                     10240        40     10200   1% /dev
tmpfs                  1684532         0   1684532   0% /dev/shm
/var/tmpmnt             483886      2360    456526   1% /tmp

Das sieht für mich auch i.O aus - LEIDER sonst wüsste ich wo ansetzen.

Ich habe mitlerweile sicher schon weit über 100h in das Problem investiert, aber komme trotz intensiven Recherchen zu keiner Lösung. Da ich weiss dass einige gute Leute im SSF möchte ich meinen "verzweifelten Hilferuf" nun an euch richten. Hab ihr irgendwelche Ideen oder Lösungsvorschläge?

Gern liefere ich noch weitere Infos. Lasst mich wissen wenn was fehlt.

Gruss,
Dawn
 
Last edited by a moderator:
Was sagt
Code:
cat /proc/sys/kernel/sem
Eventuell hilft es (wegen ServerLimit=256), die Zahl der Semaphoren entsprechend heraufzusetzen (sysctl -w).
 
Hast du mal versucht den Watchdog zu deaktivieren?
 
Ich erhalte folgende Ausgabe:

Code:
cat /proc/sys/kernel/sem
250     32000   100     128

Sind diese Werte kritisch? Ich kenne /proc/sys/kernel/sem nicht wirklich...

EDIT: Habe mich schlau gemacht. Sind 4 Werte:

SEMMSL - The maximum number of semaphores in a sempahore set
SEMMNS - The maximum number of sempahores in the system
SEMOPM - The maximum number of operations in a single Start of changesemopEnd of change call
SEMMNI - The maximum number of sempahore sets

"sysctl -w": Kann es sein dass die Zahl der Sempahores zu tief ist und da ein Wert von bis zu 256 "Servern" gesetzt ist dieses Limit überschritten wird? Ergibt es einen Sinn die Server auf weniger als 256 zu setzen oder soll ich per "sysctl -w" die Sempahores erhöhen?

Das mit dem Watchdog habe ich schon lange mal versucht. Nützt leider nichts... Habe aber gesehen dass ein Update des Watchdogs released wurde und werde dieses heute Abend mal einspielen.

Gruss und besten Dank für die neuen Vorschläge :)
Dawn
 
Last edited by a moderator:
Wie bereits erwähnt, habe ich dies auch schon versucht. Leider hat es nichts geholfen. Danke trotzdem...
 
Hi,

die Ursache des Problems wurde folgendermassen ermittelt. Es wurde eine Screen Session eröfnnet und
der Apache Prozess wurde mit einem strace gestartet: strace -o apache2 -ff -t -x /usr/sbin/apache2 -k start ; mail [...]

Sobald das von Dawn beschriebene Phenomen auftritt wurde ich via Mail darüber informiert. Dies geschah
um ca. 5:44 heute Nacht. Das Apache Error Log zeigte das beschrieben Verhalten:
Code:
[...]
[Fri Mar 20 05:44:08 2009] [emerg] (43)Identifier removed: couldn't grab the accept mutex
[Fri Mar 20 05:44:08 2009] [emerg] (43)Identifier removed: couldn't grab the accept mutex
[Fri Mar 20 05:44:08 2009] [emerg] (43)Identifier removed: couldn't grab the accept mutex
[Fri Mar 20 05:44:08 2009] [emerg] (43)Identifier removed: couldn't grab the accept mutex
[Fri Mar 20 05:44:08 2009] [emerg] (43)Identifier removed: couldn't grab the accept mutex
[Fri Mar 20 05:44:08 2009] [emerg] (43)Identifier removed: couldn't grab the accept mutex
[Fri Mar 20 05:44:08 2009] [emerg] (43)Identifier removed: couldn't grab the accept mutex
[Fri Mar 20 05:44:08 2009] [emerg] (43)Identifier removed: couldn't grab the accept mutex
[Fri Mar 20 05:44:08 2009] [emerg] (43)Identifier removed: couldn't grab the accept mutex
[...]

Ein ls -lctr zeigte mir alle Forks die zuletzt um 5:44 geändert wurden:

Code:
-rw-r--r-- 1 root root  27994854 2009-03-20 05:44 apache2.32659
-rw-r--r-- 1 root root   1892129 2009-03-20 05:44 apache2.30690
-rw-r--r-- 1 root root   1162766 2009-03-20 05:44 apache2.30689
-rw-r--r-- 1 root root  32870848 2009-03-20 05:44 apache2.30019
-rw-r--r-- 1 root root  31752352 2009-03-20 05:44 apache2.29781
-rw-r--r-- 1 root root  27530145 2009-03-20 05:44 apache2.29752
-rw-r--r-- 1 root root   9860155 2009-03-20 05:44 apache2.25368
-rw-r--r-- 1 root root   1441386 2009-03-20 05:44 apache2.2113
-rw-r--r-- 1 root root   5404889 2009-03-20 05:44 apache2.2112
-rw-r--r-- 1 root root  11439069 2009-03-20 05:44 apache2.2111
-rw-r--r-- 1 root root   5514071 2009-03-20 05:44 apache2.2110
-rw-r--r-- 1 root root  42037823 2009-03-20 05:44 apache2.18373
-rw-r--r-- 1 root root  29591368 2009-03-20 05:44 apache2.18372
-rw-r--r-- 1 root root  22290233 2009-03-20 05:44 apache2.17605

Wenn man sich diese Dateien ansieht rufen die letzten Zeilen alle die selben POPSIX Funktionen auf:


Code:
[...]
05:40:08 poll([{fd=36, events=POLLIN, revents=POLLIN|POLLHUP}], 1, 2000) = 1
05:40:09 read(36, "", 512)              = 0
05:40:09 close(36)                      = 0
05:40:09 read(8, 0xbfdf5b37, 1)         = -1 EAGAIN (Resource temporarily unavailable)
05:40:09 close(45)                      = 0
05:40:09 gettimeofday({1237524009, 207383}, NULL) = 0
05:40:09 semop(91783188, 0xb7cc9a48, 1) = -1 EIDRM (Identifier removed)
05:44:08 gettimeofday({1237524248, 741559}, NULL) = 0
05:44:08 exit_group(15)        
[...]

Hier sieht man ganz deutlich den Fehler: "05:40:09 semop(91783188, 0xb7cc9a48, 1) = -1 EIDRM (Identifier removed)"

Die Semaphorengruppe 91783188 ist nicht mehr vorhanden. Danach wird nur noch die Fehlermeldung in den FD vom error.log geschrieben (05:44:08 write(2, "[Fri Mar 20 05:44:08 2009] [emer"..., 90) = 90)

Ein grep nach der Semaphoren-Gruppe über alle Forks seit beginn der Aufzeichnung zeigt:

grep 91783188 * | wc -l
185704

185704 Operationen auf diese Semaphoren-Gruppe, jedoch gibt es nur drei Unique Operationen:

Code:
grep 91783188 * | grep -o 'semop.*' | tr -s ' ' | sort -u
semop(91783188, 0xb7cc9a48, 1) = 0
semop(91783188, 0xb7cc9a48, 1) = -1 EIDRM (Identifier removed)
semop(91783188, 0xb7cc9a4e, 1) = 0

D.h. Apache hat IMMER nur Werte auf die Semaphoren-Grupe addiert bzw. subtrahiert und auf einmal gibt es diese Gruppe nicht mehr, d.h. etwas von aussen
muss diese gelöscht haben, da es Apache selbst nicht war, siehe oben. Da das Problem immer wieder auftritt muss es etwas periodisches sein,
also wer kommt da in Frage? Richtig, z.B. cron :)

Also nochmal Fix ein grep auf error.log's nach dem Fehler String. Und siehe da, das Problem tritt scheinbar sporadisch auf, beim näheren hinsehen
stellt man aber fest, dass die Minutenagabe immer ein vielfaches von vier ist. Und was finde ich schönen in schönes in den zahlreichen cronjobs?

(Root Crontab:)
*/4 * * * * /usr/local/sassistant/monitor.sh


Der Inhalt des besagten Scripts:

Code:
#run the monitoring scripts
cd /usr/local/sassistant
[...]
sh upapache.sh > /usr/local/sassistant/apache.log 2> /usr/local/sassistant/apache2.log
[...]

Sieht ja schonmal SEHR interessant aus... :)

Inhalt von /usr/local/sassistant/upapache.sh:

Und siehe da, meien Nase hat mich nicht getäuscht!
(Was genau das Script macht habe ich mir nicht angesehen, da es uninteressant für mich ist warum das Script nicht das macht was es soll, wer Interesse hat kann das aber gerne genauer erroieren. :) )

Code:
[...]
if [ ${INPROCS} -eq "0" ]; then
        echo `date +%s` DOWN    ON >> ${apache_log}
        if [ "${already_rst}" -lt "${max_restart}" ]; then
                #restart service
                if [ ${sem_clean} -eq "1" ];then
                        CLEAN=`ipcs -s | grep -iw ${apache_user} | awk '{print $2}'` >> /dev/null 2>&1
                        ipcrm sem ${CLEAN} >> /dev/null 2>&1
                        rm -f /tmp/session_mm_*.sem
                fi     
                #force restart
[...]

Und ich präsentiere den Semaphoren-Gruppen Killer :

CLEAN=`ipcs -s | grep -iw ${apache_user} | awk '{print $2}'` >> /dev/null 2>&1
ipcrm sem ${CLEAN} >> /dev/null 2>&1




Stephan
 
Auch an dieser Stelle ein riesen Dankeschön an Stephan welcher mir super schnell und super kompetent geholfen hat. Wie ich ihm persönlich schon gesagt habe, muss ich neidvoll zugeben dass ich das niemals alleine hingekriegt hätte.

sassistant.sh ist ein Script von 4PSA Server Assistant... 4PSA hat mir etwas von "bekanntes Debian Problem" erzählt und der Apache müsste neu kompiliert werden..

Danke an alle welche mir geholfen haben :)

Gruss,
Dawn
 
Last edited by a moderator:
Also ich bin zwar komplett aussen vor... möchte aber die klasse Aufschlüsselung des Fehlers hier mal sehr loben!

"Stephan, vielen Dank für die super Aufschlüsselung"

Dank der Emotion mit der du geschrieben hast, wars sogar direkt spannend! :D

Greetz Centro
 
Ich bekomme gerade die selbe Fehlermeldung bevor sich der Apache verabschiedet, verwende jedoch nichts von 4PSA. Die Aussage mit bekanntes Debian Problem und neu kompilieren hat mich dazu gebracht, von Apache 2 2.2.9-10+lenny8 auf Apache 2 2.2.9-10+lenny7 downzugraden (kompiliere sehr ungerne), vielleicht ist es ein Bug, der in der Vorversion nicht auftritt. Bis jetzt sieht’s zumindest gut aus und er scheint nimmer abzuschmieren. Das System ist ziemlich neu und noch nackt, von dem her kann ich mir gerade nichts anderes vorstellen…
 
Ich habe nun auf 2.2.9-10+lenny7 downgegraded und nach einem Tag kam kein Ausfall mehr. Jetzt habe ich vor einer Stunde wieder auf 2.2.9-10+lenny8 aktualisiert und bis jetzt läuft er ohne murren. Komisch, aber hoffentlich bleibt es so. Vielleich ist das der Trick? ;-)
 
Back
Top