Emails delivery delay by 2 hours


#1

The mails I receive are showing up approx. after 2 hours in my mailbox.
What are the good initial things to check, which may be wrong?
Thanks in advance!


#2

Does it happen with repeat senders? The first time you get a message from someone we use greylisting to put it on ice (to stop spam), which usually results in about a 10 minute delay. It’s possible it could delay mail for longer, but it is rare and wouldn’t happen if the same sender writes again.


#3

Thanks @joshdata for your revert.
A closer look at logs revealed Google was limiting emails due to “high rate of emails from the IP”.
I have raised it with Google.


#4

Hello,

I’ve been having this problem with a couple of my domains when sending to Google and G Apps.

Here are some logs:

Nov 30 17:46:49 mail postfix/cleanup[20378]: 871611403B0: replace: header Received: from [192.168.0.100] (unknown [86.120.146.94])??(using TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits))??(No client certificate requested)??by mail.domain.tld (Postfix) with ESMT from unknown[86.120.146.94]; from=<diana@anotherdomain.tld> to=<mail@domain.tld> proto=ESMTP helo=<[192.168.0.100]>: Received: from authenticated-user (mail.domain.tld [188.226.242.226])??(using TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits))??(No client certificate requested)??by mail.domain.tld (Postfix) with ESMTPSA id 871611403B0;??Wed, 30 Nov 2016 17:46:49 +0200 (EET)

Nov 30 17:46:51 mail postfix/smtp[20380]: save session smtp&domain.tld&aspmx.l.google.com&74.125.143.27&&5E61B6DC5C08343A32A4F4D03DD3269B9130E25613714A09C4E511C795533378 to smtp cache Nov 30 17:46:51 mail postfix/tlsmgr[21422]: put smtp session id=smtp&domain.tld&aspmx.l.google.com&74.125.143.27&&5E61B6DC5C08343A32A4F4D03DD3269B9130E25613714A09C4E511C795533378 [data 1999 bytes] Nov 30 17:46:51 mail postfix/tlsmgr[21422]: write smtp TLS cache entry smtp&domain.tld&aspmx.l.google.com&74.125.143.27&&5E61B6DC5C08343A32A4F4D03DD3269B9130E25613714A09C4E511C795533378: time=1480520811 [data 1999 bytes] Nov 30 17:46:51 mail postfix/smtp[20380]: aspmx.l.google.com[74.125.143.27]:25: subject_CN=mx.google.com, issuer_CN=Google Internet Authority G2, fingerprint=5E:DC:64:54:5D:7A:67:90:CF:0D:61:86:91:B5:4E:C6, pkey_fingerprint=73:2C:A4:BB:9C:23:3B:D2:40:22:08:CC:4E:64:71:F9 Nov 30 17:46:51 mail postfix/smtp[20380]: Trusted TLS connection established to aspmx.l.google.com[74.125.143.27]:25: TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits) Nov 30 17:46:51 mail postfix/smtp[20380]: 871611403B0: host aspmx.l.google.com[74.125.143.27] said: 450-4.2.1 The user you are trying to contact is receiving mail at a rate that 450-4.2.1 prevents additional messages from being delivered. Please resend your 450-4.2.1 message at a later time. If the user is able to receive mail at that 450-4.2.1 time, your message will be delivered. For more information, please 450-4.2.1 visit 450 4.2.1 https://support.google.com/mail/?p=ReceivingRate x69si7698601wme.157 - gsmtp (in reply to RCPT TO command) Nov 30 17:46:51 mail postfix/smtp[20380]: connect to aspmx.l.google.com[2a00:1450:4013:c05::1a]:25: Network is unreachable Nov 30 17:46:51 mail postfix/smtp[20380]: connect to alt1.aspmx.l.google.com[2404:6800:4003:c02::1b]:25: Network is unreachable Nov 30 17:46:52 mail postfix/smtp[20380]: setting up TLS connection to alt2.aspmx.l.google.com[64.233.187.26]:25 Nov 30 17:46:52 mail postfix/smtp[20380]: alt2.aspmx.l.google.com[64.233.187.26]:25: TLS cipher list "aNULL:-aNULL:ALL:+RC4:@STRENGTH" Nov 30 17:46:52 mail postfix/smtp[20380]: looking for session smtp&domain.tld&alt2.aspmx.l.google.com&64.233.187.26&&5E61B6DC5C08343A32A4F4D03DD3269B9130E25613714A09C4E511C795533378 in smtp cache Nov 30 17:46:52 mail postfix/tlsmgr[21422]: lookup smtp session id=smtp&domain.tld&alt2.aspmx.l.google.com&64.233.187.26&&5E61B6DC5C08343A32A4F4D03DD3269B9130E25613714A09C4E511C795533378 Nov 30 17:46:52 mail postfix/smtp[20380]: SSL_connect:before/connect initialization Nov 30 17:46:52 mail postfix/smtp[20380]: SSL_connect:unknown state Nov 30 17:46:53 mail spampd[30322]: clean message <4761071e-9336-cbca-5d15-912df2623150@anotherdomain.tld> (-1.10/5.00) from <diana@anotherdomain.tld> for <andreea@anotherdomain.tld> in 3.23s, 14326 bytes. Nov 30 17:46:53 mail dovecot: lmtp(20381, andreea@anotherdomain.tld): hKL6Lmn0PlidTwAAvHPqVw: sieve: msgid=<4761071e-9336-cbca-5d15-912df2623150@anotherdomain.tld>: stored mail into mailbox 'INBOX' Nov 30 17:46:53 mail postfix/lmtp[20379]: 871611403B0: to=<andreea@anotherdomain.tld>, relay=127.0.0.1[127.0.0.1]:10025, delay=3.7, delays=0.35/0.02/0.02/3.3, dsn=2.0.0, status=sent (250 2.0.0 <andreea@anotherdomain.tld> hKL6Lmn0PlidTwAAvHPqVw Saved) Nov 30 17:46:53 mail dovecot: lmtp(20381): Disconnect from 127.0.0.1: Successful quit Nov 30 17:46:53 mail postfix/smtp[20380]: SSL_connect:SSLv3 read server hello A Nov 30 17:46:53 mail postfix/smtp[20380]: alt2.aspmx.l.google.com[64.233.187.26]:25: depth=3 verify=1 subject=/C=US/O=Equifax/OU=Equifax Secure Certificate Authority Nov 30 17:46:53 mail postfix/smtp[20380]: alt2.aspmx.l.google.com[64.233.187.26]:25: depth=2 verify=1 subject=/C=US/O=GeoTrust Inc./CN=GeoTrust Global CA Nov 30 17:46:53 mail postfix/smtp[20380]: alt2.aspmx.l.google.com[64.233.187.26]:25: depth=1 verify=1 subject=/C=US/O=Google Inc/CN=Google Internet Authority G2 Nov 30 17:46:53 mail postfix/smtp[20380]: alt2.aspmx.l.google.com[64.233.187.26]:25: depth=0 verify=1 subject=/C=US/ST=California/L=Mountain View/O=Google Inc/CN=mx.google.com Nov 30 17:46:53 mail postfix/smtp[20380]: SSL_connect:SSLv3 read server certificate A Nov 30 17:46:53 mail postfix/smtp[20380]: SSL_connect:SSLv3 read server key exchange A Nov 30 17:46:53 mail postfix/smtp[20380]: SSL_connect:SSLv3 read server done A Nov 30 17:46:53 mail postfix/smtp[20380]: SSL_connect:SSLv3 write client key exchange A Nov 30 17:46:53 mail postfix/smtp[20380]: SSL_connect:SSLv3 write change cipher spec A Nov 30 17:46:53 mail postfix/smtp[20380]: SSL_connect:SSLv3 write finished A Nov 30 17:46:53 mail postfix/smtp[20380]: SSL_connect:SSLv3 flush data Nov 30 17:46:53 mail postfix/smtp[20380]: SSL_connect:SSLv3 read server session ticket A Nov 30 17:46:53 mail postfix/smtp[20380]: SSL_connect:SSLv3 read finished A Nov 30 17:46:53 mail postfix/smtp[20380]: save session smtp&domain.tld&alt2.aspmx.l.google.com&64.233.187.26&&5E61B6DC5C08343A32A4F4D03DD3269B9130E25613714A09C4E511C795533378 to smtp cache Nov 30 17:46:53 mail postfix/tlsmgr[21422]: put smtp session id=smtp&domain.tld&alt2.aspmx.l.google.com&64.233.187.26&&5E61B6DC5C08343A32A4F4D03DD3269B9130E25613714A09C4E511C795533378 [data 1999 bytes] Nov 30 17:46:53 mail postfix/tlsmgr[21422]: write smtp TLS cache entry smtp&domain.tld&alt2.aspmx.l.google.com&64.233.187.26&&5E61B6DC5C08343A32A4F4D03DD3269B9130E25613714A09C4E511C795533378: time=1480520813 [data 1999 bytes] Nov 30 17:46:53 mail postfix/smtp[20380]: alt2.aspmx.l.google.com[64.233.187.26]:25: subject_CN=mx.google.com, issuer_CN=Google Internet Authority G2, fingerprint=5E:DC:64:54:5D:7A:67:90:CF:0D:61:86:91:B5:4E:C6, pkey_fingerprint=73:2C:A4:BB:9C:23:3B:D2:40:22:08:CC:4E:64:71:F9 Nov 30 17:46:53 mail postfix/smtp[20380]: Trusted TLS connection established to alt2.aspmx.l.google.com[64.233.187.26]:25: TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits) Nov 30 17:46:54 mail postfix/smtp[20380]: 871611403B0: to=<mail@domain.tld>, relay=alt2.aspmx.l.google.com[64.233.187.26]:25, delay=4.8, delays=0.35/0.05/4/0.4, dsn=4.2.1, status=deferred (host alt2.aspmx.l.google.com[64.233.187.26] said: 450-4.2.1 The user you are trying to contact is receiving mail at a rate that 450-4.2.1 prevents additional messages from being delivered. Please resend your 450-4.2.1 message at a later time. If the user is able to receive mail at that 450-4.2.1 time, your message will be delivered. For more information, please 450-4.2.1 visit 450 4.2.1 https://support.google.com/mail/?p=ReceivingRate y69si36454911plh.311 - gsmtp (in reply to RCPT TO command))

here, domain.tld is hosted on G Apps and anotherdomain.tld is hosted with MailInABox.

@JoshData - I’ve been trying to get a solution for this for the last couple of weeks when we’ve first noticed it. I do respect a whole lot what you’ve built here, and I don’t want to burden you with more problems. If you have the time to glance over the logs, I’m sure you’ll be able to find some hints. Thanks very much!

ps:

here are the mail headers from the actual email saved to the user’s sent folder:

`Reply-To: diana@anotherdomain.tld
Subject: Re: rename mobi feedback
References: mrseu6htmwlslmaqmxsxenlp.1480507572935@email.android.com
CABGUcY=vhdFQxUSfscYWF-=gzi3yKDu6_RAeS8JrV_4xDueNVQ@mail.gmail.com
To: “Sorin [domain.tld]” mail@domain.tld
Cc: “andreea@anotherdomain.tld” andreea@anotherdomain.tld
From: Diana Bangala diana@anotherdomain.tld
Message-ID: 4761071e-9336-cbca-5d15-912df2623150@anotherdomain.tld
Date: Wed, 30 Nov 2016 17:46:50 +0200
User-Agent: Mozilla/5.0 (Windows NT 10.0; WOW64; rv:45.0) Gecko/20100101
Thunderbird/45.5.0
MIME-Version: 1.0
In-Reply-To: CABGUcY=vhdFQxUSfscYWF-=gzi3yKDu6_RAeS8JrV_4xDueNVQ@mail.gmail.com
Content-Type: multipart/alternative;
boundary="------------222F7ED8AD9BCA3144F9846E"

This is a multi-part message in MIME format.
--------------222F7ED8AD9BCA3144F9846E
Content-Type: text/plain; charset=utf-8; format=flowed
Content-Transfer-Encoding: 7bit`


#5

Is there a way to disable it? I want to receive emails as fast as possible (especially annoying when it’s about some verification code).


#6

Same question - also, it would be nice if this other greylisting topic were re-opened - as it is dealing with whitelisting:

https://discourse.mailinabox.email/t/postgrey-whitelist-clients-update/4016/4


#7

To disable greylisting you need to remove the postgrey server from the postfix recipient restrictions. To view this value, use the postconf command like this:

postconf smtpd_recipient_restrictions

You should get output that looks like this:

smtpd_recipient_restrictions = permit_sasl_authenticated,permit_mynetworks,reject_rbl_client zen.spamhaus.org,reject_unlisted_recipient,check_policy_service inet:127.0.0.1:10023

To disable greylisting remove the check_policy_service inet:127.0.0.1:10023 from the end of this setting. To do that issue the command:

postconf -e "smtpd_recipient_restrictions=permit_sasl_authenticated,permit_mynetworks,reject_rbl_client zen.spamhaus.org,reject_unlisted_recipient"

However, the next time you update MiaB, it will be set back to use greylisting, so you need to issue this command after every update or install. You should also check this line after updates to see if any changes have been made in the update.


#8

If you want to add entries to the whitelist for greylisting, you can add them to:

/etc/postgrey/whitelist_clients.local

Changes made to this file will not be overwritten by MiaB or Postgrey updates.


#9

Thank you, for myself I’ve just changed the postgrey options to set the greylisting time to zero, so far so good… :slight_smile:


#10

Please be careful with this. You might get much more spam with this new configuration.


#11

I don’t have spam on this email yet… Also I’d prefer to have spam than wait for a good emails :slight_smile:


#12

That was a clever hack. I looked a little bit at the Postgrey code and it looks like that should work. The only side-effect is that I think it might be adding all repeat senders to the whitelist. So if you go back to using greylisting you might want to zero out your postgrey database.