[Tests] System.Net.Quic.Tests System.Exception : Failed to create MsQuicApi instance

[mdh1418]

Failing on an unrelated PR
Build: https://dev.azure.com/dnceng-public/public/_build/results?buildId=1247&view=ms.vss-test-web.build-test-results-tab&runId=15874&paneView=dotnet-dnceng.dnceng-anon-build-release-tasks.helix-anon-test-information-tab&resultId=156099
Log: https://helixre107v0xdeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-pull-74459-merge-cc2ff9e1bcc545b9bd/System.Net.Quic.Functional.Tests/1/console.93c01d47.log?helixlogtype=result

System.Net.Quic.Tests.MsQuicCipherSuitesPolicyTests.MismatchedCipherPolicies_ConnectAsync_ThrowsQuicException [FAIL]
      Assert.Throws() Failure
      Expected: typeof(System.Net.Quic.QuicException)
      Actual:   typeof(System.Exception): Failed to create MsQuicApi instance
      ---- System.Exception : Failed to create MsQuicApi instance
      Stack Trace:
        /_/src/libraries/System.Net.Quic/src/System/Net/Quic/Internal/MsQuicApi.cs(145,0): at System.Net.Quic.MsQuicApi.AllocateMsQuicApi()
        /_/src/libraries/System.Private.CoreLib/src/System/Lazy.cs(323,0): at System.Lazy`1[[System.Net.Quic.MsQuicApi, System.Net.Quic, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]].ViaFactory(LazyThreadSafetyMode mode)
        --- End of stack trace from previous location ---
        /_/src/libraries/System.Private.CoreLib/src/System/Lazy.cs(95,0): at System.LazyHelper.ThrowException()
        /_/src/libraries/System.Private.CoreLib/src/System/Lazy.cs(431,0): at System.Lazy`1[[System.Net.Quic.MsQuicApi, System.Net.Quic, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]].CreateValue()
        /_/src/libraries/System.Private.CoreLib/src/System/Lazy.cs(507,0): at System.Lazy`1[[System.Net.Quic.MsQuicApi, System.Net.Quic, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]].get_Value()
        /_/src/libraries/System.Net.Quic/src/System/Net/Quic/Internal/MsQuicApi.cs(52,0): at System.Net.Quic.MsQuicApi.get_Api()
        /_/src/libraries/System.Net.Quic/src/System/Net/Quic/QuicListener.cs(120,0): at System.Net.Quic.QuicListener..ctor(QuicListenerOptions options)
        /_/src/libraries/System.Net.Quic/src/System/Net/Quic/QuicListener.cs(56,0): at System.Net.Quic.QuicListener.ListenAsync(QuicListenerOptions options, CancellationToken cancellationToken)
        /_/src/libraries/System.Net.Quic/tests/FunctionalTests/QuicTestBase.cs(142,0): at System.Net.Quic.Tests.QuicTestBase.CreateQuicListener(QuicListenerOptions options)
        /_/src/libraries/System.Net.Quic/tests/FunctionalTests/MsQuicCipherSuitesPolicyTests.cs(31,0): at System.Net.Quic.Tests.MsQuicCipherSuitesPolicyTests.TestConnection(CipherSuitesPolicy serverPolicy, CipherSuitesPolicy clientPolicy)
        ----- Inner Stack Trace -----
        /_/src/libraries/System.Net.Quic/src/System/Net/Quic/Internal/MsQuicApi.cs(145,0): at System.Net.Quic.MsQuicApi.AllocateMsQuicApi()
        /_/src/libraries/System.Private.CoreLib/src/System/Lazy.cs(323,0): at System.Lazy`1[[System.Net.Quic.MsQuicApi, System.Net.Quic, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]].ViaFactory(LazyThreadSafetyMode mode)
        --- End of stack trace from previous location ---
        /_/src/libraries/System.Private.CoreLib/src/System/Lazy.cs(95,0): at System.LazyHelper.ThrowException()
        /_/src/libraries/System.Private.CoreLib/src/System/Lazy.cs(431,0): at System.Lazy`1[[System.Net.Quic.MsQuicApi, System.Net.Quic, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]].CreateValue()
        /_/src/libraries/System.Private.CoreLib/src/System/Lazy.cs(507,0): at System.Lazy`1[[System.Net.Quic.MsQuicApi, System.Net.Quic, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]].get_Value()
        /_/src/libraries/System.Net.Quic/src/System/Net/Quic/Internal/MsQuicApi.cs(52,0): at System.Net.Quic.MsQuicApi.get_Api()
        /_/src/libraries/System.Net.Quic/src/System/Net/Quic/QuicListener.cs(120,0): at System.Net.Quic.QuicListener..ctor(QuicListenerOptions options)
        /_/src/libraries/System.Net.Quic/src/System/Net/Quic/QuicListener.cs(56,0): at System.Net.Quic.QuicListener.ListenAsync(QuicListenerOptions options, CancellationToken cancellationToken)
        /_/src/libraries/System.Net.Quic/tests/FunctionalTests/QuicTestBase.cs(142,0): at System.Net.Quic.Tests.QuicTestBase.CreateQuicListener(QuicListenerOptions options)
        /_/src/libraries/System.Net.Quic/tests/FunctionalTests/MsQuicCipherSuitesPolicyTests.cs(31,0): at System.Net.Quic.Tests.MsQuicCipherSuitesPolicyTests.TestConnection(CipherSuitesPolicy serverPolicy, CipherSuitesPolicy clientPolicy)

[ghost]

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

Issue Details

---

Failing on an unrelated PR
Build: https://dev.azure.com/dnceng-public/public/_build/results?buildId=1247&view=ms.vss-test-web.build-test-results-tab&runId=15874&paneView=dotnet-dnceng.dnceng-anon-build-release-tasks.helix-anon-test-information-tab&resultId=156099
Log: https://helixre107v0xdeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-pull-74459-merge-cc2ff9e1bcc545b9bd/System.Net.Quic.Functional.Tests/1/console.93c01d47.log?helixlogtype=result

System.Net.Quic.Tests.MsQuicCipherSuitesPolicyTests.MismatchedCipherPolicies_ConnectAsync_ThrowsQuicException [FAIL]
      Assert.Throws() Failure
      Expected: typeof(System.Net.Quic.QuicException)
      Actual:   typeof(System.Exception): Failed to create MsQuicApi instance
      ---- System.Exception : Failed to create MsQuicApi instance
      Stack Trace:
        /_/src/libraries/System.Net.Quic/src/System/Net/Quic/Internal/MsQuicApi.cs(145,0): at System.Net.Quic.MsQuicApi.AllocateMsQuicApi()
        /_/src/libraries/System.Private.CoreLib/src/System/Lazy.cs(323,0): at System.Lazy`1[[System.Net.Quic.MsQuicApi, System.Net.Quic, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]].ViaFactory(LazyThreadSafetyMode mode)
        --- End of stack trace from previous location ---
        /_/src/libraries/System.Private.CoreLib/src/System/Lazy.cs(95,0): at System.LazyHelper.ThrowException()
        /_/src/libraries/System.Private.CoreLib/src/System/Lazy.cs(431,0): at System.Lazy`1[[System.Net.Quic.MsQuicApi, System.Net.Quic, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]].CreateValue()
        /_/src/libraries/System.Private.CoreLib/src/System/Lazy.cs(507,0): at System.Lazy`1[[System.Net.Quic.MsQuicApi, System.Net.Quic, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]].get_Value()
        /_/src/libraries/System.Net.Quic/src/System/Net/Quic/Internal/MsQuicApi.cs(52,0): at System.Net.Quic.MsQuicApi.get_Api()
        /_/src/libraries/System.Net.Quic/src/System/Net/Quic/QuicListener.cs(120,0): at System.Net.Quic.QuicListener..ctor(QuicListenerOptions options)
        /_/src/libraries/System.Net.Quic/src/System/Net/Quic/QuicListener.cs(56,0): at System.Net.Quic.QuicListener.ListenAsync(QuicListenerOptions options, CancellationToken cancellationToken)
        /_/src/libraries/System.Net.Quic/tests/FunctionalTests/QuicTestBase.cs(142,0): at System.Net.Quic.Tests.QuicTestBase.CreateQuicListener(QuicListenerOptions options)
        /_/src/libraries/System.Net.Quic/tests/FunctionalTests/MsQuicCipherSuitesPolicyTests.cs(31,0): at System.Net.Quic.Tests.MsQuicCipherSuitesPolicyTests.TestConnection(CipherSuitesPolicy serverPolicy, CipherSuitesPolicy clientPolicy)
        ----- Inner Stack Trace -----
        /_/src/libraries/System.Net.Quic/src/System/Net/Quic/Internal/MsQuicApi.cs(145,0): at System.Net.Quic.MsQuicApi.AllocateMsQuicApi()
        /_/src/libraries/System.Private.CoreLib/src/System/Lazy.cs(323,0): at System.Lazy`1[[System.Net.Quic.MsQuicApi, System.Net.Quic, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]].ViaFactory(LazyThreadSafetyMode mode)
        --- End of stack trace from previous location ---
        /_/src/libraries/System.Private.CoreLib/src/System/Lazy.cs(95,0): at System.LazyHelper.ThrowException()
        /_/src/libraries/System.Private.CoreLib/src/System/Lazy.cs(431,0): at System.Lazy`1[[System.Net.Quic.MsQuicApi, System.Net.Quic, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]].CreateValue()
        /_/src/libraries/System.Private.CoreLib/src/System/Lazy.cs(507,0): at System.Lazy`1[[System.Net.Quic.MsQuicApi, System.Net.Quic, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]].get_Value()
        /_/src/libraries/System.Net.Quic/src/System/Net/Quic/Internal/MsQuicApi.cs(52,0): at System.Net.Quic.MsQuicApi.get_Api()
        /_/src/libraries/System.Net.Quic/src/System/Net/Quic/QuicListener.cs(120,0): at System.Net.Quic.QuicListener..ctor(QuicListenerOptions options)
        /_/src/libraries/System.Net.Quic/src/System/Net/Quic/QuicListener.cs(56,0): at System.Net.Quic.QuicListener.ListenAsync(QuicListenerOptions options, CancellationToken cancellationToken)
        /_/src/libraries/System.Net.Quic/tests/FunctionalTests/QuicTestBase.cs(142,0): at System.Net.Quic.Tests.QuicTestBase.CreateQuicListener(QuicListenerOptions options)
        /_/src/libraries/System.Net.Quic/tests/FunctionalTests/MsQuicCipherSuitesPolicyTests.cs(31,0): at System.Net.Quic.Tests.MsQuicCipherSuitesPolicyTests.TestConnection(CipherSuitesPolicy serverPolicy, CipherSuitesPolicy clientPolicy)

Author:	mdh1418
Assignees:	-
Labels:	area-System.Net.Quic
Milestone:	-

[wfurt]

cc: @rzikm #74749?

[rzikm]

This is rather weird, I see only a single instance of this ATM, I will try to reproduce this

[wfurt]

arm64. I'm wondering if we could put more info to the exception.... At least error code or some other hint.

[rzikm]

The same failure happened on the original PR as well https://helixre107v0xdeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-pull-74749-merge-6625e31f87f14340a5/System.Net.Quic.Functional.Tests/1/console.2f3501b8.log?helixlogtype=result

We missed it because there was a blip which caused only a few checks to run on the latest commit, and I assumed everything was green :(

Looks like the failures are contained to the net7.0-Linux-Debug-arm64-Mono_release-(Debian.11.Arm64.Open)Ubuntu.1804.Armarch.Open@mcr.microsoft.com/dotnet-buildtools/prereqs:debian-11-helix-arm64v8-20220820185253-06f234f runs

[ericstj]

Hitting this on my PR: https://dev.azure.com/dnceng-public/public/_build/results?buildId=1830&view=ms.vss-test-web.build-test-results-tab&runId=23300&paneView=debug
https://helixre107v0xdeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-pull-74943-merge-534f630c09994be190/System.Net.Quic.Functional.Tests/1/console.ee97900d.log?helixlogtype=result

[wfurt]

I had repro for short time and now MsQuic is failing initialize e.g. IsSupported -> false. I suspect it may be MsQuic issue. It may be best roll-back the change @rzikm until we find good solution. (or disable runs on ARM)

[rzikm]

okay, so it looks like it is not related to my changes... the second MsQuicOpen call fails with error code QUIC_STATUS_OUT_OF_MEMORY, so I am inclined to punt this as environmental, we just need to improve error reporting

[rzikm]

The change was reverted for now via #74984 to unblock CI

[rzikm]

I have been able to get somewhat close to the root cause, the QUIC_STATUS_OUT_OF_MEMORY is actually a bit misleading here:

https://github.com/microsoft/msquic/blob/62bd43af655bbd4cdd7e9139e1e7efa7c5463994/src/platform/platform_posix.c#L217-L220

The worker pool initialization fails, because the pthread_create fails to create one of the worker threads (during debugging, it was the second one) and returns EINVAL.

https://github.com/microsoft/msquic/blob/73cabea417d05443ec1d855cd3faa47d2a0979cb/src/platform/platform_posix.c#L671

a possible workaround is to retry without attempting thread affinitization, we already do this when pthread_create returns ENOENT or ENOKEY since that was preventing us from running on ARM64 in the first place.

cc: @wfurt, @nibanks

[Nick-Stanton]

I got this on #74789 yesterday as well.

Build: https://dev.azure.com/dnceng-public/public/_build/results?buildId=1905&view=ms.vss-test-web.build-test-results-tab&runId=25478&resultId=165790&paneView=dotnet-dnceng.dnceng-anon-build-release-tasks.helix-anon-test-information-tab

Log: https://helixre107v0xdeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-pull-74789-merge-a8e725d9988441cda1/System.Net.Quic.Functional.Tests/1/console.c77c71ee.log?helixlogtype=result

[wfurt]

Retry without specific errno was suggested. Make sense to me. This feels to fragile

[karelz]

We should likely dupe it against #74629 as it is now reverted by PR #74984. @rzikm thoughts?

[rzikm]

yes, now that the CI failures are fixed, we can close this and continue in #74629.