Very slow symbolizer invocation in libfuzzer with Go c-archive library #152459
Description
I have a relatively simple fuzzing tool using libfuzzer. It is fuzzing C++ and Go code. The Go code is built to the "c-archive" with go build -buildmode=c-archive -tags=libfuzzer -gcflags=-d=libfuzzer. All seems to work correctly, except the moment the libfuzzer needs the function names (e.g. to print a stack trace or to focus a function or to report new functions covered) there is a big minutes long pause.
My investigation lead me to the llvm-symbolizer subprocess invocation. The below is libfuzzer output with UBSAN verbosity increased. The second module with 2 PCs seems to be the Go code.
export UBSAN_OPTIONS=verbosity=4
fuzz ../corpus -use_value_profile=1 -focus_function=FUNC -runs=0
==145033==Using llvm-symbolizer found at: /usr/bin/llvm-symbolizer-21
==145033==Installed the sigaction for signal 11
==145033==Installed the sigaction for signal 7
==145033==Installed the sigaction for signal 8
INFO: Seed: 32135115
INFO: Loaded 2 modules (11211 inline 8-bit counters): 11209 [0x5f4829450bf2, 0x5f48294537bb), 2 [0x5f4829e18e00, 0x5f4829e18e02),
INFO: Loaded 2 PC tables (11211 PCs): 11209 [0x5f48294537c0,0x5f482947f450), 2 [0xc00001a120,0xc00001a140),
INFO: 224 files found in ../corpus
==145033==Launching Symbolizer process: /usr/bin/llvm-symbolizer-21 --demangle --inlines --default-arch=x86_64
(PAUSE)
ERROR: Failed to set focus function. Make sure the function name is valid (FUNC) and symbolization is enabled.
However, I'm not sure the llvm-symbolizer is slow. Some perf tracing suggest this is the subprocess management. According to perf record mostly of the time is spent on closing file descriptors.
94.97% 19.76% fuzz fuzz [.] __sanitizer::internal_close(int)
|
|--89.99%--__sanitizer::internal_close(int)
| |
| |--32.39%--entry_SYSCALL_64_after_hwframe
| | |
| | |--26.76%--do_syscall_64
| | | |
| | | |--12.98%--x64_sys_call
| | | | |
| | | | |--10.60%--__x64_sys_close
| | | | | |
| | | | | |--6.06%--_raw_spin_lock
| | | | | |
| | | | | |--2.44%--file_close_fd
| | | | | | |
| | | | | | --0.52%--file_close_fd_locked
| | | | | |
| | | | | |--0.90%--file_close_fd_locked
| | | | | |
| | | | | --0.58%--_raw_spin_unlock
| | | | |
| | | | --0.53%--file_close_fd
| | | |
| | | |--7.25%--syscall_exit_to_user_mode
| | | | |
| | | | |--3.34%--arch_exit_to_user_mode_prepare.isra.0
| | | | | |
| | | | | --0.66%--fpregs_assert_state_consistent
| | | | |
| | | | |--1.26%--syscall_exit_to_user_mode_prepare
| | | | |
| | | | --0.65%--fpregs_assert_state_consistent
| | | |
| | | |--1.16%--arch_exit_to_user_mode_prepare.isra.0
| | | |
| | | --0.58%--syscall_exit_to_user_mode_prepare
| | |
| | --0.71%--syscall_exit_to_user_mode
| |
| |--28.62%--entry_SYSCALL_64
| |
| |--5.53%--entry_SYSRETQ_unsafe_stack
| |
| |--1.71%--syscall_return_via_sysret
| |
| |--1.36%--entry_SYSCALL_64_safe_stack
| |
| --0.68%--do_syscall_64
|
--4.99%--__sanitizer::StartSubprocess(char const*, char const* const*, char const* const*, int, int, int)
The llvm-symbolizer run is only 2% if I interpret the perf report correctly.
1.97% 0.00% llvm-symbolizer llvm-symbolizer [.] 0x0000564172f90db5
|
---0x564172f90db5
__libc_start_main@@GLIBC_2.34
__libc_start_call_main
0x564172f977c3
|
--1.86%--0x564172f927e6
0x564172f941a6
0x564172f95622
llvm::symbolize::LLVMSymbolizer::symbolizeInlinedCode(llvm::StringRef, llvm::object::SectionedAddress)
llvm::Expected<llvm::DIInliningInfo> llvm::symbolize::LLVMSymbolizer::symbolizeInlinedCodeCommon<llvm::StringRef>(llvm::StringRef const&, llvm::object::SectionedAddress)
|
--1.82%--llvm::symbolize::SymbolizableObjectFile::symbolizeInlinedCode(llvm::object::SectionedAddress, llvm::DILineInfoSpecifier, bool) const
llvm::DWARFContext::getInliningInfoForAddress(llvm::object::SectionedAddress, llvm::DILineInfoSpecifier)
|
--1.61%--llvm::DWARFUnit::getInlinedChainForAddress(unsigned long, llvm::SmallVectorImpl<llvm::DWARFDie>&)
llvm::DWARFUnit::getSubroutineForAddress(unsigned long)
|
|--1.03%--llvm::DWARFUnit::tryExtractDIEsIfNeeded(bool)
| |
| --1.01%--llvm::DWARFUnit::extractDIEsToVector(bool, bool, std::vector<llvm::DWARFDebugInfoEntry, std::allocator<llvm::DWARFDebugInfoEntry> >&) const
|
--0.58%--llvm::DWARFUnit::updateAddressDieMap(llvm::DWARFDie)
llvm::DWARFUnit::updateAddressDieMap(llvm::DWARFDie)
|
--0.51%--llvm::DWARFUnit::updateAddressDieMap(llvm::DWARFDie)