runtime: Hang in x509certificate build chain when using a ```Let's Encrypt``` cert.

In Ubuntu 16.04, dotnet core 2.0.3 Running a webhost console app with a server certificate issued by Let's Encrypt Server is listening to https://172.31.46.243:443 (my private IP address)

Trying to run:

openssl s_client -connect <my-public-dns-name>:443 -msg

Output:

ubuntu@ip-172-31-46-243:~$ openssl s_client -connect <my-public-dns-name>:443 -msg
CONNECTED(00000003)
>>> TLS 1.2  [length 0005]
    16 03 01 01 2c
>>> TLS 1.2 Handshake [length 012c], ClientHello
    01 00 01 28 03 03 0d 9b 38 e7 53 ba e2 ba 5b f1
    11 23 57 2b 7b 18 e1 4a d7 2e 1c de d2 43 bb e6
    2d f5 ab 43 bd fa 00 00 aa c0 30 c0 2c c0 28 c0
    24 c0 14 c0 0a 00 a5 00 a3 00 a1 00 9f 00 6b 00
    6a 00 69 00 68 00 39 00 38 00 37 00 36 00 88 00
    87 00 86 00 85 c0 32 c0 2e c0 2a c0 26 c0 0f c0
    05 00 9d 00 3d 00 35 00 84 c0 2f c0 2b c0 27 c0
    23 c0 13 c0 88 00 a4 00 a2 00 a0 00 9e 00 67 00
    40 00 3f 00 3e 00 33 00 32 00 31 00 30 00 9a 00
    99 00 98 00 97 00 45 00 44 00 43 00 42 c0 31 c0
    2d c0 29 c0 25 c0 0e c0 04 00 9c 00 3c 00 2f 00
    96 00 41 c0 11 c0 07 c0 0c c0 02 00 05 00 04 c0
    12 c0 08 00 16 00 13 00 10 00 0d c0 0d c0 03 00
    0a 00 ff 01 00 00 55 00 0b 00 04 03 00 01 02 00
    0a 00 1c 00 1a 00 17 00 19 00 1c 00 1b 00 18 00
    1a 00 16 00 0e 00 0d 00 0b 00 0c 00 09 00 0a 00
    23 00 00 00 0d 00 20 00 1e 06 01 06 02 06 03 05
    01 05 02 05 03 04 01 04 02 04 03 03 01 03 02 03
    03 02 01 02 02 02 03 00 0f 00 01 01

<<< Here it gets stuck for about 2 minutes

I ran strace on the server app - during the handshake it tries to connect to 192.35.177.64 on port 80! This IP address belongs to a certificate authority (IdenTrust). The operation gets stuck (EINPROGRESS) because port 80 is not allowed for outbound connections on my server.

Output of strace:

ubuntu@ip-172-31-46-243:~$ sudo strace -fp 5546 -Tfte trace=network
strace: Process 5546 attached with 73 threads
[pid  5571] 16:16:53 accept4(196, NULL, NULL, SOCK_CLOEXEC|SOCK_NONBLOCK) = 537 <0.000033>
[pid  5571] 16:16:53 setsockopt(537, SOL_TCP, TCP_NODELAY, [1], 4) = 0 <0.000037>
[pid  5571] 16:16:53 getpeername(537, {sa_family=AF_INET, sin_port=htons(33460), sin_addr=inet_addr("<my-public-ip>")}, [16]) = 0 <0.000034>
[pid  5571] 16:16:53 getsockname(537, {sa_family=AF_INET, sin_port=htons(443), sin_addr=inet_addr("172.31.46.243")}, [16]) = 0 <0.000033>
[pid  5571] 16:16:53 accept4(196, NULL, NULL, SOCK_CLOEXEC|SOCK_NONBLOCK) = -1 EAGAIN (Resource temporarily unavailable) <0.000033>
strace: Process 5652 attached
[pid  5652] 16:16:53 socket(PF_INET, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 538 <0.000045>
[pid  5652] 16:16:53 connect(538, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("172.31.0.2")}, 16) = 0 <0.000032>
[pid  5652] 16:16:53 sendmmsg(538, {{{msg_name(0)=NULL, msg_iov(1)=[{"u\315\1\0\0\1\0\0\0\0\0\0\4apps\tidentrust\3com\0"..., 36}], msg_controllen=0, msg_flags=MSG_DONTROUTE|MSG_CTRUNC|MSG_EOR|MSG_WAITALL|MSG_FIN|MSG_SYN|MSG_NOSIGNAL|MSG_CMSG_CLOEXEC|0x13300010}, 36}, {{msg_name(0)=NULL, msg_iov(1)=[{"\21\215\1\0\0\1\0\0\0\0\0\0\4apps\tidentrust\3com\0"..., 36}], msg_controllen=0, msg_flags=MSG_EOR|MSG_WAITALL|MSG_RST|MSG_ERRQUEUE|MSG_MORE|MSG_CMSG_CLOEXEC|0x13680010}, 36}}, 2, MSG_NOSIGNAL) = 2 <0.000038>
[pid  5652] 16:16:53 recvfrom(538, "u\315\201\200\0\1\0\2\0\0\0\0\4apps\tidentrust\3com\0"..., 2048, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("172.31.0.2")}, [16]) = 83 <0.000033>
[pid  5652] 16:16:53 recvfrom(538, "\21\215\201\200\0\1\0\1\0\1\0\0\4apps\tidentrust\3com\0"..., 65536, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("172.31.0.2")}, [16]) = 115 <0.000039>
[pid  5652] 16:16:53 +++ exited with 0 +++
[pid  5627] 16:16:53 socket(PF_INET, SOCK_STREAM, IPPROTO_TCP) = 538 <0.000041>
[pid  5627] 16:16:53 connect(538, {sa_family=AF_INET, sin_port=htons(80), sin_addr=inet_addr("192.35.177.64")}, 16) = -1 EINPROGRESS (Operation now in progress) <0.000027>
strace: Process 5653 attached
strace: Process 5654 attached
strace: Process 5655 attached
[pid  5571] 16:17:15 accept4(196, NULL, NULL, SOCK_CLOEXEC|SOCK_NONBLOCK) = 539 <0.000085>
[pid  5571] 16:17:15 setsockopt(539, SOL_TCP, TCP_NODELAY, [1], 4) = 0 <0.000037>
[pid  5571] 16:17:15 getpeername(539, {sa_family=AF_INET, sin_port=htons(64433), sin_addr=inet_addr("52.39.142.198")}, [16]) = 0 <0.000041>
[pid  5571] 16:17:15 getsockname(539, {sa_family=AF_INET, sin_port=htons(443), sin_addr=inet_addr("172.31.46.243")}, [16]) = 0 <0.000040>
[pid  5571] 16:17:15 accept4(196, NULL, NULL, SOCK_CLOEXEC|SOCK_NONBLOCK) = -1 EAGAIN (Resource temporarily unavailable) <0.000040>
strace: Process 5659 attached
[pid  5659] 16:17:15 socket(PF_INET, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 540 <0.000039>
[pid  5659] 16:17:15 connect(540, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("172.31.0.2")}, 16) = 0 <0.000021>
[pid  5659] 16:17:15 sendmmsg(540, {{{msg_name(0)=NULL, msg_iov(1)=[{"\376\216\1\0\0\1\0\0\0\0\0\0\4apps\tidentrust\3com\0"..., 36}], msg_controllen=0, msg_flags=0}, 36}, {{msg_name(0)=NULL, msg_iov(1)=[{"~\25\1\0\0\1\0\0\0\0\0\0\4apps\tidentrust\3com\0"..., 36}], msg_controllen=0, msg_flags=0}, 36}}, 2, MSG_NOSIGNAL) = 2 <0.000034>
[pid  5659] 16:17:15 recvfrom(540, "\376\216\201\200\0\1\0\2\0\0\0\0\4apps\tidentrust\3com\0"..., 2048, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("172.31.0.2")}, [16]) = 83 <0.000047>
[pid  5659] 16:17:15 recvfrom(540, "~\25\201\200\0\1\0\1\0\1\0\0\4apps\tidentrust\3com\0"..., 65536, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("172.31.0.2")}, [16]) = 115 <0.000023>
[pid  5659] 16:17:15 +++ exited with 0 +++
[pid  5632] 16:17:15 socket(PF_INET, SOCK_STREAM, IPPROTO_TCP) = 540 <0.000029>
[pid  5632] 16:17:15 connect(540, {sa_family=AF_INET, sin_port=htons(80), sin_addr=inet_addr("192.35.177.64")}, 16) = -1 EINPROGRESS (Operation now in progress) <0.000028>
strace: Process 5660 attached
[pid  5571] 16:17:15 accept4(196, NULL, NULL, SOCK_CLOEXEC|SOCK_NONBLOCK) = 541 <0.000063>
[pid  5571] 16:17:15 setsockopt(541, SOL_TCP, TCP_NODELAY, [1], 4) = 0 <0.000037>
[pid  5571] 16:17:15 getpeername(541, {sa_family=AF_INET, sin_port=htons(64435), sin_addr=inet_addr("52.39.142.198")}, [16]) = 0 <0.000031>
[pid  5571] 16:17:15 getsockname(541, {sa_family=AF_INET, sin_port=htons(443), sin_addr=inet_addr("172.31.46.243")}, [16]) = 0 <0.000031>
[pid  5571] 16:17:15 accept4(196, NULL, NULL, SOCK_CLOEXEC|SOCK_NONBLOCK) = -1 EAGAIN (Resource temporarily unavailable) <0.000039>
strace: Process 5661 attached
[pid  5661] 16:17:15 socket(PF_INET, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 542 <0.000057>
[pid  5661] 16:17:15 connect(542, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("172.31.0.2")}, 16) = 0 <0.000053>
[pid  5661] 16:17:15 sendmmsg(542, {{{msg_name(0)=NULL, msg_iov(1)=[{"M\24\1\0\0\1\0\0\0\0\0\0\4apps\tidentrust\3com\0"..., 36}], msg_controllen=0, msg_flags=0}, 36}, {{msg_name(0)=NULL, msg_iov(1)=[{"\300\36\1\0\0\1\0\0\0\0\0\0\4apps\tidentrust\3com\0"..., 36}], msg_controllen=0, msg_flags=0}, 36}}, 2, MSG_NOSIGNAL) = 2 <0.000042>
[pid  5661] 16:17:15 recvfrom(542, "M\24\201\200\0\1\0\2\0\0\0\0\4apps\tidentrust\3com\0"..., 2048, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("172.31.0.2")}, [16]) = 83 <0.000058>
[pid  5661] 16:17:15 recvfrom(542, "\300\36\201\200\0\1\0\1\0\1\0\0\4apps\tidentrust\3com\0"..., 65536, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("172.31.0.2")}, [16]) = 115 <0.000042>
[pid  5661] 16:17:15 +++ exited with 0 +++
[pid  5622] 16:17:15 socket(PF_INET, SOCK_STREAM, IPPROTO_TCP) = 542 <0.000040>
[pid  5622] 16:17:15 connect(542, {sa_family=AF_INET, sin_port=htons(80), sin_addr=inet_addr("192.35.177.64")}, 16) = -1 EINPROGRESS (Operation now in progress) <0.000047>

Also tried to install the CA certificates (Let’s Encrypt Authority X3 and DST Root CA X3) in the OS using both .NET API and update-ca-certificates. Doesn’t help. (As described here: https://github.com/dotnet/corefx/issues/16879)

Opening port 80 (outbound) solves the issue and the handshake completes successfully. Is there a way to do a TLS handshake on Linux without allowing outbound connections on http port 80?

About this issue

Original URL
State: closed
Created 7 years ago
Reactions: 2
Comments: 47 (44 by maintainers)

Most upvoted comments

Even more minimal reproduction, use with the attached certificate.

            var cert = new X509Certificate2("test.pfx");
            var chain = new X509Chain();
            chain.ChainPolicy.VerificationFlags = X509VerificationFlags.AllFlags;
            chain.ChainPolicy.RevocationFlag = X509RevocationFlag.ExcludeRoot;
            chain.ChainPolicy.RevocationMode = X509RevocationMode.NoCheck;
            Console.WriteLine(chain.Build(cert));

The root cause here is the following:

   X509v3 extensions:
            X509v3 Authority Key Identifier: 
                keyid:2C:42:A9:B8:45:2C:11:BB:57:25:40:FC:9D:8E:46:18:6D:FD:54:27

            Authority Information Access: 
                CA Issuers - URI:http://example.com/go-away

cert.zip

In particular, this seems to be related to this code: https://github.com/dotnet/corefx/blob/0101324f1ac8555c910bbbfb46c511bb86f0fbe4/src/System.Security.Cryptography.X509Certificates/src/Internal/Cryptography/Pal.Unix/OpenSslX509ChainProcessor.cs#L536-L561

In other words, if there is an authority information access with a URL, the act of building a X509Chain would force it to be hit, and it can take multiple minutes to resolve if this is not accessible.

The code seems to hint that there is some timeout there, controlled by UrlRetrievalTimeout, but I can’t see where this is actually being set, in particular, this should be set to zero:

https://github.com/dotnet/corefx/blob/0101324f1ac8555c910bbbfb46c511bb86f0fbe4/src/System.Security.Cryptography.X509Certificates/src/System/Security/Cryptography/X509Certificates/X509Chain.cs#L127

But even calling chain.ChainPolicy.UrlRetrievalTimeout = TimeSpan.Zero; is bad for us, because:

https://github.com/dotnet/corefx/blob/0101324f1ac8555c910bbbfb46c511bb86f0fbe4/src/System.Security.Cryptography.X509Certificates/src/Internal/Cryptography/Pal.Unix/ChainPal.cs#L37

I was able to get it working fast by setting the timeout to a negative value, which is good. However, there is no way to inject this behavior here:

https://github.com/dotnet/corefx/blob/0101324f1ac8555c910bbbfb46c511bb86f0fbe4/src/Common/src/System/Net/Http/TlsCertificateExtensions.cs#L78

Where this is actually happening whenever you use an SslStream that will get called and effectively hang us.

Note that even with port 80 being open, this includes the cost of a remote call on every SSL connection being made when using a server.

[EDIT] Add C# sytnax highlighting by @karelz

ayende on Dec 29, 2017