On 22/08/05, Philip Hazel <ph10@???> wrote:
> On Mon, 22 Aug 2005, John Hall wrote:
> > There is only one MX record, oxmail.ox.ac.uk. This name resolves to
> > many IP addresses, one of which is unavailable:
> > > You haven't provided enough information about your problem message
> > > for me to be able to say anything useful. We don't seem to have
> > > any problems with ox.ac.uk from here.
> >
> > The message itself is unremarkable. Exim is attempting to connect to
> > 129.67.1.171, which times out.
> >
> > 2005-08-22 14:15:49 oxmail.ox.ac.uk [129.67.1.171]: Connection timed out
> > 2005-08-22 14:15:49 xxx.yyy@??? <xxx.yyy@???>
> > R=internet T=remote_smtp defer (110): Connection timed out
> >
> > Exim doesn't seem to retry any of the other IP addresses listed for
> > oxmail.ox.ac.uk.
>
> Please try a delivery with debugging turned on, catch the stderr
> output, and see if that gives you a clue. If not, post the output so
> we can see if we (the list) can figure it out. Something like
>
> exim -d -M the-message-id 2>/tmp/something
Phil,
The full log output is included below, but in my remote smtp router, it
only seems to consider one IP address:
internet router called for xxx.yyy@???
domain = admin.ox.ac.uk
DNS lookup of admin.ox.ac.uk (MX) succeeded
fully qualified name = admin.ox.ac.uk
host_find_bydns yield = HOST_FOUND (2); returned hosts:
oxmail.ox.ac.uk 129.67.1.171 MX=9
set transport remote_smtp
I'm running a caching DNS server, but it does return all 9 hosts for
this record.
> What it *should* do is try the hosts in a random order, unless they are
> *all* dead and it hasn't hit a retry time for any of the others. You
> could also try running
>
> exinext ox.ac.uk
>
> to see if that provides anything helpful.
Transport: oxmail.ox.ac.uk [129.67.1.171] error 110: Connection timed out
first failed: 22-Aug-2005 15:37:12
last tried: 22-Aug-2005 15:37:12
next try at: 22-Aug-2005 15:52:12
The first failed and last tried times are the same because in trying to
get the e-mail to go I tried deleting the retry record.
regards,
John
Exim log:
Exim version 4.52 uid=0 gid=0 pid=28788 D=fbb95cfd
Berkeley DB: Sleepycat Software: Berkeley DB 3.2.9: (February 1, 2005)
Support for: iconv() Content_Scanning Old_Demime
Lookups: lsearch wildlsearch nwildlsearch iplsearch dbm dbmnz
Authenticators:
Routers: accept dnslookup ipliteral manualroute queryprogram redirect
Transports: appendfile autoreply pipe smtp
Fixed never_users: 0
changed uid/gid: forcing real = effective
uid=0 gid=0 pid=28788
auxiliary group list: <none>
configuration file is /etc/mail/exim.conf
log selectors = 00000ffc 00028800
cwd=/home/john 4 args: exim -d -M 1E7Aqu-0005o1-Um
trusted user
admin user
skipping ACL configuration - not needed
finduser used cached passwd data for mail
finduser used cached passwd data for mail
finduser used cached passwd data for mail
finduser used cached passwd data for mail
finduser used cached passwd data for mail
finduser used cached passwd data for mail
finduser used cached passwd data for mail
set_process_info: 28788 delivering specified messages
set_process_info: 28788 delivering 1E7Aqu-0005o1-Um
reading spool file 1E7Aqu-0005o1-Um-H
user=mail uid=8 gid=8 sender=aaa.bbb@???
sender_fullhost = optex1.optex.local [192.168.0.12]
sender_rcvhost = optex1.optex.local ([192.168.0.12])
sender_local=0 ident=unset
Non-recipients:
-->system-filter [0]
-->/var/archive/all:system-filter [2]
---- End of tree ----
recipients_count=1
body_linecount=436 message_linecount=19
Writing spool header file
Size of headers = 845
running system filter
rda_interpret (file): /etc/mail/system.filter
expanded: /etc/mail/system.filter
changed uid/gid: system filter
uid=8 gid=8 pid=28789
auxiliary group list: <none>
654 bytes read from /etc/mail/system.filter
data is an Exim filter program
Filter: start of processing
Filter: end of processing
rda_interpret: subprocess yield=1 error=NULL
system filter returned 1
system filter added /var/archive/all
Delivery address list:
/var/archive/all
xxx.yyy@???
locking /var/spool/exim/db/retry.lockfile
locked /var/spool/exim/db/retry.lockfile
EXIM_DBOPEN(/var/spool/exim/db/retry)
returned from EXIM_DBOPEN
opened hints database /var/spool/exim/db/retry: flags=0
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
Considering: /var/archive/all
unique = /var/archive/all:system-filter
/var/archive/all was previously delivered: discarded
system-filter: children all complete
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
Considering: xxx.yyy@???
unique = xxx.yyy@???
dbfn_read: key=R:admin.ox.ac.uk
dbfn_read: key=R:xxx.yyy@???
no domain retry record
no address retry record
xxx.yyy@???: queued for routing
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
routing xxx.yyy@???
--------> spamtraps router <--------
local_part=xxx.yyy domain=admin.ox.ac.uk
checking "condition"
search_open: lsearch "/etc/mail/spamtraps"
search_find: file="/etc/mail/spamtraps"
key="xxx.yyy@???" partial=-1 affix=NULL starflags=0
LRU list:
:/etc/mail/spamtraps
End
internal_search_find: file="/etc/mail/spamtraps"
type=lsearch key="xxx.yyy@???"
file lookup required for xxx.yyy@???
in /etc/mail/spamtraps
lookup failed
spamtraps router skipped: condition failure
--------> xjtagsupport_in router <--------
local_part=xxx.yyy domain=admin.ox.ac.uk
checking domains
admin.ox.ac.uk in "xjtag.com:xjtag.co.uk:x-jtag.com"? no (end of list)
admin.ox.ac.uk in "+xjtag_domains"? no (end of list)
xjtagsupport_in router skipped: domains mismatch
--------> gmail_internet router <--------
local_part=xxx.yyy domain=admin.ox.ac.uk
checking domains
admin.ox.ac.uk in "gmail.com"? no (end of list)
gmail_internet router skipped: domains mismatch
--------> internet router <--------
local_part=xxx.yyy domain=admin.ox.ac.uk
checking domains
admin.ox.ac.uk in "@:*.optex.local:optex.local:spam.local:localhost"?
no (end of list)
admin.ox.ac.uk in
"camtechconsultants.com:cambridgetechgroup.com:optionexist.co.uk:optex.co.uk:optionexist.co
m:optex.demon.co.uk:optionexist.demon.co.uk:add-by-gateway.optionexist.co.uk"?
no (end of list)
cached no match for +xjtag_domains
cached lookup data = NULL
admin.ox.ac.uk in "adiabaticlogic.com:adiabatic-logic.com"? no (end of list)
admin.ox.ac.uk in
"+office_domains:+optex_domains:+xjtag_domains:+adiabatic_domains"? no
(end of list)
admin.ox.ac.uk in "!+local_domains"? yes (end of list)
calling internet router
internet router called for xxx.yyy@???
domain = admin.ox.ac.uk
DNS lookup of admin.ox.ac.uk (MX) succeeded
fully qualified name = admin.ox.ac.uk
host_find_bydns yield = HOST_FOUND (2); returned hosts:
oxmail.ox.ac.uk 129.67.1.171 MX=9
set transport remote_smtp
queued for remote_smtp transport: local_part = xxx.yyy
domain = admin.ox.ac.uk
errors_to=NULL
domain_data=NULL localpart_data=NULL
routed by internet router
envelope to: xxx.yyy@???
transport: remote_smtp
host oxmail.ox.ac.uk [129.67.1.171] MX=9
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
After routing:
Local deliveries:
Remote deliveries:
xxx.yyy@???
Failed addresses:
Deferred addresses:
search_tidyup called
>>>>>>>>>>>>>>>> Remote deliveries >>>>>>>>>>>>>>>>
--------> xxx.yyy@??? <--------
search_tidyup called
changed uid/gid: remote delivery to xxx.yyy@??? with
transport=remote_smtp
uid=8 gid=8 pid=28791
auxiliary group list: <none>
set_process_info: 28791 delivering 1E7Aqu-0005o1-Um using remote_smtp
remote_smtp transport entered
xxx.yyy@???
checking status of oxmail.ox.ac.uk
locking /var/spool/exim/db/retry.lockfile
locked /var/spool/exim/db/retry.lockfile
EXIM_DBOPEN(/var/spool/exim/db/retry)
returned from EXIM_DBOPEN
opened hints database /var/spool/exim/db/retry: flags=0
dbfn_read: key=T:oxmail.ox.ac.uk:129.67.1.171
dbfn_read: key=T:oxmail.ox.ac.uk:129.67.1.171:1E7Aqu-0005o1-Um
no host retry record
no message retry record
oxmail.ox.ac.uk [129.67.1.171] status = usable
129.67.1.171 in serialize_hosts? no (option unset)
delivering 1E7Aqu-0005o1-Um to oxmail.ox.ac.uk [129.67.1.171]
(xxx.yyy@???)
set_process_info: 28791 delivering 1E7Aqu-0005o1-Um to oxmail.ox.ac.uk
[129.67.1.171] (xxx.yyy@???
)
set_process_info: 28788 delivering 1E7Aqu-0005o1-Um: waiting for a
remote delivery subprocess to finish
selecting on subprocess pipes
selecting on subprocess pipes
selecting on subprocess pipes
selecting on subprocess pipes
Connecting to oxmail.ox.ac.uk [129.67.1.171]:25 ... failed: Connection
timed out (timeout=5m)
LOG: MAIN
oxmail.ox.ac.uk [129.67.1.171]: Connection timed out
set_process_info: 28791 delivering 1E7Aqu-0005o1-Um: just tried
oxmail.ox.ac.uk [129.67.1.171] for xxx.yyy@ad
min.ox.ac.uk: result DEFER
added retry item for T:oxmail.ox.ac.uk:129.67.1.171: errno=110
more_errno=1,M flags=2
all IP addresses skipped or deferred at least one address
locking /var/spool/exim/db/wait-remote_smtp.lockfile
locked /var/spool/exim/db/wait-remote_smtp.lockfile
EXIM_DBOPEN(/var/spool/exim/db/wait-remote_smtp)
returned from EXIM_DBOPEN
opened hints database /var/spool/exim/db/wait-remote_smtp: flags=2
dbfn_read: key=oxmail.ox.ac.uk
Leaving remote_smtp transport
set_process_info: 28791 delivering 1E7Aqu-0005o1-Um (just run
remote_smtp for xxx.yyy@??? in subpr
ocess)
search_tidyup called
reading pipe for subprocess 28791 (not ended)
read() yielded 81
reading retry information for T:oxmail.ox.ac.uk:129.67.1.171 from subprocess
added retry item
Z0 item read
remote delivery process 28791 ended
set_process_info: 28788 delivering 1E7Aqu-0005o1-Um
post-process xxx.yyy@??? (1)
LOG: MAIN
== xxx.yyy@??? <xxx.yyy@???> R=internet
T=remote_smtp defer (110): Connection timed o
ut
>>>>>>>>>>>>>>>> deliveries are done >>>>>>>>>>>>>>>>
changed uid/gid: post-delivery tidying
uid=8 gid=8 pid=28788
auxiliary group list: <none>
set_process_info: 28788 tidying up after delivering 1E7Aqu-0005o1-Um
Processing retry items
Succeeded addresses:
Failed addresses:
Deferred addresses:
xxx.yyy@???
locking /var/spool/exim/db/retry.lockfile
locked /var/spool/exim/db/retry.lockfile
EXIM_DBOPEN(/var/spool/exim/db/retry)
returned from EXIM_DBOPEN
opened hints database /var/spool/exim/db/retry: flags=2
address match: subject=*@oxmail.ox.ac.uk pattern=*
oxmail.ox.ac.uk in "*"? yes (matched "*")
*@oxmail.ox.ac.uk in "*"? yes (matched "*")
retry for T:oxmail.ox.ac.uk:129.67.1.171 (admin.ox.ac.uk) = *
dbfn_read: key=T:oxmail.ox.ac.uk:129.67.1.171
Writing retry data for T:oxmail.ox.ac.uk:129.67.1.171
first failed=1124721432 last try=1124721432 next try=1124722332 expired=0
errno=110 more_errno=1,M Connection timed out
dbfn_write: key=T:oxmail.ox.ac.uk:129.67.1.171
end of retry processing
time on queue = 2h44m40s
warning counts: required 3 done 3
delivery deferred: update_spool=1 header_rewritten=0
Writing spool header file
Size of headers = 845
end delivery of 1E7Aqu-0005o1-Um
search_tidyup called
search_tidyup called
>>>>>>>>>>>>>>>> Exim pid=28788 terminating with rc=0 >>>>>>>>>>>>>>>>
