Quic tests AVing on free

[ericstj]

Build Information

Build: https://dev.azure.com/dnceng-public/cbb18261-c48f-4abb-8651-8cdcb5474649/_build/results?buildId=230172
Build error leg or test failing: System.Net.Quic.Functional.Tests.WorkItemExecution
Pull request: #84413

Error Message

Fill the error message using known issues guidance.

{
  "ErrorMessage": "QuicListenerFree",
  "BuildRetry": false,
  "ErrorPattern": "",
  "ExcludeConsoleLog": false
}

Here's a snippet of the faulting stack from https://helixre107v0xdcypoyl9e7f.blob.core.windows.net/dotnet-runtime-refs-pull-84413-merge-813d913fbff94e5b95/System.Net.Quic.Functional.Tests/1/console.83e44ebb.log?helixlogtype=result:

#0  0x00007f3b0927d0ca in __waitpid (pid=57, stat_loc=0x7f3ae9648b40, options=0) at ../sysdeps/unix/sysv/linux/waitpid.c:30
#1  0x00007f3b08a5c0a7 in dump_native_stacktrace (signal=<optimized out>, mctx=<optimized out>) at /__w/1/s/src/mono/mono/mini/mini-posix.c:843
#2  mono_dump_native_crash_info (signal=<optimized out>, mctx=0x7f3ae9649658, info=<optimized out>) at /__w/1/s/src/mono/mono/mini/mini-posix.c:870
#3  0x00007f3b08a01b4e in mono_handle_native_crash (signal=0x7f3b0889c01c "SIGABRT", mctx=0x7f3ae9649658, info=0x7f3ae9649930) at /__w/1/s/src/mono/mono/mini/mini-exceptions.c:2979
#4  0x00007f3b08a5b838 in sigabrt_signal_handler (_dummy=<optimized out>, _info=0x7f3ae9649930, context=0x7f3ae9649800) at /__w/1/s/src/mono/mono/mini/mini-posix.c:225
#5  <signal handler called>
#6  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#7  0x00007f3b08da7535 in __GI_abort () at abort.c:79
#8  0x00007f3b08dfe648 in __libc_message (action=action@entry=do_abort, fmt=fmt@entry=0x7f3b08f082a0 "%s\n") at ../sysdeps/posix/libc_fatal.c:181
#9  0x00007f3b08e04d6a in malloc_printerr (str=str@entry=0x7f3b08f0a038 "free(): invalid next size (normal)") at malloc.c:5359
#10 0x00007f3b08e0677c in _int_free (av=0x7f3ad0000020, p=0x7f3ad0671080, have_lock=<optimized out>) at malloc.c:4329
#11 0x00007f3b040eec41 in QuicListenerFree (Listener=Listener@entry=0x7f3ad0671090) at /__w/1/s/src/core/listener.c:128
#12 0x00007f3b040eee80 in QuicListenerStopComplete (Listener=0x7f3ad0671090, IndicateEvent=<optimized out>) at /__w/1/s/src/core/listener.c:444
#13 0x00007f3b040ef019 in QuicListenerRelease (Listener=<optimized out>, IndicateEvent=IndicateEvent@entry=1 '\001') at /__w/1/s/src/core/listener.c:456
#14 0x00007f3b04110a80 in QuicBindingAcceptConnection (Binding=<optimized out>, Connection=Connection@entry=0x7f3adc70b4b0, Info=Info@entry=0x7f3ae964a930) at /__w/1/s/src/core/binding.c:554
#15 0x00007f3b04129656 in QuicCryptoProcessData (Crypto=Crypto@entry=0x7f3adc70bd30, IsClientInitial=IsClientInitial@entry=0 '\000') at /__w/1/s/src/core/crypto.c:1818
#16 0x00007f3b04129a5a in QuicCryptoProcessFrame (Crypto=Crypto@entry=0x7f3adc70bd30, KeyType=<optimized out>, Frame=Frame@entry=0x7f3ae964aa50) at /__w/1/s/src/core/crypto.c:1319
#17 0x00007f3b0412028a in QuicConnRecvFrames (Connection=Connection@entry=0x7f3adc70b4b0, Path=<optimized out>, Packet=Packet@entry=0x7f3adc6f9070, ECN=ECN@entry=CXPLAT_ECN_NON_ECT) at /__w/1/s/src/core/connection.c:4468
#18 0x00007f3b04122eb2 in QuicConnRecvDatagramBatch (Connection=Connection@entry=0x7f3adc70b4b0, Path=<optimized out>, Path@entry=0x7f3adc70b5d8, BatchCount=<optimized out>, Datagrams=<optimized out>, Cipher=Cipher@entry=0x7f3ae964ac90 "\245\aU<K\345\272Ps\247\373Ј\277%||", RecvState=RecvState@entry=0x7f3ae964ac44) at /__w/1/s/src/core/connection.c:5367
#19 0x00007f3b04123642 in QuicConnRecvDatagrams (Connection=Connection@entry=0x7f3adc70b4b0, DatagramChain=<optimized out>, DatagramChain@entry=0x7f3adc6f8a58, DatagramChainCount=DatagramChainCount@entry=1, IsDeferred=IsDeferred@entry=0 '\000') at /__w/1/s/src/core/connection.c:5566
#20 0x00007f3b04123cc0 in QuicConnFlushRecv (Connection=0x7f3adc70b4b0) at /__w/1/s/src/core/connection.c:5724
#21 0x00007f3b041268c0 in QuicConnDrainOperations (Connection=Connection@entry=0x7f3adc70b4b0) at /__w/1/s/src/core/connection.c:7347
#22 0x00007f3b0410a304 in QuicWorkerProcessConnection (Worker=Worker@entry=0x7f3adc5e4410, Connection=0x7f3adc70b4b0, ThreadID=ThreadID@entry=51, TimeNow=TimeNow@entry=0x7f3ae964ae98) at /__w/1/s/src/core/worker.c:509
#23 0x00007f3b0410a950 in QuicWorkerLoop (Context=Context@entry=0x7f3adc5e4410, TimeNow=TimeNow@entry=0x7f3ae964ae98, ThreadID=ThreadID@entry=51) at /__w/1/s/src/core/worker.c:668
#24 0x00007f3b0410ac56 in QuicWorkerThread (Context=0x7f3adc5e4410) at /__w/1/s/src/core/worker.c:733
#25 0x00007f3b09272fa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#26 0x00007f3b08e7e06f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Report

Summary

24-Hour Hit Count	7-Day Hit Count	1-Month Count
0	0	0

[ghost]

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

Issue Details

---

Build Information

Build: https://dev.azure.com/dnceng-public/cbb18261-c48f-4abb-8651-8cdcb5474649/_build/results?buildId=230172
Build error leg or test failing: System.Net.Quic.Functional.Tests.WorkItemExecution
Pull request: #84413

Error Message

Fill the error message using known issues guidance.

{
  "ErrorMessage": "Got a SIGABRT while executing native code",
  "BuildRetry": false,
  "ErrorPattern": "",
  "ExcludeConsoleLog": false
}

Here's a snippet of the faulting stack from https://helixre107v0xdcypoyl9e7f.blob.core.windows.net/dotnet-runtime-refs-pull-84413-merge-813d913fbff94e5b95/System.Net.Quic.Functional.Tests/1/console.83e44ebb.log?helixlogtype=result:

#0  0x00007f3b0927d0ca in __waitpid (pid=57, stat_loc=0x7f3ae9648b40, options=0) at ../sysdeps/unix/sysv/linux/waitpid.c:30
#1  0x00007f3b08a5c0a7 in dump_native_stacktrace (signal=<optimized out>, mctx=<optimized out>) at /__w/1/s/src/mono/mono/mini/mini-posix.c:843
#2  mono_dump_native_crash_info (signal=<optimized out>, mctx=0x7f3ae9649658, info=<optimized out>) at /__w/1/s/src/mono/mono/mini/mini-posix.c:870
#3  0x00007f3b08a01b4e in mono_handle_native_crash (signal=0x7f3b0889c01c "SIGABRT", mctx=0x7f3ae9649658, info=0x7f3ae9649930) at /__w/1/s/src/mono/mono/mini/mini-exceptions.c:2979
#4  0x00007f3b08a5b838 in sigabrt_signal_handler (_dummy=<optimized out>, _info=0x7f3ae9649930, context=0x7f3ae9649800) at /__w/1/s/src/mono/mono/mini/mini-posix.c:225
#5  <signal handler called>
#6  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#7  0x00007f3b08da7535 in __GI_abort () at abort.c:79
#8  0x00007f3b08dfe648 in __libc_message (action=action@entry=do_abort, fmt=fmt@entry=0x7f3b08f082a0 "%s\n") at ../sysdeps/posix/libc_fatal.c:181
#9  0x00007f3b08e04d6a in malloc_printerr (str=str@entry=0x7f3b08f0a038 "free(): invalid next size (normal)") at malloc.c:5359
#10 0x00007f3b08e0677c in _int_free (av=0x7f3ad0000020, p=0x7f3ad0671080, have_lock=<optimized out>) at malloc.c:4329
#11 0x00007f3b040eec41 in QuicListenerFree (Listener=Listener@entry=0x7f3ad0671090) at /__w/1/s/src/core/listener.c:128
#12 0x00007f3b040eee80 in QuicListenerStopComplete (Listener=0x7f3ad0671090, IndicateEvent=<optimized out>) at /__w/1/s/src/core/listener.c:444
#13 0x00007f3b040ef019 in QuicListenerRelease (Listener=<optimized out>, IndicateEvent=IndicateEvent@entry=1 '\001') at /__w/1/s/src/core/listener.c:456
#14 0x00007f3b04110a80 in QuicBindingAcceptConnection (Binding=<optimized out>, Connection=Connection@entry=0x7f3adc70b4b0, Info=Info@entry=0x7f3ae964a930) at /__w/1/s/src/core/binding.c:554
#15 0x00007f3b04129656 in QuicCryptoProcessData (Crypto=Crypto@entry=0x7f3adc70bd30, IsClientInitial=IsClientInitial@entry=0 '\000') at /__w/1/s/src/core/crypto.c:1818
#16 0x00007f3b04129a5a in QuicCryptoProcessFrame (Crypto=Crypto@entry=0x7f3adc70bd30, KeyType=<optimized out>, Frame=Frame@entry=0x7f3ae964aa50) at /__w/1/s/src/core/crypto.c:1319
#17 0x00007f3b0412028a in QuicConnRecvFrames (Connection=Connection@entry=0x7f3adc70b4b0, Path=<optimized out>, Packet=Packet@entry=0x7f3adc6f9070, ECN=ECN@entry=CXPLAT_ECN_NON_ECT) at /__w/1/s/src/core/connection.c:4468
#18 0x00007f3b04122eb2 in QuicConnRecvDatagramBatch (Connection=Connection@entry=0x7f3adc70b4b0, Path=<optimized out>, Path@entry=0x7f3adc70b5d8, BatchCount=<optimized out>, Datagrams=<optimized out>, Cipher=Cipher@entry=0x7f3ae964ac90 "\245\aU<K\345\272Ps\247\373Ј\277%||", RecvState=RecvState@entry=0x7f3ae964ac44) at /__w/1/s/src/core/connection.c:5367
#19 0x00007f3b04123642 in QuicConnRecvDatagrams (Connection=Connection@entry=0x7f3adc70b4b0, DatagramChain=<optimized out>, DatagramChain@entry=0x7f3adc6f8a58, DatagramChainCount=DatagramChainCount@entry=1, IsDeferred=IsDeferred@entry=0 '\000') at /__w/1/s/src/core/connection.c:5566
#20 0x00007f3b04123cc0 in QuicConnFlushRecv (Connection=0x7f3adc70b4b0) at /__w/1/s/src/core/connection.c:5724
#21 0x00007f3b041268c0 in QuicConnDrainOperations (Connection=Connection@entry=0x7f3adc70b4b0) at /__w/1/s/src/core/connection.c:7347
#22 0x00007f3b0410a304 in QuicWorkerProcessConnection (Worker=Worker@entry=0x7f3adc5e4410, Connection=0x7f3adc70b4b0, ThreadID=ThreadID@entry=51, TimeNow=TimeNow@entry=0x7f3ae964ae98) at /__w/1/s/src/core/worker.c:509
#23 0x00007f3b0410a950 in QuicWorkerLoop (Context=Context@entry=0x7f3adc5e4410, TimeNow=TimeNow@entry=0x7f3ae964ae98, ThreadID=ThreadID@entry=51) at /__w/1/s/src/core/worker.c:668
#24 0x00007f3b0410ac56 in QuicWorkerThread (Context=0x7f3adc5e4410) at /__w/1/s/src/core/worker.c:733
#25 0x00007f3b09272fa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#26 0x00007f3b08e7e06f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Author:	ericstj
Assignees:	-
Labels:	blocking-clean-ci, untriaged, area-System.Net.Quic, Known Build Error
Milestone:	-

[ManickaP]

This is still running on 2.1, could this be somehow related with microsoft/msquic#3444 @nibanks?

We're running MsQuicListenerClose after STOP_COMPLETE, but from a different thread. This is free called from QuicListenerStopComplete which should happen only if we called MsQuicListenerClose from STOP_COMPLETE callback if I read the code correctly. So I'm confused how this code path could even be triggered.

[nibanks]

Yes, this looks to be microsoft/msquic#3444, which isn't in release/2.1.

[wfurt]

is this worth of picking up for next maintenance? (seems like the fix is simple)
We can updated main to use 2.2 but I'm wondering what would be impact on maintenance and 7.0 customers.

[ManickaP]

Triage: if #83537 turns out to be working, we can close this.

[wfurt]

I assume we do not see Quic crashes any more @rzikm. Could you please double-check and close if CI runs are clean?

[rzikm]

No recent Quic crashes. Closing.