BOLT icon indicating copy to clipboard operation
BOLT copied to clipboard

BOLTed bin core loss detail line and function debug info

Open zpget opened this issue 4 years ago • 11 comments

BOLTed bin core, loss detail core line info (gdb) bt #0 0x00007f921d1d5d0d in nanosleep () at ../sysdeps/unix/syscall-template.S:81 #1 0x00007f921d1ff9d4 in usleep (useconds=) at ../sysdeps/unix/sysv/linux/usleep.c:32 #2 0x0000000002578bd7 in ?? () #3 0x00000000023f495a in PutPidFileIfNeeded() () #4 0x0000000000d91263 in main ()

but Orign bin core, has full line and function info

#0 0x00007f921d1d5d0d in nanosleep () at ../sysdeps/unix/syscall-template.S:81 #1 0x00007f921d1ff9d4 in usleep (useconds=) at ../sysdeps/unix/sysv/linux/usleep.c:32 #2 0x0000000002578bd7 in get_or_new_task_control () at xxxx.cpp:91 #3 timer_add (id=0x7ffe9bd06260, abstime=..., on_timer=0x7ffe9bd06258, arg=0x7ffe9bd06380) at xxxx/thread.cpp:350 #4 0x00000000023f495a in ExpandPath (path=...) at xxx/server.cpp:1618 #5 PutPidFileIfNeeded (this=0x408be28 GlobalInitializer::init()::log_plugin) at xxx/server.cpp:1627 #6 0x0000000000d91263 in main (argc=, argv=) at xxx/main.cpp:72

zpget avatar Nov 10 '20 12:11 zpget

Are you using -update-debug-sections option when running BOLT?

maksfb avatar Nov 10 '20 19:11 maksfb

yes , add -update-debug-sections

my cmd: LD_PRELOAD=./libjemalloc.so llvm-bolt -enable-bat=1 bin -o bin.bolt -data perf.fdata -align-macro-fusion=all -reorder-blocks=cache+ -reorder-functions=hfsort+ -split-functions=3 -split-all-cold -split-eh -dyno-stats -icf=1 -update-debug-sections

llvm-bolt run info:

BOLT-INFO: BOLT version: f137ed238db11440f03083b1c88b7ffc0f4af65e BOLT-INFO: first alloc address is 0x400000 BOLT-INFO: creating new program header table at address 0x5200000, offset 0x4e00000 BOLT-INFO: enabling relocation mode BOLT-INFO: enabling lite mode BOLT-WARNING: __stop_malloc_hook (0x2dc78a2) does not have any section BOLT-WARNING: __stop_google_malloc (0x2dca287) does not have any section BOLT-INFO: pre-processing profile using branch profile reader BOLT-INFO: profile collection done on a binary already processed by BOLT BOLT-INFO: forcing -jump-tables=move as PIC jump table was detected in function _ZN10microvideo3grcL12murmurhash64EPKvim.constprop.3152/1(*2) BOLT-WARNING: 2 collisions detected while hashing binary objects. Use -v=1 to see the list. BOLT-INFO: 3725 out of 76392 functions in the binary (4.9%) have non-empty execution profile BOLT-INFO: 70 functions with profile could not be optimized BOLT-WARNING: 41 (1.1% of all profiled) functions have invalid (possibly stale) profile. Use -report-stale to see the list. BOLT-WARNING: 301539933 out of 1132239642 samples in the binary (26.6%) belong to functions with invalid (possibly stale) profile. BOLT-INFO: profile for 14 objects was ignored BOLT-INFO: the input contains 1238 (dynamic count : 20964311) opportunities for macro-fusion optimization that are going to be fixed BOLT-INFO: removed 1 'repz' prefixes with estimated execution count of 28404 times. BOLT-INFO: ICF folded 143 out of 77056 functions in 3 passes. 0 functions had jump tables. BOLT-INFO: Removing all identical functions will save 48.21 KB of code space. Folded functions were called 0 times based on profile. BOLT-INFO: basic block reordering modified layout of 2588 (3.36%) functions BOLT-INFO: UCE removed 0 blocks and 0 bytes of code. BOLT-INFO: splitting separates 1333013 hot bytes from 2327992 cold bytes (36.41% of split functions is hot). BOLT-INFO: running hfsort+ for 3795 functions BOLT-INFO: program-wide dynostats after all optimizations before SCTC and FOP:

       464665447 : executed forward branches
       107960199 : taken forward branches
       165252933 : executed backward branches
       102999200 : taken backward branches
        38489515 : executed unconditional branches
       101826586 : all function calls
        27566578 : indirect calls
        20335893 : PLT calls
      3725504020 : executed instructions
       956481848 : executed load instructions
       424968037 : executed store instructions
          148204 : taken jump table branches
               0 : taken unknown indirect branches
       668407895 : total branches
       249448914 : taken branches
       418958981 : non-taken conditional branches
       210959399 : taken conditional branches
       629918380 : all conditional branches

       479568846 : executed forward branches (+3.2%)
        13496556 : taken forward branches (-87.5%)
       150349534 : executed backward branches (-9.0%)
        93581833 : taken backward branches (-9.1%)
        20552068 : executed unconditional branches (-46.6%)
       101826586 : all function calls (=)
        27566578 : indirect calls (=)
        20335893 : PLT calls (=)
      3706446048 : executed instructions (-0.5%)
       956481848 : executed load instructions (=)
       424968037 : executed store instructions (=)
          148204 : taken jump table branches (=)
               0 : taken unknown indirect branches (=)
       650470448 : total branches (-2.7%)
       127630457 : taken branches (-48.8%)
       522839991 : non-taken conditional branches (+24.8%)
       107078389 : taken conditional branches (-49.2%)
       629918380 : all conditional branches (=)

BOLT-INFO: SCTC: patched 40 tail calls (39 forward) tail calls (1 backward) from a total of 40 while removing 0 double jumps and removing 33 basic blocks totalling 165 bytes of code. CTCs total execution count is 14083289 and the number of times CTCs are taken is 0. BOLT-WARNING: empty location list detected at 0x390369 for DIE at 0x62cb8d in CU at 0x48006f BOLT-WARNING: empty location list detected at 0x396bf7 for DIE at 0x63b3a2 in CU at 0x48006f BOLT-WARNING: empty location list detected at 0x3a6757 for DIE at 0x654381 in CU at 0x48006f BOLT-WARNING: empty location list detected at 0x3a8370 for DIE at 0x655543 in CU at 0x48006f

zpget avatar Nov 11 '20 02:11 zpget

Are you running the latest (top of the trunk) BOLT?

maksfb avatar Nov 11 '20 02:11 maksfb

yes, git pull the latest code commit 3c0c3752ca92812deaab0d8fa588e3559e5dde00 (HEAD -> master, origin/master, origin/HEAD) Author: Amir Ayupov [email protected] Date: Mon Nov 9 12:38:51 2020 -0800

zpget avatar Nov 11 '20 03:11 zpget

This is very unusual. When you run the program under gdb, does it provide you with source info? Does gdb give any warnings?

maksfb avatar Nov 11 '20 03:11 maksfb

gcc 8.2 gdb info: [New LWP 31812] [New LWP 31800] [Thread debugging using libthread_db enabled] Using host libthread_db library "/opt/compiler/gcc-8.2/lib/libthread_db.so.1". Core was generated by `bin/deck'. Program terminated with signal SIGSEGV, Segmentation fault. #0 0x00007fc463eecd0d in nanosleep () at ../sysdeps/unix/syscall-template.S:81 81 ../sysdeps/unix/syscall-template.S: No such file or directory. [Current thread is 1 (Thread 0x7fc463e2f6c0 (LWP 31764))] (gdb) bt #0 0x00007fc463eecd0d in nanosleep () at ../sysdeps/unix/syscall-template.S:81 #1 0x00007fc463f169d4 in usleep (useconds=) at ../sysdeps/unix/sysv/linux/usleep.c:32 #2 0x00000000054a2a0f in thusleep () #3 0x00000000054a28a3 in RunUntilAskedToQuit() () #4 0x0000000000d91263 in main ()

zpget avatar Nov 11 '20 03:11 zpget

#2-#4 miss source code line info

zpget avatar Nov 11 '20 03:11 zpget

Can you repro with a small program on your system using the same environment?

maksfb avatar Nov 11 '20 19:11 maksfb

Does gdb output contain a line with Reading symbols from <binary>...?

maksfb avatar Nov 12 '20 08:11 maksfb

Does gdb output contain a line with Reading symbols from <binary>...?

yes

bot trans has warning

BOLT-WARNING: high_pc expected immediately after low_pc. Cannot update DIE at offset 0x3bd5c524 BOLT-WARNING: high_pc expected immediately after low_pc. Cannot update DIE at offset 0x3bd5c888

zpget avatar Nov 12 '20 09:11 zpget

It will be helpful to know if you can repro with a small program in your environment.

maksfb avatar Nov 14 '20 21:11 maksfb