[WinHttp] Manual_CertificateOnlySentWhenValid_Success fails with WINHTTP_CALLBACK_STATUS_REQUEST_ERROR in rolling CI

[jakobbotsch]

Edit by @antonfirsov: It's not clear if this is an environmental problem, some transient issue with the certificate or an actual issue with WinHttp. See #69238 (comment)

---

Failures with WINHTTP_CALLBACK_STATUS_REQUEST_ERROR: 3/27-7/31 (incl. PRs)

Day	Run	OS	Notes
7/29	PR #72851	Win10	4 failures
7/26	PR #72882	Win10	4 failures
7/26	PR #72394	Win10	4 failures
7/25	PR #72814	Win10	4 failures
7/15	PR #71385	Windows various	108 failures - likely caused by the PR itself
6/30	PR #71405	Win10	4 failures (HTTP 1.1 and HTTP/2)
6/17	PR #70869	Win10	4 failures (HTTP 1.1 and HTTP/2)
6/17	PR #70063	Win10	8 failures
6/16	PR #66304	Win10	4 failures
6/7	PR #70309	Win10	4 failures
6/7	Official run	Win10	4 failures
6/3	PR #70217	Win10	4 failures
6/3	PR #70179	Win10	4 failures
6/3	PR #70186	Win10	4 failures
5/29	PR #69957	Win10	4 failures
5/11	Official run	Win10	4 failures
5/11	PR #62552	Win10	4 failures

Pipeline run: https://dev.azure.com/dnceng/public/_build/results?buildId=1765644&view=results
Job: Libraries Test Run release coreclr windows x64 release
Several test failures in certificate related tests.
Example log: https://helixre8s23ayyeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-heads-main-c43ba61f702b496b92/System.Net.Http.WinHttpHandler.Functional.Tests/3/console.2d1bb445.log?helixlogtype=result

System.Net.Http.Functional.Tests.PlatformHandler_HttpClientHandler_ClientCertificates_Test.Manual_CertificateOnlySentWhenValid_Success(certIndex: 1, serverExpectsClientCertificate: True) [FAIL]
      System.AggregateException : One or more errors occurred. (An error occurred while sending the request.) ( Received an unexpected EOF or 0 bytes from the transport stream.)
      ---- System.Net.Http.HttpRequestException : An error occurred while sending the request.
      -------- System.Net.Http.WinHttpException : Error 12175 calling WINHTTP_CALLBACK_STATUS_REQUEST_ERROR, 'Error de seguridad'.
      ---- System.IO.IOException :  Received an unexpected EOF or 0 bytes from the transport stream.
      Stack Trace:
        /_/src/libraries/Common/tests/System/Threading/Tasks/TaskTimeoutExtensions.cs(88,0): at System.Threading.Tasks.TaskTimeoutExtensions.WhenAllOrAnyFailed(Task[] tasks)
        /_/src/libraries/Common/tests/System/Threading/Tasks/TaskTimeoutExtensions.cs(55,0): at System.Threading.Tasks.TaskTimeoutExtensions.WhenAllOrAnyFailed(Task[] tasks, Int32 millisecondsTimeout)
        /_/src/libraries/Common/tests/System/Net/Http/HttpClientHandlerTest.ClientCertificates.cs(106,0): at System.Net.Http.Functional.Tests.HttpClientHandler_ClientCertificates_Test.<>c__DisplayClass6_0.<<Manual_CertificateOnlySentWhenValid_Success>b__1>d.MoveNext()
        --- End of stack trace from previous location ---
        /_/src/libraries/Common/tests/System/Net/Http/LoopbackServer.cs(101,0): at System.Net.Test.Common.LoopbackServer.CreateServerAsync(Func`2 funcAsync, Options options)
        /_/src/libraries/Common/tests/System/Net/Http/HttpClientHandlerTest.ClientCertificates.cs(101,0): at System.Net.Http.Functional.Tests.HttpClientHandler_ClientCertificates_Test.Manual_CertificateOnlySentWhenValid_Success(Int32 certIndex, Boolean serverExpectsClientCertificate)
        --- End of stack trace from previous location ---
        ----- Inner Stack Trace #1 (System.Net.Http.HttpRequestException) -----
        /_/src/libraries/System.Net.Http/src/System/Net/Http/HttpClient.cs(190,0): at System.Net.Http.HttpClient.GetStringAsyncCore(HttpRequestMessage request, CancellationToken cancellationToken)
        /_/src/libraries/Common/tests/System/Threading/Tasks/TaskTimeoutExtensions.cs(120,0): at System.Threading.Tasks.TaskTimeoutExtensions.GetRealException(Task task)
        ----- Inner Stack Trace -----
        /_/src/libraries/Common/src/System/Threading/Tasks/RendezvousAwaitable.cs(64,0): at System.Threading.Tasks.RendezvousAwaitable`1.GetResult()
        /_/src/libraries/System.Net.Http.WinHttpHandler/src/System/Net/Http/WinHttpHandler.cs(957,0): at System.Net.Http.WinHttpHandler.StartRequestAsync(WinHttpRequestState state)
        ----- Inner Stack Trace #2 (System.IO.IOException) -----
        /_/src/libraries/System.Net.Security/src/System/Net/Security/SslStream.IO.cs(366,0): at System.Net.Security.SslStream.ReceiveBlobAsync[TIOAdapter](CancellationToken cancellationToken)
        /_/src/libraries/System.Net.Security/src/System/Net/Security/SslStream.IO.cs(289,0): at System.Net.Security.SslStream.ForceAuthenticationAsync[TIOAdapter](Boolean receiveFirst, Byte[] reAuthenticationData, CancellationToken cancellationToken)
        /_/src/libraries/Common/tests/System/Net/Http/LoopbackServer.cs(476,0): at System.Net.Test.Common.LoopbackServer.Connection.CreateAsync(SocketWrapper socket, Stream stream, Options httpOptions)
        /_/src/libraries/Common/tests/System/Net/Http/LoopbackServer.cs(148,0): at System.Net.Test.Common.LoopbackServer.EstablishConnectionAsync()
        /_/src/libraries/Common/tests/System/Net/Http/LoopbackServer.cs(159,0): at System.Net.Test.Common.LoopbackServer.AcceptConnectionAsync(Func`2 funcAsync)
        /_/src/libraries/Common/tests/System/Threading/Tasks/TaskTimeoutExtensions.cs(120,0): at System.Threading.Tasks.TaskTimeoutExtensions.GetRealException(Task task)

let failedTests = (methodName : string, includePR : bool, messageSubstr: string, includePassedOnRerun : bool) {
cluster('engsrvprod.kusto.windows.net').database('engineeringdata').AzureDevOpsTests
    | where TestName startswith "System.Net" 
    | where includePassedOnRerun or (Outcome == 'Failed')
    | extend startOfTestName = indexof_regex(TestName, @"[^.]+$")
    | extend Method = substring(TestName, startOfTestName)
    | extend Type = substring(TestName, 0, startOfTestName - 1)
    | project-away startOfTestName
    | where Method == methodName
    | where Message contains messageSubstr
    | distinct JobId, WorkItemId, Message, StackTrace, Method, Type, Arguments, Outcome
    | join kind=inner (cluster('engsrvprod.kusto.windows.net').database('engineeringdata').Jobs
        | where ((Branch == 'refs/heads/main') or (Branch == 'refs/heads/master') or (includePR and (Source startswith "pr/")))
        | where Type startswith "test/functional/cli/"
            and not(Properties contains "runtime-staging")
        | summarize arg_max(Finished, Properties, Type, Branch, Source, Started, QueueName) by JobId
        | project-rename JobType = Type) on JobId
    | extend PropertiesJson = parse_json(Properties)
    | extend OS = replace_regex(tostring(PropertiesJson.operatingSystem), @'\((.*)\).*|([^\(].*)', @'\1\2')
    | extend Runtime = iif(PropertiesJson.runtimeFlavor == "mono", "Mono", iif(PropertiesJson.DefinitionName contains "coreclr", "CoreCLR", ""))
    | extend TargetBranch = extractjson("$.['System.PullRequest.TargetBranch']", Properties)
    | extend Architecture = PropertiesJson.architecture
    | extend Scenario = iif(isempty(PropertiesJson.scenario), "--", PropertiesJson.scenario)
    //| extend DefinitionName = PropertiesJson.DefinitionName
    | project-away PropertiesJson
};
failedTests('Manual_CertificateOnlySentWhenValid_Success', true, 'WINHTTP_CALLBACK_STATUS_REQUEST_ERROR', true);

[ghost]

Tagging subscribers to this area: @dotnet/ncl
See info in area-owners.md if you want to be subscribed.

Issue Details

---

Pipeline run: https://dev.azure.com/dnceng/public/_build/results?buildId=1765644&view=results
Job: Libraries Test Run release coreclr windows x64 release
Several test failures in certificate related tests.
Example log: https://helixre8s23ayyeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-heads-main-c43ba61f702b496b92/System.Net.Http.WinHttpHandler.Functional.Tests/3/console.2d1bb445.log?helixlogtype=result

    System.Net.Http.Functional.Tests.PlatformHandler_HttpClientHandler_ClientCertificates_Test.Manual_CertificateOnlySentWhenValid_Success(certIndex: 1, serverExpectsClientCertificate: True) [FAIL]
      System.AggregateException : One or more errors occurred. (An error occurred while sending the request.) ( Received an unexpected EOF or 0 bytes from the transport stream.)
      ---- System.Net.Http.HttpRequestException : An error occurred while sending the request.
      -------- System.Net.Http.WinHttpException : Error 12175 calling WINHTTP_CALLBACK_STATUS_REQUEST_ERROR, 'Error de seguridad'.
      ---- System.IO.IOException :  Received an unexpected EOF or 0 bytes from the transport stream.
      Stack Trace:
        /_/src/libraries/Common/tests/System/Threading/Tasks/TaskTimeoutExtensions.cs(88,0): at System.Threading.Tasks.TaskTimeoutExtensions.WhenAllOrAnyFailed(Task[] tasks)
        /_/src/libraries/Common/tests/System/Threading/Tasks/TaskTimeoutExtensions.cs(55,0): at System.Threading.Tasks.TaskTimeoutExtensions.WhenAllOrAnyFailed(Task[] tasks, Int32 millisecondsTimeout)
        /_/src/libraries/Common/tests/System/Net/Http/HttpClientHandlerTest.ClientCertificates.cs(106,0): at System.Net.Http.Functional.Tests.HttpClientHandler_ClientCertificates_Test.<>c__DisplayClass6_0.<<Manual_CertificateOnlySentWhenValid_Success>b__1>d.MoveNext()
        --- End of stack trace from previous location ---
        /_/src/libraries/Common/tests/System/Net/Http/LoopbackServer.cs(101,0): at System.Net.Test.Common.LoopbackServer.CreateServerAsync(Func`2 funcAsync, Options options)
        /_/src/libraries/Common/tests/System/Net/Http/HttpClientHandlerTest.ClientCertificates.cs(101,0): at System.Net.Http.Functional.Tests.HttpClientHandler_ClientCertificates_Test.Manual_CertificateOnlySentWhenValid_Success(Int32 certIndex, Boolean serverExpectsClientCertificate)
        --- End of stack trace from previous location ---
        ----- Inner Stack Trace #1 (System.Net.Http.HttpRequestException) -----
        /_/src/libraries/System.Net.Http/src/System/Net/Http/HttpClient.cs(190,0): at System.Net.Http.HttpClient.GetStringAsyncCore(HttpRequestMessage request, CancellationToken cancellationToken)
        /_/src/libraries/Common/tests/System/Threading/Tasks/TaskTimeoutExtensions.cs(120,0): at System.Threading.Tasks.TaskTimeoutExtensions.GetRealException(Task task)
        ----- Inner Stack Trace -----
        /_/src/libraries/Common/src/System/Threading/Tasks/RendezvousAwaitable.cs(64,0): at System.Threading.Tasks.RendezvousAwaitable`1.GetResult()
        /_/src/libraries/System.Net.Http.WinHttpHandler/src/System/Net/Http/WinHttpHandler.cs(957,0): at System.Net.Http.WinHttpHandler.StartRequestAsync(WinHttpRequestState state)
        ----- Inner Stack Trace #2 (System.IO.IOException) -----
        /_/src/libraries/System.Net.Security/src/System/Net/Security/SslStream.IO.cs(366,0): at System.Net.Security.SslStream.ReceiveBlobAsync[TIOAdapter](CancellationToken cancellationToken)
        /_/src/libraries/System.Net.Security/src/System/Net/Security/SslStream.IO.cs(289,0): at System.Net.Security.SslStream.ForceAuthenticationAsync[TIOAdapter](Boolean receiveFirst, Byte[] reAuthenticationData, CancellationToken cancellationToken)
        /_/src/libraries/Common/tests/System/Net/Http/LoopbackServer.cs(476,0): at System.Net.Test.Common.LoopbackServer.Connection.CreateAsync(SocketWrapper socket, Stream stream, Options httpOptions)
        /_/src/libraries/Common/tests/System/Net/Http/LoopbackServer.cs(148,0): at System.Net.Test.Common.LoopbackServer.EstablishConnectionAsync()
        /_/src/libraries/Common/tests/System/Net/Http/LoopbackServer.cs(159,0): at System.Net.Test.Common.LoopbackServer.AcceptConnectionAsync(Func`2 funcAsync)
        /_/src/libraries/Common/tests/System/Threading/Tasks/TaskTimeoutExtensions.cs(120,0): at System.Threading.Tasks.TaskTimeoutExtensions.GetRealException(Task task)

Author:	jakobbotsch
Assignees:	-
Labels:	area-System.Net.Http
Milestone:	-

[antonfirsov]

Triage: we should look into in 7.0 timeframe

[danmoseley]

Hit in #72882

[antonfirsov]

Triage:

• According to google search results, and past reports like Error 12175 calling WINHTTP_CALLBACK_STATUS_REQUEST_ERROR, 'A security error occurred #33509, people are hitting this issue out in the wild. It might make sense to investigate it.
• Error 12175 is ERROR_WINHTTP_SECURE_FAILURE. It might be an environmental error, some transient issue with the certificate or an actual WinHttp issue, hard to tell.
• The logs are hardly actionable. We may need to grab a machine where it repros more reliably, or enhance our error information by also querying WINHTTP_CALLBACK_STATUS_SECURE_FAILURE in the status callback as recommended by the WinHttp error docs.

Regardless, this is not critical for 7.0, disabling the test in #73378, and moving to Future.