In some rare cases Postfix connect to a wrong MX server

[Msd]

Hi,

I see on the logs of some of my server some strange lines :

Jan 27 11:39:53 v07 postfix/smtp[11468]: 9CCE614ED3E: to=<email address hidden>, relay=gmail-smtp-in.l.google.com[64.233.184.26]:25, conn_use=2, delay=8.2, delays=0.11/7.9/0.01/0.21, dsn=5.1.1, status=bounced (host gmail-smtp-in.l.google.com[64.233.184.26] said: 550-5.1.1 The email account that you tried to reach does not exist. Please try 550-5.1.1 double-checking the recipient's email address for typos or 550-5.1.1 unnecessary spaces. Learn more at 550 5.1.1 https://support.google.com/mail/answer/6596 h127si11333632wmd.92 - gsmtp (in reply to RCPT TO command))

Here you can see a mail to a yahoo.fr domain and postfix tries to deliver the mail to gmail-smtp-in.l.google.com !

And there is another strange thing : "conn_use=2". Normally, when Postfix uses TLS, he can't reuse a connection and with Gmail, Postfix has to use TLS...

So I look in the smtp process log "11468", just before my line :

Jan 27 11:39:51 v07 postfix/smtp[11468]: SSL_connect error to gmail-smtp-in.l.google.com[64.233.184.26]:25: lost connection
Jan 27 11:39:53 v07 postfix/smtp[11468]: A747014ECAF: Cannot start TLS: handshake failure
Jan 27 11:39:53 v07 postfix/smtp[11468]: Host offered STARTTLS: [gmail-smtp-in.l.google.com]
Jan 27 11:39:53 v07 postfix/smtp[11468]: A747014ECAF: to=<email address hidden>, relay=gmail-smtp-in.l.google.com[64.233.184.26]:25, delay=19, delays=0.22/4.4/14/0.32, dsn=2.0.0, status=sent (250 2.0.0 OK 1453891193 h127si11333632wmd.92 - gsmtp)
Jan 27 11:39:53 v07 postfix/smtp[11468]: 9CCE614ED3E: to=<email address hidden>, relay=gmail-smtp-in.l.google.com[64.233.184.26]:25, conn_use=2, delay=8.2, delays=0.11/7.9/0.01/0.21, dsn=5.1.1, status=bounced (host gmail-smtp-in.l.google.com[64.233.184.26] said: 550-5.1.1 The email account that you tried to reach does not exist. Please try 550-5.1.1 double-checking the recipient's email address for typos or 550-5.1.1 unnecessary spaces. Learn more at 550 5.1.1 https://support.google.com/mail/answer/6596 h127si11333632wmd.92 - gsmtp (in reply to RCPT TO command))
Jan 27 11:39:54 v07 postfix/smtp[11468]: B8CD514ED41: to=<email address hidden>, relay=mx1.free.fr[212.27.48.6]:25, conn_use=2, delay=8.3, delays=0.13/8/0.01/0.11, dsn=2.0.0, status=sent (250 OK)

In fact the TLS Handshake with gmail fails. It is why the connection is not in TLS and why I see "conn_use".

I have a lot of examples like this if you need more (the to address is not always yahoo.fr, sometimes it's outlook.com, aol.com, ...). Every time I saw this bug, it is with gmail-smtp-in.l.google.com and there is TLS Handshake bug.

Do you know what happens ?

[Scott Kitterman (kitterman)]

What's the output of (run on the server that has postfix installed):

postconf -n | grep relay

[Msd (msd+launchpad)]

Hi,

Here is the output of "postconf -n | grep relay" :

relayhost =

Thank you for your help !

[Scott Kitterman (kitterman)]

On Thursday, February 25, 2016 08:55:40 AM you wrote:
> Hi,
>
> Here is the output of "postconf -n | grep relay" :
>
> relayhost =
>
> Thank you for your help !

Do you have any relay map files in /etc/postfix/? If you don't know, please
provide a list of the files present in that directory.

[Msd (msd+launchpad)]

Hi,

I dont' have any relay map file.

Here is my postfix directory.

# tree /etc/postfix/
/etc/postfix/
|-- db
| |-- block_recipient
| `-- block_recipient.db
|-- dynamicmaps.cf
|-- main.cf
|-- main.cf.20151023.120708.bak
|-- master.cf
|-- master.cf.20151023.120708.bak
|-- post-install
|-- postfix-files
|-- postfix-script
|-- sasl
| `-- smtpd.conf
|-- ssl
| |-- cacert.pem
| |-- cakey.pem
| |-- smtpd.crt
| `-- smtpd.key
|-- transport
|-- transport.db
|-- virtual
|-- virtual-regexp
|-- virtual-regexp.db
`-- virtual.db

# cat /etc/postfix/db/block_recipient
XXX@domain1 REJECT
YYY@domain2 REJECT
...

About /etc/postfix/virtual and /etc/postfix/virtual-regexp : no rule in @yahoo, no rule in @gmail, no rule with "generic" (hotmail, aol, ...) domains.

About /etc/postfix/db/block_recipient : Only emails or domains with REJECT

Thanks !

[Scott Kitterman (kitterman)]

I'm not sure what to tell you then as based on the original information in the
bug, postfix thinks it is supposed to relay that domain.

[Msd (msd+launchpad)]

Hi,

Thank you for your help.

I have some news about this bug.

I changed the Postfix config to activate debug log.

And I have caught some errors "wrong MX error". Complete debug logs are attached.

Here an example with all debug logs.

We can see just after a Gmail transaction, the Postfix process tries to deliver a mail for <email address hidden>.

And the DNS reply give the good MX answer :

Mar 1 09:35:50 ns302430 postfix/smtp[1581]: begin ac-rennes.fr address list
Mar 1 09:35:50 ns302430 postfix/smtp[1581]: pref 20 host mxsrv2.ac-rennes.fr/195.221.67.38
Mar 1 09:35:50 ns302430 postfix/smtp[1581]: pref 20 host mxsrv1.ac-rennes.fr/195.221.67.29
Mar 1 09:35:50 ns302430 postfix/smtp[1581]: end ac-rennes.fr address list

But, we can see just after that scache give a Gmail connexion !!!

Mar 1 09:35:50 ns302430 postfix/smtp[1581]: private/scache: wanted attribute: property
Mar 1 09:35:50 ns302430 postfix/smtp[1581]: input attribute name: property
Mar 1 09:35:50 ns302430 postfix/smtp[1581]: input attribute value: gmail.com?gmail-smtp-in.l.google.com?64.233.167.27?4096

Mar 1 09:35:50 ns302430 postfix/smtp[1581]: scache_clnt_find_dest: dest=smtp?*? dest_prop=gmail.com?gmail-smtp-in.l.google.com?64.233.167.27?4096 endp_prop=0?31?1456821449 fd=16
Mar 1 09:35:50 ns302430 postfix/smtp[1581]: smtp_session_activate: dest=gmail.com host=gmail-smtp-in.l.google.com addr=64.233.167.27 port=25 features=0x101f, ttl=99, reuse=1

And the process try to deliver the mail to a wrong MX server...

Mar 1 09:35:50 ns302430 postfix/smtp[1581]: > gmail-smtp-in.l.google.com[64.233.167.27]:25: RSET
Mar 1 09:35:50 ns302430 postfix/smtp[1581]: > gmail-smtp-in.l.google.com[64.233.167.27]:25: MAIL FROM:<email address hidden> SIZE=27032

Mar 1 09:35:50 ns302430 postfix/smtp[1581]: 0D5F218551A: to=<email address hidden>, relay=gmail-smtp-in.l.google.com[64.233.167.27]:25, conn_use=2, delay=582, delays=0.11/581/0.01/0.09, dsn=5.1.1, status=bounced (host gmail-smtp-in.l.google.com[64.233.167.27] said: 550-5.1.1 The email account that you tried to reach does not exist. Please try 550-5.1.1 double-checking the recipient's email address for typos or 550-5.1.1 unnecessary spaces. Learn more at 550 5.1.1 https://support.google.com/mail/answer/6596 x64si24468451wmx.5 - gsmtp (in reply to RCPT TO command))

Note :
1. This bug is rare : most of the time Postfix deliver emails correctly
2. Each time the bug occurs, it's when before there were a TLS error with Gmail and the connection is "scached" (private/scache) / reuse=1 / conn_use=2
3. I have all the debug logs you want and other examples of this bug for yesterday

Can this help ?

[Scott Kitterman (kitterman)]

I would recommend that you write to the postfix-users mailing list about this
as I suspect upstream knowledge will be needed to sort it. When you subscribe
you will get a welcome message that, among other things, gives you specifics
about what information to provide. Read it carefully and provide the
information to the list. Don't assume they'll come here and read the bug.

[Msd (msd+launchpad)]

Hi,

I have contacted the postfix-users mailing list.

This is a known and corrected bug as you can see here :

http://article.gmane.org/gmane.mail.postfix.user/254717
http://www.postfix.org/announcements/postfix-2.11.1.html

But it seems it isn't the case on Ubuntu 14.04 LTS.

Can it be corrected ?

Thank you for your help !

[Robie Basak (racb)]

Thanks Msd and Scott for helping with this.

I presume this is fixed in Xenial, so have marked the bug as Fix Released but created a task to track this for 14.04.

[Scott Kitterman (kitterman)]

On Friday, March 11, 2016 06:24:52 PM you wrote:
> Thanks Msd and Scott for helping with this.
>
> I presume this is fixed in Xenial, so have marked the bug as Fix
> Released but created a task to track this for 14.04.

That's correct. Trusty is the only release affected.

Scott K

[Andreas Hasenack (ahasenack)]

http://linorg.usp.br/postfix/release/official/postfix-2.11-patch01.gz is the upstream patch for 2.11.1, and this appears to be the chunk for the fix:

--- a/postfix/src/smtp/smtp.h
+++ b/postfix/src/smtp/smtp.h
@@ -195,7 +195,7 @@ typedef struct SMTP_STATE {
        STR((state)->iterator->request_nexthop)[0] = 0; \
     }

-#define HAVE_NEXTHOP_STATE(state) (STR((state)->iterator->request_nexthop) != 0)
+#define HAVE_NEXTHOP_STATE(state) (STR((state)->iterator->request_nexthop)[0] != 0)

  /*
diff --git a/postfix/src/smtp/smtp_connect.c b/postfix/src/smtp/smtp_connect.c
index ff278c1f..2e7fc87c 100644
--- a/postfix/src/smtp/smtp_connect.c
+++ b/postfix/src/smtp/smtp_connect.c
@@ -666,6 +666,7 @@ static int smtp_reuse_session(SMTP_STATE *state, DNS_RR **addr_list,
 #endif
     SMTP_ITER_SAVE_DEST(state->iterator);
     if (*addr_list && SMTP_RCPT_LEFT(state) > 0
+ && HAVE_NEXTHOP_STATE(state)
        && (session = smtp_reuse_nexthop(state, SMTP_KEY_MASK_SCACHE_DEST_LABEL)) != 0) {
        session_count = 1;
        smtp_update_addr_list(addr_list, STR(iter->addr), session_count);

Completely untested. It's probably better to go with 2.11.1 directly, or even the last 2.11.x on the series.

[Hector Martin (marcan42)]

Lovely, so Ubuntu did nothing about this nasty bug (sending mail to the wrong servers (!!!)) for 3 years, when all it required was a simple package minor version bump, and now 14.04 support has ended and they can wash their hands.

This kind of nonsense is why I don't recommend Ubuntu.

[Miriam España Acebal (mirespace)]

Hi,

Thank you all for taking the time to report this bug. I came across this bug while doing a cleanup of old bugs (very old indeed). As @Hector said, Trusty reached EOSS (End of Standard Support) so I'm afraid it can't be fixed. It is unfortunate that we were unable to resolve this defect, however, there appears to be no further action possible at this time because it's not a security bug.

As the bug is solved in higher versions that are already incorporated to Ubuntu's newest series, I'll mark the bug as "Won't fix". Please, feel free to mark it as "New" if you consider the bug is affecting current versions.