System.Net.Sockets.Tests.DisposedSocket.NonDisposedSocket_SafeHandlesCollected test failures on Linux #35846

safern · 2020-05-05T16:46:52Z

System.Net.Sockets.Tests.DisposedSocket.NonDisposedSocket_SafeHandlesCollected

Console Log Summary

Builds

Build	Pull Request	Test Failure Count
#629997	Rolling	1
#630210	#35800	5
#630328	Rolling	2
#630702	Rolling	1
#631423	Rolling	2
#631540	Rolling	1
#631623	Rolling	2

Configurations

netcoreapp5.0-Linux-Debug-x64-CoreCLR_release-(Alpine.311.Amd64.Open)[email protected]/dotnet-buildtools/prereqs:alpine-3.11-helix-bfcd90a-20200123191053
netcoreapp5.0-Linux-Debug-x64-CoreCLR_release-Centos.7.Amd64.Open
netcoreapp5.0-Linux-Debug-x64-CoreCLR_release-Debian.9.Amd64.Open
netcoreapp5.0-Linux-Debug-x64-CoreCLR_release-RedHat.7.Amd64.Open
netcoreapp5.0-Linux-Debug-x64-CoreCLR_release-Ubuntu.1604.Amd64.Open
netcoreapp5.0-Linux-Release-x64-CoreCLR_release-(Alpine.311.Amd64.Open)[email protected]/dotnet-buildtools/prereqs:alpine-3.11-helix-bfcd90a-20200123191053
netcoreapp5.0-Linux-Release-x64-CoreCLR_release-(Debian.10.Amd64.Open)[email protected]/dotnet-buildtools/prereqs:debian-10-helix-amd64-bfcd90a-20200121150006
netcoreapp5.0-Linux-Release-x64-CoreCLR_release-(Fedora.29.Amd64.Open)[email protected]/dotnet-buildtools/prereqs:fedora-29-helix-a12566d-20191210224553
netcoreapp5.0-Linux-Release-x64-CoreCLR_release-(Fedora.30.Amd64.Open)[email protected]/dotnet-buildtools/prereqs:fedora-30-helix-4f8cef7-20200121150022
netcoreapp5.0-Linux-Release-x64-CoreCLR_release-Ubuntu.1804.Amd64.Open

Helix Logs

Build	Pull Request	Console	Test Results	Run Client
#629997	Rolling	console.log	testResults.xml	run_client.py
#630210	#35800	console.log	testResults.xml	run_client.py
#630210	#35800	console.log	testResults.xml	run_client.py
#630210	#35800	console.log	testResults.xml	run_client.py
#630210	#35800	console.log	testResults.xml	run_client.py
#630210	#35800	console.log	testResults.xml	run_client.py
#630328	Rolling	console.log	testResults.xml	run_client.py
#630328	Rolling	console.log	testResults.xml	run_client.py
#630702	Rolling	console.log	testResults.xml	run_client.py
#631423	Rolling	console.log	testResults.xml	run_client.py
#631423	Rolling	console.log	testResults.xml	run_client.py
#631540	Rolling	console.log	testResults.xml	run_client.py
#631623	Rolling	console.log	testResults.xml	run_client.py
#631623	Rolling	console.log	testResults.xml	run_client.py

System.Net.Sockets.Tests.DisposedSocket.NonDisposedSocket_SafeHandlesCollected(clientAsync: True) [FAIL]
      System.AggregateException : One or more errors occurred. (Assert.Equal() Failure
      Expected: 0
      Actual:   11) (Assert.Equal() Failure
      Expected: 0
      Actual:   1) (Assert.Equal() Failure
      Expected: 0
      Actual:   1) (Assert.Equal() Failure
      Expected: 0
      Actual:   1) (Assert.Equal() Failure
      Expected: 0
      Actual:   1)
      ---- Assert.Equal() Failure
      Expected: 0
      Actual:   11
      ---- Assert.Equal() Failure
      Expected: 0
      Actual:   1
      ---- Assert.Equal() Failure
      Expected: 0
      Actual:   1
      ---- Assert.Equal() Failure
      Expected: 0
      Actual:   1
      ---- Assert.Equal() Failure
      Expected: 0
      Actual:   1
      Stack Trace:
        /_/src/libraries/Common/tests/TestUtilities/System/RetryHelper.cs(45,0): at System.RetryHelper.Execute(Action test, Int32 maxAttempts, Func`2 backoffFunc)
        /_/src/libraries/System.Net.Sockets/tests/FunctionalTests/DisposedSocketTests.cs(757,0): at System.Net.Sockets.Tests.DisposedSocket.NonDisposedSocket_SafeHandlesCollected(Boolean clientAsync)

cc: @dotnet/runtime-infrastructure @stephentoub @wfurt

The text was updated successfully, but these errors were encountered:

ghost · 2020-05-05T16:46:56Z

Tagging subscribers to this area: @dotnet/ncl
Notify danmosemsft if you want to be subscribed.

safern · 2020-05-05T16:47:14Z

Will put up a PR to disable the test on the meantime.

wfurt · 2020-05-05T16:48:44Z

cc @alnikola

karelz · 2020-05-07T01:20:43Z

@antonfirsov may be interested to pick it up ...

kouvel · 2020-05-07T07:15:43Z

The test failure in rolling builds seem to all be in release builds. Seems to have started after my change #35330, but at the time when I tested it there were no failures in release builds, not sure why it is reproing now and not before. I took a brief look.

The test:

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

Line 755 in c2b1018

public async Task NonDisposedSocket_SafeHandlesCollected(bool clientAsync)

Seems to be verifying that a non-disposed socket that is not referenced gets finalized in reasonable time. The issue appears to be in this section of code: 8157271#diff-f7e3fa1efc2509a247819f786ac6e532R353-R360 (scroll down to see highlighted portion), ev is a 16-byte local and contains a reference to SocketAsyncContext (which in turn references Socket), and the context inside ev appears to be stored in a stack location (rbp - 0x68) and appears to be keeping the socket alive on the potentially long-running epoll thread.

GCRoot:

Thread 11f5:
    00007FFF1DFFA8E0 00007FFF7DC84AA7 System.Net.Sockets.SocketAsyncEngine.EventLoop() [~/runtime/src/libraries/System.Net.Sockets/src/System/Net/Sockets/SocketAsyncEngine.Unix.cs @ 336]
        rbp-68: 00007fff1dffa8f8
            ->  00007FFF5025D480 System.Net.Sockets.SocketAsyncContext

Source line 336 corresponds to this: 8157271#diff-f7e3fa1efc2509a247819f786ac6e532R326 (line numbers from output above and below is a bit off from that commit), where I wouldn't expect ev to be kept alive in release builds.

SOS U with GC info:

Normal JIT generated code
System.Net.Sockets.SocketAsyncEngine.EventLoop()
ilAddr is 00007FFF7C3FDC98 pImport is 000000000302FCA0
Begin 00007FFF7DC84A50, size 244

~/runtime/src/libraries/System.Net.Sockets/src/System/Net/Sockets/SocketAsyncEngine.Unix.cs @ 329:
Prolog size: 0
Security object: <none>
GS cookie: <none>
PSPSym: initial.sp+0
Generics inst context: <none>
PSP slot: caller.sp+0
GenericInst slot: <none>
Varargs: 0
Frame pointer: rbp
Wants Report Only Leaf: 1
Size of parameter area: 0
Return Kind: Scalar
Code size: 244
Untracked: +rbp-50 +rbp-68
00007fff7dc84a50 55                   push    rbp
00007fff7dc84a51 4157                 push    r15
00007fff7dc84a53 4156                 push    r14
00007fff7dc84a55 4155                 push    r13
00007fff7dc84a57 4154                 push    r12
00007fff7dc84a59 53                   push    rbx
00007fff7dc84a5a 4883ec58             sub     rsp, 0x58
00007fff7dc84a5e 488dac2480000000     lea     rbp, [rsp + 0x80]
00007fff7dc84a66 33c0                 xor     eax, eax
00007fff7dc84a68 48894598             mov     qword ptr [rbp - 0x68], rax
00007fff7dc84a6c c4413857c0           vxorps  xmm8, xmm8, xmm8
00007fff7dc84a71 c5797f45a0           vmovdqa xmmword ptr [rbp - 0x60], xmm8
00007fff7dc84a76 488945b0             mov     qword ptr [rbp - 0x50], rax
00007fff7dc84a7a 48896580             mov     qword ptr [rbp - 0x80], rsp
00007fff7dc84a7e 488bdf               mov     rbx, rdi
00000031 interruptible
00000031 +rbx
00007fff7dc84a81 4533f6               xor     r14d, r14d

~/runtime/src/libraries/System.Net.Sockets/src/System/Net/Sockets/SocketAsyncEngine.Unix.cs @ 330:
00007fff7dc84a84 4c8b7b20             mov     r15, qword ptr [rbx + 0x20]

~/runtime/src/libraries/System.Net.Sockets/src/System/Net/Sockets/SocketAsyncEngine.Unix.cs @ 331:
00007fff7dc84a88 4c8b6308             mov     r12, qword ptr [rbx + 0x8]

~/runtime/src/libraries/System.Net.Sockets/src/System/Net/Sockets/SocketAsyncEngine.Unix.cs @ 332:
0000003c +r12
00007fff7dc84a8c 4c8b6b10             mov     r13, qword ptr [rbx + 0x10]

~/runtime/src/libraries/System.Net.Sockets/src/System/Net/Sockets/SocketAsyncEngine.Unix.cs @ 335:
00000040 +r13
00007fff7dc84a90 c745d000040000       mov     dword ptr [rbp - 0x30], 0x400

~/runtime/src/libraries/System.Net.Sockets/src/System/Net/Sockets/SocketAsyncEngine.Unix.cs @ 336:
00007fff7dc84a97 488b7b18             mov     rdi, qword ptr [rbx + 0x18]
00007fff7dc84a9b 488d55d0             lea     rdx, [rbp - 0x30]
00007fff7dc84a9f 498bf7               mov     rsi, r15
00007fff7dc84aa2 e889befeff           call    0x7fff7dc70930 (Interop+Sys.WaitForSocketEvents(IntPtr, SocketEvent*, Int32*), mdToken: 0000000006000037)
>>> 00007fff7dc84aa7 8bd0                 mov     edx, eax

~/runtime/src/libraries/System.Net.Sockets/src/System/Net/Sockets/SocketAsyncEngine.Unix.cs @ 337:
00007fff7dc84aa9 8955cc               mov     dword ptr [rbp - 0x34], edx
00007fff7dc84aac 85d2                 test    edx, edx
00007fff7dc84aae 755f                 jne     0x7fff7dc84b0f

~/runtime/src/libraries/System.Net.Sockets/src/System/Net/Sockets/SocketAsyncEngine.Unix.cs @ 345:
00007fff7dc84ab0 33d2                 xor     edx, edx

~/runtime/src/libraries/System.Net.Sockets/src/System/Net/Sockets/SocketAsyncEngine.Unix.cs @ 346:
00007fff7dc84ab2 33c0                 xor     eax, eax
00007fff7dc84ab4 837dd000             cmp     dword ptr [rbp - 0x30], 0x0
00007fff7dc84ab8 7e22                 jle     0x7fff7dc84adc

~/runtime/src/libraries/System.Net.Sockets/src/System/Net/Sockets/SocketAsyncEngine.Unix.cs @ 348:
00007fff7dc84aba 4863f8               movsxd  rdi, eax
00007fff7dc84abd 48c1e704             shl     rdi, 0x4
00007fff7dc84ac1 498b0c3f             mov     rcx, qword ptr [r15 + rdi]
00007fff7dc84ac5 4883f9ff             cmp     rcx, -0x1
00007fff7dc84ac9 0f857f000000         jne     0x7fff7dc84b4e

~/runtime/src/libraries/System.Net.Sockets/src/System/Net/Sockets/SocketAsyncEngine.Unix.cs @ 351:
00007fff7dc84acf 41be01000000         mov     r14d, 0x1

~/runtime/src/libraries/System.Net.Sockets/src/System/Net/Sockets/SocketAsyncEngine.Unix.cs @ 346:
00007fff7dc84ad5 ffc0                 inc     eax
00007fff7dc84ad7 3b45d0               cmp     eax, dword ptr [rbp - 0x30]
00007fff7dc84ada 7cde                 jl      0x7fff7dc84aba

~/runtime/src/libraries/System.Net.Sockets/src/System/Net/Sockets/SocketAsyncEngine.Unix.cs @ 381:
00007fff7dc84adc 85d2                 test    edx, edx
00007fff7dc84ade 741d                 je      0x7fff7dc84afd

~/runtime/src/libraries/System.Net.Sockets/src/System/Net/Sockets/SocketAsyncEngine.Unix.cs @ 383:
00007fff7dc84ae0 488d7b40             lea     rdi, [rbx + 0x40]
00000094 +rdi(interior)
00007fff7dc84ae4 be01000000           mov     esi, 0x1
00007fff7dc84ae9 33c0                 xor     eax, eax
00007fff7dc84aeb f0                   lock
00007fff7dc84aec 0fb137               cmpxchg dword ptr [rdi], esi
00007fff7dc84aef 85c0                 test    eax, eax
00007fff7dc84af1 750a                 jne     0x7fff7dc84afd
00007fff7dc84af3 488bfb               mov     rdi, rbx
000000a6 -rdi(interior) +rdi
00007fff7dc84af6 33f6                 xor     esi, esi
00007fff7dc84af8 e83bb4e3ff           call    0x7fff7dabff38

~/runtime/src/libraries/System.Net.Sockets/src/System/Net/Sockets/SocketAsyncEngine.Unix.cs @ 333:
000000ad -rdi
00007fff7dc84afd 4585f6               test    r14d, r14d
00007fff7dc84b00 748e                 je      0x7fff7dc84a90

~/runtime/src/libraries/System.Net.Sockets/src/System/Net/Sockets/SocketAsyncEngine.Unix.cs @ 387:
000000b2 -r13 -r12
00007fff7dc84b02 488bfb               mov     rdi, rbx
000000b5 +rdi
00007fff7dc84b05 e8eefafeff           call    0x7fff7dc745f8 (System.Net.Sockets.SocketAsyncEngine.FreeNativeResources(), mdToken: 00000000060004BE)
000000ba -rdi -rbx
00007fff7dc84b0a e914010000           jmp     0x7fff7dc84c23

~/runtime/src/libraries/System.Net.Sockets/src/System/Net/Sockets/SocketAsyncEngine.Unix.cs @ 339:
00007fff7dc84b0f 48bf1084cf7dff7f0000 movabs  rdi, 0x7fff7dcf8410
00007fff7dc84b19 e8f2279178           call    0x7ffff6597310 (JitHelp: CORINFO_HELP_NEWSFAST)
000000ce +rax
00007fff7dc84b1e 488bd8               mov     rbx, rax
000000d1 +rbx
00007fff7dc84b21 448b75cc             mov     r14d, dword ptr [rbp - 0x34]
00007fff7dc84b25 44897308             mov     dword ptr [rbx + 0x8], r14d
00007fff7dc84b29 48bfb066d07dff7f0000 movabs  rdi, 0x7fff7dd066b0
00007fff7dc84b33 e8d8279178           call    0x7ffff6597310 (JitHelp: CORINFO_HELP_NEWSFAST)
00007fff7dc84b38 4c8bf0               mov     r14, rax
000000eb +r14
00007fff7dc84b3b 488bf3               mov     rsi, rbx
000000ee +rsi
00007fff7dc84b3e 498bfe               mov     rdi, r14
000000f1 +rdi
00007fff7dc84b41 e892b2ffff           call    0x7fff7dc7fdd8 (System.Net.InternalException..ctor(System.Object), mdToken: 00000000060000B6)
000000f6 -rdi -rsi -rbx -rax
00007fff7dc84b46 498bfe               mov     rdi, r14
000000f9 +rdi
00007fff7dc84b49 e862909178           call    0x7ffff659dbb0 (JitHelp: CORINFO_HELP_THROW)
000000fe -r14 -rdi +r13 +r12 +rbx
00007fff7dc84b4e 8945c4               mov     dword ptr [rbp - 0x3c], eax
00007fff7dc84b51 8955c8               mov     dword ptr [rbp - 0x38], edx
00007fff7dc84b54 498b7c2410           mov     rdi, qword ptr [r12 + 0x10]
00000109 +rdi
00007fff7dc84b59 48894db8             mov     qword ptr [rbp - 0x48], rcx
00007fff7dc84b5d 488bf1               mov     rsi, rcx
00007fff7dc84b60 49bb4823817cff7f0000 movabs  r11, 0x7fff7c812348
00007fff7dc84b6a 49b84823817cff7f0000 movabs  r8, 0x7fff7c812348
00007fff7dc84b74 41ff10               call    qword ptr [r8]
00000127 -rdi
00007fff7dc84b77 8bd0                 mov     edx, eax
00007fff7dc84b79 488d4db0             lea     rcx, [rbp - 0x50]
00007fff7dc84b7d 488b75b8             mov     rsi, qword ptr [rbp - 0x48]
00007fff7dc84b81 498bfc               mov     rdi, r12
00000134 +rdi
00007fff7dc84b84 e82fdcffff           call    0x7fff7dc827b8 (System.Collections.Concurrent.ConcurrentDictionary`2[[System.IntPtr, System.Private.CoreLib],[System.__Canon, System.Private.CoreLib]].TryGetValueInternal(IntPtr, Int32, System.__Canon ByRef), mdToken: 00000000060000BA)

~/runtime/src/libraries/System.Net.Sockets/src/System/Net/Sockets/SocketAsyncEngine.Unix.cs @ 357:
00000139 -rdi
00007fff7dc84b89 48837db000           cmp     qword ptr [rbp - 0x50], 0x0
00007fff7dc84b8e 8b45c4               mov     eax, dword ptr [rbp - 0x3c]
00007fff7dc84b91 0f8484000000         je      0x7fff7dc84c1b

~/runtime/src/libraries/System.Net.Sockets/src/System/Net/Sockets/SocketAsyncEngine.Unix.cs @ 359:
00007fff7dc84b97 8945c4               mov     dword ptr [rbp - 0x3c], eax
00007fff7dc84b9a 4863f8               movsxd  rdi, eax
00007fff7dc84b9d 48c1e704             shl     rdi, 0x4
00007fff7dc84ba1 418b743f08           mov     esi, dword ptr [r15 + rdi + 0x8]
00007fff7dc84ba6 488b7db0             mov     rdi, qword ptr [rbp - 0x50]
0000015a +rdi
00007fff7dc84baa 393f                 cmp     dword ptr [rdi], edi
00007fff7dc84bac e82ff9feff           call    0x7fff7dc744e0

~/runtime/src/libraries/System.Net.Sockets/src/System/Net/Sockets/SocketAsyncEngine.Unix.cs @ 361:
00000161 -rdi
00007fff7dc84bb1 85c0                 test    eax, eax
00007fff7dc84bb3 7455                 je      0x7fff7dc84c0a

~/runtime/src/libraries/System.Net.Sockets/src/System/Net/Sockets/SocketAsyncEngine.Unix.cs @ 363:
00007fff7dc84bb5 488b4db0             mov     rcx, qword ptr [rbp - 0x50]

~/runtime/src/libraries/System.Net.Sockets/src/System/Net/Sockets/SocketAsyncEngine.Unix.cs @ 364:
00000169 +rcx
00007fff7dc84bb9 498b7d10             mov     rdi, qword ptr [r13 + 0x10]
0000016d +rdi
00007fff7dc84bbd 488d7598             lea     rsi, [rbp - 0x68]
00000171 +rsi(interior)
00007fff7dc84bc1 48894d90             mov     qword ptr [rbp - 0x70], rcx
00000175 +rbp-70
00007fff7dc84bc5 48890e               mov     qword ptr [rsi], rcx
00007fff7dc84bc8 8945ac               mov     dword ptr [rbp - 0x54], eax
00007fff7dc84bcb 894608               mov     dword ptr [rsi + 0x8], eax
00007fff7dc84bce 488b7598             mov     rsi, qword ptr [rbp - 0x68]
00000182 -rsi(interior) +rsi
00007fff7dc84bd2 488b55a0             mov     rdx, qword ptr [rbp - 0x60]
00007fff7dc84bd6 393f                 cmp     dword ptr [rdi], edi
00007fff7dc84bd8 e8b3e1ffff           call    0x7fff7dc82d90 (System.Collections.Concurrent.ConcurrentQueueSegment`1[[System.Net.Sockets.SocketAsyncEngine+SocketIOEvent, System.Net.Sockets]].TryEnqueue(SocketIOEvent), mdToken: 0000000006005958)
0000018d -rdi -rsi -rcx
00007fff7dc84bdd 85c0                 test    eax, eax
00007fff7dc84bdf 7521                 jne     0x7fff7dc84c02
00007fff7dc84be1 488d7d98             lea     rdi, [rbp - 0x68]
00000195 +rdi(interior)
00007fff7dc84be5 488b7590             mov     rsi, qword ptr [rbp - 0x70]
00000199 +rsi
00007fff7dc84be9 488937               mov     qword ptr [rdi], rsi
00007fff7dc84bec 8b75ac               mov     esi, dword ptr [rbp - 0x54]
0000019f -rsi
00007fff7dc84bef 897708               mov     dword ptr [rdi + 0x8], esi
00007fff7dc84bf2 498bfd               mov     rdi, r13
000001a5 -rdi(interior) +rdi
00007fff7dc84bf5 488b7598             mov     rsi, qword ptr [rbp - 0x68]
000001a9 +rsi
00007fff7dc84bf9 488b55a0             mov     rdx, qword ptr [rbp - 0x60]
000001ad -rbp-70
00007fff7dc84bfd e866dfffff           call    0x7fff7dc82b68 (System.Collections.Concurrent.ConcurrentQueue`1[[System.Net.Sockets.SocketAsyncEngine+SocketIOEvent, System.Net.Sockets]].EnqueueSlow(SocketIOEvent), mdToken: 0000000006005945)

~/runtime/src/libraries/System.Net.Sockets/src/System/Net/Sockets/SocketAsyncEngine.Unix.cs @ 365:
000001b2 -rdi -rsi
00007fff7dc84c02 bf01000000           mov     edi, 0x1

~/runtime/src/libraries/System.Net.Sockets/src/System/Net/Sockets/SocketAsyncEngine.Unix.cs @ 370:
00007fff7dc84c07 897dc8               mov     dword ptr [rbp - 0x38], edi

~/runtime/src/libraries/System.Net.Sockets/src/System/Net/Sockets/SocketAsyncEngine.Unix.cs @ 376:
00007fff7dc84c0a 33c0                 xor     eax, eax
000001bc +rax
00007fff7dc84c0c 488945b0             mov     qword ptr [rbp - 0x50], rax
00007fff7dc84c10 8b45c4               mov     eax, dword ptr [rbp - 0x3c]
000001c3 -rax
00007fff7dc84c13 8b55c8               mov     edx, dword ptr [rbp - 0x38]
00007fff7dc84c16 e9bafeffff           jmp     0x7fff7dc84ad5
00007fff7dc84c1b 8b55c8               mov     edx, dword ptr [rbp - 0x38]
00007fff7dc84c1e e9b2feffff           jmp     0x7fff7dc84ad5

~/runtime/src/libraries/System.Net.Sockets/src/System/Net/Sockets/SocketAsyncEngine.Unix.cs @ 393:
000001d3 not interruptible
000001d3 -r13 -r12 -rbx
00007fff7dc84c23 488d65d8             lea     rsp, [rbp - 0x28]
00007fff7dc84c27 5b                   pop     rbx
00007fff7dc84c28 415c                 pop     r12
00007fff7dc84c2a 415d                 pop     r13
00007fff7dc84c2c 415e                 pop     r14
00007fff7dc84c2e 415f                 pop     r15
00007fff7dc84c30 5d                   pop     rbp
00007fff7dc84c31 c3                   ret

~/runtime/src/libraries/System.Net.Sockets/src/System/Net/Sockets/SocketAsyncEngine.Unix.cs @ 329:
00007fff7dc84c32 55                   push    rbp
00007fff7dc84c33 4157                 push    r15
00007fff7dc84c35 4156                 push    r14
00007fff7dc84c37 4155                 push    r13
00007fff7dc84c39 4154                 push    r12
00007fff7dc84c3b 53                   push    rbx
00007fff7dc84c3c 50                   push    rax
00007fff7dc84c3d 488b2f               mov     rbp, qword ptr [rdi]
00007fff7dc84c40 48892c24             mov     qword ptr [rsp], rbp
00007fff7dc84c44 488dad80000000       lea     rbp, [rbp + 0x80]

~/runtime/src/libraries/System.Net.Sockets/src/System/Net/Sockets/SocketAsyncEngine.Unix.cs @ 389:
000001fb interruptible
000001fb +rsi
00007fff7dc84c4b 488bde               mov     rbx, rsi

~/runtime/src/libraries/System.Net.Sockets/src/System/Net/Sockets/SocketAsyncEngine.Unix.cs @ 391:
000001fe +rbx
00007fff7dc84c4e 48bf00c90160ff7f0000 movabs  rdi, 0x7fff6001c900
00007fff7dc84c58 4c8b37               mov     r14, qword ptr [rdi]
0000020b +r14
00007fff7dc84c5b 488bfb               mov     rdi, rbx
0000020e +rdi
00007fff7dc84c5e 488b03               mov     rax, qword ptr [rbx]
00007fff7dc84c61 488b4040             mov     rax, qword ptr [rax + 0x40]
00007fff7dc84c65 ff5008               call    qword ptr [rax + 0x8]
00000218 -rdi -rsi +rax
00007fff7dc84c68 488bf0               mov     rsi, rax
0000021b +rsi
00007fff7dc84c6b 498bfe               mov     rdi, r14
0000021e +rdi
00007fff7dc84c6e e82d0b5aff           call    0x7fff7d2257a0
00000223 -r14 -rdi -rsi
00007fff7dc84c73 488bf8               mov     rdi, rax
00000226 +rdi
00007fff7dc84c76 488bf3               mov     rsi, rbx
00000229 +rsi
00007fff7dc84c79 e82289bb78           call    0x7ffff683d5a0 (System.Environment.FailFast(System.String, System.Exception), mdToken: 00000000060002EB)
0000022e -rdi -rsi -rbx -rax
00007fff7dc84c7e 488d059effffff       lea     rax, [rip - 0x62]

~/runtime/src/libraries/System.Net.Sockets/src/System/Net/Sockets/SocketAsyncEngine.Unix.cs @ 393:
00000235 not interruptible
00007fff7dc84c85 4883c408             add     rsp, 0x8
00007fff7dc84c89 5b                   pop     rbx
00007fff7dc84c8a 415c                 pop     r12
00007fff7dc84c8c 415d                 pop     r13
00007fff7dc84c8e 415e                 pop     r14
00007fff7dc84c90 415f                 pop     r15
00007fff7dc84c92 5d                   pop     rbp
00007fff7dc84c93 c3                   ret

The clearing of ev (here: 8157271#diff-f7e3fa1efc2509a247819f786ac6e532R360, for debug builds) appears to have been optimized out (source line 370 from the disasm above), and it still appears to be clearing the context local (source line 376):

~/runtime/src/libraries/System.Net.Sockets/src/System/Net/Sockets/SocketAsyncEngine.Unix.cs @ 365:
000001b2 -rdi -rsi
00007fff7dc84c02 bf01000000           mov     edi, 0x1

~/runtime/src/libraries/System.Net.Sockets/src/System/Net/Sockets/SocketAsyncEngine.Unix.cs @ 370:
00007fff7dc84c07 897dc8               mov     dword ptr [rbp - 0x38], edi

~/runtime/src/libraries/System.Net.Sockets/src/System/Net/Sockets/SocketAsyncEngine.Unix.cs @ 376:
00007fff7dc84c0a 33c0                 xor     eax, eax
000001bc +rax
00007fff7dc84c0c 488945b0             mov     qword ptr [rbp - 0x50], rax
00007fff7dc84c10 8b45c4               mov     eax, dword ptr [rbp - 0x3c]
000001c3 -rax
00007fff7dc84c13 8b55c8               mov     edx, dword ptr [rbp - 0x38]
00007fff7dc84c16 e9bafeffff           jmp     0x7fff7dc84ad5
00007fff7dc84c1b 8b55c8               mov     edx, dword ptr [rbp - 0x38]
00007fff7dc84c1e e9b2feffff           jmp     0x7fff7dc84ad5

But despite optimizing out the clearing of ev, presumably because it's dead, somehow it is being considered alive going around the loop. @dotnet/jit-contrib, thoughts?

karelz · 2020-05-07T16:38:10Z

@antonfirsov given that this is regression from @kouvel's recent change, but specific to Sockets, can you please help here? (assigning to you) Thanks!

safern · 2020-05-08T03:45:37Z

Failed again in: #36083

This time in OSX. Will update the ActiveIssue to disable it on Unix.

antonfirsov · 2020-05-27T17:28:15Z

Opened #37064 for the runtime issue. We can workaround it by moving the loop body to a separate method with [MethodImpl(MethodImplOptions.NoInlining)], but that would introduce a perf regression according to my benchmarks.

antonfirsov · 2020-05-28T22:43:43Z

@kouvel looks like my initial approach for the method extraction was too naive + my first benchmarks were not accurate. Opened #37138 for a possible fix.

tmds · 2020-05-29T14:03:56Z

@kouvel commented at #37064 (comment)

If the lifetime of the struct were extended then at least the clearing of it should be kept around.

Such clearing was explicitly added to make this test pass when the test was introduced.
See resolved conversation at https://github.com/dotnet/corefx/pull/38499/files.

stephentoub · 2020-06-29T16:09:40Z

This continues to repro, now as a hang, e.g.
https://helix.dot.net/api/2019-06-17/jobs/eaf31b3d-0e3f-4127-b317-9e69418d2582/workitems/System.Net.Sockets.Tests/files/console.6116a8de.log

Executed on a003C2B
+ ./RunTests.sh --runtime-path /home/helixbot/work/B2BE0916/p
----- start Mon Jun 29 14:43:58 UTC 2020 =============== To repro directly: =====================================================
pushd .
/home/helixbot/work/B2BE0916/p/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
===========================================================================================================
~/work/B2BE0916/w/B7D00A6A/e ~/work/B2BE0916/w/B7D00A6A/e
  Discovering: System.Net.Sockets.Tests (method display = ClassAndMethod, method display options = None)
  Discovered:  System.Net.Sockets.Tests (found 822 of 1202 test cases)
  Starting:    System.Net.Sockets.Tests (parallel test collections = on, max threads = 2)
    System.Net.Sockets.Tests.DualModeConnectAsync.DualModeConnectAsync_DnsEndPointToHost_Helper [SKIP]
      Condition(s) not met: "LocalhostIsBothIPv4AndIPv6"
    System.Net.Sockets.Tests.DualModeConnectToDnsEndPoint.DualModeConnect_DnsEndPointToHost_Helper [SKIP]
      Condition(s) not met: "LocalhostIsBothIPv4AndIPv6"
    System.Net.Sockets.Tests.DualModeConnectToHostString.DualModeConnect_LoopbackDnsToHost_Helper [SKIP]
      Condition(s) not met: "LocalhostIsBothIPv4AndIPv6"
    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:20
   System.Net.Sockets.Tests: [Long Running Test] 'System.Net.Sockets.Tests.DisposedSocket.NonDisposedSocket_SafeHandlesCollected', Elapsed: 00:04:20
   System.Net.Sockets.Tests: [Long Running Test] 'System.Net.Sockets.Tests.DisposedSocket.NonDisposedSocket_SafeHandlesCollected', Elapsed: 00:06:20
   System.Net.Sockets.Tests: [Long Running Test] 'System.Net.Sockets.Tests.DisposedSocket.NonDisposedSocket_SafeHandlesCollected', Elapsed: 00:08:20
   System.Net.Sockets.Tests: [Long Running Test] 'System.Net.Sockets.Tests.DisposedSocket.NonDisposedSocket_SafeHandlesCollected', Elapsed: 00:10:20
   System.Net.Sockets.Tests: [Long Running Test] 'System.Net.Sockets.Tests.DisposedSocket.NonDisposedSocket_SafeHandlesCollected', Elapsed: 00:12:20
   System.Net.Sockets.Tests: [Long Running Test] 'System.Net.Sockets.Tests.DisposedSocket.NonDisposedSocket_SafeHandlesCollected', Elapsed: 00:14:20

cc: @antonfirsov

karelz · 2021-05-12T15:02:11Z

Duplicate of #50068

safern added the blocking-clean-ci Blocking PR or rolling runs of 'runtime' or 'runtime-extra-platforms' label May 5, 2020

Dotnet-GitSync-Bot added area-System.Net.Sockets untriaged New issue has not been triaged by the area owner labels May 5, 2020

safern mentioned this issue May 5, 2020

Disable NonDisposedSocket_SafeHandlesCollected test #35847

Merged

davidsh added disabled-test The test is disabled in source code against the issue and removed untriaged New issue has not been triaged by the area owner labels May 5, 2020

davidsh added this to the 5.0 milestone May 5, 2020

stephentoub mentioned this issue May 6, 2020

Single epoll thread per 28 cores #35800

Merged

jashook mentioned this issue May 6, 2020

Infrastructure - Status/Health #702

Closed

karelz added the test-run-core Test failures in .NET Core test runs label May 7, 2020

safern removed the blocking-clean-ci Blocking PR or rolling runs of 'runtime' or 'runtime-extra-platforms' label May 7, 2020

karelz assigned antonfirsov May 7, 2020

safern mentioned this issue May 8, 2020

Disable NonDisposedSocket_SafeHandlesCollected in AnyUnix #36099

Merged

antonfirsov mentioned this issue May 26, 2020

[Test PR] Enable NonDisposedSocket_SafeHandlesCollected #37025

Closed

antonfirsov added a commit to antonfirsov/runtime that referenced this issue May 27, 2020

workaround for dotnet#35846

6588a12

antonfirsov mentioned this issue May 27, 2020

Unwanted GC root in unused struct on stack #37064

Closed

antonfirsov mentioned this issue May 28, 2020

Move epoll event handling to a non-inlined method #37138

Merged

karelz modified the milestones: 5.0, Future Jun 5, 2020

adamsitnik closed this as completed in #37138 Jun 19, 2020

stephentoub reopened this Jun 29, 2020

stephentoub modified the milestones: Future, 5.0.0 Jun 29, 2020

stephentoub removed the disabled-test The test is disabled in source code against the issue label Jun 29, 2020

karelz modified the milestones: 5.0.0, Future Jul 27, 2020

karelz unassigned antonfirsov Jul 27, 2020

karelz marked this as a duplicate of #50068 May 12, 2021

karelz closed this as completed May 12, 2021

karelz modified the milestones: Future, 6.0.0 May 12, 2021

ghost locked as resolved and limited conversation to collaborators Jun 11, 2021

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

System.Net.Sockets.Tests.DisposedSocket.NonDisposedSocket_SafeHandlesCollected test failures on Linux #35846

System.Net.Sockets.Tests.DisposedSocket.NonDisposedSocket_SafeHandlesCollected test failures on Linux #35846

safern commented May 5, 2020 •

edited

Loading

ghost commented May 5, 2020

safern commented May 5, 2020

wfurt commented May 5, 2020

karelz commented May 7, 2020

kouvel commented May 7, 2020 •

edited

Loading

karelz commented May 7, 2020

safern commented May 8, 2020

antonfirsov commented May 27, 2020

antonfirsov commented May 28, 2020

tmds commented May 29, 2020

stephentoub commented Jun 29, 2020

karelz commented May 12, 2021

System.Net.Sockets.Tests.DisposedSocket.NonDisposedSocket_SafeHandlesCollected test failures on Linux #35846

System.Net.Sockets.Tests.DisposedSocket.NonDisposedSocket_SafeHandlesCollected test failures on Linux #35846

Comments

safern commented May 5, 2020 • edited Loading