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

NonDisposedSocket_SafeHandlesCollected timed out after 900 seconds and was killed #50068

Closed
eerhardt opened this issue Mar 23, 2021 · 5 comments · Fixed by #50279
Closed

NonDisposedSocket_SafeHandlesCollected timed out after 900 seconds and was killed #50068

eerhardt opened this issue Mar 23, 2021 · 5 comments · Fixed by #50279
Labels
area-System.Net.Sockets blocking-clean-ci Blocking PR or rolling runs of 'runtime' or 'runtime-extra-platforms'
Milestone
6.0.0

Comments

@eerhardt
Copy link
Member

Logs at

https://dev.azure.com/dnceng/public/_build/results?buildId=1050964&view=logs&j=71afe768-e493-597c-228c-037834193aeb&t=fe87d331-02fa-5ca6-e382-69b0a11bb0f6&l=153

https://helixre8s23ayyeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-pull-49786-merge-3cc1bbe3140144248c/System.Net.Sockets.Tests/console.b9794aa3.log?sv=2019-07-07&se=2021-04-11T19%3A25%3A54Z&sr=c&sp=rl&sig=c1Q2MBo%2Ft8wLihxAKfEk%2Ff6POoI%2BSq1o3hLVtl0pu0I%3D

+ ./RunTests.sh --runtime-path /root/helix/work/correlation
----- start Mon 22 Mar 2021 07:39:28 PM UTC =============== To repro directly: =====================================================
pushd .
/root/helix/work/correlation/dotnet exec --runtimeconfig System.Net.Sockets.Tests.runtimeconfig.json --depsfile System.Net.Sockets.Tests.deps.json xunit.console.dll System.Net.Sockets.Tests.dll -xml testResults.xml -nologo -nocolor -notrait category=IgnoreForCI -notrait category=OuterLoop -notrait category=failing 
popd
===========================================================================================================
/root/helix/work/workitem /root/helix/work/workitem
  Discovering: System.Net.Sockets.Tests (method display = ClassAndMethod, method display options = None)
  Discovered:  System.Net.Sockets.Tests (found 1128 of 1583 test cases)
  Starting:    System.Net.Sockets.Tests (parallel test collections = on, max threads = 2)
    System.Net.Sockets.Tests.CreateSocket.Ctor_Raw_Supported_Success [SKIP]
      Condition(s) not met: "SupportsRawSockets"
   System.Net.Sockets.Tests: [Long Running Test] 'System.Net.Sockets.Tests.DisposedSocket.NonDisposedSocket_SafeHandlesCollected', Elapsed: 00:02:21
   System.Net.Sockets.Tests: [Long Running Test] 'System.Net.Sockets.Tests.DisposedSocket.NonDisposedSocket_SafeHandlesCollected', Elapsed: 00:04:21
   System.Net.Sockets.Tests: [Long Running Test] 'System.Net.Sockets.Tests.DisposedSocket.NonDisposedSocket_SafeHandlesCollected', Elapsed: 00:06:21
   System.Net.Sockets.Tests: [Long Running Test] 'System.Net.Sockets.Tests.DisposedSocket.NonDisposedSocket_SafeHandlesCollected', Elapsed: 00:08:21
   System.Net.Sockets.Tests: [Long Running Test] 'System.Net.Sockets.Tests.DisposedSocket.NonDisposedSocket_SafeHandlesCollected', Elapsed: 00:10:21
   System.Net.Sockets.Tests: [Long Running Test] 'System.Net.Sockets.Tests.DisposedSocket.NonDisposedSocket_SafeHandlesCollected', Elapsed: 00:12:21
   System.Net.Sockets.Tests: [Long Running Test] 'System.Net.Sockets.Tests.DisposedSocket.NonDisposedSocket_SafeHandlesCollected', Elapsed: 00:14:21

...
[EXECUTION TIMED OUT]
Exit Code:-3Executor timed out after 900 seconds and was killed
@eerhardt eerhardt added area-System.Net.Sockets blocking-clean-ci Blocking PR or rolling runs of 'runtime' or 'runtime-extra-platforms' labels Mar 23, 2021
@ghost
Copy link

ghost commented Mar 23, 2021

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

Issue Details

Logs at

https://dev.azure.com/dnceng/public/_build/results?buildId=1050964&view=logs&j=71afe768-e493-597c-228c-037834193aeb&t=fe87d331-02fa-5ca6-e382-69b0a11bb0f6&l=153

https://helixre8s23ayyeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-pull-49786-merge-3cc1bbe3140144248c/System.Net.Sockets.Tests/console.b9794aa3.log?sv=2019-07-07&se=2021-04-11T19%3A25%3A54Z&sr=c&sp=rl&sig=c1Q2MBo%2Ft8wLihxAKfEk%2Ff6POoI%2BSq1o3hLVtl0pu0I%3D

+ ./RunTests.sh --runtime-path /root/helix/work/correlation
----- start Mon 22 Mar 2021 07:39:28 PM UTC =============== To repro directly: =====================================================
pushd .
/root/helix/work/correlation/dotnet exec --runtimeconfig System.Net.Sockets.Tests.runtimeconfig.json --depsfile System.Net.Sockets.Tests.deps.json xunit.console.dll System.Net.Sockets.Tests.dll -xml testResults.xml -nologo -nocolor -notrait category=IgnoreForCI -notrait category=OuterLoop -notrait category=failing 
popd
===========================================================================================================
/root/helix/work/workitem /root/helix/work/workitem
  Discovering: System.Net.Sockets.Tests (method display = ClassAndMethod, method display options = None)
  Discovered:  System.Net.Sockets.Tests (found 1128 of 1583 test cases)
  Starting:    System.Net.Sockets.Tests (parallel test collections = on, max threads = 2)
    System.Net.Sockets.Tests.CreateSocket.Ctor_Raw_Supported_Success [SKIP]
      Condition(s) not met: "SupportsRawSockets"
   System.Net.Sockets.Tests: [Long Running Test] 'System.Net.Sockets.Tests.DisposedSocket.NonDisposedSocket_SafeHandlesCollected', Elapsed: 00:02:21
   System.Net.Sockets.Tests: [Long Running Test] 'System.Net.Sockets.Tests.DisposedSocket.NonDisposedSocket_SafeHandlesCollected', Elapsed: 00:04:21
   System.Net.Sockets.Tests: [Long Running Test] 'System.Net.Sockets.Tests.DisposedSocket.NonDisposedSocket_SafeHandlesCollected', Elapsed: 00:06:21
   System.Net.Sockets.Tests: [Long Running Test] 'System.Net.Sockets.Tests.DisposedSocket.NonDisposedSocket_SafeHandlesCollected', Elapsed: 00:08:21
   System.Net.Sockets.Tests: [Long Running Test] 'System.Net.Sockets.Tests.DisposedSocket.NonDisposedSocket_SafeHandlesCollected', Elapsed: 00:10:21
   System.Net.Sockets.Tests: [Long Running Test] 'System.Net.Sockets.Tests.DisposedSocket.NonDisposedSocket_SafeHandlesCollected', Elapsed: 00:12:21
   System.Net.Sockets.Tests: [Long Running Test] 'System.Net.Sockets.Tests.DisposedSocket.NonDisposedSocket_SafeHandlesCollected', Elapsed: 00:14:21

...
[EXECUTION TIMED OUT]
Exit Code:-3Executor timed out after 900 seconds and was killed
Author: eerhardt
Assignees: -
Labels:

area-System.Net.Sockets, blocking-clean-ci
Milestone: -

@dotnet-issue-labeler dotnet-issue-labeler bot added the untriaged New issue has not been triaged by the area owner label Mar 23, 2021
@eerhardt eerhardt mentioned this issue Mar 23, 2021
Merged
@runfoapp runfoapp bot mentioned this issue Mar 23, 2021
Closed
@antonfirsov antonfirsov mentioned this issue Mar 23, 2021
Merged
@antonfirsov
Copy link
Member

We need stats about the frequency of this failure, so I raised #50104.

@antonfirsov
Copy link
Member

This test should no longer timeout but fail instead. I recommend to close the issue and open a new one in case we notice failures. I expect the occurrences to be extremely rare.

@eerhardt
Copy link
Member Author

Occurred again:

https://helixre8s23ayyeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-pull-50191-merge-3f4bc6670beb4900b2/System.Net.Sockets.Tests/console.743426e6.log?sv=2019-07-07&se=2021-04-13T19%3A32%3A12Z&sr=c&sp=rl&sig=vrh7N%2BYmSYqxFP%2FtTSdGaE5ljKcPTm1KA86MMVapOb4%3D

https://dev.azure.com/dnceng/public/_build/results?buildId=1054609&view=logs&j=71afe768-e493-597c-228c-037834193aeb&t=fe87d331-02fa-5ca6-e382-69b0a11bb0f6&l=151

+ ./RunTests.sh --runtime-path /root/helix/work/correlation
----- start Wed 24 Mar 2021 07:52:01 PM UTC =============== To repro directly: =====================================================
pushd .
/root/helix/work/correlation/dotnet exec --runtimeconfig System.Net.Sockets.Tests.runtimeconfig.json --depsfile System.Net.Sockets.Tests.deps.json xunit.console.dll System.Net.Sockets.Tests.dll -xml testResults.xml -nologo -nocolor -notrait category=IgnoreForCI -notrait category=OuterLoop -notrait category=failing 
popd
===========================================================================================================
/root/helix/work/workitem /root/helix/work/workitem
  Discovering: System.Net.Sockets.Tests (method display = ClassAndMethod, method display options = None)
  Discovered:  System.Net.Sockets.Tests (found 1128 of 1583 test cases)
  Starting:    System.Net.Sockets.Tests (parallel test collections = on, max threads = 2)
    System.Net.Sockets.Tests.CreateSocket.Ctor_Raw_Supported_Success [SKIP]
      Condition(s) not met: "SupportsRawSockets"
    System.Net.Sockets.Tests.DisposedSocket.NonDisposedSocket_SafeHandlesCollected(clientAsync: True) [FAIL]
      System.TimeoutException : The operation has timed out.
      Stack Trace:
        /_/src/libraries/System.Net.Sockets/tests/FunctionalTests/DisposedSocketTests.cs(756,0): at System.Net.Sockets.Tests.DisposedSocket.NonDisposedSocket_SafeHandlesCollected(Boolean clientAsync)
        --- End of stack trace from previous location ---
  Finished:    System.Net.Sockets.Tests
=== TEST EXECUTION SUMMARY ===
   System.Net.Sockets.Tests  Total: 1765, Errors: 0, Failed: 1, Skipped: 1, Time: 15.665s
/root/helix/work/workitem
----- end Wed 24 Mar 2021 07:52:18 PM UTC ----- exit code 1 ----------------------------------------------------------

@eerhardt eerhardt mentioned this issue Mar 25, 2021
Merged
@antonfirsov
Copy link
Member

According to Kusto data, this is a regular failure that doesn't depend on OS. Line 756 belongs to CreateHandlesAsync() so the hang is not in the finalizer. Always happens with clientAsync : true.

If connecting 100 socket pairs asynchronously can lead to hangs, that might be a sign a product bug.

@antonfirsov antonfirsov mentioned this issue Mar 26, 2021
Merged
@ghost ghost added the in-pr There is an active PR which will close this issue when it is merged label Mar 26, 2021
@ghost ghost removed the in-pr There is an active PR which will close this issue when it is merged label Mar 26, 2021
@ghost ghost locked as resolved and limited conversation to collaborators Apr 25, 2021
@karelz karelz added this to the 6.0.0 milestone May 20, 2021
@karelz karelz removed the untriaged New issue has not been triaged by the area owner label Oct 20, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
area-System.Net.Sockets blocking-clean-ci Blocking PR or rolling runs of 'runtime' or 'runtime-extra-platforms'
Projects
None yet
Milestone
6.0.0
Development

Successfully merging a pull request may close this issue.

Move NonDisposedSocket_SafeHandlesCollected to a non-parallel test collection antonfirsov/runtime
3 participants
@karelz @antonfirsov @eerhardt