RequestDuration_EnrichmentHandler_Success_Recorded fails with System.Net.Quic.QuicException : Stream aborted by peer #93250

ericstj · 2023-10-09T19:14:53Z

Build Information

Build: https://dev.azure.com/dnceng-public/cbb18261-c48f-4abb-8651-8cdcb5474649/_build/results?buildId=429885
Build error leg or test failing: System.Net.Http.Functional.Tests.HttpMetricsTest_Http30.RequestDuration_EnrichmentHandler_Success_Recorded
Pull request: #93120

Error Message

{
  "ErrorMessage": "RequestDuration_EnrichmentHandler_Success_Recorded",
  "ErrorPattern": "",
  "BuildRetry": false,
  "ExcludeConsoleLog": false
}

Could be similar to #87552.

Exception Message
System.Net.Quic.QuicException : Stream aborted by peer (268).
Stack Trace
   at System.Net.Quic.ResettableValueTaskSource.TryComplete(Exception exception, Boolean final) in /_/src/libraries/System.Net.Quic/src/System/Net/Quic/Internal/ResettableValueTaskSource.cs:line 169
   at System.Net.Quic.ResettableValueTaskSource.TrySetException(Exception exception, Boolean final) in /_/src/libraries/System.Net.Quic/src/System/Net/Quic/Internal/ResettableValueTaskSource.cs:line 233
   at System.Net.Quic.QuicStream.HandleEventPeerReceiveAborted(_PEER_RECEIVE_ABORTED_e__Struct& data) in /_/src/libraries/System.Net.Quic/src/System/Net/Quic/QuicStream.cs:line 559
   at System.Net.Quic.QuicStream.HandleStreamEvent(QUIC_STREAM_EVENT& streamEvent) in /_/src/libraries/System.Net.Quic/src/System/Net/Quic/QuicStream.cs:line 609
   at System.Net.Quic.QuicStream.NativeCallback(QUIC_HANDLE* connection, Void* context, QUIC_STREAM_EVENT* streamEvent) in /_/src/libraries/System.Net.Quic/src/System/Net/Quic/QuicStream.cs:line 640
--- End of stack trace from previous location ---
   at System.Net.Quic.ResettableValueTaskSource.System.Threading.Tasks.Sources.IValueTaskSource.GetResult(Int16 token) in /_/src/libraries/System.Net.Quic/src/System/Net/Quic/Internal/ResettableValueTaskSource.cs:line 279
   at System.Net.Test.Common.Http3LoopbackStream.SendFrameAsync(Int64 frameType, ReadOnlyMemory`1 framePayload) in /_/src/libraries/Common/tests/System/Net/Http/Http3LoopbackStream.cs:line 165
   at System.Net.Test.Common.Http3LoopbackStream.SendDataFrameAsync(ReadOnlyMemory`1 data) in /_/src/libraries/Common/tests/System/Net/Http/Http3LoopbackStream.cs:line 137
   at System.Net.Test.Common.Http3LoopbackStream.SendResponseBodyAsync(Byte[] content, Boolean isFinal) in /_/src/libraries/Common/tests/System/Net/Http/Http3LoopbackStream.cs:line 280
   at System.Net.Test.Common.Http3LoopbackStream.SendResponseAsync(HttpStatusCode statusCode, IList`1 headers, String content, Boolean isFinal) in /_/src/libraries/Common/tests/System/Net/Http/Http3LoopbackStream.cs:line 245
   at System.Net.Test.Common.Http3LoopbackConnection.HandleRequestAsync(HttpStatusCode statusCode, IList`1 headers, String content) in /_/src/libraries/Common/tests/System/Net/Http/Http3LoopbackConnection.cs:line 255
   at System.Net.Test.Common.Http3LoopbackServer.HandleRequestAsync(HttpStatusCode statusCode, IList`1 headers, String content) in /_/src/libraries/Common/tests/System/Net/Http/Http3LoopbackServer.cs:line 98
   at System.Net.Test.Common.Http3LoopbackServer.HandleRequestAsync(HttpStatusCode statusCode, IList`1 headers, String content) in /_/src/libraries/Common/tests/System/Net/Http/Http3LoopbackServer.cs:line 98
   at System.Net.Http.Functional.Tests.HttpMetricsTest.<>c__DisplayClass15_0.<<RequestDuration_EnrichmentHandler_Success_Recorded>b__1>d.MoveNext() in /_/src/libraries/System.Net.Http/tests/FunctionalTests/MetricsTest.cs:line 473
--- End of stack trace from previous location ---
   at System.Threading.Tasks.TaskTimeoutExtensions.GetRealException(Task task) in /_/src/libraries/Common/tests/System/Threading/Tasks/TaskTimeoutExtensions.cs:line 120
--- End of stack trace from previous location ---
   at System.Threading.Tasks.TaskTimeoutExtensions.WhenAllOrAnyFailed(Task[] tasks) in /_/src/libraries/Common/tests/System/Threading/Tasks/TaskTimeoutExtensions.cs:line 90
   at System.Net.Test.Common.LoopbackServerFactory.<>c__DisplayClass6_0.<<CreateClientAndServerAsync>b__0>d.MoveNext() in /_/src/libraries/Common/tests/System/Net/Http/GenericLoopbackServer.cs:line 44
--- End of stack trace from previous location ---
   at System.Net.Test.Common.Http3LoopbackServerFactory.CreateServerAsync(Func`3 funcAsync, Int32 millisecondsTimeout, GenericLoopbackOptions options) in /_/src/libraries/Common/tests/System/Net/Http/Http3LoopbackServer.cs:line 116
   at System.Net.Http.Functional.Tests.HttpMetricsTest.RequestDuration_EnrichmentHandler_Success_Recorded(HttpCompletionOption completionOption, ResponseContentType responseContentType) in /_/src/libraries/System.Net.Http/tests/FunctionalTests/MetricsTest.cs:line 452
--- End of stack trace from previous location ---

Known issue validation

Build: 🔎 https://dev.azure.com/dnceng-public/public/_build/results?buildId=429885
Error message validated: RequestDuration_EnrichmentHandler_Success_Recorded
Result validation: ✅ Known issue matched with the provided build.
Validation performed at: 10/9/2023 7:22:25 PM UTC

Report

Build	Definition	Test	Pull Request
440729	dotnet/runtime	WasmTestOnNodeJS-System.Net.Http.Functional.Tests.WorkItemExecution	#93472
439408	dotnet/runtime	System.Net.Http.Functional.Tests.TelemetryTest_Http20.EventSource_ExistsWithCorrectId	#93473
437793	dotnet/runtime	WasmTestOnBrowser-System.Net.Http.Functional.Tests.WorkItemExecution	#93473
433514	dotnet/runtime	WasmTestOnBrowser-System.Net.Http.Functional.Tests.WorkItemExecution	#93010
433274	dotnet/runtime	WasmTestOnBrowser-System.Net.Http.Functional.Tests.WorkItemExecution	#93010
432707	dotnet/runtime	System.Net.Http.Functional.Tests.HttpClientHandlerTest_Http3.ServerClosesOutboundControlStream_ClientClosesConnection	#93193
432205	dotnet/runtime	WasmTestOnBrowser-System.Net.Http.Functional.Tests.WorkItemExecution	#93010
429885	dotnet/runtime	System.Net.Http.Functional.Tests.HttpMetricsTest_Http30.RequestDuration_EnrichmentHandler_Success_Recorded	#93120

Summary

24-Hour Hit Count	7-Day Hit Count	1-Month Count
1	3	8

The text was updated successfully, but these errors were encountered:

ghost · 2023-10-09T19:15:04Z

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/cbb18261-c48f-4abb-8651-8cdcb5474649/_build/results?buildId=429885
Build error leg or test failing: System.Net.Http.Functional.Tests.HttpMetricsTest_Http30.RequestDuration_EnrichmentHandler_Success_Recorded
Pull request: #93120

Error Message

{
  "ErrorMessage": "RequestDuration_EnrichmentHandler_Success_Recorded",
  "ErrorPattern": "",
  "BuildRetry": false,
  "ExcludeConsoleLog": false
}

Could be similar to #87552.

Exception Message
System.Net.Quic.QuicException : Stream aborted by peer (268).
Stack Trace
   at System.Net.Quic.ResettableValueTaskSource.TryComplete(Exception exception, Boolean final) in /_/src/libraries/System.Net.Quic/src/System/Net/Quic/Internal/ResettableValueTaskSource.cs:line 169
   at System.Net.Quic.ResettableValueTaskSource.TrySetException(Exception exception, Boolean final) in /_/src/libraries/System.Net.Quic/src/System/Net/Quic/Internal/ResettableValueTaskSource.cs:line 233
   at System.Net.Quic.QuicStream.HandleEventPeerReceiveAborted(_PEER_RECEIVE_ABORTED_e__Struct& data) in /_/src/libraries/System.Net.Quic/src/System/Net/Quic/QuicStream.cs:line 559
   at System.Net.Quic.QuicStream.HandleStreamEvent(QUIC_STREAM_EVENT& streamEvent) in /_/src/libraries/System.Net.Quic/src/System/Net/Quic/QuicStream.cs:line 609
   at System.Net.Quic.QuicStream.NativeCallback(QUIC_HANDLE* connection, Void* context, QUIC_STREAM_EVENT* streamEvent) in /_/src/libraries/System.Net.Quic/src/System/Net/Quic/QuicStream.cs:line 640
--- End of stack trace from previous location ---
   at System.Net.Quic.ResettableValueTaskSource.System.Threading.Tasks.Sources.IValueTaskSource.GetResult(Int16 token) in /_/src/libraries/System.Net.Quic/src/System/Net/Quic/Internal/ResettableValueTaskSource.cs:line 279
   at System.Net.Test.Common.Http3LoopbackStream.SendFrameAsync(Int64 frameType, ReadOnlyMemory`1 framePayload) in /_/src/libraries/Common/tests/System/Net/Http/Http3LoopbackStream.cs:line 165
   at System.Net.Test.Common.Http3LoopbackStream.SendDataFrameAsync(ReadOnlyMemory`1 data) in /_/src/libraries/Common/tests/System/Net/Http/Http3LoopbackStream.cs:line 137
   at System.Net.Test.Common.Http3LoopbackStream.SendResponseBodyAsync(Byte[] content, Boolean isFinal) in /_/src/libraries/Common/tests/System/Net/Http/Http3LoopbackStream.cs:line 280
   at System.Net.Test.Common.Http3LoopbackStream.SendResponseAsync(HttpStatusCode statusCode, IList`1 headers, String content, Boolean isFinal) in /_/src/libraries/Common/tests/System/Net/Http/Http3LoopbackStream.cs:line 245
   at System.Net.Test.Common.Http3LoopbackConnection.HandleRequestAsync(HttpStatusCode statusCode, IList`1 headers, String content) in /_/src/libraries/Common/tests/System/Net/Http/Http3LoopbackConnection.cs:line 255
   at System.Net.Test.Common.Http3LoopbackServer.HandleRequestAsync(HttpStatusCode statusCode, IList`1 headers, String content) in /_/src/libraries/Common/tests/System/Net/Http/Http3LoopbackServer.cs:line 98
   at System.Net.Test.Common.Http3LoopbackServer.HandleRequestAsync(HttpStatusCode statusCode, IList`1 headers, String content) in /_/src/libraries/Common/tests/System/Net/Http/Http3LoopbackServer.cs:line 98
   at System.Net.Http.Functional.Tests.HttpMetricsTest.<>c__DisplayClass15_0.<<RequestDuration_EnrichmentHandler_Success_Recorded>b__1>d.MoveNext() in /_/src/libraries/System.Net.Http/tests/FunctionalTests/MetricsTest.cs:line 473
--- End of stack trace from previous location ---
   at System.Threading.Tasks.TaskTimeoutExtensions.GetRealException(Task task) in /_/src/libraries/Common/tests/System/Threading/Tasks/TaskTimeoutExtensions.cs:line 120
--- End of stack trace from previous location ---
   at System.Threading.Tasks.TaskTimeoutExtensions.WhenAllOrAnyFailed(Task[] tasks) in /_/src/libraries/Common/tests/System/Threading/Tasks/TaskTimeoutExtensions.cs:line 90
   at System.Net.Test.Common.LoopbackServerFactory.<>c__DisplayClass6_0.<<CreateClientAndServerAsync>b__0>d.MoveNext() in /_/src/libraries/Common/tests/System/Net/Http/GenericLoopbackServer.cs:line 44
--- End of stack trace from previous location ---
   at System.Net.Test.Common.Http3LoopbackServerFactory.CreateServerAsync(Func`3 funcAsync, Int32 millisecondsTimeout, GenericLoopbackOptions options) in /_/src/libraries/Common/tests/System/Net/Http/Http3LoopbackServer.cs:line 116
   at System.Net.Http.Functional.Tests.HttpMetricsTest.RequestDuration_EnrichmentHandler_Success_Recorded(HttpCompletionOption completionOption, ResponseContentType responseContentType) in /_/src/libraries/System.Net.Http/tests/FunctionalTests/MetricsTest.cs:line 452
--- End of stack trace from previous location ---

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

carlossanlop · 2023-10-12T00:05:55Z

@dotnet/ncl I'm seeing a spike of hits of this failure in release/8.0 PRs. Can someone please take a look?

Here's a recent example:

Affected 8.0 PR: [release/8.0] Handle binding to initialized abstract members #93120
Queue: Libraries Test Run release coreclr linux x64 Debug
Build: https://dev.azure.com/dnceng-public/public/_build/results?buildId=429885&view=logs&j=bc8f69e2-91b3-518c-84f8-466a04c1af40&t=0864dbdb-cb3f-5f82-b0b6-057b78db53e2&l=86
Log: https://helixre107v0xd1eu3ibi6ka.blob.core.windows.net/dotnet-runtime-refs-pull-93120-merge-47197dce91b04dbf87/System.Net.Http.Functional.Tests/3/console.e4e6d7cd.log?helixlogtype=result
Callstack:

      System.Net.Quic.QuicException : Stream aborted by peer (268).
      Stack Trace:
        /_/src/libraries/System.Net.Quic/src/System/Net/Quic/Internal/ResettableValueTaskSource.cs(169,0): at System.Net.Quic.ResettableValueTaskSource.TryComplete(Exception exception, Boolean final)
        /_/src/libraries/System.Net.Quic/src/System/Net/Quic/Internal/ResettableValueTaskSource.cs(233,0): at System.Net.Quic.ResettableValueTaskSource.TrySetException(Exception exception, Boolean final)
        /_/src/libraries/System.Net.Quic/src/System/Net/Quic/QuicStream.cs(559,0): at System.Net.Quic.QuicStream.HandleEventPeerReceiveAborted(_PEER_RECEIVE_ABORTED_e__Struct& data)
        /_/src/libraries/System.Net.Quic/src/System/Net/Quic/QuicStream.cs(609,0): at System.Net.Quic.QuicStream.HandleStreamEvent(QUIC_STREAM_EVENT& streamEvent)
        /_/src/libraries/System.Net.Quic/src/System/Net/Quic/QuicStream.cs(640,0): at System.Net.Quic.QuicStream.NativeCallback(QUIC_HANDLE* connection, Void* context, QUIC_STREAM_EVENT* streamEvent)
        --- End of stack trace from previous location ---
        /_/src/libraries/System.Net.Quic/src/System/Net/Quic/Internal/ResettableValueTaskSource.cs(279,0): at System.Net.Quic.ResettableValueTaskSource.System.Threading.Tasks.Sources.IValueTaskSource.GetResult(Int16 token)
        /_/src/libraries/Common/tests/System/Net/Http/Http3LoopbackStream.cs(165,0): at System.Net.Test.Common.Http3LoopbackStream.SendFrameAsync(Int64 frameType, ReadOnlyMemory`1 framePayload)
        /_/src/libraries/Common/tests/System/Net/Http/Http3LoopbackStream.cs(120,0): at System.Net.Test.Common.Http3LoopbackStream.SendHeadersFrameAsync(Nullable`1 statusCode, IEnumerable`1 headers, Boolean qpackEncodeStatus)
        /_/src/libraries/Common/tests/System/Net/Http/Http3LoopbackStream.cs(261,0): at System.Net.Test.Common.Http3LoopbackStream.SendResponseHeadersAsync(Nullable`1 statusCode, IEnumerable`1 headers)
        /_/src/libraries/Common/tests/System/Net/Http/Http3LoopbackStream.cs(244,0): at System.Net.Test.Common.Http3LoopbackStream.SendResponseAsync(HttpStatusCode statusCode, IList`1 headers, String content, Boolean isFinal)
        /_/src/libraries/Common/tests/System/Net/Http/Http3LoopbackConnection.cs(255,0): at System.Net.Test.Common.Http3LoopbackConnection.HandleRequestAsync(HttpStatusCode statusCode, IList`1 headers, String content)
        /_/src/libraries/Common/tests/System/Net/Http/Http3LoopbackServer.cs(98,0): at System.Net.Test.Common.Http3LoopbackServer.HandleRequestAsync(HttpStatusCode statusCode, IList`1 headers, String content)
        /_/src/libraries/Common/tests/System/Net/Http/Http3LoopbackServer.cs(98,0): at System.Net.Test.Common.Http3LoopbackServer.HandleRequestAsync(HttpStatusCode statusCode, IList`1 headers, String content)
        /_/src/libraries/System.Net.Http/tests/FunctionalTests/MetricsTest.cs(473,0): at System.Net.Http.Functional.Tests.HttpMetricsTest.<>c__DisplayClass15_0.<<RequestDuration_EnrichmentHandler_Success_Recorded>b__1>d.MoveNext()
        --- End of stack trace from previous location ---
        /_/src/libraries/Common/tests/System/Threading/Tasks/TaskTimeoutExtensions.cs(120,0): at System.Threading.Tasks.TaskTimeoutExtensions.GetRealException(Task task)
        --- End of stack trace from previous location ---
        /_/src/libraries/Common/tests/System/Threading/Tasks/TaskTimeoutExtensions.cs(90,0): at System.Threading.Tasks.TaskTimeoutExtensions.WhenAllOrAnyFailed(Task[] tasks)
        /_/src/libraries/Common/tests/System/Net/Http/GenericLoopbackServer.cs(44,0): at System.Net.Test.Common.LoopbackServerFactory.<>c__DisplayClass6_0.<<CreateClientAndServerAsync>b__0>d.MoveNext()
        --- End of stack trace from previous location ---
        /_/src/libraries/Common/tests/System/Net/Http/Http3LoopbackServer.cs(116,0): at System.Net.Test.Common.Http3LoopbackServerFactory.CreateServerAsync(Func`3 funcAsync, Int32 millisecondsTimeout, GenericLoopbackOptions options)
        /_/src/libraries/System.Net.Http/tests/FunctionalTests/MetricsTest.cs(452,0): at System.Net.Http.Functional.Tests.HttpMetricsTest.RequestDuration_EnrichmentHandler_Success_Recorded(HttpCompletionOption completionOption, ResponseContentType responseContentType)
        --- End of stack trace from previous location ---

karelz · 2023-10-12T00:42:39Z

@rzikm can you please check 8.0 frequency in your Thu CI report for 8.0?

5 hits per day in main should be prioritized for main anyway - @ManickaP any thoughts here?

ManickaP · 2023-10-12T07:33:31Z

This is a test bug, client doesn't drain the response and based on timing closes the stream faster than the server can send the full reply. I'll put up a fix in main, we can then backport it to 8.0 if we decide to.

rzikm · 2023-10-12T10:40:41Z

The test in question has 1 failure in last 30 days in 8.0, and about 30 PassedOnRerun. Since it is a test-only change with low risk I think we should backport it to stabilize CI

ManickaP · 2023-10-12T11:14:15Z

Re-opening for 8.0 backport

ManickaP · 2023-10-18T08:33:06Z

#93381 is merged, closing.

karelz · 2023-10-18T09:45:58Z

Fixed in main (9.0) in PR #93379 and in 8.0 (GA) in PR #93381

ericstj added blocking-clean-ci Blocking PR or rolling runs of 'runtime' or 'runtime-extra-platforms' Known Build Error Use this to report build issues in the .NET Helix tab labels Oct 9, 2023

dotnet-issue-labeler bot added the area-System.Net.Http label Oct 9, 2023

ghost added the untriaged New issue has not been triaged by the area owner label Oct 9, 2023

rzikm added this to the 9.0.0 milestone Oct 10, 2023

ghost removed the untriaged New issue has not been triaged by the area owner label Oct 10, 2023

carlossanlop mentioned this issue Oct 12, 2023

[release/8.0] Fix Options Source Gen Trimming Issues #93193

Merged

ManickaP self-assigned this Oct 12, 2023

ManickaP mentioned this issue Oct 12, 2023

[H/3] Fix draining response in metrics test #93379

Merged

ghost added the in-pr There is an active PR which will close this issue when it is merged label Oct 12, 2023

ManickaP closed this as completed in #93379 Oct 12, 2023

ghost removed the in-pr There is an active PR which will close this issue when it is merged label Oct 12, 2023

ManickaP reopened this Oct 12, 2023

ManickaP modified the milestones: 9.0.0, 8.0.0 Oct 12, 2023

ManickaP mentioned this issue Oct 12, 2023

[release/8.0] [H/3] Fix draining response in metrics test #93381

Merged

ghost added in-pr There is an active PR which will close this issue when it is merged and removed in-pr There is an active PR which will close this issue when it is merged labels Oct 12, 2023

ManickaP closed this as completed Oct 18, 2023

karelz added the test-bug Problem in test source code (most likely) label Oct 18, 2023

ghost locked as resolved and limited conversation to collaborators Nov 17, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

RequestDuration_EnrichmentHandler_Success_Recorded fails with System.Net.Quic.QuicException : Stream aborted by peer #93250

RequestDuration_EnrichmentHandler_Success_Recorded fails with System.Net.Quic.QuicException : Stream aborted by peer #93250

ericstj commented Oct 9, 2023 •

edited by build-analysis bot

Loading

ghost commented Oct 9, 2023

Build Information

Error Message

carlossanlop commented Oct 12, 2023

karelz commented Oct 12, 2023

ManickaP commented Oct 12, 2023

rzikm commented Oct 12, 2023

ManickaP commented Oct 12, 2023

ManickaP commented Oct 18, 2023

karelz commented Oct 18, 2023

RequestDuration_EnrichmentHandler_Success_Recorded fails with System.Net.Quic.QuicException : Stream aborted by peer #93250

RequestDuration_EnrichmentHandler_Success_Recorded fails with System.Net.Quic.QuicException : Stream aborted by peer #93250

Comments

ericstj commented Oct 9, 2023 • edited by build-analysis bot Loading

Build Information

Error Message

Known issue validation

Report

Summary

ghost commented Oct 9, 2023

Build Information

Error Message

carlossanlop commented Oct 12, 2023

karelz commented Oct 12, 2023

ManickaP commented Oct 12, 2023

rzikm commented Oct 12, 2023

ManickaP commented Oct 12, 2023

ManickaP commented Oct 18, 2023

karelz commented Oct 18, 2023

ericstj commented Oct 9, 2023 •

edited by build-analysis bot

Loading