Author: Simon Date: To: exim-users Subject: Re: [exim] Need more informations about remote_smtp defer exim4 log
Yes sure,I'am sorry, I forgot to send you output with exim -d, here is
an example with an message in queue :
#exim -d -M 1ggnQv-00010z-Iu
Exim version 4.84_2 uid=0 gid=0 pid=8781 D=fbb95cfd
Berkeley DB: Berkeley DB 5.3.28: (September 9, 2013)
Support for: crypteq iconv() IPv6 PAM Perl Expand_dlfunc GnuTLS
move_frozen_messages Content_Scanning DKIM Old_Demime PRDR OCSP
Lookups (built-in): lsearch wildlsearch nwildlsearch iplsearch cdb dbm
dbmjz dbmnz dnsdb dsearch ldap ldapdn ldapm mysql nis nis0 passwd pgsql
sqlite
Authenticators: cram_md5 cyrus_sasl dovecot plaintext spa
Routers: accept dnslookup ipliteral iplookup manualroute queryprogram
redirect
Transports: appendfile/maildir/mailstore/mbx autoreply lmtp pipe smtp
Fixed never_users: 0
Size of off_t: 8
Compiler: GCC [4.9.2]
Library version: GnuTLS: Compile: 3.3.8
Runtime: 3.3.8
Library version: Cyrus SASL: Compile: 2.1.26
Runtime: 2.1.26 [Cyrus SASL]
Library version: PCRE: Compile: 8.35
Runtime: 8.35 2014-04-04
Total 19 lookups
Library version: MySQL: Compile: 5.5.59 [(Debian)]
Runtime: 5.5.59
Library version: SQLite: Compile: 3.8.7.1
Runtime: 3.8.7.1
WHITELIST_D_MACROS: "OUTGOING"
TRUSTED_CONFIG_LIST: "/etc/exim4/trusted_configs"
changed uid/gid: forcing real = effective
uid=0 gid=0 pid=8781
auxiliary group list: <none>
seeking password data for user "root": cache not available
getpwnam() succeeded uid=0 gid=0
changed uid/gid: calling tls_validate_require_cipher
uid=105 gid=109 pid=8783
auxiliary group list: <none>
tls_validate_require_cipher child 8783 ended: status=0x0
LOG: MAIN
Warning: purging the environment.
Suggested action: use keep_environment.
configuration file is /etc/exim4/exim4.conf
log selectors = 00000ffc 00232001
cwd=/root 4 args: exim -d -M 1ggnQv-00010z-Iu
trusted user
admin user
seeking password data for user "Debian-exim": cache not available
getpwnam() succeeded uid=105 gid=109
set_process_info: 8781 delivering specified messages
set_process_info: 8781 delivering 1ggnQv-00010z-Iu
reading spool file 1ggnQv-00010z-Iu-H
user=Debian-exim uid=105 gid=109 sender=sender_mail@???
sender_fullhost = 177-128-190-109.isp.overthebox.ovh (bureau2)
[109.190.128.177]
sender_rcvhost = 177-128-190-109.isp.overthebox.ovh ([109.190.128.177]
helo=bureau2)
sender_local=0 ident=unset
Non-recipients:
-->application@??? [0]
-->/home/mails/mboxs/synaptik.fr/application/:application@??? [2]
---- End of tree ----
recipients_count=2
body_linecount=4727 message_linecount=20
Delivery address list:
mail_to@???
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=O_RDONLY >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> Considering: mail_to@???
unique = mail_to@???
dbfn_read: key=R:orange.fr
dbfn_read: key=R:mail_to@???
dbfn_read: key=R:mail_to@???:<sender_mail@???>
no domain retry record
no address retry record
mail_to@???: queued for routing >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> routing mail_to@???
--------> system_aliases router <--------
local_part=valerie.wallrich domain=orange.fr
checking domains
orange.fr in "/home/mails/configs/domaines_master"? no (end of list)
orange.fr in "+local_domains"? no (end of list)
system_aliases router skipped: domains mismatch
--------> copy_out_mail router <--------
local_part=valerie.wallrich domain=orange.fr
calling copy_out_mail router
rda_interpret (string):
${extract{1}{:}{${lookup{${sender_address_domain}}lsearch{/home/mails/configs/backup_outgoing}{$value}fail}}}
search_open: lsearch "/home/mails/configs/backup_outgoing"
search_find: file="/home/mails/configs/backup_outgoing"
key="poirot-construction.fr" partial=-1 affix=NULL starflags=0
LRU list:
:/home/mails/configs/backup_outgoing
End
internal_search_find: file="/home/mails/configs/backup_outgoing"
type=lsearch key="poirot-construction.fr"
file lookup required for poirot-construction.fr
in /home/mails/configs/backup_outgoing
lookup failed
copy_out_mail router declined for mail_to@???
--------> dnslookup_users router <--------
local_part=valerie.wallrich domain=orange.fr
checking domains
cached no match for +local_domains
cached lookup data = NULL
orange.fr in "! +local_domains"? yes (end of list)
checking "condition"
search_open: lsearch "/home/mails/configs/users"
search_find: file="/home/mails/configs/users"
key="sender_mail@???" partial=-1 affix=NULL
starflags=0
LRU list:
:/home/mails/configs/users
:/home/mails/configs/backup_outgoing
End
internal_search_find: file="/home/mails/configs/users"
type=lsearch key="sender_mail@???"
file lookup required for sender_mail@???
in /home/mails/configs/users
lookup yielded: rzQ/.InCTHVLc:Arnaud
JEANNOT:105:109:/home/mails/mboxs/poirot-construction.fr/arnaud/:2000M:y:n:y:y:1:n:::0:Y:0:0:0:1:Votre
conseiller Poirot Constructions Bois:0:0:1432:2:2:1:3
search_open: lsearch "/home/mails/configs/users"
cached open
search_find: file="/home/mails/configs/users"
key="sender_mail@???" partial=-1 affix=NULL
starflags=0
LRU list:
:/home/mails/configs/users
:/home/mails/configs/backup_outgoing
End
internal_search_find: file="/home/mails/configs/users"
type=lsearch key="sender_mail@???"
cached data used for lookup of sender_mail@???
in /home/mails/configs/users
lookup yielded: rzQ/.InCTHVLc:Arnaud
JEANNOT:105:109:/home/mails/mboxs/poirot-construction.fr/arnaud/:2000M:y:n:y:y:1:n:::0:Y:0:0:0:1:Votre
conseiller Poirot Constructions Bois:0:0:1432:2:2:1:3
calling dnslookup_users router
dnslookup_users router called for mail_to@???
domain = orange.fr
DNS lookup of orange.fr (MX) succeeded
DNS lookup of smtp-in.orange.fr (AAAA) gave NO_DATA
returning DNS_NODATA
DNS lookup of smtp-in.orange.fr (A) succeeded
80.12.242.9 in "0.0.0.0 : 127.0.0.0/8 : 176.31.234.153"? no (end of list)
193.252.22.65 in "0.0.0.0 : 127.0.0.0/8 : 176.31.234.153"? no (end of list)
fully qualified name = orange.fr
host_find_bydns yield = HOST_FOUND (2); returned hosts:
smtp-in.orange.fr 80.12.242.9 MX=10
smtp-in.orange.fr 193.252.22.65 MX=10
set transport remote_smtp
queued for remote_smtp transport: local_part = valerie.wallrich
domain = orange.fr
errors_to=NULL
domain_data=NULL localpart_data=NULL
routed by dnslookup_users router
envelope to: mail_to@???
transport: remote_smtp
host smtp-in.orange.fr [80.12.242.9] MX=10
host smtp-in.orange.fr [193.252.22.65] MX=10 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> After routing:
Local deliveries:
Remote deliveries:
mail_to@???
Failed addresses:
Deferred addresses:
search_tidyup called >>>>>>>>>>>>>>>> Remote deliveries >>>>>>>>>>>>>>>> --------> mail_to@??? <--------
search_tidyup called
set_process_info: 8781 delivering 1ggnQv-00010z-Iu: waiting for a
remote delivery subprocess to finish
selecting on subprocess pipes
changed uid/gid: remote delivery to mail_to@??? with
transport=remote_smtp
uid=105 gid=109 pid=8785
auxiliary group list: <none>
set_process_info: 8785 delivering 1ggnQv-00010z-Iu using remote_smtp
remote_smtp transport entered
mail_to@???
checking status of smtp-in.orange.fr
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=O_RDONLY
dbfn_read: key=T:smtp-in.orange.fr:80.12.242.9
dbfn_read: key=T:smtp-in.orange.fr:80.12.242.9:1ggnQv-00010z-Iu
no message retry record
smtp-in.orange.fr [80.12.242.9] status = usable
80.12.242.9 in serialize_hosts? no (option unset)
delivering 1ggnQv-00010z-Iu to smtp-in.orange.fr [80.12.242.9]
(mail_to@???)
set_process_info: 8785 delivering 1ggnQv-00010z-Iu to smtp-in.orange.fr
[80.12.242.9] (mail_to@???)
Connecting to smtp-in.orange.fr [80.12.242.9]:25 from 176.31.234.153 ...
unable to bind outgoing SMTP call to 176.31.234.153: Address already in
usefailed: Address already in use
LOG: MAIN
smtp-in.orange.fr [80.12.242.9] Address already in use
set_process_info: 8785 delivering 1ggnQv-00010z-Iu: just tried
smtp-in.orange.fr [80.12.242.9] for mail_to@???: result DEFER
added retry item for T:smtp-in.orange.fr:80.12.242.9: errno=98
more_errno=0,M flags=2
address match test: subject=*@smtp-in.orange.fr pattern=*
smtp-in.orange.fr in "*"? yes (matched "*")
*@smtp-in.orange.fr in "*"? yes (matched "*")
checking status of smtp-in.orange.fr
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=O_RDONLY
dbfn_read: key=T:smtp-in.orange.fr:193.252.22.65
dbfn_read: key=T:smtp-in.orange.fr:193.252.22.65:1ggnQv-00010z-Iu
no message retry record
smtp-in.orange.fr [193.252.22.65] status = usable
193.252.22.65 in serialize_hosts? no (option unset)
delivering 1ggnQv-00010z-Iu to smtp-in.orange.fr [193.252.22.65]
(mail_to@???)
set_process_info: 8785 delivering 1ggnQv-00010z-Iu to smtp-in.orange.fr
[193.252.22.65] (mail_to@???)
Connecting to smtp-in.orange.fr [193.252.22.65]:25 from 176.31.234.153
... unable to bind outgoing SMTP call to 176.31.234.153: Address already
in usefailed: Address already in use
LOG: MAIN
smtp-in.orange.fr [193.252.22.65] Address already in use
set_process_info: 8785 delivering 1ggnQv-00010z-Iu: just tried
smtp-in.orange.fr [193.252.22.65] for mail_to@???: result DEFER
added retry item for T:smtp-in.orange.fr:193.252.22.65: errno=98
more_errno=0,M flags=2
all IP addresses skipped or deferred at least one address
updating wait-remote_smtp database
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=O_RDWR
dbfn_read: key=smtp-in.orange.fr
already listed for smtp-in.orange.fr
Leaving remote_smtp transport
set_process_info: 8785 delivering 1ggnQv-00010z-Iu (just run
remote_smtp for mail_to@??? in subprocess)
search_tidyup called
header write id:H,subid:0,size:14,final:H000014
reading pipe for subprocess 8785 (not ended)
read() yielded 21
header read id:H,subid:0,size:00014,required:21,remaining:21,unfinished:0
selecting on subprocess pipes
header write id:H,subid:0,size:16,final:H000016
reading pipe for subprocess 8785 (not ended)
read() yielded 23
header read id:H,subid:0,size:00016,required:23,remaining:23,unfinished:0
selecting on subprocess pipes
header write id:S,subid:0,size:4,final:S000004
reading pipe for subprocess 8785 (not ended)
read() yielded 11
header read id:S,subid:0,size:00004,required:11,remaining:11,unfinished:0
selecting on subprocess pipes
header write id:R,subid:0,size:44,final:R000044
reading pipe for subprocess 8785 (not ended)
read() yielded 51
header read id:R,subid:0,size:00044,required:51,remaining:51,unfinished:0
reading retry information for T:smtp-in.orange.fr:193.252.22.65 from
subprocess
added retry item
selecting on subprocess pipes
header write id:R,subid:0,size:42,final:R000042
reading pipe for subprocess 8785 (not ended)
read() yielded 49
header read id:R,subid:0,size:00042,required:49,remaining:49,unfinished:0
reading retry information for T:smtp-in.orange.fr:80.12.242.9 from
subprocess
added retry item
selecting on subprocess pipes
header write id:A,subid:0,size:15,final:A000015
reading pipe for subprocess 8785 (not ended)
read() yielded 22
header read id:A,subid:0,size:00015,required:22,remaining:22,unfinished:0
selecting on subprocess pipes
header write id:Z,subid:0,size:1,final:Z000001
reading pipe for subprocess 8785 (not ended)
read() yielded 8
header read id:Z,subid:0,size:00001,required:8,remaining:8,unfinished:0
Z00 item read
remote delivery process 8785 ended
set_process_info: 8781 delivering 1ggnQv-00010z-Iu
post-process mail_to@??? (1)
LOG: MAIN
== mail_to@??? R=dnslookup_users T=remote_smtp defer (98):
Address already in use >>>>>>>>>>>>>>>> deliveries are done >>>>>>>>>>>>>>>> changed uid/gid: post-delivery tidying
uid=105 gid=109 pid=8781
auxiliary group list: <none>
set_process_info: 8781 tidying up after delivering 1ggnQv-00010z-Iu
Processing retry items
Succeeded addresses:
Failed addresses:
Deferred addresses:
mail_to@???
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=O_RDWR
address match test: subject=*@smtp-in.orange.fr pattern=*
smtp-in.orange.fr in "*"? yes (matched "*")
*@smtp-in.orange.fr in "*"? yes (matched "*")
retry for T:smtp-in.orange.fr:80.12.242.9 (orange.fr) = * 0 0
dbfn_read: key=T:smtp-in.orange.fr:80.12.242.9
failing_interval=11656 message_age=2040
Writing retry data for T:smtp-in.orange.fr:80.12.242.9
first failed=1546929129 last try=1546940785 next try=1546944385 expired=0
errno=98 more_errno=0,M Address already in use
dbfn_write: key=T:smtp-in.orange.fr:80.12.242.9
address match test: subject=*@smtp-in.orange.fr pattern=*
smtp-in.orange.fr in "*"? yes (matched "*")
*@smtp-in.orange.fr in "*"? yes (matched "*")
retry for T:smtp-in.orange.fr:193.252.22.65 (orange.fr) = * 0 0
dbfn_read: key=T:smtp-in.orange.fr:193.252.22.65
failing_interval=903 message_age=2040
Writing retry data for T:smtp-in.orange.fr:193.252.22.65
first failed=1546939882 last try=1546940785 next try=1546941685 expired=0
errno=98 more_errno=0,M Address already in use
dbfn_write: key=T:smtp-in.orange.fr:193.252.22.65
end of retry processing
time on queue = 34m
warning counts: required 0 done 0
delivery deferred: update_spool=0 header_rewritten=0
end delivery of 1ggnQv-00010z-Iu
search_tidyup called
search_tidyup called >>>>>>>>>>>>>>>> Exim pid=8781 terminating with rc=0 >>>>>>>>>>>>>>>>
two interesting things in this log, first :
mail_to@??? R=dnslookup_users T=remote_smtp defer (98): Address
already in use
and second :
Connecting to smtp-in.orange.fr [80.12.242.9]:25 from 176.31.234.153 ...
unable to bind outgoing SMTP call to 176.31.234.153: Address already in
usefailed: Address already in use
Le 07/01/2019 à 17:12, Evgeniy Berdnikov via Exim-users a écrit : > On Mon, Jan 07, 2019 at 09:17:28AM +0100, Simon via Exim-users wrote:
>> When I try to send message with this command *exim -d -M <exim-message-id>
>> *sometimes message sent and sometimes I have again *remote_smtp defer
>> (98).*||||
> If you run exim with "-d", there may be some relevant information,
> but you did not post it.
>
> What "strace -e network -f exim -M <exim-message-id>" shows on error?
