Increase some of the DnsEndPointTest timeouts #58129

antonfirsov · 2021-08-25T18:44:11Z

Long story short:
I have spent several hours trying to get a test run on SLES in order to repro #57929, no success so far, and it may take days to make progress, since I'm unfamiliar with SLES.

I recommend to bump the timeout values for now, and see if it helps with the issue. If not, we may invest into another round of investigation.

(hopefully) fixes #57929

ghost · 2021-08-25T18:44:17Z

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

Issue Details

Long story short:
I have spent several hours trying to get a test run on SLES in order to repro #57929, no success so far, and it may take days to make progress, since I'm unfamiliar with SLES.

I recommend to bump the timeout values for now, and see if it helps with the issue. If not, we may invest into another round of investigation.

(hopefully) fixes #57929

Author:	antonfirsov
Assignees:	-
Labels:	`area-System.Net.Sockets`
Milestone:	-

antonfirsov · 2021-08-25T18:50:10Z

/azp run runtime-libraries-coreclr outerloop

azure-pipelines · 2021-08-25T18:50:24Z

Azure Pipelines successfully started running 1 pipeline(s).

wfurt · 2021-08-25T19:07:38Z

src/libraries/System.Net.Sockets/tests/FunctionalTests/DnsEndPointTest.cs

@@ -272,7 +272,7 @@ public void Socket_ConnectAsyncDnsEndPoint_HostNotFound()
                bool willRaiseEvent = sock.ConnectAsync(args);
                if (willRaiseEvent)
                {
-                    Assert.True(complete.WaitOne(TestSettings.PassingTestTimeout), "Timed out while waiting for connection");
+                    Assert.True(complete.WaitOne(TimeSpan.FromSeconds(30)), "Timed out while waiting for connection");


I would do it as TestSettings.PassingTestTimeout * 3 e.g. factor of baseline instead of hardcoded value.
(or add new constant)

I can rename the 10 sec PassingTestTimeout to PassingTestShortTimeout, and define another constant PassingTestLongTimeout = 30 sec ?

But maybe better to do it in a separate PR, to keep the changes in this one minimal? (It's about to be backported.)

It might be actually better to do the rename in the release/* branches too to keep the code in sync, avoiding conflicts in future PR-s. I'm undecided.

wfurt · 2021-08-25T19:10:59Z

Did you get VM from the Helix gallery @antonfirsov ?
Can you check content of /etc/resolv.conf and /etc/nsswitch.conf?
AFAIK SLES should be using normal glibc resolver....

antonfirsov · 2021-08-26T15:48:53Z

@wfurt also reacting to #57929 (comment):

Note the most problematic tests (Socket_ConnectAsyncDnsEndPoint_HostNotFound and Socket_StaticConnectAsync_HostNotFound) are negative tests which check the error code resolving notahostname.invalid.corp.microsoft.com. There is a sync variant of those tests which never fails:

runtime/src/libraries/System.Net.Sockets/tests/FunctionalTests/DnsEndPointTest.cs

Lines 56 to 69 in d9a1302

    
                   [OuterLoop] 
        
                   [Fact] 
        
                   public void Socket_ConnectDnsEndPoint_Failure() 
        
                   { 
        
                       using (Socket sock = new Socket(AddressFamily.InterNetwork, SocketType.Stream, ProtocolType.Tcp)) 
        
                       { 
        
                           SocketException ex = Assert.ThrowsAny<SocketException>(() => 
        
                           { 
        
                               sock.Connect(new DnsEndPoint(Configuration.Sockets.InvalidHost, UnusedPort)); 
        
                           }); 
        
                           SocketError errorCode = ex.SocketErrorCode; 
        
                           Assert.True((errorCode == SocketError.HostNotFound) || (errorCode == SocketError.NoData), 
        
                               $"SocketErrorCode: {errorCode}");

I believe this means that the OS level name resolution works fine, and the problem is more likely some sort of threadpool execution timeout, since async name resolution is actually is async-over-sync on Unix.

I don't think this is CPU intensive test.

It isn't but the rest of the socket test suite is using threadpool threads in parallel quite heavily, and we've seen timeouts because of that. The only difference between release/* and main queues is CPU, which can explain different thread pool behavior. Of course, this is only speculation, but I would rather merge this change on trial and error basis, than spend days figuring out SLES package management. If the the failures disappear, or get reduced significantly after this change, that would be a sign that there is no serious bug, if not, that would mean that we actually have an async hang, which would justify the investigation.

wfurt · 2021-08-26T15:59:08Z

Do we have any stats how long does it take to run the sync test comparing to other platforms?
I'm generally OK making the timeout longer and waiting if that makes difference.

antonfirsov · 2021-08-26T16:05:57Z

I did some microbenchmarks for the failing connect, numbers were something like:

Windows (surface laptop): 280 ms, Ubuntu 100ms, SLES: 5ms. So weirdly SLES is actually the fastest (at least on the Helix DTL machine I got). I think if there is a problem it's not with DNS but rather with the threadpool or our async-over-sync resolution code. (Or the way it works with DnsConnectAsync.)

wfurt · 2021-08-26T16:12:06Z

Would it make sense to move it to the non-parallel bucket?

antonfirsov · 2021-08-26T16:20:26Z

Would it make sense to move it to the non-parallel bucket?

I think it would make the error go away with higher chance, but also hide potential issues with the async-over-sync code, plus the usual penalty in test run time on all platforms, so I prefer not to do it in this particular case.

antonfirsov · 2021-08-31T13:57:47Z

Reacting to #58129 (comment), I pushed a change that renames existing TestSettings.PassingTestTimeout to PassingTestShortTimeout and introducing PassingTestLongTimeout = 30sec. This is a necessary change to improve the maintainability for the code on master, backporting the entire change to 6.0 will make it easier to adapt future test improvements.

wfurt · 2021-08-31T19:28:50Z

src/libraries/Common/tests/System/Net/Sockets/TestSettings.cs

@@ -8,9 +8,10 @@ namespace System.Net.Sockets.Tests
    public static class TestSettings
    {
        // Timeout values in milliseconds.
-        public const int PassingTestTimeout = 10000;


Can you keep this untouched to be consistent with other tests? e.g. PassingTestTimeout is normal/default timeout. If we need anything different for come case we would make it with specific name - like PassingTestLongTimeout (that part looks ok to me)

Reverted this renaming to reduce the diff size.

I think more verbosity in the names wouldn't hurt here. 10 sec is quite a short time in comparison to Http.Tests's default PassingTestTimeout=30sec. We use hardcoded 30 seconds at a bunch of places in socket tests, which we will eventually replace with PassingTestLongTimeout, meaning that the "default" PassingTestTimeout=10sec will become much less common.

karelz · 2021-09-01T09:22:16Z

Test run reported networking test failures 4x this specific test:

System.Net.Http.Functional.Tests.SocketsHttpHandler_HttpClientHandler_ServerCertificates_Test.UseCallback_ValidCertificate_ExpectedValuesDuringCallback(remoteServer: (BaseUri: https://corefx-net-http11.azurewebsites.net/, HttpVersion: 1.1), url: https://corefx-net-http11.azurewebsites.net/Echo.ashx, checkRevocation: True) [FAIL]

      System.Net.Http.HttpRequestException : The SSL connection could not be established, see inner exception.
      ---- Expected None, got RemoteCertificateChainErrors with chain status RevocationStatusUnknown, OfflineRevocation
      Expected: True
      Actual:   False
      Stack Trace:
        /_/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/ConnectHelper.cs(92,0): at System.Net.Http.ConnectHelper.EstablishSslConnectionAsync(SslClientAuthenticationOptions sslOptions, HttpRequestMessage request, Boolean async, Stream stream, CancellationToken cancellationToken)
        /_/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpConnectionPool.cs(1364,0): at System.Net.Http.HttpConnectionPool.ConnectAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
        /_/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpConnectionPool.cs(1430,0): at System.Net.Http.HttpConnectionPool.CreateHttp11ConnectionAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
        /_/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpConnectionPool.cs(454,0): at System.Net.Http.HttpConnectionPool.AddHttp11ConnectionAsync(HttpRequestMessage request)
        /_/src/libraries/Common/src/System/Threading/Tasks/TaskCompletionSourceWithCancellation.cs(21,0): at System.Threading.Tasks.TaskCompletionSourceWithCancellation`1.WaitWithCancellationAsync(CancellationToken cancellationToken)
        /_/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpConnectionPool.cs(548,0): at System.Net.Http.HttpConnectionPool.GetHttp11ConnectionAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
        /_/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpConnectionPool.cs(988,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/Common/tests/System/Net/Http/HttpClientHandlerTestBase.cs(119,0): at System.Net.Http.Functional.Tests.HttpClientHandlerTestBase.VersionCheckerHttpHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
        /_/src/libraries/System.Net.Http/src/System/Net/Http/HttpClient.cs(527,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/Common/tests/System/Net/Http/HttpClientHandlerTest.ServerCertificates.cs(173,0): at System.Net.Http.Functional.Tests.HttpClientHandler_ServerCertificates_Test.UseCallback_ValidCertificate_ExpectedValuesDuringCallback(RemoteServer remoteServer, Uri url, Boolean checkRevocation)
        --- End of stack trace from previous location ---
        ----- Inner Stack Trace -----
        /_/src/libraries/Common/tests/System/Net/Http/HttpClientHandlerTest.ServerCertificates.cs(159,0): at System.Net.Http.Functional.Tests.HttpClientHandler_ServerCertificates_Test.<>c__DisplayClass14_1.<UseCallback_ValidCertificate_ExpectedValuesDuringCallback>b__0(HttpRequestMessage request, X509Certificate2 cert, X509Chain chain, SslPolicyErrors errors)
        /_/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/ConnectHelper.cs(49,0): at System.Net.Http.ConnectHelper.<>c__DisplayClass1_0.<SetUpRemoteCertificateValidationCallback>b__0(Object sender, X509Certificate certificate, X509Chain chain, SslPolicyErrors sslPolicyErrors)
        /_/src/libraries/System.Net.Security/src/System/Net/Security/SecureChannel.cs(998,0): at System.Net.Security.SecureChannel.VerifyRemoteCertificate(RemoteCertificateValidationCallback remoteCertValidationCallback, SslCertificateTrust trust, ProtocolToken& alertToken, SslPolicyErrors& sslPolicyErrors, X509ChainStatusFlags& chainStatus)
        /_/src/libraries/System.Net.Security/src/System/Net/Security/SslStream.Implementation.cs(639,0): at System.Net.Security.SslStream.CompleteHandshake(ProtocolToken& alertToken, SslPolicyErrors& sslPolicyErrors, X509ChainStatusFlags& chainStatus)
        /_/src/libraries/System.Net.Security/src/System/Net/Security/SslStream.Implementation.cs(652,0): at System.Net.Security.SslStream.CompleteHandshake(SslAuthenticationOptions sslAuthenticationOptions)
        /_/src/libraries/System.Net.Security/src/System/Net/Security/SslStream.Implementation.cs(435,0): at System.Net.Security.SslStream.ForceAuthenticationAsync[TIOAdapter](TIOAdapter adapter, Boolean receiveFirst, Byte[] reAuthenticationData, Boolean isApm)
        /_/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/ConnectHelper.cs(68,0): at System.Net.Http.ConnectHelper.EstablishSslConnectionAsync(SslClientAuthenticationOptions sslOptions, HttpRequestMessage request, Boolean async, Stream stream, CancellationToken cancellationToken)

That may be just some networking hiccup I guess ... cc @wfurt

Rerunning the failed legs.

wfurt

LGTM

karelz · 2021-09-02T15:08:44Z

Test failures:

BeginReceiveFromV4BoundToSpecificV4_Success timeout - likely unrelated - @antonfirsov can you please confirm?

    System.Net.Sockets.Tests.DualModeConnectionlessBeginReceiveFrom.BeginReceiveFromV4BoundToSpecificV4_Success [FAIL]
      System.TimeoutException : The operation has timed out.
      Stack Trace:
        /_/src/libraries/System.Net.Sockets/tests/FunctionalTests/DualModeSocketTest.cs(1612,0): at System.Net.Sockets.Tests.DualModeConnectionlessBeginReceiveFrom.BeginReceiveFrom_Helper(IPAddress listenOn, IPAddress connectTo, Boolean expectedToTimeout)
        /_/src/libraries/System.Net.Sockets/tests/FunctionalTests/DualModeSocketTest.cs(1525,0): at System.Net.Sockets.Tests.DualModeConnectionlessBeginReceiveFrom.BeginReceiveFromV4BoundToSpecificV4_Success()

Azure storage outage? -- .packages/microsoft.dotnet.helix.sdk/6.0.0-beta.21427.6/tools/Microsoft.DotNet.Helix.Sdk.MonoQueue.targets(55,5): error : (NETCORE_ENGINEERING_TELEMETRY=Helix) StorageException: nodename nor servname provided, or not known (helixde8s23ayyeko0k025g8.blob.core.windows.net:443) (logs)
2x System.Runtime.Tests killed - unrelated failures - Debian.11 and Debian.10

/root/helix/work/workitem /root/helix/work/workitem
  Discovering: System.Runtime.Tests (method display = ClassAndMethod, method display options = None)
  Discovered:  System.Runtime.Tests (found 28 of 6264 test cases)
  Starting:    System.Runtime.Tests (parallel test collections = on, max threads = 2)
./RunTests.sh: line 162:    24 Killed

runtime-staging - unrelated Helix hiccups

Rerunning tests.

antonfirsov · 2021-09-02T15:44:57Z

Yes, BeginReceiveFromV4BoundToSpecificV4_Success is unrelated.

karelz · 2021-09-03T10:23:40Z

Same System.Runtime.Tests unrelated failures on Debian.10 and Debian.11 - tracked by #58616:

  Discovering: System.Runtime.Tests (method display = ClassAndMethod, method display options = None)
  Discovered:  System.Runtime.Tests (found 28 of 6264 test cases)
  Starting:    System.Runtime.Tests (parallel test collections = on, max threads = 2)
./RunTests.sh: line 162:    24 Killed

karelz · 2021-09-03T10:25:13Z

/backport to release/6.0

github-actions · 2021-09-03T10:25:27Z

Started backporting to release/6.0: https://github.com/dotnet/runtime/actions/runs/1197645068

antonfirsov added 2 commits August 25, 2021 20:32

Increase some of the DnsEndPointTest timeouts

eeb0b21

remove accidental comment

d9a1302

dotnet-issue-labeler bot added the area-System.Net.Sockets label Aug 25, 2021

antonfirsov changed the title ~~Sockets/dns connect timeouts~~ Increase some of the DnsEndPointTest timeouts Aug 25, 2021

wfurt reviewed Aug 25, 2021

View reviewed changes

PassingTestTimeout -> PassingTestShortTimeout & PassingTestLongTimeout

75caacf

This comment has been minimized.

Sign in to view

karelz added this to the 7.0.0 milestone Aug 31, 2021

wfurt reviewed Aug 31, 2021

View reviewed changes

antonfirsov added 4 commits September 1, 2021 15:08

undo renaming PassingTestTimeout

4daff4b

remove whitespaces VS inserted

918b59f

whitespaces

b342613

whitespaces

37969d4

This comment has been minimized.

Sign in to view

wfurt approved these changes Sep 1, 2021

View reviewed changes

karelz mentioned this pull request Sep 3, 2021

System.Runtime.Tests Outerloop "killed" on Debian.10 and Debian.11 #58616

Open

karelz merged commit 566b3eb into dotnet:main Sep 3, 2021

github-actions bot mentioned this pull request Sep 3, 2021

[release/6.0] Increase some of the DnsEndPointTest timeouts #58617

Merged

karelz mentioned this pull request Sep 8, 2021

Tests time out: System.Net.Sockets.Tests.DnsEndPointTest - mostly on SLES.15 in release/6.0 branches #57929

Closed

ghost locked as resolved and limited conversation to collaborators Oct 3, 2021

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Increase some of the DnsEndPointTest timeouts #58129

Increase some of the DnsEndPointTest timeouts #58129

antonfirsov commented Aug 25, 2021

ghost commented Aug 25, 2021

antonfirsov commented Aug 25, 2021

azure-pipelines bot commented Aug 25, 2021

wfurt Aug 25, 2021

antonfirsov Aug 26, 2021 •

edited

Loading

antonfirsov Aug 26, 2021

wfurt commented Aug 25, 2021

antonfirsov commented Aug 26, 2021 •

edited

Loading

wfurt commented Aug 26, 2021

antonfirsov commented Aug 26, 2021 •

edited

Loading

wfurt commented Aug 26, 2021

antonfirsov commented Aug 26, 2021

antonfirsov commented Aug 31, 2021

This comment has been minimized.

This comment has been minimized.

wfurt Aug 31, 2021

antonfirsov Sep 1, 2021 •

edited

Loading

karelz commented Sep 1, 2021

This comment has been minimized.

This comment has been minimized.

wfurt left a comment

karelz commented Sep 2, 2021 •

edited

Loading

antonfirsov commented Sep 2, 2021

karelz commented Sep 3, 2021

karelz commented Sep 3, 2021

github-actions bot commented Sep 3, 2021

Increase some of the DnsEndPointTest timeouts #58129

Increase some of the DnsEndPointTest timeouts #58129

Conversation

antonfirsov commented Aug 25, 2021

ghost commented Aug 25, 2021

antonfirsov commented Aug 25, 2021

azure-pipelines bot commented Aug 25, 2021

wfurt Aug 25, 2021

Choose a reason for hiding this comment

antonfirsov Aug 26, 2021 • edited Loading

Choose a reason for hiding this comment

antonfirsov Aug 26, 2021

Choose a reason for hiding this comment

wfurt commented Aug 25, 2021

antonfirsov commented Aug 26, 2021 • edited Loading

wfurt commented Aug 26, 2021

antonfirsov commented Aug 26, 2021 • edited Loading

wfurt commented Aug 26, 2021

antonfirsov commented Aug 26, 2021

antonfirsov commented Aug 31, 2021

This comment has been minimized.

This comment has been minimized.

wfurt Aug 31, 2021

Choose a reason for hiding this comment

antonfirsov Sep 1, 2021 • edited Loading

Choose a reason for hiding this comment

karelz commented Sep 1, 2021

This comment has been minimized.

This comment has been minimized.

wfurt left a comment

Choose a reason for hiding this comment

karelz commented Sep 2, 2021 • edited Loading

antonfirsov commented Sep 2, 2021

karelz commented Sep 3, 2021

karelz commented Sep 3, 2021

github-actions bot commented Sep 3, 2021

antonfirsov Aug 26, 2021 •

edited

Loading

antonfirsov commented Aug 26, 2021 •

edited

Loading

antonfirsov commented Aug 26, 2021 •

edited

Loading

antonfirsov Sep 1, 2021 •

edited

Loading

karelz commented Sep 2, 2021 •

edited

Loading