smtp_greylist.pl: child crashed

  • pd-admin-version: v4.58
    serverumgebung: 0313


    hallo zusammen,


    Absender die an Mailadressen auf meinem Server eine Mail schreiben bekommen teilweise folgende Fehlermeldung und die Mail wird bei mir nicht zugestellt:



    Zitat

    <xxx@domain.de>: host domain.de[xx.xx.xx.xx] said: 451 qmail-spp failure: /opt/pdadmin/bin/smtp_greylist.pl: child crashed (#4.3.0) (in reply to MAIL FROM command)


    Bei mir ist im Log keine Fehlermeldung zu sehen. Ich sehe lediglich dass der fremde Mailserver Kontakt aufgenommen hat:


    Zitat


    smtpd: 1527246086.588039 tcpserver: ok 32746 mail.domain.de:::ffff:xx.xx.xx.xx:25 absenderdomain.de:::ffff:yy.yy.yy.yy::22407



    Wahrscheinlich steht der Fehler im Zusammenhang mit einem Update auf Ubuntu 16.044


    Irgendwelche Ideen?
    Wie bekomme ich von /opt/pdadmin/bin/smtp_greylist.pl mehr Debug-Infos? Kann ich das Script ggf. selbst testen? Welche Parameter erwartet es?



    Danke und Grüße

  • Der Fehler sagt mir so leider nichts... :( Eingetragen/Aufgerufen wird die Datei hier:



    Vielleicht kann man die Datei über ein wrapper script aufrufen und darin debuggen?

  • Vielleicht hilft folgendes bei der Fehlersuche:


    1. Wrapper Skript erstellen:


    Code
    cat /opt/pdadmin/bin/debug_greylist.sh
    #!/bin/bash
    strace -o /tmp/smtp_greylist.log-$(date "+%s") /opt/pdadmin/bin/smtp_greylist.pl "$@"


    Code
    chmod 755 /opt/pdadmin/bin/debug_greylist.sh


    2. qmail anpassen



    Unter /tmp/smtp_grelist.log-* finden sich dann die Logs zu der Ausführung des Skripts.

  • Danke für den Tipp.


    Die strace-Ausgabe sagt mir allerdings nichts. Es sind ca. 150 KB Informationen. Sehr oft so was wie

    Zitat

    stat64("/opt/pdadmin/lib/auto/DBI/DESTROY.al", 0xbfa4a7c4) = -1 ENOENT (No such file or directory.


    Was in der Häufigkeit eigentlich nicht sein kann, daher nehme ich an dass dort einfach verschiedene Verzeichnisse nach Bibliotheken durchsucht werden.


    Hast du einen Tipp wonach ich genau suchen muss???


    Jetzt findet sich allerdings in meinem Maillog folgender Eintrag


    Zitat

    smtpd: 1527974542.836836 /opt/pdadmin/bin/debug_greylist.sh: line 2: 1787 Segmentation fault strace -o /var/log/smtp_greylist/$(date "+%s") /opt/pdadmin/bin/smtp_greylist.pl "$@"

  • Segmentaktion fault deutet auf ein Problem beim Arbeitsspeicher hin. qmail-smtpd wird mit einem softlimit ausgeführt. Oft ist dies zu niedrig. Wie hoch ist der Wert in

    Code
    /service/qmail-smtpd/run


    ? Bei meinem Server ist der Wert auf

    Code
    [..] softlimit -m 75000000 [..]

    gesetzt. Ich würde den werde einmal sukzessiv erhöhen, bis der Fehler nicht mehr auftritt.

  • Hallo zusammen,


    schließe mich diesem Thread an, da ich dasselbe Problem auf einem Debian 9 Stretch habe.


    Debug aktiviert wie oben beschrieben - selbes Verhalten mit sehr vielen Libs, die nicht gefunden werden:


    cat /tmp/smtp_greylist.log-1540981497

    execve("/opt/pdadmin/bin/smtp_greylist.pl", ["/opt/pdadmin/bin/smtp_greylist.p"...], [/* 30 vars */]) = 0

    brk(NULL) = 0xa11c000

    access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)

    mmap2(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xf7745000

    access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)

    open("./tls/i686/sse2/cmov/libnsl.so.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)

    open("./tls/i686/sse2/libnsl.so.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)

    open("./tls/i686/cmov/libnsl.so.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)

    open("./tls/i686/libnsl.so.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)

    open("./tls/sse2/cmov/libnsl.so.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)

    open("./tls/sse2/libnsl.so.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)

    open("./tls/cmov/libnsl.so.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)

    open("./tls/libnsl.so.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)

    open("./i686/sse2/cmov/libnsl.so.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)

    open("./i686/sse2/libnsl.so.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)

    open("./i686/cmov/libnsl.so.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)

    open("./i686/libnsl.so.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)

    open("./sse2/cmov/libnsl.so.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)

    open("./sse2/libnsl.so.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)

    open("./cmov/libnsl.so.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)

    open("./libnsl.so.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)

    open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 0

    fstat64(0, {st_mode=S_IFREG|0644, st_size=44010, ...}) = 0

    mmap2(NULL, 44010, PROT_READ, MAP_PRIVATE, 0, 0) = 0xf773a000

    close(0) = 0

    access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)

    open("/lib32/libnsl.so.1", O_RDONLY|O_CLOEXEC) = 0

    read(0, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\0201\0\0004\0\0\0"..., 512) = 512

    fstat64(0, {st_mode=S_IFREG|0644, st_size=96128, ...}) = 0

    mmap2(NULL, 108488, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 0, 0) = 0xf771f000

    mprotect(0xf7735000, 4096, PROT_NONE) = 0

    mmap2(0xf7736000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 0, 0x16000) = 0xf7736000

    mmap2(0xf7738000, 6088, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xf7738000

    close(0) = 0

    open("./tls/i686/sse2/cmov/libdl.so.2", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)

    open("./tls/i686/sse2/libdl.so.2", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)

    open("./tls/i686/cmov/libdl.so.2", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)

    open("./tls/i686/libdl.so.2", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)

    open("./tls/sse2/cmov/libdl.so.2", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)

    open("./tls/sse2/libdl.so.2", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)

    open("./tls/cmov/libdl.so.2", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)

    open("./tls/libdl.so.2", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)

    open("./i686/sse2/cmov/libdl.so.2", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)

    open("./i686/sse2/libdl.so.2", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)

    open("./i686/cmov/libdl.so.2", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)

    open("./i686/libdl.so.2", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)

    open("./sse2/cmov/libdl.so.2", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)

    open("./sse2/libdl.so.2", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)

    open("./cmov/libdl.so.2", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)

    open("./libdl.so.2", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)

    access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)

    open("/lib32/libdl.so.2", O_RDONLY|O_CLOEXEC) = 0

    ...


    Das Verhalten tritt nach einem Debian 8 auf 9 Upgrade auf.


    Gibt es noch Anhaltspunkte um das Problem allgemein zu lösen? Da ohne das Debug Skript greylisting de-facto nicht funktioniert.


    Danke

  • Es wird nach 'libnsl.so.1' und 'libdl.so.2' gesucht. Diese werden gefunden:

    Code
    [...]
    open("/lib32/libnsl.so.1", O_RDONLY|O_CLOEXEC) = 0
    [...]
    open("/lib32/libdl.so.2", O_RDONLY|O_CLOEXEC) = 0
    [...]

    Sieht für mich also ok aus. Die suche nach Libs ist auch durchaus normales Verhalten. Selber setze ich kein Debian ein, daher müsste der Fundort der Libs einmal verifiziert werden.


    Und es scheint mir nicht die vollständige Ausgabe des Logs zu sein. Zumindest sind am Ende "...". Ohne vollständiges Log ist eine korrekte Analyse nicht möglich. Meist tritt der eigentliche Fehler nämlich am Ende auf ;)


    Ansonsten auch hier die Frage wie hoch das Speicherlimit bei qmail-smtpd ist. Die Antwort, ob eine Erhöhung des Limits das Problem löste ist bisher ja ausgeblieben.

  • Danke für deine Rückmeldung, gerne stelle ich das gesamte Log rein:


    gist auf github


    Bezüglich softlimit (qmail-smtpd):


    exec /usr/local/bin/softlimit -m 50000000 \

    /usr/local/bin/tcpserver -j -x /etc/tcp.smtp.cdb -h -P -R -u $QMAILDUID \

    -g $NOFILESGID -c $MAXCONN -v 0 smtp \

    /var/qmail/bin/qmail-smtpd $HOSTNAME \

    /usr/local/pd-admin2/bin/checksmtppasswd /bin/true 2>&1


    Da qmail-smtpdSd im Einsatz ist:


    /usr/local/bin/softlimit -m 128000000 \

    /usr/local/bin/tcpserver -x /etc/tcp.msa.cdb \

    -c "$MAXSMTPD" \

    -u "$QMAILDUID" -g "$NOFILESGID" \

    -v -R -H -l $HOSTNAME 0 465 \

    /usr/local/pd-admin2/bin/couriertls -server -tcpd \

    /var/qmail/bin/qmail-smtpd $HOSTNAME /usr/local/pd-admin2/bin/checksmtppasswd \

    /bin/true 2>&1


    Zusätzlich: Speicher auf diesem Server ist reichlich vorhanden und frei (32GB und 20GB frei)


    Fehlt weitere Info?


    Besten Dank.

  • Ich konnte im Log auf die schnelle keine Fehler finden. Es kann aber sein, dass der Fehler genau da nicht auftrat... Trat der Fehler denn U dem Zeitpunkt auf? Wenn ja, findet sich vielleicht etwas in anderen Logs?


    Bei /service/qmail-smtpd/run ist eine Speicherlimit von 50MB eingestellt. Wie ich zuvor schrieb, habe ich auf meinem VPS ein Limit von 75MB. Ich würde daher einmal das Ganze mit einem höheren Speicherlimit testen. Anstatt

    Code
    exec /usr/local/bin/softlimit -m 50000000 \


    vielleicht Mal

    Code
    exec /usr/local/bin/softlimit -m 100000000 \


    nehmen.


    Es kann sein, dass sich durch das Upgrade die Anforderungen einiger Libs geändert haben und das bisherige softlimit nicht mehr ausreicht. 'softlimit -m' limitiert nicht nur den Speicherbedarf in Bytes, sondern auch Adressraum bzw die Page Table (siehe man Page). Als Beispiel, die o.g. Libs 'libnsl.so.1' und 'libdl.so.2' sind im Paket libc6-x32 enthalten. Hier hat sich die Version von Debian 8 auf 9 von 2.19 auf 2.24 geändert.

  • Hallo - vielen Dank nochmals!


    Habe das Speicherlimit nun einmal auf 100MB erhöht wie von dir vorgeschlagen und bis dato ist der Fehler nicht mehr aufgetreten. Ich werde das weiterhin beobachten und sollte sich noch etwas ergeben hier rückmeldung.


    Nochmals danke für den Tipp!