T=remote_smtp defer (-53): retry time not reached for any host

Check to see if your domain is on some blacklist: Email Blacklist Check - See if your server is blacklisted

Cheers - Bob

I'm getting a similar thing - heaps of

"R=static_route_hostlist T=static_smtp defer (-53): retry time not reached for any host"

errors in my SMTP log, and lots of unhappy users wanting to know why they are not getting emails, or why they are delayed for days.

Is there anyway to tell Astaro to force send these emails to my mail server?

Thanks,

James.

Wait a minute, JL, that's a different problem.  The first post here is about outbound email, and the issue from the German Forum would have this effect on outbound emails.  I don't think it should affect inbound.

What else do you see in the SMTP log when the Astaro first tries to deliver one of the mails?  Have you tried the DNS flush from Post #6 above?

Cheers - Bob

You are right Bob. Inbound is the problem for me. I should have read the first message properly. My error message starts with "R=static_route_hostlist" not "R-dnslookup".

I couldn't run the CLI command to flush the DNS as I don't know the login username and password (I have emailed the person who did the install but haven't heard back).

I will look into the logs the next time I notice one getting blocked. At the moment I'm constantly looking at the Mail Manager SMTP Queue and clicking on the Retry button, so at least my users are happy that they are getting their mail on time now.

Thanks,

James.

James, You should be able to look at the log entries for a specific email.  Use 'Search Log Files' and look for the title of the email that got delayed.  That will give you a specific time to search for where you can look through the SMTP log to find the other entries related to that email.

I'll email you about getting to the command line.

Cheers - Bob

OK. Log says:

2009:05:12-22:01:22 astaro1-1 exim[28996]: 2009-05-12 22:01:22 SMTP connection from [91.205.173.28]:57134 (TCP/IP connection count = 1)

2009:05:12-22:01:26 astaro1-1 exim[8421]: 2009-05-12 22:01:26 H=(mx28.looksmartbank.com) [91.205.173.28]:57134 Warning: Exception matched: Skipping greylisting for this message

2009:05:12-22:01:26 astaro1-1 exim[8421]: 2009-05-12 22:01:26 H=(mx28.looksmartbank.com) [91.205.173.28]:57134 Warning: Exception matched: Skipping antispam for this message

2009:05:12-22:01:26 astaro1-1 exim[8421]: 2009-05-12 22:01:26 H=(mx28.looksmartbank.com) [91.205.173.28]:57134 Warning: bordo.com.au profile excludes greylisting: Skipping greylisting for this message

2009:05:12-22:01:26 astaro1-1 exim[8421]: 2009-05-12 22:01:26 [91.205.173.28] F= R= Verifying recipient address with callout

2009:05:12-22:01:43 astaro1-1 exim[8421]: 2009-05-12 22:01:43 1M3qfn-0002Bp-1v ctasd reports 'Confirmed' RefID:str=0001.0A150202.4A096527.0009,ss=4,fgs=8

2009:05:12-22:01:43 astaro1-1 exim[8421]: 2009-05-12 22:01:43 1M3qfn-0002Bp-1v 

If I View the message in Mail Manager, it says:

Message Delivery Log:

2009-05-12 22:01:54 192.168.1.9 [192.168.1.9]: Broken pipe

2009-05-12 22:01:54 myuser@bordo.com.au R=static_route_hostlist T=static_smtp defer (32): Broken pipe: 192.168.1.9 [192.168.1.9]

2009-05-12 22:06:44 192.168.1.9 [192.168.1.9]: Broken pipe

2009-05-12 22:06:44 myuser@bordo.com.au R=static_route_hostlist T=static_smtp defer (32): Broken pipe: 192.168.1.9 [192.168.1.9]

2009-05-12 22:07:16 192.168.1.9 [192.168.1.9]: Broken pipe

2009-05-12 22:07:16 myuser@bordo.com.au R=static_route_hostlist T=static_smtp defer (32): Broken pipe: 192.168.1.9 [192.168.1.9]

2009-05-12 22:10:03 192.168.1.9 [192.168.1.9]: Broken pipe

2009-05-12 22:10:03 myuser@bordo.com.au R=static_route_hostlist T=static_smtp defer (32): Broken pipe: 192.168.1.9 [192.168.1.9]

2009-05-12 22:13:01 192.168.1.9 [192.168.1.9]: Broken pipe

2009-05-12 22:13:01 myuser@bordo.com.au R=static_route_hostlist T=static_smtp defer (32): Broken pipe: 192.168.1.9 [192.168.1.9]

2009-05-12 22:13:04 192.168.1.9 [192.168.1.9]: Broken pipe

2009-05-12 22:13:04 myuser@bordo.com.au R=static_route_hostlist T=static_smtp defer (32): Broken pipe: 192.168.1.9 [192.168.1.9]

2009-05-12 22:19:02 192.168.1.9 [192.168.1.9]: Broken pipe

2009-05-12 22:19:02 myuser@bordo.com.au R=static_route_hostlist T=static_smtp defer (32): Broken pipe: 192.168.1.9 [192.168.1.9]

2009-05-12 22:22:02 192.168.1.9 [192.168.1.9]: Broken pipe

2009-05-12 22:22:02 myuser@bordo.com.au R=static_route_hostlist T=static_smtp defer (32): Broken pipe: 192.168.1.9 [192.168.1.9]

2009-05-12 22:25:24 Remote host 192.168.1.9 [192.168.1.9] closed connection in response to MAIL FROM:

2009-05-12 22:25:24 myuser@bordo.com.au R=static_route_hostlist T=static_smtp defer (-18): Remote host 192.168.1.9 [192.168.1.9] closed connection in response to MAIL FROM:

2009-05-12 22:34:03 Remote host 192.168.1.9 [192.168.1.9] closed connection in response to MAIL FROM:

2009-05-12 22:34:03 myuser@bordo.com.au R=static_route_hostlist T=static_smtp defer (-18): Remote host 192.168.1.9 [192.168.1.9] closed connection in response to MAIL FROM:

2009-05-12 22:34:06 192.168.1.9 [192.168.1.9]: Broken pipe

2009-05-12 22:34:06 myuser@bordo.com.au R=static_route_hostlist T=static_smtp defer (32): Broken pipe: 192.168.1.9 [192.168.1.9]

2009-05-12 22:36:31 192.168.1.9 [192.168.1.9]: Broken pipe

2009-05-12 22:36:31 myuser@bordo.com.au R=static_route_hostlist T=static_smtp defer (32): Broken pipe: 192.168.1.9 [192.168.1.9]

2009-05-12 22:43:06 192.168.1.9 [192.168.1.9]: Broken pipe

2009-05-12 22:43:06 myuser@bordo.com.au R=static_route_hostlist T=static_smtp defer (32): Broken pipe: 192.168.1.9 [192.168.1.9]

2009-05-12 22:46:20 192.168.1.9 [192.168.1.9]: Broken pipe

2009-05-12 22:46:20 myuser@bordo.com.au R=static_route_hostlist T=static_smtp defer (32): Broken pipe: 192.168.1.9 [192.168.1.9]

2009-05-12 22:46:23 192.168.1.9 [192.168.1.9]: Broken pipe

2009-05-12 22:46:23 myuser@bordo.com.au R=static_route_hostlist T=static_smtp defer (32): Broken pipe: 192.168.1.9 [192.168.1.9]

2009-05-12 22:47:03 192.168.1.9 [192.168.1.9]: Broken pipe

2009-05-12 22:47:03 myuser@bordo.com.au R=static_route_hostlist T=static_smtp defer (32): Broken pipe: 192.168.1.9 [192.168.1.9]

2009-05-12 22:53:03 Remote host 192.168.1.9 [192.168.1.9] closed connection in response to MAIL FROM:

2009-05-12 22:53:03 myuser@bordo.com.au R=static_route_hostlist T=static_smtp defer (-18): Remote host 192.168.1.9 [192.168.1.9] closed connection in response to MAIL FROM:

2009-05-12 22:56:17 192.168.1.9 [192.168.1.9]: Broken pipe

2009-05-12 22:56:17 myuser@bordo.com.au R=static_route_hostlist T=static_smtp defer (32): Broken pipe: 192.168.1.9 [192.168.1.9]

2009-05-12 22:56:20 192.168.1.9 [192.168.1.9]: Broken pipe

2009-05-12 22:56:20 myuser@bordo.com.au R=static_route_hostlist T=static_smtp defer (32): Broken pipe: 192.168.1.9 [192.168.1.9]





Message Headers and Body:

it then goes on with the message.

Astaro then sends the mail on to our anti-spam proxy, ASSP, which recognises that it is spam but delivers it (as it is set up to do).

ASSP's log says:

May-12-09 22:01:45 [Worker_1] Connected: 192.168.1.2:42332 -> 192.168.1.9:25 -> 127.0.0.1:10026

May-12-09 22:01:50 id-29706-04480 [Worker_1] 192.168.1.2  to: myuser@bordo.com.au Bayesian Check  - Prob: 1.00000 => spam

May-12-09 22:01:50 id-29706-04480 [Worker_1] 192.168.1.2  to: myuser@bordo.com.au Message-Score: total for this message is 25, added 25 for Bayesian Probability: 1.0000 

May-12-09 22:01:50 id-29706-04480 [Worker_1] [Bayesian] 192.168.1.2  to: myuser@bordo.com.au [spam found] (Bayesian) [Leave extra body fat behind] -> /Applications/assp//spam/4480.eml;

May-12-09 22:01:50 [Worker_1] Disconnected: 192.168.1.2 

May-12-09 22:01:50 [Worker_1] to: myuser@bordo.com.au info: message forwarded to me@bordo.com.au

Notice that ASSP has made the email now to me@bordo.com.au and not myuser@bordo.com.au because it has classified it as spam, and all spam gets forwarded to me to check for false positives.

To help with understanding the flow. The Astaro box is 192.168.1.2. The mail server (which runs ASSP in front of Postfix) is 192.168.1.9

Continuing on next post, as message is too long...

(Continued)

Finally, Postfix says:

May 12 22:01:46 mail-bordo-com-au postfix/smtpd[29812]: connect from localhost[127.0.0.1]

May 12 22:01:46 mail-bordo-com-au postfix/smtpd[29812]: 4775F8249EC4: client=localhost[127.0.0.1]

May 12 22:01:50 mail-bordo-com-au postfix/smtpd[29812]: lost connection after DATA from localhost[127.0.0.1]

May 12 22:01:50 mail-bordo-com-au postfix/smtpd[29812]: disconnect from localhost[127.0.0.1]

May 12 22:01:50 mail-bordo-com-au postfix/smtpd[29812]: connect from localhost[127.0.0.1]

May 12 22:01:50 mail-bordo-com-au postfix/smtpd[29812]: 69A848249ED2: client=localhost[127.0.0.1]

May 12 22:01:50 mail-bordo-com-au postfix/cleanup[29815]: 69A848249ED2: message-id=

May 12 22:01:50 mail-bordo-com-au postfix/smtpd[29812]: disconnect from localhost[127.0.0.1]

May 12 22:01:50 mail-bordo-com-au postfix/qmgr[789]: 69A848249ED2: from=, size=100673, nrcpt=1 (queue active)

May 12 22:01:54 mail-bordo-com-au postfix/smtpd[29821]: connect from localhost[127.0.0.1]

May 12 22:01:54 mail-bordo-com-au postfix/smtpd[29821]: A84648249EDB: client=localhost[127.0.0.1]

May 12 22:01:54 mail-bordo-com-au postfix/cleanup[29815]: A84648249EDB: message-id=

May 12 22:01:54 mail-bordo-com-au postfix/qmgr[789]: A84648249EDB: from=, size=101286, nrcpt=1 (queue active)

May 12 22:01:54 mail-bordo-com-au postfix/smtpd[29821]: disconnect from localhost[127.0.0.1]

May 12 22:01:54 mail-bordo-com-au amavis[29323]: (29323-11) Passed BAD-HEADER, MYNETS LOCAL [127.0.0.1] [91.205.173.28]  -> , quarantine: badh-mxc05cs3YiGB, Message-ID: , mail_id: mxc05cs3YiGB, Hits: -, size: 100673, queued_as: A84648249EDB, 3835 ms

May 12 22:01:54 mail-bordo-com-au postfix/smtp[29818]: 69A848249ED2: to=, relay=127.0.0.1[127.0.0.1]:10024, delay=4.3, delays=0.47/0.01/0/3.8, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as A84648249EDB)

May 12 22:01:54 mail-bordo-com-au postfix/virtual[29822]: A84648249EDB: to=, relay=virtual, delay=0.05, delays=0.01/0.01/0/0.03, dsn=2.0.0, status=sent (delivered to maildir)

May 12 22:01:54 mail-bordo-com-au postfix/qmgr[789]: 69A848249ED2: removed

May 12 22:01:54 mail-bordo-com-au postfix/qmgr[789]: A84648249EDB: removed

This looks a little bit complicated as Postfix sends the message (ID 69A848249ED2) to Amavisd-new for a virus scan (ID A84648249EDB), after which it gets 'reinjected' back into Postfix.

Hope that helps!

Thanks,

James.

BTW, the email was actually delivered to me at 22.01. The headers of the message were:

From:  Slim@looksmartbank.com
Subject:  [SPAM]:  Leave extra body fat behind
Date:  13 May 2009 12:02:18 AM
To:  myuser@bordo.com.au
Return-Path: 
X-Original-To:  me@bordo.com.au
Delivered-To:  me@bordo.com.au
Received:  from localhost (localhost [127.0.0.1]) by mail.bordo.com.au (Postfix) with ESMTP id A84648249EDB for ; Tue, 12 May 2009 22:01:54 +1000 (EST)
Received:  from mail.bordo.com.au ([127.0.0.1]) by localhost (mail.bordo.com.au [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id mxc05cs3YiGB for ; Tue, 12 May 2009 22:01:50 +1000 (EST)
Received:  from ASSP-nospam (localhost [127.0.0.1]) by mail.bordo.com.au (Postfix) with SMTP id 69A848249ED2 for ; Tue, 12 May 2009 22:01:50 +1000 (EST)
Received:  from astaro1.bordo.com.au ([192.168.1.2] helo=astaro1.bordo.com.au) by ASSP-nospam; 12 May 2009 22:01:45 +1000
Received:  from [91.205.173.28] (port=57134 helo=mx28.looksmartbank.com) by astaro1.bordo.com.au with smtp (Exim 4.69) (envelope-from ) id 1M3qfn-0002Bp-1v for myuser@bordo.com.au; Tue, 12 May 2009 22:01:43 +1000
X-Quarantine-Id: 
X-Virus-Scanned:  by amavisd-new by Sophos Anti-Virus for Macintosh at bordo.com.au
X-Amavis-Alert:  BAD HEADER SECTION, MIME error: error: part did not end with expected boundary
X-Ctch-Refid:  str=0001.0A150202.4A096527.0009,ss=4,fgs=8
Message-Id: 

So I don't know why Astaro thought there was a problem with delivery - it came through fine!

James.

So, maybe the problem is a damaged PostgreSQL database; the one that holds the mail queue?

Not sure. Resetting the DNS did not solve the problem.

44 messages waiting in queue this morning.

James.

Definitely a funky postgresql database.  I've seen threads here on how to reindex and reinitialize reporting databases, but not this.  I think you need Astaro Support to fix it, then please tell us the trick.

Cheers - Bob

Just a followup Bob.

Support have logged into my ASG and found over 800 open unix sockets on the system. They think it is because I've been using the bittorrent client Vuze (formerly Azureus) and to get it to work I've had to have it connect through Astaro's SOCKS proxy and that was creating all the sockets.

Anyway, I'm not running Vuze and have turned off the SOCKs proxy. Still getting emails banking up in queue - broken pipe seems to be the cause. I think perhaps ClamAV running on my mail server is dropping the connection if it contains a virus/phish/spam email and Astaro wants to keep trying to send it.

Just a followup Bob.

Support have logged into my ASG and found over 800 open unix sockets on the system. They think it is because I've been using the bittorrent client Vuze (formerly Azureus) and to get it to work I've had to have it connect through Astaro's SOCKS proxy and that was creating all the sockets.

Anyway, I'm not running Vuze and have turned off the SOCKs proxy. Still getting emails banking up in queue - broken pipe seems to be the cause. I think perhaps ClamAV running on my mail server is dropping the connection if it contains a virus/phish/spam email and Astaro wants to keep trying to send it.