[exim] long delays sending (not ident related) (mypost: rl3s…

Top Page
Delete this message
Reply to this message
Author: rich lott
Date:  
To: exim-users
Subject: [exim] long delays sending (not ident related) (mypost: rl3sept27)
hi All

exim newbie. My mail takes ages (always >30s) to deliver.

I added the lines following lines to the exim configuration:
rfc1413_hosts = !*
rfc1413_query_timeout = 0s

as I was advised that that turns off dns lookups, but my dns lookups were fast
anyway, and this didn't seem to help. Can anyone else help?

(this is a sort of re-posting, but it's because my last thread sort of got
sidelined into a debate about the benefits of ident, which I didn't
understand!)

always grateful, Rich.

Here's the logs:

-----------------8<-------------------------------------------
2005-09-28 19:00:12 1EKgE0-0003nO-V9 <= root@??? U=root P=local
S=278 from <root@???> for rl3@???
2005-09-28 19:00:43 1EKgE0-0003nO-V9 => rl3@???
F=<root@???> P=<root@???> R=dnslookup T=remote_smtp S=291
H=mail.shinyblue.net [195.50.105.121]:25 C="250 ok 1127930747 qp 75549"
QT=31s DT=30s
2005-09-28 19:00:43 1EKgE0-0003nO-V9 Completed QT=31s
-----------------8<-------------------------------------------

And here's the output of exim4 -d -qf :
-----------------8<-------------------------------------------

Exim version 4.52 uid=0 gid=0 pid=14672 D=fbb95cfd
Berkeley DB: Sleepycat Software: Berkeley DB 4.2.52: (December 3, 2003)
Support for: iconv() IPv6 GnuTLS
Lookups: lsearch wildlsearch nwildlsearch iplsearch cdb dbm dbmnz dsearch nis
nis0 passwd
Authenticators: cram_md5 plaintext
Routers: accept dnslookup ipliteral manualroute queryprogram redirect
Transports: appendfile/maildir/mailstore autoreply lmtp pipe smtp
Fixed never_users: 0
changed uid/gid: forcing real = effective
uid=0 gid=0 pid=14672
auxiliary group list: <none>
configuration file is /var/lib/exim4/config.autogenerated
log selectors = ffffffff 7fff7ffe
cwd=/home/rich 3 args: exim4 -d -qf
trusted user
admin user
skipping ACL configuration - not needed
Single queue run
set_process_info: 14672 running the queue (single queue run)
LOG: queue_run MAIN
Start queue run: pid=14672 -qf
queue running main directory
search_tidyup called
set_process_info: 14672 running queue: 1EKgNb-0003oc-4a-H
set_process_info: 14672 running queue: waiting for 1EKgNb-0003oc-4a (14674)
set_process_info: 14674 delivering 1EKgNb-0003oc-4a (queue run pid 14672)
reading spool file 1EKgNb-0003oc-4a-H
user=root uid=0 gid=0 sender=root@???
sender_local=1 ident=root
Non-recipients:
Empty Tree
---- End of tree ----
recipients_count=1
body_linecount=1 message_linecount=8
Delivery address list:
rl3@???
locking /var/spool/exim4/db/retry.lockfile
locked /var/spool/exim4/db/retry.lockfile
EXIM_DBOPEN(/var/spool/exim4/db/retry)
returned from EXIM_DBOPEN
opened hints database /var/spool/exim4/db/retry: flags=0
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>

Considering: rl3@???
unique = rl3@???
dbfn_read: key=R:shinyblue.net
dbfn_read: key=R:rl3@???
no domain retry record
no address retry record
rl3@???: queued for routing
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>

routing rl3@???
--------> hubbed_hosts router <--------
local_part=rl3 domain=shinyblue.net
checking domains
expansion of "${if exists{/etc/exim4/hubbed_hosts}
{partial-lsearch;/etc/exim4/hubbed_hosts}fail}" forced failure: assume not in
this list
hubbed_hosts router skipped: domains mismatch
--------> dnslookup_relay_to_domains router <--------
local_part=rl3 domain=shinyblue.net
checking domains
shinyblue.net in "@:localhost"? no (end of list)
shinyblue.net in ""? no (end of list)
shinyblue.net in "! +local_domains : +relay_to_domains"? no (end of list)
dnslookup_relay_to_domains router skipped: domains mismatch
--------> dnslookup router <--------
local_part=rl3 domain=shinyblue.net
checking domains
cached no match for +local_domains
cached lookup data = NULL
shinyblue.net in "! +local_domains"? yes (end of list)
R: dnslookup for rl3@???
calling dnslookup router
dnslookup router called for rl3@???
domain = shinyblue.net
DNS lookup of shinyblue.net (MX) succeeded
195.50.105.121 in "0.0.0.0 : 127.0.0.0/8 : 192.168.0.0/16 :172.16.0.0/12 :
10.0.0.0/8 : 169.254.0.0/16"? no (end of list)
fully qualified name = shinyblue.net
host_find_bydns yield = HOST_FOUND (2); returned hosts:
mail.shinyblue.net 195.50.105.121 MX=30
set transport remote_smtp
queued for remote_smtp transport: local_part = rl3
domain = shinyblue.net
errors_to=NULL
domain_data=NULL localpart_data=NULL
routed by dnslookup router
envelope to: rl3@???
transport: remote_smtp
host mail.shinyblue.net [195.50.105.121] MX=30
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>

After routing:
  Local deliveries:
  Remote deliveries:
    rl3@???
  Failed addresses:
  Deferred addresses:
search_tidyup called

>>>>>>>>>>>>>>>> Remote deliveries >>>>>>>>>>>>>>>>

--------> rl3@??? <--------
search_tidyup called
changed uid/gid: remote delivery to rl3@??? with
transport=remote_smtp
uid=115 gid=115 pid=14675
auxiliary group list: <none>
set_process_info: 14675 delivering 1EKgNb-0003oc-4a using remote_smtp
T: remote_smtp for rl3@???
remote_smtp transport entered
rl3@???
checking status of mail.shinyblue.net
locking /var/spool/exim4/db/retry.lockfile
locked /var/spool/exim4/db/retry.lockfile
EXIM_DBOPEN(/var/spool/exim4/db/retry)
returned from EXIM_DBOPEN
opened hints database /var/spool/exim4/db/retry: flags=0
dbfn_read: key=T:mail.shinyblue.net:195.50.105.121
dbfn_read: key=T:mail.shinyblue.net:195.50.105.121:1EKgNb-0003oc-4a
no host retry record
no message retry record
mail.shinyblue.net [195.50.105.121] status = usable
195.50.105.121 in serialize_hosts? no (option unset)
delivering 1EKgNb-0003oc-4a to mail.shinyblue.net [195.50.105.121]
(rl3@???)
set_process_info: 14675 delivering 1EKgNb-0003oc-4a to mail.shinyblue.net
[195.50.105.121] (rl3@???)
set_process_info: 14674 delivering 1EKgNb-0003oc-4a: waiting for a remote
delivery subprocess to finish
selecting on subprocess pipes
Connecting to mail.shinyblue.net [195.50.105.121]:25 ... connected
waiting for data on socket
read response data: size=27
SMTP<< 220 bishop.34sp.com ESMTP
195.50.105.121 in hosts_avoid_esmtp? no (option unset)
SMTP>> EHLO reech

waiting for data on socket
read response data: size=51
  SMTP<< 250-bishop.34sp.com
         250-PIPELINING
         250 8BITMIME
195.50.105.121 in hosts_require_tls? no (option unset)
using PIPELINING
195.50.105.121 in hosts_require_auth? no (option unset)

SMTP>> MAIL FROM:<root@???>
SMTP>> RCPT TO:<rl3@???>
SMTP>> DATA

waiting for data on socket
read response data: size=30
SMTP<< 250 ok
SMTP<< 250 ok
SMTP<< 354 go ahead
SMTP>> writing message and terminating "."

writing data block fd=8 size=291 timeout=300
waiting for data on socket
read response data: size=28
SMTP<< 250 ok 1127931341 qp 80393
journalling rl3@???
ok=1 send_quit=1 send_rset=0 continue_more=0 yield=0 first_address is NULL
transport_check_waiting entered
sequence=1 local_max=500 global_max=-1
locking /var/spool/exim4/db/wait-remote_smtp.lockfile
locked /var/spool/exim4/db/wait-remote_smtp.lockfile
EXIM_DBOPEN(/var/spool/exim4/db/wait-remote_smtp)
returned from EXIM_DBOPEN
opened hints database /var/spool/exim4/db/wait-remote_smtp: flags=2
dbfn_read: key=mail.shinyblue.net
no messages waiting for mail.shinyblue.net
SMTP>> QUIT

set_process_info: 14675 delivering 1EKgNb-0003oc-4a: just tried
mail.shinyblue.net [195.50.105.121] for rl3@???: result OK
Leaving remote_smtp transport
set_process_info: 14675 delivering 1EKgNb-0003oc-4a (just run remote_smtp for
rl3@??? in subprocess)
search_tidyup called
reading pipe for subprocess 14675 (not ended)
read() yielded 86
Z0 item read
remote delivery process 14675 ended
set_process_info: 14674 delivering 1EKgNb-0003oc-4a
post-process rl3@??? (0)
rl3@??? delivered
LOG: MAIN
=> rl3@??? F=<root@???> P=<root@???>
R=dnslookup T=remote_smtp S=291 H=mail.shinyblue.net [195.50.105.121]:25
C="250 ok 1127931341 qp 80393" QT=30s DT=30s
>>>>>>>>>>>>>>>> deliveries are done >>>>>>>>>>>>>>>>

changed uid/gid: post-delivery tidying
uid=115 gid=115 pid=14674
auxiliary group list: <none>
set_process_info: 14674 tidying up after delivering 1EKgNb-0003oc-4a
Processing retry items
Succeeded addresses:
rl3@???: no retry items
Failed addresses:
Deferred addresses:
end of retry processing
LOG: MAIN
Completed QT=30s
end delivery of 1EKgNb-0003oc-4a
search_tidyup called
set_process_info: 14672 running queue: waiting for children of 14674
set_process_info: 14672 running queue
LOG: queue_run MAIN
End queue run: pid=14672 -qf
search_tidyup called
>>>>>>>>>>>>>>>> Exim pid=14672 terminating with rc=0 >>>>>>>>>>>>>>>>