Remove an expensive lock from Timer

The Timer destructor would grab a global mutex in order to update
execution time. Add a class to define a category once, statically; the
class adds itself to an atomic singly linked list, and thus subsequent
updates only need to use an atomic rather than grab a lock and perform a
hashtable lookup.

Differential Revision: https://reviews.llvm.org/D32823
Patch by Scott Smith <scott.smith@purestorage.com>.

llvm-svn: 303058
This commit is contained in:
Pavel Labath 2017-05-15 13:02:37 +00:00
parent 3030bf0c81
commit f9d1647657
28 changed files with 183 additions and 127 deletions

View File

@ -37,10 +37,23 @@ namespace lldb_private {
class Timer {
public:
class Category {
public:
explicit Category(const char *category_name);
private:
friend class Timer;
const char *m_name;
std::atomic<uint64_t> m_nanos;
std::atomic<Category *> 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 @@ protected:
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};

View File

@ -400,7 +400,8 @@ void SystemInitializerFull::InitializeSWIG() {
}
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();

View File

@ -269,8 +269,8 @@ protected:
}
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)

View File

@ -59,7 +59,8 @@ using namespace lldb_private;
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 @@ std::function<bool(const Instruction::Operand &)>
lldb_private::OperandMatchers::MatchOpType(Instruction::Operand::Type type) {
return [type](const Instruction::Operand &op) { return op.m_type == type; };
}

View File

@ -258,8 +258,8 @@ Mangled::GetDemangledName(lldb::LanguageType language) const {
// 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);

View File

@ -429,8 +429,8 @@ void Module::DumpSymbolContext(Stream *s) {
size_t Module::GetNumCompileUnits() {
std::lock_guard<std::recursive_mutex> 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<void *>(this));
SymbolVendor *symbols = GetSymbolVendor();
if (symbols)
@ -453,7 +453,8 @@ CompUnitSP Module::GetCompileUnitAtIndex(size_t index) {
bool Module::ResolveFileAddress(lldb::addr_t vm_addr, Address &so_addr) {
std::lock_guard<std::recursive_mutex> 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 Module::ResolveSymbolContextsForFileSpec(const FileSpec &file_spec,
uint32_t resolve_scope,
SymbolContextList &sc_list) {
std::lock_guard<std::recursive_mutex> 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 @@ size_t Module::FindTypes_Impl(
const CompilerDeclContext *parent_decl_ctx, bool append, size_t max_matches,
llvm::DenseSet<lldb_private::SymbolFile *> &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 @@ SymbolVendor *Module::GetSymbolVendor(bool can_create,
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 @@ ObjectFile *Module::GetObjectFile() {
if (!m_did_load_objfile.load()) {
std::lock_guard<std::recursive_mutex> 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 @@ SectionList *Module::GetUnifiedSectionList() {
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 @@ void Module::SymbolIndicesToSymbolContextList(
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 @@ size_t Module::FindSymbolsWithNameAndType(const ConstString &name,
// 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 @@ size_t Module::FindSymbolsMatchingRegExAndType(const RegularExpression &regex,
// 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();

View File

@ -27,8 +27,8 @@ using namespace lldb_private;
#define TIMER_INDENT_AMOUNT 2
namespace {
typedef std::map<const char *, std::chrono::nanoseconds> TimerCategoryMap;
typedef std::vector<Timer *> TimerStack;
static std::atomic<Timer::Category *> g_categories;
} // end of anonymous namespace
std::atomic<bool> Timer::g_quiet(true);
@ -38,16 +38,6 @@ static std::mutex &GetFileMutex() {
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<TimerStack *>(p);
}
@ -64,9 +54,17 @@ static TimerStack *GetTimerStackForCurrentThread() {
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 @@ Timer::~Timer() {
stack->back()->ChildDuration(total_dur);
// Keep total results for each category so we can dump results.
{
std::lock_guard<std::mutex> 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 @@ void Timer::SetDisplayDepth(uint32_t depth) { g_display_depth = depth; }
/* 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<const char *, uint64_t> TimerEntry;
static bool CategoryMapIteratorSortCriterion(const TimerEntry &lhs,
const TimerEntry &rhs) {
return lhs.second > rhs.second;
}
void Timer::ResetCategoryTimes() {
std::lock_guard<std::mutex> 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<std::mutex> guard(GetCategoryMutex());
TimerCategoryMap &category_map = GetCategoryMap();
std::vector<TimerCategoryMap::const_iterator> 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<TimerEntry> 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<double>(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);
}

View File

@ -151,8 +151,9 @@ FileSpec LocateExecutableSymbolFileDsym(const ModuleSpec &module_spec) {
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("<NULL>") : "<NULL>",
arch ? arch->GetArchitectureName() : "<NULL>", (const void *)uuid);
@ -175,9 +176,9 @@ ModuleSpec Symbols::LocateExecutableObjectFile(const ModuleSpec &module_spec) {
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("<NULL>") : "<NULL>",
arch ? arch->GetArchitectureName() : "<NULL>", (const void *)uuid);

View File

@ -72,7 +72,8 @@ void SystemInitializerCommon::Initialize() {
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::Initialize() {
}
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();

View File

@ -169,7 +169,8 @@ bool CommandInterpreter::GetSpaceReplPrompts() const {
}
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 @@ const char *CommandInterpreter::ProcessEmbeddedScriptCommands(const char *arg) {
}
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 @@ bool CommandInterpreter::HandleCommand(const char *command_line,
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);

View File

@ -1803,7 +1803,8 @@ lldb::addr_t AppleObjCRuntimeV2::GetSharedCacheReadOnlyAddress() {
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();

View File

@ -301,8 +301,9 @@ ObjectContainer *ObjectContainerBSDArchive::CreateInstance(
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(),

View File

@ -727,8 +727,9 @@ size_t ObjectFileELF::GetModuleSpecifications(
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);

View File

@ -2121,8 +2121,8 @@ UUID ObjectFileMachO::GetSharedCacheUUID(FileSpec dyld_shared_cache,
}
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)

View File

@ -928,7 +928,8 @@ protected:
};
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 @@ bool ScriptInterpreterPython::GetScriptedSummary(
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("<no object>");
@ -2019,8 +2021,8 @@ bool ScriptInterpreterPython::GetScriptedSummary(
{
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 @@ void ScriptInterpreterPython::InitializePrivate() {
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-

View File

@ -135,8 +135,9 @@ size_t DWARFCompileUnit::ExtractDIEsIfNeeded(bool cu_die_only) {
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);

View File

@ -110,7 +110,8 @@ void DWARFDebugAranges::AppendRange(dw_offset_t offset, dw_addr_t low_pc,
}
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<void *>(this));
Log *log(LogChannelDWARF::GetLogIfAll(DWARF_LOG_DEBUG_ARANGES));

View File

@ -484,9 +484,9 @@ bool DWARFDebugLine::ParseStatementTable(
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())) {

View File

@ -25,7 +25,8 @@ using namespace lldb_private;
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::Extract(const DWARFDataExtractor &data) {
}
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<void *>(dwarf2Data));

View File

@ -666,8 +666,9 @@ const DWARFDebugAbbrev *SymbolFileDWARF::DebugAbbrev() const {
DWARFDebugInfo *SymbolFileDWARF::DebugInfo() {
if (m_info.get() == NULL) {
Timer scoped_timer(LLVM_PRETTY_FUNCTION, "%s this = %p",
LLVM_PRETTY_FUNCTION, static_cast<void *>(this));
static Timer::Category func_cat(LLVM_PRETTY_FUNCTION);
Timer scoped_timer(func_cat, "%s this = %p", LLVM_PRETTY_FUNCTION,
static_cast<void *>(this));
if (get_debug_info_data().GetByteSize() > 0) {
m_info.reset(new DWARFDebugInfo());
if (m_info.get()) {
@ -703,8 +704,9 @@ SymbolFileDWARF::GetDWARFCompileUnit(lldb_private::CompileUnit *comp_unit) {
DWARFDebugRanges *SymbolFileDWARF::DebugRanges() {
if (m_ranges.get() == NULL) {
Timer scoped_timer(LLVM_PRETTY_FUNCTION, "%s this = %p",
LLVM_PRETTY_FUNCTION, static_cast<void *>(this));
static Timer::Category func_cat(LLVM_PRETTY_FUNCTION);
Timer scoped_timer(func_cat, "%s this = %p", LLVM_PRETTY_FUNCTION,
static_cast<void *>(this));
if (get_debug_ranges_data().GetByteSize() > 0) {
m_ranges.reset(new DWARFDebugRanges());
if (m_ranges.get())
@ -1666,10 +1668,12 @@ SymbolFileDWARF::GlobalVariableMap &SymbolFileDWARF::GetGlobalAranges() {
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<void *>(so_addr.GetSection().get()),
so_addr.GetOffset(), resolve_scope);
uint32_t resolved = 0;
@ -1927,8 +1931,9 @@ void SymbolFileDWARF::Index() {
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("<Unknown>"));
DWARFDebugInfo *debug_info = DebugInfo();
@ -2390,8 +2395,8 @@ SymbolFileDWARF::FindFunctions(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,
"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 @@ SymbolFileDWARF::FindFunctions(const ConstString &name,
uint32_t SymbolFileDWARF::FindFunctions(const RegularExpression &regex,
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));

View File

@ -991,7 +991,8 @@ uint32_t SymbolFileDWARFDebugMap::FindFunctions(
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 @@ uint32_t SymbolFileDWARFDebugMap::FindFunctions(const RegularExpression &regex,
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 @@ uint32_t SymbolFileDWARFDebugMap::FindFunctions(const RegularExpression &regex,
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);

View File

@ -92,8 +92,8 @@ SymbolVendorELF::CreateInstance(const lldb::ModuleSP &module_sp,
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) {

View File

@ -419,7 +419,8 @@ void DWARFCallFrameInfo::GetFDEIndex() {
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;

View File

@ -37,8 +37,9 @@ ObjectFile::FindPlugin(const lldb::ModuleSP &module_sp, const FileSpec *file,
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 ObjectFile::FindPlugin(const lldb::ModuleSP &module_sp,
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<void *>(process_sp.get()), header_addr);
uint32_t idx;

View File

@ -220,7 +220,8 @@ void Symtab::InitNameIndexes() {
// 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 @@ void Symtab::AppendSymbolNamesToMap(const IndexCollection &indexes,
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<std::recursive_mutex> guard(m_mutex);
// Create the name index vector to be able to quickly search by name
@ -595,7 +597,8 @@ void Symtab::SortSymbolIndexesByValue(std::vector<uint32_t> &indexes,
bool remove_duplicates) const {
std::lock_guard<std::recursive_mutex> 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 @@ uint32_t Symtab::AppendSymbolIndexesWithName(const ConstString &symbol_name,
std::vector<uint32_t> &indexes) {
std::lock_guard<std::recursive_mutex> 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 @@ uint32_t Symtab::AppendSymbolIndexesWithName(const ConstString &symbol_name,
std::vector<uint32_t> &indexes) {
std::lock_guard<std::recursive_mutex> 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 @@ Symtab::FindAllSymbolsWithNameAndType(const ConstString &name,
std::vector<uint32_t> &symbol_indexes) {
std::lock_guard<std::recursive_mutex> 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 @@ size_t Symtab::FindAllSymbolsWithNameAndType(
Visibility symbol_visibility, std::vector<uint32_t> &symbol_indexes) {
std::lock_guard<std::recursive_mutex> 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 @@ Symbol *Symtab::FindFirstSymbolWithNameAndType(const ConstString &name,
Visibility symbol_visibility) {
std::lock_guard<std::recursive_mutex> 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();

View File

@ -1235,7 +1235,8 @@ void Target::SetExecutableModule(ModuleSP &executable_sp,
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());

View File

@ -325,10 +325,10 @@ Status TargetList::CreateTargetInternal(Debugger &debugger,
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);

View File

@ -18,7 +18,8 @@ using namespace lldb_private;
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, CategoryTimes) {
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, CategoryTimesNested) {
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;