This is an automated email from the ASF dual-hosted git repository. yiguolei pushed a commit to branch branch-2.0 in repository https://gitbox.apache.org/repos/asf/doris.git
The following commit(s) were added to refs/heads/branch-2.0 by this push: new 6f87f1767dd [branch-2.0](stacktrace) Optimize stack trace output (#25362) 6f87f1767dd is described below commit 6f87f1767dd60dd8c578d0dae0ce6f5d7b5fefd5 Author: Xinyi Zou <zouxiny...@gmail.com> AuthorDate: Thu Oct 12 20:38:55 2023 +0800 [branch-2.0](stacktrace) Optimize stack trace output (#25362) * [opt](stacktrace) Optimize stacktrace output #22467 * [fix](stacktrace) Temporary fix ARM and MacOS stacktrace #23650 * [fix](stack trace) Optimize stack trace output (#24933) Status prints the stack trace, the first four frame pointers are removed, it doesn't make sense. Optimize stack trace field order. example: 0# doris::PlanFragmentExecutor::cancel(doris::PPlanFragmentCancelReason const&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&) at doris/core/be/src/common/status.h:0 1# doris::FragmentMgr::cancel_query_unlocked(doris::TUniqueId const&, doris::PPlanFragmentCancelReason const&, std::unique_lock<std::mutex> const&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&) at doris/cor e/be/src/runtime/fragment_mgr.cpp:984 2# doris::FragmentMgr::cancel_query(doris::TUniqueId const&, doris::PPlanFragmentCancelReason const&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&) at doris/ldb_toolchain/bin/../lib/gcc/x86_64-linux-gnu/11/ ../../../../include/x86_64-linux-gnu/c++/11/bits/gthr-default.h:778 3# long doris::MemTrackerLimiter::free_top_memory_query<doris::MemTrackerLimiter::TrackerLimiterGroup>(long, doris::MemTrackerLimiter::Type, std::vector<doris::MemTrackerLimiter::TrackerLimiterGroup, std::allocator<doris::MemTrackerLimiter::TrackerLimiterGroup> >&, s td::function<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > (long, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&)> const&, doris::RuntimeProfile*) at doris/ldb_toolchain/bin/../ lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/basic_string.h:187 4# doris::MemTrackerLimiter::free_top_memory_query(long, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, doris::RuntimeProfile*, doris::Mem TrackerLimiter::Type) at doris/core/be/src/runtime/memory/mem_tracker_limiter.cpp:362 5# doris::MemInfo::process_full_gc() at doris/core/be/src/util/mem_info.cpp:198 6# doris::Daemon::memory_gc_thread() at doris/core/be/src/common/daemon.cpp:0 7# doris::Thread::supervise_thread(void*) at doris/ldb_toolchain/bin/../usr/include/pthread.h:562 8# start_thread 9# __clone * fix format --- be/src/common/config.cpp | 1 + be/src/common/config.h | 6 +++ be/src/common/stack_trace.cpp | 86 +++++++++++++++++++++++++++--------------- be/src/common/stack_trace.h | 2 +- be/src/common/status.h | 2 +- be/src/util/stack_util.cpp | 8 ++-- be/src/util/stack_util.h | 4 +- thirdparty/build-thirdparty.sh | 6 +-- 8 files changed, 73 insertions(+), 42 deletions(-) diff --git a/be/src/common/config.cpp b/be/src/common/config.cpp index b6cf2a3ba8f..c299e2a8e3e 100644 --- a/be/src/common/config.cpp +++ b/be/src/common/config.cpp @@ -1046,6 +1046,7 @@ DEFINE_Bool(allow_invalid_decimalv2_literal, "false"); DEFINE_mInt64(kerberos_expiration_time_seconds, "43200"); DEFINE_mString(get_stack_trace_tool, "libunwind"); +DEFINE_mString(dwarf_location_info_mode, "FAST"); // the ratio of _prefetch_size/_batch_size in AutoIncIDBuffer DEFINE_mInt64(auto_inc_prefetch_size_ratio, "10"); diff --git a/be/src/common/config.h b/be/src/common/config.h index 82f8369f611..443f2773057 100644 --- a/be/src/common/config.h +++ b/be/src/common/config.h @@ -1093,6 +1093,12 @@ DECLARE_mInt64(kerberos_expiration_time_seconds); // Values include `none`, `glog`, `boost`, `glibc`, `libunwind` DECLARE_mString(get_stack_trace_tool); +// DISABLED: Don't resolve location info. +// FAST: Perform CU lookup using .debug_aranges (might be incomplete). +// FULL: Scan all CU in .debug_info (slow!) on .debug_aranges lookup failure. +// FULL_WITH_INLINE: Scan .debug_info (super slower, use with caution) for inline functions in addition to FULL. +DECLARE_mString(dwarf_location_info_mode); + // the ratio of _prefetch_size/_batch_size in AutoIncIDBuffer DECLARE_mInt64(auto_inc_prefetch_size_ratio); diff --git a/be/src/common/stack_trace.cpp b/be/src/common/stack_trace.cpp index 1174fff0749..a6768517943 100644 --- a/be/src/common/stack_trace.cpp +++ b/be/src/common/stack_trace.cpp @@ -34,6 +34,7 @@ #include <unordered_map> #include "config.h" +#include "util/string_util.h" #include "vec/common/demangle.h" #include "vec/common/hex.h" @@ -48,14 +49,14 @@ namespace { /// But we use atomic just in case, so it is possible to be modified at runtime. std::atomic<bool> show_addresses = true; -#if defined(__ELF__) && !defined(__FreeBSD__) -void writePointerHex(const void* ptr, std::stringstream& buf) { - buf.write("0x", 2); - char hex_str[2 * sizeof(ptr)]; - doris::vectorized::write_hex_uint_lowercase(reinterpret_cast<uintptr_t>(ptr), hex_str); - buf.write(hex_str, 2 * sizeof(ptr)); -} -#endif +// #if defined(__ELF__) && !defined(__FreeBSD__) +// void writePointerHex(const void* ptr, std::stringstream& buf) { +// buf.write("0x", 2); +// char hex_str[2 * sizeof(ptr)]; +// doris::vectorized::write_hex_uint_lowercase(reinterpret_cast<uintptr_t>(ptr), hex_str); +// buf.write(hex_str, 2 * sizeof(ptr)); +// } +// #endif bool shouldShowAddress(const void* addr) { /// If the address is less than 4096, most likely it is a nullptr dereference with offset, @@ -344,7 +345,7 @@ constexpr bool operator<(const MaybeRef auto& left, const MaybeRef auto& right) std::tuple {right.pointers, right.size, right.offset}; } -static void toStringEveryLineImpl([[maybe_unused]] bool fatal, +static void toStringEveryLineImpl([[maybe_unused]] const std::string dwarf_location_info_mode, const StackTraceRefTriple& stack_trace, std::function<void(std::string_view)> callback) { if (stack_trace.size == 0) { @@ -353,7 +354,20 @@ static void toStringEveryLineImpl([[maybe_unused]] bool fatal, #if defined(__ELF__) && !defined(__FreeBSD__) using enum doris::Dwarf::LocationInfoMode; - const auto mode = fatal ? FULL_WITH_INLINE : FAST; + doris::Dwarf::LocationInfoMode mode; + auto dwarf_location_info_mode_lower = doris::to_lower(dwarf_location_info_mode); + if (dwarf_location_info_mode_lower == "disabled") { + mode = DISABLED; + } else if (dwarf_location_info_mode_lower == "fast") { + mode = FAST; + } else if (dwarf_location_info_mode_lower == "full") { + mode = FULL; + } else if (dwarf_location_info_mode_lower == "full_with_inline") { + mode = FULL_WITH_INLINE; + } else { + LOG(INFO) << "invalid LocationInfoMode: " << dwarf_location_info_mode; + mode = DISABLED; + } auto symbol_index_ptr = doris::SymbolIndex::instance(); const doris::SymbolIndex& symbol_index = *symbol_index_ptr; std::unordered_map<std::string, doris::Dwarf> dwarfs; @@ -366,7 +380,16 @@ static void toStringEveryLineImpl([[maybe_unused]] bool fatal, reinterpret_cast<const void*>(uintptr_t(virtual_addr) - virtual_offset); std::stringstream out; - out << i << ". "; + out << "\t" << i << "# "; + if (i < 10) { // for alignment + out << " "; + } + + if (const auto* const symbol = symbol_index.findSymbol(virtual_addr)) { + out << collapseNames(demangle(symbol->name)); + } else { + out << "?"; + } if (std::error_code ec; object && std::filesystem::exists(object->name, ec) && !ec) { auto dwarf_it = dwarfs.try_emplace(object->name, object->elf).first; @@ -375,31 +398,26 @@ static void toStringEveryLineImpl([[maybe_unused]] bool fatal, if (dwarf_it->second.findAddress(uintptr_t(physical_addr), location, mode, inline_frames)) { - out << location.file.toString() << ":" << location.line << ": "; + out << " at " << location.file.toString() << ":" << location.line; } } - if (const auto* const symbol = symbol_index.findSymbol(virtual_addr)) { - out << collapseNames(demangle(symbol->name)); - } else { - out << "?"; - } + // Do not display the stack address and file name, it is not important. + // if (shouldShowAddress(physical_addr)) { + // out << " @ "; + // writePointerHex(physical_addr, out); + // } - if (shouldShowAddress(physical_addr)) { - out << " @ "; - writePointerHex(physical_addr, out); - } + // out << " in " << (object ? object->name : "?"); - out << " in " << (object ? object->name : "?"); + callback(out.str()); for (size_t j = 0; j < inline_frames.size(); ++j) { const auto& frame = inline_frames[j]; - callback(fmt::format("{}.{}. inlined from {}:{}: {}", i, j + 1, - frame.location.file.toString(), frame.location.line, - collapseNames(demangle(frame.name)))); + callback(fmt::format("\t{}.{}. inlined from {}: {}:{}", i, j + 1, + collapseNames(demangle(frame.name)), + frame.location.file.toString(), frame.location.line)); } - - callback(out.str()); } #else for (size_t i = stack_trace.offset; i < stack_trace.size; ++i) @@ -409,7 +427,7 @@ static void toStringEveryLineImpl([[maybe_unused]] bool fatal, } void StackTrace::toStringEveryLine(std::function<void(std::string_view)> callback) const { - toStringEveryLineImpl(true, {frame_pointers, offset, size}, std::move(callback)); + toStringEveryLineImpl("FULL_WITH_INLINE", {frame_pointers, offset, size}, std::move(callback)); } using StackTraceCache = std::map<StackTraceTriple, std::string, std::less<>>; @@ -434,14 +452,20 @@ std::string toStringCached(const StackTrace::FramePointers& pointers, size_t off return it->second; } else { std::stringstream out; - toStringEveryLineImpl(false, key, [&](std::string_view str) { out << str << '\n'; }); + toStringEveryLineImpl(doris::config::dwarf_location_info_mode, key, + [&](std::string_view str) { out << str << '\n'; }); return cache.emplace(StackTraceTriple {pointers, offset, size}, out.str()).first->second; } } -std::string StackTrace::toString() const { - return toStringCached(frame_pointers, offset, size); +std::string StackTrace::toString(int start_pointers_index) const { + // Default delete the first three frame pointers, which are inside the stack_trace.cpp. + start_pointers_index += 3; + StackTrace::FramePointers frame_pointers_raw {}; + std::copy(frame_pointers.begin() + start_pointers_index, frame_pointers.end(), + frame_pointers_raw.begin()); + return toStringCached(frame_pointers_raw, offset, size - start_pointers_index); } std::string StackTrace::toString(void** frame_pointers_raw, size_t offset, size_t size) { diff --git a/be/src/common/stack_trace.h b/be/src/common/stack_trace.h index 7e6ae14a4c7..b28d7293724 100644 --- a/be/src/common/stack_trace.h +++ b/be/src/common/stack_trace.h @@ -73,7 +73,7 @@ public: [[nodiscard]] constexpr size_t getSize() const { return size; } [[nodiscard]] constexpr size_t getOffset() const { return offset; } [[nodiscard]] const FramePointers& getFramePointers() const { return frame_pointers; } - [[nodiscard]] std::string toString() const; + [[nodiscard]] std::string toString(int start_pointers_index = 0) const; static std::string toString(void** frame_pointers, size_t offset, size_t size); static void dropCache(); diff --git a/be/src/common/status.h b/be/src/common/status.h index 1dd7fa175b2..b15876f7168 100644 --- a/be/src/common/status.h +++ b/be/src/common/status.h @@ -381,7 +381,7 @@ public: } #ifdef ENABLE_STACKTRACE if (stacktrace && capture_stacktrace(code)) { - status._err_msg->_stack = get_stack_trace(); + status._err_msg->_stack = get_stack_trace(1); LOG(WARNING) << "meet error status: " << status; // may print too many stacks. } #endif diff --git a/be/src/util/stack_util.cpp b/be/src/util/stack_util.cpp index 5aa4df16c21..ef21f3f010d 100644 --- a/be/src/util/stack_util.cpp +++ b/be/src/util/stack_util.cpp @@ -35,7 +35,7 @@ void DumpStackTraceToString(std::string* stacktrace); namespace doris { -std::string get_stack_trace() { +std::string get_stack_trace(int start_pointers_index) { #ifdef ENABLE_STACKTRACE auto tool = config::get_stack_trace_tool; if (tool == "glog") { @@ -48,7 +48,7 @@ std::string get_stack_trace() { #if defined(__APPLE__) // TODO return get_stack_trace_by_glog(); #endif - return get_stack_trace_by_libunwind(); + return get_stack_trace_by_libunwind(start_pointers_index); } else { return "no stack"; } @@ -80,8 +80,8 @@ std::string get_stack_trace_by_glibc() { return out.str(); } -std::string get_stack_trace_by_libunwind() { - return StackTrace().toString(); +std::string get_stack_trace_by_libunwind(int start_pointers_index) { + return "\n" + StackTrace().toString(start_pointers_index); } } // namespace doris diff --git a/be/src/util/stack_util.h b/be/src/util/stack_util.h index e33e6f02f5d..65b2d8bad2f 100644 --- a/be/src/util/stack_util.h +++ b/be/src/util/stack_util.h @@ -29,7 +29,7 @@ namespace doris { // boost: 1000 times cost 1min, has line numbers, but has memory leak. // glibc: 1000 times cost 1min, no line numbers, unresolved backtrace symbol. // libunwind: cost is negligible, has line numbers. -std::string get_stack_trace(); +std::string get_stack_trace(int start_pointers_index = 0); // Note: there is a libc bug that causes this not to work on 64 bit machines // for recursive calls. @@ -53,6 +53,6 @@ std::string get_stack_trace_by_glibc(); // 2. Support signal handle // 3. libunwid support unw_backtrace for jemalloc // 4. Use of undefined compile option USE_MUSL for later -std::string get_stack_trace_by_libunwind(); +std::string get_stack_trace_by_libunwind(int start_pointers_index); } // namespace doris diff --git a/thirdparty/build-thirdparty.sh b/thirdparty/build-thirdparty.sh index e156500bcc6..2a911ed27bb 100755 --- a/thirdparty/build-thirdparty.sh +++ b/thirdparty/build-thirdparty.sh @@ -1438,9 +1438,9 @@ build_jemalloc() { # libunwind build_libunwind() { - # https://github.com/libunwind/libunwind - # https://github.com/libunwind/libunwind/issues/189 - # https://stackoverflow.com/questions/27842377/building-libunwind-for-mac + # There are two major variants of libunwind. libunwind on Linux + # (https://www.nongnu.org/libunwind/) provides unw_backtrace, and + # Apache/LLVM libunwind (notably used on Apple platforms) doesn't if [[ "${KERNEL}" != 'Darwin' ]]; then check_if_source_exist "${LIBUNWIND_SOURCE}" cd "${TP_SOURCE_DIR}/${LIBUNWIND_SOURCE}" --------------------------------------------------------------------- To unsubscribe, e-mail: commits-unsubscr...@doris.apache.org For additional commands, e-mail: commits-h...@doris.apache.org