[Test Failure] System.Net.Http.WinHttpHandlerFunctional.Tests.WinHttpHandlerTest.SendAsync_SlowServerRespondsAfterDefaultReceiveTimeout_ThrowsHttpRequestException

[rzikm]

Build Information

Build: https://dev.azure.com/dnceng-public/public/_build/results?buildId=715461
Build error leg or test failing: System.Net.Http.WinHttpHandlerFunctional.Tests.WinHttpHandlerTest.SendAsync_SlowServerRespondsAfterDefaultReceiveTimeout_ThrowsHttpRequestException

Error Message

Fill the error message using step by step known issues guidance.

{
  "ErrorMessage": [ "System.Net.Http.WinHttpHandlerFunctional.Tests.WinHttpHandlerTest.SendAsync_SlowServerRespondsAfterDefaultReceiveTimeout_ThrowsHttpRequestException [FAIL]", "Error 12152 calling WINHTTP_CALLBACK_STATUS_REQUEST_ERROR"],
  "BuildRetry": false,
  "ExcludeConsoleLog": false
}

Known issue validation

Build: 🔎 https://dev.azure.com/dnceng-public/public/_build/results?buildId=715461
Error message validated: [System.Net.Http.WinHttpHandlerFunctional.Tests.WinHttpHandlerTest.SendAsync_SlowServerRespondsAfterDefaultReceiveTimeout_ThrowsHttpRequestException [FAIL] Error 12152 calling WINHTTP_CALLBACK_STATUS_REQUEST_ERROR]
Result validation: ✅ Known issue matched with the provided build.
Validation performed at: 6/25/2024 3:32:56 PM UTC

Report

Build	Definition	Test	Pull Request
715461	dotnet/runtime	System.Net.Http.WinHttpHandlerFunctional.Tests.WinHttpHandlerTest.SendAsync_SlowServerRespondsAfterDefaultReceiveTimeout_ThrowsHttpRequestException

Summary

24-Hour Hit Count	7-Day Hit Count	1-Month Count
0	0	1

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

Issue Details

---

Build Information

Build: https://dev.azure.com/dnceng-public/public/_build/results?buildId=510958
Build error leg or test failing: System.Net.Http.WinHttpHandlerFunctional.Tests.WinHttpHandlerTest.SendAsync_SlowServerRespondsAfterDefaultReceiveTimeout_ThrowsHttpRequestException

Error Message

Fill the error message using step by step known issues guidance.

{
  "ErrorMessage": "System.Net.Http.WinHttpHandlerFunctional.Tests.WinHttpHandlerTest.SendAsync_SlowServerRespondsAfterDefaultReceiveTimeout_ThrowsHttpRequestException [FAIL]",
  "BuildRetry": false,
  "ExcludeConsoleLog": false
}

Author:	rzikm
Assignees:	-
Labels:	area-System.Net.Http, blocking-clean-ci, untriaged, Known Build Error
Milestone:	-

[rzikm]

The known issue does not seem to get matched, but it should IMO.

The failure log can be found via

https://dev.azure.com/dnceng-public/public/_build/results?buildId=511527&view=logs&j=2686528b-6bb9-52cf-c87c-9a2bbdff7996&t=5c32730d-9d2b-5d94-bfff-01026160003a

Sent Helix Job; see work items at https://helix.dot.net/api/jobs/cfed76aa-4fff-41c4-bd4c-e2fff1898339/workitems?api-version=2019-06-17

    {
        "DetailsUrl": "https://helix.dot.net/api/jobs/cfed76aa-4fff-41c4-bd4c-e2fff1898339/workitems/System.Net.Http.WinHttpHandler.Functional.Tests?api-version=2019-06-17",
        "Job": "cfed76aa-4fff-41c4-bd4c-e2fff1898339",
        "Name": "System.Net.Http.WinHttpHandler.Functional.Tests",
        "State": "Finished"
    },

In the DetailsUrl, there is

"ConsoleOutputUri": "https://helixre107v0xdcypoyl9e7f.blob.core.windows.net/dotnet-runtime-refs-heads-main-cfed76aa4fff41c4bd/System.Net.Http.WinHttpHandler.Functional.Tests/3/console.2f0f7f31.log?helixlogtype=result",

which contains the failure.

@dotnet/dnceng does the Known Issues infrastructure fall under your team? Can you please take a look? If not, do you know who maintains the Known Issues?

[ilyas1974]

@AlitzelMendez can you take a look at this, please?

[AlitzelMendez]

Hi @rzikm,
Could you please share with me to which test is that log entitled?

For context, for known issues we review two things:

• the build logs
• the tests reported to azdo (including the helix logs of those tests)

the first link that you shared for the build doesn't have the error: https://dev.azure.com/dnceng-public/public/_build/results?buildId=511527&view=logs&j=2686528b-6bb9-52cf-c87c-9a2bbdff7996&t=5c32730d-9d2b-5d94-bfff-01026160003a

and the second link doesn't seem to be entitled to any test reported to azdo, when I mention test I am referring to the ones in this tab: https://dev.azure.com/dnceng-public/public/_build/results?buildId=511527&view=ms.vss-test-web.build-test-results-tab

Additionally if your link is just mentioned in the build log or any log, we don't parse that log looking for links pointing to other logs, we just analyze the log as a text comparing it with the error message.

[rzikm]

Hi @rzikm, Could you please share with me to which test is that log entitled?

The test is System.Net.Http.WinHttpHandlerFunctional.Tests.WinHttpHandlerTest.SendAsync_SlowServerRespondsAfterDefaultReceiveTimeout_ThrowsHttpRequestException

For context, for known issues we review two things:

• the build logs
• the tests reported to azdo (including the helix logs of those tests)

the first link that you shared for the build doesn't have the error: https://dev.azure.com/dnceng-public/public/_build/results?buildId=511527&view=logs&j=2686528b-6bb9-52cf-c87c-9a2bbdff7996&t=5c32730d-9d2b-5d94-bfff-01026160003a

and the second link doesn't seem to be entitled to any test reported to azdo, when I mention test I am referring to the ones in this tab: https://dev.azure.com/dnceng-public/public/_build/results?buildId=511527&view=ms.vss-test-web.build-test-results-tab

Additionally if your link is just mentioned in the build log or any log, we don't parse that log looking for links pointing to other logs, we just analyze the log as a text comparing it with the error message.

Let's have a look at it from a different perspective. I am monitoring frequently failing tests using the cluster('engsrvprod.kusto.windows.net').database('engineeringdata').AzureDevOpsTests table. Following query

Kusto Query

cluster('engsrvprod.kusto.windows.net').database('engineeringdata').AzureDevOpsTests
    | where TestName has 'SendAsync_SlowServerRespondsAfterDefaultReceiveTimeout_ThrowsHttpRequestException'
    | where Outcome == 'Failed' // or Outcome == 'PassedOnRerun'
    | distinct JobId, WorkItemId, Message, StackTrace, TestName, Arguments, Outcome
    | join kind=inner (cluster('engsrvprod.kusto.windows.net').database('engineeringdata').Jobs
        | where Finished > now(-14d)
        | extend TargetBranch = extractjson("$.['System.PullRequest.TargetBranch']", Properties)
        | where (Branch == 'refs/heads/main') or (Source startswith "pr/" and TargetBranch == 'main')
        | summarize arg_max(JobName=Name, Finished, Properties, Type, Branch, Source, Started, QueueName, Attempt, Build, TargetBranch) 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 Architecture = PropertiesJson.architecture
    | extend DefinitionName = PropertiesJson.DefinitionName
    | project-away JobId
    | extend BuildId = extractjson("$.['BuildId']", Properties)
    | join kind=inner (cluster('engsrvprod.kusto.windows.net').database('engineeringdata').WorkItems
        | project-keep ConsoleUri, WorkItemId) on WorkItemId
    | project-away PropertiesJson
    | project-reorder Started, TestName, ConsoleUri, BuildId, JobName, OS, Architecture, DefinitionName, Branch, TargetBranch, Attempt, Build//, * 
;

The query returns, among others, failures occuring connected to build 511527

The associated Console output link is https://helixre107v0xdcypoyl9e7f.blob.core.windows.net/dotnet-runtime-refs-heads-main-cfed76aa4fff41c4bd/System.Net.Http.WinHttpHandler.Functional.Tests/3/console.2f0f7f31.log?helixlogtype=result and the associated failure is indeed mentioned in the output

System.Net.Http.WinHttpHandlerFunctional.Tests.WinHttpHandlerTest.SendAsync_SlowServerRespondsAfterDefaultReceiveTimeout_ThrowsHttpRequestException [FAIL]
      Assert.IsType() Failure: Value is not the exact type
      Expected: typeof(System.IO.IOException)
      Actual:   typeof(System.Net.Http.WinHttpException)

So my assumption is that if I file a Known Build error against this build and test, it should match correctly. Or am I missing something?

[CarnaViire]

Triage: this is an Outerloop test that fails quite regularly for Windows.Nano.1809.Amd64.Open (I've also seen one occurrence for Windows.Amd64.Server2022.Open on 2023-10-11).

17 failures in the past 30 days (2023-12-06 to 2024-01-05).
First occurrence on 2023-10-07.

We need to investigate in 9.0.

[AlitzelMendez]

could you please share with me a link to the test in AzDO?

as I mentioned it needs to be a test that appears on the AzDO tab, we don't parse the log, so if it is just mentioned and not reported back to AzDO we will not review it

we don't pull the test (helix work items) for our kusto tables, we ask AzDO to return all the tests ran in that build, AzDO returns all the test that are on https://dev.azure.com/dnceng-public/public/_build/results?buildId=511527&view=ms.vss-test-web.build-test-results-tab and we analyze those tests, if the test is not in there we won't analyze that log

[rzikm]

I see, AzDO seems to report entire work items as failed and not individual failed tests. I think we have recently run into this similar issue in #95898 (comment). @carlossanlop Could this be the same problem?