spam_hook: eMails verschwinden in Postfix (Plesk 9.5.4)

VisualBeo

New Member
Hallo Community,

habe vorhin in der Postfix-Logfile auf meinem Plesk 9.5.4 (Ubuntu) zufällig gesehen, dass eine eMail, auf die ich vergeblich gewartet hatte, auf seltsame Weise verschwunden ist:

Code:
Sep  7 09:14:29 h1125512 postfix/smtpd[26495]: connect from mail.stadt.wuerzburg.de[195.243.139.187]
Sep  7 09:14:29 h1125512 postfix/smtpd[26523]: connect from localhost.localdomain[127.0.0.1]
Sep  7 09:14:29 h1125512 postfix/smtpd[26495]: NOQUEUE: client=mail.stadt.wuerzburg.de[195.243.139.187]
Sep  7 09:14:29 h1125512 postfix/smtpd[26523]: BA9D51E8015: client=mail.stadt.wuerzburg.de[195.243.139.187]:49217
Sep  7 09:14:29 h1125512 before-queue[26520]: check handlers for addr: jemand@stadt.wuerzburg.de
Sep  7 09:14:29 h1125512 before-queue[26520]: check handlers for addr: mail@meinedomain.de
Sep  7 09:14:29 h1125512 before-remote[26522]: check handlers for addr: jemand@stadt.wuerzburg.de
Sep  7 09:14:29 h1125512 before-remote[26522]: check handlers for addr: mail@meinedomain.de
Sep  7 09:14:29 h1125512 postfix/cleanup[26536]: BA9D51E8015: message-id=<4E6735BF.XXXX.00BE.1@stadt.wuerzburg.de>
Sep  7 09:14:29 h1125512 postfix/smtpd[26495]: disconnect from mail.stadt.wuerzburg.de[195.243.139.187]
Sep  7 09:14:29 h1125512 postfix/smtpd[26523]: disconnect from localhost.localdomain[127.0.0.1]
Sep  7 09:14:29 h1125512 postfix/qmgr[14091]: BA9D51E8015: from=<jemand@stadt.wuerzburg.de>, size=2390, nrcpt=1 (queue active)
Sep  7 09:14:29 h1125512 postfix-local[26549]: postfix-local: from=jemand@stadt.wuerzburg.de, to=mail@meinedomain.de, dirname=/var/qmail/mailnames
Sep  7 09:14:29 h1125512 postfix-local[26549]: hook_dir = '/opt/psa/handlers/before-local'
Sep  7 09:14:29 h1125512 postfix-local[26549]: recipient[3] = 'mail@meinedomain.de'
Sep  7 09:14:29 h1125512 postfix-local[26549]: handlers dir = '/opt/psa/handlers/before-local/recipient/mail@meinedomain.de'
Sep  7 09:14:30 h1125512 postfix-local[26549]: call_handlers: call executable = '/opt/psa/handlers/info/10-spam-5AKVce/executable'
Sep  7 09:14:30 h1125512 spam_hook[26550]: Message was deleted by spam_hook
Sep  7 09:14:30 h1125512 postfix-local[26549]: handlers_stderr: STOP
Sep  7 09:14:30 h1125512 postfix-local[26549]: call_handlers: STOP during call '/opt/psa/handlers/info/10-spam-5AKVce/executable' handler
Sep  7 09:14:30 h1125512 postfix-local[26549]: call_handlers: stop call handlers from dir '/opt/psa/handlers/before-local/recipient/mail@meinedomain.de'
Sep  7 09:14:30 h1125512 postfix-local[26549]: message discarded by a mail handler
Sep  7 09:14:30 h1125512 postfix/pipe[26548]: BA9D51E8015: to=<mail@meinedomain.de>, relay=plesk_virtual, delay=0.52, delays=0.2/0.02/0/0.3, dsn=2.0.0, status=sent (delivered via plesk_virtual service)
Sep  7 09:14:30 h1125512 master[26553]: fatal: master_spawn: exec /usr/lib/postfix/bounce: Argument list too long
Sep  7 09:14:30 h1125512 postfix/cleanup[26536]: 3BF0F1E8330: message-id=<20110907071430.3BF0F1E8330@h1125512.serverkompetenz.net>
Sep  7 09:14:30 h1125512 postfix/bounce[26552]: BA9D51E8015: sender delivery status notification: 3BF0F1E8330
Sep  7 09:14:30 h1125512 postfix/qmgr[14091]: BA9D51E8015: removed
Sep  7 09:14:30 h1125512 postfix/qmgr[14091]: 3BF0F1E8330: from=<>, size=3838, nrcpt=1 (queue active)
Sep  7 09:14:30 h1125512 postfix/master[13997]: warning: master_spawn: fork: Cannot allocate memory -- throttling
Sep  7 09:14:31 h1125512 postfix/master[13997]: warning: process /usr/lib/postfix/bounce pid 26553 exit status 1
Sep  7 09:14:31 h1125512 postfix/master[13997]: warning: /usr/lib/postfix/bounce: bad command startup -- throttling
Sep  7 09:15:30 h1125512 postfix/master[13997]: warning: master_spawn: fork: Cannot allocate memory -- throttling
Sep  7 09:16:31 h1125512 postfix/smtp[26565]: 3BF0F1E8330: to=<jemand@stadt.wuerzburg.de>, relay=mail.stadt.wuerzburg.de[195.243.139.187]:25, delay=121, delays=0.01/120/0.25/0.59, dsn=4.7.1, status=deferred (host mail.stadt.wuerzburg.de[195.243.139.187] said: 450 4.7.1 <jemand@stadt.wuerzburg.de>: Recipient address rejected: Greylisted for 5 minutes (in reply to RCPT TO command))
Sep  7 09:17:49 h1125512 postfix/anvil[26517]: statistics: max connection rate 1/60s for (smtp:195.243.139.187) at Sep  7 09:14:29
Sep  7 09:17:49 h1125512 postfix/anvil[26517]: statistics: max connection count 1 for (smtp:195.243.139.187) at Sep  7 09:14:29
Sep  7 09:17:49 h1125512 postfix/anvil[26517]: statistics: max cache size 1 at Sep  7 09:14:29
Sep  7 09:22:14 h1125512 postfix/qmgr[14091]: 3BF0F1E8330: from=<>, size=3838, nrcpt=1 (queue active)
Sep  7 09:22:15 h1125512 postfix/smtp[26603]: 3BF0F1E8330: to=<jemand@stadt.wuerzburg.de>, relay=mail.stadt.wuerzburg.de[195.243.139.187]:25, delay=465, delays=464/0.03/0.14/0.83, dsn=5.7.1, status=bounced (host mail.stadt.wuerzburg.de[195.243.139.187] said: 550 5.7.1 no third-party DSNs (in reply to end of DATA command))
Sep  7 09:22:15 h1125512 postfix/qmgr[14091]: 3BF0F1E8330: removed

Ich habe ehrlich gesagt keine Ahnung, was die Logs zu bedeuten haben. Laut

Code:
Sep  7 09:14:30 h1125512 spam_hook[26550]: Message was deleted by spam_hook

hat ja wohl der Spamfilter (SpamAssasin ist aktiv) die Mail aussortiert, aber warum?

Bin sehr verzweifelt, dass einfach ankommende eMails verschwinden. Wäre dankbar, wenn mir jemand einen Tipp geben könnte, wo das Problem liegt.

Schönes Wochenende! Chris
 
Sowas ähnliches kenne ich von diversen Pleskversionen.

Was steht denn zb. in den diversen /opt/psa/handlers/info/10-spam-*/context drin?

Lass mal in der Shell folgendes laufen:

for i in /opt/psa/handlers/info/*/context; do echo $i; cat $i; done

und schau mal ob da irgendwo delete drin steht.

Ansonsten hat bei mir nur geholfen bei allen Mailkonten den Spamfilter zu deaktivieren und mit neuen Einstellungen wieder zu aktivieren.
 
Last edited by a moderator:
//EDIT: Irgendjemand muss da ja eingestellt haben, dass Spam gelöscht wird, was ziemlich unpraktisch ist!
Wie das geht?

Ganz einfach, dass du in Plesk bei Domains unter den verschiedenen Mailadressen für das Spamfilter einstellen musst, dass Spam nicht gelöscht wird sondern gekennzeichnet.

Schau mal bitte in dein Plesk rein.
 
Last edited by a moderator:
//EDIT: Irgendjemand muss da ja eingestellt haben, dass Spam gelöscht wird, was ziemlich unpraktisch ist!
Wie das geht?

Das geht, ist bei dieser Mailbox, um die es geht, aber *nicht* so eingestellt. Spam wird (eigentlich) nur markiert, aber nicht gelöscht. Warum die eMail also verschwunden ist, weiß ich immer noch nicht.
 
Hmm. Seltsame Sache.

Dann muss ich raten und dir diese Vorgeshensweise vorschlagen:

1. Deaktviere bei allen Mailboxen den Spamfilter komplett
2. lösche bitte in allen /opt/psa/handlers/info/*/ die Datei context.
3. Starte /opt/psa/admin/sbin/mchk
4. In Plesk aktiviere den Spamfilter bei den Mailboxen und stellen ihn dort auf markieren

Jetzt schau mal ob in /opt/psa/handlers/info/*/context was anderes als delete steht

Wenn nicht hat Plesk einen Bug.
 
Also ich gehe mal von einem Bug in Plesk aus.

Immer wenn eMails von Blacklists oder Spamassassin aussortiert wurden, war das auch klar in den Logfiles dokumentiert:

Code:
spamd[20435]: spamd: got connection over /tmp/spamd_full.sock 
spamd[20435]: spamd: using default config for info@lokaledomain.de: /var/qmail/mailnames/lokaledomain.de/info/.spamassassin/user_prefs 
spamd[20435]: spamd: processing message <20100930123636.14AF17A88E2@tostay.net> for info@lokaledomain.de:110 
spamd[20435]: spamd: identified spam (14.4/6.0) for info@lokaledomain.de:110 in 1.9 seconds, 4088 bytes. 
spamd[20435]: spamd: result: Y 14 - ADVANCE_FEE_2,ADVANCE_FEE_3,DNS_FROM_OPENWHOIS,FORGED_MUA_OUTLOOK,MILLION_USD,MSOE_MID_WRONG_CASE,SUBJ_ALL_CAPS scantime=1.9,size=4088,user=info@lokaledomain.de,uid=110,required_score=6.0,rhost=localhost,raddr=127.0.0.1,rport=/tmp/spamd_full.sock,mid=<20100930123636.14AF17A88E2@tostay.net>,autolearn=spam 
spamd[19518]: prefork: child states: I 
spam_hook[9453]: spam_hook: STOP mail for info@lokaledomain.de
postfix-local[9452]: handlers_stderr: STOP
postfix-local[9452]: call_handlers: STOP during call '/opt/psa/handlers/info/10-spam-pN3bUz/executable' handler
postfix-local[9452]: call_handlers: stop call handlers from dir '/opt/psa/handlers/before-local/recipient/info@lokaledomain.de'
postfix-local[9452]: message discarded by a mail handler
postfix/pipe[9451]: 1510E1E8004: to=<info@lokaledomain.de>, relay=plesk_virtual, delay=2.1, delays=0.16/0.01/0/2, dsn=2.0.0, status=sent (delivered via plesk_virtual service)
postfix/qmgr[14192]: 1510E1E8004: removed

Code:
postfix/smtpd[9890]: connect from 176-96-178-94.pool.ukrtel.net[94.178.96.176]
postfix/smtpd[9890]: NOQUEUE: reject: RCPT from 176-96-178-94.pool.ukrtel.net[94.178.96.176]: 554 5.7.1 Service unavailable; Client host [94.178.96.176] blocked using zen.spamhaus.org; http://www.spamhaus.org/query/bl?ip=94.178.96.176; from=<steepmvpe@real-time-vision.com> to=<info@lokaledomain.com> proto=ESMTP helo=<30-33-94-178.pool.ukrtel.net>
postfix/smtpd[9890]: lost connection after DATA (0 bytes) from 176-96-178-94.pool.ukrtel.net[94.178.96.176]
postfix/smtpd[9890]: disconnect from 176-96-178-94.pool.ukrtel.net[94.178.96.176]

Dass eine eMail jedoch kommentarlos deleted wird, wie im OP beschrieben, kam in meinen ganzen Logdateien nur dieses eine Mal vor. Echt seltsam.

Habe inzwischen auf Plesk 10 upgedated und Spamassassin deaktiviert.
 
Back
Top