Large performance overhead and lock contention while adding and reading fragments on Aarch64
I tested DynamoRIO-AArch64-Linux-8.0.0-1 and drcov with a large application of ca. 150 threads. Yocto Linux. The program seems to get stuck at certain points. Attaching with gdb shows that the program still runs but contends a mutex that has to do with fragment writing/reading:
DynamoRIO-AArch64-Linux-8.0.0-1
/media/mp000/DynamoRIO-AArch64-Linux-8.0.0-1/bin64/drrun -root /media/mp000/DynamoRIO-AArch64-Linux-8.0.0-1 -t drcov -logdir /media/mp000/ -dump_binary -- /bin/myprogram
The readers ( dozens ):
Thread 42 (LWP 2650):
#0 0x000000007112fd08 in dynamorio_syscall ()
#1 0x000000007105b2a8 in d_r_read_lock (rw=0x7f0fefe5ac) at /home/travis/build/DynamoRIO/dynamorio/core/utils.c:1185
#2 0x0000000071048730 in fragment_lookup_type (lookup_flags=15, tag=0x7f0c28431c "\342\003", dcontext=0x7f110859e0) at /home/travis/build/DynamoRIO/dynamorio/core/fragment.c:2738
#3 fragment_lookup (tag=0x7f0c28431c "\342\003", dcontext=0x7f110859e0) at /home/travis/build/DynamoRIO/dynamorio/core/fragment.c:2756
#4 fragment_lookup_fine_and_coarse (dcontext=dcontext@entry=0x7f110859e0, tag=0x7f0c28431c "\342\003", wrapper=wrapper@entry=0x7f10c44fc8, last_exit=0x7f10e09a48) at /home/travis/build/DynamoRIO/dynamorio/core/fragment.c:8109
#5 0x0000000071057d80 in dispatch_exit_fcache_stats (dcontext=0x7f110859e0) at /home/travis/build/DynamoRIO/dynamorio/core/dispatch.c:1416
#6 dispatch_enter_dynamorio (dcontext=0x7f110859e0) at /home/travis/build/DynamoRIO/dynamorio/core/dispatch.c:856
#7 d_r_dispatch (dcontext=0x7f110859e0) at /home/travis/build/DynamoRIO/dynamorio/core/dispatch.c:164
#8 0x0000007f0c2842fc in ?? ()
The writer who slows everything down:
#0 0x000000007104257c in hashtable_fragment_add (dcontext=dcontext@entry=0x7f14cc9900, e=0x7f130e9e48, table=table@entry=0x7f0fefe568) at /home/travis/build/DynamoRIO/dynamorio/core/hashtablex.h:782
782 /home/travis/build/DynamoRIO/dynamorio/core/hashtablex.h: No such file or directory.
(gdb) bt
#0 0x000000007104257c in hashtable_fragment_add (dcontext=dcontext@entry=0x7f14cc9900, e=0x7f130e9e48, table=table@entry=0x7f0fefe568) at /home/travis/build/DynamoRIO/dynamorio/core/hashtablex.h:782
#1 0x00000000710423d0 in hashtable_fragment_add (table=0x7f0fefe568, e=, dcontext=0x7f14cc9900) at /home/travis/build/DynamoRIO/dynamorio/core/hashtablex.h:768
#2 hashtable_fragment_check_size (add_now=1, add_later=0, table=0x7f0fefe568, dcontext=0x7f14cc9900, dcontext@entry=0x7115a000 <reg_names+544>) at /home/travis/build/DynamoRIO/dynamorio/core/hashtablex.h:1102
#3 hashtable_fragment_add (dcontext=dcontext@entry=0x7f14cc9900, e=0x7f159b2860, table=table@entry=0x7f0fefe568) at /home/travis/build/DynamoRIO/dynamorio/core/hashtablex.h:780
#4 0x0000000071043148 in hashtable_fragment_add (table=0x7f0fefe568, e=, dcontext=0x7f14cc9900) at /home/travis/build/DynamoRIO/dynamorio/core/hashtablex.h:768
#5 fragment_add_to_hashtable (table=0x7f0fefe568, e=, dcontext=0x7f14cc9900) at /home/travis/build/DynamoRIO/dynamorio/core/fragment.c:872
#6 fragment_add (dcontext=0x7f14cc9900, f=) at /home/travis/build/DynamoRIO/dynamorio/core/fragment.c:2975
#7 0x0000000071059efc in emit_fragment_common (dcontext=dcontext@entry=0x7f14cc9900, tag=0x200000001 <error: Cannot access memory at address 0x200000001>, tag@entry=0x3028a30 "\202\n@\371C", ilist=0x7115a000 <reg_names+544>, flags=, vmlist=0x3028a30, link_fragment=false, link_fragment@entry=255, add_to_htable=false, add_to_htable@entry=true, replace_fragment=0x7f14cc9900, replace_fragment@entry=0x0) at /home/travis/build/DynamoRIO/dynamorio/core/emit.c:810
#8 0x0000000071059f48 in emit_fragment_ex (dcontext=dcontext@entry=0x7f14cc9900, tag=tag@entry=0x3028a30 "\202\n@\371C", ilist=, flags=, vmlist=, link=link@entry=255, visible=visible@entry=true) at /home/travis/build/DynamoRIO/dynamorio/core/emit.c:864
#9 0x000000007110232c in build_basic_block_fragment (dcontext=dcontext@entry=0x7f14cc9900, start=0x3028a30 "\202\n@\371C", initial_flags=initial_flags@entry=0, link=255, link@entry=true, visible=visible@entry=true, for_trace=for_trace@entry=false, unmangled_ilist=unmangled_ilist@entry=0x0) at /home/travis/build/DynamoRIO/dynamorio/core/arch/interp.c:5167
#10 0x0000000071057668 in d_r_dispatch (dcontext=0x7f14cc9900) at /home/travis/build/DynamoRIO/dynamorio/core/dispatch.c:214
#11 0x0000000003028a30 in ?? ()
Also, strace shows an above average time spent in sched_yield.
Derek Bruening told me to do some profiling in https://github.com/DynamoRIO/dynamorio/issues/4278 Please tell me what you need to know.