diff --git a/lldb/include/lldb/Core/Module.h b/lldb/include/lldb/Core/Module.h --- a/lldb/include/lldb/Core/Module.h +++ b/lldb/include/lldb/Core/Module.h @@ -16,6 +16,7 @@ #include "lldb/Symbol/SymbolContextScope.h" #include "lldb/Symbol/TypeSystem.h" #include "lldb/Target/PathMappingList.h" +#include "lldb/Target/Statistics.h" #include "lldb/Utility/ArchSpec.h" #include "lldb/Utility/ConstString.h" #include "lldb/Utility/FileSpec.h" @@ -870,6 +871,18 @@ /// Update the ArchSpec to a more specific variant. bool MergeArchitecture(const ArchSpec &arch_spec); + /// Accessor for the symbol table parse time metric. + /// + /// The value is returned as a reference to allow it to be updated by the + /// ElapsedTime RAII object. + StatsDuration &GetSymtabParseTime() { return m_symtab_parse_time; } + + /// Accessor for the symbol table index time metric. + /// + /// The value is returned as a reference to allow it to be updated by the + /// ElapsedTime RAII object. + StatsDuration &GetSymtabIndexTime() { return m_symtab_index_time; } + /// \class LookupInfo Module.h "lldb/Core/Module.h" /// A class that encapsulates name lookup information. /// @@ -995,6 +1008,14 @@ mutable bool m_file_has_changed : 1, m_first_file_changed_log : 1; /// See if the module was modified after it /// was initially opened. + /// We store a symbol table parse time duration here because we might have + /// an object file and a symbol file which both have symbol tables. The parse + /// time for the symbol tables can be aggregated here. + StatsDuration m_symtab_parse_time{0.0}; + /// We store a symbol named index time duration here because we might have + /// an object file and a symbol file which both have symbol tables. The parse + /// time for the symbol tables can be aggregated here. + StatsDuration m_symtab_index_time{0.0}; /// Resolve a file or load virtual address. /// diff --git a/lldb/include/lldb/Target/Statistics.h b/lldb/include/lldb/Target/Statistics.h --- a/lldb/include/lldb/Target/Statistics.h +++ b/lldb/include/lldb/Target/Statistics.h @@ -72,10 +72,21 @@ uint32_t failures = 0; }; +/// A class that represents statistics for a since lldb_private::Module. +struct ModuleStats { + llvm::json::Value ToJSON() const; + + std::string path; + std::string uuid; + std::string triple; + double symtab_parse_time = 0.0; + double symtab_index_time = 0.0; +}; + /// A class that represents statistics for a since lldb_private::Target. class TargetStats { public: - llvm::json::Value ToJSON(); + llvm::json::Value ToJSON(Target &target); void SetLaunchOrAttachTime(); void SetFirstPrivateStopTime(); @@ -92,6 +103,9 @@ llvm::Optional<StatsTimepoint> m_first_public_stop_time; StatsSuccessFail m_expr_eval{"expressionEvaluation"}; StatsSuccessFail m_frame_var{"frameVariable"}; + std::vector<ModuleStats> m_modules; + + void CollectStats(Target &target); }; class DebuggerStats { diff --git a/lldb/source/Plugins/ObjectFile/ELF/ObjectFileELF.cpp b/lldb/source/Plugins/ObjectFile/ELF/ObjectFileELF.cpp --- a/lldb/source/Plugins/ObjectFile/ELF/ObjectFileELF.cpp +++ b/lldb/source/Plugins/ObjectFile/ELF/ObjectFileELF.cpp @@ -2692,9 +2692,6 @@ if (!module_sp) return nullptr; - Progress progress(llvm::formatv("Parsing symbol table for {0}", - m_file.GetFilename().AsCString("<Unknown>"))); - // We always want to use the main object file so we (hopefully) only have one // cached copy of our symtab, dynamic sections, etc. ObjectFile *module_obj_file = module_sp->GetObjectFile(); @@ -2702,6 +2699,10 @@ return module_obj_file->GetSymtab(); if (m_symtab_up == nullptr) { + Progress progress( + llvm::formatv("Parsing symbol table for {0}", + m_file.GetFilename().AsCString("<Unknown>"))); + ElapsedTime elapsed(module_sp->GetSymtabParseTime()); SectionList *section_list = module_sp->GetSectionList(); if (!section_list) return nullptr; diff --git a/lldb/source/Plugins/ObjectFile/JIT/ObjectFileJIT.cpp b/lldb/source/Plugins/ObjectFile/JIT/ObjectFileJIT.cpp --- a/lldb/source/Plugins/ObjectFile/JIT/ObjectFileJIT.cpp +++ b/lldb/source/Plugins/ObjectFile/JIT/ObjectFileJIT.cpp @@ -111,6 +111,7 @@ if (module_sp) { std::lock_guard<std::recursive_mutex> guard(module_sp->GetMutex()); if (m_symtab_up == nullptr) { + ElapsedTime elapsed(module_sp->GetSymtabParseTime()); m_symtab_up = std::make_unique<Symtab>(this); std::lock_guard<std::recursive_mutex> symtab_guard( m_symtab_up->GetMutex()); diff --git a/lldb/source/Plugins/ObjectFile/Mach-O/ObjectFileMachO.cpp b/lldb/source/Plugins/ObjectFile/Mach-O/ObjectFileMachO.cpp --- a/lldb/source/Plugins/ObjectFile/Mach-O/ObjectFileMachO.cpp +++ b/lldb/source/Plugins/ObjectFile/Mach-O/ObjectFileMachO.cpp @@ -1316,6 +1316,7 @@ if (module_sp) { std::lock_guard<std::recursive_mutex> guard(module_sp->GetMutex()); if (m_symtab_up == nullptr) { + ElapsedTime elapsed(module_sp->GetSymtabParseTime()); m_symtab_up = std::make_unique<Symtab>(this); std::lock_guard<std::recursive_mutex> symtab_guard( m_symtab_up->GetMutex()); diff --git a/lldb/source/Plugins/ObjectFile/PECOFF/ObjectFilePECOFF.cpp b/lldb/source/Plugins/ObjectFile/PECOFF/ObjectFilePECOFF.cpp --- a/lldb/source/Plugins/ObjectFile/PECOFF/ObjectFilePECOFF.cpp +++ b/lldb/source/Plugins/ObjectFile/PECOFF/ObjectFilePECOFF.cpp @@ -595,6 +595,7 @@ if (module_sp) { std::lock_guard<std::recursive_mutex> guard(module_sp->GetMutex()); if (m_symtab_up == nullptr) { + ElapsedTime elapsed(module_sp->GetSymtabParseTime()); SectionList *sect_list = GetSectionList(); m_symtab_up = std::make_unique<Symtab>(this); std::lock_guard<std::recursive_mutex> guard(m_symtab_up->GetMutex()); diff --git a/lldb/source/Symbol/Symtab.cpp b/lldb/source/Symbol/Symtab.cpp --- a/lldb/source/Symbol/Symtab.cpp +++ b/lldb/source/Symbol/Symtab.cpp @@ -265,6 +265,7 @@ // Protected function, no need to lock mutex... if (!m_name_indexes_computed) { m_name_indexes_computed = true; + ElapsedTime elapsed(m_objfile->GetModule()->GetSymtabIndexTime()); LLDB_SCOPED_TIMER(); // Collect all loaded language plugins. diff --git a/lldb/source/Target/Statistics.cpp b/lldb/source/Target/Statistics.cpp --- a/lldb/source/Target/Statistics.cpp +++ b/lldb/source/Target/Statistics.cpp @@ -17,6 +17,16 @@ using namespace lldb_private; using namespace llvm; +static void EmplaceSafeString(llvm::json::Object &obj, llvm::StringRef key, + const std::string &str) { + if (str.empty()) + return; + if (LLVM_LIKELY(llvm::json::isUTF8(str))) + obj.try_emplace(key, str); + else + obj.try_emplace(key, llvm::json::fixUTF8(str)); +} + json::Value StatsSuccessFail::ToJSON() const { return json::Object{{"successes", successes}, {"failures", failures}}; } @@ -26,9 +36,49 @@ return elapsed.count(); } -json::Value TargetStats::ToJSON() { - json::Object target_metrics_json{{m_expr_eval.name, m_expr_eval.ToJSON()}, - {m_frame_var.name, m_frame_var.ToJSON()}}; +void TargetStats::CollectStats(Target &target) { + m_modules.clear(); + for (ModuleSP module_sp : target.GetImages().Modules()) { + ModuleStats module; + module.path = module_sp->GetFileSpec().GetPath(); + module.uuid = module_sp->GetUUID().GetAsString(); + module.triple = module_sp->GetArchitecture().GetTriple().str(); + module.symtab_parse_time = module_sp->GetSymtabParseTime().count(); + module.symtab_index_time = module_sp->GetSymtabIndexTime().count(); + m_modules.push_back(std::move(module)); + } +} + +json::Value ModuleStats::ToJSON() const { + json::Object module; + EmplaceSafeString(module, "path", path); + EmplaceSafeString(module, "uuid", uuid); + EmplaceSafeString(module, "triple", triple); + module.try_emplace("symbolTableParseTime", symtab_parse_time); + module.try_emplace("symbolTableIndexTime", symtab_index_time); + return module; +} + +json::Value TargetStats::ToJSON(Target &target) { + CollectStats(target); + double symtab_parse_time = 0.0; + double symtab_index_time = 0.0; + + json::Array modules; + for (const auto &module : m_modules) { + modules.push_back(module.ToJSON()); + symtab_parse_time += module.symtab_parse_time; + symtab_index_time += module.symtab_index_time; + } + + json::Object target_metrics_json{ + {m_expr_eval.name, m_expr_eval.ToJSON()}, + {m_frame_var.name, m_frame_var.ToJSON()}, + {"totalSymbolTableParseTime", symtab_parse_time}, + {"totalSymbolTableIndexTime", symtab_index_time}, + {"modules", std::move(modules)} + }; + if (m_launch_or_attach_time && m_first_private_stop_time) { double elapsed_time = elapsed(*m_launch_or_attach_time, *m_first_private_stop_time); diff --git a/lldb/source/Target/Target.cpp b/lldb/source/Target/Target.cpp --- a/lldb/source/Target/Target.cpp +++ b/lldb/source/Target/Target.cpp @@ -4454,4 +4454,4 @@ } /// Get metrics associated with this target in JSON format. -llvm::json::Value Target::ReportStatistics() { return m_stats.ToJSON(); } +llvm::json::Value Target::ReportStatistics() { return m_stats.ToJSON(*this); } diff --git a/lldb/test/API/commands/statistics/basic/TestStats.py b/lldb/test/API/commands/statistics/basic/TestStats.py --- a/lldb/test/API/commands/statistics/basic/TestStats.py +++ b/lldb/test/API/commands/statistics/basic/TestStats.py @@ -139,7 +139,10 @@ keys_exist = [ 'expressionEvaluation', 'frameVariable', + 'modules', 'targetCreateTime', + 'totalSymbolTableParseTime', + 'totalSymbolTableIndexTime' ] keys_missing = [ 'firstStopTime', @@ -181,9 +184,69 @@ 'firstStopTime', 'frameVariable', 'launchOrAttachTime', + 'modules', 'targetCreateTime', + 'totalSymbolTableParseTime', + 'totalSymbolTableIndexTime' ] self.verify_keys(stats, '"stats"', keys_exist, None) self.assertGreater(stats['firstStopTime'], 0.0) self.assertGreater(stats['launchOrAttachTime'], 0.0) self.assertGreater(stats['targetCreateTime'], 0.0) + + def find_module_in_metrics(self, path, stats): + modules = stats['modules'] + for module in modules: + if module['path'] == path: + return module + return None + + def test_modules(self): + """Test "statistics dump --modules" + + Output expected to be something like: + + (lldb) statistics dump --modules + { + "targetCreateTime": 0.26566899599999999, + "totalSymbolTableIndexTime": 0.056834488000000009, + "totalSymbolTableParseTime": 0.093979421999999979, + "modules": [ + { + "path": "/.../TestStats.test_modules/a.out", + "symbolTableIndexTime": 2.3816e-05, + "symbolTableParseTime": 0.000163747, + "triple": "x86_64-apple-macosx11.0.0", + "uuid": "10531B95-4DF4-3FFE-9D51-549DD17435E2" + }, + { + "path": "/.../TestStats.test_modules/libload_a.dylib", + "symbolTableIndexTime": 2.7852999999999999e-05, + "symbolTableParseTime": 0.000110246, + "triple": "x86_64-apple-macosx11.0.0", + "uuid": "F0974CDE-309A-3837-9593-385ABDC93803" + }, + ] + } + + """ + exe = self.getBuildArtifact("a.out") + target = self.createTestTarget(file_path=exe) + stats = self.get_stats(log_path="/tmp/test_default_no_run.txt") + keys_exist = [ + 'targetCreateTime', + 'totalSymbolTableIndexTime', + 'totalSymbolTableParseTime', + 'modules', + ] + self.verify_keys(stats, '"stats"', keys_exist, None) + exe_module = self.find_module_in_metrics(exe, stats) + module_keys = [ + 'path', + 'symbolTableIndexTime', + 'symbolTableParseTime', + 'triple', + 'uuid', + ] + self.assertNotEqual(exe_module, None) + self.verify_keys(exe_module, 'module dict for "%s"' % (exe), module_keys)