Google Groups no longer supports new Usenet posts or subscriptions. Historical content remains viewable.
Dismiss

MTA Deferring e-mail

102 views
Skip to first unread message

Jason T. Slack-Moehrle

unread,
Oct 1, 2012, 5:35:20 PM10/1/12
to
Zimbra 7.1.2 and the MTA seems to be deferring e-mail when it is received.

Oct 1 09:35:42 www postfix/error[16614]: 5FB8C1A803EE: to=<x...@xxx.xx>,
relay=none, delay=0.15, delays=0.08/0.01/0/0.06, dsn=4.4.1,
status=deferred (delivery
temporarily suspended: connect to
thedigiologygroup.org[75.149.56.27]:7025: Connection
timed out)

I can telnet to both 25 and 7025.

I do get a

$ telnet thedigiologygroup.org 25
Trying 75.149.56.27...
Connected to thedigiologygroup.org.
Escape character is '^]'.
220 thedigiologygroup.org ESMTP Postfix

500 5.5.2 Error: bad syntax

500 5.5.2 Error: bad syntax`

I dont see email in the inbox obviously and I am not sure how to
troubleshoot what is going on.

Nothing DNS has changed.

This box has been running for a year

Zimbra was removed and re-installed after trying to upgrade to ZCS-8
with no luck.

Here is an example it I tail the log and watch the message come in

Oct 1 14:30:06 www zmmailboxdmgr[9369]: status OK
Oct 1 14:31:34 www postfix/smtpd[9570]: connect from
mail-lb0-f181.google.com[209.85.217.181]
Oct 1 14:31:35 www postfix/smtpd[9570]: setting up TLS connection
from mail-lb0-f181.google.com[209.85.217.181]
Oct 1 14:31:35 www postfix/smtpd[9570]: Anonymous TLS connection
established from mail-lb0-f181.google.com[209.85.217.181]: TLSv1 with
cipher RC4-SHA (128/128 bits)
Oct 1 14:31:36 www postfix/smtpd[9570]: 1DD9A1A80452:
client=mail-lb0-f181.google.com[209.85.217.181]
Oct 1 14:31:36 www postfix/cleanup[9575]: 1DD9A1A80452:
message-id=<CAEyvkJM1Ry0232LhHTyrW7ajHOZW+-62rBv9qX1=gBMmu...@mail.gmail.com>
Oct 1 14:31:36 www postfix/qmgr[15204]: 1DD9A1A80452:
from=<x...@gmail.com>, size=1651, nrcpt=1 (queue active)
Oct 1 14:31:36 www amavis[14927]: (14927-02) ESMTP::10024
/opt/zimbra/data/amavisd/tmp/amavis-20121001T094644-14927:
<x...@gmail.com> -> <x...@ouremail.us> SIZE=1651 Received: from
thedigiologygroup.org ([127.0.0.1]) by localhost
(thedigiologygroup.org [127.0.0.1]) (amavisd-new, port 10024) with
ESMTP for <x...@ouremail.us>; Mon, 1 Oct 2012 14:31:36 -0700 (PDT)
Oct 1 14:31:36 www amavis[14927]: (14927-02) Checking: U0Cg+GK5fRMh
[209.85.217.181] <x...@gmail.com> -> <x...@ouremail.us>
Oct 1 14:31:36 www clamd[14992]: SelfCheck: Database status OK.
Oct 1 14:31:37 www postfix/smtpd[9579]: connect from
localhost.localdomain[127.0.0.1]
Oct 1 14:31:37 www postfix/smtpd[9579]: 553821A80458:
client=localhost.localdomain[127.0.0.1]
Oct 1 14:31:37 www postfix/cleanup[9575]: 553821A80458:
message-id=<CAEyvkJM1Ry0232LhHTyrW7ajHOZW+-62rBv9qX1=gBMmu...@mail.gmail.com>
Oct 1 14:31:37 www postfix/qmgr[15204]: 553821A80458:
from=<x...@gmail.com>, size=2486, nrcpt=1 (queue active)
Oct 1 14:31:37 www amavis[14927]: (14927-02) FWD via SMTP:
<x...@gmail.com> -> <x...@ouremail.us>,BODY=7BIT 250 2.0.0 from
MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as 553821A80458
Oct 1 14:31:37 www postfix/smtpd[9579]: disconnect from
localhost.localdomain[127.0.0.1]
Oct 1 14:31:37 www postfix/qmgr[15204]: warning: connect to transport
private/lsmtp: No such file or directory
Oct 1 14:31:37 www amavis[14927]: (14927-02) Passed CLEAN,
[209.85.217.181] [209.85.217.181] <x...@gmail.com> ->
<x...@ouremail.us>, Message-ID:
<CAEyvkJM1Ry0232LhHTyrW7ajHOZW+-62rBv9qX1=gBMmu...@mail.gmail.com>,
mail_id: U0Cg+GK5fRMh, Hits: -2.7, size: 1651, queued_as:
553821A80458, dkim_id=@gmail.com, 771 ms
Oct 1 14:31:37 www postfix/smtp[9576]: 1DD9A1A80452:
to=<x...@ouremail.us>, relay=127.0.0.1[127.0.0.1]:10024, delay=1.5,
delays=0.74/0.01/0/0.77, dsn=2.0.0, status=sent (250 2.0.0 from
MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as 553821A80458)
Oct 1 14:31:37 www postfix/qmgr[15204]: 1DD9A1A80452: removed
Oct 1 14:31:37 www amavis[14927]: (14927-02) extra modules loaded:
unicore/lib/gc_sc/Alnum.pl, unicore/lib/gc_sc/Alpha.pl
Oct 1 14:31:37 www postfix/error[9580]: 553821A80458:
to=<ja...@ouremail.us>, relay=none, delay=0.15,
delays=0.07/0.02/0/0.07, dsn=4.3.0, status=deferred (mail transport
unavailable)

I can send mail out to GMail, however.

Ports seem open:
PORT STATE SERVICE
25/tcp open smtp
80/tcp open http
110/tcp open pop3
111/tcp open rpcbind
143/tcp open imap
443/tcp open https
465/tcp open smtps
587/tcp open submission
631/tcp open ipp
993/tcp open imaps
995/tcp open pop3s
3306/tcp open mysql
5222/tcp open xmpp-client
5269/tcp open xmpp-server
7025/tcp open vmsvc-2
7777/tcp open cbt
10024/tcp open unknown
10025/tcp open unknown

Can anyone help me see what is going wrong? This was working before
attempting a failed upgrade.

-Jason

Wietse Venema

unread,
Oct 1, 2012, 5:51:15 PM10/1/12
to
Jason T. Slack-Moehrle:
> Oct 1 14:31:37 www postfix/qmgr[15204]: warning: connect to transport
> private/lsmtp: No such file or directory

Fix that.

Wietse

Jason T. Slack-Moehrle

unread,
Oct 1, 2012, 6:10:38 PM10/1/12
to
Hi Wietse,

>> Oct 1 14:31:37 www postfix/qmgr[15204]: warning: connect to transport
>> private/lsmtp: No such file or directory
>
> Fix that.

I am not sure where it expects `private/lsmtp` to be located though.

-Jason

Viktor Dukhovni

unread,
Oct 1, 2012, 6:24:02 PM10/1/12
to
By fix that, what is meant is to not typo the names of transports
in main.cf and FILTER rules in access tables.

You almost certainly mean "lmtp"...

--
Viktor.

Jason T. Slack-Moehrle

unread,
Oct 1, 2012, 7:16:21 PM10/1/12
to
I noticed that, a typo from earlier.

But now it seems I cannot send, nor receive e-mail:

Oct 1 16:12:05 www zmmailboxdmgr[25272]: status OK
Oct 1 16:12:20 www postfix/smtpd[25394]: connect from mail[192.168.1.27]
Oct 1 16:12:20 www postfix/smtpd[25394]: A6EDD1A8043C:
client=mail[192.168.1.27]
Oct 1 16:12:20 www postfix/cleanup[25398]: A6EDD1A8043C:
message-id=<1344622638.2.1349133...@ouremail.us>
Oct 1 16:12:20 www postfix/qmgr[24672]: A6EDD1A8043C:
from=<x...@ouremail.us>, size=600, nrcpt=2 (queue active)
Oct 1 16:12:20 www postfix/smtpd[25394]: disconnect from mail[192.168.1.27]
Oct 1 16:12:20 www amavis[20527]: (20527-01) ESMTP::10024
/opt/zimbra/data/amavisd/tmp/amavis-20121001T161220-20527:
<ja...@ouremail.us> -> <x...@gmail.com>,<x...@thedigiologygroup.org>
SIZE=600 Received: from thedigiologygroup.org ([127.0.0.1]) by
localhost (thedigiologygroup.org [127.0.0.1]) (amavisd-new, port
10024) with ESMTP; Mon, 1 Oct 2012 16:12:20 -0700 (PDT)
Oct 1 16:12:20 www amavis[20527]: (20527-01) Checking: Fhh+FWfhscEU
MYNETS [192.168.1.27] <x...@ouremail.us> ->
<x...@gmail.com>,<x...@thedigiologygroup.org>
Oct 1 16:12:21 www postfix/smtpd[25403]: connect from
localhost.localdomain[127.0.0.1]
Oct 1 16:12:21 www postfix/smtpd[25403]: 2A6051A80445:
client=localhost.localdomain[127.0.0.1]
Oct 1 16:12:21 www postfix/cleanup[25398]: 2A6051A80445:
message-id=<1344622638.2.1349133...@ouremail.us>
Oct 1 16:12:21 www postfix/qmgr[24672]: 2A6051A80445:
from=<x...@ouremail.us>, size=1048, nrcpt=1 (queue active)
Oct 1 16:12:21 www amavis[20527]: (20527-01) FWD via SMTP:
<x...@ouremail.us> -> <x...@gmail.com>,BODY=7BIT 250 2.0.0 from
MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as 2A6051A80445
Oct 1 16:12:21 www postfix/smtpd[25403]: 4972C1A80447:
client=localhost.localdomain[127.0.0.1]
Oct 1 16:12:21 www postfix/cleanup[25398]: 4972C1A80447:
message-id=<1344622638.2.1349133...@ouremail.us>
Oct 1 16:12:21 www postfix/qmgr[24672]: 4972C1A80447:
from=<x...@ouremail.us>, size=1249, nrcpt=1 (queue active)
Oct 1 16:12:21 www amavis[20527]: (20527-01) FWD via SMTP:
<x...@ouremail.us> -> <x...@thedigiologygroup.org>,BODY=7BIT 250 2.0.0
from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as 4972C1A80447
Oct 1 16:12:21 www amavis[20527]: (20527-01) Passed CLEAN, MYNETS
LOCAL [192.168.1.27] [192.168.1.27] <x...@ouremail.us> ->
<x...@gmail.com>,<x...@thedigiologygroup.org>, Message-ID:
<1344622638.2.1349133...@ouremail.us>, mail_id:
Fhh+FWfhscEU, Hits: -1.106, size: 600, queued_as:
2A6051A80445/4972C1A80447, 571 ms
Oct 1 16:12:21 www postfix/smtp[25400]: A6EDD1A8043C:
to=<x...@gmail.com>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.71,
delays=0.13/0.01/0.01/0.57, dsn=2.0.0, status=sent (250 2.0.0 from
MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as 2A6051A80445)
Oct 1 16:12:21 www postfix/smtp[25400]: A6EDD1A8043C:
to=<x...@thedigiologygroup.org>, relay=127.0.0.1[127.0.0.1]:10024,
delay=0.71, delays=0.13/0.01/0.01/0.57, dsn=2.0.0, status=sent (250
2.0.0 from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as
2A6051A80445)
Oct 1 16:12:21 www postfix/qmgr[24672]: A6EDD1A8043C: removed
Oct 1 16:12:21 www amavis[20527]: (20527-01) extra modules loaded:
/opt/zimbra/zimbramon/lib/x86_64-linux-thread-multi/auto/Net/SSLeay/autosplit.ix,
/opt/zimbra/zimbramon/lib/x86_64-linux-thread-multi/auto/Net/SSLeay/randomize.al,
/usr/lib64/perl5/vendor_perl/auto/Net/LibIDN/autosplit.ix,
IO/Socket/SSL.pm, Net/LDAP/Extension.pm, Net/LibIDN.pm, Net/SSLeay.pm
Oct 1 16:12:21 www postfix/lmtp[25404]: 4972C1A80447:
to=<x...@thedigiologygroup.org>,
relay=thedigiologygroup.org[192.168.1.27]:7025, delay=0.29,
delays=0.07/0.01/0/0.2, dsn=2.1.5, status=sent (250 2.1.5 Delivery OK)
Oct 1 16:12:21 www postfix/qmgr[24672]: 4972C1A80447: removed
Oct 1 16:12:29 www zmmailboxdmgr[25495]: status requested
Oct 1 16:12:29 www zmmailboxdmgr[25495]: status OK
Oct 1 16:12:30 www zmmailboxdmgr[25504]: status requested
Oct 1 16:12:30 www zmmailboxdmgr[25504]: status OK
Oct 1 16:12:51 www postfix/smtp[24675]: connect to
gmail.com[74.125.224.149]:25: Connection timed out
Oct 1 16:13:12 www postfix/smtpd[23012]: timeout after END-OF-MESSAGE
from localhost.localdomain[127.0.0.1]
Oct 1 16:13:12 www postfix/smtpd[23012]: disconnect from
localhost.localdomain[127.0.0.1]
Oct 1 16:13:21 www postfix/smtp[24675]: connect to
gmail.com[74.125.224.150]:25: Connection timed out
Oct 1 16:13:21 www postfix/smtp[24675]: 2A6051A80445:
to=<x...@gmail.com>, relay=none, delay=60, delays=0.12/0.01/60/0,
dsn=4.4.1, status=deferred (connect to gmail.com[74.125.224.150]:25:
Connection timed out)

Jason T. Slack-Moehrle

unread,
Oct 1, 2012, 7:35:32 PM10/1/12
to
So it looks like incoming e-mail might be working now, outgoing not so much.

Oct 1 16:33:32 www clamd[20590]: SelfCheck: Database status OK.
Oct 1 16:33:33 www postfix/smtpd[32650]: connect from
localhost.localdomain[127.0.0.1]
Oct 1 16:33:33 www postfix/smtpd[32650]: 64D131A8045E:
client=localhost.localdomain[127.0.0.1]
Oct 1 16:33:33 www postfix/cleanup[3358]: 64D131A8045E:
message-id=<1989555850.5.1349134...@ouremail.us>
Oct 1 16:33:33 www postfix/qmgr[24672]: 64D131A8045E:
from=<x...@ouremail.us>, size=1399, nrcpt=1 (queue active)
Oct 1 16:33:33 www amavis[20533]: (20533-01) FWD via SMTP:
<x...@ouremail.us> -> <x...@gmail.com>,BODY=7BIT 250 2.0.0 from
MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as 64D131A8045E
Oct 1 16:33:33 www amavis[20533]: (20533-01) Passed CLEAN, MYNETS
LOCAL [192.168.1.27] [192.168.1.27] <x...@ouremail.us> ->
<x...@gmail.com>, Message-ID:
<1989555850.5.1349134...@ouremail.us>, mail_id:
dVByAWcL3Dcp, Hits: -1.106, size: 920, queued_as: 64D131A8045E, 836 ms
Oct 1 16:33:33 www postfix/smtp[3359]: 8F3BF1A80459:
to=<x...@gmail.com>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.97,
delays=0.12/0.01/0.01/0.83, dsn=2.0.0, status=sent (250 2.0.0 from
MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as 64D131A8045E)
Oct 1 16:33:33 www postfix/qmgr[24672]: 8F3BF1A80459: removed
Oct 1 16:33:33 www amavis[20533]: (20533-01) extra modules loaded:
/opt/zimbra/zimbramon/lib/x86_64-linux-thread-multi/auto/Net/SSLeay/autosplit.ix,
/opt/zimbra/zimbramon/lib/x86_64-linux-thread-multi/auto/Net/SSLeay/randomize.al,
/usr/lib64/perl5/vendor_perl/auto/Net/LibIDN/autosplit.ix,
IO/Socket/SSL.pm, Net/LDAP/Extension.pm, Net/LibIDN.pm, Net/SSLeay.pm
Oct 1 16:34:03 www postfix/smtp[3362]: connect to
gmail.com[74.125.224.149]:25: Connection timed out
Oct 1 16:34:05 www zmmailboxdmgr[3687]: status requested
Oct 1 16:34:05 www zmmailboxdmgr[3687]: status OK
Oct 1 16:34:18 www zmmailboxdmgr[3896]: status requested
Oct 1 16:34:18 www zmmailboxdmgr[3896]: status OK
Oct 1 16:34:18 www zmmailboxdmgr[3905]: status requested
Oct 1 16:34:18 www zmmailboxdmgr[3905]: status OK

Wietse Venema

unread,
Oct 1, 2012, 7:47:06 PM10/1/12
to
Jason T. Slack-Moehrle:
> Oct 1 16:34:03 www postfix/smtp[3362]: connect to
> gmail.com[74.125.224.149]:25: Connection timed out

You have configured Postfix to connect to gmail.com instead of the
MX HOSTS for gmail.com.

If this is gobbledygook, I suggest that you send output
from "postconf -n".

Wietse

/dev/rob0

unread,
Oct 1, 2012, 7:57:03 PM10/1/12
to
On Mon, Oct 01, 2012 at 04:35:32PM -0700, Jason T. Slack-Moehrle
wrote:
> So it looks like incoming e-mail might be working now, outgoing
> not so much.

> Oct 1 16:34:03 www postfix/smtp[3362]: connect to
> gmail.com[74.125.224.149]:25: Connection timed out

This looks quite like a "disable_dns_lookups=yes" issue. The question
then would be: how was it working before?

$ for Mx in $(dig gmail.com. mx +short | cut -f2 -d\ ) ; do host -tA $Mx ; done
gmail-smtp-in.l.google.com has address 173.194.73.26
alt2.gmail-smtp-in.l.google.com has address 173.194.70.26
alt4.gmail-smtp-in.l.google.com has address 74.125.143.27
alt1.gmail-smtp-in.l.google.com has address 173.194.65.26
alt3.gmail-smtp-in.l.google.com has address 173.194.69.26

None of those are 74.125.224.149 and none are called "gmail.com".
--
http://rob0.nodns4.us/ -- system administration and consulting
Offlist GMX mail is seen only if "/dev/rob0" is in the Subject:

Jason T. Slack-Moehrle

unread,
Oct 1, 2012, 8:56:06 PM10/1/12
to
>> So it looks like incoming e-mail might be working now, outgoing
>> not so much.
>
>> Oct 1 16:34:03 www postfix/smtp[3362]: connect to
>> gmail.com[74.125.224.149]:25: Connection timed out
>
> This looks quite like a "disable_dns_lookups=yes" issue. The question
> then would be: how was it working before?

$ postconf -n
disable_dns_lookups = yes

I now changed it to 'no' and things seem to be working again.

I dont understand why, though, this would be creating the problem.
Could you explain? If it creates this problem, why do people set it?

-Jason

Reindl Harald

unread,
Oct 2, 2012, 4:02:35 AM10/2/12
to


Am 02.10.2012 02:56, schrieb Jason T. Slack-Moehrle:
>>> So it looks like incoming e-mail might be working now, outgoing
>>> not so much.
>>
>>> Oct 1 16:34:03 www postfix/smtp[3362]: connect to
>>> gmail.com[74.125.224.149]:25: Connection timed out
>>
>> This looks quite like a "disable_dns_lookups=yes" issue. The question
>> then would be: how was it working before?
>
> $ postconf -n
> disable_dns_lookups = yes
>
> I now changed it to 'no' and things seem to be working again.
>
> I dont understand why, though, this would be creating the problem.
> Could you explain?

see docs: http://www.postfix.org/postconf.5.html#disable_dns_lookups

disable_dns_lookups (default: no)

> If it creates this problem, why do people set it?

nobody does set it global

it makes sense on internal transports like LMTP in
master.cf but NOT as global setting!

dbmail-lmtp unix - - n - - lmtp -o disable_dns_lookups=yes -o max_use=100




signature.asc

/dev/rob0

unread,
Oct 2, 2012, 9:42:19 AM10/2/12
to
On Tue, Oct 02, 2012 at 10:02:35AM +0200, Reindl Harald wrote:
> Am 02.10.2012 02:56, schrieb Jason T. Slack-Moehrle:
> >>> So it looks like incoming e-mail might be working now, outgoing
> >>> not so much.
> >>
> >>> Oct 1 16:34:03 www postfix/smtp[3362]: connect to
> >>> gmail.com[74.125.224.149]:25: Connection timed out
> >>
> >> This looks quite like a "disable_dns_lookups=yes" issue. The
> >> question then would be: how was it working before?
> >
> > $ postconf -n
> > disable_dns_lookups = yes
> >
> > I now changed it to 'no' and things seem to be working again.
> >
> > I dont understand why, though, this would be creating the
> > problem. Could you explain?
>
> see docs: http://www.postfix.org/postconf.5.html#disable_dns_lookups
>
> disable_dns_lookups (default: no)

The higher-level explanation is that by using the getaddrinfo()
system library routine, you are not able to look up the MX records
which control mail routing.

> > If it creates this problem, why do people set it?

The better question: why did Jason set it? :) Don't change defaults
if you don't understand them.

> nobody does set it global
>
> it makes sense on internal transports like LMTP in
> master.cf but NOT as global setting!
>
> dbmail-lmtp unix - - n - - lmtp -o disable_dns_lookups=yes -o max_use=100

It might also simplify things in a relayhost + transport_maps
configuration, but that is not really important. Bottom line here:
Postfix comes with a lot of knobs and dials you can tweak and turn.
Resist the urge. :)
0 new messages