dotnet / dotnet/performance

Two Perf_Regex_Common tests crashing in MonoAOT testing

Open
#4,099 0 comments 0 reactions 0 assignees View on GitHub
bug
Dominant language
F#
Stars
773
Forks
301
Avg merge
6d 9h
Merged PRs (30d)
15

Description

The System.Text.RegularExpressions.Tests.Perf_Regex_Common.MatchesBoundary(Options: IgnoreCase, Compiled) and System.Text.RegularExpressions.Tests.Perf_Regex_Common.OneNodeBacktracking(Options: IgnoreCase, Compiled) tests are crashing during MonoAOT test execution. Example report from job https://dev.azure.com/dnceng/internal/_build/results?buildId=2416822 is below. ~Last known good run was build [20240325.1](https://dev.azure.com/dnceng/internal/_build/results?buildId=2413509&view=results) with git hash [330b70cfac](https://github.com/dotnet/runtime/commit/330b70cfacc7751ab5ac546ed7138cb8a09c3097), first known bad run was build [20240325.2](https://dev.azure.com/dnceng/internal/_build/results?buildId=2413997) with git hash [13a90361bb](https://github.com/dotnet/runtime/commit/13a90361bb8a527482d98b2f31eb245c1dcbf183). [Runtime Compare](https://github.com/dotnet/runtime/compare/330b70cfacc7751ab5ac546ed7138cb8a09c3097...13a90361bb8a527482d98b2f31eb245c1dcbf183). Edit: The last known good and first bad were just for that single test, but the error was occuring for some other tests in the "good" run. The start time of this still needs to be determined.~

Further investigation surfaces this in build [20240311.4](https://dev.azure.com/dnceng/internal/_build/results?buildId=2400250) with compare to the build before [20240311.2](https://dev.azure.com/dnceng/internal/_build/results?buildId=2399871) [Runtime Compare](https://github.com/dotnet/runtime/compare/9c828a17c347118968d7a1a170178daf4a9ce126...e171360c844ea9c1f4f98e8de7567342deb53e85). Although this was also around a time we updated BDN https://github.com/dotnet/performance/pull/4044.

```
// Benchmark: Perf_Regex_Common.MatchesBoundary: Job-WHPMBT(PowerPlanMode=00000000-0000-0000-0000-000000000000, Runtime=MonoAOTLLVM, Toolchain=MonoAOTLLVM, IterationTime=250ms, MaxIterationCount=20, MinIterationCount=15, WarmupCount=1) [Options=IgnoreCase, Compiled]
// *** Execute ***
// Launch: 1 / 1
// Execute: /home/helixbot/work/AD4B094A/w/B5F20A05/e/performance/artifacts/bin/MicroBenchmarks/Release/net9.0/Job-AMNAZR/bin/Release/net9.0/linux-x64/publish/Job-AMNAZR --anonymousPipes 188 189 --benchmarkName "System.Text.RegularExpressions.Tests.Perf_Regex_Common.MatchesBoundary(Options: IgnoreCase, Compiled)" --job "PowerPlanMode=00000000-0000-0000-0000-000000000000, Runtime=MonoAOTLLVM, Toolchain=MonoAOTLLVM, IterationTime=250ms, MaxIterationCount=20, MinIterationCount=15, WarmupCount=1" --benchmarkId 160 in /home/helixbot/work/AD4B094A/w/B5F20A05/e/performance/artifacts/bin/MicroBenchmarks/Release/net9.0/Job-AMNAZR/bin/Release/net9.0/linux-x64/publish
// Failed to set up high priority (Permission denied). In order to run benchmarks with high priority, make sure you have the right permissions.
// BeforeAnythingElse

// Benchmark Process Environment Information:
// BenchmarkDotNet v0.13.13-nightly.20240311.145
// Runtime=.NET 9.0.0 (42.42.42.42424) using MonoVM, X64 SSE4.2
// GC=Non-concurrent Workstation
// HardwareIntrinsics=SSE4.2,AES,BMI1,BMI2,LZCNT,PCLMUL,POPCNT VectorSize=128
// Job: Job-ACAJIL(PowerPlanMode=00000000-0000-0000-0000-000000000000, IterationTime=250ms, MaxIterationCount=20, MinIterationCount=15, WarmupCount=1)

=================================================================
Native Crash Reporting
=================================================================
Got a SIGSEGV while executing native code. This usually indicates
a fatal error in the mono runtime or one of the native libraries
used by your application.
=================================================================
=================================================================
Native stacktrace:
=================================================================
0x7e23f28f1b61 - Unknown
0x7e23f289451e - Unknown
0x7e23f27f7ef1 - Unknown
0x7e23f3842520 - Unknown
0x7e23f2abdc3b - Unknown
0x7e23f2aa9ab8 - Unknown
0x7e23f2aaa678 - Unknown
0x7e23f2aa932c - Unknown
0x7e23f2aa5145 - Unknown
0x7e23f2aa60a1 - Unknown
0x7e23f2a94710 - Unknown
0x4200f5ca - Unknown

=================================================================
External Debugger Dump:
=================================================================
[New LWP 149245]
[New LWP 149246]
[New LWP 149247]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
0x00007e23f38ea42f in __GI___wait4 (pid=pid@entry=149250, stat_loc=stat_loc@entry=0x7fffc6003400, options=options@entry=0, usage=usage@entry=0x0) at ../sysdeps/unix/sysv/linux/wait4.c:30
30 ../sysdeps/unix/sysv/linux/wait4.c: No such file or directory.
Id Target Id Frame
* 1 Thread 0x7e23f3e36740 (LWP 149244) "Job-AMNAZR" 0x00007e23f38ea42f in __GI___wait4 (pid=pid@entry=149250, stat_loc=stat_loc@entry=0x7fffc6003400, options=options@entry=0, usage=usage@entry=0x0) at ../sysdeps/unix/sysv/linux/wait4.c:30
2 Thread 0x7e23f13ff640 (LWP 149245) "SGen worker" __futex_abstimed_wait_common64 (private=0, cancel=true, abstime=0x0, op=393, expected=0, futex_word=0x7e23f3736b88 ) at ./nptl/futex-internal.c:57
3 Thread 0x7e23eedff640 (LWP 149246) ".NET EventPipe" 0x00007e23f384280a in __GI___sigsuspend (set=set@entry=0x7e23f3722540 ) at ../sysdeps/unix/sysv/linux/sigsuspend.c:26
4 Thread 0x7e23eebfe640 (LWP 149247) "Finalizer" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=393, expected=0, futex_word=0x7e23f37280d0 ) at ./nptl/futex-internal.c:57

Thread 4 (Thread 0x7e23eebfe640 (LWP 149247) "Finalizer"):
#0 __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=393, expected=0, futex_word=0x7e23f37280d0 ) at ./nptl/futex-internal.c:57
#1 __futex_abstimed_wait_common (cancel=true, private=, abstime=0x0, clockid=0, expected=0, futex_word=0x7e23f37280d0 ) at ./nptl/futex-internal.c:87
#2 __GI___futex_abstimed_wait_cancelable64 (futex_word=futex_word@entry=0x7e23f37280d0 , expected=expected@entry=0, clockid=clockid@entry=0, abstime=abstime@entry=0x0, private=) at ./nptl/futex-internal.c:139
#3 0x00007e23f389cbdf in do_futex_wait (sem=sem@entry=0x7e23f37280d0 , abstime=0x0, clockid=0) at ./nptl/sem_waitcommon.c:111
#4 0x00007e23f389cc78 in __new_sem_wait_slow64 (sem=0x7e23f37280d0 , abstime=0x0, clockid=0) at ./nptl/sem_waitcommon.c:183
#5 0x00007e23f389ccf1 in __new_sem_wait (sem=) at ./nptl/sem_wait.c:42
#6 0x00007e23f2a84388 in mono_os_sem_wait (flags=MONO_SEM_FLAGS_ALERTABLE, sem=) at /__w/1/s/src/mono/mono/metadata/../../mono/utils/mono-os-semaphore.h:204
#7 mono_coop_sem_wait (flags=MONO_SEM_FLAGS_ALERTABLE, sem=) at /__w/1/s/src/mono/mono/metadata/../../mono/utils/mono-coop-semaphore.h:41
#8 finalizer_thread (unused=) at /__w/1/s/src/mono/mono/metadata/gc.c:864
#9 0x00007e23f2a5d239 in start_wrapper_internal (start_info=0x0, stack_ptr=) at /__w/1/s/src/mono/mono/metadata/threads.c:1208
#10 start_wrapper (data=) at /__w/1/s/src/mono/mono/metadata/threads.c:1276
#11 0x00007e23f3894ac3 in start_thread (arg=) at ./nptl/pthread_create.c:442
#12 0x00007e23f3926850 in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81

Thread 3 (Thread 0x7e23eedff640 (LWP 149246) ".NET EventPipe"):
#0 0x00007e23f384280a in __GI___sigsuspend (set=set@entry=0x7e23f3722540 ) at ../sysdeps/unix/sysv/linux/sigsuspend.c:26
#1 0x00007e23f29d2be3 in suspend_signal_handler (_dummy=, info=, context=0x7e23eedfe580) at /__w/1/s/src/mono/mono/utils/mono-threads-posix-signals.c:200
#2
#3 0x00007e23f3918bcf in __GI___poll (fds=fds@entry=0x7e23e8002970, nfds=nfds@entry=1, timeout=timeout@entry=-1) at ../sysdeps/unix/sysv/linux/poll.c:29
#4 0x00007e23f29a9bce in ipc_poll_fds (fds=0x7e23e8002970, nfds=1, timeout=4294967295) at /__w/1/s/src/native/eventpipe/ds-ipc-pal-socket.c:470
#5 ds_ipc_poll (poll_handles_data=0x7e23e8002760, poll_handles_data_len=poll_handles_data_len@entry=1, timeout_ms=timeout_ms@entry=4294967295, callback=callback@entry=0x7e23f29a9060 ) at /__w/1/s/src/native/eventpipe/ds-ipc-pal-socket.c:1100
#6 0x00007e23f29a6ae8 in ds_ipc_stream_factory_get_next_available_stream (callback=callback@entry=0x7e23f29a9060 ) at /__w/1/s/src/native/eventpipe/ds-ipc.c:393
#7 0x00007e23f29a514f in server_thread (data=) at /__w/1/s/src/native/eventpipe/ds-server.c:129
#8 0x00007e23f29a9041 in ep_rt_thread_mono_start_func (data=0x62d108b3f040) at /__w/1/s/src/mono/mono/mini/../../mono/eventpipe/ep-rt-mono.h:878
#9 0x00007e23f3894ac3 in start_thread (arg=) at ./nptl/pthread_create.c:442
#10 0x00007e23f3926850 in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81

Thread 2 (Thread 0x7e23f13ff640 (LWP 149245) "SGen worker"):
#0 __futex_abstimed_wait_common64 (private=0, cancel=true, abstime=0x0, op=393, expected=0, futex_word=0x7e23f3736b88 ) at ./nptl/futex-internal.c:57
#1 __futex_abstimed_wait_common (cancel=true, private=0, abstime=0x0, clockid=0, expected=0, futex_word=0x7e23f3736b88 ) at ./nptl/futex-internal.c:87
#2 __GI___futex_abstimed_wait_cancelable64 (futex_word=futex_word@entry=0x7e23f3736b88 , expected=expected@entry=0, clockid=clockid@entry=0, abstime=abstime@entry=0x0, private=private@entry=0) at ./nptl/futex-internal.c:139
#3 0x00007e23f3893a41 in __pthread_cond_wait_common (abstime=0x0, clockid=0, mutex=0x7e23f3736b38 , cond=0x7e23f3736b60 ) at ./nptl/pthread_cond_wait.c:503
#4 ___pthread_cond_wait (cond=0x7e23f3736b60 , mutex=0x7e23f3736b38 ) at ./nptl/pthread_cond_wait.c:627
#5 0x00007e23f2ae25a3 in mono_os_cond_wait (cond=, mutex=) at /__w/1/s/src/mono/mono/sgen/../../mono/utils/mono-os-mutex.h:219
#6 get_work (worker_index=0, work_context=, do_idle=, job=) at /__w/1/s/src/mono/mono/sgen/sgen-thread-pool.c:164
#7 thread_func (data=0x0) at /__w/1/s/src/mono/mono/sgen/sgen-thread-pool.c:195
#8 0x00007e23f3894ac3 in start_thread (arg=) at ./nptl/pthread_create.c:442
#9 0x00007e23f3926850 in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81

Thread 1 (Thread 0x7e23f3e36740 (LWP 149244) "Job-AMNAZR"):
#0 0x00007e23f38ea42f in __GI___wait4 (pid=pid@entry=149250, stat_loc=stat_loc@entry=0x7fffc6003400, options=options@entry=0, usage=usage@entry=0x0) at ../sysdeps/unix/sysv/linux/wait4.c:30
#1 0x00007e23f38ea3ab in __GI___waitpid (pid=pid@entry=149250, stat_loc=stat_loc@entry=0x7fffc6003400, options=options@entry=0) at ./posix/waitpid.c:38
#2 0x00007e23f28f1c92 in dump_native_stacktrace (signal=, mctx=) at /__w/1/s/src/mono/mono/mini/mini-posix.c:843
#3 mono_dump_native_crash_info (signal=, mctx=mctx@entry=0x7fffc6003f70, info=) at /__w/1/s/src/mono/mono/mini/mini-posix.c:870
#4 0x00007e23f289451e in mono_handle_native_crash (signal=0x7e23f24bf7a8 "SIGSEGV", mctx=0x7fffc6003f70, info=0x7fffc6004230) at /__w/1/s/src/mono/mono/mini/mini-exceptions.c:2967
#5 0x00007e23f27f7ef1 in mono_sigsegv_signal_handler_debug (_dummy=11, _info=0x7fffc6004230, context=0x7fffc6004100, debug_fault_addr=0x204000000) at /__w/1/s/src/mono/mono/mini/mini-runtime.c:3902
#6
#7 0x00007e23f2abdc3b in major_copy_or_mark_object_no_evacuation (ptr=0x7e23df2d2fa0, obj=0x204000000, queue=0x7fffc60049a0) at /__w/1/s/src/mono/mono/sgen/../../mono/sgen/sgen-gc.h:206
#8 major_scan_object_no_evacuation (full_object=0x7e23df2d2f30, desc=, queue=0x7fffc60049a0) at /__w/1/s/src/mono/mono/sgen/sgen-scan-object.h:66
#9 drain_gray_stack_no_evacuation (queue=0x7fffc60049a0) at /__w/1/s/src/mono/mono/sgen/sgen-marksweep-drain-gray-stack.h:347
#10 drain_gray_stack (queue=0x7fffc60049a0) at /__w/1/s/src/mono/mono/sgen/sgen-marksweep.c:1287
#11 0x00007e23f2aa9ab8 in sgen_drain_gray_stack (ctx=...) at /__w/1/s/src/mono/mono/sgen/sgen-gc.c:578
#12 finish_gray_stack (generation=generation@entry=1, ctx=...) at /__w/1/s/src/mono/mono/sgen/sgen-gc.c:1140
#13 0x00007e23f2aaa678 in major_finish_collection (gc_thread_gray_queue=gc_thread_gray_queue@entry=0x7fffc60049a0, reason=reason@entry=0x7e23f24f5cf3 "user request", is_overflow=is_overflow@entry=0, old_next_pin_slot=85, forced=forced@entry=1) at /__w/1/s/src/mono/mono/sgen/sgen-gc.c:2323
#14 0x00007e23f2aa932c in major_do_collection (reason=reason@entry=0x7e23f24f5cf3 "user request", is_overflow=is_overflow@entry=0, forced=forced@entry=1) at /__w/1/s/src/mono/mono/sgen/sgen-gc.c:2465
#15 0x00007e23f2aa5145 in sgen_perform_collection_inner (requested_size=, generation_to_collect=, reason=, forced_serial=, stw=) at /__w/1/s/src/mono/mono/sgen/sgen-gc.c:2665
#16 sgen_perform_collection (requested_size=requested_size@entry=0, generation_to_collect=generation_to_collect@entry=1, reason=0x7e23f24f5cf3 "user request", forced_serial=forced_serial@entry=1, stw=stw@entry=1) at /__w/1/s/src/mono/mono/sgen/sgen-gc.c:2762
#17 0x00007e23f2aa60a1 in sgen_gc_collect (generation=generation@entry=1) at /__w/1/s/src/mono/mono/sgen/sgen-gc.c:3214
#18 0x00007e23f2a94710 in mono_gc_collect (generation=1) at /__w/1/s/src/mono/mono/metadata/sgen-mono.c:2359
#19 0x000000004200f5ca in ?? ()
#20 0x0000000000000001 in ?? ()
#21 0x00007e23f1411f60 in ?? ()
#22 0x0000000000000001 in ?? ()
#23 0x00007e23f146af50 in ?? ()
#24 0x0000000000000001 in ?? ()
#25 0x00007fffc60055c8 in ?? ()
#26 0x0000000000000000 in ?? ()
[Inferior 1 (process 149244) detached]
=================================================================
Basic Fault Address Reporting
=================================================================
Memory around native instruction pointer (0x7e23f2abdc3b):0x7e23f2abdc2b 48 c7 c2 ff ff ff ff 48 d3 e2 48 89 d6 48 21 ee H......H..H..H!.
0x7e23f2abdc3b 48 8b 45 00 49 3b 32 75 3c a8 02 0f 85 c4 01 00 H.E.I;2u<.......
0x7e23f2abdc4b 00 a8 01 0f 84 42 01 00 00 48 83 e0 f8 0f 84 38 .....B...H.....8
0x7e23f2abdc5b 01 00 00 49 89 45 00 41 0f b6 09 48 c7 c2 ff ff ...I.E.A...H....
=================================================================
Managed Stacktrace:
=================================================================
at <0xffffffff>
at System.GC:InternalCollect <0x00079>
at System.GC:Collect <0x00024>
at BenchmarkDotNet.Engines.Engine:RunIteration <0x000b5>
at BenchmarkDotNet.Engines.EngineFactory:Jit <0x0009c>
at BenchmarkDotNet.Engines.EngineFactory:CreateReadyToRun <0x0016f>
at BenchmarkDotNet.Autogenerated.Runnable_160:Run <0x00c7f>
at :runtime_invoke_void_object_object <0x00095>
at <0xffffffff>
at System.Reflection.RuntimeMethodInfo:InternalInvoke <0x000b9>
at System.Reflection.MethodBaseInvoker:InterpretedInvoke_Method <0x00041>
at System.Reflection.MethodBaseInvoker:InvokeDirectByRefWithFewArgs <0x001b2>
at System.Reflection.MethodBaseInvoker:InvokeWithFewArgs <0x0080f>
at System.Reflection.RuntimeMethodInfo:Invoke <0x001a4>
at System.Reflection.MethodBase:Invoke <0x00020>
at BenchmarkDotNet.Autogenerated.UniqueProgramName:AfterAssemblyLoadingAttached <0x005c4>
at BenchmarkDotNet.Autogenerated.UniqueProgramName:Main <0x00012>
at :runtime_invoke_int_object <0x00091>
=================================================================
No Workload Results were obtained from the run.
```

Contributor guide

No contributing guide indexed for this repository

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.