[lldb-dev] lldb_private::Timer class introduction

[Greg Clayton]

I just wanted to take a little time to introduce everyone to the Timer class.

I know the linux version isn't up and running yet, but we have scoped timer classes that can help you test out the performance impact of your new code changes. The constructor looks like:

        Timer (const char *name, const char *format, ...);

Timers have thread specific timer stacks that they push themselves onto and stop the timer above them on the stack. Each timer will print itself to STDOUT and indent itself appropriately as it pushes itself on the timer stack. When the "scoped_timer" goes out of scope, it will pop itself off the stack and print out the time the task took. The time the task took will also be added to a global map that tracks the total time for all tasks by "name". So you will want to make sure the same "const char *" is used for "name" so all timings are aggregated correctly in the total timings.

This allows these scoped timers to come and go and keep very accurate timing information for each timer by "name". You will see a lot of code around LLDB using these. The simplest way to use these in a function is:

        Timer scoped_timer (__PRETTY_FUNCTION__, __PRETTY_FUNCTION__);

The timers can be enabled:

(lldb) log timers enable

Then run some code that excercises the code you have modified

(lldb) log timers dump

or 

(lldb) log timers disable

"log timers dump" will just dump the current state of the timers without disabling them. "log timers disable" will disable the timers and also dump the current totals.

An example output of this is shown below. I load an Objective C program with DWARF information for 91 shared library, the I set a breakpoint at main without limitting the search to any shared libraries which causes all DWARF to be index (which causes a _lot_ of DWARF to get indexed):

(lldb) log timers enable
(lldb) breakpoint set --name main
(lldb) log timers disable
2.479288000 sec for void SymbolFileDWARF::Index()
1.983044000 sec for void lldb_private::Symtab::InitNameIndexes()
1.152179000 sec for size_t DWARFCompileUnit::ExtractDIEsIfNeeded(bool)
0.379501000 sec for size_t ObjectFileMachO::ParseSymtab(bool)
0.222010000 sec for const lldb_private::ConstString& lldb_private::Mangled::GetDemangledName() const
0.055482000 sec for SymbolVendorMacOSX::CreateInstance () locate dSYM
0.035886000 sec for virtual uint32_t SymbolFileDWARF::FindFunctions(const lldb_private::ConstString&, bool, lldb_private::SymbolContextList&)
0.034275000 sec for static lldb_private::FileSpec lldb_private::Symbols::LocateExecutableSymbolFile(const lldb_private::FileSpec*, const lldb_private::ArchSpec*, const lldb_private::UUID*)
0.010591000 sec for static lldb_private::ObjectFile* lldb_private::ObjectFile::FindPlugin(lldb_private::Module*, const lldb_private::FileSpec*, lldb::addr_t, lldb::addr_t)
0.005288000 sec for size_t lldb_private::Module::FindSymbolsWithNameAndType(const lldb_private::ConstString&, lldb::SymbolType, lldb_private::SymbolContextList&)
0.003093000 sec for size_t lldb_private::Symtab::FindAllSymbolsWithNameAndType(const lldb_private::ConstString&, lldb::SymbolType, std::vector<unsigned int, std::allocator<unsigned int> >&)
0.002176000 sec for static lldb_private::SymbolVendor* SymbolVendorMacOSX::CreateInstance(lldb_private::Module*)
0.001947000 sec for lldb_private::SymbolVendor* lldb_private::Module::GetSymbolVendor(bool)
0.001299000 sec for static bool DWARFDebugLine::ParseStatementTable(const lldb_private::DataExtractor&, dw_offset_t*, void (*)(dw_offset_t, const DWARFDebugLine::State&, void*), void*)
0.000910000 sec for DWARFDebugRanges* SymbolFileDWARF::DebugRanges()
0.000227000 sec for DWARFDebugInfo* SymbolFileDWARF::DebugInfo()
0.000208000 sec for uint32_t lldb_private::Symtab::AppendSymbolIndexesWithName(const lldb_private::ConstString&, std::vector<unsigned int, std::allocator<unsigned int> >&)
0.000201000 sec for virtual uint32_t SymbolFileSymtab::FindFunctions(const lldb_private::ConstString&, bool, lldb_private::SymbolContextList&)

As you can see, we get some nice totals for which tasks took a lot of time.

If you make any changes to code that might affect parsing (reading, swapping, sorting), it might be a good idea to add one of these timers to check the performance impact. 

Greg Clayton
LLDB Architect