Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Closed
ericstj opened this issue Oct 9, 2023 · 8 comments · Fixed by #93379
Assignees
Labels
area-System.Net.Http blocking-clean-ci Blocking PR or rolling runs of 'runtime' or 'runtime-extra-platforms' in-pr There is an active PR which will close this issue when it is merged Known Build Error Use this to report build issues in the .NET Helix tab test-bug Problem in test source code (most likely)
Milestone

Comments

@ericstj
Copy link
Member

ericstj commented Oct 9, 2023

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
@ericstj 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
@ghost ghost added the untriaged New issue has not been triaged by the area owner label Oct 9, 2023
@ghost
Copy link

ghost commented Oct 9, 2023

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: -

@rzikm rzikm added this to the 9.0.0 milestone Oct 10, 2023
@ghost ghost removed the untriaged New issue has not been triaged by the area owner label Oct 10, 2023
@carlossanlop
Copy link
Member

@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:

      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
Copy link
Member

karelz commented Oct 12, 2023

@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
Copy link
Member

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.

@ManickaP ManickaP self-assigned this Oct 12, 2023
@ghost ghost added the in-pr There is an active PR which will close this issue when it is merged label Oct 12, 2023
@rzikm
Copy link
Member

rzikm commented Oct 12, 2023

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

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

Re-opening for 8.0 backport

@ManickaP ManickaP reopened this Oct 12, 2023
@ManickaP ManickaP modified the milestones: 9.0.0, 8.0.0 Oct 12, 2023
@ghost 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
Copy link
Member

#93381 is merged, closing.

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

karelz commented Oct 18, 2023

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

@ghost ghost locked as resolved and limited conversation to collaborators Nov 17, 2023
@dotnet-policy-service dotnet-policy-service bot added the in-pr There is an active PR which will close this issue when it is merged label Dec 12, 2024
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
area-System.Net.Http blocking-clean-ci Blocking PR or rolling runs of 'runtime' or 'runtime-extra-platforms' in-pr There is an active PR which will close this issue when it is merged Known Build Error Use this to report build issues in the .NET Helix tab test-bug Problem in test source code (most likely)
Projects
None yet
Development

Successfully merging a pull request may close this issue.

5 participants