qmail: Erst schnell dann immer langsamer

F

Felix80

New Member
Hallo Forum,

ich kann gar nicht sagen, wieviel mir dieses Forum schon geholfen, diesmal stehe ich aber auf dem Schlauch.

Ich habe einen relativ alten VServer (Plesk 8.6, openSUSE 10.3, Qmail). Seit etwa zwei Monaten (gefühlt) wird der Email-Versand immer langsamer. Kollegen mit Email-Programmen klagen, dass die Email nicht verschickt werden können und sie müssen teilweise mehrere Minuten warten. Auf dem selben Server werden von einer Webanwendung relativ viele (~1000 prozessbezogene) Emails mit der PHP-Funktion mail() verschickt.

Wenn die Kollegen klagen und ich Plesk nach dem SMTP-Dienst schaue, zeigt er meisten rot an (läuft nicht). Gleichtzeitig gehen aber Mails aus der Mailqueue raus und auch ein Neustart ist nicht erforderlich, da das Icon von selbst wieder auf grün geht. Die ganze Zeit über gibt es auch ein qmail-send Prozess in der Prozessliste, der nicht zuviel Last erzeugt. Ein Aufruf von top zeigt, dass dieses Problem unabhängig vom load auftaucht, der irgendwo zwischen 0,4 und 2 liegt (siehe top ganz unten).

Allerdings gibt es einen Zusammenhang mit anderen z.Z. zu verschickenden Mails. Sobald qmail eine Mail ausliefern muss (egal ob lokal oder remote), bricht die Geschwindigkeit für neue Mailaufträge massiv ein. Wenn die Mailqueue leer ist, kann PHP mail() eine knapp unter einer Sekunde ausliefern, sobald Mails in der Mailqueue sind dauert es zwischen 10-45 Sekunden. Ruf ich das PHP Script kurz hintereinander auf, geht die erste Mail schnell raus und die zweite Mail langsam.

Bei hohem Mailaufkommen schaukelt sich das Problem spürbar auf. Wobei es keine Rolle spiel, ob die Mails auf dem Server erstellt werden oder von Kollegen eingeliefert werden. Sobald das Mailaufkommen wieder kleiner wird, verringert sich das Problem. Einen Anstieg im Mailaufkommen hat es aber vor zwei Monaten auch nicht gegeben, als die Probleme begannen.

Die Nameserver, Reverse-DNS, und -Rt0 Geschichten habe ich natürlich gecheckt (siehe unten). Die Mails werden unverschlüsselt eingeliefert (an den Zertifikaten sollte es nicht liegen). Einige Postfächer sind bis zu 6 Gigs groß.

An die concurrency-Settings von Qmail bin ich noch nicht rangegangen. Da es ja auch schon reicht, dass in der Mailqueue nur eine Mail liegt (egal ob remote oder local), damit dieses Problem auftritt. Vielleicht verstehe ich da aber etwas falsch.

Und mir ist aufgefallen, dass in /var/qmail/handlers/spool etwa 200 z.T. Monate alte Mails liegen.

Kennt jemand das Problem und kann mir helfen?

Grüße und Danke
Felix


Mit PHP:
Code: 
$ php mail.php
Sending mail()
0.63656902313232 seconds
$ php mail.php
Sending mail()
4.7495679855347 seconds

Ich habe das mal nachgebaut mit qmail-inject. Auch hier kann man sehen, das nachfolgende mails deutlich langsamer rausgehen.

Code: 
h14xxxxx:~ # date; echo to: felix@server.de | /var/qmail/bin/qmail-inject; date
Do 16. Feb 13:24:24 CET 2012
Do 16. Feb 13:24:25 CET 2012
h14xxxxx:~ # date; echo to: felix@server.de | /var/qmail/bin/qmail-inject; date
Do 16. Feb 13:24:26 CET 2012
Do 16. Feb 13:24:28 CET 2012
h14xxxxx:~ # date; echo to: felix@server.de | /var/qmail/bin/qmail-inject; date
Do 16. Feb 13:24:29 CET 2012
Do 16. Feb 13:24:34 CET 2012
h14xxxxx:~ # date; echo to: felix@server.de | /var/qmail/bin/qmail-inject; date
Do 16. Feb 13:24:35 CET 2012
Do 16. Feb 13:24:39 CET 2012
h14xxxxx:~ #

Der passende Auszug aus /usr/local/psa/var/log/maillog
Code: 
Feb 16 13:24:24 h14xxxxx qmail-queue-handlers[19931]: Handlers Filter before-queue for qmail started ...
Feb 16 13:24:24 h14xxxxx qmail-queue-handlers[19931]: from=root@h14xxxxx.stratoserver.net
Feb 16 13:24:24 h14xxxxx qmail-queue-handlers[19931]: to=felix@server.de
Feb 16 13:24:24 h14xxxxx qmail-queue-handlers[19931]: hook_dir = '/var/qmail//handlers/before-queue'
Feb 16 13:24:24 h14xxxxx qmail-queue-handlers[19931]: recipient[3] = 'felix@server.de'
Feb 16 13:24:24 h14xxxxx qmail-queue-handlers[19931]: handlers dir = '/var/qmail//handlers/before-queue/recipient/felix@server.de'
Feb 16 13:24:25 h14xxxxx qmail-queue-handlers[19931]: starter: submitter[19932] exited normally
Feb 16 13:24:25 h14xxxxx qmail: 1329395065.157427 new msg 9850236
Feb 16 13:24:25 h14xxxxx qmail: 1329395065.157626 info msg 9850236: bytes 230 from <root@h14xxxxx.stratoserver.net> qp 19932 uid 0
Feb 16 13:24:25 h14xxxxx qmail: 1329395065.856861 starting delivery 46: msg 9850236 to local 1-felix@server.de
Feb 16 13:24:25 h14xxxxx qmail: 1329395065.857024 status: local 1/10 remote 0/20
Feb 16 13:24:25 h14xxxxx qmail-local-handlers[19934]: Handlers Filter before-local for qmail started ...
Feb 16 13:24:26 h14xxxxx qmail-queue-handlers[19938]: Handlers Filter before-queue for qmail started ...
Feb 16 13:24:26 h14xxxxx qmail-local-handlers[19934]: from=root@h14xxxxx.stratoserver.net
Feb 16 13:24:26 h14xxxxx qmail-local-handlers[19934]: to=felix@server.de
Feb 16 13:24:26 h14xxxxx qmail-queue-handlers[19938]: from=root@h14xxxxx.stratoserver.net
Feb 16 13:24:26 h14xxxxx qmail: 1329395066.298940 delivery 46: success: did_0+0+2/
Feb 16 13:24:26 h14xxxxx qmail-queue-handlers[19938]: to=felix@server.de
Feb 16 13:24:27 h14xxxxx qmail-queue-handlers[19938]: hook_dir = '/var/qmail//handlers/before-queue'
Feb 16 13:24:27 h14xxxxx qmail: 1329395067.091093 status: local 0/10 remote 0/20
Feb 16 13:24:28 h14xxxxx qmail-queue-handlers[19938]: recipient[3] = 'felix@server.de'
Feb 16 13:24:28 h14xxxxx qmail: 1329395068.363638 end msg 9850236
Feb 16 13:24:28 h14xxxxx qmail-queue-handlers[19938]: handlers dir = '/var/qmail//handlers/before-queue/recipient/felix@server.de'
Feb 16 13:24:28 h14xxxxx qmail-queue-handlers[19938]: starter: submitter[19942] exited normally
Feb 16 13:24:28 h14xxxxx qmail: 1329395068.665296 new msg 9850184
Feb 16 13:24:28 h14xxxxx qmail-local-handlers[19944]: Handlers Filter before-local for qmail started ...
Feb 16 13:24:29 h14xxxxx qmail: 1329395069.473648 info msg 9850184: bytes 230 from <root@h14xxxxx.stratoserver.net> qp 19942 uid 0
Feb 16 13:24:29 h14xxxxx qmail-queue-handlers[19948]: Handlers Filter before-queue for qmail started ...
Feb 16 13:24:29 h14xxxxx qmail-local-handlers[19944]: from=root@h14xxxxx.stratoserver.net
Feb 16 13:24:30 h14xxxxx qmail: 1329395070.264613 starting delivery 47: msg 9850184 to local 1-felix@server.de
Feb 16 13:24:30 h14xxxxx qmail-local-handlers[19944]: to=felix@server.de
Feb 16 13:24:30 h14xxxxx qmail-queue-handlers[19948]: from=root@h14xxxxx.stratoserver.net
Feb 16 13:24:31 h14xxxxx qmail: 1329395071.364589 status: local 1/10 remote 0/20
Feb 16 13:24:32 h14xxxxx qmail-queue-handlers[19948]: to=felix@server.de
Feb 16 13:24:32 h14xxxxx qmail: 1329395072.423865 delivery 47: success: did_0+0+2/
Feb 16 13:24:32 h14xxxxx qmail-queue-handlers[19948]: hook_dir = '/var/qmail//handlers/before-queue'
Feb 16 13:24:33 h14xxxxx qmail: 1329395073.026831 status: local 0/10 remote 0/20
Feb 16 13:24:33 h14xxxxx qmail-queue-handlers[19948]: recipient[3] = 'felix@server.de'
Feb 16 13:24:33 h14xxxxx qmail: 1329395073.401616 end msg 9850184
Feb 16 13:24:33 h14xxxxx qmail-queue-handlers[19948]: handlers dir = '/var/qmail//handlers/before-queue/recipient/felix@server.de'
Feb 16 13:24:34 h14xxxxx qmail-queue-handlers[19948]: starter: submitter[19952] exited normally
Feb 16 13:24:34 h14xxxxx qmail: 1329395074.558677 new msg 9850184
Feb 16 13:24:34 h14xxxxx qmail: 1329395074.773783 info msg 9850184: bytes 230 from <root@h14xxxxx.stratoserver.net> qp 19952 uid 0
Feb 16 13:24:34 h14xxxxx qmail-local-handlers[19954]: Handlers Filter before-local for qmail started ...
Feb 16 13:24:35 h14xxxxx qmail: 1329395075.309948 starting delivery 48: msg 9850184 to local 1-felix@server.de
Feb 16 13:24:35 h14xxxxx qmail-queue-handlers[19958]: Handlers Filter before-queue for qmail started ...
Feb 16 13:24:36 h14xxxxx qmail: 1329395076.330075 status: local 1/10 remote 0/20
Feb 16 13:24:36 h14xxxxx qmail-local-handlers[19954]: from=root@h14xxxxx.stratoserver.net
Feb 16 13:24:37 h14xxxxx qmail-local-handlers[19954]: to=felix@server.de
Feb 16 13:24:37 h14xxxxx qmail-queue-handlers[19958]: from=root@h14xxxxx.stratoserver.net
Feb 16 13:24:37 h14xxxxx qmail: 1329395077.678698 delivery 48: success: did_0+0+2/
Feb 16 13:24:38 h14xxxxx qmail-queue-handlers[19958]: to=felix@server.de
Feb 16 13:24:38 h14xxxxx qmail: 1329395078.009558 status: local 0/10 remote 0/20
Feb 16 13:24:38 h14xxxxx qmail: 1329395078.871718 end msg 9850184
Feb 16 13:24:38 h14xxxxx qmail-queue-handlers[19958]: hook_dir = '/var/qmail//handlers/before-queue'
Feb 16 13:24:38 h14xxxxx qmail-queue-handlers[19958]: recipient[3] = 'felix@server.de'
Feb 16 13:24:39 h14xxxxx qmail-queue-handlers[19958]: handlers dir = '/var/qmail//handlers/before-queue/recipient/felix@server.de'
Feb 16 13:24:39 h14xxxxx qmail: 1329395079.587290 new msg 9850184
Feb 16 13:24:39 h14xxxxx qmail-queue-handlers[19958]: starter: submitter[19962] exited normally
Feb 16 13:24:39 h14xxxxx qmail: 1329395079.697880 info msg 9850184: bytes 230 from <root@h14xxxxx.stratoserver.net> qp 19962 uid 0
Feb 16 13:24:40 h14xxxxx qmail-local-handlers[19964]: Handlers Filter before-local for qmail started ...
Feb 16 13:24:40 h14xxxxx qmail: 1329395080.167264 starting delivery 49: msg 9850184 to local 1-felix@server.de
Feb 16 13:24:41 h14xxxxx qmail: 1329395081.380693 status: local 1/10 remote 0/20
Feb 16 13:24:40 h14xxxxx qmail-local-handlers[19964]: from=root@h14xxxxx.stratoserver.net
Feb 16 13:24:41 h14xxxxx qmail-local-handlers[19964]: to=felix@server.de
Feb 16 13:24:41 h14xxxxx qmail: 1329395081.775765 delivery 49: success: did_0+0+2/
Feb 16 13:24:41 h14xxxxx qmail: 1329395081.775847 status: local 0/10 remote 0/20
Feb 16 13:24:41 h14xxxxx qmail: 1329395081.904212

/etc/resolv.conf
Code: 
nameserver 85.214.7.22
nameserver 81.169.163.106

/etc/hosts
Code: 
127.0.0.1       localhost

# special IPv6 addresses
::1             localhost ipv6-localhost ipv6-loopback

fe00::0         ipv6-localnet

ff00::0         ipv6-mcastprefix
ff02::1         ipv6-allnodes
ff02::2         ipv6-allrouters
ff02::3         ipv6-allhosts

# Auto-generated hostname. Please do not remove this comment.
85.214.xx.xxx h14xxxxx.stratoserver.net h14xxxxx

Code: 
$nslookup 127.0.0.1
Server:         85.214.7.22
Address:        85.214.7.22#53

Non-authoritative answer:
1.0.0.127.in-addr.arpa  name = localhost.

Authoritative answers can be found from:

$nslookup 85.214.xx.xxx
Server:         85.214.7.22
Address:        85.214.7.22#53

Non-authoritative answer:
xxx.xx.214.85.in-addr.arpa      name = h14xxxxx.stratoserver.net.

Authoritative answers can be found from:

/var/qmail/control/me
Code: 
h14xxxxx.stratoserver.net

/var/qmail/control/locals
Code: 
localhost

/etc/xinet.d/smtp_psa
Code: 
service smtp
{
        socket_type     = stream
        protocol        = tcp
        wait            = no
        disable         = no
        user            = root
        instances       = UNLIMITED
        env             =  SMTPAUTH=1
        server          = /var/qmail/bin/tcp-env
        server_args     = -Rt0  /var/qmail/bin/relaylock /var/qmail/bin/qmail-smtpd /var/qmail/bin/smtp_auth /var/qmail/bin/true /var/qmail/bin/cmd5checkpw /var/qmail/bin/true
}

/etc/xinet.d/smtps_psa
Code: 
service smtps
{
        socket_type     = stream
        protocol        = tcp
        wait            = no
        disable         = no
        user            = root
        instances       = UNLIMITED
        env             =  SMTPAUTH=1
        server          = /var/qmail/bin/tcp-env
        server_args     = -Rt0  /var/qmail/bin/relaylock /var/qmail/bin/qmail-smtpd /var/qmail/bin/smtp_auth /var/qmail/bin/true /var/qmail/bin/cmd5checkpw /var/qmail/bin/true
}

Code: 
top - 13:53:29 up 21:53,  2 users,  load average: 0.78, 0.58, 0.42
Tasks:  83 total,   3 running,  80 sleeping,   0 stopped,   0 zombie
Cpu(s):  5.4%us,  2.0%sy,  0.0%ni, 86.7%id,  6.0%wa,  0.0%hi,  0.0%si,  0.0%st
Mem:   6291456k total,   473208k used,  5818248k free,        0k buffers
Swap:        0k total,        0k used,        0k free,        0k cached
 
Last edited by a moderator:
Felix80 said:
Ich habe einen relativ alten VServer (Plesk 8.6, openSUSE 10.3, Qmail).
Click to expand...

Für openSUSE 10.3 gibt es seit mehr als zwei Jahren(!) keinerlei (Sicherheits-)Updates mehr:

http://lists.opensuse.org/opensuse-announce/2009-08/msg00008.html

Das Plesk ist ebenfalls altertümlich. Daher Accounts und Userdaten exportieren, Server mit aktuellem System neu installieren und danach Accounts und Daten wieder importieren. Sollte es dann immer noch Probleme mit den Mails geben, kann man das dann genauer analysieren.
 
Von der Sicherheitsproblematik mal abgesehn (kümmer dich darum! :-)) -
beobachte mal ob dein io-wait (%wa im top) zwischendurch steigt und/oder ob einer deiner Prozesse im D-State hängt.

Das wäre dann ein Hinweis auf io-last, die entweder vom System selber kommt oder vom Hostsystem nicht verarbeiten kann (wenn der Hoster die Vserver zu dicht packt).

Interessant in dem Zusammenhang noch tools wie iotop, dstat, iostat.

Mit den Mails in der Mailqueue könnte ein Zusammenhang bestehen, wenn qmail die immer mal wieder versucht auszuliefern.

schöne Grüße,
Nils
 
Der Plan war bis zur neuen Ubuntu 12.04 LTS zu warten und dann die Dienste auf verschiedene Server zu verteilen. Daher die antiquierte Software. Die paar Monate wollte ich noch mit diesem System überbrücken. Deshalb bin ich sehr an einer Lösung interessiert. Wahrscheinlich habe ich schon zu lange gewartet.

Ein Einfluss von Mails auf %wa konnte ich nicht fesstellen. Nur in ganz wenigen Fällen erreicht er mal 6%, sonst liegt er meist bei 0 oder 0.8%.

Trotzdem werde ich bei Strato mal nachfragen. Auch ein Backup ist einmal in den letzten Tagen gescheitert. Als die Probleme anfingen hatten wir sehr rechenintensive Jobs auf dem Server, auf die ich ursprünglich das Problem geschoben haben. Da hatten wir z.T. einen Load von 17. Ich dachte qmail gingen die Ressourcen aus. Diese Jobs sind nun optimiert. Möglicherweise hat mich Strato dann auf einen Cluster für ressourcenhungrige Kunden geschoben. Gibt es sowas?

Gruß Felix
 
You must log in or register to reply here.
Back
Top