[8.0] HttpClient test failure - attempting to access disposed object 'ConnectedStreams'

[carlossanlop]

Build Information

Build: https://dev.azure.com/dnceng-public/public/_build/results?buildId=593479
Build error leg or test failing: System.Net.Http.Functional.Tests.HttpMetricsTest

Error Message

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

{
  "ErrorMessage": "Object name: 'ConnectedStreams",
  "BuildRetry": false,
  "ExcludeConsoleLog": false
}

• PR: [release/8.0][browser] Fix failures in CalendarTestBase affecting several globalization tests  #99407
• Queue: Libraries Test Run release coreclr windows x64 Debug
• Build: https://dev.azure.com/dnceng-public/public/_build/results?buildId=593479
• Log file: https://helixre107v0xd1eu3ibi6ka.blob.core.windows.net/dotnet-runtime-refs-pull-99407-merge-463928b535334e2bb2/System.Net.Http.Functional.Tests/3/console.670d5413.log?helixlogtype=result
• Output:

    System.Net.Http.Functional.Tests.HttpMetricsTest_Http11_Async_HttpMessageInvoker.ActiveRequests_Success_Recorded [FAIL]
      System.TimeoutException : The operation has timed out.
      Stack Trace:
        --- End of stack trace from previous location ---
    System.Net.Http.Functional.Tests.HttpMetricsTest_Http20.RequestDuration_Success_Recorded(method: "GET", statusCode: OK) [FAIL]
      System.TimeoutException : The operation has timed out.
      Stack Trace:
        --- End of stack trace from previous location ---
    System.Net.Http.Functional.Tests.Http1CloseResponseStreamZeroByteReadTest.ZeroByteRead_IssuesZeroByteReadOnUnderlyingStream(readMode: SyncSpan, useSsl: True) [FAIL]
      System.Threading.Tasks.TaskCanceledException : The request was canceled due to the configured HttpClient.Timeout of 100 seconds elapsing.
      ---- System.TimeoutException : The operation was canceled.
      -------- System.Threading.Tasks.TaskCanceledException : The operation was canceled.
      ------------ System.IO.IOException : The read operation failed, see inner exception.
      ---------------- System.ObjectDisposedException : Cannot access a disposed object.
      Object name: 'ConnectedStreams'.
      Stack Trace:
        /_/src/libraries/System.Net.Http/src/System/Net/Http/HttpClient.cs(630,0): at System.Net.Http.HttpClient.HandleFailure(Exception e, Boolean telemetryStarted, HttpResponseMessage response, CancellationTokenSource cts, CancellationToken cancellationToken, CancellationTokenSource pendingRequestsCts)
        /_/src/libraries/System.Net.Http/src/System/Net/Http/HttpClient.cs(549,0): at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenSource pendingRequestsCts, CancellationToken originalCancellationToken)
        /_/src/libraries/System.Net.Http/tests/FunctionalTests/ResponseStreamZeroByteReadTests.cs(124,0): at System.Net.Http.Functional.Tests.Http1ResponseStreamZeroByteReadTestBase.ZeroByteRead_IssuesZeroByteReadOnUnderlyingStream(ReadWriteMode readMode, Boolean useSsl)
        --- End of stack trace from previous location ---
        ----- Inner Stack Trace -----
        
        ----- Inner Stack Trace -----
        /_/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpConnection.cs(862,0): at System.Net.Http.HttpConnection.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
        /_/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpConnectionPool.cs(1116,0): at System.Net.Http.HttpConnectionPool.SendWithVersionDetectionAndRetryAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken)
        /_/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/RedirectHandler.cs(30,0): at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
        /_/src/libraries/System.Net.Http/src/System/Net/Http/HttpClient.cs(530,0): at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenSource pendingRequestsCts, CancellationToken originalCancellationToken)
        ----- Inner Stack Trace -----
        /_/src/libraries/System.Net.Security/src/System/Net/Security/SslStream.IO.cs(918,0): at System.Net.Security.SslStream.ReadAsyncInternal[TIOAdapter](Memory`1 buffer, CancellationToken cancellationToken)
        /_/src/libraries/System.Private.CoreLib/src/System/Runtime/CompilerServices/PoolingAsyncValueTaskMethodBuilderT.cs(422,0): at System.Runtime.CompilerServices.PoolingAsyncValueTaskMethodBuilder`1.StateMachineBox`1.System.Threading.Tasks.Sources.IValueTaskSource<TResult>.GetResult(Int16 token)
        /_/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpConnection.cs(1593,0): at System.Net.Http.HttpConnection.InitialFillAsync(Boolean async)
        /_/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpConnection.cs(610,0): at System.Net.Http.HttpConnection.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
        ----- Inner Stack Trace -----
        /_/src/libraries/Common/tests/System/IO/ConnectedStreams.cs(421,0): at System.IO.ConnectedStreams.BidirectionalStreamBufferStream.ThrowIfDisposed()
        /_/src/libraries/Common/tests/System/IO/ConnectedStreams.cs(368,0): at System.IO.ConnectedStreams.BidirectionalStreamBufferStream.ReadAsync(Memory`1 buffer, CancellationToken cancellationToken)
        /_/src/libraries/Common/src/System/IO/DelegatingStream.cs(112,0): at System.IO.DelegatingStream.ReadAsync(Memory`1 buffer, CancellationToken cancellationToken)
        /_/src/libraries/System.Net.Http/tests/FunctionalTests/ResponseStreamZeroByteReadTests.cs(346,0): at System.Net.Http.Functional.Tests.<ResponseStreamZeroByteReadTests>F1C54D5ACCABC045F7BA21BFB92D4C16B34692D65BC870FDAF262922E655452FE__ReadInterceptStream.ReadAsync(Memory`1 buffer, CancellationToken cancellationToken)
        /_/src/libraries/System.Net.Security/src/System/Net/Security/ReadWriteAdapter.cs(22,0): at System.Net.Security.AsyncReadWriteAdapter.ReadAsync(Stream stream, Memory`1 buffer, CancellationToken cancellationToken)
        /_/src/libraries/System.Net.Security/src/System/Net/Security/SslStream.IO.cs(723,0): at System.Net.Security.SslStream.EnsureFullTlsFrameAsync[TIOAdapter](CancellationToken cancellationToken, Int32 estimatedSize)
        /_/src/libraries/System.Private.CoreLib/src/System/Runtime/CompilerServices/PoolingAsyncValueTaskMethodBuilderT.cs(422,0): at System.Runtime.CompilerServices.PoolingAsyncValueTaskMethodBuilder`1.StateMachineBox`1.System.Threading.Tasks.Sources.IValueTaskSource<TResult>.GetResult(Int16 token)
        /_/src/libraries/System.Net.Security/src/System/Net/Security/SslStream.IO.cs(831,0): at System.Net.Security.SslStream.ReadAsyncInternal[TIOAdapter](Memory`1 buffer, CancellationToken cancellationToken)

Known issue validation

Build: 🔎 https://dev.azure.com/dnceng-public/public/_build/results?buildId=593479
Error message validated: [Object name: 'ConnectedStreams]
Result validation: ✅ Known issue matched with the provided build.
Validation performed at: 3/7/2024 7:23:55 PM UTC

Report

Build	Definition	Test	Pull Request
707058	dotnet/runtime	System.Net.Http.Functional.Tests.SocksProxyTest_Http1_Async.TestLoopbackAsync

Summary

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

[ghost]

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

Issue Details

---

Error Blob

{
  "ErrorMessage": "Object name: 'ConnectedStreams'",
  "BuildRetry": false,
  "ErrorPattern": "",
  "ExcludeConsoleLog": true
}

Reproduction Steps

• PR: [release/8.0-staging] Update dependencies from dotnet/hotreload-utils #96761
• Queue: Libraries Test Run release coreclr windows x64 Debug
• Build: https://dev.azure.com/dnceng-public/public/_build/results?buildId=521682&view=logs&j=cb131f87-d5af-5ecc-6e5f-6dc86994859c&t=76503e0a-8c41-542c-43da-63a4758a95b0&l=104
• Log file: https://helixre107v0xd1eu3ibi6ka.blob.core.windows.net/dotnet-runtime-refs-pull-96761-merge-149438f12937443fbf/System.Net.Http.Functional.Tests/3/console.98522580.log?helixlogtype=result
• Output:

System.Net.Http.Functional.Tests.Http1SingleChunkResponseStreamZeroByteReadTest.ZeroByteRead_IssuesZeroByteReadOnUnderlyingStream(readMode: SyncSpan, useSsl: True) [FAIL]
      System.Threading.Tasks.TaskCanceledException : The request was canceled due to the configured HttpClient.Timeout of 100 seconds elapsing.
      ---- System.TimeoutException : The operation was canceled.
      -------- System.Threading.Tasks.TaskCanceledException : The operation was canceled.
      ------------ System.IO.IOException : The read operation failed, see inner exception.
      ---------------- System.ObjectDisposedException : Cannot access a disposed object.
      Object name: 'ConnectedStreams'.
      Stack Trace:
        /_/src/libraries/System.Net.Http/src/System/Net/Http/HttpClient.cs(630,0): at System.Net.Http.HttpClient.HandleFailure(Exception e, Boolean telemetryStarted, HttpResponseMessage response, CancellationTokenSource cts, CancellationToken cancellationToken, CancellationTokenSource pendingRequestsCts)
        /_/src/libraries/System.Net.Http/src/System/Net/Http/HttpClient.cs(549,0): at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenSource pendingRequestsCts, CancellationToken originalCancellationToken)
        /_/src/libraries/System.Net.Http/tests/FunctionalTests/ResponseStreamZeroByteReadTests.cs(124,0): at System.Net.Http.Functional.Tests.Http1ResponseStreamZeroByteReadTestBase.ZeroByteRead_IssuesZeroByteReadOnUnderlyingStream(ReadWriteMode readMode, Boolean useSsl)

Author:	carlossanlop
Assignees:	-
Labels:	area-System.Net.Http, os-windows, arch-x64, blocking-clean-ci, runtime-coreclr, Known Build Error
Milestone:	-

[CarnaViire]

Triage: We should investigate this in 9.0.

If counting both "Failed" and "PassedOnRerun", this has been happening quite a lot (over main, release/8.0 and PRs): 123 records in Kusto for the last 30 days. For "Failed" only, it's not that much: 7 in total for the last 30 days (1 main, 1 release/8.0, 5 PR).

It is always for readMode: SyncSpan, useSsl: True, but for several types of HTTP/1 response stream tests: Http1Raw.., Http1SingleChunk.., Http1MultiChunk.., Http1ContentLength.., Http1Close.. (..ResponseStreamZeroByteReadTest)

[jeffschwMSFT]

removing blocking-clean-ci as it has not failed in 30 days

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

[carlossanlop]

I'm still seeing this. I don't know how it is reporting 0 hits. I suspect it has to do with the fact that the build link does not exist anymore.

Reopening and updating the KnownBuildError info.

[karelz]

@rzikm it is marked as 8.0, but it was in 9.0 main in the past as well - #96797 (comment)
Can you please look at stats when it failed last in main (9.0)? Thanks!

[rzikm]

@rzikm it is marked as 8.0, but it was in 9.0 main in the past as well - #96797 (comment) Can you please look at stats when it failed last in main (9.0)? Thanks!

I see last report on May 26th. then May 29th on a PR, nothing since then.

Also, all hits seem to be on Windows (both ARM64 and x64)

[liveans]

Can this be related to #102699? Actual issue seems that one of the streams is stuck(?) somewhere while reading, and it causes a TimeoutException but 100 seconds is still too much time for this and I'm not %100 sure. However, there were 2-3 failures every month, but no occurrences on main and PRs since June 2nd.

[rzikm]

Sounds plausible, are we seeing any recent failures on 8.0? if yes, then we can try backporting the change

[liveans]

are we seeing any recent failures on 8.0? if yes, then we can try backporting the change

Yes, in June we have 2 failures on 8.0, June 5th, June 11th

[liveans]

Triage: This is fixed in main (9.0) and hitting 2-3 times (low impact) per month in 8.0, closing this for now. If this issue bothers 8.0 so high, we can backport the fix in the future. Feel free to re-open if you disagree with the decision.