​smtp_greylist.p[5476]: segfault at 18 ip 00000000004320a8 …

1. offizieller Beitrag
    • Offizieller Beitrag
    Code
    > top -bn1
top - 10:47:27 up 14:06,  1 user,  load average: 0.02, 0.01, 0.01
Tasks: 776 total,   1 running, 775 sleeping,   0 stopped,   0 zombie
%Cpu(s):  0.3 us,  0.1 sy,  1.0 ni, 97.8 id,  0.7 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem:  24735704 total, 24502880 used,   232824 free,   952884 buffers
KiB Swap:  9765620 total,        0 used,  9765620 free. 19200836 cached Mem

    auf der Konsole erscheint auch ständig so etwas:

    Code
    Message from syslogd@mail at Dec 22 10:43:50 ...
 t of memory [NNNNN]


    ansonsten funktioniert soweit alles :/


    Das Problem tritt auch kurz nach einem reboot auf

    Konnte das Problem denn schon nachgestellt werden? Was genau heißt "auf der Konsole"?

    Zitat von Twilo

    KiB Mem: 24735704 total, 24502880 used, 232824 free, 952884 buffers
    KiB Swap: 9765620 total, 0 used, 9765620 free. 19200836 cached Mem

    Hier sind ~230MB frei und ~950MB als Buffer verfügbar. Der Großteil des Arbeitsspeichers ist jedoch belegt. Eventuell stehen dem Prozess tatsächlich nicht genug Ressourcen zur Verfügung. Wie sieht die "free -ht" Ausgabe aus? Da gar kein Swap genutzt wird, ist die swappiness auf dem Server eventuell auf 0 gestellt?


    Ich würde aber zuerst einmal versuchen das Problem nachzustellen. Vielleicht einmal den Zeitpunkt der Meldung im messages/system Log und dem maillog abgleichen. Vermutlich wird sich da die Einlieferung einer Mail finden. Dies muss man sich dann genauer anschauen. Wenn dies keinen Treffer gibt, dann einmal die Zustellung selber testen.

    • Offizieller Beitrag


    die Meldung erscheint direkt im Terminal, z.B. direkt nachdem ich swappiness ausgeben lassen hatte



    Code
    mail:~
> grep smtp_greylist.p /var/log/messages |tail -n1
Dec 22 11:49:51 mail kernel: [54455.559483] smtp_greylist.p[26115]: segfault at 18 ip 00000000004320a8 sp 00007fff97614f90 error 4 in smtp_greylist.pl[400000+151000]


    in der mail.log steht dazu nichts …



    bei dmesg sieht es z.B. wie folgt aus

    Die Meldungen direkt auf der Konsole sind schon merkwürdig. Auf meinem VPS kann ich dies nicht beobachten und habe auch keinerlei derartige Log Einträge.

    Zitat von Twilo

    Dec 22 11:49:49 mail qmail-smtpd: qmail-smtpd/VC started

    Hier wurde ein neuer qmail Prozess gestartet um, vermutlich, eine Mail einzuliefern. Bei Sekunde 51 gab es dann die segfault Meldung im messages log. Dies passt in meinen Augen zusammen. Bliebe weiterhin die Frage, wieso es dazu kommt.


    Bei der free Ausgabe sieht man bei Zeile -/+ buffers/cache und Spalte free, dass 19GB zur Verfügung stehen. Sieht also OK aus.


    Wie hoch ist denn das softlimit für den smtpd Dienst? Eventuell kann man dies testweise einmal erhöhen.


    smtp_greylist.pl wird bei "rcpt" ausgeführt (Datei /var/qmail/control/greylist). Man kann versuchen das Skript durch ein Wrapper Skript zu ersetzen. In dem Wrapper Skript wird dann ein strace von smtp_greylist.pl ausgeführt.

    Zitat von Twilo

    /service/qmail-smtpSd/run: -m 128000000

    /service/qmail-smtpd/run: -m 80000000

    Es geht nur um qmail-smtpd. qmail-smtpSd ist hierbei nicht beteiligt.

    Der Dienst qmail-smtpd hat als Limit 80000000 (80MB) zugewiesen. Das scheint mir zu gering zu sein. Ich würde es einmal auf 128000000 anheben.

    • Offizieller Beitrag

    nachdem ich den Wert auf 128000000 erhöht habe und den Server neugestartet habe ("svc -du /service/qmail-smtpd/ " reichte nicht aus, da kam dann "smtpd: 1640177489.686760 tcpserver: fatal: unable to bind: address already used")


    Code
    > free -ht
             total       used       free     shared    buffers     cached
Mem:           23G       3.3G        20G        27M       285M       751M
-/+ buffers/cache:       2.3G        21G
Swap:         9.3G         0B       9.3G
Total:         32G       3.3G        29G

    Wie hängt das ganze zusammen? :/

    • Offizieller Beitrag
    Zitat von Eisenherz

    Irgendwie sieht das jetzt aus, als würden zwei Dienste jetzt laufen.

    das war, nachdem ich den Wert geändert hatte und den Dienst dann mit ""svc -du /service/qmail-smtpd/" neugestartet hatte.

    Mir fiel das erst nach einer Weile auf, da ich den Server eh rebooten wollte, wurde das durch den Reboot gleich mit behoben.


    Der Reboot war vor ca. 80 Minuten, seit dem trat kein Problem mehr auf, auch nicht die Meldung, die immer direkt im Terminal erschien.

    • Offizieller Beitrag

    Dann denke ich, dass der Qmail einfach nicht richtig neu gestartet war und deshalb noch hing und jetzt nach dem Reboot wieder ordentlich gestartet ist.


    Bei mir war es so, dass die Kunden sich beschwert haben, dass die eMails "lange" dauern würden. Ich denke es lag einfach daran, dass das Aufkommen auch höher war, als ich den den Wert geändert habe war alles gut. Vielleicht sind bei Dir einfach jetzt "zu viele" eMails die gleichzeitig bearbeitet wurden und dafür hatte Qmail dann zu wenig Speicher und ist abgestürzt.

    • Offizieller Beitrag

    Wieder etwas neues …

    Code
    [11282.987642] php5[30792]: segfault at 0 ip 000000000049bbc1 sp 00007ffe9b1902b0 error 4 in php5[400000+5f5000]
[11283.113544] php5[447]: segfault at 0 ip 000000000049bbc1 sp 00007fff62a993c0 error 4 in php5[400000+5f5000]
[16801.763581] perf interrupt took too long (2501 > 2500), lowering kernel.perf_event_max_sample_rate to 50000

    tja, wie kann ermittelt werden, bei welchem Kunden das Problem aufgetreten ist? :/

    • Offizieller Beitrag

    php Segfaults, insbesondere bei alten Versionen (php5), gibts immer wieder mal. Die seh ich seit gefühlt 15 Jahren auf allen Servern immer wieder mal. Frag mich nicht wie es zu denen kommt, fehlerhafte Skripte oder welche die Abstürzen weil komische Requests (Angriffsversuche) daher kommen - ich vermute was in der Richtung. Könnte mir auch vorstellen dass es durch den CGI Wrapper dazu kommt, da dieser ja die Resourcen eines php Prozesses sehr vergleichbar begrenzt wie es bei den qmail Prozessen auch der Fall ist. Also wenn ein php Skript resourcenmäßig über die Stränge schlägt, wird es vielleicht ebenso abgewürgt und hinterlässt so einen Segfault.


    Jedenfalls: Obwohl ich solche php5 segfaults wie Deine mehrmals am Tag sehe, hör ich aber seit Jahren keine Beschwerden, insofern gehört das für mich zum Grundrauschen des Serverbetriebs dazu.

    Zitat von Twilo

    Was mich verwundert, der Server läuft so seit bestimmt 10 Jahren … warum tritt das Problem jetzt auf einmal auf :/

    Wenn der Server 10 Jahre ound Updates laufen würde, wäre es sicherlich merkwürdig. Da aber sicherlich Updates eingespielt werden, können sich Bedingungen immer Mal ändern.

    Oder wurde ein SE Upgrade auf Version 4 durchgeführt? Dadurch wurden dann auf 64bit Bibliotheken umgestellt. Die vorherigen SE Versionen hatten 32bit Bibliotheken. Durch die Umstellung können dann höhere Limits notwendig sein, da durch 64bit auch größere Adressräume benötigt werden.


    Gleiches gilt dann für die segfault Fehler.

    Zitat von Twilo

    tja, wie kann ermittelt werden, bei welchem Kunden das Problem aufgetreten ist? :/

    Das ist schwierig. Es könnte ebenfalls ein zu geringes Speicherlimit sein oder auch eine fehlerhafte PHP Extension.

    Ich habe bei mir in den logs auch ein, zwei Einträge gefunden. Jedoch keine Relation zu einem konkreten Aufruf oder anderen Fehlern.

    Man kann versuchen core dumps für PHP zu aktivieren und so den Fehlern auf die Spur zu kommen. So aus dem Stehgreif weiß ich jedoch gerade nicht wie dies zu konfigurieren ist. Man muss wohl zuerst core dumps im Kernel aktivieren. Bei FPM muss in der Konfiguration dann

    Code
    rlimit_core = unlimited


    angegeben werden. core dumps können dann mit gdb ausgewertet werden.