Mailing List Archive

Need more informations about remote_smtp defer exim4 log
Hi all,

I'am encoutering some trouble with exim4, occasionally when I try to
send message, in mainlog file, I can see this line :

*address_to@domain.com R=dnslookup_users T=remote_smtp defer (98):
Address already in use*

After that, the mail is put in mail queue, I don't know why, I have
searched on web, informations about *remote_smtp defer (98) *but I
didn't find any useful information.

The probleme occurs with multiple domain names.


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 somebody has a lead, I would be happy :)


Thanks

Simon
**

--
## 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/
Re: Need more informations about remote_smtp defer exim4 log [ In reply to ]
On 07/01/2019 08:17, Simon via Exim-users wrote:
> *address_to@domain.com R=dnslookup_users T=remote_smtp defer (98):
> Address already in use*

That's quite difficult error to induce. It's a conflict in
address usage between the socket being used and some other
process.

Is there anything unusual about the system you are running?
Multiple MTAs active, perhaps? Or malware doing their
own mailsending...

We might need to see debug for this, but I'd guess
it's on the "connect" syscall being done by the transport.

> After that, the mail is put in mail queue, I don't know why,

It gets queued because the attempt to send it failed.
That part is expected given the earlier error.
--
Cheers,
Jeremy

--
## 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/
Re: Need more informations about remote_smtp defer exim4 log [ In reply to ]
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?
--
Eugene Berdnikov

--
## 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/
Re: Need more informations about remote_smtp defer exim4 log [ In reply to ]
On 07/01/2019 16:12, Evgeniy Berdnikov via Exim-users wrote:
> If you run exim with "-d", there may be some relevant information,
> but you did not post it.

Also, as this is an intermittent problem, speculative debug
might be a useful technique. Look into the "control=debug"
ACL modifier, and the "msg:delivery" event (assmuming a
recent-enough Exim version).
--
Cheers,
Jeremy

--
## 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/
Re: Need more informations about remote_smtp defer exim4 log [ In reply to ]
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@poirot-construction.fr
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@synaptik.fr [0]
-->/home/mails/mboxs/synaptik.fr/application/:application@synaptik.fr [2]
---- End of tree ----
recipients_count=2
body_linecount=4727 message_linecount=20
Delivery address list:
  mail_to@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
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
Considering: mail_to@orange.fr
unique = mail_to@orange.fr
dbfn_read: key=R:orange.fr
dbfn_read: key=R:mail_to@orange.fr
dbfn_read: key=R:mail_to@orange.fr:<sender_mail@poirot-construction.fr>
no domain retry record
no address retry record
mail_to@orange.fr: queued for routing
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
routing mail_to@orange.fr
--------> 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@orange.fr
--------> 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@poirot-construction.fr" 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@poirot-construction.fr"
file lookup required for sender_mail@poirot-construction.fr
  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@poirot-construction.fr" 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@poirot-construction.fr"
cached data used for lookup of sender_mail@poirot-construction.fr
  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@orange.fr
  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@orange.fr
  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@orange.fr
  Failed addresses:
  Deferred addresses:
search_tidyup called
>>>>>>>>>>>>>>>> Remote deliveries >>>>>>>>>>>>>>>>
--------> mail_to@orange.fr <--------
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@orange.fr 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@orange.fr
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@orange.fr)
set_process_info:  8785 delivering 1ggnQv-00010z-Iu to smtp-in.orange.fr
[80.12.242.9] (mail_to@orange.fr)
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@orange.fr: 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@orange.fr)
set_process_info:  8785 delivering 1ggnQv-00010z-Iu to smtp-in.orange.fr
[193.252.22.65] (mail_to@orange.fr)
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@orange.fr: 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@orange.fr 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@orange.fr (1)
LOG: MAIN
  == mail_to@orange.fr 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@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_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@orange.fr 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

And here is output with strace

#strace -e network -f exim -M 1ggnQv-00010z-Iu

socket(PF_LOCAL, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 4
connect(4, {sa_family=AF_LOCAL, sun_path="/var/run/nscd/socket"}, 110) =
-1 ENOENT (No such file or directory)
socket(PF_LOCAL, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 4
connect(4, {sa_family=AF_LOCAL, sun_path="/var/run/nscd/socket"}, 110) =
-1 ENOENT (No such file or directory)
socket(PF_LOCAL, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 4
connect(4, {sa_family=AF_LOCAL, sun_path="/var/run/nscd/socket"}, 110) =
-1 ENOENT (No such file or directory)
socket(PF_LOCAL, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 4
connect(4, {sa_family=AF_LOCAL, sun_path="/var/run/nscd/socket"}, 110) =
-1 ENOENT (No such file or directory)
Process 16478 attached
[pid 16478] +++ exited with 0 +++
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=16478,
si_uid=105, si_status=0, si_utime=0, si_stime=0} ---
socket(PF_INET, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 9
connect(9, {sa_family=AF_INET, sin_port=htons(53),
sin_addr=inet_addr("127.0.0.1")}, 16) = 0
sendto(9, "\r\204\1\0\0\1\0\0\0\0\0\0\6orange\2fr\0\0\17\0\1", 27,
MSG_NOSIGNAL, NULL, 0) = 27
recvfrom(9,
"\r\204\201\200\0\1\0\1\0\2\0\4\6orange\2fr\0\0\17\0\1\300\f\0\17\0"...,
2048, 0, {sa_family=AF_INET, sin_port=htons(53),
sin_addr=inet_addr("127.0.0.1")}, [16]) = 175
socket(PF_INET, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 9
connect(9, {sa_family=AF_INET, sin_port=htons(53),
sin_addr=inet_addr("127.0.0.1")}, 16) = 0
sendto(9, "\25>\1\0\0\1\0\0\0\0\0\0\7smtp-in\6orange\2fr\0\0"..., 35,
MSG_NOSIGNAL, NULL, 0) = 35
recvfrom(9, "\25>\201\200\0\1\0\0\0\1\0\0\7smtp-in\6orange\2fr\0\0"...,
2048, 0, {sa_family=AF_INET, sin_port=htons(53),
sin_addr=inet_addr("127.0.0.1")}, [16]) = 86
socket(PF_INET, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 9
connect(9, {sa_family=AF_INET, sin_port=htons(53),
sin_addr=inet_addr("127.0.0.1")}, 16) = 0
sendto(9, "a\235\1\0\0\1\0\0\0\0\0\0\7smtp-in\6orange\2fr\0\0"..., 35,
MSG_NOSIGNAL, NULL, 0) = 35
recvfrom(9, "a\235\201\200\0\1\0\2\0\2\0\2\7smtp-in\6orange\2fr\0\0"...,
2048, 0, {sa_family=AF_INET, sin_port=htons(53),
sin_addr=inet_addr("127.0.0.1")}, [16]) = 159
Process 16479 attached
[pid 16479] socket(PF_LOCAL, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 8
[pid 16479] connect(8, {sa_family=AF_LOCAL,
sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or
directory)
[pid 16479] socket(PF_LOCAL, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 8
[pid 16479] connect(8, {sa_family=AF_LOCAL,
sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or
directory)
[pid 16479] socket(PF_INET, SOCK_STREAM, IPPROTO_IP) = 8
[pid 16479] setsockopt(8, SOL_TCP, TCP_NODELAY, [1], 4) = 0
[pid 16479] bind(8, {sa_family=AF_INET, sin_port=htons(0),
sin_addr=inet_addr("176.31.234.153")}, 16) = -1 EADDRINUSE (Address
already in use)
[pid 16479] socket(PF_INET, SOCK_STREAM, IPPROTO_IP) = 8
[pid 16479] setsockopt(8, SOL_TCP, TCP_NODELAY, [1], 4) = 0
[pid 16479] bind(8, {sa_family=AF_INET, sin_port=htons(0),
sin_addr=inet_addr("176.31.234.153")}, 16) = -1 EADDRINUSE (Address
already in use)
[pid 16479] +++ exited with 0 +++
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=16479,
si_uid=105, si_status=0, si_utime=0, si_stime=1} ---
+++ exited with 0 +++


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?

--
## 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/
Re: Need more informations about remote_smtp defer exim4 log [ In reply to ]
On 08/01/2019 09:55, Simon via Exim-users wrote:
> 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
> use

We're trying to bind the local address, before making the connection.
This is done in order to force use of a specified interface, because
of the transpotr configuration. The bind syscall uses an IP address
and port zero (which should mean "any port", and have the kernel assign
an ephemeral port). There's no good reason for that to fail, that I can
think of, beyond being totally out of ports.

Is the system configured with a very restricted range for ephemeral
ports? Is it very busy, as shown by "netstat -pant"? What OS, distro
and version?

> And here is output with strace

> [pid 16479] socket(PF_INET, SOCK_STREAM, IPPROTO_IP) = 8
> [pid 16479] setsockopt(8, SOL_TCP, TCP_NODELAY, [1], 4) = 0
> [pid 16479] bind(8, {sa_family=AF_INET, sin_port=htons(0),
> sin_addr=inet_addr("176.31.234.153")}, 16) = -1 EADDRINUSE (Address
> already in use)

Matches the above.
--
Cheers,
Jeremy

--
## 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/
Re: Need more informations about remote_smtp defer exim4 log [ In reply to ]
What do you mean by very restricted range for ephemeral port? How can I
know that, because it's not me who done the server/configuration
installation.

Here is output for uname -a

Linux 3.10.23-xxxx-std-ipv6-64 #1 SMP Tue Mar 18 14:48:24 CET 2014
x86_64 GNU/Linux

And here is netstat -pant, output is amazing !!!


Connexions Internet actives (serveurs et établies)
Proto Recv-Q Send-Q Adresse locale          Adresse distante       
Etat        PID/Program name
tcp        0      0 127.0.0.1:783 0.0.0.0:*               LISTEN     
1327/spamd child
tcp        0      0 0.0.0.0:143 0.0.0.0:*               LISTEN      1/init
tcp        0      0 0.0.0.0:111 0.0.0.0:*               LISTEN     
4496/rpcbind
tcp        0      0 176.31.234.153:465 0.0.0.0:*              
LISTEN      25015/exim4
tcp        0      0 127.0.0.1:53 0.0.0.0:*               LISTEN     
31475/named
tcp        0      0 176.31.234.153:4949 0.0.0.0:*              
LISTEN      23723/perl
tcp        0      0 0.0.0.0:22 0.0.0.0:*               LISTEN     
27537/sshd
tcp        0      0 127.0.0.1:25 0.0.0.0:*               LISTEN     
25015/exim4
tcp        0      0 176.31.234.153:25 0.0.0.0:*              
LISTEN      25015/exim4
tcp        0      0 127.0.0.1:953 0.0.0.0:*               LISTEN     
31475/named
tcp        0      0 0.0.0.0:4190 0.0.0.0:*               LISTEN     
23354/dovecot
tcp        0      0 0.0.0.0:993 0.0.0.0:*               LISTEN      1/init
tcp        0      0 127.0.0.1:10024 0.0.0.0:*               LISTEN     
5706/amavisd-new (m
tcp        0      0 127.0.0.1:10025 0.0.0.0:*               LISTEN     
25015/exim4
tcp        0      0 0.0.0.0:3306 0.0.0.0:*               LISTEN     
22696/mysqld
tcp        0      0 127.0.0.1:10026 0.0.0.0:*               LISTEN     
5270/perl
tcp        0      0 176.31.234.153:587 0.0.0.0:*              
LISTEN      25015/exim4
tcp        0      0 127.0.0.1:10028 0.0.0.0:*               LISTEN     
5288/perl
tcp        0      0 176.31.234.153:56947 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:47225 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:46949 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:60357 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:33023 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:55981 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:39292 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:52523 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:53944 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:39764 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:44355 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:60683 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:42479 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:43909 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:52001 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:59347 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:52934 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:58318 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:37072 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:59808 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:45440 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:52302 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:55509 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:39606 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:42176 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:58536 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:39012 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:34615 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:45383 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:59129 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:40227 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:35386 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:42800 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:48375 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:34533 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:3306 109.190.128.177:38364  
TIME_WAIT   -
tcp        0      0 176.31.234.153:39307 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:54227 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:39840 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:42142 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:60842 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:40563 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:43172 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:33117 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:51507 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:36488 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:57089 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:60800 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:50443 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:45284 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:59523 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:60284 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:56499 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:45977 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:53045 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:47498 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:38472 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:49769 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:53636 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:57940 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:51090 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:143 109.190.128.177:52982  
ESTABLISHED 1273/imap-login
tcp        0      0 176.31.234.153:34881 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:33908 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:58282 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:55682 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:59792 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:45427 85.233.202.178:80      
TIME_WAIT   -
tcp        0      0 176.31.234.153:40023 85.233.202.178:80      
TIME_WAIT   -



lot of line between 25621 !!!!!


tcp6       0      0 :::110 :::*                    LISTEN     
4607/couriertcpd
tcp6       0      0 ::1:783 :::*                    LISTEN     
1327/spamd child
tcp6       0      0 :::143 :::*                    LISTEN      1/init
tcp6       0      0 :::111 :::*                    LISTEN      4496/rpcbind
tcp6       0      0 :::80 :::*                    LISTEN      9551/apache2
tcp6       0      0 2001:41d0:2:fb99:::465 :::*                   
LISTEN      25015/exim4
tcp6       0      0 ::1:53 :::*                    LISTEN      31475/named
tcp6       0      0 :::22 :::*                    LISTEN      27537/sshd
tcp6       0      0 2001:41d0:2:fb99:::25 :::*                   
LISTEN      25015/exim4
tcp6       0      0 ::1:953 :::*                    LISTEN      31475/named
tcp6       0      0 :::443 :::*                    LISTEN      9551/apache2
tcp6       0      0 :::4190 :::*                    LISTEN     
23354/dovecot
tcp6       0      0 :::993 :::*                    LISTEN      1/init
tcp6       0      0 :::995 :::*                    LISTEN     
4605/couriertcpd
tcp6       0      0 ::1:10024 :::*                    LISTEN     
5706/amavisd-new (m
tcp6       0      0 2001:41d0:2:fb99:::587 :::*                   
LISTEN      25015/exim4
tcp6       0      0 176.31.234.153:80 109.190.128.177:45558   TIME_WAIT   -
tcp6       0      0 176.31.234.153:80 77.153.35.92:50836     
ESTABLISHED 8902/apache2
tcp6       0      0 176.31.234.153:80 109.190.128.177:45614   TIME_WAIT   -
tcp6       0      0 2001:41d0:2:fb99:::993 2a01:cb11:229:7f0:44497
ESTABLISHED 27739/imap-login
tcp6       0      0 ::1:34713 ::1:783                 TIME_WAIT   -
tcp6       0      0 ::1:53868 ::1:783                 TIME_WAIT   -
tcp6       0      0 2001:41d0:2:fb99::45299 2a00:1450:4007:80f:::80
TIME_WAIT   -
tcp6       0      0 176.31.234.153:80 77.153.35.92:50835     
ESTABLISHED 8901/apache2
tcp6       0      0 ::1:37773 ::1:783                 TIME_WAIT   -
tcp6       0      0 ::1:34712 ::1:783                 TIME_WAIT   -
tcp6       0      0 2001:41d0:2:fb99:::993 2a01:cb11:229:7f0:44500
ESTABLISHED 31263/imap-login
tcp6       0      0 ::1:53866 ::1:783                 TIME_WAIT   -
tcp6       0      0 ::1:37698 ::1:783                 TIME_WAIT   -
tcp6       0      0 176.31.234.153:80 109.190.128.177:39420   TIME_WAIT   -
tcp6       0      0 ::1:38284 ::1:783                 TIME_WAIT   -



> On 08/01/2019 09:55, Simon via Exim-users wrote:
>> 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
>> use
> We're trying to bind the local address, before making the connection.
> This is done in order to force use of a specified interface, because
> of the transpotr configuration. The bind syscall uses an IP address
> and port zero (which should mean "any port", and have the kernel assign
> an ephemeral port). There's no good reason for that to fail, that I can
> think of, beyond being totally out of ports.
>
> Is the system configured with a very restricted range for ephemeral
> ports? Is it very busy, as shown by "netstat -pant"? What OS, distro
> and version?
>
>> And here is output with strace
>> [pid 16479] socket(PF_INET, SOCK_STREAM, IPPROTO_IP) = 8
>> [pid 16479] setsockopt(8, SOL_TCP, TCP_NODELAY, [1], 4) = 0
>> [pid 16479] bind(8, {sa_family=AF_INET, sin_port=htons(0),
>> sin_addr=inet_addr("176.31.234.153")}, 16) = -1 EADDRINUSE (Address
>> already in use)
> Matches the above.

--
## 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/
Re: Need more informations about remote_smtp defer exim4 log [ In reply to ]
On 08/01/2019 11:23, Simon via Exim-users wrote:
> What do you mean by very restricted range for ephemeral port? How can I
> know that, because it's not me who done the server/configuration
> installation.

Perhaps you need to read up on general IP networking concepts, to learn
about ephemeral ports.

cat /proc/sys/net/ipv4/ip_local_port_range
cat /proc/sys/net/ipv4/ip_local_reserved_ports

> Here is output for uname -a
>
> Linux 3.10.23-xxxx-std-ipv6-64 #1 SMP Tue Mar 18 14:48:24 CET 2014
> x86_64 GNU/Linux

You didn't say what distro. At least that tells me it's a Linux.

> And here is netstat -pant, output is amazing !!!

Well, I didn't need to see the whole output - merely get you
to look and interpret. However, if that is all of it - it
doesn't show a problem.

--
Cheers,
Jeremy


--
## 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/
Re: Need more informations about remote_smtp defer exim4 log [ In reply to ]
Hi, Simon.

On Tue, Jan 08, 2019 at 10:55:19AM +0100, Simon via Exim-users wrote:
> #exim -d -M 1ggnQv-00010z-Iu
...
> 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

It seems that your Exim is configured to use 176.31.234.153 as local
ip-address. To check look for "local_interfaces" variable in config,
or (if you are running Debian) for MAIN_LOCAL_INTERFACES macro and/or
"dc_local_interfaces parameter" in /etc/exim4/update-exim4.conf.conf.

Exim tries to bind() socket to this address before connect() syscall,
and fails if all ports are busy. Address space exhausts much quickly
with bind() than without it. The question is whether you really need
binding to ip=176.31.234.153. If not, you have better to remove it.

On Tue, Jan 08, 2019 at 12:23:46PM +0100, Simon via Exim-users wrote:
> tcp 0 0 176.31.234.153:58282 85.233.202.178:80 TIME_WAIT
> -
> tcp 0 0 176.31.234.153:55682 85.233.202.178:80 TIME_WAIT
> -
> tcp 0 0 176.31.234.153:59792 85.233.202.178:80 TIME_WAIT
> -
> tcp 0 0 176.31.234.153:45427 85.233.202.178:80 TIME_WAIT
> -
> tcp 0 0 176.31.234.153:40023 85.233.202.178:80 TIME_WAIT
> -
>
> lot of line between 25621 !!!!!

Does it mean there are ~26000 similar lines? If so, this is a source of
address space pollution: some application (web client) makes many HTTP
requests to 85.233.202.178, occupying ports on local ip=176.31.234.153.

Quick workaround: change kernel parameter "net.ipv4.ip_local_port_range"
(default is "32768 60999" in modern Linux kernels, for 28230 ports).
Then fix your web application or move it to another host.
--
Eugene Berdnikov

--
## 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/
Re: Need more informations about remote_smtp defer exim4 log [ In reply to ]
Ok, if i do cat /proc/sys/net/ipv4/ip_local_port_range I have this output

32768    61000

And here is output of cat /proc/version

Linux version 3.10.23-xxxx-std-ipv6-64 (kernel@kernel.ovh.net) (gcc
version 4.7.2 (Debian 4.7.2-5) ) #1 SMP Tue Mar 18 14:48:24 CET 2014


I think the problem come from this address 85.233.202.178:80, this is a
web service use by curl in php script, and 99.9% lines that come from
netstat, I will talk to developer :)


Le 08/01/2019 à 12:43, Jeremy Harris via Exim-users a écrit :
> On 08/01/2019 11:23, Simon via Exim-users wrote:
>> What do you mean by very restricted range for ephemeral port? How can I
>> know that, because it's not me who done the server/configuration
>> installation.
> Perhaps you need to read up on general IP networking concepts, to learn
> about ephemeral ports.
>
> cat /proc/sys/net/ipv4/ip_local_port_range
> cat /proc/sys/net/ipv4/ip_local_reserved_ports
>
>> Here is output for uname -a
>>
>> Linux 3.10.23-xxxx-std-ipv6-64 #1 SMP Tue Mar 18 14:48:24 CET 2014
>> x86_64 GNU/Linux
> You didn't say what distro. At least that tells me it's a Linux.
>
>> And here is netstat -pant, output is amazing !!!
> Well, I didn't need to see the whole output - merely get you
> to look and interpret. However, if that is all of it - it
> doesn't show a problem.
>

--
## 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/