llvm-project icon indicating copy to clipboard operation
llvm-project copied to clipboard

BOLT crashes with -update-debug-sections on clang.

Open rlavaee opened this issue 2 years ago • 16 comments

llvm-bolt crashes when optimizing clang binary built with -DLLVM_BUILD_TYPE=RelWithDebInfo. Stacktrace is included below:

BOLT-INFO: shared object or position-independent executable detected
BOLT-INFO: Target architecture: x86_64
BOLT-INFO: BOLT version: 3f028c02ba6a24b7230fd5907a2b7ba076664a8b
BOLT-INFO: first alloc address is 0x0
BOLT-INFO: enabling relocation mode
BOLT-INFO: enabling lite mode
BOLT-WARNING: Failed to analyze 4027 relocations
BOLT-INFO: pre-processing profile using YAML profile reader
BOLT-INFO: forcing -jump-tables=move as PIC jump table was detected in function _ZN5clang13TreeTransformIN12_GLOBAL__N_120TemplateInstantiatorEE25TransformCXXNamedCastExprEPNS_16CXXNamedCastExprE.__uniq.55632760368638704870153814335850836202/1(*2)
BOLT-WARNING: 2 collisions detected while hashing binary objects. Use -v=1 to see the list.
BOLT-INFO: 10328 out of 137230 functions in the binary (7.5%) have non-empty execution profile
BOLT-INFO: 504 functions with profile could not be optimized
BOLT-INFO: the input contains 7820 (dynamic count : 475973) opportunities for macro-fusion optimization. Will fix instances on a hot path.
BOLT-INFO: 670206 instructions were shortened
BOLT-INFO: removed 1673 empty blocks
BOLT-INFO: ICF folded 733 out of 137545 functions in 4 passes. 1 functions had jump tables.
BOLT-INFO: Removing all identical functions will save 114.34 KB of code space. Folded functions were called 137574 times based on profile.
BOLT-INFO: simplified 178 out of 4471 loads from a statically computed address.
BOLT-INFO: dynamic loads simplified: 4828
BOLT-INFO: dynamic loads found: 86157
BOLT-INFO: inlined 1193 calls at 68 call sites in 2 iteration(s). Change in binary size: 113 bytes.
BOLT-INFO: 9050 PLT calls in the binary were optimized.
BOLT-INFO: basic block reordering modified layout of 7061 (5.16%) functions
BOLT-INFO: UCE removed 1 blocks and 7 bytes of code.
BOLT-INFO: splitting separates 11625846 hot bytes from 7895664 cold bytes (59.55% of split functions is hot).
BOLT-INFO: 176 Functions were reordered by LoopInversionPass
BOLT-INFO: hfsort+ reduced the number of chains from 10098 to 1125
BOLT-INFO: program-wide dynostats after all optimizations before SCTC and FOP:

            26368242 : executed forward branches
             3451088 : taken forward branches
             5197677 : executed backward branches
             2926258 : taken backward branches
             1636564 : executed unconditional branches
             2141777 : all function calls
              730319 : indirect calls
              351324 : PLT calls
           214479309 : executed instructions
            53996055 : executed load instructions
            27601931 : executed store instructions
              289730 : taken jump table branches
                   0 : taken unknown indirect branches
            33202483 : total branches
             8013910 : taken branches
            25188573 : non-taken conditional branches
             6377346 : taken conditional branches
            31565919 : all conditional branches

            25066576 : executed forward branches (-4.9%)
             1517139 : taken forward branches (-56.0%)
             6499343 : executed backward branches (+25.0%)
             2791736 : taken backward branches (-4.6%)
             1155686 : executed unconditional branches (-29.4%)
             1789661 : all function calls (-16.4%)
              730319 : indirect calls (=)
                   0 : PLT calls (-100.0%)
           212861320 : executed instructions (-0.8%)
            53991570 : executed load instructions (-0.0%)
            27601932 : executed store instructions (+0.0%)
              289730 : taken jump table branches (=)
                   0 : taken unknown indirect branches (=)
            32721605 : total branches (-1.4%)
             5464561 : taken branches (-31.8%)
            27257044 : non-taken conditional branches (+8.2%)
             4308875 : taken conditional branches (-32.4%)
            31565919 : all conditional branches (=)

BOLT-INFO: SCTC: patched 27 tail calls (25 forward) tail calls (2 backward) from a total of 29 while removing 2 double jumps and removing 21 basic blocks totalling 105 bytes of code. CTCs total execution count is 1298 and the number of times CTCs are taken is 1269.
 #0 0x0000000000f5b863 llvm::sys::PrintStackTrace(llvm::raw_ostream&, int) (DIR/source/llvm-project/relwithdeb/stage1/install/bin/llvm-bolt+0xf5b863)
 #1 0x0000000000f597dc llvm::sys::RunSignalHandlers() (DIR/source/llvm-project/relwithdeb/stage1/install/bin/llvm-bolt+0xf597dc)
 #2 0x0000000000f5bcea SignalHandler(int) Signals.cpp:0:0
 #3 0x00007f23fd456200 __restore_rt (/lib/x86_64-linux-gnu/libpthread.so.0+0x12200)
 #4 0x0000000001ba352b llvm::bolt::BinaryContext::addDebugFilenameToUnit(unsigned int, unsigned int, unsigned int) (DIR/source/llvm-project/relwithdeb/stage1/install/bin/llvm-bolt+0x1ba352b)
 #5 0x0000000001bb394d (anonymous namespace)::BinaryEmitter::emitFunctionBody(llvm::bolt::BinaryFunction&, bool, bool) BinaryEmitter.cpp:0:0
 #6 0x0000000001bb4895 (anonymous namespace)::BinaryEmitter::emitFunction(llvm::bolt::BinaryFunction&, bool) BinaryEmitter.cpp:0:0
 #7 0x0000000001bb428b (anonymous namespace)::BinaryEmitter::emitFunctions()::$_3::operator()(std::vector<llvm::bolt::BinaryFunction*, std::allocator<llvm::bolt::BinaryFunction*>> const&) const BinaryEmitter.cpp:0:0
 #8 0x0000000001bb2472 llvm::bolt::emitBinaryContext(llvm::MCStreamer&, llvm::bolt::BinaryContext&, llvm::StringRef) (DIR/source/llvm-project/relwithdeb/stage1/install/bin/llvm-bolt+0x1bb2472)
 #9 0x0000000000fbd074 llvm::bolt::RewriteInstance::emitAndLink() (DIR/source/llvm-project/relwithdeb/stage1/install/bin/llvm-bolt+0xfbd074)
#10 0x0000000000fb54d0 llvm::bolt::RewriteInstance::run() (DIR/source/llvm-project/relwithdeb/stage1/install/bin/llvm-bolt+0xfb54d0)
#11 0x0000000000b31a6d main (DIR/source/llvm-project/relwithdeb/stage1/install/bin/llvm-bolt+0xb31a6d)
#12 0x00007f23fceac7fd __libc_start_main ./csu/../csu/libc-start.c:332:16
#13 0x0000000000b2fa0a _start (DIR/source/llvm-project/relwithdeb/stage1/install/bin/llvm-bolt+0xb2fa0a)
PLEASE submit a bug report to https://github.com/llvm/llvm-project/issues/ and include the crash backtrace.
Stack dump:
0.	Program arguments: DIR/source/llvm-project/relwithdeb/stage1/install/bin/llvm-bolt DIR/source/llvm-project/relwithdeb/pgo-labels/build/bin/clang-15 -o pgo-labels/build/bin/clang-15-bolt -b pgo-labels-compiler.yaml -reorder-blocks=ext-tsp -reorder-functions=hfsort+ -split-functions -update-debug-sections -split-all-cold -dyno-stats -icf=1 -use-gnu-stack -inline-small-functions -simplify-rodata-loads -plt=hot
Command terminated by signal 11
	Command being timed: "DIR/source/llvm-project/relwithdeb/stage1/install/bin/llvm-bolt DIR/source/llvm-project/relwithdeb/pgo-labels/build/bin/clang-15 -o pgo-labels/build/bin/clang-15-bolt -b pgo-labels-compiler.yaml -reorder-blocks=ext-tsp -reorder-functions=hfsort+ -split-functions -update-debug-sections -split-all-cold -dyno-stats -icf=1 -use-gnu-stack -inline-small-functions -simplify-rodata-loads -plt=hot”

rlavaee avatar Jun 29 '22 04:06 rlavaee

@llvm/issue-subscribers-bolt

llvmbot avatar Jun 29 '22 04:06 llvmbot

Is this with latest bolt from llvm trunk? How as clang built?

ayermolo avatar Jun 29 '22 22:06 ayermolo

Is this with latest bolt from llvm trunk?

Yes

How as clang built?

It's a PGO ThinLTO build with RelWithDebInfo and DLLVM_ENABLE_EH. cmake -G Ninja -DLLVM_OPTIMIZED_TABLEGEN=On -DCMAKE_BUILD_TYPE=RelWithDebInfo -DLLVM_ENABLE_EH=On -DLLVM_ENABLE_RTTI=On -DLLVM_ENABLE_LLD="On" -DCMAKE_LINKER="lld" -DLLVM_TARGETS_TO_BUILD="X86" -DCMAKE_C_COMPILER="stage1/install/bin/clang" -DCMAKE_CXX_COMPILER="stage1/install/bin/clang++" -DCMAKE_ASM_COMPILER="stage1/install/bin/clang" -DLLVM_PROFDATA_FILE=stage-pgo-relocs.profdata -DLLVM_ENABLE_LTO=Thin -DCMAKE_C_FLAGS="" -DCMAKE_CXX_FLAGS="" -DCMAKE_EXE_LINKER_FLAGS="-fuse-ld=lld -Wl,-q -Wl,-build-id" -DCMAKE_SHARED_LINKER_FLAGS="-fuse-ld=lld -Wl,-q -Wl,-build-id" -DCMAKE_MODULE_LINKER_FLAGS="-fuse-ld=lld -Wl,-q -Wl,-build-id" -DLLVM_ENABLE_PROJECTS="clang;compiler-rt;lld" copt/source/llvm-project/llvm

rlavaee avatar Jun 30 '22 17:06 rlavaee

Can you try again with trunk BOLT? I landed a fix for DWARF5 that might help here.

ayermolo avatar Aug 02 '22 01:08 ayermolo

I think I might have gotten something similar to this bug?

Without -update-debug-sections, this works:

$ /home/lofty/llvm-project/llvm-install/bin/llvm-bolt -instrument /home/lofty/test/yukari/target/x86_64-unknown-linux-gnu/release/yukari --instrumentation-file-append-pid --instrumentation-file /home/lofty/test/yukari/target/bolt-profiles/yukari/profile -o /home/lofty/test/yukari/target/x86_64-unknown-linux-gnu/release/yukari-bolt-instrumented
BOLT-INFO: shared object or position-independent executable detected
BOLT-INFO: Target architecture: x86_64
BOLT-INFO: BOLT version: 6bb51bf06214af3690af7034f4edeb265732c481
BOLT-INFO: first alloc address is 0x0
BOLT-INFO: creating new program header table at address 0x200000, offset 0x200000
BOLT-WARNING: debug info will be stripped from the binary. Use -update-debug-sections to keep it.
BOLT-INFO: enabling relocation mode
BOLT-INFO: forcing -jump-tables=move for instrumentation
BOLT-INFO: enabling -align-macro-fusion=all since no profile was specified
BOLT-INFO: enabling lite mode
BOLT-INSTRUMENTER: Number of indirect call site descriptors: 794
BOLT-INSTRUMENTER: Number of indirect call target descriptors: 450
BOLT-INSTRUMENTER: Number of function descriptors: 450
BOLT-INSTRUMENTER: Number of branch counters: 7191
BOLT-INSTRUMENTER: Number of ST leaf node counters: 4013
BOLT-INSTRUMENTER: Number of direct call counters: 870
BOLT-INSTRUMENTER: Total number of counters: 12074
BOLT-INSTRUMENTER: Total size of counters: 96592 bytes (static alloc memory)
BOLT-INSTRUMENTER: Total size of string table emitted: 42289 bytes in file
BOLT-INSTRUMENTER: Total size of descriptors: 649540 bytes in file
BOLT-INSTRUMENTER: Profile will be saved to file /home/lofty/test/yukari/target/bolt-profiles/yukari/profile
BOLT-INFO: 0 out of 496 functions in the binary (0.0%) have non-empty execution profile
BOLT-INFO: the input contains 99 (dynamic count : 0) opportunities for macro-fusion optimization that are going to be fixed
BOLT-INFO: 4912 instructions were shortened
BOLT-INFO: removed 41 empty blocks
BOLT-INFO: UCE removed 309 blocks and 18719 bytes of code.
BOLT-INFO: SCTC: patched 0 tail calls (0 forward) tail calls (0 backward) from a total of 0 while removing 0 double jumps and removing 0 basic blocks totalling 0 bytes of code. CTCs total execution count is 0 and the number of times CTCs are taken is 0.
BOLT-INFO: output linked against instrumentation runtime library, lib entry point is 0x4d7dc0
BOLT-INFO: clear procedure is 0x4d6c10
BOLT-INFO: setting _end to 0x4b298c
BOLT-INFO: patched build-id (flipped last bit)

With -update-debug-sections it crashes:

$ /home/lofty/llvm-project/llvm-install/bin/llvm-bolt -instrument /home/lofty/test/yukari/target/x86_64-unknown-linux-gnu/release/yukari --instrumentation-file-append-pid --instrumentation-file /home/lofty/test/yukari/target/bolt-profiles/yukari/profile -update-debug-sections -o /home/lofty/test/yukari/target/x86_64-unknown-linux-gnu/release/yukari-bolt-instrumented
BOLT-INFO: shared object or position-independent executable detected
BOLT-INFO: Target architecture: x86_64
BOLT-INFO: BOLT version: 6bb51bf06214af3690af7034f4edeb265732c481
BOLT-INFO: first alloc address is 0x0
BOLT-INFO: creating new program header table at address 0x200000, offset 0x200000
BOLT-INFO: enabling relocation mode
BOLT-INFO: forcing -jump-tables=move for instrumentation
BOLT-INFO: enabling -align-macro-fusion=all since no profile was specified
BOLT-INFO: enabling lite mode
BOLT-INSTRUMENTER: Number of indirect call site descriptors: 794
BOLT-INSTRUMENTER: Number of indirect call target descriptors: 450
BOLT-INSTRUMENTER: Number of function descriptors: 450
BOLT-INSTRUMENTER: Number of branch counters: 7191
BOLT-INSTRUMENTER: Number of ST leaf node counters: 4013
BOLT-INSTRUMENTER: Number of direct call counters: 870
BOLT-INSTRUMENTER: Total number of counters: 12074
BOLT-INSTRUMENTER: Total size of counters: 96592 bytes (static alloc memory)
BOLT-INSTRUMENTER: Total size of string table emitted: 42289 bytes in file
BOLT-INSTRUMENTER: Total size of descriptors: 649540 bytes in file
BOLT-INSTRUMENTER: Profile will be saved to file /home/lofty/test/yukari/target/bolt-profiles/yukari/profile
BOLT-INFO: 0 out of 496 functions in the binary (0.0%) have non-empty execution profile
BOLT-INFO: the input contains 99 (dynamic count : 0) opportunities for macro-fusion optimization that are going to be fixed
BOLT-INFO: 4912 instructions were shortened
BOLT-INFO: removed 41 empty blocks
BOLT-INFO: UCE removed 309 blocks and 18719 bytes of code.
BOLT-INFO: SCTC: patched 0 tail calls (0 forward) tail calls (0 backward) from a total of 0 while removing 0 double jumps and removing 0 basic blocks totalling 0 bytes of code. CTCs total execution count is 0 and the number of times CTCs are taken is 0.
BOLT-INFO: output linked against instrumentation runtime library, lib entry point is 0x4d7dc0
BOLT-INFO: clear procedure is 0x4d6c10
BOLT-ERROR: skeleton CU at 0x54b does not have DW_AT_GNU_ranges_base or DW_AT_low_pc to convert to update ranges base
BOLT-ERROR: skeleton CU at 0x5b870 does not have DW_AT_GNU_ranges_base or DW_AT_low_pc to convert to update ranges base
 #0 0x000055ab2c06d9e1 llvm::sys::PrintStackTrace(llvm::raw_ostream&, int) /home/lofty/llvm-project/llvm/lib/Support/Unix/Signals.inc:573:3
 #1 0x000055ab2c06bbd4 llvm::sys::RunSignalHandlers() /home/lofty/llvm-project/llvm/lib/Support/Signals.cpp:103:20
 #2 0x000055ab2c06bd46 SignalHandler(int) /home/lofty/llvm-project/llvm/lib/Support/Unix/Signals.inc:407:1
 #3 0x00007fe182580a40 (/usr/lib/libc.so.6+0x38a40)
 #4 0x000055ab2cc63786 llvm::bolt::DebugAddrWriterDwarf5::getOffset(llvm::DWARFUnit&) /home/lofty/llvm-project/bolt/lib/Core/DebugData.cpp:495:16
 #5 0x000055ab2c10bc11 llvm::bolt::DWARFRewriter::finalizeDebugSections(llvm::bolt::DebugInfoBinaryPatcher&) /home/lofty/llvm-project/bolt/lib/Rewrite/DWARFRewriter.cpp:1036:7
 #6 0x000055ab2c117de2 llvm::bolt::DWARFRewriter::updateDebugInfo() /home/lofty/llvm-project/bolt/lib/Rewrite/DWARFRewriter.cpp:348:3
 #7 0x000055ab2c0d8228 llvm::TimeRegion::~TimeRegion() /home/lofty/llvm-project/llvm/include/llvm/Support/Timer.h:157:9
 #8 0x000055ab2c0d8228 llvm::NamedRegionTimer::~NamedRegionTimer() /home/lofty/llvm-project/llvm/include/llvm/Support/Timer.h:165:8
 #9 0x000055ab2c0d8228 llvm::bolt::RewriteInstance::updateMetadata() /home/lofty/llvm-project/bolt/lib/Rewrite/RewriteInstance.cpp:3214:3
#10 0x000055ab2c10120e llvm::bolt::RewriteInstance::run() /home/lofty/llvm-project/bolt/lib/Rewrite/RewriteInstance.cpp:758:3
#11 0x000055ab2bb9fc12 llvm::Error::getPtr() const /home/lofty/llvm-project/llvm/include/llvm/Support/Error.h:274:12
#12 0x000055ab2bb9fc12 llvm::Error::operator bool() /home/lofty/llvm-project/llvm/include/llvm/Support/Error.h:234:22
#13 0x000055ab2bb9fc12 main /home/lofty/llvm-project/bolt/tools/driver/llvm-bolt.cpp:244:29
#14 0x00007fe18256b2d0 (/usr/lib/libc.so.6+0x232d0)
#15 0x00007fe18256b38a __libc_start_main (/usr/lib/libc.so.6+0x2338a)
#16 0x000055ab2bc16705 _start /build/glibc/src/glibc/csu/../sysdeps/x86_64/start.S:117:0
PLEASE submit a bug report to https://github.com/llvm/llvm-project/issues/ and include the crash backtrace.
Stack dump:
0.      Program arguments: /home/lofty/llvm-project/llvm-install/bin/llvm-bolt -instrument /home/lofty/test/yukari/target/x86_64-unknown-linux-gnu/release/yukari --instrumentation-file-append-pid --instrumentation-file /home/lofty/test/yukari/target/bolt-profiles/yukari/profile -update-debug-sections -o /home/lofty/test/yukari/target/x86_64-unknown-linux-gnu/release/yukari-bolt-instrumented
Segmentation fault

BOLT was built with cmake -S llvm -B build -G Ninja -DCMAKE_BUILD_TYPE=RelWithDebInfo -DCMAKE_INSTALL_PREFIX=${PWD}/llvm-install -DLLVM_ENABLE_PROJECTS="bolt" -DLLVM_TARGETS_TO_BUILD="X86"

I can provide the binary if necessary.

Ravenslofty avatar Aug 08 '22 19:08 Ravenslofty

@Ravenslofty Is this with llvm top of the trunk bolt? If you could provide a small repro hat would be great.

ayermolo avatar Aug 08 '22 20:08 ayermolo

BOLT-INFO: shared object or position-independent executable detected
BOLT-INFO: Target architecture: x86_64
BOLT-INFO: BOLT version: 6b3bc7cd3c6f56a63f97e71dc236b2281d98d9d1
BOLT-INFO: first alloc address is 0x0
BOLT-INFO: creating new program header table at address 0x200000, offset 0x200000
BOLT-INFO: enabling relocation mode
BOLT-INFO: forcing -jump-tables=move for instrumentation
BOLT-INFO: enabling -align-macro-fusion=all since no profile was specified
BOLT-INFO: enabling lite mode
BOLT-INSTRUMENTER: Number of indirect call site descriptors: 794
BOLT-INSTRUMENTER: Number of indirect call target descriptors: 450
BOLT-INSTRUMENTER: Number of function descriptors: 450
BOLT-INSTRUMENTER: Number of branch counters: 7191
BOLT-INSTRUMENTER: Number of ST leaf node counters: 4013
BOLT-INSTRUMENTER: Number of direct call counters: 870
BOLT-INSTRUMENTER: Total number of counters: 12074
BOLT-INSTRUMENTER: Total size of counters: 96592 bytes (static alloc memory)
BOLT-INSTRUMENTER: Total size of string table emitted: 42289 bytes in file
BOLT-INSTRUMENTER: Total size of descriptors: 649540 bytes in file
BOLT-INSTRUMENTER: Profile will be saved to file /home/lofty/test/yukari/target/bolt-profiles/yukari/profile
BOLT-INFO: 0 out of 496 functions in the binary (0.0%) have non-empty execution profile
BOLT-INFO: the input contains 99 (dynamic count : 0) opportunities for macro-fusion optimization that are going to be fixed
BOLT-INFO: 4912 instructions were shortened
BOLT-INFO: removed 41 empty blocks
BOLT-INFO: UCE removed 309 blocks and 18719 bytes of code.
BOLT-INFO: SCTC: patched 0 tail calls (0 forward) tail calls (0 backward) from a total of 0 while removing 0 double jumps and removing 0 basic blocks totalling 0 bytes of code. CTCs total execution count is 0 and the number of times CTCs are taken is 0.
BOLT-INFO: output linked against instrumentation runtime library, lib entry point is 0x4d7dc0
BOLT-INFO: clear procedure is 0x4d6c10
BOLT-ERROR: skeleton CU at 0x54b does not have DW_AT_GNU_ranges_base or DW_AT_low_pc to convert to update ranges base
BOLT-ERROR: skeleton CU at 0x5b870 does not have DW_AT_GNU_ranges_base or DW_AT_low_pc to convert to update ranges base
 #0 0x0000564d736a1411 llvm::sys::PrintStackTrace(llvm::raw_ostream&, int) /home/lofty/llvm-project/llvm/lib/Support/Unix/Signals.inc:573:3
 #1 0x0000564d7369f644 llvm::sys::RunSignalHandlers() /home/lofty/llvm-project/llvm/lib/Support/Signals.cpp:103:20
 #2 0x0000564d7369f7b6 SignalHandler(int) /home/lofty/llvm-project/llvm/lib/Support/Unix/Signals.inc:407:1
 #3 0x00007fb00a74da40 (/usr/lib/libc.so.6+0x38a40)
 #4 0x0000564d7429ab76 llvm::bolt::DebugAddrWriterDwarf5::getOffset(llvm::DWARFUnit&) /home/lofty/llvm-project/bolt/lib/Core/DebugData.cpp:495:16
 #5 0x0000564d737409c5 llvm::bolt::DWARFRewriter::finalizeDebugSections(llvm::bolt::DebugInfoBinaryPatcher&) /home/lofty/llvm-project/bolt/lib/Rewrite/DWARFRewriter.cpp:1036:7
 #6 0x0000564d7374cdd2 llvm::bolt::DWARFRewriter::updateDebugInfo() /home/lofty/llvm-project/bolt/lib/Rewrite/DWARFRewriter.cpp:348:3
 #7 0x0000564d7370d058 llvm::TimeRegion::~TimeRegion() /home/lofty/llvm-project/llvm/include/llvm/Support/Timer.h:157:9
 #8 0x0000564d7370d058 llvm::NamedRegionTimer::~NamedRegionTimer() /home/lofty/llvm-project/llvm/include/llvm/Support/Timer.h:165:8
 #9 0x0000564d7370d058 llvm::bolt::RewriteInstance::updateMetadata() /home/lofty/llvm-project/bolt/lib/Rewrite/RewriteInstance.cpp:3214:3
#10 0x0000564d7373629e llvm::bolt::RewriteInstance::run() /home/lofty/llvm-project/bolt/lib/Rewrite/RewriteInstance.cpp:758:3
#11 0x0000564d731d3bfd llvm::Error::getPtr() const /home/lofty/llvm-project/llvm/include/llvm/Support/Error.h:274:12
#12 0x0000564d731d3bfd llvm::Error::operator bool() /home/lofty/llvm-project/llvm/include/llvm/Support/Error.h:234:22
#13 0x0000564d731d3bfd main /home/lofty/llvm-project/bolt/tools/driver/llvm-bolt.cpp:244:29
#14 0x00007fb00a7382d0 (/usr/lib/libc.so.6+0x232d0)
#15 0x00007fb00a73838a __libc_start_main (/usr/lib/libc.so.6+0x2338a)
#16 0x0000564d7324a2f5 _start /build/glibc/src/glibc/csu/../sysdeps/x86_64/start.S:117:0
PLEASE submit a bug report to https://github.com/llvm/llvm-project/issues/ and include the crash backtrace.
Stack dump:
0.      Program arguments: /home/lofty/llvm-project/llvm-install/bin/llvm-bolt -instrument /home/lofty/test/yukari/target/x86_64-unknown-linux-gnu/release/yukari --instrumentation-file-append-pid --instrumentation-file /home/lofty/test/yukari/target/bolt-profiles/yukari/profile -update-debug-sections -o /home/lofty/test/yukari/target/x86_64-unknown-linux-gnu/release/yukari-bolt-instrumented
Segmentation fault

This is latest BOLT, as far as I can tell.

Unfortunately I don't know how to reproduce this with Clang, but I can reproduce it with Rust:

$ rustup install nightly-2022-08-06
[snip]
$ cargo +nightly-2022-08-06 new --bin hello; cd hello
$ RUSTFLAGS="-Clink-args=-Wl,-q" cargo +nightly-2022-08-06 build --release
[snip]
$ llvm-bolt -instrument target/release/hello --instrumentation-file-append-pid --instrumentation-file profile -update-debug-sections -o target/release/hello-bolt-instrumented
BOLT-INFO: shared object or position-independent executable detected
BOLT-INFO: Target architecture: x86_64
BOLT-INFO: BOLT version: 6b3bc7cd3c6f56a63f97e71dc236b2281d98d9d1
BOLT-INFO: first alloc address is 0x0
BOLT-INFO: creating new program header table at address 0x200000, offset 0x200000
BOLT-INFO: enabling relocation mode
BOLT-INFO: forcing -jump-tables=move for instrumentation
BOLT-INFO: enabling -align-macro-fusion=all since no profile was specified
BOLT-INFO: enabling lite mode
BOLT-WARNING: Failed to analyze 97 relocations
BOLT-INSTRUMENTER: Number of indirect call site descriptors: 1691
BOLT-INSTRUMENTER: Number of indirect call target descriptors: 501
BOLT-INSTRUMENTER: Number of function descriptors: 501
BOLT-INSTRUMENTER: Number of branch counters: 5266
BOLT-INSTRUMENTER: Number of ST leaf node counters: 3251
BOLT-INSTRUMENTER: Number of direct call counters: 468
BOLT-INSTRUMENTER: Total number of counters: 8985
BOLT-INSTRUMENTER: Total size of counters: 71880 bytes (static alloc memory)
BOLT-INSTRUMENTER: Total size of string table emitted: 45440 bytes in file
BOLT-INSTRUMENTER: Total size of descriptors: 479884 bytes in file
BOLT-INSTRUMENTER: Profile will be saved to file profile
BOLT-INFO: 0 out of 550 functions in the binary (0.0%) have non-empty execution profile
BOLT-INFO: the input contains 65 (dynamic count : 0) opportunities for macro-fusion optimization that are going to be fixed
BOLT-INFO: 3511 instructions were shortened
BOLT-INFO: removed 19 empty blocks
BOLT-INFO: UCE removed 224 blocks and 13541 bytes of code.
BOLT-INFO: SCTC: patched 0 tail calls (0 forward) tail calls (0 backward) from a total of 0 while removing 0 double jumps and removing 0 basic blocks totalling 0 bytes of code. CTCs total execution count is 0 and the number of times CTCs are taken is 0.
BOLT-INFO: output linked against instrumentation runtime library, lib entry point is 0x4abda0
BOLT-INFO: clear procedure is 0x4aabf0
BOLT-ERROR: skeleton CU at 0x54b does not have DW_AT_GNU_ranges_base or DW_AT_low_pc to convert to update ranges base
BOLT-ERROR: skeleton CU at 0xdab3b does not have DW_AT_GNU_ranges_base or DW_AT_low_pc to convert to update ranges base
 #0 0x000055b304442411 llvm::sys::PrintStackTrace(llvm::raw_ostream&, int) /home/lofty/llvm-project/llvm/lib/Support/Unix/Signals.inc:573:3
 #1 0x000055b304440644 llvm::sys::RunSignalHandlers() /home/lofty/llvm-project/llvm/lib/Support/Signals.cpp:103:20
 #2 0x000055b3044407b6 SignalHandler(int) /home/lofty/llvm-project/llvm/lib/Support/Unix/Signals.inc:407:1
 #3 0x00007f67f6521a40 (/usr/lib/libc.so.6+0x38a40)
 #4 0x000055b30503bb76 llvm::bolt::DebugAddrWriterDwarf5::getOffset(llvm::DWARFUnit&) /home/lofty/llvm-project/bolt/lib/Core/DebugData.cpp:495:16
 #5 0x000055b3044e19c5 llvm::bolt::DWARFRewriter::finalizeDebugSections(llvm::bolt::DebugInfoBinaryPatcher&) /home/lofty/llvm-project/bolt/lib/Rewrite/DWARFRewriter.cpp:1036:7
 #6 0x000055b3044eddd2 llvm::bolt::DWARFRewriter::updateDebugInfo() /home/lofty/llvm-project/bolt/lib/Rewrite/DWARFRewriter.cpp:348:3
 #7 0x000055b3044ae058 llvm::TimeRegion::~TimeRegion() /home/lofty/llvm-project/llvm/include/llvm/Support/Timer.h:157:9
 #8 0x000055b3044ae058 llvm::NamedRegionTimer::~NamedRegionTimer() /home/lofty/llvm-project/llvm/include/llvm/Support/Timer.h:165:8
 #9 0x000055b3044ae058 llvm::bolt::RewriteInstance::updateMetadata() /home/lofty/llvm-project/bolt/lib/Rewrite/RewriteInstance.cpp:3214:3
#10 0x000055b3044d729e llvm::bolt::RewriteInstance::run() /home/lofty/llvm-project/bolt/lib/Rewrite/RewriteInstance.cpp:758:3
#11 0x000055b303f74bfd llvm::Error::getPtr() const /home/lofty/llvm-project/llvm/include/llvm/Support/Error.h:274:12
#12 0x000055b303f74bfd llvm::Error::operator bool() /home/lofty/llvm-project/llvm/include/llvm/Support/Error.h:234:22
#13 0x000055b303f74bfd main /home/lofty/llvm-project/bolt/tools/driver/llvm-bolt.cpp:244:29
#14 0x00007f67f650c2d0 (/usr/lib/libc.so.6+0x232d0)
#15 0x00007f67f650c38a __libc_start_main (/usr/lib/libc.so.6+0x2338a)
#16 0x000055b303feb2f5 _start /build/glibc/src/glibc/csu/../sysdeps/x86_64/start.S:117:0
PLEASE submit a bug report to https://github.com/llvm/llvm-project/issues/ and include the crash backtrace.
Stack dump:
0.      Program arguments: llvm-bolt -instrument target/release/hello --instrumentation-file-append-pid --instrumentation-file profile -update-debug-sections -o target/release/hello-bolt-instrumented
Segmentation fault

Ravenslofty avatar Aug 08 '22 22:08 Ravenslofty

OK. Yeah I guess if you can share a small binary (and rust code along with build command) that generated it, that would be great. Also can you post llvm-dwarfdump of skeleton CU?

Thanks

ayermolo avatar Aug 08 '22 22:08 ayermolo

Rust code:

fn main() {
    println!("Hello, world!");
}

Build command was RUSTFLAGS="-Clink-args=-Wl,-q" cargo +nightly-2022-08-06 build --release as above.

llvm-dwarfdump:

0x0000054b: DW_TAG_compile_unit
              DW_AT_stmt_list   (0x00000111)
              DW_AT_ranges      (0x0000000c
                 [0x0000000000006000, 0x0000000000006016)
                 [0x000000000003daf8, 0x000000000003db00))
              DW_AT_name        ("../sysdeps/x86_64/crti.S")
              DW_AT_comp_dir    ("/build/glibc/src/glibc/csu")
              DW_AT_producer    ("GNU AS 2.38")
              DW_AT_language    (DW_LANG_Mips_Assembler)
0x00000562: Compile Unit: length = 0x0009680b, format = DWARF32, version = 0x0004, abbr_offset = 0x0186, addr_size = 0x08 (next unit at 0x00096d71)

0x000daa75: DW_TAG_compile_unit
              DW_AT_stmt_list   (0x00060a21)
              DW_AT_ranges      (0x0000002d
                 [0x0000000000006016, 0x000000000000601b)
                 [0x000000000003db00, 0x000000000003db05))
              DW_AT_name        ("../sysdeps/x86_64/crtn.S")
              DW_AT_comp_dir    ("/build/glibc/src/glibc/csu")
              DW_AT_producer    ("GNU AS 2.38")
              DW_AT_language    (DW_LANG_Mips_Assembler)

binary: hello.zip

Ravenslofty avatar Aug 08 '22 23:08 Ravenslofty

If it came from rust, why is DW_AT_language is DW_LANG_Mips_Assembler?

ayermolo avatar Aug 08 '22 23:08 ayermolo

We normally link in libgcc rather than duplicating the work, by simply invoking gcc and asking it to link things, precisely because we would rather not try to outwit anyone, bypassing linkers which know a system's layout better than we do, and cause problems. The producer is GNU AS, as noted, not Rust.

I assume these are https://github.com/bminor/glibc/blob/master/sysdeps/x86_64/crti.S https://github.com/bminor/glibc/blob/master/sysdeps/x86_64/crtn.S

I have no idea why the DW_AT_language is marked as a MIPS assembler, but I would first assume that is either GNU AS deciding to have a sense of humor or the llvm-dwarfdump misparsing it. It's not impossible it's us at fault, but we really are trying to not do anything so clever as to break that.

workingjubilee avatar Aug 08 '22 23:08 workingjubilee

repro on my system:

llvm-dwarfdump /usr/lib/libgcc_s.so.1


# first we get a bunch of other items, then
0x0001ea2b:   NULL
0x0001ea2c: Compile Unit: length = 0x0000001f, format = DWARF32, version = 0x0005, unit_type = DW_UT_compile, abbr_offset = 0x8cd1, addr_size = 0x08 (next unit at 0x0001ea4f)

0x0001ea38: DW_TAG_compile_unit
              DW_AT_stmt_list	(0x00015bc1)
              DW_AT_ranges	(0x000033d7
                 [0x0000000000003016, 0x000000000000301b)
                 [0x00000000000197a0, 0x00000000000197a5))
              DW_AT_name	("../sysdeps/x86_64/crtn.S")
              DW_AT_comp_dir	("/build/glibc/src/glibc/csu")
              DW_AT_producer	("GNU AS 2.38")
              DW_AT_language	(DW_LANG_Mips_Assembler)

So yes, llvm-dwarfdump really does think the GNU AS emitted libgcc_s code is marked as coming from a MIPS assembler. Perhaps it's even right.

workingjubilee avatar Aug 09 '22 00:08 workingjubilee

I installed libdwarf and asked what it thinks of libgcc_s.so.1, and it says:

dwarfdump /usr/lib/libgcc_s.so.1

#...a lot of text and...
COMPILE_UNIT<header overall offset = 0x0001ea2c>:
< 0><0x0000000c>  DW_TAG_compile_unit
                    DW_AT_stmt_list             0x00015bbb
                    DW_AT_ranges                0x000033d7

      Offset of rnglists entries: 0x000033d7
      [ 0] start,end             0x00003016 0x0000301b
      [ 1] start,end             0x000197a0 0x000197a5
      [ 2] end of list                                
                    DW_AT_name                  ../sysdeps/x86_64/crtn.S
                    DW_AT_comp_dir              /build/glibc/src/glibc/csu
                    DW_AT_producer              GNU AS 2.38
                    DW_AT_language              DW_LANG_Mips_Assembler


arange starts at 0x00003016, length of 0x00000005, cu_die_offset = 0x0001ea38
arange starts at 0x000197a0, length of 0x00000005, cu_die_offset = 0x0001ea38
arange end

.debug_frame is not present

Seemingly universal agreement. "Sir, are you classified as ~~human~~ Rust?" "Uhhh. Negative. I am a ~~meat popsicle~~ MIPS assembler." https://www.youtube.com/watch?v=8Dd_qiuWxPs

workingjubilee avatar Aug 09 '22 01:08 workingjubilee

I went ahead and checked the DWARF5 Standard and there is no DW_LANG_Mips_Assembler formally encoded in the DWARF5 Standard. By recognizing such, both llvm-dwarfdump and dwarfdump have extended the DWARF Standard. Now, this may in fact be a quite, ahem, "standard" extension, but we can now safely dismiss its relevance. On top of being the responsibility of libgcc, it is clearly some sort of in-joke between GCC and LLVM, and not relevant to this issue.

workingjubilee avatar Aug 09 '22 03:08 workingjubilee

Ah ok. Thanks for looking into it. I added this to my queue of things to look into.

ayermolo avatar Aug 09 '22 18:08 ayermolo

I can't reproduce this using LLVM tree revision 6b3bc7cd3c6f56a63f97e71dc236b2281d98d9d1 and Rust nightly-2022-08-06. I wonder if the problem is specific to your distro's linker.

pcwalton avatar Aug 16 '22 23:08 pcwalton

An update. Found few issues related to how gcc generates debug info. https://reviews.llvm.org/D132087 Will publish another diff later today, once I can construct small test that works with llvm toolchain.

ayermolo avatar Aug 19 '22 18:08 ayermolo

Landed https://reviews.llvm.org/D132422 hello example now works locally.

ayermolo avatar Aug 26 '22 00:08 ayermolo

Going to close it. Please re-open or file a new issue as applicable.

ayermolo avatar Aug 30 '22 00:08 ayermolo