Add download time for each module in statistics

Author: George Hu

lldb/include/lldb/Core/PluginManager.h

@@ -377,11 +377,14 @@ class PluginManager {
   static SymbolLocatorCreateInstance
   GetSymbolLocatorCreateCallbackAtIndex(uint32_t idx);
 
-  static ModuleSpec LocateExecutableObjectFile(const ModuleSpec &module_spec);
+  static ModuleSpec
+  LocateExecutableObjectFile(const ModuleSpec &module_spec,
+                             std::string *locator_name = nullptr);
 
   static FileSpec
   LocateExecutableSymbolFile(const ModuleSpec &module_spec,
-                             const FileSpecList &default_search_paths);
+                             const FileSpecList &default_search_paths,
+                             std::string *locator_name = nullptr);
 
   static bool DownloadObjectAndSymbolFile(ModuleSpec &module_spec,
                                           Status &error,

lldb/include/lldb/Symbol/ObjectFile.h

@@ -13,6 +13,7 @@
 #include "lldb/Core/PluginInterface.h"
 #include "lldb/Symbol/Symtab.h"
 #include "lldb/Symbol/UnwindTable.h"
+#include "lldb/Target/Statistics.h"
 #include "lldb/Utility/AddressableBits.h"
 #include "lldb/Utility/DataExtractor.h"
 #include "lldb/Utility/Endian.h"
@@ -589,6 +590,8 @@ class ObjectFile : public std::enable_shared_from_this<ObjectFile>,
   /// this routine to set eTypeDebugInfo when loading debug link files.
   virtual void SetType(Type type) { m_type = type; }
 
+  virtual StatsDuration &GetDownloadTime() { return m_download_time; }
+
   /// The object file should be able to calculate the strata of the object
   /// file.
   ///
@@ -752,6 +755,7 @@ class ObjectFile : public std::enable_shared_from_this<ObjectFile>,
 
 protected:
   // Member variables.
+  StatsDuration m_download_time; ///< Time to download the object file
   FileSpec m_file;
   Type m_type;
   Strata m_strata;

lldb/include/lldb/Symbol/SymbolFile.h

@@ -422,6 +422,11 @@ class SymbolFile : public PluginInterface {
   /// hasn't been indexed yet, or a valid duration if it has.
   virtual StatsDuration::Duration GetDebugInfoIndexTime() { return {}; }
 
+  /// Return the time it took to download any extra symbol files.
+  ///
+  /// \returns 0.0 if no extra symbol files need to be downloaded
+  virtual StatsDuration::Duration GetSymbolDownloadTime() { return {}; }
+
   /// Reset the statistics for the symbol file.
   virtual void ResetStatistics() {}
 

lldb/include/lldb/Target/Statistics.h

@@ -122,6 +122,7 @@ struct ModuleStats {
   double symtab_index_time = 0.0;
   double debug_parse_time = 0.0;
   double debug_index_time = 0.0;
+  double symbol_download_time = 0.0;
   uint64_t debug_info_size = 0;
   bool symtab_loaded_from_cache = false;
   bool symtab_saved_to_cache = false;

lldb/source/Core/DynamicLoader.cpp

@@ -16,6 +16,7 @@
 #include "lldb/Core/Progress.h"
 #include "lldb/Core/Section.h"
 #include "lldb/Symbol/ObjectFile.h"
+#include "lldb/Symbol/SymbolFile.h"
 #include "lldb/Target/MemoryRegionInfo.h"
 #include "lldb/Target/Platform.h"
 #include "lldb/Target/Process.h"
@@ -25,6 +26,8 @@
 #include "lldb/Utility/Log.h"
 #include "lldb/lldb-private-interfaces.h"
 
+#include "Plugins/SymbolLocator/Debuginfod/SymbolLocatorDebuginfod.h"
+
 #include "llvm/ADT/StringRef.h"
 
 #include <memory>
@@ -243,15 +246,40 @@ ModuleSP DynamicLoader::LoadBinaryWithUUIDAndAddress(
     // find an executable and symbol file.
     if (!module_sp) {
       FileSpecList search_paths = Target::GetDefaultDebugFileSearchPaths();
-      module_spec.GetSymbolFileSpec() =
-          PluginManager::LocateExecutableSymbolFile(module_spec, search_paths);
-      ModuleSpec objfile_module_spec =
-          PluginManager::LocateExecutableObjectFile(module_spec);
+      StatsDuration symbol_duration;
+      std::string symbol_locator_name;
+      StatsDuration object_duration;
+      std::string object_locator_name;
+      ModuleSpec objfile_module_spec;
+      {
+        ElapsedTime elapsed(symbol_duration);
+        module_spec.GetSymbolFileSpec() =
+            PluginManager::LocateExecutableSymbolFile(module_spec, search_paths,
+                                                      &symbol_locator_name);
+      }
+      {
+        ElapsedTime elapsed(object_duration);
+        objfile_module_spec = PluginManager::LocateExecutableObjectFile(
+            module_spec, &object_locator_name);
+      }
       module_spec.GetFileSpec() = objfile_module_spec.GetFileSpec();
       if (FileSystem::Instance().Exists(module_spec.GetFileSpec()) &&
           FileSystem::Instance().Exists(module_spec.GetSymbolFileSpec())) {
         module_sp = std::make_shared<Module>(module_spec);
       }
+      if (module_sp) {
+        if (object_locator_name ==
+                SymbolLocatorDebuginfod::GetPluginNameStatic() &&
+            module_sp->GetObjectFile())
+          module_sp->GetObjectFile()->GetDownloadTime() += object_duration;
+        if (symbol_locator_name ==
+            SymbolLocatorDebuginfod::GetPluginNameStatic()) {
+          const auto symfile = module_sp->GetSymbolFile();
+          if (symfile) {
+            symfile->GetObjectFile()->GetDownloadTime() += symbol_duration;
+          }
+        }
+      }
     }
 
     // If we haven't found a binary, or we don't have a SymbolFile, see

lldb/source/Core/ModuleList.cpp

@@ -7,6 +7,7 @@
 //===----------------------------------------------------------------------===//
 
 #include "lldb/Core/ModuleList.h"
+#include "Plugins/SymbolLocator/Debuginfod/SymbolLocatorDebuginfod.h"
 #include "lldb/Core/Module.h"
 #include "lldb/Core/ModuleSpec.h"
 #include "lldb/Core/PluginManager.h"
@@ -917,9 +918,14 @@ ModuleList::GetSharedModule(const ModuleSpec &module_spec, ModuleSP &module_sp,
 
   // Fixup the incoming path in case the path points to a valid file, yet the
   // arch or UUID (if one was passed in) don't match.
-  ModuleSpec located_binary_modulespec =
-      PluginManager::LocateExecutableObjectFile(module_spec);
-
+  ModuleSpec located_binary_modulespec;
+  StatsDuration locate_duration;
+  std::string locator_name;
+  {
+    ElapsedTime elapsed(locate_duration);
+    located_binary_modulespec =
+        PluginManager::LocateExecutableObjectFile(module_spec, &locator_name);
+  }
   // Don't look for the file if it appears to be the same one we already
   // checked for above...
   if (located_binary_modulespec.GetFileSpec() != module_file_spec) {
@@ -992,6 +998,8 @@ ModuleList::GetSharedModule(const ModuleSpec &module_spec, ModuleSP &module_sp,
       // By getting the object file we can guarantee that the architecture
       // matches
       if (module_sp && module_sp->GetObjectFile()) {
+        if (locator_name == SymbolLocatorDebuginfod::GetPluginNameStatic())
+          module_sp->GetObjectFile()->GetDownloadTime() += locate_duration;
         if (module_sp->GetObjectFile()->GetType() ==
             ObjectFile::eTypeStubLibrary) {
           module_sp.reset();

lldb/source/Core/PluginManager.cpp

@@ -1217,28 +1217,36 @@ PluginManager::GetSymbolLocatorCreateCallbackAtIndex(uint32_t idx) {
 }
 
 ModuleSpec
-PluginManager::LocateExecutableObjectFile(const ModuleSpec &module_spec) {
+PluginManager::LocateExecutableObjectFile(const ModuleSpec &module_spec,
+                                          std::string *locator_name) {
   auto instances = GetSymbolLocatorInstances().GetSnapshot();
   for (auto &instance : instances) {
     if (instance.locate_executable_object_file) {
       std::optional<ModuleSpec> result =
           instance.locate_executable_object_file(module_spec);
-      if (result)
+      if (result) {
+        if (locator_name)
+          *locator_name = instance.name;
         return *result;
+      }
     }
   }
   return {};
 }
 
 FileSpec PluginManager::LocateExecutableSymbolFile(
-    const ModuleSpec &module_spec, const FileSpecList &default_search_paths) {
+    const ModuleSpec &module_spec, const FileSpecList &default_search_paths,
+    std::string *locator_name) {
   auto instances = GetSymbolLocatorInstances().GetSnapshot();
   for (auto &instance : instances) {
     if (instance.locate_executable_symbol_file) {
       std::optional<FileSpec> result = instance.locate_executable_symbol_file(
           module_spec, default_search_paths);
-      if (result)
+      if (result) {
+        if (locator_name)
+          *locator_name = instance.name;
         return *result;
+      }
     }
   }
   return {};

lldb/source/Plugins/SymbolFile/DWARF/SymbolFileDWARF.cpp

@@ -32,6 +32,7 @@
 
 #include "Plugins/ExpressionParser/Clang/ClangModulesDeclVendor.h"
 #include "Plugins/Language/CPlusPlus/CPlusPlusLanguage.h"
+#include "Plugins/SymbolLocator/Debuginfod/SymbolLocatorDebuginfod.h"
 
 #include "lldb/Host/FileSystem.h"
 #include "lldb/Host/Host.h"
@@ -4250,13 +4251,18 @@ const std::shared_ptr<SymbolFileDWARFDwo> &SymbolFileDWARF::GetDwpSymbolFile() {
     ModuleSpec module_spec;
     module_spec.GetFileSpec() = m_objfile_sp->GetFileSpec();
     FileSpec dwp_filespec;
+    StatsDuration duration;
+    std::string locator_name;
     for (const auto &symfile : symfiles.files()) {
       module_spec.GetSymbolFileSpec() =
           FileSpec(symfile.GetPath() + ".dwp", symfile.GetPathStyle());
       LLDB_LOG(log, "Searching for DWP using: \"{0}\"",
                module_spec.GetSymbolFileSpec());
-      dwp_filespec =
-          PluginManager::LocateExecutableSymbolFile(module_spec, search_paths);
+      {
+        ElapsedTime elapsed(duration);
+        dwp_filespec = PluginManager::LocateExecutableSymbolFile(
+            module_spec, search_paths, &locator_name);
+      }
       if (FileSystem::Instance().Exists(dwp_filespec)) {
         break;
       }
@@ -4267,8 +4273,12 @@ const std::shared_ptr<SymbolFileDWARFDwo> &SymbolFileDWARF::GetDwpSymbolFile() {
       // find the correct DWP file, as the Debuginfod plugin uses *only* this
       // data to correctly match the DWP file with the binary.
       module_spec.GetUUID() = m_objfile_sp->GetUUID();
-      dwp_filespec =
-          PluginManager::LocateExecutableSymbolFile(module_spec, search_paths);
+      duration.reset();
+      {
+        ElapsedTime elapsed(duration);
+        dwp_filespec = PluginManager::LocateExecutableSymbolFile(
+            module_spec, search_paths, &locator_name);
+      }
     }
     if (FileSystem::Instance().Exists(dwp_filespec)) {
       LLDB_LOG(log, "Found DWP file: \"{0}\"", dwp_filespec);
@@ -4279,6 +4289,8 @@ const std::shared_ptr<SymbolFileDWARFDwo> &SymbolFileDWARF::GetDwpSymbolFile() {
           FileSystem::Instance().GetByteSize(dwp_filespec), dwp_file_data_sp,
           dwp_file_data_offset);
       if (dwp_obj_file) {
+        if (locator_name == SymbolLocatorDebuginfod::GetPluginNameStatic())
+          dwp_obj_file->GetDownloadTime() += duration;
         m_dwp_symfile = std::make_shared<SymbolFileDWARFDwo>(
             *this, dwp_obj_file, DIERef::k_file_index_mask);
       }
@@ -4349,6 +4361,14 @@ LanguageType SymbolFileDWARF::GetLanguageFamily(DWARFUnit &unit) {
   return LanguageTypeFromDWARF(lang);
 }
 
+StatsDuration::Duration SymbolFileDWARF::GetSymbolDownloadTime() {
+  StatsDuration total_time;
+  total_time += GetObjectFile()->GetDownloadTime();
+  if (m_dwp_symfile)
+    total_time += m_dwp_symfile->GetObjectFile()->GetDownloadTime();
+  return total_time;
+}
+
 StatsDuration::Duration SymbolFileDWARF::GetDebugInfoIndexTime() {
   if (m_index)
     return m_index->GetIndexTime();

lldb/source/Plugins/SymbolFile/DWARF/SymbolFileDWARF.h

@@ -309,6 +309,9 @@ class SymbolFileDWARF : public SymbolFileCommon {
   StatsDuration::Duration GetDebugInfoParseTime() override {
     return m_parse_time;
   }
+
+  StatsDuration::Duration GetSymbolDownloadTime() override;
+
   StatsDuration::Duration GetDebugInfoIndexTime() override;
 
   StatsDuration &GetDebugInfoParseTimeRef() { return m_parse_time; }

lldb/source/Plugins/SymbolVendor/ELF/SymbolVendorELF.cpp

@@ -21,6 +21,8 @@
 #include "lldb/Utility/StreamString.h"
 #include "lldb/Utility/Timer.h"
 
+#include "Plugins/SymbolLocator/Debuginfod/SymbolLocatorDebuginfod.h"
+
 using namespace lldb;
 using namespace lldb_private;
 
@@ -103,14 +105,25 @@ SymbolVendorELF::CreateInstance(const lldb::ModuleSP &module_sp,
   module_spec.GetSymbolFileSpec() = fspec;
   module_spec.GetUUID() = uuid;
   FileSpecList search_paths = Target::GetDefaultDebugFileSearchPaths();
-  FileSpec dsym_fspec =
-      PluginManager::LocateExecutableSymbolFile(module_spec, search_paths);
+  StatsDuration duration;
+  FileSpec dsym_fspec;
+  std::string locator_name;
+  {
+    ElapsedTime elapsed(duration);
+    dsym_fspec = PluginManager::LocateExecutableSymbolFile(
+        module_spec, search_paths, &locator_name);
+  }
   if (!dsym_fspec || IsDwpSymbolFile(module_sp, dsym_fspec)) {
     // If we have a stripped binary or if we have a DWP file, SymbolLocator
     // plugins may be able to give us an unstripped binary or an
     // 'only-keep-debug' stripped file.
-    ModuleSpec unstripped_spec =
-        PluginManager::LocateExecutableObjectFile(module_spec);
+    ModuleSpec unstripped_spec;
+    duration.reset();
+    {
+      ElapsedTime elapsed(duration);
+      unstripped_spec =
+          PluginManager::LocateExecutableObjectFile(module_spec, &locator_name);
+    }
     if (!unstripped_spec)
       return nullptr;
     // The default SymbolLocator plugin returns the original binary if no other
@@ -127,7 +140,8 @@ SymbolVendorELF::CreateInstance(const lldb::ModuleSP &module_sp,
       dsym_file_data_sp, dsym_file_data_offset);
   if (!dsym_objfile_sp)
     return nullptr;
-
+  if (locator_name == SymbolLocatorDebuginfod::GetPluginNameStatic())
+    dsym_objfile_sp->GetDownloadTime() += duration;
   // This objfile is for debugging purposes. Sadly, ObjectFileELF won't
   // be able to figure this out consistently as the symbol file may not
   // have stripped the code sections, etc.

lldb/source/Target/Statistics.cpp

@@ -71,6 +71,7 @@ json::Value ModuleStats::ToJSON() const {
   module.try_emplace("debugInfoHadIncompleteTypes",
                      debug_info_had_incomplete_types);
   module.try_emplace("symbolTableStripped", symtab_stripped);
+  module.try_emplace("symbolDownloadTime", symbol_download_time);
   if (!symfile_path.empty())
     module.try_emplace("symbolFilePath", symfile_path);
 
@@ -288,6 +289,7 @@ llvm::json::Value DebuggerStats::ReportStatistics(
 
   json::Array json_targets;
   json::Array json_modules;
+  double symbol_download_time = 0.0;
   double symtab_parse_time = 0.0;
   double symtab_index_time = 0.0;
   double debug_parse_time = 0.0;
@@ -345,6 +347,11 @@ llvm::json::Value DebuggerStats::ReportStatistics(
         ++debug_index_saved;
       module_stat.debug_index_time = sym_file->GetDebugInfoIndexTime().count();
       module_stat.debug_parse_time = sym_file->GetDebugInfoParseTime().count();
+      module_stat.symbol_download_time +=
+          sym_file->GetSymbolDownloadTime().count();
+      if (sym_file->GetObjectFile() != module->GetObjectFile())
+        module_stat.symbol_download_time +=
+            module->GetObjectFile()->GetDownloadTime().get().count();
       module_stat.debug_info_size =
           sym_file->GetDebugInfoSize(load_all_debug_info);
       module_stat.symtab_stripped = module->GetObjectFile()->IsStripped();
@@ -361,6 +368,7 @@ llvm::json::Value DebuggerStats::ReportStatistics(
       if (module_stat.debug_info_had_variable_errors)
         ++num_modules_with_variable_errors;
     }
+    symbol_download_time += module_stat.symbol_download_time;
     symtab_parse_time += module_stat.symtab_parse_time;
     symtab_index_time += module_stat.symtab_index_time;
     debug_parse_time += module_stat.debug_parse_time;
@@ -391,6 +399,7 @@ llvm::json::Value DebuggerStats::ReportStatistics(
   }
 
   json::Object global_stats{
+      {"totalSymbolDownloadTime", symbol_download_time},
       {"totalSymbolTableParseTime", symtab_parse_time},
       {"totalSymbolTableIndexTime", symtab_index_time},
       {"totalSymbolTablesLoadedFromCache", symtabs_loaded},