Date: Sun, 21 Jun 2020 22:33:48 +0100 From: Mike Clarke <jmc-freebsd2@milibyte.co.uk> To: freebsd-questions@freebsd.org Subject: Re: Exim - retry time not reached for any host Message-ID: <1954651.YXp4yczo3S@curlew> In-Reply-To: <40ca3e9d-2859-6428-e7ad-c1b2dff36a69@smokepit.net> References: <2534646.NQNxk83B2J@curlew> <40ca3e9d-2859-6428-e7ad-c1b2dff36a69@smokepit.net>
next in thread | previous in thread | raw e-mail | index | archive | help
On Saturday, 20 June 2020 01:07:04 BST Daniel Lysfjord via freebsd-questions wrote:
> On 19.06.2020 17:57, Mike Clarke wrote:
> [..]
>
> > So it looks very much like the problem lies somewhere in my system even
> > though there's been no changes made recently. I'd appreciate suggestions
> > on how I should go about tracing and fixing the cause of this problem.
>
> Have you tried to start exim with "-bd -d+all" to get some debug output?
OK, I've done that now and it's highlighted what's happening, though I'm not sure if it helps to
explain why;
To summarise it looks like the SSL connection fails but eventually succeeds after a number of
retries although the delay could be an hour or more.
As a workaround I've reverted exim from 4.94 to 4.93.0.4 which does not appear to suffer from this
problem.
And now for the details:
16:50:53 3161 Connecting to mail.gridhost.co.uk [95.142.156.28]:465 ... 95.142.156.28 in
hosts_try_fastopen? yes (matched "*")^M
16:50:53 3161 TFO mode connection attempt to 95.142.156.28, 0 data^M
16:50:53 3161 connected^M
16:50:53 3161 ?considering: $primary_hostname^M
16:50:53 3161 ???expanding: $primary_hostname^M
16:50:53 3161 ??????result: curlew.milibyte.co.uk^M
16:50:53 3161 95.142.156.28 in hosts_avoid_esmtp? no (option unset)^M
16:50:53 3161 95.142.156.28 in hosts_require_ocsp? no (option unset)^M
16:50:53 3161 95.142.156.28 in hosts_request_ocsp? yes (matched "*")^M
16:50:53 3161 setting SSL CTX options: 0x42004000^M
16:50:53 3161 Diffie-Hellman initialized from default with 2048-bit prime^M
16:50:53 3161 Initialized TLS^M
16:50:53 3161 95.142.156.28 in tls_verify_hosts? no (option unset)^M
16:50:53 3161 95.142.156.28 in tls_try_verify_hosts? yes (matched "*")^M
16:50:53 3161 tls_verify_certificates: system^M
16:50:53 3161 95.142.156.28 in tls_verify_cert_hostnames? yes (matched "*")^M
16:50:53 3161 Cert hostname to check: "mail.gridhost.co.uk"^M
16:50:53 3161 Calling SSL_connect^M
16:50:53 3161 SSL_connect: before SSL initialization^M
16:50:53 3161 SSL_connect: error in SSLv3/TLS write client hello^M
16:50:53 3161 TLS error '(SSL_connect): error:00000000:lib(0):func(0):reason(0)'^M
16:50:53 3161 TLS session fail: (SSL_connect): error:00000000:lib(0):func(0):reason(0)^M
16:50:53 3161 SMTP(close)>>^M
16:50:53 3161 set_process_info: 3161 delivering 1jn2FA-0000ow-Uy: just tried mail.gridhost.co.uk
[95.142.156.28]:465 for REDACTED@gmail.com:
result DEFER^M
16:50:53 3161 added retry item for T:mail.gridhost.co.uk:95.142.156.28:465: errno=-37
more_errno=0,A flags=2^M
This was repeated for the other 3 IP addresses for mail.gridhost.co.uk
Then followed periodic attempts to deliver:
17:10:45 3445 Connecting to mail.gridhost.co.uk [95.142.156.8]:465 ... 95.142.156.8 in
hosts_try_fastopen? yes (matched "*")^M
17:10:45 3445 SSL_connect: error in SSLv3/TLS write client hello^M
17:30:45 3493 Connecting to mail.gridhost.co.uk [95.142.156.8]:465 ... 95.142.156.8 in
hosts_try_fastopen? yes (matched "*")^M
17:30:45 3493 SSL_connect: error in SSLv3/TLS write client hello^M
And eventual success after 1 hour and 20 minutes
18:10:45 3840 Connecting to mail.gridhost.co.uk [95.142.156.18]:465 ... 95.142.156.18 in
hosts_try_fastopen? yes (matched "*")^M
18:10:45 3840 TFO mode connection attempt to 95.142.156.18, 0 data^M
18:10:45 3840 connected^M
18:10:45 3840 ?considering: $primary_hostname^M
18:10:45 3840 ???expanding: $primary_hostname^M
18:10:45 3840 ??????result: curlew.milibyte.co.uk^M
18:10:45 3840 95.142.156.18 in hosts_avoid_esmtp? no (option unset)^M
18:10:45 3840 95.142.156.18 in hosts_require_ocsp? no (option unset)^M
18:10:45 3840 95.142.156.18 in hosts_request_ocsp? yes (matched "*")^M
18:10:45 3840 setting SSL CTX options: 0x42004000^M
18:10:45 3840 Diffie-Hellman initialized from default with 2048-bit prime^M
18:10:45 3840 Initialized TLS^M
18:10:45 3840 95.142.156.18 in tls_verify_hosts? no (option unset)^M
18:10:45 3840 95.142.156.18 in tls_try_verify_hosts? yes (matched "*")^M
18:10:45 3840 tls_verify_certificates: system^M
18:10:45 3840 95.142.156.18 in tls_verify_cert_hostnames? yes (matched "*")^M
18:10:45 3840 Cert hostname to check: "mail.gridhost.co.uk"^M
18:10:45 3840 Calling SSL_connect^M
18:10:45 3840 SSL_connect: before SSL initialization^M
18:10:45 3840 SSL_connect: SSLv3/TLS write client hello^M
18:10:45 3840 SSL_connect: SSLv3/TLS write client hello^M
18:10:45 3840 SSL_connect: SSLv3/TLS read server hello^M
18:10:45 3840 SSL verify ok: depth=2 SN=/C=US/O=SecureTrust Corporation/CN=SecureTrust
CA^M
18:10:45 3840 SSL verify ok: depth=1 SN=/C=US/ST=Illinois/L=Chicago/O=Trustwave Holdings,
Inc./CN=Trustwave Organization Validation SHA256 CA
, Level 1/emailAddress=ca@trustwave.com^M
18:10:45 3840 SSL authenticated verify ok: depth=0 SN=/CN=*.gridhost.co.uk/O=Paragon
Internet Group Limited/L=Hayes/ST=England/C=GB^M
... snip ...
18:10:45 3840 SMTP<< 250 2.0.0 Ok: queued as 6BB47221B18C1^M
Previous tests have followed a similar pattern but with different times before successful delivery.
Exim was upgraded from 4.93.0.4 to 4.94 a few weeks ago so it's possible this might have been
happening since then. I don't often look at the exim log so wouldn't have noticed the long delays in
sending emails.
As an experiment I reverted to 4.93.0.4 and performed more tests with all emails being successfully
delivered on the first attempt.
This now leaves the question as to whether this is a new bug in 4.94 or if there's some less than
ideal setting in my configuration which I've managed to get away with over the last few years but is
causing a problem with the new version.
In case it's relevant here's what I expect to be the appropriate snippets from my exim
configuration:
milibyte_route:
driver = manualroute
domains = !+local_domains
transport = remote_auth_smtp
condition = ${if match_domain{${domain:$h_From:}}{milibyte.co.uk}{yes}{no}}
route_list = * mail3.gridhost.co.uk
no_more
remote_auth_smtp:
driver = smtp
protocol = smtps
hosts_require_auth = $host_address
hosts_require_tls = $host_address
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?1954651.YXp4yczo3S>