Server stürtzt ab, wenn eine Mail aus der Qmail-Queue automatisch entfernt wird

HMnet · Apr 14, 2009

Hi @ all,

erstmal HALLO an ALLE.

Ich habe folgendes Problem auf meinem 1&1 Server mit SuSe 10.2 und Plesk 9.01 (von 1&1) - ca. 200 Websites:

Ich habe einen Kunden, der ein Problem mit dem E-Mail-Versand an eine spezielle Domain hat. An diese Domain kann er keine E-Mails mit Anhang versenden, ab ca. 500kb bleiben die Mails in der Mail-Queue hängen, der Server versucht die ständig zuzustellen, geht aber nicht, am Ende (nach 7 Tagen) kommt der Kunde die Fehlermeldung: "Connected to xxx.xxx.xxx.xxx but connection died. (#4.4.2) I'm not going to try again; this message has been in the queue too long.". (Übrigens, wenn ich die Mail über web.de oder t-online.de verschicke, gehen 8 MB problemlos durch.) Ok, das ist aber noch nicht das eingentliche Problem, das Problem ist folgendes:

Sobald die 7 Tage (qmaillifetime) vorüber sind, soll die Mail ja automatisch aus der Queue gelöscht werden und eben o.g. Error-Mail an den Absender geschickt werden und genau bei diesem Vorgang stirbt mein Server. Er ist dann nicht mehr erreichbar, kein Dienst läuft, per SSH komme ich ebenfalls nicht mehr ran. Die serielle Konsole bringt keine Ausgaben mehr. Das einzigste, was ich mache kann, das Teil per Recovery Console neu zu starten und im Anschluß, also, wenn er wieder läuft, bekommt der Kunde seine Error-Mail.

Wenn ich ehrlich bin, dann kann ich nichts unnormales in den logfiles entdecken. Alle Updates sind eingespielt. Qmail habe ich per autoinstaller über SSH nochmal manuell drübergebügelt.

So, ich hoffe, jemand hat einen Rat für mich, habe leider noch keinen solchen Fall in Foren oder Google gefunden, aber vielleicht kann ja trotzdem jemand was zur Lösung beitragen.

Bin für jeden Lösungsansatz dankbar.

THX schon mal,
HMnet

Huschi · Apr 14, 2009

Spuckt "df" zufällig 100% auf der unter /var/ gemounteten Platte aus?

huschi.

HMnet · Apr 15, 2009

Hallo!

Nein:

Code:

Filesystem            Size  Used Avail Use% Mounted on
/dev/sda1             950M   89M  813M  10% /
udev                  2.0G   84K  2.0G   1% /dev
/dev/sda5             4.7G  3.3G  1.5G  69% /usr
/dev/sda6             4.7G  3.1G  1.7G  65% /var
/dev/sda7              19G  4.6M   19G   1% /home
/dev/sda8             668G  304G  364G  46% /srv
none                  2.0G  476K  2.0G   1% /tmp

Habe alle Mailboxen und logfiles von /var nach /srv/ "gesymlinkt".

Das Thema das "/var/" vollläuft hatte ich schon vor langer Zeit ;-) .

Grüße,
HMnet

Huschi · Apr 15, 2009

Es war zumindest ein typischer Fehler, auf den die Symptome passen.

HMnet said:
dann kann ich nichts unnormales in den logfiles entdecken.

Du nicht. Und damit auch sonst keiner?

a) maillog (aus /usr/local/psa/var/)
b) messages

Auf der anderen Seite, wenn der Server wirklich zusammenbricht, werden wahrscheinlich auch keine Logfiles mehr geschrieben.
Aber da Du bei 1und1 bist, könnte der Server es noch schaffen die Fehlermeldung auf der seriellen Konsole auszugeben.

huschi.

HMnet · Apr 15, 2009

Hallo Huschi,

danke für Deine schnellen Antworten.

Gute Idee, ich werde die serielle Konsole mal mitlaufen lassen, wenn wieder eine Mail an die Grenze kommt. Bisher hab ich natürlich immer erst geschaut, wenn er schon "abgestürzt" war.

Ich suche nachher mal die Loglifes zusammen und poste nen Auszug kurz vor dem "Tod". Vielleicht siehst Du mehr.

DANKE schon mal,
HMnet

HMnet · Apr 15, 2009

So, hier nun der Auszug aus den "gewünschten" Log-Files:

Dank Deiner Ausführungen über Bounce-Mails sind die Files schon wesentlich kleiner geworden.

Ich hatte teiweise Files, die mehrere Gigabyte groß waren.

Jeweils die letzten 3 Sekunden vor dem Crash:

messages:

Code:

Apr 13 13:09:55 hmnet qmail-queue[23338]: scan: the message(drweb.tmp.Y6EYDW) sent by [email protected] to rcpts is passed
Apr 13 13:09:55 hmnet qmail-queue-handlers[23337]: handlers_stderr: PASS
Apr 13 13:09:55 hmnet qmail-queue-handlers[23337]: recipient[4] = 'a.koppanyi@[DOMAIN].de'
Apr 13 13:09:55 hmnet qmail-queue-handlers[23337]: handlers dir = '/usr/local/psa/handlers/before-queue/recipient/a.koppanyi@[DOMAIN].de'
Apr 13 13:09:55 hmnet qmail-queue-handlers[23337]: found handlers entry = '/usr/local/psa/handlers/before-queue/recipient/a.koppanyi@[DOMAIN].de/20-drweb-3R7Grf'
Apr 13 13:09:55 hmnet qmail-queue-handlers[23337]: call_handlers: call executable = '/usr/local/psa/handlers/info/20-drweb-3R7Grf/executable'
Apr 13 13:09:55 hmnet qmail-queue[23339]: scan: the message(drweb.tmp.TR0MJR) sent by [email protected] to rcpts is passed
Apr 13 13:09:55 hmnet qmail-queue-handlers[23337]: handlers_stderr: PASS
Apr 13 13:09:55 hmnet qmail-queue-handlers[23337]: found handlers entry = '/usr/local/psa/handlers/before-queue/global/10-spf-r0OY0K'
Apr 13 13:09:55 hmnet qmail-queue-handlers[23337]: call_handlers: call executable = '/usr/local/psa/handlers/info/10-spf-r0OY0K/executable'
Apr 13 13:09:55 hmnet spf filter[23342]: Starting spf filter...
Apr 13 13:09:55 hmnet spf filter[23342]: remote IP address does not correct
Apr 13 13:09:55 hmnet spf filter[23342]: Unable to get options for spf filter
Apr 13 13:09:55 hmnet qmail-queue-handlers[23337]: call_handlers: Error during call '/usr/local/psa/handlers/info/10-spf-r0OY0K/executable' handler
Apr 13 13:09:55 hmnet qmail-queue-handlers[23337]: LOG Internal error in handler '10-spf-r0OY0K'. Skip handler.
Apr 13 13:09:55 hmnet qmail: 1239620995.143563 new msg 12596301
Apr 13 13:09:55 hmnet qmail: 1239620995.143839 info msg 12596301: bytes 3818 from <[email protected]> qp 23343 uid 110
Apr 13 13:09:55 hmnet qmail-queue-handlers[23337]: starter: submitter[23343] exited normally
Apr 13 13:09:55 hmnet qmail: 1239620995.146045 starting delivery 31710: msg 12596301 to local 145-r.henkel@[DOMAIN].de
Apr 13 13:09:55 hmnet qmail: 1239620995.146102 status: local 2/10 remote 1/20
Apr 13 13:09:55 hmnet qmail: 1239620995.146130 delivery 31709: success: did_0+2+1/qp_23337/
Apr 13 13:09:55 hmnet qmail: 1239620995.146155 status: local 1/10 remote 1/20
Apr 13 13:09:55 hmnet qmail: 1239620995.146184 starting delivery 31711: msg 12596301 to local 145-a.koppanyi@[DOMAIN].de
Apr 13 13:09:55 hmnet qmail: 1239620995.146212 status: local 2/10 remote 1/20
Apr 13 13:09:55 hmnet qmail: 1239620995.146239 end msg 12596299
Apr 13 13:09:55 hmnet qmail-local-handlers[23344]: Handlers Filter before-local for qmail started ...
Apr 13 13:09:55 hmnet qmail-local-handlers[23344]: [email protected]
Apr 13 13:09:55 hmnet qmail-local-handlers[23344]: to=r.henkel@[DOMAIN].de
Apr 13 13:09:55 hmnet qmail-local-handlers[23344]: mailbox: /var/qmail/mailnames/[DOMAIN].de/r.henkel
Apr 13 13:09:55 hmnet qmail-local-handlers[23344]: hook_dir = '/usr/local/psa/handlers/before-local'
Apr 13 13:09:55 hmnet qmail-local-handlers[23344]: recipient[3] = 'r.henkel@[DOMAIN].de'
Apr 13 13:09:55 hmnet qmail-local-handlers[23344]: handlers dir = '/usr/local/psa/handlers/before-local/recipient/r.henkel@[DOMAIN].de'
Apr 13 13:09:55 hmnet qmail-local-handlers[23344]: found handlers entry = '/usr/local/psa/handlers/before-local/recipient/r.henkel@[DOMAIN].de/10-spam-xdgPsK'
Apr 13 13:09:55 hmnet qmail-local-handlers[23344]: call_handlers: call executable = '/usr/local/psa/handlers/info/10-spam-xdgPsK/executable'
Apr 13 13:09:55 hmnet qmail-local-handlers[23345]: Handlers Filter before-local for qmail started ...
Apr 13 13:09:55 hmnet qmail-local-handlers[23345]: [email protected]
Apr 13 13:09:55 hmnet qmail-local-handlers[23345]: to=a.koppanyi@[DOMAIN].de
Apr 13 13:09:55 hmnet qmail-local-handlers[23345]: mailbox: /var/qmail/mailnames/[DOMAIN].de/a.koppanyi
Apr 13 13:09:55 hmnet qmail-local-handlers[23345]: hook_dir = '/usr/local/psa/handlers/before-local'
Apr 13 13:09:55 hmnet qmail-local-handlers[23345]: recipient[3] = 'a.koppanyi@[DOMAIN].de'
Apr 13 13:09:55 hmnet qmail-local-handlers[23345]: handlers dir = '/usr/local/psa/handlers/before-local/recipient/a.koppanyi@[DOMAIN].de'
Apr 13 13:09:55 hmnet qmail-local-handlers[23345]: found handlers entry = '/usr/local/psa/handlers/before-local/recipient/a.koppanyi@[DOMAIN].de/10-spam-JDNfjz'
Apr 13 13:09:55 hmnet qmail-local-handlers[23345]: call_handlers: call executable = '/usr/local/psa/handlers/info/10-spam-JDNfjz/executable'
Apr 13 13:09:55 hmnet spamd[1662]: spamd: got connection over /tmp/spamd_full.sock 
Apr 13 13:09:55 hmnet spamd[17050]: spamd: got connection over /tmp/spamd_full.sock 
Apr 13 13:09:55 hmnet spamd[1662]: spamd: using default config for r.henkel@[DOMAIN].de: /var/qmail/mailnames/[DOMAIN].de/r.henkel/.spamassassin/user_prefs 
Apr 13 13:09:55 hmnet spamd[17050]: spamd: using default config for a.koppanyi@[DOMAIN].de: /var/qmail/mailnames/[DOMAIN].de/a.koppanyi/.spamassassin/user_prefs 
Apr 13 13:09:55 hmnet spamd[17050]: spamd: processing message <000d01c9bc28$5bbaeae0$6400a8c0@idealismx045> for a.koppanyi@[DOMAIN].de:110 
Apr 13 13:09:55 hmnet spamd[1662]: spamd: processing message <000d01c9bc28$5bbaeae0$6400a8c0@idealismx045> for r.henkel@[DOMAIN].de:110 
Apr 13 13:09:55 hmnet qmail-queue-handlers[23351]: Handlers Filter before-queue for qmail started ...
Apr 13 13:09:56 hmnet qmail-queue-handlers[23328]: [email protected]
Apr 13 13:09:56 hmnet qmail-queue-handlers[23328]: to=iamjustsendingthisleter@[DOMAIN].de
Apr 13 13:09:56 hmnet qmail-queue-handlers[23328]: hook_dir = '/usr/local/psa/handlers/before-queue'
Apr 13 13:09:56 hmnet qmail-queue-handlers[23328]: recipient[3] = 'iamjustsendingthisleter@[DOMAIN].de'
Apr 13 13:09:56 hmnet qmail-queue-handlers[23328]: handlers dir = '/usr/local/psa/handlers/before-queue/recipient/iamjustsendingthisleter@[DOMAIN].de'
Apr 13 13:09:56 hmnet qmail-queue-handlers[23328]: found handlers entry = '/usr/local/psa/handlers/before-queue/global/10-spf-r0OY0K'
Apr 13 13:09:56 hmnet qmail-queue-handlers[23328]: call_handlers: call executable = '/usr/local/psa/handlers/info/10-spf-r0OY0K/executable'
Apr 13 13:09:56 hmnet spf filter[23357]: Starting spf filter...
Apr 13 13:09:56 hmnet spf filter[23357]: Error code: (2) Could not find a valid SPF record
Apr 13 13:09:56 hmnet spf filter[23357]: Failed to query MAIL-FROM: No DNS data for 'cg-test.com'.
Apr 13 13:09:56 hmnet spf filter[23357]: SPF result: none
Apr 13 13:09:56 hmnet spf filter[23357]: SPF status: PASS
Apr 13 13:09:56 hmnet qmail-queue-handlers[23328]: handlers_stderr: PASS
Apr 13 13:09:56 hmnet qmail-queue-handlers[23328]: starter: submitter[23358] exited normally
Apr 13 13:09:56 hmnet qmail: 1239620996.316119 new msg 12596299
Apr 13 13:09:56 hmnet qmail: 1239620996.316187 info msg 12596299: bytes 1901 from <[email protected]> qp 23358 uid 2020
Apr 13 13:09:56 hmnet qmail: 1239620996.320364 starting delivery 31712: msg 12596299 to local 333-iamjustsendingthisleter@[DOMAIN].de
Apr 13 13:09:56 hmnet qmail: 1239620996.320537 status: local 3/10 remote 1/20
Apr 13 13:09:56 hmnet qmail-local-handlers[23359]: Handlers Filter before-local for qmail started ...
Apr 13 13:09:56 hmnet qmail-local-handlers[23359]: [email protected]
Apr 13 13:09:56 hmnet qmail-local-handlers[23359]: to=iamjustsendingthisleter@[DOMAIN].de
Apr 13 13:09:56 hmnet qmail-local-handlers[23359]: mailbox: /var/qmail/mailnames/[DOMAIN].de
Apr 13 13:09:56 hmnet qmail-local-handlers[23359]: hook_dir = '/usr/local/psa/handlers/before-local'
Apr 13 13:09:56 hmnet qmail-local-handlers[23359]: recipient[3] = 'iamjustsendingthisleter@[DOMAIN].de'
Apr 13 13:09:56 hmnet qmail-local-handlers[23359]: handlers dir = '/usr/local/psa/handlers/before-local/recipient/iamjustsendingthisleter@[DOMAIN].de'
Apr 13 13:09:56 hmnet qmail-local-handlers[23359]: found handlers entry = '/usr/local/psa/handlers/before-local/global/10-dd52-domainkeys-h0SZ4f'
Apr 13 13:09:56 hmnet qmail-local-handlers[23359]: call_handlers: call executable = '/usr/local/psa/handlers/info/10-dd52-domainkeys-h0SZ4f/executable'
Apr 13 13:09:56 hmnet dk_check[23360]: DK_STAT_NOSIG: No signature available in message
Apr 13 13:09:56 hmnet qmail-local-handlers[23359]: handlers_stderr: PASS
Apr 13 13:09:56 hmnet qmail-queue-handlers[23361]: Handlers Filter before-queue for qmail started ...
Apr 13 13:09:56 hmnet qmail-queue-handlers[23361]: [email protected]
Apr 13 13:09:56 hmnet qmail-queue-handlers[23361]: to=info@[DOMAIN].de
Apr 13 13:09:56 hmnet qmail-queue-handlers[23361]: hook_dir = '/usr/local/psa/handlers/before-queue'
Apr 13 13:09:56 hmnet qmail-queue-handlers[23361]: recipient[3] = 'info@[DOMAIN].de'
Apr 13 13:09:56 hmnet qmail-queue-handlers[23361]: handlers dir = '/usr/local/psa/handlers/before-queue/recipient/info@[DOMAIN].de'
Apr 13 13:09:56 hmnet qmail-queue-handlers[23361]: found handlers entry = '/usr/local/psa/handlers/before-queue/recipient/info@[DOMAIN].de/20-drweb-Otf3Yz'
Apr 13 13:09:56 hmnet qmail-queue-handlers[23361]: call_handlers: call executable = '/usr/local/psa/handlers/info/20-drweb-Otf3Yz/executable'
Apr 13 13:09:56 hmnet qmail-queue-handlers[23351]: [email protected]
Apr 13 13:09:56 hmnet qmail-queue-handlers[23351]: to=k.landgraf@[DOMAIN].de
Apr 13 13:09:56 hmnet qmail-queue-handlers[23351]: hook_dir = '/usr/local/psa/handlers/before-queue'
Apr 13 13:09:56 hmnet qmail-queue-handlers[23351]: recipient[3] = 'k.landgraf@[DOMAIN].de'
Apr 13 13:09:56 hmnet qmail-queue-handlers[23351]: handlers dir = '/usr/local/psa/handlers/before-queue/recipient/k.landgraf@[DOMAIN].de'
Apr 13 13:09:56 hmnet qmail-queue-handlers[23351]: found handlers entry = '/usr/local/psa/handlers/before-queue/recipient/k.landgraf@[DOMAIN].de/20-drweb-9dLw3R'
Apr 13 13:09:56 hmnet qmail-queue-handlers[23351]: call_handlers: call executable = '/usr/local/psa/handlers/info/20-drweb-9dLw3R/executable'
Apr 13 13:09:56 hmnet qmail-queue[23362]: scan: the message(drweb.tmp.jE5KKh) sent by [email protected] to info@[DOMAIN].de is passed
Apr 13 13:09:56 hmnet qmail-queue-handlers[23361]: handlers_stderr: PASS
Apr 13 13:09:56 hmnet qmail-queue-handlers[23361]: found handlers entry = '/usr/local/psa/handlers/before-queue/global/10-spf-r0OY0K'
Apr 13 13:09:56 hmnet qmail-queue-handlers[23361]: call_handlers: call executable = '/usr/local/psa/handlers/info/10-spf-r0OY0K/executable'
Apr 13 13:09:56 hmnet spf filter[23364]: Starting spf filter...
Apr 13 13:09:56 hmnet spf filter[23364]: remote IP address does not correct
Apr 13 13:09:56 hmnet spf filter[23364]: Unable to get options for spf filter
Apr 13 13:09:56 hmnet qmail-queue-handlers[23361]: call_handlers: Error during call '/usr/local/psa/handlers/info/10-spf-r0OY0K/executable' handler
Apr 13 13:09:56 hmnet qmail-queue-handlers[23361]: LOG Internal error in handler '10-spf-r0OY0K'. Skip handler.
Apr 13 13:09:56 hmnet qmail: 1239620996.443759 new msg 12596302
Apr 13 13:09:56 hmnet qmail: 1239620996.443932 info msg 12596302: bytes 2055 from <[email protected]> qp 23365 uid 110
Apr 13 13:09:56 hmnet qmail-queue-handlers[23361]: starter: submitter[23365] exited normally
Apr 13 13:09:56 hmnet qmail: 1239620996.447281 starting delivery 31713: msg 12596302 to local 333-info@[DOMAIN].de
Apr 13 13:09:56 hmnet qmail: 1239620996.447340 status: local 4/10 remote 1/20
Apr 13 13:09:56 hmnet qmail: 1239620996.447371 delivery 31712: success: did_0+1+0/qp_23361/
Apr 13 13:09:56 hmnet qmail: 1239620996.447400 status: local 3/10 remote 1/20
Apr 13 13:09:56 hmnet qmail: 1239620996.447424 end msg 12596299
Apr 13 13:09:56 hmnet qmail-local-handlers[23366]: Handlers Filter before-local for qmail started ...
Apr 13 13:09:56 hmnet qmail-local-handlers[23366]: [email protected]
Apr 13 13:09:56 hmnet qmail-local-handlers[23366]: to=info@[DOMAIN].de
Apr 13 13:09:56 hmnet qmail-local-handlers[23366]: mailbox: /var/qmail/mailnames/[DOMAIN].de/info
Apr 13 13:09:56 hmnet qmail-local-handlers[23366]: hook_dir = '/usr/local/psa/handlers/before-local'
Apr 13 13:09:56 hmnet qmail-local-handlers[23366]: recipient[3] = 'info@[DOMAIN].de'
Apr 13 13:09:56 hmnet qmail-local-handlers[23366]: handlers dir = '/usr/local/psa/handlers/before-local/recipient/info@[DOMAIN].de'
Apr 13 13:09:56 hmnet qmail-local-handlers[23366]: found handlers entry = '/usr/local/psa/handlers/before-local/recipient/info@[DOMAIN].de/10-spam-kSNW9m'
Apr 13 13:09:56 hmnet qmail-local-handlers[23366]: call_handlers: call executable = '/usr/local/psa/handlers/info/10-spam-kSNW9m/executable'
Apr 13 13:09:56 hmnet qmail-queue[23363]: scan: the message(drweb.tmp.kCC2Rk) sent by [email protected] to k.landgraf@[DOMAIN].de is passed
Apr 13 13:09:56 hmnet qmail-queue-handlers[23351]: handlers_stderr: PASS
Apr 13 13:09:56 hmnet qmail-queue-handlers[23351]: found handlers entry = '/usr/local/psa/handlers/before-queue/global/10-spf-r0OY0K'
Apr 13 13:09:56 hmnet qmail-queue-handlers[23351]: call_handlers: call executable = '/usr/local/psa/handlers/info/10-spf-r0OY0K/executable'
Apr 13 13:09:56 hmnet spf filter[23369]: Starting spf filter...
Apr 13 13:09:56 hmnet spf filter[23369]: Error code: (2) Could not find a valid SPF record
Apr 13 13:09:56 hmnet spf filter[23369]: Failed to query MAIL-FROM: No DNS data for 'defensesale.com'.
Apr 13 13:09:56 hmnet spf filter[23369]: SPF result: none
Apr 13 13:09:56 hmnet spf filter[23369]: SPF status: PASS
Apr 13 13:09:56 hmnet qmail-queue-handlers[23351]: handlers_stderr: PASS
Apr 13 13:09:56 hmnet qmail: 1239620996.498333 new msg 12596299
Apr 13 13:09:56 hmnet qmail: 1239620996.498397 info msg 12596299: bytes 1564 from <[email protected]> qp 23370 uid 2020
Apr 13 13:09:56 hmnet qmail-queue-handlers[23351]: starter: submitter[23370] exited normally
Apr 13 13:09:56 hmnet qmail: 1239620996.502223 starting delivery 31714: msg 12596299 to local 145-k.landgraf@[DOMAIN].de
Apr 13 13:09:56 hmnet qmail: 1239620996.502281 status: local 4/10 remote 1/20
Apr 13 13:09:56 hmnet qmail-local-handlers[23371]: Handlers Filter before-local for qmail started ...
Apr 13 13:09:56 hmnet qmail-local-handlers[23371]: [email protected]
Apr 13 13:09:56 hmnet qmail-local-handlers[23371]: to=k.landgraf@[DOMAIN].de
Apr 13 13:09:56 hmnet qmail-local-handlers[23371]: mailbox: /var/qmail/mailnames/[DOMAIN].de/k.landgraf
Apr 13 13:09:56 hmnet qmail-local-handlers[23371]: hook_dir = '/usr/local/psa/handlers/before-local'
Apr 13 13:09:56 hmnet qmail-local-handlers[23371]: recipient[3] = 'k.landgraf@[DOMAIN].de'
Apr 13 13:09:56 hmnet qmail-local-handlers[23371]: handlers dir = '/usr/local/psa/handlers/before-local/recipient/k.landgraf@[DOMAIN].de'
Apr 13 13:09:56 hmnet qmail-local-handlers[23371]: found handlers entry = '/usr/local/psa/handlers/before-local/recipient/k.landgraf@[DOMAIN].de/10-spam-JGraJJ'
Apr 13 13:09:56 hmnet qmail-local-handlers[23371]: call_handlers: call executable = '/usr/local/psa/handlers/info/10-spam-JGraJJ/executable'
Apr 13 13:09:56 hmnet spamd[1662]: spamd: identified spam (14.0/7.0) for r.henkel@[DOMAIN].de:110 in 1.5 seconds, 3818 bytes. 
Apr 13 13:09:56 hmnet spamd[1662]: spamd: result: Y 13 - BAYES_50,HTML_50_60,HTML_MESSAGE,RCVD_IN_XBL,UNPARSEABLE_RELAY,URIBL_AB_SURBL,URIBL_SBL,URIBL_SC_SURBL scantime=1.5,size=3818,user=r.henkel@[DOMAIN].de,uid=110,required_score=7.0,rhost=localhost,raddr=127.0.0.1,rport=/tmp/spamd_full.sock,mid=<000d01c9bc28$5bbaeae0$6400a8c0@idealismx045>,bayes=0.520994360939399,autolearn=no 
Apr 13 13:09:56 hmnet qmail-local-handlers[23344]: handlers_stderr: PASS
Apr 13 13:09:56 hmnet qmail-local-handlers[23344]: found handlers entry = '/usr/local/psa/handlers/before-local/global/10-dd52-domainkeys-h0SZ4f'
Apr 13 13:09:56 hmnet qmail-local-handlers[23344]: call_handlers: call executable = '/usr/local/psa/handlers/info/10-dd52-domainkeys-h0SZ4f/executable'
Apr 13 13:09:56 hmnet dk_check[23376]: DK_STAT_NOSIG: No signature available in message
Apr 13 13:09:56 hmnet qmail-local-handlers[23344]: handlers_stderr: PASS
Apr 13 13:09:56 hmnet spamd[17050]: spamd: identified spam (11.1/7.0) for a.koppanyi@[DOMAIN].de:110 in 1.5 seconds, 3818 bytes. 
Apr 13 13:09:56 hmnet spamd[17050]: spamd: result: Y 11 - HTML_MESSAGE,RCVD_IN_XBL,UNPARSEABLE_RELAY,URIBL_AB_SURBL,URIBL_SBL,URIBL_SC_SURBL scantime=1.5,size=3818,user=a.koppanyi@[DOMAIN].de,uid=110,required_score=7.0,rhost=localhost,raddr=127.0.0.1,rport=/tmp/spamd_full.sock,mid=<000d01c9bc28$5bbaeae0$6400a8c0@idealismx045>,autolearn=no 
Apr 13 13:09:56 hmnet qmail-local-handlers[23345]: handlers_stderr: PASS
Apr 13 13:09:56 hmnet qmail-local-handlers[23345]: found handlers entry = '/usr/local/psa/handlers/before-local/global/10-dd52-domainkeys-h0SZ4f'
Apr 13 13:09:56 hmnet qmail-local-handlers[23345]: call_handlers: call executable = '/usr/local/psa/handlers/info/10-dd52-domainkeys-h0SZ4f/executable'
Apr 13 13:09:56 hmnet dk_check[23379]: DK_STAT_NOSIG: No signature available in message
Apr 13 13:09:56 hmnet qmail-local-handlers[23345]: handlers_stderr: PASS
Apr 13 13:09:56 hmnet qmail: 1239620996.692085 delivery 31710: success: did_0+0+2/
Apr 13 13:09:56 hmnet qmail: 1239620996.692157 status: local 3/10 remote 1/20
Apr 13 13:09:56 hmnet qmail: 1239620996.698900 delivery 31711: success: did_0+0+2/
Apr 13 13:09:56 hmnet qmail: 1239620996.698951 status: local 2/10 remote 1/20
Apr 13 13:09:56 hmnet qmail: 1239620996.698965 end msg 12596301
Apr 13 13:09:56 hmnet spamd[4244]: prefork: child states: BB 
Apr 13 13:09:56 hmnet spamd[4244]: spamd: server successfully spawned child process, pid 23382 
Apr 13 13:09:56 hmnet spamd[1662]: spamd: got connection over /tmp/spamd_full.sock 
Apr 13 13:09:56 hmnet spamd[1662]: spamd: using default config for info@[DOMAIN].de: /var/qmail/mailnames/[DOMAIN].de/info/.spamassassin/user_prefs 
Apr 13 13:09:56 hmnet spamd[4244]: prefork: child states: BBB 
Apr 13 13:09:56 hmnet spamd[4244]: spamd: server successfully spawned child process, pid 23383 
Apr 13 13:09:56 hmnet spamd[23382]: spamd: got connection over /tmp/spamd_full.sock 
Apr 13 13:09:56 hmnet spamd[4244]: prefork: child states: BIBI 
Apr 13 13:09:56 hmnet spamd[1662]: spamd: processing message <000d01c9bc26$89b4b3b0$6400a8c0@descend674> for info@[DOMAIN].de:110 
Apr 13 13:09:56 hmnet spamd[23382]: spamd: using default config for k.landgraf@[DOMAIN].de: /var/qmail/mailnames/[DOMAIN].de/k.landgraf/.spamassassin/user_prefs 
Apr 13 13:09:56 hmnet spamd[23382]: spamd: processing message <001101cc3169$8f19c6a0$003c789c@r> for k.landgraf@[DOMAIN].de:110 
Apr 13 13:09:57 hmnet relaylock: /var/qmail/bin/relaylock: mail from 59.93.125.56:2467 (not defined)

maillog:

Code:

Apr 13 13:09:59 hmnet qmail-queue-handlers[23418]: [email protected]
Apr 13 13:09:59 hmnet qmail-queue-handlers[23418]: to=bleichbritta@[DOMAIN].de
Apr 13 13:09:59 hmnet qmail-queue-handlers[23418]: hook_dir = '/usr/local/psa/handlers/before-queue'
Apr 13 13:09:59 hmnet qmail-queue-handlers[23418]: recipient[3] = 'bleichbritta@[DOMAIN].de'
Apr 13 13:09:59 hmnet qmail-queue-handlers[23418]: handlers dir = '/usr/local/psa/handlers/before-queue/recipient/bleichbritta@[DOMAIN].de'
Apr 13 13:09:59 hmnet qmail-queue-handlers[23418]: found handlers entry = '/usr/local/psa/handlers/before-queue/global/10-spf-r0OY0K'
Apr 13 13:09:59 hmnet qmail-queue-handlers[23418]: call_handlers: call executable = '/usr/local/psa/handlers/info/10-spf-r0OY0K/executable'
Apr 13 13:09:59 hmnet spf filter[23426]: Starting spf filter...
Apr 13 13:09:59 hmnet spf filter[23426]: Error code: (2) Could not find a valid SPF record
Apr 13 13:09:59 hmnet spf filter[23426]: Failed to query MAIL-FROM: No DNS data for 'blendoncom.com'.
Apr 13 13:09:59 hmnet spf filter[23426]: SPF result: none
Apr 13 13:09:59 hmnet spf filter[23426]: SPF status: PASS
Apr 13 13:09:59 hmnet qmail-queue-handlers[23418]: handlers_stderr: PASS
Apr 13 13:09:59 hmnet qmail-queue-handlers[23418]: starter: submitter[23427] exited normally
Apr 13 13:09:59 hmnet qmail: 1239620999.968079 new msg 12596299
Apr 13 13:09:59 hmnet qmail: 1239620999.968137 info msg 12596299: bytes 1057 from <[email protected]> qp 23427 uid 2020
Apr 13 13:09:59 hmnet qmail: 1239620999.972644 starting delivery 31715: msg 12596299 to local 333-bleichbritta@[DOMAIN].de
Apr 13 13:09:59 hmnet qmail: 1239620999.972704 status: local 1/10 remote 1/20
Apr 13 13:09:59 hmnet qmail-local-handlers[23428]: Handlers Filter before-local for qmail started ...
Apr 13 13:09:59 hmnet qmail-local-handlers[23428]: [email protected]
Apr 13 13:09:59 hmnet qmail-local-handlers[23428]: to=bleichbritta@[DOMAIN].de
Apr 13 13:09:59 hmnet qmail-local-handlers[23428]: mailbox: /var/qmail/mailnames/[DOMAIN].de
Apr 13 13:09:59 hmnet qmail-local-handlers[23428]: hook_dir = '/usr/local/psa/handlers/before-local'
Apr 13 13:09:59 hmnet qmail-local-handlers[23428]: recipient[3] = 'bleichbritta@[DOMAIN].de'
Apr 13 13:09:59 hmnet qmail-local-handlers[23428]: handlers dir = '/usr/local/psa/handlers/before-local/recipient/bleichbritta@[DOMAIN].de'
Apr 13 13:09:59 hmnet qmail-local-handlers[23428]: found handlers entry = '/usr/local/psa/handlers/before-local/global/10-dd52-domainkeys-h0SZ4f'
Apr 13 13:09:59 hmnet qmail-local-handlers[23428]: call_handlers: call executable = '/usr/local/psa/handlers/info/10-dd52-domainkeys-h0SZ4f/executable'
Apr 13 13:09:59 hmnet dk_check[23429]: DK_STAT_NOSIG: No signature available in message
Apr 13 13:09:59 hmnet qmail-local-handlers[23428]: handlers_stderr: PASS
Apr 13 13:09:59 hmnet qmail-queue-handlers[23430]: Handlers Filter before-queue for qmail started ...
Apr 13 13:09:59 hmnet qmail-queue-handlers[23430]: [email protected]
Apr 13 13:09:59 hmnet qmail-queue-handlers[23430]: to=info@[DOMAIN].de
Apr 13 13:09:59 hmnet qmail-queue-handlers[23430]: hook_dir = '/usr/local/psa/handlers/before-queue'
Apr 13 13:09:59 hmnet qmail-queue-handlers[23430]: recipient[3] = 'info@[DOMAIN].de'
Apr 13 13:09:59 hmnet qmail-queue-handlers[23430]: handlers dir = '/usr/local/psa/handlers/before-queue/recipient/info@[DOMAIN].de'
Apr 13 13:09:59 hmnet qmail-queue-handlers[23430]: found handlers entry = '/usr/local/psa/handlers/before-queue/recipient/info@[DOMAIN].de/20-drweb-Otf3Yz'
Apr 13 13:09:59 hmnet qmail-queue-handlers[23430]: call_handlers: call executable = '/usr/local/psa/handlers/info/20-drweb-Otf3Yz/executable'
Apr 13 13:10:00 hmnet qmail-queue[23431]: scan: the message(drweb.tmp.CJmMjZ) sent by [email protected] to info@[DOMAIN].de is passed
Apr 13 13:10:00 hmnet qmail-queue-handlers[23430]: handlers_stderr: PASS
Apr 13 13:10:00 hmnet qmail-queue-handlers[23430]: found handlers entry = '/usr/local/psa/handlers/before-queue/global/10-spf-r0OY0K'
Apr 13 13:10:00 hmnet qmail-queue-handlers[23430]: call_handlers: call executable = '/usr/local/psa/handlers/info/10-spf-r0OY0K/executable'
Apr 13 13:10:00 hmnet spf filter[23432]: Starting spf filter...
Apr 13 13:10:00 hmnet spf filter[23432]: remote IP address does not correct
Apr 13 13:10:00 hmnet spf filter[23432]: Unable to get options for spf filter
Apr 13 13:10:00 hmnet qmail-queue-handlers[23430]: call_handlers: Error during call '/usr/local/psa/handlers/info/10-spf-r0OY0K/executable' handler
Apr 13 13:10:00 hmnet qmail-queue-handlers[23430]: LOG Internal error in handler '10-spf-r0OY0K'. Skip handler.
Apr 13 13:10:00 hmnet qmail-queue-handlers[23430]: starter: submitter[23433] exited normally
Apr 13 13:10:00 hmnet qmail: 1239621000.079942 new msg 12596301
Apr 13 13:10:00 hmnet qmail: 1239621000.080005 info msg 12596301: bytes 1200 from <[email protected]> qp 23433 uid 110
Apr 13 13:10:00 hmnet qmail: 1239621000.085085 starting delivery 31716: msg 12596301 to local 333-info@[DOMAIN].de
Apr 13 13:10:00 hmnet qmail: 1239621000.085136 status: local 2/10 remote 1/20
Apr 13 13:10:00 hmnet qmail: 1239621000.085163 delivery 31715: success: did_0+1+0/qp_23430/
Apr 13 13:10:00 hmnet qmail: 1239621000.085189 status: local 1/10 remote 1/20
Apr 13 13:10:00 hmnet qmail: 1239621000.085214 end msg 12596299
Apr 13 13:10:00 hmnet qmail-local-handlers[23434]: Handlers Filter before-local for qmail started ...
Apr 13 13:10:00 hmnet qmail-local-handlers[23434]: [email protected]
Apr 13 13:10:00 hmnet qmail-local-handlers[23434]: to=info@[DOMAIN].de
Apr 13 13:10:00 hmnet qmail-local-handlers[23434]: mailbox: /var/qmail/mailnames/[DOMAIN].de/info
Apr 13 13:10:00 hmnet qmail-local-handlers[23434]: hook_dir = '/usr/local/psa/handlers/before-local'
Apr 13 13:10:00 hmnet qmail-local-handlers[23434]: recipient[3] = 'info@[DOMAIN].de'
Apr 13 13:10:00 hmnet qmail-local-handlers[23434]: handlers dir = '/usr/local/psa/handlers/before-local/recipient/info@[DOMAIN].de'
Apr 13 13:10:00 hmnet qmail-local-handlers[23434]: found handlers entry = '/usr/local/psa/handlers/before-local/recipient/info@[DOMAIN].de/10-spam-kSNW9m'
Apr 13 13:10:00 hmnet qmail-local-handlers[23434]: call_handlers: call executable = '/usr/local/psa/handlers/info/10-spam-kSNW9m/executable'
Apr 13 13:10:00 hmnet spamd[1662]: spamd: got connection over /tmp/spamd_full.sock 
Apr 13 13:10:00 hmnet spamd[1662]: spamd: using default config for info@[DOMAIN].de: /var/qmail/mailnames/[DOMAIN].de/info/.spamassassin/user_prefs 
Apr 13 13:10:00 hmnet spamd[1662]: spamd: processing message <01c9bc56$7b620300$387d5d3b@qybvyqjlvp> for info@[DOMAIN].de:110 
Apr 13 13:10:00 hmnet relaylock: /var/qmail/bin/relaylock: mail from 78.175.72.30:4530 (not defined)
Apr 13 13:10:00 hmnet spf filter[23403]: Error code: (2) Could not find a valid SPF record
Apr 13 13:10:00 hmnet spf filter[23403]: Failed to query MAIL-FROM: No DNS data for 'dotw.com'.
Apr 13 13:10:00 hmnet spf filter[23403]: SPF result: none
Apr 13 13:10:00 hmnet spf filter[23403]: SPF status: PASS
Apr 13 13:10:00 hmnet qmail-queue-handlers[23399]: handlers_stderr: PASS
Apr 13 13:10:00 hmnet qmail-queue-handlers[23399]: starter: submitter[23442] exited normally
Apr 13 13:10:00 hmnet qmail: 1239621000.701294 new msg 12596299
Apr 13 13:10:00 hmnet qmail: 1239621000.701351 info msg 12596299: bytes 1520 from <[email protected]> qp 23442 uid 2020
Apr 13 13:10:00 hmnet qmail: 1239621000.706038 starting delivery 31717: msg 12596299 to local 189-d.weiler@[DOMAIN].de
Apr 13 13:10:00 hmnet qmail: 1239621000.706100 status: local 2/10 remote 1/20
Apr 13 13:10:00 hmnet qmail-local-handlers[23443]: Handlers Filter before-local for qmail started ...
Apr 13 13:10:00 hmnet qmail-local-handlers[23443]: [email protected]
Apr 13 13:10:00 hmnet qmail-local-handlers[23443]: to=d.weiler@[DOMAIN].de
Apr 13 13:10:00 hmnet qmail-local-handlers[23443]: mailbox: /var/qmail/mailnames/[DOMAIN].de/d.weiler
Apr 13 13:10:00 hmnet qmail-local-handlers[23443]: hook_dir = '/usr/local/psa/handlers/before-local'
Apr 13 13:10:00 hmnet qmail-local-handlers[23443]: recipient[3] = 'd.weiler@[DOMAIN].de'
Apr 13 13:10:00 hmnet qmail-local-handlers[23443]: handlers dir = '/usr/local/psa/handlers/before-local/recipient/d.weiler@[DOMAIN].de'
Apr 13 13:10:00 hmnet qmail-local-handlers[23443]: found handlers entry = '/usr/local/psa/handlers/before-local/recipient/d.weiler@[DOMAIN].de/10-spam-QpWvLA'
Apr 13 13:10:00 hmnet qmail-local-handlers[23443]: call_handlers: call executable = '/usr/local/psa/handlers/info/10-spam-QpWvLA/executable'
Apr 13 13:10:00 hmnet spamd[17050]: spamd: got connection over /tmp/spamd_full.sock 
Apr 13 13:10:00 hmnet spamd[17050]: spamd: using default config for d.weiler@[DOMAIN].de: /var/qmail/mailnames/[DOMAIN].de/d.weiler/.spamassassin/user_prefs 
Apr 13 13:10:00 hmnet spamd[17050]: spamd: processing message <000e01c9bc4d$f254fed0$0090910c@ict2> for d.weiler@[DOMAIN].de:110 
Apr 13 13:10:01 hmnet spamd[1662]: spamd: identified spam (9.4/6.5) for info@[DOMAIN].de:110 in 1.5 seconds, 1200 bytes. 
Apr 13 13:10:01 hmnet spamd[1662]: spamd: result: Y 9 - BAYES_99,RCVD_IN_SORBS_DUL,RCVD_IN_XBL scantime=1.5,size=1200,user=info@[DOMAIN].de,uid=110,required_score=6.5,rhost=localhost,raddr=127.0.0.1,rport=/tmp/spamd_full.sock,mid=<01c9bc56$7b620300$387d5d3b@qybvyqjlvp>,bayes=0.994991286953777,autolearn=no 
Apr 13 13:10:01 hmnet spamd[4244]: prefork: child states: IB 
Apr 13 13:10:01 hmnet qmail-local-handlers[23434]: handlers_stderr: PASS
Apr 13 13:10:01 hmnet qmail-local-handlers[23434]: found handlers entry = '/usr/local/psa/handlers/before-local/global/10-dd52-domainkeys-h0SZ4f'
Apr 13 13:10:01 hmnet qmail-local-handlers[23434]: call_handlers: call executable = '/usr/local/psa/handlers/info/10-dd52-domainkeys-h0SZ4f/executable'
Apr 13 13:10:01 hmnet dk_check[23454]: DK_STAT_NOSIG: No signature available in message
Apr 13 13:10:01 hmnet qmail-local-handlers[23434]: handlers_stderr: PASS
Apr 13 13:10:01 hmnet qmail: 1239621001.690558 delivery 31716: success: did_0+0+2/
Apr 13 13:10:01 hmnet qmail: 1239621001.690631 status: local 1/10 remote 1/20
Apr 13 13:10:01 hmnet qmail: 1239621001.690659 end msg 12596301
Apr 13 13:10:01 hmnet relaylock: /var/qmail/bin/relaylock: mail from 59.87.195.210:3067 (59x87x195x210.ap59.ftth.ucom.ne.jp)

Bis dann,
HMnet

Huschi · Apr 16, 2009

Ist es wirklich so, dass das Maillog noch 4 Sekunden länger geschrieben wird als die Messages?
Und in der Messages folgt dann nach diesen Zeilen dann der Boot-Prozess?
Wenn zu beiden "Ja", dann schmiert der ja wirklich ohne Gnaden ab...
Evtl. ist auch ein Hardware-Problem (RAM oder HD) nicht auszuschließen.
Sowas muss man aber immer belegen können.

Das nächste Mal im Rescue-System booten und einen Ram-Check durchlaufen lassen.

huschi.

HMnet · Apr 16, 2009

Hallo!

Also, erst nochmal VIELEN DANK für Deine Hilfe.

Ja, genau, das Maillog wird genau 4 Sekunden länger geschrieben.

Die messages sieht beim "Übergang" so aus:

Code:

Apr 13 13:09:56 hmnet spamd[4244]: prefork: child states: BB 
Apr 13 13:09:56 hmnet spamd[4244]: spamd: server successfully spawned child process, pid 23382 
Apr 13 13:09:56 hmnet spamd[1662]: spamd: got connection over /tmp/spamd_full.sock 
Apr 13 13:09:56 hmnet spamd[1662]: spamd: using default config for info@: /var/qmail/mailnames//info/.spamassassin/user_prefs 
Apr 13 13:09:56 hmnet spamd[4244]: prefork: child states: BBB 
Apr 13 13:09:56 hmnet spamd[4244]: spamd: server successfully spawned child process, pid 23383 
Apr 13 13:09:56 hmnet spamd[23382]: spamd: got connection over /tmp/spamd_full.sock 
Apr 13 13:09:56 hmnet spamd[4244]: prefork: child states: BIBI 
Apr 13 13:09:56 hmnet spamd[1662]: spamd: processing message <000d01c9bc26$89b4b3b0$6400a8c0@descend674> for [email protected]:110 
Apr 13 13:09:56 hmnet spamd[23382]: spamd: using default config for : /var/qmail/mailnames//.spamassassin/user_prefs 
Apr 13 13:09:56 hmnet spamd[23382]: spamd: processing message <001101cc3169$8f19c6a0$003c789c@r> for :110 
Apr 13 13:09:57 hmnet relaylock: /var/qmail/bin/relaylock: mail from 59.93.125.56:2467 (not defined)
Apr 13 14:09:59 hmnet syslog-ng[4114]: syslog-ng version 1.6.11 starting
Apr 13 14:09:59 hmnet relaylock: /var/qmail/bin/relaylock: mail from 221.221.186.141:4299 (not defined)
Apr 13 14:09:59 hmnet relaylock: /var/qmail/bin/relaylock: mail from 124.121.20.237:3613 (ppp-124-121-20-237.revip2.asianet.co.th)
Apr 13 14:09:59 hmnet rcpowersaved: s2ram does not know your machine. See 's2ram -i' for details. (127)
Apr 13 14:09:59 hmnet rcpowersaved: Use SUSPEND2RAM_FORCE=yes to override this detection.
Apr 13 14:09:59 hmnet relaylock: /var/qmail/bin/relaylock: mail from 85.97.95.64:3871 (dsl.dynamic85979564.ttnet.net.tr)
Apr 13 14:09:59 hmnet relaylock: /var/qmail/bin/relaylock: mail from 92.80.171.132:63874 (not defined)
Apr 13 14:10:00 hmnet sshd[4253]: Server listening on :: port xxxx.
Apr 13 14:10:00 hmnet qmail: 1239624600.044180 status: local 0/10 remote 0/20
Apr 13 14:10:00 hmnet relaylock: /var/qmail/bin/relaylock: mail from 68.164.154.66:58841 (h-68-164-154-66-static.chcgilgb.covad.net)
Apr 13 14:10:00 hmnet relaylock: /var/qmail/bin/relaylock: mail from 88.108.57.123:64957 (88-108-57-123.dynamic.dsl.as9105.com)
Apr 13 14:10:00 hmnet relaylock: /var/qmail/bin/relaylock: mail from 94.45.174.181:19647 (not defined)
Apr 13 14:10:00 hmnet relaylock: /var/qmail/bin/relaylock: mail from 83.23.44.75:3118 (dbs75.neoplus.adsl.tpnet.pl)
Apr 13 14:10:00 hmnet qmail: 1239624600.194577 starting delivery 1: msg 12639234 to local 424-@
Apr 13 14:10:00 hmnet qmail: 1239624600.194633 status: local 1/10 remote 0/20
Apr 13 14:10:00 hmnet qmail-queue-handlers[4255]: Handlers Filter before-queue for qmail started ...
Apr 13 14:10:00 hmnet qmail-queue-handlers[4256]: Handlers Filter before-queue for qmail started ...

Also heute Abend, "fliegt" um ca. 22.00 Uhr wieder eine Mail aus der Queue, da lasse ich die Remote-Console und ein top per SSH mal mitlaufen.

Anschließend boote ich mal im Rescue-Modus. Kannst Du mir schnell helfen, wie des mit dem RAM-Check geht?

HMnet

HMnet · Apr 16, 2009

So, der "kontrollierte Absturz" ist vorüber, leider keine Ausgaben an der seriellen Konsole. Ab dem Zeitpunkt, als keine Logfiles mehr geschrieben werden, steigt die Serverload horrent an. Ich hatte ja top laufen und habe gesehen, logfiles blieben leer und die Serverload steigt kontinuierlich immer weiter, so bis auf 135.0!!! Leider konnte ich dann keine Befehle mehr eingeben. Habe nur gesehen, dass ganz oben in der "top-Liste" "mysqld" und drunter ein "http2-prefork" stand und die blieben da mit 100% stehen.

Es sah so aus, als ob der Server an mysql-abfragen gestorben wäre. Aber was hat das mit meiner Mail in der Queue zu tun? Und werden die Abfragen irgendwo mitgeloggt?

Komischerweise ist meine Mail, die an das queuelifetime gestoßen ist, nach dem Neustart immernoch in der Queue, nun schon über eine Stunde überfällig. Echt seltsam das Ganze!

HMnet

Huschi · Apr 17, 2009

Dann ist ein Hardware-Problem doch eher ausgeschlossen.
Die Frage ist, ob ein "kill -hup [mysql-PID]" eine Rettung gewesen wäre.
Wenn es wirklich eine Kombination aus Qmail und MySQL ist, dann wäre meine nächste Vermutung, dass die PSA-Datenbank einen Schuss weg hat.
Versuch mal einen Dump der PSA-DB. Bringt er da Fehlermeldungen oder steigt aus?

huschi.

HMnet · Apr 17, 2009

Guten Morgen,

also, der Dump lief ohne Probleme durch (3,9MB).

Also, der kill war nicht mehr möglich, ich bin erst dazugekommen, als die Serverload auf ca. 70.0 stand. Und schon da konnte ich keine Eingaben mehr machen. Der Server lief noch, wie gesagt, die Serverload stieg dann noch bis 135.0 und dann starb er komplett.

Das komische war, die Mail, die an die queuelifetime kam, hätte im 21.55 Uhr das Ende erreicht, und der Server fing an gegen 20.12 Uhr zu sterben, da hören jedenfalls die Maillogs auf. Die hohe Serverload war dann um 20.57 Uhr. Und nach dem Neustart war dann die betreffende Mail immer noch in der Queue und wurde dann um 1.57 Uhr regulär aus der Queue entfernt und der Kunde bekam seiner Mailer-Daemon Mail.

Habe die queuelifetime auf 48h reduziert. Morgen Abend ist wieder eine fällig.

Habe proforma mit

Code:

mysqlcheck --all-databases --auto-repair --optimize -uadmin -p

mal die Datenbank repariert ;-) .

Schaun mer mal weiter...

HMnet
Das ist alles echt strange.

Huschi · Apr 17, 2009

HMnet said:
Also, der kill war nicht mehr möglich

Dann gib Deiner Shell rechtzeitig vorher eine höhere Priorität. ("renice -19 $$")

als die Serverload auf ca. 70.0 stand.

Wo stand der Memory, der Swap, die CPU-Usage, die IO-Waits?
Das sind wichtige Infos! Denn die Load ist ein kommulierter Wert der sich u.a. aus diesen Werten ergibt.

hätte im 21.55 Uhr das Ende erreicht, und der Server fing an gegen 20.12 Uhr zu sterben

Evtl. hängt es ja doch nicht zusammen sondern ist eher purer Zufall das es ein paar Mal zeitlich gleich viel.

stieg dann noch bis 135.0 und dann starb er komplett

Gab es dann noch eine Ausgabe auf der seriellen Konsole? War überhaupt ein Einloggen auf der Sercon noch möglich?

huschi.

HMnet · Apr 17, 2009

Du bist ja fix.

Das mit den Werten (Memory, der Swap, die CPU-Usage, die IO-Waits) checke ich morgen Abend, wenn die nächste Mail ins Haus steht. Hatte nur die CPU-Usage im Auge und die lag unter 1%.

Wie gesagt, auf der seriellen Konsole kam keine Ausgabe und ein erneutes Einloggen auf der Konsole war nicht möglich, sobald ich das Passwort eingegeben habe ging das Putty-Fenster einfach zu. Habe es mehrfach versucht.

HMnet

HMnet · Apr 18, 2009

Also, heute Morgen um 9.55 Uhr flog wieder eine Mail aus der Queue. Alles lief problemlos - ohne Absturz. Habe die queuelifetime auf 48h stehen.

Sieht also so aus, dass des die Datenbankreparatur gebracht hat oder es war wirklich alles Zufall und die Abstürze haben gar nichts mit der Queue zu tun (glaube ich aber nicht, das war eigentlich offensichtlich).

Morgen um 11.35 Uhr sind wieder 2 Mails fällig - bleibt nur zu warten.

SCHON MAL TAUSEND DANK an Dich HUSCHI für den sensationellen SUPPORT - ohne dich wäre ich nicht darauf gekommen!

HMnet

chris085 · Apr 18, 2009

Gehen die Mails über 500 kb jetzt sofort raus ?

HMnet · Apr 18, 2009

Nein. Die sind noch da. Ich denke, das liegt an der Gegenstelle.

HMnet

HMnet · Apr 19, 2009

Also kurze Information:

ALLES PERFEKT! Gerade vorhin sind wieder zwei Mails aus der Queue entfernt worden.

Das sieht super aus, also lag es wohl tatsächlich an der Datenbank.

Morgen gegen 10.00 Uhr habe ich nochmal 2 Mails, dann ist die Queue leer

.

BIG THX nochmal an HUSCHI für den perfekten Support!

HMnet

HMnet · Apr 23, 2009

Also, leider muss ich sagen, dass dieser elende Schrotthaufen von Server nochmals abgestürtzt ist. Ich konnte zusehen. In top standen 27 Zombies und die Serverload stieg ziemlich langsam aber unaufhörlich an. An der seriellen Konsole kamen keine Ausgaben, es liefen keine Prozesse, die die Load verursachten. Die CPU-Auslastung war immer unter 1%. Memory, der Swap, die CPU-Usage, die IO-Waits waren alle normal. Hab vmstat 5 mitlaufen gehabt und auch top. Nix auffälliges. (Kann ich posten, falls von Interese, ist aber ziemlich unleserlich). Als die Load bei 15.00 angekommen war, hatte ich schon 2 Kundenanrufe, dass sie keine Mails mehr abrufen können, also musste ich rebooten, das hab ich dann auch von der seriellen Konsole gemacht, ging problemlos. Jetzt läuft er seit 3 Tagen problemlos. Man das Teil raubt mir noch den letzten Nerv.

An den Mails in der Queue liegt jetzt auf jeden Fall nicht (mehr), da sind schon ne Menge "durchgelaufen".

Bin für jeden (weiteren) Tipp dankbar,
HMnet

Huschi · Apr 23, 2009

Ein Bild sagt mehr als 1000 Worte...
oder
Ein Screenshot sagt mehr als 5 Sätze Beschreibung...

Poste halt einen Ausschnitt aus dem vmstat.

huschi.

HMnet · Apr 23, 2009

Gerne:

vmstat:

Code:

procs -----------memory---------- ---swap-- -----io---- -system-- ----cpu----
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa
 7  0  84364 1426968  17540 2006332    0    0     0     0  102   68  0  0 100  0
 8  0  84364 1426968  17540 2006332    0    0     0     3  104   70  0  0 100  0
 7  0  84364 1426968  17540 2006332    0    0     0     1  102   70  0  0 100  0
 7  0  84364 1426968  17540 2006332    0    0     0     0  102   69  0  0 100  0
 7  0  84364 1426968  17540 2006332    0    0     0     0  102   69  0  0 100  0
 7  0  84364 1426968  17540 2006332    0    0     0     3  102   69  0  0 100  0
 7  0  84364 1426968  17540 2006332    0    0     0     1  102   69  0  0 100  0
 7  0  84364 1426968  17540 2006332    0    0     0    12  103   68  0  0 100  0
 7  0  84364 1426968  17540 2006332    0    0     0     0  102   69  0  0 100  0
 7  0  84364 1426968  17540 2006332    0    0     0     0  102   68  0  0 100  0
 7  0  84364 1427204  17540 2006332    0    0     0     0  102   71  0  0 100  0
 8  0  84364 1427300  17540 2006332    0    0     0     0  102   70  0  0 100  0
 7  0  84364 1427300  17540 2006332    0    0     0     0  102   69  0  0 100  0
 7  0  84364 1427300  17540 2006332    0    0     0    16  102   71  0  0 100  0
 7  0  84364 1427300  17540 2006332    0    0     0     0  102   69  0  0 100  0
 7  0  84364 1427300  17540 2006332    0    0     0     0  102   68  0  0 100  0
 7  0  84364 1427300  17540 2006332    0    0     0     0  102   67  0  0 100  0

Und hier der letzte top-Auszug:

Code:

22:11:58 up 3 days,  1:15,  1 user,  load average: 19.78, 14.02, 8.61
Tasks: 314 total,  10 running, 277 sleeping,   0 stopped,  27 zombie
Cpu(s):  0.1%us,  0.0%sy,  0.0%ni, 99.9%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Mem:   4028164k total,  2619888k used,  1408276k free,    17572k buffers
Swap:  1959920k total,    84068k used,  1875852k free,  2009588k cache
  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND            
19667 root      20   0  8880 1436  932 R    0  0.0   0:00.47 top                
    1 root      20   0   812  264  208 S    0  0.0   0:04.82 init               
    2 root      15  -5     0    0    0 S    0  0.0   0:00.00 kthreadd           
    3 root      RT  -5     0    0    0 S    0  0.0   0:00.91 migration/0        
    4 root      15  -5     0    0    0 S    0  0.0   0:01.16 ksoftirqd/0        
    5 root      RT  -5     0    0    0 S    0  0.0   0:00.47 migration/1        
    6 root      15  -5     0    0    0 S    0  0.0   0:01.07 ksoftirqd/1        
    7 root      RT  -5     0    0    0 S    0  0.0   0:00.42 migration/2        
    8 root      15  -5     0    0    0 S    0  0.0   0:01.17 ksoftirqd/2        
    9 root      RT  -5     0    0    0 S    0  0.0   0:01.78 migration/3        
   10 root      15  -5     0    0    0 S    0  0.0   0:02.08 ksoftirqd/3        
   11 root      15  -5     0    0    0 S    0  0.0   0:02.79 events/0           
   12 root      15  -5     0    0    0 S    0  0.0   0:01.55 events/1           
   13 root      15  -5     0    0    0 S    0  0.0   0:01.34 events/2           
   14 root      15  -5     0    0    0 S    0  0.0   0:04.07 events/3           
   15 root      15  -5     0    0    0 S    0  0.0   0:00.00 khelper            
  106 root      15  -5     0    0    0 S    0  0.0   0:00.06 kblockd/0

THX schon mal,
HMnet

Server stürtzt ab, wenn eine Mail aus der Qmail-Queue automatisch entfernt wird

Registered User

Moderator

Registered User

Moderator

Registered User

Registered User

Moderator

Registered User

Registered User

Moderator

Registered User

Moderator

Registered User

Registered User

Registered User

Registered User

Registered User

Registered User

Moderator

Registered User