-----Messaggio originale-----
Da: Exim-users [
mailto:exim-users-bounces+info=swwork.it@exim.org] Per conto
di Heiko Schlittermann via Exim-users
Inviato: martedì 19 settembre 2017 23:47
A: exim-users@???
Oggetto: Re: [exim] "Introduce a delay into the SMTP transaction" -
connection timeout
SW & Work SaS <info@???> (Di 19 Sep 2017 23:23:36 CEST):
> Hi all,
>
> I'm having a problem sending email to a particular network.
> We have Exim 4.87 and is working quite well without particular problem.
> and doing a check with mxtoolbox give a warning for the SMTP transaction
> time
> SMTP Transaction Time 15.297 seconds - Not good! on Transaction
Time
>
> I can telnet the mail server and they have exim 4.89
> the answer time to telnet is about 19 seconds
>
> I'm rather sure that they have cPanel in place with the new tarpitting
> choice on
> Introduce a delay into the SMTP transaction for unknown hosts and messages
> detected as spam
>
> But, unfortunately, we have no connection with this network and a first
> request to them has been refused as we have no active services with them.
>
> I tried to put these set in the smtp transport of our exim conf
> connect_timeout = 10m
> command_timeout = 5m
> data_timeout = 5m
> final_timeout = 10m
> but they did not help.
What does your logs say about the connection attempts?
Do you have tcpdump traces, in case the logs are not meaningful?
Did you try sending via
<message.eml exim -d user@destination
?
Does it happen during recipient verification (in case you do that)
or does it happen during the delivery?
> Question, is there anything I can do (or try) to manage the long initial
> delay while connecting to this servers ?
> There should be something as verify-email.org manage to go on and do the
> recipient check.
I do not know what verify-email.org does. Maybe theyre known to the
particular servers meanwhile.
Best regards from Dresden/Germany
Viele Grüße aus Dresden
Heiko Schlittermann
--
SCHLITTERMANN.de ---------------------------- internet & unix support -
Heiko Schlittermann, Dipl.-Ing. (TU) - {fon,fax}: +49.351.802998{1,3} -
gnupg encrypted messages are welcome --------------- key ID: F69376CE -
! key id 7CBF764A and 972EAC9F are revoked since 2015-01 ------------ -
Thanks Heiko,
Thanks Jeremy,
I've tried now to send with debug one message still in queue,
below is the relevant part
===
--------> mylookuphost router <--------
local_part=info domain=thistledesign.it
checking domains
cached no match for +local_domains
cached lookup data = NULL
thistledesign.it in "! +local_domains"? yes (end of list)
calling mylookuphost router
mylookuphost router called for info@???
domain = thistledesign.it
DNS lookup of thistledesign.it (MX) succeeded
DNS lookup of smtp.thistledesign.it (A) succeeded
set_address_from_dns: A query succeeded; skipping AAAA query (cPanel patched
behavior)
46.252.149.139 in "<; @[]; 127.0.0.0/8 ; 0.0.0.0 ; ::1 ;
0000:0000:0000:0000:0000:ffff:7f00:0000/8"? no (end of list)
46.252.149.139 in "+loopback : 64.94.110.0/24"? no (end of list)
fully qualified name = thistledesign.it
host_find_bydns yield = HOST_FOUND (2); returned hosts:
smtp.thistledesign.it 46.252.149.139 MX=10
set transport my_remote_smtp
queued for my_remote_smtp transport: local_part = info
domain = thistledesign.it
errors_to=NULL
domain_data=NULL localpart_data=NULL
routed by mylookuphost router
envelope to: info@???
transport: my_remote_smtp
host smtp.thistledesign.it [46.252.149.139] MX=10
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
After routing:
Local deliveries:
Remote deliveries:
info@???
Failed addresses:
Deferred addresses:
search_tidyup called
>>>>>>>>>>>>>>>> Remote deliveries >>>>>>>>>>>>>>>>
--------> info@??? <--------
search_tidyup called
set_process_info: 16150 delivering 1duKcf-00088V-Uv: waiting for a remote
delivery subprocess to finish
selecting on subprocess pipes
changed uid/gid: remote delivery to info@??? with
transport=my_remote_smtp
uid=47 gid=12 pid=16159
auxiliary group list: <none>
set_process_info: 16159 delivering 1duKcf-00088V-Uv using my_remote_smtp
my_remote_smtp transport entered
info@???
checking status of smtp.thistledesign.it
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=O_RDONLY
dbfn_read: key=T:smtp.thistledesign.it:46.252.149.139/207.58.179.71
dbfn_read:
key=T:smtp.thistledesign.it:46.252.149.139/207.58.179.71:1duKcf-00088V-Uv
no message retry record
smtp.thistledesign.it [46.252.149.139]/207.58.179.71 status = usable
46.252.149.139 in serialize_hosts? no (option unset)
delivering 1duKcf-00088V-Uv to smtp.thistledesign.it [46.252.149.139]
(info@???)
set_process_info: 16159 delivering 1duKcf-00088V-Uv to smtp.thistledesign.it
[46.252.149.139] (info@???)
selecting on subprocess pipes
Connecting to smtp.thistledesign.it [46.252.149.139]:25 from 207.58.179.71
... failed: Connection timed out (timeout=10m)
LOG: MAIN
H=smtp.thistledesign.it [46.252.149.139] Connection timed out
set_process_info: 16159 delivering 1duKcf-00088V-Uv: just tried
smtp.thistledesign.it [46.252.149.139] for info@???: result
DEFER
added retry item for T:smtp.thistledesign.it:46.252.149.139/207.58.179.71:
errno=110 more_errno=1,M flags=2
all IP addresses skipped or deferred at least one address
updating wait-my_remote_smtp database
locking /var/spool/exim/db/wait-my_remote_smtp.lockfile
locked /var/spool/exim/db/wait-my_remote_smtp.lockfile
EXIM_DBOPEN(/var/spool/exim/db/wait-my_remote_smtp)
returned from EXIM_DBOPEN
opened hints database /var/spool/exim/db/wait-my_remote_smtp: flags=O_RDWR
dbfn_read: key=smtp.thistledesign.it
already listed for smtp.thistledesign.it
Leaving my_remote_smtp transport
set_process_info: 16159 delivering 1duKcf-00088V-Uv (just run my_remote_smtp
for info@??? in subprocess)
search_tidyup called
header write id:H,subid:0,size:17,final:H000017
header write id:S,subid:0,size:4,final:S000004
header write id:D,subid:0,size:4,final:D000004
DSN write: addr->dsn_aware = 0
header write id:R,subid:0,size:63,final:R000063
header write id:A,subid:0,size:15,final:A000015
header write id:Z,subid:0,size:1,final:Z000001
reading pipe for subprocess 16159 (not ended)
read() yielded 146
header read id:H,subid:0,size:00017,required:24,remaining:146,unfinished:0
header read id:S,subid:0,size:00004,required:11,remaining:122,unfinished:0
header read id:D,subid:0,size:00004,required:11,remaining:111,unfinished:0
DSN read: addr->dsn_aware = 0
header read id:R,subid:0,size:00063,required:70,remaining:100,unfinished:0
reading retry information for
T:smtp.thistledesign.it:46.252.149.139/207.58.179.71 from subprocess
added retry item
header read id:A,subid:0,size:00015,required:22,remaining:30,unfinished:0
header read id:Z,subid:0,size:00001,required:8,remaining:8,unfinished:0
Z00 item read
remote delivery process 16159 ended
set_process_info: 16150 delivering 1duKcf-00088V-Uv
post-process info@??? (1)
LOG: MAIN
== info@??? R=mylookuphost T=my_remote_smtp defer (110):
Connection timed out
>>>>>>>>>>>>>>>> deliveries are done >>>>>>>>>>>>>>>>
changed uid/gid: post-delivery tidying
uid=47 gid=12 pid=16150
auxiliary group list: <none>
set_process_info: 16150 tidying up after delivering 1duKcf-00088V-Uv
Processing retry items
Succeeded addresses:
Failed addresses:
Deferred addresses:
info@???
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=O_RDWR
address match test: subject=*@smtp.thistledesign.it pattern=*
smtp.thistledesign.it in "*"? yes (matched "*")
*@smtp.thistledesign.it in "*"? yes (matched "*")
retry for T:smtp.thistledesign.it:46.252.149.139/207.58.179.71
(thistledesign.it) = * 0 0
dbfn_read: key=T:smtp.thistledesign.it:46.252.149.139/207.58.179.71
failing_interval=23318 message_age=23320
Writing retry data for T:smtp.thistledesign.it:46.252.149.139/207.58.179.71
first failed=1505835656 last try=1505858974 next try=1505866777 expired=0
errno=110 more_errno=1,M Connection timed out
dbfn_write: key=T:smtp.thistledesign.it:46.252.149.139/207.58.179.71
end of retry processing
time on queue = 6h29m53s
warning counts: required 0 done 0
delivery deferred: update_spool=0 header_rewritten=0
end delivery of 1duKcf-00088V-Uv
search_tidyup called
search_tidyup called
===
The timeout happens at connection
Connecting to smtp.thistledesign.it [46.252.149.139]:25 from 207.58.179.71
... failed: Connection timed out (timeout=10m)
but while it reports "...Connection timed out (timeout=10m)..." the drop
happens after a few seconds, not after 10 minutes.
Best Regards
Flaviano
