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.

Sign up for GitHub

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

Jump to bottom

SslStream tests can hit Assert and fail completely #65455

Closed
wfurt opened this issue Feb 16, 2022 · 13 comments · Fixed by #66682
Closed

SslStream tests can hit Assert and fail completely #65455

wfurt opened this issue Feb 16, 2022 · 13 comments · Fixed by #66682
Assignees
@rzikm
Labels
area-System.Net.Security bug
Milestone
7.0.0

Comments

@wfurt
Copy link
Member

wfurt commented Feb 16, 2022

https://helix.dot.net/api/2019-06-17/jobs/ef6bb735-70e8-4269-9758-93a9fda98c7d/workitems/System.Net.Security.Tests/console

    System.Net.Security.Tests.SslStreamNetworkStreamTest.SslStream_NegotiateClientCertificateAsync_PendingDecryptedData_Throws [SKIP]
      Condition(s) not met: "SupportsRenegotiation"
Process terminated due to "Expected 7 <= 0
   at System.Diagnostics.DebugProvider.Fail(String message, String detailMessage) in /_/src/libraries/System.Private.CoreLib/src/System/Diagnostics/DebugProvider.cs:line 22
   at System.Diagnostics.Debug.Fail(String message, String detailMessage) in /_/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Debug.cs:line 131
   at System.Diagnostics.Debug.Assert(Boolean condition, String message, String detailMessage) in /_/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Debug.cs:line 95
   at System.Diagnostics.Debug.Assert(Boolean condition, String message) in /_/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Debug.cs:line 84
   at System.Diagnostics.Debug.Assert(Boolean condition, AssertInterpolatedStringHandler& message) in /_/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Debug.cs:line 88
   at System.Net.ArrayBuffer.Discard(Int32 byteCount) in /_/src/libraries/Common/src/System/Net/ArrayBuffer.cs:line 67
   at System.Net.Security.SslStream.SslBuffer.DiscardEncrypted(Int32 byteCount) in /_/src/libraries/System.Net.Security/src/System/Net/Security/SslStream.cs:line 152
   at System.Net.Security.SslStream.ProcessBlob(Int32 frameSize) in /_/src/libraries/System.Net.Security/src/System/Net/Security/SslStream.Implementation.cs:line 498
   at System.Net.Security.SslStream.<ReceiveBlobAsync>d__167`1[[System.Net.Security.AsyncReadWriteAdapter, System.Net.Security, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]].MoveNext() in /_/src/libraries/System.Net.Security/src/System/Net/Security/SslStream.Implementation.cs:line 487
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.AsyncStateMachineBox`1[[System.Net.Security.ProtocolToken, System.Net.Security, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a],[System.Net.Security.SslStream.<ReceiveBlobAsync>d__167`1[[System.Net.Security.AsyncReadWriteAdapter, System.Net.Security, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]], System.Net.Security, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]].ExecutionContextCallback(Object s) in /_/src/libraries/System.Private.CoreLib/src/System/Runtime/CompilerServices/AsyncTaskMethodBuilderT.cs:line 286
   at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state) in /_/src/libraries/System.Private.CoreLib/src/System/Threading/ExecutionContext.cs:line 183
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.AsyncStateMachineBox`1[[System.Net.Security.ProtocolToken, System.Net.Security, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a],[System.Net.Security.SslStream.<ReceiveBlobAsync>d__167`1[[System.Net.Security.AsyncReadWriteAdapter, System.Net.Security, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]], System.Net.Security, Version=7.0.0.0,

may be regression from #64747
@ghost
Copy link

ghost commented Feb 16, 2022

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

Issue Details

https://helix.dot.net/api/2019-06-17/jobs/ef6bb735-70e8-4269-9758-93a9fda98c7d/workitems/System.Net.Security.Tests/console

    System.Net.Security.Tests.SslStreamNetworkStreamTest.SslStream_NegotiateClientCertificateAsync_PendingDecryptedData_Throws [SKIP]
      Condition(s) not met: "SupportsRenegotiation"
Process terminated due to "Expected 7 <= 0
   at System.Diagnostics.DebugProvider.Fail(String message, String detailMessage) in /_/src/libraries/System.Private.CoreLib/src/System/Diagnostics/DebugProvider.cs:line 22
   at System.Diagnostics.Debug.Fail(String message, String detailMessage) in /_/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Debug.cs:line 131
   at System.Diagnostics.Debug.Assert(Boolean condition, String message, String detailMessage) in /_/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Debug.cs:line 95
   at System.Diagnostics.Debug.Assert(Boolean condition, String message) in /_/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Debug.cs:line 84
   at System.Diagnostics.Debug.Assert(Boolean condition, AssertInterpolatedStringHandler& message) in /_/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Debug.cs:line 88
   at System.Net.ArrayBuffer.Discard(Int32 byteCount) in /_/src/libraries/Common/src/System/Net/ArrayBuffer.cs:line 67
   at System.Net.Security.SslStream.SslBuffer.DiscardEncrypted(Int32 byteCount) in /_/src/libraries/System.Net.Security/src/System/Net/Security/SslStream.cs:line 152
   at System.Net.Security.SslStream.ProcessBlob(Int32 frameSize) in /_/src/libraries/System.Net.Security/src/System/Net/Security/SslStream.Implementation.cs:line 498
   at System.Net.Security.SslStream.<ReceiveBlobAsync>d__167`1[[System.Net.Security.AsyncReadWriteAdapter, System.Net.Security, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]].MoveNext() in /_/src/libraries/System.Net.Security/src/System/Net/Security/SslStream.Implementation.cs:line 487
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.AsyncStateMachineBox`1[[System.Net.Security.ProtocolToken, System.Net.Security, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a],[System.Net.Security.SslStream.<ReceiveBlobAsync>d__167`1[[System.Net.Security.AsyncReadWriteAdapter, System.Net.Security, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]], System.Net.Security, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]].ExecutionContextCallback(Object s) in /_/src/libraries/System.Private.CoreLib/src/System/Runtime/CompilerServices/AsyncTaskMethodBuilderT.cs:line 286
   at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state) in /_/src/libraries/System.Private.CoreLib/src/System/Threading/ExecutionContext.cs:line 183
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.AsyncStateMachineBox`1[[System.Net.Security.ProtocolToken, System.Net.Security, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a],[System.Net.Security.SslStream.<ReceiveBlobAsync>d__167`1[[System.Net.Security.AsyncReadWriteAdapter, System.Net.Security, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]], System.Net.Security, Version=7.0.0.0,

may be regression from #64747

Author: wfurt
Assignees: rzikm
Labels:

area-System.Net.Security
Milestone: -

@dotnet-issue-labeler dotnet-issue-labeler bot added the untriaged New issue has not been triaged by the area owner label Feb 16, 2022
@wfurt wfurt added this to the 7.0.0 milestone Feb 16, 2022
@danmoseley
Copy link
Member

As an aside, it's unfortunate that a failed assert causes the whole test library to terminate. It is possible for test libraries to twiddle this, so that the individual test fails but others still run, it is done here (there may be a better way)

runtime/src/libraries/System.Diagnostics.Debug/tests/DebugTests.cs

Line 67 in 6e05d78

FieldInfo failCoreHook = typeof(DebugProvider).GetField("s_FailCore", BindingFlags.Static | BindingFlags.NonPublic);

@stephentoub I wonder whether we should do this across all our test libraries.

@wfurt
Copy link
Member Author

wfurt commented Feb 16, 2022

Note the Assert comes from production code not test or test library.

@stephentoub
Copy link
Member

it's unfortunate that a failed assert causes the whole test library to terminate

Just to be clear, a failed assert in the production code, not a test assert. Those production asserts are things that should never fail, and if they do, it's generally either a serious problem or a faulty assert. With the rarity that they cause a test suite to fail and the possible severity of when they do, and the fact that if they do, there's a reasonable chance the process is somehow corrupted and other tests continuing to run could easily lead to other test failures that mask the original problem, I'm happy with the status quo of crashing at that exact moment, hopefully with a good dump from the resulting FailFast.

there may be a better way

If we really wanted to, we'd plug in via Trace.Listeners and supply an alternative handler. I'm skeptical of doing so, however.

@wfurt
Copy link
Member Author

wfurt commented Feb 16, 2022

Most of the tests we have are functional e.g. test that for given input we produce expected output. We don't have many (or maybe any) tests that would stress concurrent behavior. While this is not generally applicable to all libraries it feels like for networking this would be valuable and could be good improvement. That would increase our chances to catch problems like this one during development cycle.

@rzikm
Copy link
Member

rzikm commented Feb 17, 2022

That's weird, this should not be possible. According to the stack trace and the assert message, the _buffer is empty, but after EnsureFullTlsFrameAsync (called in ReceiveBlobAsync lower in the call stack), frameSize >= _buffer.EncryptedLength should always hold.

Did this happen in main, or is nome PR?

@karelz karelz added bug and removed untriaged New issue has not been triaged by the area owner labels Feb 17, 2022
@wfurt
Copy link
Member Author

wfurt commented Feb 17, 2022

Happened on #65435. Look at #43686 @rzikm

@danmoseley
Copy link
Member

Just to be clear, a failed assert in the production code, not a test assert. Those production asserts are things that should never fail, and if they do, it's generally either a serious problem or a faulty assert. With the rarity that they cause a test suite to fail and the possible severity of when they do, and the fact that if they do, there's a reasonable chance the process is somehow corrupted and other tests continuing to run could easily lead to other test failures that mask the original problem, I'm happy with the status quo of crashing at that exact moment, hopefully with a good dump from the resulting FailFast.

I think the infrequency is the best argument here. With respect to severity, one could argue (perhaps reasonably actually) that we should tear down the test process on a NullReferenceException. We have a fair number of Debug.Asserts that test for those.

@stephentoub
Copy link
Member

We have a fair number of Debug.Asserts that test for those.

And many more since we annotated for nullable reference types, since if you have a local the compiler doesn't know is non-null but you do, you can either use ! or Debug.Assert(local is not null) to suppress it, and we often choose the latter in order to get that added debug-only validation / tear-down.

@rzikm
Copy link
Member

rzikm commented Feb 23, 2022 •
edited
Loading

The current suspicion is that the SslStream has been disposed meanwhile. However, I was unable to confirm this by inspecting the coredump from the mentioned PRs (issues when opening the dump).

If I have time later, I will try to stress it and repro this locally, but it is not currently at the top of the priority list.

@rzikm rzikm removed their assignment Feb 23, 2022
@elinor-fung elinor-fung mentioned this issue Mar 2, 2022
Merged
@kunalspathak kunalspathak mentioned this issue Mar 4, 2022
Merged
@rzikm
Copy link
Member

rzikm commented Mar 11, 2022

I managed to get a dump which I can analyze. The SslStream instance is indeed disposed. Once I figure out which test this is happening on, we will have something actionable

@wfurt
Copy link
Member Author

wfurt commented Mar 12, 2022

It may be nice to add test that does not on purpose to get better coverage for such case.

@rzikm
Copy link
Member

rzikm commented Mar 15, 2022 •
edited
Loading

The responsible test seems to be SslStreamNetworkStreamTest.SslStream_SendReceiveOverNetworkStream_AuthenticationException. The call to AuthenticateAsClient is not awaited and the connection is torn down in the middle of the handshake.

@rzikm rzikm self-assigned this Mar 15, 2022
rzikm added a commit to rzikm/dotnet-runtime that referenced this issue Mar 15, 2022
@rzikm
Await pending client authentication task before disposing
fbdec0d 
Fixes dotnet#65455.

The assert was hit due to the SslStream being disposed during handshake, while `AuthenticateAsClientAsync` was still running.
@rzikm rzikm mentioned this issue Mar 15, 2022
Merged
@ghost ghost added the in-pr There is an active PR which will close this issue when it is merged label Mar 15, 2022
rzikm added a commit that referenced this issue Mar 16, 2022
@rzikm
Await pending client authentication task before disposing (#66682)
7c89933 
Fixes #65455.

The assert was hit due to the SslStream being disposed during handshake, while `AuthenticateAsClientAsync` was still running. This removes a rare crash in test runs with debug libraries configuration.
@ghost ghost removed the in-pr There is an active PR which will close this issue when it is merged label Mar 16, 2022
@rzikm rzikm reopened this Mar 18, 2022
@rzikm rzikm closed this as completed Mar 18, 2022
@rzikm rzikm mentioned this issue Mar 18, 2022
Closed
radekdoulik pushed a commit to radekdoulik/runtime that referenced this issue Mar 30, 2022
@rzikm @radekdoulik
Await pending client authentication task before disposing (dotnet#66682)
e9bfbc3 
Fixes dotnet#65455.

The assert was hit due to the SslStream being disposed during handshake, while `AuthenticateAsClientAsync` was still running. This removes a rare crash in test runs with debug libraries configuration.
@ghost ghost locked as resolved and limited conversation to collaborators Apr 17, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees

@rzikm rzikm

Labels
area-System.Net.Security bug
Projects
None yet
Milestone
7.0.0
Development

Successfully merging a pull request may close this issue.

Await pending client authentication task before disposing rzikm/dotnet-runtime
5 participants
@stephentoub @karelz @danmoseley @wfurt @rzikm