[clang-tools-extra] [clang-doc] add ftime profiling (PR #97644)

via cfe-commits cfe-commits at lists.llvm.org
Wed Jul 3 14:42:20 PDT 2024


llvmbot wrote:


<!--LLVM PR SUMMARY COMMENT-->

@llvm/pr-subscribers-clang-tools-extra

Author: None (PeterChou1)

<details>
<summary>Changes</summary>

this patches adds ftime-tracing option for clang-doc which was what I used to profile the performance problems we had with clang-doc generating the llvm docs.

It introduces two option --ftime-trace and --ftime-gran 
- ftime-trace  produces a time profiler json file called clang-doc-tracing.json
- ftime-gran allows the user to specify the granularity of the profiling

---
Full diff: https://github.com/llvm/llvm-project/pull/97644.diff


5 Files Affected:

- (modified) clang-tools-extra/clang-doc/BitcodeReader.cpp (+8) 
- (modified) clang-tools-extra/clang-doc/Mapper.cpp (+12-1) 
- (modified) clang-tools-extra/clang-doc/Representation.cpp (+2) 
- (modified) clang-tools-extra/clang-doc/Representation.h (+4-1) 
- (modified) clang-tools-extra/clang-doc/tool/ClangDocMain.cpp (+49-2) 


``````````diff
diff --git a/clang-tools-extra/clang-doc/BitcodeReader.cpp b/clang-tools-extra/clang-doc/BitcodeReader.cpp
index bfb04e7407b38..2fa228dd7b180 100644
--- a/clang-tools-extra/clang-doc/BitcodeReader.cpp
+++ b/clang-tools-extra/clang-doc/BitcodeReader.cpp
@@ -10,6 +10,7 @@
 #include "llvm/ADT/IndexedMap.h"
 #include "llvm/Support/Error.h"
 #include "llvm/Support/raw_ostream.h"
+#include "llvm/Support/TimeProfiler.h"
 #include <optional>
 
 namespace clang {
@@ -670,6 +671,7 @@ llvm::Error ClangDocBitcodeReader::readRecord(unsigned ID, T I) {
 
 template <>
 llvm::Error ClangDocBitcodeReader::readRecord(unsigned ID, Reference *I) {
+  llvm::TimeTraceScope("clang-doc", "readRecord Reference");
   Record R;
   llvm::StringRef Blob;
   llvm::Expected<unsigned> MaybeRecID = Stream.readRecord(ID, R, &Blob);
@@ -681,6 +683,7 @@ llvm::Error ClangDocBitcodeReader::readRecord(unsigned ID, Reference *I) {
 // Read a block of records into a single info.
 template <typename T>
 llvm::Error ClangDocBitcodeReader::readBlock(unsigned ID, T I) {
+  llvm::TimeTraceScope("readBlock", "ClangDocBitcodeReader");
   if (llvm::Error Err = Stream.EnterSubBlock(ID))
     return Err;
 
@@ -711,6 +714,7 @@ llvm::Error ClangDocBitcodeReader::readBlock(unsigned ID, T I) {
 
 template <typename T>
 llvm::Error ClangDocBitcodeReader::readSubBlock(unsigned ID, T I) {
+  llvm::TimeTraceScope("readSubBlock", "ClangDocBitcodeReader");
   switch (ID) {
   // Blocks can only have certain types of sub blocks.
   case BI_COMMENT_BLOCK_ID: {
@@ -817,6 +821,7 @@ llvm::Error ClangDocBitcodeReader::readSubBlock(unsigned ID, T I) {
 
 ClangDocBitcodeReader::Cursor
 ClangDocBitcodeReader::skipUntilRecordOrBlock(unsigned &BlockOrRecordID) {
+  llvm::TimeTraceScope("skipUntilRecordOrBlock", "ClangDocBitcodeReader");
   BlockOrRecordID = 0;
 
   while (!Stream.AtEndOfStream()) {
@@ -878,6 +883,7 @@ llvm::Error ClangDocBitcodeReader::validateStream() {
 }
 
 llvm::Error ClangDocBitcodeReader::readBlockInfoBlock() {
+  llvm::TimeTraceScope("readBlockInfoBlock", "ClangDocBitcodeReader");
   Expected<std::optional<llvm::BitstreamBlockInfo>> MaybeBlockInfo =
       Stream.ReadBlockInfoBlock();
   if (!MaybeBlockInfo)
@@ -894,6 +900,7 @@ llvm::Error ClangDocBitcodeReader::readBlockInfoBlock() {
 template <typename T>
 llvm::Expected<std::unique_ptr<Info>>
 ClangDocBitcodeReader::createInfo(unsigned ID) {
+  llvm::TimeTraceScope("createInfo", "ClangDocBitcodeReader");
   std::unique_ptr<Info> I = std::make_unique<T>();
   if (auto Err = readBlock(ID, static_cast<T *>(I.get())))
     return std::move(Err);
@@ -902,6 +909,7 @@ ClangDocBitcodeReader::createInfo(unsigned ID) {
 
 llvm::Expected<std::unique_ptr<Info>>
 ClangDocBitcodeReader::readBlockToInfo(unsigned ID) {
+  llvm::TimeTraceScope("readBlockToInfo", "ClangDocBitcodeReader");
   switch (ID) {
   case BI_NAMESPACE_BLOCK_ID:
     return createInfo<NamespaceInfo>(ID);
diff --git a/clang-tools-extra/clang-doc/Mapper.cpp b/clang-tools-extra/clang-doc/Mapper.cpp
index bb8b7952980ac..d56546dbfa73f 100644
--- a/clang-tools-extra/clang-doc/Mapper.cpp
+++ b/clang-tools-extra/clang-doc/Mapper.cpp
@@ -13,12 +13,17 @@
 #include "clang/Index/USRGeneration.h"
 #include "llvm/ADT/StringExtras.h"
 #include "llvm/Support/Error.h"
+#include "llvm/Support/TimeProfiler.h"
 
 namespace clang {
 namespace doc {
 
 void MapASTVisitor::HandleTranslationUnit(ASTContext &Context) {
+  if (CDCtx.FTimeTrace)
+    llvm::timeTraceProfilerInitialize(CDCtx.Granularity, "clang-doc");
   TraverseDecl(Context.getTranslationUnitDecl());
+  if (CDCtx.FTimeTrace)
+    llvm::timeTraceProfilerFinishThread();
 }
 
 template <typename T> bool MapASTVisitor::mapDecl(const T *D) {
@@ -30,6 +35,7 @@ template <typename T> bool MapASTVisitor::mapDecl(const T *D) {
   if (D->getParentFunctionOrMethod())
     return true;
 
+  llvm::timeTraceProfilerBegin("emit info phase", "emit info");
   llvm::SmallString<128> USR;
   // If there is an error generating a USR for the decl, skip this decl.
   if (index::generateUSRForDecl(D, USR))
@@ -40,7 +46,9 @@ template <typename T> bool MapASTVisitor::mapDecl(const T *D) {
   auto I = serialize::emitInfo(D, getComment(D, D->getASTContext()),
                                getLine(D, D->getASTContext()), File,
                                IsFileInRootDir, CDCtx.PublicOnly);
+  llvm::timeTraceProfilerEnd();
 
+  llvm::timeTraceProfilerBegin("serializing info", "serializing");
   // A null in place of I indicates that the serializer is skipping this decl
   // for some reason (e.g. we're only reporting public decls).
   if (I.first)
@@ -49,6 +57,7 @@ template <typename T> bool MapASTVisitor::mapDecl(const T *D) {
   if (I.second)
     CDCtx.ECtx->reportResult(llvm::toHex(llvm::toStringRef(I.second->USR)),
                              serialize::serialize(I.second));
+  llvm::timeTraceProfilerEnd();
   return true;
 }
 
@@ -56,7 +65,9 @@ bool MapASTVisitor::VisitNamespaceDecl(const NamespaceDecl *D) {
   return mapDecl(D);
 }
 
-bool MapASTVisitor::VisitRecordDecl(const RecordDecl *D) { return mapDecl(D); }
+bool MapASTVisitor::VisitRecordDecl(const RecordDecl *D) {
+  return mapDecl(D);
+}
 
 bool MapASTVisitor::VisitEnumDecl(const EnumDecl *D) { return mapDecl(D); }
 
diff --git a/clang-tools-extra/clang-doc/Representation.cpp b/clang-tools-extra/clang-doc/Representation.cpp
index d08afbb962189..23e739a675789 100644
--- a/clang-tools-extra/clang-doc/Representation.cpp
+++ b/clang-tools-extra/clang-doc/Representation.cpp
@@ -366,10 +366,12 @@ void Index::sort() {
 
 ClangDocContext::ClangDocContext(tooling::ExecutionContext *ECtx,
                                  StringRef ProjectName, bool PublicOnly,
+                                 bool FTimeTrace, int Granularity,
                                  StringRef OutDirectory, StringRef SourceRoot,
                                  StringRef RepositoryUrl,
                                  std::vector<std::string> UserStylesheets)
     : ECtx(ECtx), ProjectName(ProjectName), PublicOnly(PublicOnly),
+      FTimeTrace(FTimeTrace), Granularity(Granularity),
       OutDirectory(OutDirectory), UserStylesheets(UserStylesheets) {
   llvm::SmallString<128> SourceRootDir(SourceRoot);
   if (SourceRoot.empty())
diff --git a/clang-tools-extra/clang-doc/Representation.h b/clang-tools-extra/clang-doc/Representation.h
index d70c279f7a2bd..619fa34da8779 100644
--- a/clang-tools-extra/clang-doc/Representation.h
+++ b/clang-tools-extra/clang-doc/Representation.h
@@ -480,12 +480,15 @@ mergeInfos(std::vector<std::unique_ptr<Info>> &Values);
 struct ClangDocContext {
   ClangDocContext() = default;
   ClangDocContext(tooling::ExecutionContext *ECtx, StringRef ProjectName,
-                  bool PublicOnly, StringRef OutDirectory, StringRef SourceRoot,
+                  bool PublicOnly, bool FTimeTrace, int Granularity,
+                  StringRef OutDirectory, StringRef SourceRoot,
                   StringRef RepositoryUrl,
                   std::vector<std::string> UserStylesheets);
   tooling::ExecutionContext *ECtx;
   std::string ProjectName; // Name of project clang-doc is documenting.
   bool PublicOnly; // Indicates if only public declarations are documented.
+  bool FTimeTrace; // Indicates if ftime trace is turned on
+  int Granularity; // Granularity of ftime trace
   std::string OutDirectory; // Directory for outputting generated files.
   std::string SourceRoot;   // Directory where processed files are stored. Links
                             // to definition locations will only be generated if
diff --git a/clang-tools-extra/clang-doc/tool/ClangDocMain.cpp b/clang-tools-extra/clang-doc/tool/ClangDocMain.cpp
index 6198a6e0cdcc3..4cd4a845629fa 100644
--- a/clang-tools-extra/clang-doc/tool/ClangDocMain.cpp
+++ b/clang-tools-extra/clang-doc/tool/ClangDocMain.cpp
@@ -42,6 +42,7 @@
 #include "llvm/Support/Signals.h"
 #include "llvm/Support/ThreadPool.h"
 #include "llvm/Support/raw_ostream.h"
+#include "llvm/Support/TimeProfiler.h"
 #include <atomic>
 #include <mutex>
 #include <string>
@@ -99,6 +100,16 @@ URL of repository that hosts code.
 Used for links to definition locations.)"),
                   llvm::cl::cat(ClangDocCategory));
 
+static llvm::cl::opt<bool> FTimeTrace(
+    "ftime-trace", llvm::cl::desc(R"(
+Turn on time profiler. Generates clang-doc-tracing.json)"),
+    llvm::cl::init(false), llvm::cl::cat(ClangDocCategory));
+
+static llvm::cl::opt<int> FTimeGranularity(
+    "ftime-gran", llvm::cl::desc(R"(
+Specify granularity for ftime-trace defaults to 200)"),
+    llvm::cl::init(200), llvm::cl::cat(ClangDocCategory));
+
 enum OutputFormatTy {
   md,
   yaml,
@@ -229,6 +240,12 @@ Example usage for a project using a compile commands database:
     return 1;
   }
 
+  // turns on ftime trace profiling
+  if (FTimeTrace)
+    llvm::timeTraceProfilerInitialize(FTimeGranularity, "clang-doc");
+
+  llvm::TimeTraceScope("clang-doc", "main");
+
   // Fail early if an invalid format was provided.
   std::string Format = getFormatString();
   llvm::outs() << "Emiting docs in " << Format << " format.\n";
@@ -249,6 +266,8 @@ Example usage for a project using a compile commands database:
       Executor->get()->getExecutionContext(),
       ProjectName,
       PublicOnly,
+      FTimeTrace,
+      FTimeGranularity,
       OutDirectory,
       SourceRoot,
       RepositoryUrl,
@@ -262,6 +281,7 @@ Example usage for a project using a compile commands database:
     }
   }
 
+  llvm::timeTraceProfilerBegin("mapping phase", "mapping");
   // Mapping phase
   llvm::outs() << "Mapping decls...\n";
   auto Err =
@@ -276,10 +296,12 @@ Example usage for a project using a compile commands database:
       return 1;
     }
   }
+  llvm::timeTraceProfilerEnd();
 
   // Collect values into output by key.
   // In ToolResults, the Key is the hashed USR and the value is the
   // bitcode-encoded representation of the Info object.
+  llvm::timeTraceProfilerBegin("clang-doc", "collection phase");
   llvm::outs() << "Collecting infos...\n";
   llvm::StringMap<std::vector<StringRef>> USRToBitcode;
   Executor->get()->getToolResults()->forEachResult(
@@ -287,6 +309,7 @@ Example usage for a project using a compile commands database:
         auto R = USRToBitcode.try_emplace(Key, std::vector<StringRef>());
         R.first->second.emplace_back(Value);
       });
+  llvm::timeTraceProfilerEnd();
 
   // Collects all Infos according to their unique USR value. This map is added
   // to from the thread pool below and is protected by the USRToInfoMutex.
@@ -294,6 +317,7 @@ Example usage for a project using a compile commands database:
   llvm::StringMap<std::unique_ptr<doc::Info>> USRToInfo;
 
   // First reducing phase (reduce all decls into one info per decl).
+  llvm::timeTraceProfilerBegin("reduction phase", "reducing");
   llvm::outs() << "Reducing " << USRToBitcode.size() << " infos...\n";
   std::atomic<bool> Error;
   Error = false;
@@ -302,8 +326,11 @@ Example usage for a project using a compile commands database:
   llvm::DefaultThreadPool Pool(llvm::hardware_concurrency(ExecutorConcurrency));
   for (auto &Group : USRToBitcode) {
     Pool.async([&]() {
-      std::vector<std::unique_ptr<doc::Info>> Infos;
+      if (FTimeTrace)
+        llvm::timeTraceProfilerInitialize(FTimeGranularity, "clang-doc");
 
+      llvm::timeTraceProfilerBegin("decoding bitcode phase", "decoding");
+      std::vector<std::unique_ptr<doc::Info>> Infos;
       for (auto &Bitcode : Group.getValue()) {
         llvm::BitstreamCursor Stream(Bitcode);
         doc::ClangDocBitcodeReader Reader(Stream);
@@ -316,12 +343,16 @@ Example usage for a project using a compile commands database:
         std::move(ReadInfos->begin(), ReadInfos->end(),
                   std::back_inserter(Infos));
       }
+      llvm::timeTraceProfilerEnd();
 
+      llvm::timeTraceProfilerBegin("merging bitcode phase", "merging");
       auto Reduced = doc::mergeInfos(Infos);
       if (!Reduced) {
         llvm::errs() << llvm::toString(Reduced.takeError());
         return;
       }
+      llvm::timeTraceProfilerEnd();
+
 
       // Add a reference to this Info in the Index
       {
@@ -334,14 +365,20 @@ Example usage for a project using a compile commands database:
         std::lock_guard<llvm::sys::Mutex> Guard(USRToInfoMutex);
         USRToInfo[Group.getKey()] = std::move(Reduced.get());
       }
+
+      if (CDCtx.FTimeTrace)
+        llvm::timeTraceProfilerFinishThread();
+
     });
   }
+  llvm::timeTraceProfilerEnd();
 
   Pool.wait();
 
   if (Error)
     return 1;
 
+  llvm::timeTraceProfilerBegin("generating phase", "generating");
   // Ensure the root output directory exists.
   if (std::error_code Err = llvm::sys::fs::create_directories(OutDirectory);
       Err != std::error_code()) {
@@ -362,6 +399,16 @@ Example usage for a project using a compile commands database:
   if (Err) {
     llvm::outs() << "warning: " << toString(std::move(Err)) << "\n";
   }
-
+  llvm::timeTraceProfilerEnd();
+
+  if (FTimeTrace) {
+    std::error_code EC;
+    llvm::raw_fd_ostream OS("clang-doc-tracing.json", EC, llvm::sys::fs::OF_Text);
+    if (!EC) {
+      llvm::timeTraceProfilerWrite(OS);
+    } else {
+      llvm::errs() << "Error opening file: " << EC.message() << "\n";
+    }
+  }
   return 0;
 }

``````````

</details>


https://github.com/llvm/llvm-project/pull/97644


More information about the cfe-commits mailing list