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 [email protected]: 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] ([email protected]) 17:22:31 8470 set_process_info: 8470 delivering 1UkGQN-0002ok-5C to mta6.am0.yahoodns.net [98.138.112.38] ([email protected]) 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 [email protected]: 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 [email protected] 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 [email protected] (1) 17:23:34 8466 LOG: MAIN 17:23:34 8466 == [email protected] 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 [email protected] 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: [email protected] [mailto:[email protected]] On Behalf Of Graeme Fowler Sent: Thursday, June 06, 2013 9:40 AM To: [email protected] Subject: Re: [exim] remote_smtp defer (110): Connection timed out on AWS EC2 Instance On 6 Jun 2013, at 16:31, Don O'Neil <[email protected]> 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/ -- ## 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/
