Re: [exim] remote_smtp defer (110): Connection timed out on …

Kezdőlap
Üzenet törlése
Válasz az üzenetre
Szerző: Don O'Neil
Dátum:  
Címzett: 'Graeme Fowler', exim-users
Tárgy: Re: [exim] remote_smtp defer (110): Connection timed out on AWS EC2Instance
I just tried the extended logging as you suggested, and here's the output of
the last attempt before it gave up (it tried a whole host of yahoo hosts
first). I don't see anything in there that is helping me find the problem.
What other sorts of issues can cause these types of failures? Any other
ideas?

17:22:31  8470 LOG: MAIN
17:22:31  8470   mta6.am0.yahoodns.net [98.136.216.26] Connection timed out
17:22:31  8470 set_process_info:  8470 delivering 1UkGQN-0002ok-5C: just
tried mta6.am0.yahoodns.net [98.136.216.26] for don_oneil@???: result
DEFER
17:22:31  8470 added retry item for T:mta6.am0.yahoodns.net:98.136.216.26:
errno=110 more_errno=1,M flags=2
17:22:31  8470 address match: subject=*@mta6.am0.yahoodns.net pattern=*
17:22:31  8470 mta6.am0.yahoodns.net in "*"? yes (matched "*")
17:22:31  8470 *@mta6.am0.yahoodns.net in "*"? yes (matched "*")
17:22:31  8470 checking status of mta6.am0.yahoodns.net
17:22:31  8470 locking /var/spool/exim/db/retry.lockfile
17:22:31  8470 locked /var/spool/exim/db/retry.lockfile
17:22:31  8470 EXIM_DBOPEN(/var/spool/exim/db/retry)
17:22:31  8470 returned from EXIM_DBOPEN
17:22:31  8470 opened hints database /var/spool/exim/db/retry:
flags=O_RDONLY
17:22:31  8470 dbfn_read: key=T:mta6.am0.yahoodns.net:98.138.112.38
17:22:31  8470 dbfn_read:
key=T:mta6.am0.yahoodns.net:98.138.112.38:1UkGQN-0002ok-5C
17:22:31  8470 no message retry record
17:22:31  8470 mta6.am0.yahoodns.net [98.138.112.38] status = usable
17:22:31  8470 98.138.112.38 in serialize_hosts? no (option unset)
17:22:31  8470 delivering 1UkGQN-0002ok-5C to mta6.am0.yahoodns.net
[98.138.112.38] (don_oneil@???)
17:22:31  8470 set_process_info:  8470 delivering 1UkGQN-0002ok-5C to
mta6.am0.yahoodns.net [98.138.112.38] (don_oneil@???)
17:22:31  8470 hosts_max_try limit reached with this host
17:23:19  8466 selecting on subprocess pipes
17:22:31  8470 Connecting to mta6.am0.yahoodns.net [98.138.112.38]:25 from
54.236.194.225 ... failed: Connection timed out (timeout=5m)
17:23:34  8470 LOG: MAIN
17:23:34  8470   mta6.am0.yahoodns.net [98.138.112.38] Connection timed out
17:23:34  8470 set_process_info:  8470 delivering 1UkGQN-0002ok-5C: just
tried mta6.am0.yahoodns.net [98.138.112.38] for don_oneil@???: result
DEFER
17:23:34  8470 added retry item for T:mta6.am0.yahoodns.net:98.138.112.38:
errno=110 more_errno=1,M flags=2
17:23:34  8470 address match: subject=*@mta6.am0.yahoodns.net pattern=*
17:23:34  8470 mta6.am0.yahoodns.net in "*"? yes (matched "*")
17:23:34  8470 *@mta6.am0.yahoodns.net in "*"? yes (matched "*")
17:23:34  8470 all IP addresses skipped or deferred at least one address
17:23:34  8470 hosts_max_try limit caused some hosts to be skipped
17:23:34  8470 updating wait-remote_smtp database
17:23:34  8470 locking /var/spool/exim/db/wait-remote_smtp.lockfile
17:23:34  8470 locked /var/spool/exim/db/wait-remote_smtp.lockfile
17:23:34  8470 EXIM_DBOPEN(/var/spool/exim/db/wait-remote_smtp)
17:23:34  8470 returned from EXIM_DBOPEN
17:23:34  8470 opened hints database /var/spool/exim/db/wait-remote_smtp:
flags=O_RDWR
17:23:34  8470 dbfn_read: key=mta6.am0.yahoodns.net
17:23:34  8470 already listed for mta6.am0.yahoodns.net
17:23:34  8470 dbfn_read: key=mta7.am0.yahoodns.net
17:23:34  8470 already listed for mta7.am0.yahoodns.net
17:23:34  8470 dbfn_read: key=mta5.am0.yahoodns.net
17:23:34  8470 already listed for mta5.am0.yahoodns.net
17:23:34  8470 Leaving remote_smtp transport
17:23:34  8470 set_process_info:  8470 delivering 1UkGQN-0002ok-5C (just run
remote_smtp for don_oneil@??? in subprocess)
17:23:34  8470 search_tidyup called
17:23:34  8466 reading pipe for subprocess 8470 (not ended)
17:23:34  8466 read() yielded 17
17:23:34  8466 selecting on subprocess pipes
17:23:34  8466 reading pipe for subprocess 8470 (not ended)
17:23:34  8466 read() yielded 338
17:23:34  8466 reading retry information for
T:mta6.am0.yahoodns.net:98.138.112.38 from subprocess
17:23:34  8466   added retry item
17:23:34  8466 reading retry information for
T:mta6.am0.yahoodns.net:98.136.216.26 from subprocess
17:23:34  8466   added retry item
17:23:34  8466 reading retry information for
T:mta6.am0.yahoodns.net:66.196.118.35 from subprocess
17:23:34  8466   added retry item
17:23:34  8466 reading retry information for
T:mta6.am0.yahoodns.net:66.196.118.240 from subprocess
17:23:34  8466   added retry item
17:23:34  8466 reading retry information for
T:mta6.am0.yahoodns.net:98.138.112.33 from subprocess
17:23:34  8466   added retry item
17:23:34  8466 Z0 item read
17:23:34  8466 remote delivery process 8470 ended
17:23:34  8466 set_process_info:  8466 delivering 1UkGQN-0002ok-5C
17:23:34  8466 post-process don_oneil@??? (1)
17:23:34  8466 LOG: MAIN
17:23:34  8466   == don_oneil@??? R=lookuphost T=remote_smtp defer
(110): Connection timed out
17:23:34  8466 >>>>>>>>>>>>>>>> deliveries are done >>>>>>>>>>>>>>>>
17:23:34  8466 changed uid/gid: post-delivery tidying
17:23:34  8466   uid=8 gid=12 pid=8466
17:23:34  8466   auxiliary group list: <none>
17:23:34  8466 set_process_info:  8466 tidying up after delivering
1UkGQN-0002ok-5C
17:23:34  8466 Processing retry items
17:23:34  8466 Succeeded addresses:
17:23:34  8466 Failed addresses:
17:23:34  8466 Deferred addresses:
17:23:34  8466 don_oneil@???
17:23:34  8466 locking /var/spool/exim/db/retry.lockfile
17:23:34  8466 locked /var/spool/exim/db/retry.lockfile
17:23:34  8466 EXIM_DBOPEN(/var/spool/exim/db/retry)
17:23:34  8466 returned from EXIM_DBOPEN
17:23:34  8466 opened hints database /var/spool/exim/db/retry: flags=O_RDWR
17:23:34  8466 address match: subject=*@mta6.am0.yahoodns.net pattern=*
17:23:34  8466 mta6.am0.yahoodns.net in "*"? yes (matched "*")
17:23:34  8466 *@mta6.am0.yahoodns.net in "*"? yes (matched "*")
17:23:34  8466 retry for T:mta6.am0.yahoodns.net:98.138.112.33 (yahoo.com) =
* 0 0
17:23:34  8466 dbfn_read: key=T:mta6.am0.yahoodns.net:98.138.112.33
17:23:34  8466 failing_interval=87424 message_age=89960
17:23:34  8466 Writing retry data for T:mta6.am0.yahoodns.net:98.138.112.33
17:23:34  8466   first failed=1370451990 last try=1370539414 next
try=1370568214 expired=0
17:23:34  8466   errno=110 more_errno=1,M Connection timed out
17:23:34  8466 dbfn_write: key=T:mta6.am0.yahoodns.net:98.138.112.33
17:23:34  8466 address match: subject=*@mta6.am0.yahoodns.net pattern=*
17:23:34  8466 mta6.am0.yahoodns.net in "*"? yes (matched "*")
17:23:34  8466 *@mta6.am0.yahoodns.net in "*"? yes (matched "*")
17:23:34  8466 retry for T:mta6.am0.yahoodns.net:66.196.118.240 (yahoo.com)
= * 0 0
17:23:34  8466 dbfn_read: key=T:mta6.am0.yahoodns.net:66.196.118.240
17:23:34  8466 failing_interval=88324 message_age=89960
17:23:34  8466 Writing retry data for T:mta6.am0.yahoodns.net:66.196.118.240
17:23:34  8466   first failed=1370451090 last try=1370539414 next
try=1370568214 expired=0
17:23:34  8466   errno=110 more_errno=1,M Connection timed out
17:23:34  8466 dbfn_write: key=T:mta6.am0.yahoodns.net:66.196.118.240
17:23:34  8466 address match: subject=*@mta6.am0.yahoodns.net pattern=*
17:23:34  8466 mta6.am0.yahoodns.net in "*"? yes (matched "*")
17:23:34  8466 *@mta6.am0.yahoodns.net in "*"? yes (matched "*")
17:23:34  8466 retry for T:mta6.am0.yahoodns.net:66.196.118.35 (yahoo.com) =
* 0 0
17:23:34  8466 dbfn_read: key=T:mta6.am0.yahoodns.net:66.196.118.35
17:23:34  8466 failing_interval=87424 message_age=89960
17:23:34  8466   first failed=1370451990 last try=1370539414 next
try=1370568214 expired=0
17:23:34  8466   errno=110 more_errno=1,M Connection timed out
17:23:34  8466 dbfn_write: key=T:mta6.am0.yahoodns.net:66.196.118.35
17:23:34  8466 address match: subject=*@mta6.am0.yahoodns.net pattern=*
17:23:34  8466 mta6.am0.yahoodns.net in "*"? yes (matched "*")
17:23:34  8466 *@mta6.am0.yahoodns.net in "*"? yes (matched "*")
17:23:34  8466 retry for T:mta6.am0.yahoodns.net:98.136.216.26 (yahoo.com) =
* 0 0
17:23:34  8466 dbfn_read: key=T:mta6.am0.yahoodns.net:98.136.216.26
17:23:34  8466 failing_interval=88324 message_age=89960
17:23:34  8466 Writing retry data for T:mta6.am0.yahoodns.net:98.136.216.26
17:23:34  8466   first failed=1370451090 last try=1370539414 next
try=1370568214 expired=0
17:23:34  8466   errno=110 more_errno=1,M Connection timed out
17:23:34  8466 dbfn_write: key=T:mta6.am0.yahoodns.net:98.136.216.26
17:23:34  8466 address match: subject=*@mta6.am0.yahoodns.net pattern=*
17:23:34  8466 mta6.am0.yahoodns.net in "*"? yes (matched "*")
17:23:34  8466 *@mta6.am0.yahoodns.net in "*"? yes (matched "*")
17:23:34  8466 retry for T:mta6.am0.yahoodns.net:98.138.112.38 (yahoo.com) =
* 0 0
17:23:34  8466 dbfn_read: key=T:mta6.am0.yahoodns.net:98.138.112.38
17:23:34  8466 failing_interval=84724 message_age=89960
17:23:34  8466 Writing retry data for T:mta6.am0.yahoodns.net:98.138.112.38
17:23:34  8466   first failed=1370454690 last try=1370539414 next
try=1370568214 expired=0
17:23:34  8466   errno=110 more_errno=1,M Connection timed out
17:23:34  8466 dbfn_write: key=T:mta6.am0.yahoodns.net:98.138.112.38
17:23:34  8466 end of retry processing
17:23:34  8466 expanding: $h_list-id:$h_list-post:$h_list-subscribe:
17:23:34  8466    result:
17:23:34  8466 expanding:
17:23:34  8466    result:
17:23:34  8466 expanding: $h_precedence:
17:23:34  8466    result:
17:23:34  8466 expanding: (?i)bulk|list|junk
17:23:34  8466    result: (?i)bulk|list|junk
17:23:34  8466 expanding: $h_auto-submitted:
17:23:34  8466    result:
17:23:34  8466 expanding: (?i)auto-generated|auto-replied
17:23:34  8466    result: (?i)auto-generated|auto-replied
17:23:34  8466 condition: or {{
!eq{$h_list-id:$h_list-post:$h_list-subscribe:}{} }{
match{$h_precedence:}{(?i)bulk|list|junk} }{
match{$h_auto-submitted:}{(?i)auto-generated|auto-replied} }}
17:23:34  8466    result: false
17:23:34  8466 expanding: no
17:23:34  8466    result: no
17:23:34  8466 skipping: result is not used
17:23:34  8466 expanding: yes
17:23:34  8466    result: yes
17:23:34  8466 expanding: ${if or {{
!eq{$h_list-id:$h_list-post:$h_list-subscribe:}{} }{
match{$h_precedence:}{(?i)bulk|list|junk} }{
match{$h_auto-submitted:}{(?i)auto-generated|auto-replied} }} {no}{yes}}
17:23:34  8466    result: yes
17:23:34  8466 time on queue = 1d1h4m35s
17:23:34  8466 warning counts: required 1 done 1
17:23:34  8466 delivery deferred: update_spool=0 header_rewritten=0
17:23:34  8466 end delivery of 1UkGQN-0002ok-5C
17:23:34  8466 search_tidyup called
17:23:34  8466 search_tidyup called
17:23:34  8466 >>>>>>>>>>>>>>>> Exim pid=8466 terminating with rc=0

>>>>>>>>>>>>>>>>



-----Original Message-----
From: exim-users-bounces+lists=lizardhill.com@???
[mailto:exim-users-bounces+lists=lizardhill.com@exim.org] On Behalf Of
Graeme Fowler
Sent: Thursday, June 06, 2013 9:40 AM
To: exim-users@???
Subject: Re: [exim] remote_smtp defer (110): Connection timed out on AWS EC2
Instance

On 6 Jun 2013, at 16:31, Don O'Neil <lists@???> wrote:
> SELinux is already disabled.

<snip>
> Any other ideas?


exim -d+all -M 1UkGQN-0002ok-5C 2>&1 | tee logfile

watch it, and see where it stalls. and when it ends, you've got all the
debug output in logfile.

Is it always timing out on the same host? Could be that you have a duff
retry DB, causing it to try the same MX all the time. In theory that message
should try all available MXes for the remote domain in a random order (for
their grouped priority values).

Graeme
--
## List details at https://lists.exim.org/mailman/listinfo/exim-users
## Exim details at http://www.exim.org/
## Please use the Wiki with this list - http://wiki.exim.org/