[exim] Exim resend email many times

Top Page
Delete this message
Reply to this message
Author: Marco Zeni
Date:  
To: exim-users
Subject: [exim] Exim resend email many times
Hi,
I ha ve a problem with my Exim version 4.43, it act as a MX server that
deliver email to our internal mail server.
Very often we receive the same mail many times (often neswletters).
checking on EXIM log i find this error for everyone of the email tha i
receive more time

2007-02-14 13:52:36 SMTP timeout while connected to 192.168.1.102
[192.168.1.102] after end of data (46606 bytes written): Connection
timed out
2007-02-14 13:52:36 i...@mydomain.it R=static_route T=static_smtp defer
(110): Connection timed out: SMTP timeout while connected to
192.168.1.102 [192.168.1.102 after end of data (46606 bytes written)


Our internal mail server receive the email correctly and delivery it,
but Exim keep it in the retry queue and resend the email after the retry
time.


We have traced a mail session with the command exim -d -M <messageID>


and the result is te following


------------------------------------------------------------------------
---------------------------


Exim version 4.43 uid=0 gid=0 pid=7446 D=fbb95cfd
Berkeley DB: Sleepycat Software: Berkeley DB 4.2.52: (June 30, 2004)
Support for: iconv() Perl OpenSSL
Lookups: lsearch wildlsearch nwildlsearch iplsearch dsearch
Authenticators: plaintext
Routers: accept dnslookup ipliteral manualroute queryprogram redirect
Transports: smtp
Fixed never_users: 0
changed uid/gid: forcing real = effective
uid=0 gid=0 pid=7446
auxiliary group list: <none>
configuration file is /etc/exim.conf
log selectors = 00000ffc 00010400
trusted user
admin user
skipping ACL configuration - not needed
set_process_info: 7446 delivering specified messages
set_process_info: 7446 delivering 1HHLx3-0007Dx-I6
reading spool file 1HHLx3-0007Dx-I6-H
user=MailerDaemon uid=0 gid=0 sender=area.fi...@newsmaggioli.it
sender_fullhost = apollo13.zeus.it [195.31.185.250]
sender_rcvhost = apollo13.zeus.it ([195.31.185.250])
sender_local=0 ident=unset
Non-recipients:
Empty Tree
---- End of tree ----
recipients_count=1
body_linecount=1232 message_linecount=42
running system filter
rda_interpret (file): /etc/exim.system_filter
expanded: /etc/exim.system_filter
328 bytes read from /etc/exim.system_filter
data is an Exim filter program
Filter: start of processing
Filter: end of processing
system filter returned 1
Delivery address list:
email...@mydomain.com
locking /spool/db/retry.lockfile
locked /spool/db/retry.lockfile
opened hints database /spool/db/retry: flags=0




Considering: email...@mydomain.com
unique = email...@mydomain.com
dbfn_read: key=R:mydomain.com
dbfn_read: key=R:email...@mydomain.com
no domain retry record
no address retry record
email...@mydomain.com: queued for routing



routing email...@mydomain.com
--------> postmaster_ipliteral router <--------
local_part=aipaspa domain=mydomain.com
checking domains
mydomain.com in "@[]"? no (end of list)
mydomain.com in "+domain_literals"? no (end of list)
postmaster_ipliteral router skipped: domains mismatch
--------> batv_redirect router <--------
local_part=aipaspa domain=mydomain.com
checking senders
address match: subject=area.fi...@newsmaggioli.it pattern=
newsmaggioli.it in ""? no (end of list)
area.fi...@newsmaggioli.it in ":"? no (end of list)
batv_redirect router skipped: senders mismatch
--------> static_route router <--------
local_part=aipaspa domain=mydomain.com
processing address_data
Starting Perl interpreter
calling static_route router
static_route router called for email...@mydomain.com
domain = mydomain.com
original list of hosts = "192.168.1.102" options =
expanded list of hosts = "192.168.1.102" options =
set transport static_smtp
finding IP address for 192.168.1.102
calling host_find_byname
fully qualified name = 192.168.1.102
gethostbyname looked up these IP addresses:
name=192.168.1.102 address=192.168.1.102
queued for static_smtp transport: local_part = aipaspa
domain = mydomain.com
errors_to=NULL
domain_data=NULL localpart_data=NULL
routed by static_route router
envelope to: email...@mydomain.com
transport: static_smtp
host 192.168.1.102 [192.168.1.102]



After routing: 
  Local deliveries: 
  Remote deliveries: 
    email...@mydomain.com 
  Failed addresses: 
  Deferred addresses: 
search_tidyup called 


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



--------> email...@mydomain.com <--------
search_tidyup called
changed uid/gid: remote delivery to email...@mydomain.com with
transport=static_smtp
uid=666 gid=666 pid=7447
auxiliary group list: <none>
set_process_info: 7447 delivering 1HHLx3-0007Dx-I6 using static_smtp
static_smtp transport entered
email...@mydomain.com
checking status of 192.168.1.102
locking /spool/db/retry.lockfile
locked /spool/db/retry.lockfile
set_process_info: 7446 delivering 1HHLx3-0007Dx-I6: waiting for a
remote delivery subprocess to finish
selecting on subprocess pipes
opened hints database /spool/db/retry: flags=0
dbfn_read: key=T:192.168.1.102:192.168.1.102
dbfn_read: key=T:192.168.1.102:192.168.1.102:1HHLx3-0007Dx-I6
no host retry record
192.168.1.102 [192.168.1.102] status = usable
192.168.1.102 in serialize_hosts? no (option unset)
delivering 1HHLx3-0007Dx-I6 to 192.168.1.102 [192.168.1.102]
(email...@mydomain.com)
set_process_info: 7447 delivering 1HHLx3-0007Dx-I6 to 192.168.1.102
[192.168.1.102] (email...@mydomain.com)
Connecting to 192.168.1.102 [192.168.1.102]:25 ... connected
waiting for data on socket
read response data: size=30
SMTP<< 220 ESMTP Mail Service
192.168.1.102 in hosts_avoid_esmtp? no (option unset)
SMTP>> EHLO mx1.idc.domain.it

waiting for data on socket 
read response data: size=118 
  SMTP<< 250-idc.domain.it [192.168.1.103], this server offers 4 
extensions 
         250-AUTH LOGIN 
         250-SIZE 0 
         250-HELP 
         250 AUTH=LOGIN 
192.168.1.102 in hosts_require_tls? no (option unset) 
not using PIPELINING 
192.168.1.102 in hosts_require_auth? no (option unset) 
192.168.1.102 in hosts_try_auth? no (option unset) 

SMTP>> MAIL FROM:<area.fi...@newsmaggioli.it> SIZE=60412

waiting for data on socket
read response data: size=43
SMTP<< 250 Requested mail action okay, completed
SMTP>> RCPT TO:<email...@mydomain.com>

waiting for data on socket
read response data: size=43
SMTP<< 250 Requested mail action okay, completed
SMTP>> DATA

waiting for data on socket
read response data: size=46
SMTP<< 354 Start mail input; end with <CRLF>.<CRLF>
SMTP>> writing message and terminating "."

removed header line:
X-LOC-Local-RCPT: email...@mydomain.com
---
writing data block fd=6 size=8189 timeout=300
writing data block fd=6 size=8189 timeout=300
writing data block fd=6 size=8189 timeout=300
writing data block fd=6 size=8189 timeout=300
writing data block fd=6 size=8189 timeout=300
writing data block fd=6 size=8189 timeout=300
writing data block fd=6 size=8189 timeout=300
writing data block fd=6 size=2038 timeout=300
waiting for data on socket
selecting on subprocess pipes
selecting on subprocess pipes
selecting on subprocess pipes
selecting on subprocess pipes
selecting on subprocess pipes
selecting on subprocess pipes
selecting on subprocess pipes
selecting on subprocess pipes
selecting on subprocess pipes
selecting on subprocess pipes
ok=0 send_quit=0 send_rset=1 continue_more=0 yield=0 first_address is
NULL
set_process_info: 7447 delivering 1HHLx3-0007Dx-I6: just tried
192.168.1.102 [192.168.1.102] for email...@mydomain.com: result OK
added retry item for T:192.168.1.102:192.168.1.102:1HHLx3-0007Dx-I6:
errno=110 more_errno=0,A flags=6
all IP addresses skipped or deferred at least one address
locking /spool/db/wait-static_smtp.lockfile
locked /spool/db/wait-static_smtp.lockfile
opened hints database /spool/db/wait-static_smtp: flags=2
Leaving static_smtp transport
set_process_info: 7447 delivering 1HHLx3-0007Dx-I6 (just run
static_smtp for email...@mydomain.com in subprocess)
search_tidyup called
reading pipe for subprocess 7447 (not ended)
read() yielded 5
selecting on subprocess pipes
reading pipe for subprocess 7447 (not ended)
read() yielded 147
reading retry information for T:
192.168.1.102:192.168.1.102:1HHLx3-0007Dx-I6 from subprocess
added retry item
selecting on subprocess pipes
reading pipe for subprocess 7447 (not ended)
read() yielded 111
selecting on subprocess pipes
reading pipe for subprocess 7447 (not ended)
read() yielded 2
Z0 item read
remote delivery process 7447 ended
set_process_info: 7446 delivering 1HHLx3-0007Dx-I6
post-process email...@mydomain.com (1)
LOG: MAIN
== email...@mydomain.com R=static_route T=static_smtp defer (110):
Connection timed out: SMTP timeout while connected to 192.168.1.102
[192.168.1.102] after end of data (59361 bytes written)

>>>>>>>>>>>>>>>> deliveries are done >>>>>>>>>>>>>>>>



changed uid/gid: post-delivery tidying
uid=666 gid=666 pid=7446
auxiliary group list: <none>
set_process_info: 7446 tidying up after delivering 1HHLx3-0007Dx-I6
Processing retry items
Succeeded addresses:
Failed addresses:
Deferred addresses:
email...@mydomain.com
locking /spool/db/retry.lockfile
locked /spool/db/retry.lockfile
opened hints database /spool/db/retry: flags=2
address match: subjec...@192.168.1.102 pattern=*
192.168.1.102 in "*"? yes (matched "*")
*...@192.168.1.102 in "*"? yes (matched "*")
retry for T:192.168.1.102:192.168.1.102:1HHLx3-0007Dx-I6
(mydomain.com) = *
dbfn_read: key=T:192.168.1.102:192.168.1.102:1HHLx3-0007Dx-I6
Writing retry data for T:192.168.1.102:192.168.1.102:1HHLx3-0007Dx-I6
first failed=1171467116 last try=1171469952 next try=1171470852
expired=0
errno=110 more_errno=0,A Connection timed out
dbfn_write: key=T:192.168.1.102:192.168.1.102:1HHLx3-0007Dx-I6
end of retry processing
time on queue = 57m27s
warning counts: required 0 done 0
delivery deferred: update_spool=0 header_rewritten=0
end delivery of 1HHLx3-0007Dx-I6
search_tidyup called
search_tidyup called


>>>>>>>>>>>>>>>> Exim pid=7446 terminating with rc=0 >>>>>>>>>>>>>>>>



------------------------------------------------------------------------
-----------------------------------------------------

Thank you in advance for your help
Marco