Assertion in certificate validation code when talking to HTTP2 remote server on Linux

[geoffkizer]

The way we have been running HTTP2 tests against remote servers has meant that certificate validation is always disabled. I am making test changes in dotnet/corefx#39343 that re-enable this, and now we're seeing an assert in the cert validation code on every Linux distro except for RedHat.

Process terminated. Assertion failed.
Unrecognized X509VerifyStatusCode:44
   at Internal.Cryptography.Pal.OpenSslX509ChainProcessor.MapVerifyErrorToChainStatus(X509VerifyStatusCode code) in /_/src/System.Security.Cryptography.X509Certificates/src/Internal/Cryptography/Pal.Unix/OpenSslX509ChainProcessor.cs:line 819
   at Internal.Cryptography.Pal.OpenSslX509ChainProcessor.AddElementStatus(X509VerifyStatusCode errorCode, List`1 elementStatus, List`1 overallStatus) in /_/src/System.Security.Cryptography.X509Certificates/src/Internal/Cryptography/Pal.Unix/OpenSslX509ChainProcessor.cs:line 703
   at Internal.Cryptography.Pal.OpenSslX509ChainProcessor.AddElementStatus(ErrorCollection errorCodes, List`1 elementStatus, List`1 overallStatus) in /_/src/System.Security.Cryptography.X509Certificates/src/Internal/Cryptography/Pal.Unix/OpenSslX509ChainProcessor.cs:line 694
   at Internal.Cryptography.Pal.OpenSslX509ChainProcessor.BuildChainElements(WorkingChain workingChain, List`1& overallStatus) in /_/src/System.Security.Cryptography.X509Certificates/src/Internal/Cryptography/Pal.Unix/OpenSslX509ChainProcessor.cs:line 599
   at Internal.Cryptography.Pal.OpenSslX509ChainProcessor.Finish(OidCollection applicationPolicy, OidCollection certificatePolicy) in /_/src/System.Security.Cryptography.X509Certificates/src/Internal/Cryptography/Pal.Unix/OpenSslX509ChainProcessor.cs:line 393
   at Internal.Cryptography.Pal.ChainPal.BuildChain(Boolean useMachineContext, ICertificatePal cert, X509Certificate2Collection extraStore, OidCollection applicationPolicy, OidCollection certificatePolicy, X509RevocationMode revocationMode, X509RevocationFlag revocationFlag, DateTime verificationTime, TimeSpan timeout) in /_/src/System.Security.Cryptography.X509Certificates/src/Internal/Cryptography/Pal.Unix/ChainPal.cs:line 99
   at System.Security.Cryptography.X509Certificates.X509Chain.Build(X509Certificate2 certificate, Boolean throwOnException) in /_/src/System.Security.Cryptography.X509Certificates/src/System/Security/Cryptography/X509Certificates/X509Chain.cs:line 118
   at System.Security.Cryptography.X509Certificates.X509Chain.Build(X509Certificate2 certificate) in /_/src/System.Security.Cryptography.X509Certificates/src/System/Security/Cryptography/X509Certificates/X509Chain.cs:line 105
   at System.Net.Security.CertificateValidation.BuildChainAndVerifyProperties(X509Chain chain, X509Certificate2 remoteCertificate, Boolean checkCertName, String hostName) in /_/src/Common/src/System/Net/Security/CertificateValidation.Unix.cs:line 18
   at System.Net.CertificateValidationPal.VerifyCertificateProperties(SafeDeleteContext securityContext, X509Chain chain, X509Certificate2 remoteCertificate, Boolean checkCertName, Boolean isServer, String hostName) in /_/src/System.Net.Security/src/System/Net/CertificateValidationPal.Unix.cs:line 22
   at System.Net.Security.SecureChannel.VerifyRemoteCertificate(RemoteCertValidationCallback remoteCertValidationCallback, ProtocolToken& alertToken) in /_/src/System.Net.Security/src/System/Net/Security/SecureChannel.cs:line 1010
   at System.Net.Security.SslStream.CompleteHandshake(ProtocolToken& alertToken) in /_/src/System.Net.Security/src/System/Net/Security/SslStream.Implementation.cs:line 754

Additional details in dotnet/corefx#39343

[bartonjs]

Looks like we have a mapping for 43 codes (https://github.com/dotnet/corefx/blob/6c6d68558aaccbd16de6e84cf7e59c0fb32b8273/src/Common/src/Interop/Unix/System.Security.Cryptography.Native/Interop.X509.cs#L242-L281) and OpenSSL is now up to 77.
Obviously we should map in the missing 44 codes so this doesn't surprise us.

This one (44) is X509_V_ERR_DIFFERENT_CRL_SCOPE, which seems weird... perhaps it's a subcode of X509_V_ERR_UNABLE_TO_GET_CRL... or something else weird is going on.

@geoffkizer Can you easily identify which cert was being used to help me see what's actually going on with this chain?

[geoffkizer]

Can you easily identify which cert was being used to help me see what's actually going on with this chain?

How do I do that?

The server is https://corefx-net-http2.azurewebsites.net, if that helps...

[bartonjs]

I ran the tests (without the "disable this check" commit) on my Ubuntu 18.04 machine, confirmed it's loading OpenSSL 1.1.0 (which added codes 44-72), and don't get a repro.

That was with ../../../../.dotnet/dotnet msbuild /t:BuildAndTest from System.Net.Http/tests/FunctionalTests, in case I'm not actually trying the right thing...

[geoffkizer]

Run them with /p:Outerloop=true

[bartonjs]

Oh, yep, that did it.

[geoffkizer]

Can you tell which test this is happening during?

[bartonjs]

Not yet. I removed the assert expecting the CryptographicException after it to be thrown, but only one test failed then (it claimed it was cancelled, IIRC?). I changed it to a PNSE to see if that would light things up, but had to leave before I could see the results.

[wfurt]

note, that most Linux images now run as container. It should be trivial to get exactly same image (get tag from eng/pipelines/linux.yml)

[geoffkizer]

I removed the assert expecting the CryptographicException after it to be thrown, but only one test failed then (it claimed it was cancelled, IIRC?).

It could be that the exception just isn't getting surfaced, and then the test is hanging until the HttpClient default timeout kicks in, which is why it's reported as a cancellation. We see this fairly often with test issues with async code.

If you can tell me which test it is that's timing out and getting cancelled, that should help narrow things down.

[bartonjs]

    System.Net.Http.Functional.Tests.SocketsHttpHandlerTest_Http2.SendAsync_ConcurentSendReceive_Fail [FAIL]
      System.TimeoutException : WhenAllOrAnyFailed timed out after 60000ms
      Stack Trace:
        /home/jbarton/git/bartonjs/corefx/src/Common/tests/System/Threading/Tasks/TaskTimeoutExtensions.cs(75,0): at System.Threading.Tasks.TaskTimeoutExtensions.WhenAllOrAnyFailed(Task[] tasks, Int32 millisecondsTimeout)
        /home/jbarton/git/bartonjs/corefx/src/Common/tests/System/Net/Http/Http2LoopbackServer.cs(186,0): at System.Net.Test.Common.Http2LoopbackServer.CreateClientAndServerAsync(Func`2 clientFunc, Func`2 serverFunc, Int32 timeout)
        /home/jbarton/git/bartonjs/corefx/src/System.Net.Http/tests/FunctionalTests/HttpClientHandlerTest.Http2.cs(1941,0): at System.Net.Http.Functional.Tests.HttpClientHandlerTest_Http2.SendAsync_ConcurentSendReceive_Fail()
        --- End of stack trace from previous location where exception was thrown ---

was the only failure with a CryptographicException.

None failed when it was a PlatformNotSupportedException.

[geoffkizer]

That is very strange. You may be seeing an unrelated timeout issue.

Do you have a PR for the fix to not assert? That would at least help me diagnose this.

[bartonjs]

Yay, caught it (one?) with -parallel none -verbose:

    System.Net.Http.Functional.Tests.SocketsHttpHandler_HttpClientHandler_ServerCertificates_Test.NoCallback_RevokedCertificate_RevocationChecking_Fails [STARTING]
Process terminated. Assertion failed.
Unrecognized X509VerifyStatusCode:44
   at Internal.Cryptography.Pal.OpenSslX509ChainProcessor.MapVerifyErrorToChainStatus(X509VerifyStatusCode code) in /home/jbarton/git/bartonjs/corefx/src/System.Security.Cryptography.X509Certificates/src/Internal/Cryptography/Pal.Unix/OpenSslX509ChainProcessor.cs:line 819

Commenting out the assert in OpenSslX509ChainProcessor.cs lets the tests finish, but it shouldn't be checked in that way.

[bartonjs]

And then I wiped out my CRL cache and ran the test and it passed; so now I get to let the repro try to come back. Sigh.

[bartonjs]

Okay, now I understand the problem.

• revoked.badssl.com offers up a certificate.
• This certificate says that the CRL can be downloaded from one of two places: 1) http://crl3.digicert.com/ssca-sha2-g5.crl 2) http://crl4.digicert.com/ssca-sha2-g5.crl.
• We load the CRL from our CRL cache based on the CA name
• The CRL from the cache says "I should have been published at http://crl3.digicert.com/ssca-sha2-g6.crl"
• g5 != g6
• Error 44.

This happens because some other cert that we got from DigiCert indiciated that it wanted the CRL to be downloaded from g6. I don't know if this is that DigiCert has two different CAs running with the same name, or just that they rolled over to a new CDP (g6 is at iteration 619, g5 is on 1344).

Their CRLs don't end in the same data, so they aren't keeping them in sync, so that is actually indicating that our caching logic does have a problem.

My new understanding is thanks to the BBC: https://www.bbc.co.uk/blogs/internet/entries/42d52ca4-5f48-450e-aec4-3fc8e6296929