[geloest] Probleme mit genau einer Mail

Knappe · 2 Juni 2008

Hallo,

setzen seit Jahren unter OpenSuSE 10.2 (64-Bit) die Kombination fetchmail, postfix, amavis, antivir, procmail ein und habe damit auch keine Probleme.

Jetzt ist jedoch ein Fall einer Mail (bzw. von Mails die mit einer bestimmten Absenderkennung versehen sind) aufgetreten, deren Bearbeitung & Weiterleitung durch o.g. Programme für mich unerklärlich ist.

Im Endeffekt
- wird die Mail via fetchmail vom IMAP-Konto des Providers gelesen
- von postfix an amavis weitergereicht
- von amavis wieder zurückgereicht (
ja und dann .... das "Nirwana" schlägt zu :evil:

Wie gesagt : nur von diesem einem Sender (Kennung habe ich anonymisiert, Textinhalt nicht mit kopiert) ...

Die Mail im RAW-Format

X-Envelope-From: <buchung@senderdomain.com>
X-Envelope-To: <info@receiveddomain.de>
X-Delivery-Time: 1212324684
X-UID: 13127
Return-Path: <buchung@senderdomain.com>
X-RZG-CLASS-ID: mi
Received: from db1.senderdomain.de (mail1.senderdomain.de [82.135.108.48])
by mailin.webmailer.de (bertie mi3) (RZmta 16.38)
with ESMTP id 113157k51Ci5XY for <info@receiveddomain.de>;
Sun, 1 Jun 2008 14:51:24 +0200 (MEST)
(envelope-from: <buchung@senderdomain.com>)
Received: from host-22-133-100-133.customer.m-online.net ([22.133.100.133] helo=mail.senderdomain.de)
by db1.senderdomain.de with smtp (Exim 4.62)
(envelope-from <buchung@senderdomain.com>)
id 1Y2n1w-1111tm-EB; Sun, 01 Jun 2008 14:51:24 +0200
MIME-Version: 1.0
From: SenderName <buchung@senderdomain.com>
X-Mailer: SenderName
DATE: Sun, 01 Jun 2008 14:51:24 +0200
Subject: Your Booking, No 45678912 |ID121212-KD|
Content-Type: multipart/alternative;
boundary="=_314a7576236e6eb05b08d927cba69343"
Message-ID: <k1sbpo.iyhcwx@mail.senderdomain.de>
To: info@receiveddomain.de
X-Envelope-From: <buchung@senderdomain.com>
X-Envelope-To: <info@receiveddomain.de>
X-Delivery-Time: 1212324684
X-UID: 13127
Return-Path: <buchung@senderdomain.com>
X-RZG-CLASS-ID: mi
Received: from db1.senderdomain.de (mail1.senderdomain.de [82.135.108.48])
by mailin.webmailer.de (bertie mi3) (RZmta 16.38)
with ESMTP id 113157k51Ci5XY for <info@receiveddomain.de>;
Sun, 1 Jun 2008 14:51:24 +0200 (MEST)
(envelope-from: <buchung@senderdomain.com>)
Received: from host-22-133-100-133.customer.m-online.net ([22.133.100.133] helo=mail.senderdomain.de)
by db1.senderdomain.de with smtp (Exim 4.62)
(envelope-from <buchung@senderdomain.com>)
id 1Y2n1w-1111tm-EB; Sun, 01 Jun 2008 14:51:24 +0200
MIME-Version: 1.0
From: SenderName <buchung@senderdomain.com>
X-Mailer: SenderName
DATE: Sun, 01 Jun 2008 14:51:24 +0200
Subject: Your Booking, No 45678912 |ID121212-KD|
Content-Type: multipart/alternative;
boundary="=_314a7576236e6eb05b08d927cba69343"
Message-ID: <k1sbpo.iyhcwx@mail.senderdomain.de>
To: info@receiveddomain.de

Und hier die zugehörige Ausgabe im mail.log

Jun 2 08:52:07 myserver postfix/smtpd[25994]: connect from localhost[127.0.0.1]
Jun 2 08:52:08 myserver postfix/smtpd[25994]: 00E5E8E6CF34: client=localhost[127.0.0.1]
Jun 2 08:52:08 myserver postfix/cleanup[25997]: 00E5E8E6CF34: reject: header DATE: Sun, 01 Jun 2008 14:51:24 +0200 from localhost[127.0.0.1]; from=<buchung@senderdomain.com> to=<thomas@localhost> proto=ESMTP helo=<myserver.mydomain.de>: 5.7.1 191
Jun 2 08:52:08 myserver postfix/smtpd[26004]: connect from localhost[127.0.0.1]
Jun 2 08:52:08 myserver postfix/smtpd[26004]: 2F80B8E6CF34: client=localhost[127.0.0.1]
Jun 2 08:52:08 myserver postfix/cleanup[25997]: 2F80B8E6CF34: message-id=<20080602065208.2F80B8E6CF34@myserver.mydomain.de>
Jun 2 08:52:08 myserver postfix/qmgr[21404]: 2F80B8E6CF34: from=<>, size=2381, nrcpt=1 (queue active)
Jun 2 08:52:08 myserver postfix/smtpd[26004]: disconnect from localhost[127.0.0.1]
Jun 2 08:52:08 myserver amavis[6987]: (06987-07) process_request: fileno sock=13, STDIN=0, STDOUT=1
Jun 2 08:52:08 myserver amavis[6987]: (06987-08) LMTP::10024 /var/spool/amavis/tmp/amavis-20080602T080750-06987: <> -> <buchung@senderdomain.com> SIZE=2381 Received: from myserver.mydomain.de ([127.0.0.1]) by localhost (myserver.home.mydomain.de [127.0.0.1]) (amavisd-new, port 10024) with LMTP for <buchung@senderdomain.com>; Mon, 2 Jun 2008 08:52:08 +0200 (CEST)
Jun 2 08:52:08 myserver postfix/smtpd[25994]: disconnect from localhost[127.0.0.1]
Jun 2 08:52:08 myserver amavis[6987]: (06987-08) body hash: 609a846043d91d444555f29d3992ae06
Jun 2 08:52:08 myserver amavis[6987]: (06987-08) Checking: 9gQAweiqE3H6 <> -> <buchung@senderdomain.com>
Jun 2 08:52:08 myserver amavis[6987]: (06987-08) p004 1 Content-Type: multipart/report
Jun 2 08:52:08 myserver amavis[6987]: (06987-08) p001 1/1 Content-Type: text/plain, size: 256 B, name:
Jun 2 08:52:08 myserver amavis[6987]: (06987-08) p002 1/2 Content-Type: message/delivery-status, size: 202 B, name:
Jun 2 08:52:08 myserver amavis[6987]: (06987-08) p003 1/3 Content-Type: text/rfc822-headers, size: 995 B, name:
Jun 2 08:52:08 myserver amavis[6987]: (06987-08) Checking for banned types and filenames
Jun 2 08:52:08 myserver amavis[6987]: (06987-08) collect banned table[0]: buchung@senderdomain.com, tables: DEFAULT=>Amavis::Lookup::RE=ARRAY(0x1d86710)
Jun 2 08:52:08 myserver amavis[6987]: (06987-08) p.path buchung@senderdomain.com: "P=p004,L=1,M=multipart/report | P=p001,L=1/1,M=text/plain,T=asc"
Jun 2 08:52:08 myserver amavis[6987]: (06987-08) p.path buchung@senderdomain.com: "P=p004,L=1,M=multipart/report | P=p002,L=1/2,M=message/delivery-status,T=asc"
Jun 2 08:52:08 myserver amavis[6987]: (06987-08) p.path buchung@senderdomain.com: "P=p004,L=1,M=multipart/report | P=p003,L=1/3,M=text/rfc822-headers,T=txt"
Jun 2 08:52:08 myserver amavis[6987]: (06987-08) Using (Avira AntiVir): /usr/bin/antivir --allfiles -noboot -nombr -rs -s -z /var/spool/amavis/tmp/amavis-20080602T080750-06987/parts
Jun 2 08:52:11 myserver amavis[6987]: (06987-08) run_av: /usr/bin/antivir exit 0, AntiVir / Linux Version 2.1.12-36\nCopyright (c) 2008 by Avira GmbH.\nAll rights reserved.\n\nVDF version: 7.0.4.63 created 20 May 2008\n\nAntiVir license: 149996 for PersonalEdition Classic\n\nauto excluding /sys/ from scans (is a special fs)\nauto excluding /proc from scans (is a special fs)\nchecking drive/path (list): /var/spool/amavis/tmp/amavis-20080602T080750-06987/parts\n\n------ scan results ------\n directories: ...1\n scanned files: ...3\n...alerts: ...0\n...suspicious: ...0\n...scan time: 00:00:01\n--------------------------\nThank you for using AntiVir.
Jun 2 08:52:11 myserver amavis[6987]: (06987-08) run_av (Avira AntiVir): CLEAN
Jun 2 08:52:13 myserver amavis[6987]: (06987-08) spam_scan: score=-4.396 tests=[ALL_TRUSTED=-1.8,AWL=0.003,BAYES_00=-2.599]
Jun 2 08:52:13 myserver amavis[6987]: (06987-08) do_notify_and_quar: ccat=Clean (1,0) ("1":Clean, "0":CatchAll), q_mth=, qar_mth=
Jun 2 08:52:13 myserver postfix/smtpd[26041]: connect from localhost[127.0.0.1]
Jun 2 08:52:13 myserver amavis[6987]: (06987-08) AUTH not needed, user='', MTA offers ''
Jun 2 08:52:13 myserver postfix/smtpd[26041]: D17BA8E758BB: client=localhost[127.0.0.1]
Jun 2 08:52:13 myserver amavis[6987]: (06987-08) response to RCPT TO for <buchung@senderdomain.com>: "250 2.1.5 Ok"
Jun 2 08:52:13 myserver postfix/cleanup[25997]: D17BA8E758BB: message-id=<20080602065208.2F80B8E6CF34@myserver.mydomain.de>
Jun 2 08:52:13 myserver postfix/qmgr[21404]: D17BA8E758BB: from=<>, size=2849, nrcpt=1 (queue active)
Jun 2 08:52:13 myserver amavis[6987]: (06987-08) FWD via SMTP: <> -> <buchung@senderdomain.com>, BODY=8BITMIME 250 2.6.0 Ok, id=06987-08, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as D17BA8E758BB
Jun 2 08:52:13 myserver amavis[6987]: (06987-08) Passed CLEAN, [127.0.0.1] <> -> <buchung@senderdomain.com>, Message-ID: <20080602065208.2F80B8E6CF34@myserver.mydomain.de>, mail_id: 9gQAweiqE3H6, Hits: -4.396, queued_as: D17BA8E758BB, 5646 ms
Jun 2 08:52:13 myserver amavis[6987]: (06987-08) TIMING [total 5654 ms] - SMTP LHLO: 4 (0%)0, SMTP pre-MAIL: 0 (0%)0, SMTP pre-DATA-flush: 3 (0%)0, SMTP DATA: 41 (1%)1, body_digest: 2 (0%)1, gen_mail_id: 0 (0%)1, mime_decode: 20 (0%)1, get-file-type3: 25 (0%)2, decompose_part: 2 (0%)2, decompose_part: 1 (0%)2, parts_decode: 0 (0%)2, AV-scan-1: 2873 (51%)53, spam-wb-list: 2 (0%)53, SA msg read: 1 (0%)53, SA parse: 1 (0%)53, SA check: 2500 (44%)97, SA finish: 5 (0%)97, update_cache: 2 (0%)97, decide_mail_destiny: 1 (0%)97, fwd-connect: 47 (1%)98, fwd-mail-from: 1 (0%)98, fwd-rcpt-to: 5 (0%)98, fwd-data-cmd: 1 (0%)98, write-header: 1 (0%)98, fwd-data-contents: 2 (0%)98, fwd-data-end: 96 (2%)100, fwd-rundown: 1 (0%)100, prepare-dsn: 1 (0%)100, main_log_entry: 13 (0%)100, update_snmp: 2 (0%)100, unlink-3-files: 2 (0%)100, rundown: 0 (0%)100
Jun 2 08:52:13 myserver postfix/lmtp[26005]: 2F80B8E6CF34: to=<buchung@senderdomain.com>, relay=127.0.0.1[127.0.0.1]:10024, delay=5.8, delays=0.16/0.03/0.01/5.7, dsn=2.6.0, status=sent (250 2.6.0 Ok, id=06987-08, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as D17BA8E758BB)
Jun 2 08:52:13 myserver postfix/qmgr[21404]: 2F80B8E6CF34: removed
Jun 2 08:52:13 myserver amavis[6987]: (06987-08) load: 2 %, total idle 2621.719 s, busy 42.217 s
Jun 2 08:52:13 myserver postfix/smtpd[26041]: disconnect from localhost[127.0.0.1]
Jun 2 08:52:14 myserver postfix/smtp[26042]: D17BA8E758BB: to=<buchung@senderdomain.com>, relay=post.provider.de[81.169.145.136]:587, delay=0.54, delays=0.09/0.05/0.16/0.23, dsn=2.0.0, status=sent (250 queued as w07293k525XJvb)
Jun 2 08:52:14 myserver postfix/qmgr[21404]: D17BA8E758BB: removed

Was passiert da ? Warum wird die Mail nicht weitergeleitet (das Log von procmail enthält keinen einzig Eintrag von dieser Mail) ?

Knappe · 2 Juni 2008

Problem geloest !

Die Mail wurde durch einen "Header-Check" geprueft und als 'Spam' erkannt. Anschliessend wurde sofort ein "reject' ausgefuehrt.

Eine Zwischenspeicherung etc. erfolgte nicht; daher auch keine infos im Protokoll.

Muss mal ueberlegen ob es nicht besser waere, auch in einem 'reject' eine Meldung ins Protokoll schreiben zu lassen.

Hat da ja vielleicht eine Idee ?

[geloest] Probleme mit genau einer Mail

Knappe

Hacker

Knappe

Hacker