Index: lldb/trunk/include/lldb/Core/Timer.h =================================================================== --- lldb/trunk/include/lldb/Core/Timer.h +++ lldb/trunk/include/lldb/Core/Timer.h @@ -37,10 +37,23 @@ class Timer { public: + class Category { + public: + explicit Category(const char *category_name); + + private: + friend class Timer; + const char *m_name; + std::atomic m_nanos; + std::atomic m_next; + + DISALLOW_COPY_AND_ASSIGN(Category); + }; + //-------------------------------------------------------------- /// Default constructor. //-------------------------------------------------------------- - Timer(const char *category, const char *format, ...) + Timer(Category &category, const char *format, ...) __attribute__((format(printf, 3, 4))); //-------------------------------------------------------------- @@ -62,7 +75,7 @@ using TimePoint = std::chrono::steady_clock::time_point; void ChildDuration(TimePoint::duration dur) { m_child_duration += dur; } - const char *m_category; + Category &m_category; TimePoint m_total_start; TimePoint::duration m_child_duration{0}; Index: lldb/trunk/source/API/SystemInitializerFull.cpp =================================================================== --- lldb/trunk/source/API/SystemInitializerFull.cpp +++ lldb/trunk/source/API/SystemInitializerFull.cpp @@ -400,7 +400,8 @@ } void SystemInitializerFull::Terminate() { - Timer scoped_timer(LLVM_PRETTY_FUNCTION, LLVM_PRETTY_FUNCTION); + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, LLVM_PRETTY_FUNCTION); Debugger::SettingsTerminate(); Index: lldb/trunk/source/Commands/CommandObjectTarget.cpp =================================================================== --- lldb/trunk/source/Commands/CommandObjectTarget.cpp +++ lldb/trunk/source/Commands/CommandObjectTarget.cpp @@ -269,8 +269,8 @@ } const char *file_path = command.GetArgumentAtIndex(0); - Timer scoped_timer(LLVM_PRETTY_FUNCTION, "(lldb) target create '%s'", - file_path); + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, "(lldb) target create '%s'", file_path); FileSpec file_spec; if (file_path) Index: lldb/trunk/source/Core/Disassembler.cpp =================================================================== --- lldb/trunk/source/Core/Disassembler.cpp +++ lldb/trunk/source/Core/Disassembler.cpp @@ -59,7 +59,8 @@ DisassemblerSP Disassembler::FindPlugin(const ArchSpec &arch, const char *flavor, const char *plugin_name) { - Timer scoped_timer(LLVM_PRETTY_FUNCTION, + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, "Disassembler::FindPlugin (arch = %s, plugin_name = %s)", arch.GetArchitectureName(), plugin_name); @@ -1460,4 +1461,3 @@ lldb_private::OperandMatchers::MatchOpType(Instruction::Operand::Type type) { return [type](const Instruction::Operand &op) { return op.m_type == type; }; } - Index: lldb/trunk/source/Core/Mangled.cpp =================================================================== --- lldb/trunk/source/Core/Mangled.cpp +++ lldb/trunk/source/Core/Mangled.cpp @@ -258,8 +258,8 @@ // haven't already decoded our mangled name. if (m_mangled && !m_demangled) { // We need to generate and cache the demangled name. - Timer scoped_timer(LLVM_PRETTY_FUNCTION, - "Mangled::GetDemangledName (m_mangled = %s)", + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, "Mangled::GetDemangledName (m_mangled = %s)", m_mangled.GetCString()); Log *log = lldb_private::GetLogIfAllCategoriesSet(LIBLLDB_LOG_DEMANGLE); Index: lldb/trunk/source/Core/Module.cpp =================================================================== --- lldb/trunk/source/Core/Module.cpp +++ lldb/trunk/source/Core/Module.cpp @@ -429,8 +429,8 @@ size_t Module::GetNumCompileUnits() { std::lock_guard guard(m_mutex); - Timer scoped_timer(LLVM_PRETTY_FUNCTION, - "Module::GetNumCompileUnits (module = %p)", + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, "Module::GetNumCompileUnits (module = %p)", static_cast(this)); SymbolVendor *symbols = GetSymbolVendor(); if (symbols) @@ -453,7 +453,8 @@ bool Module::ResolveFileAddress(lldb::addr_t vm_addr, Address &so_addr) { std::lock_guard guard(m_mutex); - Timer scoped_timer(LLVM_PRETTY_FUNCTION, + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, "Module::ResolveFileAddress (vm_addr = 0x%" PRIx64 ")", vm_addr); SectionList *section_list = GetSectionList(); @@ -616,7 +617,8 @@ uint32_t resolve_scope, SymbolContextList &sc_list) { std::lock_guard guard(m_mutex); - Timer scoped_timer(LLVM_PRETTY_FUNCTION, + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, "Module::ResolveSymbolContextForFilePath (%s:%u, " "check_inlines = %s, resolve_scope = 0x%8.8x)", file_spec.GetPath().c_str(), line, @@ -987,7 +989,8 @@ const CompilerDeclContext *parent_decl_ctx, bool append, size_t max_matches, llvm::DenseSet &searched_symbol_files, TypeMap &types) { - Timer scoped_timer(LLVM_PRETTY_FUNCTION, LLVM_PRETTY_FUNCTION); + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, LLVM_PRETTY_FUNCTION); if (!sc.module_sp || sc.module_sp.get() == this) { SymbolVendor *symbols = GetSymbolVendor(); if (symbols) @@ -1078,7 +1081,8 @@ if (!m_did_load_symbol_vendor.load() && can_create) { ObjectFile *obj_file = GetObjectFile(); if (obj_file != nullptr) { - Timer scoped_timer(LLVM_PRETTY_FUNCTION, LLVM_PRETTY_FUNCTION); + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, LLVM_PRETTY_FUNCTION); m_symfile_ap.reset( SymbolVendor::FindPlugin(shared_from_this(), feedback_strm)); m_did_load_symbol_vendor = true; @@ -1278,8 +1282,8 @@ if (!m_did_load_objfile.load()) { std::lock_guard guard(m_mutex); if (!m_did_load_objfile.load()) { - Timer scoped_timer(LLVM_PRETTY_FUNCTION, - "Module::GetObjectFile () module = %s", + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, "Module::GetObjectFile () module = %s", GetFileSpec().GetFilename().AsCString("")); DataBufferSP data_sp; lldb::offset_t data_offset = 0; @@ -1338,9 +1342,9 @@ const Symbol *Module::FindFirstSymbolWithNameAndType(const ConstString &name, SymbolType symbol_type) { + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); Timer scoped_timer( - LLVM_PRETTY_FUNCTION, - "Module::FindFirstSymbolWithNameAndType (name = %s, type = %i)", + func_cat, "Module::FindFirstSymbolWithNameAndType (name = %s, type = %i)", name.AsCString(), symbol_type); SymbolVendor *sym_vendor = GetSymbolVendor(); if (sym_vendor) { @@ -1372,7 +1376,8 @@ size_t Module::FindFunctionSymbols(const ConstString &name, uint32_t name_type_mask, SymbolContextList &sc_list) { - Timer scoped_timer(LLVM_PRETTY_FUNCTION, + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, "Module::FindSymbolsFunctions (name = %s, mask = 0x%8.8x)", name.AsCString(), name_type_mask); SymbolVendor *sym_vendor = GetSymbolVendor(); @@ -1390,9 +1395,9 @@ // No need to protect this call using m_mutex all other method calls are // already thread safe. + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); Timer scoped_timer( - LLVM_PRETTY_FUNCTION, - "Module::FindSymbolsWithNameAndType (name = %s, type = %i)", + func_cat, "Module::FindSymbolsWithNameAndType (name = %s, type = %i)", name.AsCString(), symbol_type); const size_t initial_size = sc_list.GetSize(); SymbolVendor *sym_vendor = GetSymbolVendor(); @@ -1413,8 +1418,9 @@ // No need to protect this call using m_mutex all other method calls are // already thread safe. + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); Timer scoped_timer( - LLVM_PRETTY_FUNCTION, + func_cat, "Module::FindSymbolsMatchingRegExAndType (regex = %s, type = %i)", regex.GetText().str().c_str(), symbol_type); const size_t initial_size = sc_list.GetSize(); Index: lldb/trunk/source/Core/Timer.cpp =================================================================== --- lldb/trunk/source/Core/Timer.cpp +++ lldb/trunk/source/Core/Timer.cpp @@ -27,8 +27,8 @@ #define TIMER_INDENT_AMOUNT 2 namespace { -typedef std::map TimerCategoryMap; typedef std::vector TimerStack; +static std::atomic g_categories; } // end of anonymous namespace std::atomic Timer::g_quiet(true); @@ -38,16 +38,6 @@ return *g_file_mutex_ptr; } -static std::mutex &GetCategoryMutex() { - static std::mutex g_category_mutex; - return g_category_mutex; -} - -static TimerCategoryMap &GetCategoryMap() { - static TimerCategoryMap g_category_map; - return g_category_map; -} - static void ThreadSpecificCleanup(void *p) { delete static_cast(p); } @@ -64,9 +54,17 @@ return (TimerStack *)timer_stack; } +Timer::Category::Category(const char *cat) : m_name(cat) { + m_nanos.store(0, std::memory_order_release); + Category *expected = g_categories; + do { + m_next = expected; + } while (!g_categories.compare_exchange_weak(expected, this)); +} + void Timer::SetQuiet(bool value) { g_quiet = value; } -Timer::Timer(const char *category, const char *format, ...) +Timer::Timer(Timer::Category &category, const char *format, ...) : m_category(category), m_total_start(std::chrono::steady_clock::now()) { TimerStack *stack = GetTimerStackForCurrentThread(); if (!stack) @@ -114,11 +112,7 @@ stack->back()->ChildDuration(total_dur); // Keep total results for each category so we can dump results. - { - std::lock_guard guard(GetCategoryMutex()); - TimerCategoryMap &category_map = GetCategoryMap(); - category_map[m_category] += timer_dur; - } + m_category.m_nanos += std::chrono::nanoseconds(timer_dur).count(); } void Timer::SetDisplayDepth(uint32_t depth) { g_display_depth = depth; } @@ -126,33 +120,32 @@ /* binary function predicate: * - returns whether a person is less than another person */ -static bool -CategoryMapIteratorSortCriterion(const TimerCategoryMap::const_iterator &lhs, - const TimerCategoryMap::const_iterator &rhs) { - return lhs->second > rhs->second; + +typedef std::pair TimerEntry; + +static bool CategoryMapIteratorSortCriterion(const TimerEntry &lhs, + const TimerEntry &rhs) { + return lhs.second > rhs.second; } void Timer::ResetCategoryTimes() { - std::lock_guard guard(GetCategoryMutex()); - TimerCategoryMap &category_map = GetCategoryMap(); - category_map.clear(); + for (Category *i = g_categories; i; i = i->m_next) + i->m_nanos.store(0, std::memory_order_release); } void Timer::DumpCategoryTimes(Stream *s) { - std::lock_guard guard(GetCategoryMutex()); - TimerCategoryMap &category_map = GetCategoryMap(); - std::vector sorted_iterators; - TimerCategoryMap::const_iterator pos, end = category_map.end(); - for (pos = category_map.begin(); pos != end; ++pos) { - sorted_iterators.push_back(pos); + std::vector sorted; + for (Category *i = g_categories; i; i = i->m_next) { + uint64_t nanos = i->m_nanos.load(std::memory_order_acquire); + if (nanos) + sorted.push_back(std::make_pair(i->m_name, nanos)); } - std::sort(sorted_iterators.begin(), sorted_iterators.end(), - CategoryMapIteratorSortCriterion); + if (sorted.empty()) + return; // Later code will break without any elements. - const size_t count = sorted_iterators.size(); - for (size_t i = 0; i < count; ++i) { - const auto timer = sorted_iterators[i]->second; - s->Printf("%.9f sec for %s\n", std::chrono::duration(timer).count(), - sorted_iterators[i]->first); - } + // Sort by time + std::sort(sorted.begin(), sorted.end(), CategoryMapIteratorSortCriterion); + + for (const auto &timer : sorted) + s->Printf("%.9f sec for %s\n", timer.second / 1000000000., timer.first); } Index: lldb/trunk/source/Host/common/Symbols.cpp =================================================================== --- lldb/trunk/source/Host/common/Symbols.cpp +++ lldb/trunk/source/Host/common/Symbols.cpp @@ -151,8 +151,9 @@ const ArchSpec *arch = module_spec.GetArchitecturePtr(); const UUID *uuid = module_spec.GetUUIDPtr(); + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); Timer scoped_timer( - LLVM_PRETTY_FUNCTION, + func_cat, "LocateExecutableSymbolFileDsym (file = %s, arch = %s, uuid = %p)", exec_fspec ? exec_fspec->GetFilename().AsCString("") : "", arch ? arch->GetArchitectureName() : "", (const void *)uuid); @@ -175,9 +176,9 @@ const FileSpec *exec_fspec = module_spec.GetFileSpecPtr(); const ArchSpec *arch = module_spec.GetArchitecturePtr(); const UUID *uuid = module_spec.GetUUIDPtr(); + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); Timer scoped_timer( - LLVM_PRETTY_FUNCTION, - "LocateExecutableObjectFile (file = %s, arch = %s, uuid = %p)", + func_cat, "LocateExecutableObjectFile (file = %s, arch = %s, uuid = %p)", exec_fspec ? exec_fspec->GetFilename().AsCString("") : "", arch ? arch->GetArchitectureName() : "", (const void *)uuid); Index: lldb/trunk/source/Initialization/SystemInitializerCommon.cpp =================================================================== --- lldb/trunk/source/Initialization/SystemInitializerCommon.cpp +++ lldb/trunk/source/Initialization/SystemInitializerCommon.cpp @@ -72,7 +72,8 @@ llvm::EnablePrettyStackTrace(); InitializeLog(); HostInfo::Initialize(); - Timer scoped_timer(LLVM_PRETTY_FUNCTION, LLVM_PRETTY_FUNCTION); + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, LLVM_PRETTY_FUNCTION); process_gdb_remote::ProcessGDBRemoteLog::Initialize(); @@ -102,7 +103,8 @@ } void SystemInitializerCommon::Terminate() { - Timer scoped_timer(LLVM_PRETTY_FUNCTION, LLVM_PRETTY_FUNCTION); + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, LLVM_PRETTY_FUNCTION); ObjectContainerBSDArchive::Terminate(); ObjectFileELF::Terminate(); ObjectFilePECOFF::Terminate(); Index: lldb/trunk/source/Interpreter/CommandInterpreter.cpp =================================================================== --- lldb/trunk/source/Interpreter/CommandInterpreter.cpp +++ lldb/trunk/source/Interpreter/CommandInterpreter.cpp @@ -169,7 +169,8 @@ } void CommandInterpreter::Initialize() { - Timer scoped_timer(LLVM_PRETTY_FUNCTION, LLVM_PRETTY_FUNCTION); + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, LLVM_PRETTY_FUNCTION); CommandReturnObject result; @@ -391,7 +392,8 @@ } void CommandInterpreter::LoadCommandDictionary() { - Timer scoped_timer(LLVM_PRETTY_FUNCTION, LLVM_PRETTY_FUNCTION); + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, LLVM_PRETTY_FUNCTION); lldb::ScriptLanguage script_language = m_debugger.GetScriptLanguage(); @@ -1533,8 +1535,8 @@ if (log) log->Printf("Processing command: %s", command_line); - Timer scoped_timer(LLVM_PRETTY_FUNCTION, "Handling command: %s.", - command_line); + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, "Handling command: %s.", command_line); if (!no_context_switching) UpdateExecutionContext(override_context); Index: lldb/trunk/source/Plugins/LanguageRuntime/ObjC/AppleObjCRuntime/AppleObjCRuntimeV2.cpp =================================================================== --- lldb/trunk/source/Plugins/LanguageRuntime/ObjC/AppleObjCRuntime/AppleObjCRuntimeV2.cpp +++ lldb/trunk/source/Plugins/LanguageRuntime/ObjC/AppleObjCRuntime/AppleObjCRuntimeV2.cpp @@ -1803,7 +1803,8 @@ void AppleObjCRuntimeV2::UpdateISAToDescriptorMapIfNeeded() { Log *log(GetLogIfAnyCategoriesSet(LIBLLDB_LOG_PROCESS | LIBLLDB_LOG_TYPES)); - Timer scoped_timer(LLVM_PRETTY_FUNCTION, LLVM_PRETTY_FUNCTION); + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, LLVM_PRETTY_FUNCTION); // Else we need to check with our process to see when the map was updated. Process *process = GetProcess(); Index: lldb/trunk/source/Plugins/ObjectContainer/BSD-Archive/ObjectContainerBSDArchive.cpp =================================================================== --- lldb/trunk/source/Plugins/ObjectContainer/BSD-Archive/ObjectContainerBSDArchive.cpp +++ lldb/trunk/source/Plugins/ObjectContainer/BSD-Archive/ObjectContainerBSDArchive.cpp @@ -301,8 +301,9 @@ DataExtractor data; data.SetData(data_sp, data_offset, length); if (file && data_sp && ObjectContainerBSDArchive::MagicBytesMatch(data)) { + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); Timer scoped_timer( - LLVM_PRETTY_FUNCTION, + func_cat, "ObjectContainerBSDArchive::CreateInstance (module = %s, file = " "%p, file_offset = 0x%8.8" PRIx64 ", file_size = 0x%8.8" PRIx64 ")", module_sp->GetFileSpec().GetPath().c_str(), Index: lldb/trunk/source/Plugins/ObjectFile/ELF/ObjectFileELF.cpp =================================================================== --- lldb/trunk/source/Plugins/ObjectFile/ELF/ObjectFileELF.cpp +++ lldb/trunk/source/Plugins/ObjectFile/ELF/ObjectFileELF.cpp @@ -727,8 +727,9 @@ uint32_t core_notes_crc = 0; if (!gnu_debuglink_crc) { + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); lldb_private::Timer scoped_timer( - LLVM_PRETTY_FUNCTION, + func_cat, "Calculating module crc32 %s with size %" PRIu64 " KiB", file.GetLastPathComponent().AsCString(), (file.GetByteSize() - file_offset) / 1024); Index: lldb/trunk/source/Plugins/ObjectFile/Mach-O/ObjectFileMachO.cpp =================================================================== --- lldb/trunk/source/Plugins/ObjectFile/Mach-O/ObjectFileMachO.cpp +++ lldb/trunk/source/Plugins/ObjectFile/Mach-O/ObjectFileMachO.cpp @@ -2121,8 +2121,8 @@ } size_t ObjectFileMachO::ParseSymtab() { - Timer scoped_timer(LLVM_PRETTY_FUNCTION, - "ObjectFileMachO::ParseSymtab () module = %s", + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, "ObjectFileMachO::ParseSymtab () module = %s", m_file.GetFilename().AsCString("")); ModuleSP module_sp(GetModule()); if (!module_sp) Index: lldb/trunk/source/Plugins/ScriptInterpreter/Python/ScriptInterpreterPython.cpp =================================================================== --- lldb/trunk/source/Plugins/ScriptInterpreter/Python/ScriptInterpreterPython.cpp +++ lldb/trunk/source/Plugins/ScriptInterpreter/Python/ScriptInterpreterPython.cpp @@ -928,7 +928,8 @@ }; void ScriptInterpreterPython::ExecuteInterpreterLoop() { - Timer scoped_timer(LLVM_PRETTY_FUNCTION, LLVM_PRETTY_FUNCTION); + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, LLVM_PRETTY_FUNCTION); Debugger &debugger = GetCommandInterpreter().GetDebugger(); @@ -1995,7 +1996,8 @@ StructuredData::ObjectSP &callee_wrapper_sp, const TypeSummaryOptions &options, std::string &retval) { - Timer scoped_timer(LLVM_PRETTY_FUNCTION, LLVM_PRETTY_FUNCTION); + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, LLVM_PRETTY_FUNCTION); if (!valobj.get()) { retval.assign(""); @@ -2019,8 +2021,8 @@ { TypeSummaryOptionsSP options_sp(new TypeSummaryOptions(options)); - Timer scoped_timer("g_swig_typescript_callback", - "g_swig_typescript_callback"); + static Timer::Category func_cat("g_swig_typescript_callback"); + Timer scoped_timer(func_cat, "g_swig_typescript_callback"); ret_val = g_swig_typescript_callback( python_function_name, GetSessionDictionary().get(), valobj, &new_callee, options_sp, retval); @@ -3102,7 +3104,8 @@ g_initialized = true; - Timer scoped_timer(LLVM_PRETTY_FUNCTION, LLVM_PRETTY_FUNCTION); + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, LLVM_PRETTY_FUNCTION); // RAII-based initialization which correctly handles multiple-initialization, // version- Index: lldb/trunk/source/Plugins/SymbolFile/DWARF/DWARFCompileUnit.cpp =================================================================== --- lldb/trunk/source/Plugins/SymbolFile/DWARF/DWARFCompileUnit.cpp +++ lldb/trunk/source/Plugins/SymbolFile/DWARF/DWARFCompileUnit.cpp @@ -135,8 +135,9 @@ if ((cu_die_only && initial_die_array_size > 0) || initial_die_array_size > 1) return 0; // Already parsed + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); Timer scoped_timer( - LLVM_PRETTY_FUNCTION, + func_cat, "%8.8x: DWARFCompileUnit::ExtractDIEsIfNeeded( cu_die_only = %i )", m_offset, cu_die_only); Index: lldb/trunk/source/Plugins/SymbolFile/DWARF/DWARFDebugAranges.cpp =================================================================== --- lldb/trunk/source/Plugins/SymbolFile/DWARF/DWARFDebugAranges.cpp +++ lldb/trunk/source/Plugins/SymbolFile/DWARF/DWARFDebugAranges.cpp @@ -110,7 +110,8 @@ } void DWARFDebugAranges::Sort(bool minimize) { - Timer scoped_timer(LLVM_PRETTY_FUNCTION, "%s this = %p", LLVM_PRETTY_FUNCTION, + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, "%s this = %p", LLVM_PRETTY_FUNCTION, static_cast(this)); Log *log(LogChannelDWARF::GetLogIfAll(DWARF_LOG_DEBUG_ARANGES)); Index: lldb/trunk/source/Plugins/SymbolFile/DWARF/DWARFDebugLine.cpp =================================================================== --- lldb/trunk/source/Plugins/SymbolFile/DWARF/DWARFDebugLine.cpp +++ lldb/trunk/source/Plugins/SymbolFile/DWARF/DWARFDebugLine.cpp @@ -484,9 +484,9 @@ const dw_offset_t debug_line_offset = *offset_ptr; + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); Timer scoped_timer( - LLVM_PRETTY_FUNCTION, - "DWARFDebugLine::ParseStatementTable (.debug_line[0x%8.8x])", + func_cat, "DWARFDebugLine::ParseStatementTable (.debug_line[0x%8.8x])", debug_line_offset); if (!ParsePrologue(debug_line_data, offset_ptr, prologue.get())) { Index: lldb/trunk/source/Plugins/SymbolFile/DWARF/DWARFDebugPubnames.cpp =================================================================== --- lldb/trunk/source/Plugins/SymbolFile/DWARF/DWARFDebugPubnames.cpp +++ lldb/trunk/source/Plugins/SymbolFile/DWARF/DWARFDebugPubnames.cpp @@ -25,7 +25,8 @@ DWARFDebugPubnames::DWARFDebugPubnames() : m_sets() {} bool DWARFDebugPubnames::Extract(const DWARFDataExtractor &data) { - Timer scoped_timer(LLVM_PRETTY_FUNCTION, + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, "DWARFDebugPubnames::Extract (byte_size = %" PRIu64 ")", (uint64_t)data.GetByteSize()); Log *log(LogChannelDWARF::GetLogIfAll(DWARF_LOG_DEBUG_PUBNAMES)); @@ -52,7 +53,8 @@ } bool DWARFDebugPubnames::GeneratePubnames(SymbolFileDWARF *dwarf2Data) { - Timer scoped_timer(LLVM_PRETTY_FUNCTION, + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, "DWARFDebugPubnames::GeneratePubnames (data = %p)", static_cast(dwarf2Data)); Index: lldb/trunk/source/Plugins/SymbolFile/DWARF/SymbolFileDWARF.cpp =================================================================== --- lldb/trunk/source/Plugins/SymbolFile/DWARF/SymbolFileDWARF.cpp +++ lldb/trunk/source/Plugins/SymbolFile/DWARF/SymbolFileDWARF.cpp @@ -666,8 +666,9 @@ DWARFDebugInfo *SymbolFileDWARF::DebugInfo() { if (m_info.get() == NULL) { - Timer scoped_timer(LLVM_PRETTY_FUNCTION, "%s this = %p", - LLVM_PRETTY_FUNCTION, static_cast(this)); + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, "%s this = %p", LLVM_PRETTY_FUNCTION, + static_cast(this)); if (get_debug_info_data().GetByteSize() > 0) { m_info.reset(new DWARFDebugInfo()); if (m_info.get()) { @@ -703,8 +704,9 @@ DWARFDebugRanges *SymbolFileDWARF::DebugRanges() { if (m_ranges.get() == NULL) { - Timer scoped_timer(LLVM_PRETTY_FUNCTION, "%s this = %p", - LLVM_PRETTY_FUNCTION, static_cast(this)); + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, "%s this = %p", LLVM_PRETTY_FUNCTION, + static_cast(this)); if (get_debug_ranges_data().GetByteSize() > 0) { m_ranges.reset(new DWARFDebugRanges()); if (m_ranges.get()) @@ -1666,10 +1668,12 @@ uint32_t SymbolFileDWARF::ResolveSymbolContext(const Address &so_addr, uint32_t resolve_scope, SymbolContext &sc) { - Timer scoped_timer(LLVM_PRETTY_FUNCTION, "SymbolFileDWARF::" - "ResolveSymbolContext (so_addr = { " - "section = %p, offset = 0x%" PRIx64 - " }, resolve_scope = 0x%8.8x)", + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, + "SymbolFileDWARF::" + "ResolveSymbolContext (so_addr = { " + "section = %p, offset = 0x%" PRIx64 + " }, resolve_scope = 0x%8.8x)", static_cast(so_addr.GetSection().get()), so_addr.GetOffset(), resolve_scope); uint32_t resolved = 0; @@ -1927,8 +1931,9 @@ if (m_indexed) return; m_indexed = true; + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); Timer scoped_timer( - LLVM_PRETTY_FUNCTION, "SymbolFileDWARF::Index (%s)", + func_cat, "SymbolFileDWARF::Index (%s)", GetObjectFile()->GetFileSpec().GetFilename().AsCString("")); DWARFDebugInfo *debug_info = DebugInfo(); @@ -2390,8 +2395,8 @@ const CompilerDeclContext *parent_decl_ctx, uint32_t name_type_mask, bool include_inlines, bool append, SymbolContextList &sc_list) { - Timer scoped_timer(LLVM_PRETTY_FUNCTION, - "SymbolFileDWARF::FindFunctions (name = '%s')", + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, "SymbolFileDWARF::FindFunctions (name = '%s')", name.AsCString()); // eFunctionNameTypeAuto should be pre-resolved by a call to @@ -2670,8 +2675,8 @@ uint32_t SymbolFileDWARF::FindFunctions(const RegularExpression ®ex, bool include_inlines, bool append, SymbolContextList &sc_list) { - Timer scoped_timer(LLVM_PRETTY_FUNCTION, - "SymbolFileDWARF::FindFunctions (regex = '%s')", + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, "SymbolFileDWARF::FindFunctions (regex = '%s')", regex.GetText().str().c_str()); Log *log(LogChannelDWARF::GetLogIfAll(DWARF_LOG_LOOKUPS)); Index: lldb/trunk/source/Plugins/SymbolFile/DWARF/SymbolFileDWARFDebugMap.cpp =================================================================== --- lldb/trunk/source/Plugins/SymbolFile/DWARF/SymbolFileDWARFDebugMap.cpp +++ lldb/trunk/source/Plugins/SymbolFile/DWARF/SymbolFileDWARFDebugMap.cpp @@ -991,7 +991,8 @@ const ConstString &name, const CompilerDeclContext *parent_decl_ctx, uint32_t name_type_mask, bool include_inlines, bool append, SymbolContextList &sc_list) { - Timer scoped_timer(LLVM_PRETTY_FUNCTION, + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, "SymbolFileDWARFDebugMap::FindFunctions (name = %s)", name.GetCString()); @@ -1018,7 +1019,8 @@ bool include_inlines, bool append, SymbolContextList &sc_list) { - Timer scoped_timer(LLVM_PRETTY_FUNCTION, + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, "SymbolFileDWARFDebugMap::FindFunctions (regex = '%s')", regex.GetText().str().c_str()); @@ -1044,7 +1046,8 @@ size_t SymbolFileDWARFDebugMap::GetTypes(SymbolContextScope *sc_scope, uint32_t type_mask, TypeList &type_list) { - Timer scoped_timer(LLVM_PRETTY_FUNCTION, + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, "SymbolFileDWARFDebugMap::GetTypes (type_mask = 0x%8.8x)", type_mask); Index: lldb/trunk/source/Plugins/SymbolVendor/ELF/SymbolVendorELF.cpp =================================================================== --- lldb/trunk/source/Plugins/SymbolVendor/ELF/SymbolVendorELF.cpp +++ lldb/trunk/source/Plugins/SymbolVendor/ELF/SymbolVendorELF.cpp @@ -92,8 +92,8 @@ if (file_spec_list.IsEmpty()) return NULL; - Timer scoped_timer(LLVM_PRETTY_FUNCTION, - "SymbolVendorELF::CreateInstance (module = %s)", + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, "SymbolVendorELF::CreateInstance (module = %s)", module_sp->GetFileSpec().GetPath().c_str()); for (size_t idx = 0; idx < file_spec_list.GetSize(); ++idx) { Index: lldb/trunk/source/Symbol/DWARFCallFrameInfo.cpp =================================================================== --- lldb/trunk/source/Symbol/DWARFCallFrameInfo.cpp +++ lldb/trunk/source/Symbol/DWARFCallFrameInfo.cpp @@ -419,7 +419,8 @@ if (m_fde_index_initialized) // if two threads hit the locker return; - Timer scoped_timer(LLVM_PRETTY_FUNCTION, "%s - %s", LLVM_PRETTY_FUNCTION, + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, "%s - %s", LLVM_PRETTY_FUNCTION, m_objfile.GetFileSpec().GetFilename().AsCString("")); bool clear_address_zeroth_bit = false; Index: lldb/trunk/source/Symbol/ObjectFile.cpp =================================================================== --- lldb/trunk/source/Symbol/ObjectFile.cpp +++ lldb/trunk/source/Symbol/ObjectFile.cpp @@ -37,8 +37,9 @@ ObjectFileSP object_file_sp; if (module_sp) { + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); Timer scoped_timer( - LLVM_PRETTY_FUNCTION, + func_cat, "ObjectFile::FindPlugin (module = %s, file = %p, file_offset = " "0x%8.8" PRIx64 ", file_size = 0x%8.8" PRIx64 ")", module_sp->GetFileSpec().GetPath().c_str(), @@ -176,9 +177,11 @@ ObjectFileSP object_file_sp; if (module_sp) { - Timer scoped_timer(LLVM_PRETTY_FUNCTION, "ObjectFile::FindPlugin (module = " - "%s, process = %p, header_addr = " - "0x%" PRIx64 ")", + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, + "ObjectFile::FindPlugin (module = " + "%s, process = %p, header_addr = " + "0x%" PRIx64 ")", module_sp->GetFileSpec().GetPath().c_str(), static_cast(process_sp.get()), header_addr); uint32_t idx; Index: lldb/trunk/source/Symbol/Symtab.cpp =================================================================== --- lldb/trunk/source/Symbol/Symtab.cpp +++ lldb/trunk/source/Symbol/Symtab.cpp @@ -220,7 +220,8 @@ // Protected function, no need to lock mutex... if (!m_name_indexes_computed) { m_name_indexes_computed = true; - Timer scoped_timer(LLVM_PRETTY_FUNCTION, "%s", LLVM_PRETTY_FUNCTION); + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, "%s", LLVM_PRETTY_FUNCTION); // Create the name index vector to be able to quickly search by name const size_t num_symbols = m_symbols.size(); #if 1 @@ -433,7 +434,8 @@ bool add_demangled, bool add_mangled, NameToIndexMap &name_to_index_map) const { if (add_demangled || add_mangled) { - Timer scoped_timer(LLVM_PRETTY_FUNCTION, "%s", LLVM_PRETTY_FUNCTION); + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, "%s", LLVM_PRETTY_FUNCTION); std::lock_guard guard(m_mutex); // Create the name index vector to be able to quickly search by name @@ -595,7 +597,8 @@ bool remove_duplicates) const { std::lock_guard guard(m_mutex); - Timer scoped_timer(LLVM_PRETTY_FUNCTION, LLVM_PRETTY_FUNCTION); + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, LLVM_PRETTY_FUNCTION); // No need to sort if we have zero or one items... if (indexes.size() <= 1) return; @@ -621,7 +624,8 @@ std::vector &indexes) { std::lock_guard guard(m_mutex); - Timer scoped_timer(LLVM_PRETTY_FUNCTION, "%s", LLVM_PRETTY_FUNCTION); + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, "%s", LLVM_PRETTY_FUNCTION); if (symbol_name) { if (!m_name_indexes_computed) InitNameIndexes(); @@ -637,7 +641,8 @@ std::vector &indexes) { std::lock_guard guard(m_mutex); - Timer scoped_timer(LLVM_PRETTY_FUNCTION, "%s", LLVM_PRETTY_FUNCTION); + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, "%s", LLVM_PRETTY_FUNCTION); if (symbol_name) { const size_t old_size = indexes.size(); if (!m_name_indexes_computed) @@ -766,7 +771,8 @@ std::vector &symbol_indexes) { std::lock_guard guard(m_mutex); - Timer scoped_timer(LLVM_PRETTY_FUNCTION, "%s", LLVM_PRETTY_FUNCTION); + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, "%s", LLVM_PRETTY_FUNCTION); // Initialize all of the lookup by name indexes before converting NAME // to a uniqued string NAME_STR below. if (!m_name_indexes_computed) @@ -785,7 +791,8 @@ Visibility symbol_visibility, std::vector &symbol_indexes) { std::lock_guard guard(m_mutex); - Timer scoped_timer(LLVM_PRETTY_FUNCTION, "%s", LLVM_PRETTY_FUNCTION); + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, "%s", LLVM_PRETTY_FUNCTION); // Initialize all of the lookup by name indexes before converting NAME // to a uniqued string NAME_STR below. if (!m_name_indexes_computed) @@ -817,7 +824,8 @@ Visibility symbol_visibility) { std::lock_guard guard(m_mutex); - Timer scoped_timer(LLVM_PRETTY_FUNCTION, "%s", LLVM_PRETTY_FUNCTION); + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, "%s", LLVM_PRETTY_FUNCTION); if (!m_name_indexes_computed) InitNameIndexes(); Index: lldb/trunk/source/Target/Target.cpp =================================================================== --- lldb/trunk/source/Target/Target.cpp +++ lldb/trunk/source/Target/Target.cpp @@ -1235,7 +1235,8 @@ ClearModules(false); if (executable_sp) { - Timer scoped_timer(LLVM_PRETTY_FUNCTION, + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer(func_cat, "Target::SetExecutableModule (executable = '%s')", executable_sp->GetFileSpec().GetPath().c_str()); Index: lldb/trunk/source/Target/TargetList.cpp =================================================================== --- lldb/trunk/source/Target/TargetList.cpp +++ lldb/trunk/source/Target/TargetList.cpp @@ -325,10 +325,10 @@ lldb::PlatformSP &platform_sp, lldb::TargetSP &target_sp, bool is_dummy_target) { - Timer scoped_timer(LLVM_PRETTY_FUNCTION, - "TargetList::CreateTarget (file = '%s', arch = '%s')", - user_exe_path.str().c_str(), - specified_arch.GetArchitectureName()); + static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); + Timer scoped_timer( + func_cat, "TargetList::CreateTarget (file = '%s', arch = '%s')", + user_exe_path.str().c_str(), specified_arch.GetArchitectureName()); Status error; ArchSpec arch(specified_arch); Index: lldb/trunk/unittests/Core/TimerTest.cpp =================================================================== --- lldb/trunk/unittests/Core/TimerTest.cpp +++ lldb/trunk/unittests/Core/TimerTest.cpp @@ -18,7 +18,8 @@ TEST(TimerTest, CategoryTimes) { Timer::ResetCategoryTimes(); { - Timer t("CAT1", ""); + static Timer::Category tcat("CAT1"); + Timer t(tcat, ""); std::this_thread::sleep_for(std::chrono::milliseconds(10)); } StreamString ss; @@ -32,14 +33,18 @@ TEST(TimerTest, CategoryTimesNested) { Timer::ResetCategoryTimes(); { - Timer t1("CAT1", ""); + static Timer::Category tcat1("CAT1"); + Timer t1(tcat1, ""); std::this_thread::sleep_for(std::chrono::milliseconds(10)); - Timer t2("CAT1", ""); + // Explicitly testing the same category as above. + Timer t2(tcat1, ""); std::this_thread::sleep_for(std::chrono::milliseconds(10)); } StreamString ss; Timer::DumpCategoryTimes(&ss); double seconds; + // It should only appear once. + ASSERT_EQ(ss.GetString().count("CAT1"), 1U); ASSERT_EQ(1, sscanf(ss.GetData(), "%lf sec for CAT1", &seconds)); EXPECT_LT(0.002, seconds); EXPECT_GT(0.2, seconds); @@ -48,9 +53,11 @@ TEST(TimerTest, CategoryTimes2) { Timer::ResetCategoryTimes(); { - Timer t1("CAT1", ""); + static Timer::Category tcat1("CAT1"); + Timer t1(tcat1, ""); std::this_thread::sleep_for(std::chrono::milliseconds(100)); - Timer t2("CAT2", ""); + static Timer::Category tcat2("CAT2"); + Timer t2(tcat2, ""); std::this_thread::sleep_for(std::chrono::milliseconds(10)); } StreamString ss;