Mails kommen doppelt und dreifach an
Hallo,
habe letzes Wochenende meinen Server von Debian Wheezy auf Devuan Jessie aktualisiert. Nun habe ich komische Phänomene. Kann Zufall sein, oder auch nicht. Ich meine jedenfalls, alles korrekt übernommen zu haben.
Manchmal bekomme ich die gleiche Mail mehrfach. Heute kam von Amazon eine 2 mal, und jetzt aus einem anderen Online-Shop die gleiche Mail sogar 3 mal! Im Log sieht das so aus als hätte der fremde Mailserver die wirklich 3 mal geschickt. So geht das los:
Jan 11 17:02:21 s4 postfix/postscreen[28814]: CONNECT from [52.58.63.0]:49380 to [172.31.1.100]:25 Jan 11 17:02:22 s4 postfix/postscreen[28814]: CONNECT from [52.58.63.9]:46498 to [172.31.1.100]:25 Jan 11 17:02:23 s4 postfix/postscreen[28814]: CONNECT from [52.58.63.12]:56492 to [172.31.1.100]:25 Jan 11 17:02:27 s4 postfix/postscreen[28814]: PASS NEW [52.58.63.0]:49380
Kann das sein, dass manche Mailserver nicht damit klar kommen, dass Postscreen die Verbindung beim ersten Kontakt verzögert?
In diesem Fall schliesse ich Konfigurationsfehler bei mir eigentlich aus, denn 3 Connects von unterschiedlichen IPs innerhalb 3 Sekunden, die mir die gleiche Mail abliefern wollen, das kann doch nicht von meiner Seite verursacht sein, oder?
MfG
Jochen
* J. Fahrner jf@fahrner.name:
Hallo,
habe letzes Wochenende meinen Server von Debian Wheezy auf Devuan Jessie aktualisiert. Nun habe ich komische Phänomene. Kann Zufall sein, oder auch nicht. Ich meine jedenfalls, alles korrekt übernommen zu haben.
Manchmal bekomme ich die gleiche Mail mehrfach. Heute kam von Amazon eine 2 mal, und jetzt aus einem anderen Online-Shop die gleiche Mail sogar 3 mal! Im Log sieht das so aus als hätte der fremde Mailserver die wirklich 3 mal geschickt. So geht das los:
Jan 11 17:02:21 s4 postfix/postscreen[28814]: CONNECT from [52.58.63.0]:49380 to [172.31.1.100]:25 Jan 11 17:02:22 s4 postfix/postscreen[28814]: CONNECT from [52.58.63.9]:46498 to [172.31.1.100]:25 Jan 11 17:02:23 s4 postfix/postscreen[28814]: CONNECT from [52.58.63.12]:56492 to [172.31.1.100]:25 Jan 11 17:02:27 s4 postfix/postscreen[28814]: PASS NEW [52.58.63.0]:49380
Kann das sein, dass manche Mailserver nicht damit klar kommen, dass Postscreen die Verbindung beim ersten Kontakt verzögert?
In diesem Fall schliesse ich Konfigurationsfehler bei mir eigentlich aus, denn 3 Connects von unterschiedlichen IPs innerhalb 3 Sekunden, die mir die gleiche Mail abliefern wollen, das kann doch nicht von meiner Seite verursacht sein, oder?
Sie kommen, die Mail geht an den Content Filter. Der Content Filter wird nicht vor dem timeout von Postfix fertig. Postfix beendet die Verbindung zum externen Client. Der Content Filter wird fertig. Er gibt die Mail an Postfix. Postfix stellt die Mail zu.
Dein Content Filter ist überlastet?
p@rick
Am 11.01.2017 um 17:42 schrieb J. Fahrner:
Hallo,
habe letzes Wochenende meinen Server von Debian Wheezy auf Devuan Jessie aktualisiert. Nun habe ich komische Phänomene. Kann Zufall sein, oder auch nicht. Ich meine jedenfalls, alles korrekt übernommen zu haben.
Manchmal bekomme ich die gleiche Mail mehrfach. Heute kam von Amazon eine 2 mal, und jetzt aus einem anderen Online-Shop die gleiche Mail sogar 3 mal! Im Log sieht das so aus als hätte der fremde Mailserver die wirklich 3 mal geschickt. So geht das los:
Jan 11 17:02:21 s4 postfix/postscreen[28814]: CONNECT from [52.58.63.0]:49380 to [172.31.1.100]:25 Jan 11 17:02:22 s4 postfix/postscreen[28814]: CONNECT from [52.58.63.9]:46498 to [172.31.1.100]:25 Jan 11 17:02:23 s4 postfix/postscreen[28814]: CONNECT from [52.58.63.12]:56492 to [172.31.1.100]:25 Jan 11 17:02:27 s4 postfix/postscreen[28814]: PASS NEW [52.58.63.0]:49380
Kann das sein, dass manche Mailserver nicht damit klar kommen, dass Postscreen die Verbindung beim ersten Kontakt verzögert?
ja das kann sein, aber das resultat sollte dann eher sein dass eine Mail nie ankommt, eine Verdoppelung geschieht fast immer wenn die Mail schon angenommen wurde, durch nachgelagerte Prozesse wenn du zb amavis als content filter verwendest ueberpruefe das nochmal, lmtp mit sieve koennte auch sein
In diesem Fall schliesse ich Konfigurationsfehler bei mir eigentlich aus, denn 3 Connects von unterschiedlichen IPs innerhalb 3 Sekunden, die mir die gleiche Mail abliefern wollen, das kann doch nicht von meiner Seite verursacht sein, oder?
nun warum sollte dir die gleiche Mail nicht 3 mal von div ips zugestellt werden..., ja der Fehler kann beim Absender liegen, bzw ist das ein Massenproblem oder nur bei bestimmten Absendern.... wenn du postscreen in Verdacht hast setzte die ips doch mal schnell in eine Whitelist
MfG
Jochen
Best Regards MfG Robert Schetterer
Hallo,
Am 11.01.2017 um 20:14 schrieb Robert Schetterer:
nun warum sollte dir die gleiche Mail nicht 3 mal von div ips zugestellt werden..., ja der Fehler kann beim Absender liegen, bzw ist das ein Massenproblem oder nur bei bestimmten Absendern.... wenn du postscreen in Verdacht hast setzte die ips doch mal schnell in eine Whitelist
Schwierig. Sooo oft bestelle ich jetzt nicht in diesem Online-Shop wo das passiert ist. ;-)
Wenn ich das richtig im Kopf habe, dann verzögert postscreen bei ihm noch unbekannten Servern die Antwort. Da ich den mailserver neu aufgesetzt habe, sind natürlich erstmal alle unbekannt. Und da die 3 Mailzustellungen innerhalb von 3 Sekunden initiiert wurden, war mein Verdacht natürlich, dass es mit dieser gewollten Verzögerung des postscreen zu tun hat. Das ist ja so gewollt, und gegen die Ungeduld des Senders kann ich wenig machen. ;-) Das der die dann aber gleich 3 mal parallel zustellt, kann doch nur ein Fehler beim Sender sein. Hier das komplette Szenario:
Jan 11 17:02:21 s4 postfix/postscreen[28814]: CONNECT from [52.58.63.0]:49380 to [172.31.1.100]:25
Jan 11 17:02:22 s4 postfix/postscreen[28814]: CONNECT from [52.58.63.9]:46498 to [172.31.1.100]:25
Jan 11 17:02:23 s4 postfix/postscreen[28814]: CONNECT from [52.58.63.12]:56492 to [172.31.1.100]:25
Jan 11 17:02:27 s4 postfix/postscreen[28814]: PASS NEW [52.58.63.0]:49380
Jan 11 17:02:27 s4 postfix/smtpd[28823]: connect from routemea1.hes.trendmicro.eu[52.58.63.0]
Jan 11 17:02:27 s4 postfix/smtpd[28823]: Anonymous TLS connection established from routemea1.hes.trendmicro.eu[52.58.63.0]: TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)
Jan 11 17:02:27 s4 policyd-spf[28829]: None; identity=helo; client-ip=52.58.63.0; helo=routemea1.hes.trendmicro.eu; envelope-from=service@gustini.de; receiver=jf@fahrner.name
Jan 11 17:02:27 s4 policyd-spf[28829]: Permerror; identity=mailfrom; client-ip=52.58.63.0; helo=routemea1.hes.trendmicro.eu; envelope-from=service@gustini.de; receiver=jf@fahrner.name
Jan 11 17:02:27 s4 postfix/smtpd[28823]: EA0FC10123E: client=routemea1.hes.trendmicro.eu[52.58.63.0]
Jan 11 17:02:27 s4 postfix/cleanup[28830]: EA0FC10123E: message-id=201701111702190196@82093962
Jan 11 17:02:28 s4 opendkim[2642]: EA0FC10123E: routemea1.hes.trendmicro.eu [52.58.63.0] not internal
Jan 11 17:02:28 s4 opendkim[2642]: EA0FC10123E: not authenticated
Jan 11 17:02:28 s4 opendkim[2642]: EA0FC10123E: no signature data
Jan 11 17:02:28 s4 opendmarc[2927]: implicit authentication service: s4.fahrner.name
Jan 11 17:02:28 s4 opendmarc[2927]: EA0FC10123E: gustini.de none
Jan 11 17:02:28 s4 spamd[11570]: spamd: got connection over /var/run/spamd.sock
Jan 11 17:02:28 s4 spamd[11570]: spamd: processing message 201701111702190196@82093962 for jf:116
Jan 11 17:02:28 s4 spamd[11570]: spamd: clean message (1.3/5.0) for jf:116 in 0.3 seconds, 177298 bytes.
Jan 11 17:02:28 s4 spamd[11570]: spamd: result: . 1 - BAD_ENC_HEADER,RDNS_NONE,T_OBFU_PDF_ATTACH,UNPARSEABLE_RELAY,URIBL_BLOCKED scantime=0.3,size=177298,user=jf,uid=116,required_score=5.0,rhost=localhost,raddr=127.0.0.1,rport=/var/run/spamd.sock,mid=201701111702190196@82093962,autolearn=no autolearn_force=no
Jan 11 17:02:28 s4 postfix/qmgr[7851]: EA0FC10123E: from=service@gustini.de, size=177316, nrcpt=1 (queue active)
Jan 11 17:02:28 s4 postfix/smtpd[28823]: disconnect from routemea1.hes.trendmicro.eu[52.58.63.0]
Jan 11 17:02:28 s4 spamd[11568]: prefork: child states: II
Jan 11 17:02:28 s4 postfix/pipe[28832]: EA0FC10123E: to=joachim@xxx.de, orig_to=jf@fahrner.name, relay=dovecot, delay=0.86, delays=0.7/0.02/0/0.14, dsn=2.0.0, status=sent (delivered via dovecot service)
Jan 11 17:02:28 s4 postfix/qmgr[7851]: EA0FC10123E: removed
Jan 11 17:02:28 s4 postfix/postscreen[28814]: PASS OLD [52.58.63.9]:46498
Jan 11 17:02:28 s4 postfix/smtpd[28823]: connect from routemea2.hes.trendmicro.eu[52.58.63.9]
Jan 11 17:02:28 s4 postfix/smtpd[28823]: Anonymous TLS connection established from routemea2.hes.trendmicro.eu[52.58.63.9]: TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)
Jan 11 17:02:28 s4 policyd-spf[28829]: None; identity=helo; client-ip=52.58.63.9; helo=routemea2.hes.trendmicro.eu; envelope-from=service@gustini.de; receiver=jf@fahrner.name
Jan 11 17:02:28 s4 policyd-spf[28829]: Permerror; identity=mailfrom; client-ip=52.58.63.9; helo=routemea2.hes.trendmicro.eu; envelope-from=service@gustini.de; receiver=jf@fahrner.name
Jan 11 17:02:28 s4 postfix/smtpd[28823]: E57ED10121A: client=routemea2.hes.trendmicro.eu[52.58.63.9]
Jan 11 17:02:28 s4 postfix/cleanup[28830]: E57ED10121A: message-id=201701111702200632@90426921
Jan 11 17:02:28 s4 opendkim[2642]: E57ED10121A: routemea2.hes.trendmicro.eu [52.58.63.9] not internal
Jan 11 17:02:28 s4 opendkim[2642]: E57ED10121A: not authenticated
Jan 11 17:02:29 s4 opendkim[2642]: E57ED10121A: no signature data
Jan 11 17:02:29 s4 opendmarc[2927]: implicit authentication service: s4.fahrner.name
Jan 11 17:02:29 s4 opendmarc[2927]: E57ED10121A: gustini.de none
Jan 11 17:02:29 s4 spamd[11570]: spamd: got connection over /var/run/spamd.sock
Jan 11 17:02:29 s4 spamd[11570]: spamd: processing message 201701111702200632@90426921 for jf:116
Jan 11 17:02:29 s4 spamd[11570]: spamd: clean message (1.3/5.0) for jf:116 in 0.2 seconds, 177298 bytes.
Jan 11 17:02:29 s4 spamd[11570]: spamd: result: . 1 - BAD_ENC_HEADER,RDNS_NONE,T_OBFU_PDF_ATTACH,UNPARSEABLE_RELAY,URIBL_BLOCKED scantime=0.2,size=177298,user=jf,uid=116,required_score=5.0,rhost=localhost,raddr=127.0.0.1,rport=/var/run/spamd.sock,mid=201701111702200632@90426921,autolearn=no autolearn_force=no
Jan 11 17:02:29 s4 postfix/qmgr[7851]: E57ED10121A: from=service@gustini.de, size=177316, nrcpt=1 (queue active)
Jan 11 17:02:29 s4 postfix/smtpd[28823]: disconnect from routemea2.hes.trendmicro.eu[52.58.63.9]
Jan 11 17:02:29 s4 spamd[11568]: prefork: child states: II
Jan 11 17:02:29 s4 postfix/pipe[28832]: E57ED10121A: to=joachim@xxx.de, orig_to=jf@fahrner.name, relay=dovecot, delay=0.5, delays=0.41/0/0/0.09, dsn=2.0.0, status=sent (delivered via dovecot service)
Jan 11 17:02:29 s4 postfix/qmgr[7851]: E57ED10121A: removed
Jan 11 17:02:29 s4 postfix/postscreen[28814]: PASS NEW [52.58.63.12]:56492
Jan 11 17:02:29 s4 postfix/smtpd[28823]: connect from routemea2.hes.trendmicro.eu[52.58.63.12]
Jan 11 17:02:29 s4 postfix/smtpd[28823]: Anonymous TLS connection established from routemea2.hes.trendmicro.eu[52.58.63.12]: TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)
Jan 11 17:02:29 s4 policyd-spf[28829]: None; identity=helo; client-ip=52.58.63.12; helo=routemea2.hes.trendmicro.eu; envelope-from=service@gustini.de; receiver=jf@fahrner.name
Jan 11 17:02:29 s4 policyd-spf[28829]: Permerror; identity=mailfrom; client-ip=52.58.63.12; helo=routemea2.hes.trendmicro.eu; envelope-from=service@gustini.de; receiver=jf@fahrner.name
Jan 11 17:02:29 s4 postfix/smtpd[28823]: C95EF10121A: client=routemea2.hes.trendmicro.eu[52.58.63.12]
Jan 11 17:02:29 s4 postfix/cleanup[28830]: C95EF10121A: message-id=201701111702210536@06582229
Jan 11 17:02:29 s4 opendkim[2642]: C95EF10121A: routemea2.hes.trendmicro.eu [52.58.63.12] not internal
Jan 11 17:02:29 s4 opendkim[2642]: C95EF10121A: not authenticated
Jan 11 17:02:29 s4 opendkim[2642]: C95EF10121A: no signature data
Jan 11 17:02:29 s4 opendmarc[2927]: implicit authentication service: s4.fahrner.name
Jan 11 17:02:29 s4 opendmarc[2927]: C95EF10121A: gustini.de none
Jan 11 17:02:29 s4 spamd[11570]: spamd: got connection over /var/run/spamd.sock
Jan 11 17:02:29 s4 spamd[11570]: spamd: processing message 201701111702210536@06582229 for jf:116
Jan 11 17:02:30 s4 spamd[11570]: spamd: clean message (1.3/5.0) for jf:116 in 0.2 seconds, 177299 bytes.
Jan 11 17:02:30 s4 spamd[11570]: spamd: result: . 1 - BAD_ENC_HEADER,RDNS_NONE,T_OBFU_PDF_ATTACH,UNPARSEABLE_RELAY,URIBL_BLOCKED scantime=0.2,size=177299,user=jf,uid=116,required_score=5.0,rhost=localhost,raddr=127.0.0.1,rport=/var/run/spamd.sock,mid=201701111702210536@06582229,autolearn=no autolearn_force=no
Jan 11 17:02:30 s4 postfix/qmgr[7851]: C95EF10121A: from=service@gustini.de, size=177318, nrcpt=1 (queue active)
Jan 11 17:02:30 s4 postfix/smtpd[28823]: disconnect from routemea2.hes.trendmicro.eu[52.58.63.12]
Jan 11 17:02:30 s4 spamd[11568]: prefork: child states: II
Jan 11 17:02:30 s4 postfix/pipe[28832]: C95EF10121A: to=joachim@xxx.de, orig_to=jf@fahrner.name, relay=dovecot, delay=0.48, delays=0.4/0/0/0.08, dsn=2.0.0, status=sent (delivered via dovecot service)
Jan 11 17:02:30 s4 postfix/qmgr[7851]: C95EF10121A: removed
participants (3)
-
J. Fahrner -
Patrick Ben Koetter -
Robert Schetterer