Hallo,
ich betreibe seit 5 Jahren einen Postfix-Server als relay für meinen Exchange. Das System ist an sich absolut stabil und zuverlässig.
Einer Userin meldete das sie eine von drei Mails nicht erhalten hatte und bei der Sichtung bin ich auf folgende Logeinträge gestossen.
############## Aug 26 19:58:03 relay postfix/smtpd[24613]: E0CA3144A8B: client=mout.gmx.net[212.227.17.20] Aug 26 19:58:03 relay postfix/cleanup[24616]: E0CA3144A8B: message-id=001501d0e028$c0aaff50$4200fdf0$@gmx.de Aug 26 19:58:03 relay postfix/qmgr[22954]: E0CA3144A8B: from=regina.unbekannt@gmx.de, size=3894, nrcpt=1 (queue active) Aug 26 19:58:04 relay postfix/smtp[24617]: E0CA3144A8B: to=Lena.unbekannt@unbekannt.com, relay=flsv-mail.flitoe.unbekannt.de[10.20.0.20]:25, delay=0.54, delays=0.12/0.01/0/0.4, dsn=2.6.0, status=sent (250 2.6.0 001501d0e028$c0aaff50$4200fdf0$@gmx.de [InternalId=3748098] Queued mail for delivery) Aug 26 19:58:04 relay postfix/qmgr[22954]: E0CA3144A8B: removed ###############
so sieht es richtig aus. Die Mail wurde an den Exchange zugestellt.
Aber hier nicht: ############### Aug 26 10:54:05 relay postfix/smtpd[22178]: 91134144A8B: client=mout.gmx.net[212.227.15.18] Aug 26 10:54:05 relay postfix/cleanup[22180]: 91134144A8B: message-id=trinity-5167db0a-c22e-43ca-bb26-42253bf46019-1440579244775@3capp-gmx-bs23 Aug 26 10:54:05 relay postfix/qmgr[21987]: 91134144A8B: from=Regina.unbekannt@gmx.de, size=107776, nrcpt=1 (queue active) Aug 26 10:54:06 relay postfix/smtp[22150]: 91134144A8B: to=Lena.unbekannt@unbekannt.com, relay=flsv-mail.flitoe.unbekannt.de[10.20.0.20]:25, delay=0.86, delays=0.19/0/0/0.67, dsn=2.0.0, status=sent (250 2.0.0 OK) Aug 26 10:54:06 relay postfix/qmgr[21987]: 91134144A8B: removed ###############
Was kann hier mit dieser Mail passiert sein. Sie ist im Exchange nie angekommen. Der Eintrag dsn=2* besagt ja es wurde zugestellt. Der Satz "Queued mail for delivery" fehlt hier gänzlich.
Kann mir Jemand einen Tip geben, was hier los sein könnte?
LG aus Mühldorf
Joerg Bornholt
Meine config (hab meine Domäne und Namen durch "unbekannt" ersetzt):
(Postfix 2.7.1 auf Debian Squeeze, Exchange 2010)
alias_database = hash:/etc/aliases alias_maps = hash:/etc/aliases append_dot_mydomain = no biff = no config_directory = /etc/postfix inet_interfaces = all local_transport = error:Local delivery disabled! mailbox_command = procmail -a "$EXTENSION" mailbox_size_limit = 0 message_size_limit = 30720000 mydestination = myhostname = relay.unbekannt.com mynetworks = 127.0.0.0/8 [::ffff:127.0.0.0]/104 [::1]/128 myorigin = /etc/mailname readme_directory = no recipient_delimiter = + relay_domains = unbekannt.com relay_recipient_maps = hash:/etc/postfix/relay_recipients relayhost = smtp_tls_session_cache_database = btree:${data_directory}/smtp_scache smtpd_banner = $myhostname ESMTP UNBEKANNT smtpd_recipient_restrictions = reject_non_fqdn_recipient reject_non_fqdn_sender reject_unknown_sender_domain reject_unknown_recipient_domain permit_mynetworks reject_unauth_destination reject_non_fqdn_helo_hostnamereject_invalid_helo_hostname check_helo_access pcre:/etc/postfix/helo_checks check_sender_mx_access cidr:/etc/postfix/bogus_mx permit smtpd_tls_cert_file = /etc/ssl/certs/ssl-cert-snakeoil.pem smtpd_tls_key_file = /etc/ssl/private/ssl-cert-snakeoil.key smtpd_tls_session_cache_database = btree:${data_directory}/smtpd_scache smtpd_use_tls = yes transport_maps = hash:/etc/postfix/transport virtual_alias_maps = hash:/etc/postfix/virtual_alias
Am 01.09.2015 um 15:43 schrieb Jörg Bornholt:
Aber hier nicht: ############### Aug 26 10:54:05 relay postfix/smtpd[22178]: 91134144A8B: client=mout.gmx.net[212.227.15.18] Aug 26 10:54:05 relay postfix/cleanup[22180]: 91134144A8B: message-id=trinity-5167db0a-c22e-43ca-bb26-42253bf46019-1440579244775@3capp-gmx-bs23 Aug 26 10:54:05 relay postfix/qmgr[21987]: 91134144A8B: from=Regina.unbekannt@gmx.de, size=107776, nrcpt=1 (queue active) Aug 26 10:54:06 relay postfix/smtp[22150]: 91134144A8B: to=Lena.unbekannt@unbekannt.com, relay=flsv-mail.flitoe.unbekannt.de[10.20.0.20]:25, delay=0.86, delays=0.19/0/0/0.67, dsn=2.0.0, status=sent (250 2.0.0 OK) Aug 26 10:54:06 relay postfix/qmgr[21987]: 91134144A8B: removed ###############
und was sagen die Logs vom Exchange zu dieser Sache? Es wäre mir noch nie untergekommen, dass Postfix eine Mail, die er via Relay zustellt, aus seiner Queue löschen würde, wenn nicht die Gegenseite eine erfolgreiche Abnahme der Mail bestätigt hätte. Sind irgendwelche Filter im Exchange im Spiel?
Hallo Jörg,
Am 01.09.2015 um 15:43 schrieb Jörg Bornholt:
ich betreibe seit 5 Jahren einen Postfix-Server als relay für meinen Exchange. Das System ist an sich absolut stabil und zuverlässig.
[..]
Zum Vergleich, hier gings:
Aug 26 19:58:04 relay postfix/smtp[24617]: E0CA3144A8B: to=Lena.unbekannt@unbekannt.com, relay=flsv-mail.flitoe.unbekannt.de[10.20.0.20]:25, delay=0.54, delays=0.12/0.01/0/0.4, dsn=2.6.0, status=sent (250 2.6.0 001501d0e028$c0aaff50$4200fdf0$@gmx.de [InternalId=3748098] Queued mail for delivery)
[..]
Was kann hier mit dieser Mail passiert sein. Sie ist im Exchange nie angekommen. Der Eintrag dsn=2* besagt ja es wurde zugestellt. Der Satz "Queued mail for delivery" fehlt hier gänzlich.
Der Teil "250 2.6.0 001501d0e028$c0aaff50$4200fdf0$@gmx.de[InternalId=3748098] Queued mail for delivery)" ist die SMTP-Antwort des Exchange, welchen der Postfix nur zu Informationszwecken ins Logfile schreibt. Das ist also keine Meldung, die der Postfix selbst erstellt.
Wenn da steht:
Aug 26 10:54:06 relay postfix/smtp[22150]: 91134144A8B: to=Lena.unbekannt@unbekannt.com, relay=flsv-mail.flitoe.unbekannt.de[10.20.0.20]:25, delay=0.86, delays=0.19/0/0/0.67, dsn=2.0.0, status=sent (250 2.0.0 OK)
dann ist das aus Postfix-Seite wunderbar, und der gegnerische Mailserver (in Deinem Fall der Exchange) hat nur mit einem "250 2.0.0 OK" geantwortet, aber auch das sagt protokollarisch aus, dass die E-Mail erfolgreich angenommen wurde.
Schau mal im Exchange nach, in der Nachrichtenverfolgung (ich glaub, so heisst das Ding), welche Meldungen Du genau zu dieser Uhrzeit findest, und ob da was dabei ist, was "komisch" ist. Schau auch in den Queues nach, ob da noch was hängt. Und frag doch auch die Empfängerin, was denn in diesen vermissten E-Mails drin sein soll - wenn auch Dein Exchange brav und unaufällig seinen Dienst versieht und nur genau diese drei E-Mails fehlen, und alle von Regina an Lena, könnte auch die E-Mails bzw. der Inhalt der E-Mails der Grund sein. Ich sehe z.B., dass die verschwundene E-Mail einen Anhang hatte bzw. relativ groß war, siehe "size=107776".
Dein Postfix ist nach Lage der Logfiles unschuldig.
Viele Grüße,
Mathias
Hallo,
hatte bisher stets jede Mail gefunden. Ganz sicher im Log des Postfix und auch immer in der Nachrichhtenverfolgung des Exchange. Nachdem ihr alle geschrieben habt das der Exchange die Mail quasi quitiert hat, habe ich dort weiter gesucht. Für das Ergebnis schäme ich mich fast ein wenig, denn der Eset-Anti-Spam hat die Mail aggeriffen. Das erklärt zwar nicht warum Exchange aber auch garnichts davon geloggt hat, aber da hätte ich gleich nachsehen müssen. Aber wie gesagt es kam auch nocht nicht vor das ich eine Mail nicht mehr weiter verfolgen konnte.
Vielen Dank für die Beiträge.
LG Jörg
Mathias Zunterer m.zunterer@link-m.de hat am 2. September 2015 um 08:51 geschrieben:
Hallo Jörg,
Am 01.09.2015 um 15:43 schrieb Jörg Bornholt:
ich betreibe seit 5 Jahren einen Postfix-Server als relay für meinen Exchange. Das System ist an sich absolut stabil und zuverlässig.
[..]
Zum Vergleich, hier gings:
Aug 26 19:58:04 relay postfix/smtp[24617]: E0CA3144A8B: to=Lena.unbekannt@unbekannt.com, relay=flsv-mail.flitoe.unbekannt.de[10.20.0.20]:25, delay=0.54, delays=0.12/0.01/0/0.4, dsn=2.6.0, status=sent (250 2.6.0 001501d0e028$c0aaff50$4200fdf0$@gmx.de [InternalId=3748098] Queued mail for delivery)
[..]
Was kann hier mit dieser Mail passiert sein. Sie ist im Exchange nie angekommen. Der Eintrag dsn=2* besagt ja es wurde zugestellt. Der Satz "Queued mail for delivery" fehlt hier gänzlich.
Der Teil "250 2.6.0 001501d0e028$c0aaff50$4200fdf0$@gmx.de[InternalId=3748098] Queued mail for delivery)" ist die SMTP-Antwort des Exchange, welchen der Postfix nur zu Informationszwecken ins Logfile schreibt. Das ist also keine Meldung, die der Postfix selbst erstellt.
Wenn da steht:
Aug 26 10:54:06 relay postfix/smtp[22150]: 91134144A8B: to=Lena.unbekannt@unbekannt.com, relay=flsv-mail.flitoe.unbekannt.de[10.20.0.20]:25, delay=0.86, delays=0.19/0/0/0.67, dsn=2.0.0, status=sent (250 2.0.0 OK)
dann ist das aus Postfix-Seite wunderbar, und der gegnerische Mailserver (in Deinem Fall der Exchange) hat nur mit einem "250 2.0.0 OK" geantwortet, aber auch das sagt protokollarisch aus, dass die E-Mail erfolgreich angenommen wurde.
Schau mal im Exchange nach, in der Nachrichtenverfolgung (ich glaub, so heisst das Ding), welche Meldungen Du genau zu dieser Uhrzeit findest, und ob da was dabei ist, was "komisch" ist. Schau auch in den Queues nach, ob da noch was hängt. Und frag doch auch die Empfängerin, was denn in diesen vermissten E-Mails drin sein soll - wenn auch Dein Exchange brav und unaufällig seinen Dienst versieht und nur genau diese drei E-Mails fehlen, und alle von Regina an Lena, könnte auch die E-Mails bzw. der Inhalt der E-Mails der Grund sein. Ich sehe z.B., dass die verschwundene E-Mail einen Anhang hatte bzw. relativ groß war, siehe "size=107776".
Dein Postfix ist nach Lage der Logfiles unschuldig.
Viele Grüße,
Mathias
* Jörg Bornholt joerg.bornholt@madit.de:
Hallo,
ich betreibe seit 5 Jahren einen Postfix-Server als relay für meinen Exchange. Das System ist an sich absolut stabil und zuverlässig.
Einer Userin meldete das sie eine von drei Mails nicht erhalten hatte und bei der Sichtung bin ich auf folgende Logeinträge gestossen.
############## Aug 26 19:58:03 relay postfix/smtpd[24613]: E0CA3144A8B: client=mout.gmx.net[212.227.17.20] Aug 26 19:58:03 relay postfix/cleanup[24616]: E0CA3144A8B: message-id=001501d0e028$c0aaff50$4200fdf0$@gmx.de Aug 26 19:58:03 relay postfix/qmgr[22954]: E0CA3144A8B: from=regina.unbekannt@gmx.de, size=3894, nrcpt=1 (queue active) Aug 26 19:58:04 relay postfix/smtp[24617]: E0CA3144A8B: to=Lena.unbekannt@unbekannt.com, relay=flsv-mail.flitoe.unbekannt.de[10.20.0.20]:25, delay=0.54, delays=0.12/0.01/0/0.4, dsn=2.6.0, status=sent (250 2.6.0 001501d0e028$c0aaff50$4200fdf0$@gmx.de [InternalId=3748098] Queued mail for delivery) Aug 26 19:58:04 relay postfix/qmgr[22954]: E0CA3144A8B: removed ###############
so sieht es richtig aus. Die Mail wurde an den Exchange zugestellt.
Aber hier nicht: ############### Aug 26 10:54:05 relay postfix/smtpd[22178]: 91134144A8B: client=mout.gmx.net[212.227.15.18] Aug 26 10:54:05 relay postfix/cleanup[22180]: 91134144A8B: message-id=trinity-5167db0a-c22e-43ca-bb26-42253bf46019-1440579244775@3capp-gmx-bs23 Aug 26 10:54:05 relay postfix/qmgr[21987]: 91134144A8B: from=Regina.unbekannt@gmx.de, size=107776, nrcpt=1 (queue active) Aug 26 10:54:06 relay postfix/smtp[22150]: 91134144A8B: to=Lena.unbekannt@unbekannt.com, relay=flsv-mail.flitoe.unbekannt.de[10.20.0.20]:25, delay=0.86, delays=0.19/0/0/0.67, dsn=2.0.0, status=sent (250 2.0.0 OK) Aug 26 10:54:06 relay postfix/qmgr[21987]: 91134144A8B: removed ###############
Was kann hier mit dieser Mail passiert sein. Sie ist im Exchange nie angekommen. Der Eintrag dsn=2* besagt ja es wurde zugestellt. Der Satz "Queued mail for delivery" fehlt hier gänzlich.
In beiden Fällen war das Ziel die 10.20.0.20. Es wirkt beim Betrachten der Quittung so, also wären zwei unterschiedliche SMTP-Server auf der 10.20.0.20.
Kann mir Jemand einen Tip geben, was hier los sein könnte?
Die IP ist immer die 10.20.0.20. Postfix hat immer zu dieser IP ausgeliefert.
Hat jemand am Netzwerk gedreht? Kann der host, der die 10.20.0.20 besitzt, zeitweise gewechselt haben - einmal der Exchange und ein anderes Mal ein anderer host?
Im Log des Exchange wirst Du sicherlich einen Vermerk für die Mail 3748098 finden. Findest Du auch einen Eintrag für die Mail, die Postfix mit 91134144A8B führt? Möglicherweise (Spekulation!) hat der Exchange auch mal eine Reply gegeben, die nicht dem typischen Schema entsprach.
p@rick
p@rick
p@rick
participants (4)
-
Jörg Bornholt -
Mathias Zunterer -
Patrick Ben Koetter -
Tobi