[clang] ecaacd1 - Reapply "Add source file name for template instantiations in -ftime-trace" (#99757)

via cfe-commits cfe-commits at lists.llvm.org
Sun Jul 21 11:55:39 PDT 2024


Author: Utkarsh Saxena
Date: 2024-07-21T20:55:34+02:00
New Revision: ecaacd14c35996ad6ee53da6af6c9f4cf36d9110

URL: https://github.com/llvm/llvm-project/commit/ecaacd14c35996ad6ee53da6af6c9f4cf36d9110
DIFF: https://github.com/llvm/llvm-project/commit/ecaacd14c35996ad6ee53da6af6c9f4cf36d9110.diff

LOG: Reapply "Add source file name for template instantiations in -ftime-trace" (#99757)

Reverts https://github.com/llvm/llvm-project/pull/99731

Remove accidentally added temporary file.
Also, fix the uninitialized read of line number.

Added: 
    

Modified: 
    clang/docs/ReleaseNotes.rst
    clang/include/clang/Driver/Options.td
    clang/include/clang/Frontend/FrontendOptions.h
    clang/lib/Driver/ToolChains/Clang.cpp
    clang/lib/Sema/SemaTemplateInstantiate.cpp
    clang/lib/Sema/SemaTemplateInstantiateDecl.cpp
    clang/test/Driver/ftime-trace-sections.cpp
    clang/test/Driver/ftime-trace.cpp
    clang/tools/driver/cc1_main.cpp
    clang/unittests/Support/TimeProfilerTest.cpp
    llvm/include/llvm/Support/TimeProfiler.h
    llvm/lib/Support/TimeProfiler.cpp

Removed: 
    


################################################################################
diff  --git a/clang/docs/ReleaseNotes.rst b/clang/docs/ReleaseNotes.rst
index 4638b91b48f95..4ab6bd9de8ea9 100644
--- a/clang/docs/ReleaseNotes.rst
+++ b/clang/docs/ReleaseNotes.rst
@@ -752,6 +752,9 @@ Improvements to Clang's time-trace
 - Clang now specifies that using ``auto`` in a lambda parameter is a C++14 extension when
   appropriate. (`#46059: <https://github.com/llvm/llvm-project/issues/46059>`_).
 
+- Clang now adds source file infomation for template instantiations as ``event["args"]["filename"]``. This
+  added behind an option ``-ftime-trace-verbose``. This is expected to increase the size of trace by 2-3 times.
+
 Improvements to Coverage Mapping
 --------------------------------
 

diff  --git a/clang/include/clang/Driver/Options.td b/clang/include/clang/Driver/Options.td
index 8707e71f2a319..9c6cebd77ff0a 100644
--- a/clang/include/clang/Driver/Options.td
+++ b/clang/include/clang/Driver/Options.td
@@ -3998,6 +3998,10 @@ def ftime_trace_granularity_EQ : Joined<["-"], "ftime-trace-granularity=">, Grou
   HelpText<"Minimum time granularity (in microseconds) traced by time profiler">,
   Visibility<[ClangOption, CC1Option, CLOption, DXCOption]>,
   MarshallingInfoInt<FrontendOpts<"TimeTraceGranularity">, "500u">;
+def ftime_trace_verbose : Joined<["-"], "ftime-trace-verbose">, Group<f_Group>,
+  HelpText<"Make time trace capture verbose event details (e.g. source filenames). This can increase the size of the output by 2-3 times">,
+  Visibility<[ClangOption, CC1Option, CLOption, DXCOption]>,
+  MarshallingInfoFlag<FrontendOpts<"TimeTraceVerbose">>;
 def ftime_trace_EQ : Joined<["-"], "ftime-trace=">, Group<f_Group>,
   HelpText<"Similar to -ftime-trace. Specify the JSON file or a directory which will contain the JSON file">,
   Visibility<[ClangOption, CC1Option, CLOption, DXCOption]>,

diff  --git a/clang/include/clang/Frontend/FrontendOptions.h b/clang/include/clang/Frontend/FrontendOptions.h
index 5e5034fe01eb5..8241925c98476 100644
--- a/clang/include/clang/Frontend/FrontendOptions.h
+++ b/clang/include/clang/Frontend/FrontendOptions.h
@@ -580,6 +580,11 @@ class FrontendOptions {
   /// Minimum time granularity (in microseconds) traced by time profiler.
   unsigned TimeTraceGranularity;
 
+  /// Make time trace capture verbose event details (e.g. source filenames).
+  /// This can increase the size of the output by 2-3 times.
+  LLVM_PREFERRED_TYPE(bool)
+  unsigned TimeTraceVerbose : 1;
+
   /// Path which stores the output files for -ftime-trace
   std::string TimeTracePath;
 
@@ -601,7 +606,8 @@ class FrontendOptions {
         EmitSymbolGraph(false), EmitExtensionSymbolGraphs(false),
         EmitSymbolGraphSymbolLabelsForTesting(false),
         EmitPrettySymbolGraphs(false), GenReducedBMI(false),
-        UseClangIRPipeline(false), TimeTraceGranularity(500) {}
+        UseClangIRPipeline(false), TimeTraceGranularity(500),
+        TimeTraceVerbose(false) {}
 
   /// getInputKindForExtension - Return the appropriate input kind for a file
   /// extension. For example, "c" would return Language::C.

diff  --git a/clang/lib/Driver/ToolChains/Clang.cpp b/clang/lib/Driver/ToolChains/Clang.cpp
index 71cdaa10416f4..364e55a628c34 100644
--- a/clang/lib/Driver/ToolChains/Clang.cpp
+++ b/clang/lib/Driver/ToolChains/Clang.cpp
@@ -6759,6 +6759,7 @@ void Clang::ConstructJob(Compilation &C, const JobAction &JA,
   if (const char *Name = C.getTimeTraceFile(&JA)) {
     CmdArgs.push_back(Args.MakeArgString("-ftime-trace=" + Twine(Name)));
     Args.AddLastArg(CmdArgs, options::OPT_ftime_trace_granularity_EQ);
+    Args.AddLastArg(CmdArgs, options::OPT_ftime_trace_verbose);
   }
 
   if (Arg *A = Args.getLastArg(options::OPT_ftrapv_handler_EQ)) {

diff  --git a/clang/lib/Sema/SemaTemplateInstantiate.cpp b/clang/lib/Sema/SemaTemplateInstantiate.cpp
index a7bc6749c5852..725b62db5e80a 100644
--- a/clang/lib/Sema/SemaTemplateInstantiate.cpp
+++ b/clang/lib/Sema/SemaTemplateInstantiate.cpp
@@ -3426,11 +3426,16 @@ Sema::InstantiateClass(SourceLocation PointOfInstantiation,
     return true;
 
   llvm::TimeTraceScope TimeScope("InstantiateClass", [&]() {
-    std::string Name;
-    llvm::raw_string_ostream OS(Name);
+    llvm::TimeTraceMetadata M;
+    llvm::raw_string_ostream OS(M.Detail);
     Instantiation->getNameForDiagnostic(OS, getPrintingPolicy(),
                                         /*Qualified=*/true);
-    return Name;
+    if (llvm::isTimeTraceVerbose()) {
+      auto Loc = SourceMgr.getExpansionLoc(Instantiation->getLocation());
+      M.File = SourceMgr.getFilename(Loc);
+      M.Line = SourceMgr.getExpansionLineNumber(Loc);
+    }
+    return M;
   });
 
   Pattern = PatternDef;

diff  --git a/clang/lib/Sema/SemaTemplateInstantiateDecl.cpp b/clang/lib/Sema/SemaTemplateInstantiateDecl.cpp
index 97161febc15f7..a12d2eff1d2c8 100644
--- a/clang/lib/Sema/SemaTemplateInstantiateDecl.cpp
+++ b/clang/lib/Sema/SemaTemplateInstantiateDecl.cpp
@@ -4966,11 +4966,16 @@ void Sema::InstantiateFunctionDefinition(SourceLocation PointOfInstantiation,
   }
 
   llvm::TimeTraceScope TimeScope("InstantiateFunction", [&]() {
-    std::string Name;
-    llvm::raw_string_ostream OS(Name);
+    llvm::TimeTraceMetadata M;
+    llvm::raw_string_ostream OS(M.Detail);
     Function->getNameForDiagnostic(OS, getPrintingPolicy(),
                                    /*Qualified=*/true);
-    return Name;
+    if (llvm::isTimeTraceVerbose()) {
+      auto Loc = SourceMgr.getExpansionLoc(Function->getLocation());
+      M.File = SourceMgr.getFilename(Loc);
+      M.Line = SourceMgr.getExpansionLineNumber(Loc);
+    }
+    return M;
   });
 
   // If we're performing recursive template instantiation, create our own

diff  --git a/clang/test/Driver/ftime-trace-sections.cpp b/clang/test/Driver/ftime-trace-sections.cpp
index 0c16052bc0c3a..da7109b9d81a6 100644
--- a/clang/test/Driver/ftime-trace-sections.cpp
+++ b/clang/test/Driver/ftime-trace-sections.cpp
@@ -1,5 +1,5 @@
 // RUN: rm -rf %t && mkdir %t && cd %t
-// RUN: %clangxx -S -ftime-trace -ftime-trace-granularity=0 -o out %s
+// RUN: %clangxx -S -ftime-trace -ftime-trace-granularity=0 -ftime-trace-verbose -o out %s
 // RUN: %python %S/ftime-trace-sections.py < out.json
 
 template <typename T>

diff  --git a/clang/test/Driver/ftime-trace.cpp b/clang/test/Driver/ftime-trace.cpp
index 5fe63de915a71..60c5885704b58 100644
--- a/clang/test/Driver/ftime-trace.cpp
+++ b/clang/test/Driver/ftime-trace.cpp
@@ -1,18 +1,18 @@
 // RUN: rm -rf %t && mkdir -p %t && cd %t
-// RUN: %clangxx -S -no-canonical-prefixes -ftime-trace -ftime-trace-granularity=0 -o out %s
+// RUN: %clangxx -S -no-canonical-prefixes -ftime-trace -ftime-trace-granularity=0 -ftime-trace-verbose -o out %s
 // RUN: cat out.json \
 // RUN:   | %python -c 'import json, sys; json.dump(json.loads(sys.stdin.read()), sys.stdout, sort_keys=True, indent=2)' \
 // RUN:   | FileCheck %s
-// RUN: %clangxx -S -no-canonical-prefixes -ftime-trace=new-name.json -ftime-trace-granularity=0 -o out %s
+// RUN: %clangxx -S -no-canonical-prefixes -ftime-trace=new-name.json -ftime-trace-granularity=0 -ftime-trace-verbose -o out %s
 // RUN: cat new-name.json \
 // RUN:   | %python -c 'import json, sys; json.dump(json.loads(sys.stdin.read()), sys.stdout, sort_keys=True, indent=2)' \
 // RUN:   | FileCheck %s
 // RUN: mkdir dir1 dir2
-// RUN: %clangxx -S -no-canonical-prefixes -ftime-trace=dir1 -ftime-trace-granularity=0 -o out %s
+// RUN: %clangxx -S -no-canonical-prefixes -ftime-trace=dir1 -ftime-trace-granularity=0 -ftime-trace-verbose -o out %s
 // RUN: cat dir1/out.json \
 // RUN:   | %python -c 'import json, sys; json.dump(json.loads(sys.stdin.read()), sys.stdout, sort_keys=True, indent=2)' \
 // RUN:   | FileCheck %s
-// RUN: %clangxx -S -no-canonical-prefixes -ftime-trace=dir2/ -ftime-trace-granularity=0 -o out %s
+// RUN: %clangxx -S -no-canonical-prefixes -ftime-trace=dir2/ -ftime-trace-granularity=0 -ftime-trace-verbose -o out %s
 // RUN: cat dir2/out.json \
 // RUN:   | %python -c 'import json, sys; json.dump(json.loads(sys.stdin.read()), sys.stdout, sort_keys=True, indent=2)' \
 // RUN:   | FileCheck %s
@@ -34,32 +34,33 @@
 // RUN: mkdir d e f && cp %s d/a.cpp && touch d/b.c
 
 /// TODO: Support -fno-integrated-as.
-// RUN: %clang -### -c -ftime-trace -ftime-trace-granularity=0 -fintegrated-as d/a.cpp -o e/a.o 2>&1 | FileCheck %s --check-prefix=COMPILE1
-// COMPILE1: -cc1{{.*}} "-ftime-trace=e/a.json" "-ftime-trace-granularity=0"
+// RUN: %clang -### -c -ftime-trace -ftime-trace-granularity=0 -ftime-trace-verbose -fintegrated-as d/a.cpp -o e/a.o 2>&1 | FileCheck %s --check-prefix=COMPILE1
+// COMPILE1: -cc1{{.*}} "-ftime-trace=e/a.json" "-ftime-trace-granularity=0" "-ftime-trace-verbose"
 
-// RUN: %clang -### -c -ftime-trace -ftime-trace-granularity=0 d/a.cpp d/b.c -dumpdir f/ 2>&1 | FileCheck %s --check-prefix=COMPILE2
-// COMPILE2: -cc1{{.*}} "-ftime-trace=f/a.json" "-ftime-trace-granularity=0"
-// COMPILE2: -cc1{{.*}} "-ftime-trace=f/b.json" "-ftime-trace-granularity=0"
+// RUN: %clang -### -c -ftime-trace -ftime-trace-granularity=0 -ftime-trace-verbose d/a.cpp d/b.c -dumpdir f/ 2>&1 | FileCheck %s --check-prefix=COMPILE2
+// COMPILE2: -cc1{{.*}} "-ftime-trace=f/a.json" "-ftime-trace-granularity=0" "-ftime-trace-verbose"
+// COMPILE2: -cc1{{.*}} "-ftime-trace=f/b.json" "-ftime-trace-granularity=0" "-ftime-trace-verbose"
 
 /// -o specifies the link output. Create ${output}-${basename}.json.
-// RUN: %clang -### -ftime-trace -ftime-trace-granularity=0 d/a.cpp d/b.c -o e/x 2>&1 | FileCheck %s --check-prefix=LINK1
-// LINK1: -cc1{{.*}} "-ftime-trace=e/x-a.json" "-ftime-trace-granularity=0"
-// LINK1: -cc1{{.*}} "-ftime-trace=e/x-b.json" "-ftime-trace-granularity=0"
+// RUN: %clang -### -ftime-trace -ftime-trace-granularity=0 -ftime-trace-verbose d/a.cpp d/b.c -o e/x 2>&1 | FileCheck %s --check-prefix=LINK1
+// LINK1: -cc1{{.*}} "-ftime-trace=e/x-a.json" "-ftime-trace-granularity=0" "-ftime-trace-verbose"
+// LINK1: -cc1{{.*}} "-ftime-trace=e/x-b.json" "-ftime-trace-granularity=0" "-ftime-trace-verbose"
 
 /// -dumpdir is f/g, not ending with a path separator. We create f/g${basename}.json.
-// RUN: %clang -### -ftime-trace -ftime-trace-granularity=0 d/a.cpp d/b.c -o e/x -dumpdir f/g 2>&1 | FileCheck %s --check-prefix=LINK2
-// LINK2: -cc1{{.*}} "-ftime-trace=f/ga.json" "-ftime-trace-granularity=0"
-// LINK2: -cc1{{.*}} "-ftime-trace=f/gb.json" "-ftime-trace-granularity=0"
+// RUN: %clang -### -ftime-trace -ftime-trace-granularity=0 -ftime-trace-verbose d/a.cpp d/b.c -o e/x -dumpdir f/g 2>&1 | FileCheck %s --check-prefix=LINK2
+// LINK2: -cc1{{.*}} "-ftime-trace=f/ga.json" "-ftime-trace-granularity=0" "-ftime-trace-verbose"
+// LINK2: -cc1{{.*}} "-ftime-trace=f/gb.json" "-ftime-trace-granularity=0" "-ftime-trace-verbose"
 
-// RUN: %clang -### -ftime-trace=e -ftime-trace-granularity=0 d/a.cpp d/b.c -o f/x -dumpdir f/ 2>&1 | FileCheck %s --check-prefix=LINK3
-// LINK3: -cc1{{.*}} "-ftime-trace=e{{/|\\\\}}a-{{[^.]*}}.json" "-ftime-trace-granularity=0"
-// LINK3: -cc1{{.*}} "-ftime-trace=e{{/|\\\\}}b-{{[^.]*}}.json" "-ftime-trace-granularity=0"
+// RUN: %clang -### -ftime-trace=e -ftime-trace-granularity=0 -ftime-trace-verbose d/a.cpp d/b.c -o f/x -dumpdir f/ 2>&1 | FileCheck %s --check-prefix=LINK3
+// LINK3: -cc1{{.*}} "-ftime-trace=e{{/|\\\\}}a-{{[^.]*}}.json" "-ftime-trace-granularity=0" "-ftime-trace-verbose"
+// LINK3: -cc1{{.*}} "-ftime-trace=e{{/|\\\\}}b-{{[^.]*}}.json" "-ftime-trace-granularity=0" "-ftime-trace-verbose"
 
-// RUN: %clang -### -ftime-trace -ftime-trace=e -ftime-trace-granularity=1 -xassembler d/a.cpp 2>&1 | \
+// RUN: %clang -### -ftime-trace -ftime-trace=e -ftime-trace-granularity=1 -ftime-trace-verbose -xassembler d/a.cpp 2>&1 | \
 // RUN:   FileCheck %s --check-prefix=UNUSED
 // UNUSED:      warning: argument unused during compilation: '-ftime-trace'
 // UNUSED-NEXT: warning: argument unused during compilation: '-ftime-trace=e'
 // UNUSED-NEXT: warning: argument unused during compilation: '-ftime-trace-granularity=1'
+// UNUSED-NEXT: warning: argument unused during compilation: '-ftime-trace-verbose'
 // UNUSED-NOT:  warning:
 
 template <typename T>

diff  --git a/clang/tools/driver/cc1_main.cpp b/clang/tools/driver/cc1_main.cpp
index c2ccb47a15bc8..f5e5fad36573e 100644
--- a/clang/tools/driver/cc1_main.cpp
+++ b/clang/tools/driver/cc1_main.cpp
@@ -241,7 +241,8 @@ int cc1_main(ArrayRef<const char *> Argv, const char *Argv0, void *MainAddr) {
 
   if (!Clang->getFrontendOpts().TimeTracePath.empty()) {
     llvm::timeTraceProfilerInitialize(
-        Clang->getFrontendOpts().TimeTraceGranularity, Argv0);
+        Clang->getFrontendOpts().TimeTraceGranularity, Argv0,
+        Clang->getFrontendOpts().TimeTraceVerbose);
   }
   // --print-supported-cpus takes priority over the actual compilation.
   if (Clang->getFrontendOpts().PrintSupportedCPUs)

diff  --git a/clang/unittests/Support/TimeProfilerTest.cpp b/clang/unittests/Support/TimeProfilerTest.cpp
index 5f3950ff033f1..56d880cffde61 100644
--- a/clang/unittests/Support/TimeProfilerTest.cpp
+++ b/clang/unittests/Support/TimeProfilerTest.cpp
@@ -10,11 +10,15 @@
 #include "clang/Frontend/FrontendActions.h"
 #include "clang/Lex/PreprocessorOptions.h"
 
+#include "llvm/ADT/StringMap.h"
 #include "llvm/Support/JSON.h"
+#include "llvm/Support/Path.h"
 #include "llvm/Support/TimeProfiler.h"
+#include "llvm/Support/VirtualFileSystem.h"
 #include <stack>
 
 #include "gtest/gtest.h"
+#include <tuple>
 
 using namespace clang;
 using namespace llvm;
@@ -23,7 +27,8 @@ namespace {
 
 // Should be called before testing.
 void setupProfiler() {
-  timeTraceProfilerInitialize(/*TimeTraceGranularity=*/0, "test");
+  timeTraceProfilerInitialize(/*TimeTraceGranularity=*/0, "test",
+                              /*TimeTraceVerbose=*/true);
 }
 
 // Should be called after `compileFromString()`.
@@ -38,14 +43,24 @@ std::string teardownProfiler() {
 
 // Returns true if code compiles successfully.
 // We only parse AST here. This is enough for constexpr evaluation.
-bool compileFromString(StringRef Code, StringRef Standard, StringRef FileName) {
+bool compileFromString(StringRef Code, StringRef Standard, StringRef File,
+                       llvm::StringMap<std::string> Headers = {}) {
   CompilerInstance Compiler;
   Compiler.createDiagnostics();
 
+  llvm::IntrusiveRefCntPtr<llvm::vfs::InMemoryFileSystem> FS(
+      new llvm::vfs::InMemoryFileSystem());
+  FS->addFile(File, 0, MemoryBuffer::getMemBuffer(Code));
+  for (const auto &Header : Headers) {
+    FS->addFile(Header.getKey(), 0,
+                MemoryBuffer::getMemBuffer(Header.getValue()));
+  }
+  llvm::IntrusiveRefCntPtr<FileManager> Files(
+      new FileManager(FileSystemOptions(), FS));
+  Compiler.setFileManager(Files.get());
+
   auto Invocation = std::make_shared<CompilerInvocation>();
-  Invocation->getPreprocessorOpts().addRemappedFile(
-      FileName, MemoryBuffer::getMemBuffer(Code).release());
-  const char *Args[] = {Standard.data(), FileName.data()};
+  std::vector<const char *> Args = {Standard.data(), File.data()};
   CompilerInvocation::CreateFromArgs(*Invocation, Args,
                                      Compiler.getDiagnostics());
   Compiler.setInvocation(std::move(Invocation));
@@ -60,13 +75,28 @@ bool compileFromString(StringRef Code, StringRef Standard, StringRef FileName) {
   return Compiler.ExecuteAction(Action);
 }
 
+std::string GetMetadata(json::Object *Event) {
+  std::string Metadata;
+  llvm::raw_string_ostream OS(Metadata);
+  if (json::Object *Args = Event->getObject("args")) {
+    if (auto Detail = Args->getString("detail"))
+      OS << Detail;
+    // Use only filename to not include os-specific path separators.
+    if (auto File = Args->getString("file"))
+      OS << ", " << llvm::sys::path::filename(*File);
+    if (auto Line = Args->getInteger("line"))
+      OS << ":" << *Line;
+  }
+  return Metadata;
+}
+
 // Returns pretty-printed trace graph.
 std::string buildTraceGraph(StringRef Json) {
   struct EventRecord {
     int64_t TimestampBegin;
     int64_t TimestampEnd;
-    StringRef Name;
-    StringRef Detail;
+    std::string Name;
+    std::string Metadata;
   };
   std::vector<EventRecord> Events;
 
@@ -81,10 +111,13 @@ std::string buildTraceGraph(StringRef Json) {
     int64_t TimestampBegin = TraceEventObj->getInteger("ts").value_or(0);
     int64_t TimestampEnd =
         TimestampBegin + TraceEventObj->getInteger("dur").value_or(0);
-    StringRef Name = TraceEventObj->getString("name").value_or("");
-    StringRef Detail = "";
-    if (json::Object *Args = TraceEventObj->getObject("args"))
-      Detail = Args->getString("detail").value_or("");
+    std::string Name = TraceEventObj->getString("name").value_or("").str();
+    std::string Metadata = GetMetadata(TraceEventObj);
+
+    // Source events are asynchronous events and may not perfectly nest the
+    // synchronous events. Skip testing them.
+    if (Name == "Source")
+      continue;
 
     // This is a "summary" event, like "Total PerformPendingInstantiations",
     // skip it
@@ -92,7 +125,7 @@ std::string buildTraceGraph(StringRef Json) {
       continue;
 
     Events.emplace_back(
-        EventRecord{TimestampBegin, TimestampEnd, Name, Detail});
+        EventRecord{TimestampBegin, TimestampEnd, Name, Metadata});
   }
 
   // There can be nested events that are very fast, for example:
@@ -132,9 +165,9 @@ std::string buildTraceGraph(StringRef Json) {
       Stream << "| ";
     }
     Stream.write(Event.Name.data(), Event.Name.size());
-    if (!Event.Detail.empty()) {
+    if (!Event.Metadata.empty()) {
       Stream << " (";
-      Stream.write(Event.Detail.data(), Event.Detail.size());
+      Stream.write(Event.Metadata.data(), Event.Metadata.size());
       Stream << ")";
     }
     Stream << "\n";
@@ -145,7 +178,7 @@ std::string buildTraceGraph(StringRef Json) {
 } // namespace
 
 TEST(TimeProfilerTest, ConstantEvaluationCxx20) {
-  constexpr StringRef Code = R"(
+  std::string Code = R"(
 void print(double value);
 
 namespace slow_namespace {
@@ -175,8 +208,7 @@ constexpr int slow_init_list[] = {1, 1, 2, 3, 5, 8, 13, 21}; // 25th line
   setupProfiler();
   ASSERT_TRUE(compileFromString(Code, "-std=c++20", "test.cc"));
   std::string Json = teardownProfiler();
-  std::string TraceGraph = buildTraceGraph(Json);
-  ASSERT_TRUE(TraceGraph == R"(
+  ASSERT_EQ(R"(
 Frontend
 | ParseDeclarationOrFunctionDefinition (test.cc:2:1)
 | ParseDeclarationOrFunctionDefinition (test.cc:6:1)
@@ -202,14 +234,54 @@ Frontend
 | ParseDeclarationOrFunctionDefinition (test.cc:25:1)
 | | EvaluateAsInitializer (slow_init_list)
 | PerformPendingInstantiations
-)");
+)",
+            buildTraceGraph(Json));
+}
+
+TEST(TimeProfilerTest, TemplateInstantiations) {
+  std::string B_H = R"(
+    template <typename T>
+    T fooB(T t) {
+      return T();
+    }
 
-  // NOTE: If this test is failing, run this test with
-  // `llvm::errs() << TraceGraph;` and change the assert above.
+    #define MacroTemp(x) template <typename T> void foo##x(T) { T(); }
+  )";
+
+  std::string A_H = R"(
+    #include "b.h"
+
+    MacroTemp(MTA)
+
+    template <typename T>
+    void fooA(T t) { fooB(t); fooMTA(t); }
+  )";
+  std::string Code = R"(
+    #include "a.h"
+    void user() { fooA(0); }
+  )";
+
+  setupProfiler();
+  ASSERT_TRUE(compileFromString(Code, "-std=c++20", "test.cc",
+                                /*Headers=*/{{"a.h", A_H}, {"b.h", B_H}}));
+  std::string Json = teardownProfiler();
+  ASSERT_EQ(R"(
+Frontend
+| ParseFunctionDefinition (fooB)
+| ParseFunctionDefinition (fooMTA)
+| ParseFunctionDefinition (fooA)
+| ParseDeclarationOrFunctionDefinition (test.cc:3:5)
+| | ParseFunctionDefinition (user)
+| PerformPendingInstantiations
+| | InstantiateFunction (fooA<int>, a.h:7)
+| | | InstantiateFunction (fooB<int>, b.h:3)
+| | | InstantiateFunction (fooMTA<int>, a.h:4)
+)",
+            buildTraceGraph(Json));
 }
 
 TEST(TimeProfilerTest, ConstantEvaluationC99) {
-  constexpr StringRef Code = R"(
+  std::string Code = R"(
 struct {
   short quantval[4]; // 3rd line
 } value;
@@ -218,15 +290,12 @@ struct {
   setupProfiler();
   ASSERT_TRUE(compileFromString(Code, "-std=c99", "test.c"));
   std::string Json = teardownProfiler();
-  std::string TraceGraph = buildTraceGraph(Json);
-  ASSERT_TRUE(TraceGraph == R"(
+  ASSERT_EQ(R"(
 Frontend
 | ParseDeclarationOrFunctionDefinition (test.c:2:1)
 | | isIntegerConstantExpr (<test.c:3:18>)
 | | EvaluateKnownConstIntCheckOverflow (<test.c:3:18>)
 | PerformPendingInstantiations
-)");
-
-  // NOTE: If this test is failing, run this test with
-  // `llvm::errs() << TraceGraph;` and change the assert above.
+)",
+            buildTraceGraph(Json));
 }

diff  --git a/llvm/include/llvm/Support/TimeProfiler.h b/llvm/include/llvm/Support/TimeProfiler.h
index 31f7df10916db..9e2ba31991f54 100644
--- a/llvm/include/llvm/Support/TimeProfiler.h
+++ b/llvm/include/llvm/Support/TimeProfiler.h
@@ -83,16 +83,28 @@ namespace llvm {
 
 class raw_pwrite_stream;
 
+struct TimeTraceMetadata {
+  std::string Detail;
+  // Source file and line number information for the event.
+  std::string File;
+  int Line = 0;
+
+  bool isEmpty() const { return Detail.empty() && File.empty(); }
+};
+
 struct TimeTraceProfiler;
 TimeTraceProfiler *getTimeTraceProfilerInstance();
 
+bool isTimeTraceVerbose();
+
 struct TimeTraceProfilerEntry;
 
 /// Initialize the time trace profiler.
 /// This sets up the global \p TimeTraceProfilerInstance
 /// variable to be the profiler instance.
 void timeTraceProfilerInitialize(unsigned TimeTraceGranularity,
-                                 StringRef ProcName);
+                                 StringRef ProcName,
+                                 bool TimeTraceVerbose = false);
 
 /// Cleanup the time trace profiler, if it was initialized.
 void timeTraceProfilerCleanup();
@@ -128,6 +140,10 @@ TimeTraceProfilerEntry *
 timeTraceProfilerBegin(StringRef Name,
                        llvm::function_ref<std::string()> Detail);
 
+TimeTraceProfilerEntry *
+timeTraceProfilerBegin(StringRef Name,
+                       llvm::function_ref<TimeTraceMetadata()> MetaData);
+
 /// Manually begin a time section, with the given \p Name and \p Detail.
 /// This starts Async Events having \p Name as a category which is shown
 /// separately from other traces. See
@@ -164,6 +180,11 @@ class TimeTraceScope {
     if (getTimeTraceProfilerInstance() != nullptr)
       Entry = timeTraceProfilerBegin(Name, Detail);
   }
+  TimeTraceScope(StringRef Name,
+                 llvm::function_ref<TimeTraceMetadata()> Metadata) {
+    if (getTimeTraceProfilerInstance() != nullptr)
+      Entry = timeTraceProfilerBegin(Name, Metadata);
+  }
   ~TimeTraceScope() {
     if (getTimeTraceProfilerInstance() != nullptr)
       timeTraceProfilerEnd(Entry);

diff  --git a/llvm/lib/Support/TimeProfiler.cpp b/llvm/lib/Support/TimeProfiler.cpp
index 9612db7d30f98..c2014028ddadc 100644
--- a/llvm/lib/Support/TimeProfiler.cpp
+++ b/llvm/lib/Support/TimeProfiler.cpp
@@ -73,12 +73,20 @@ struct llvm::TimeTraceProfilerEntry {
   const TimePointType Start;
   TimePointType End;
   const std::string Name;
-  const std::string Detail;
+  TimeTraceMetadata Metadata;
+
   const bool AsyncEvent = false;
   TimeTraceProfilerEntry(TimePointType &&S, TimePointType &&E, std::string &&N,
                          std::string &&Dt, bool Ae)
+      : Start(std::move(S)), End(std::move(E)), Name(std::move(N)), Metadata(),
+        AsyncEvent(Ae) {
+    Metadata.Detail = std::move(Dt);
+  }
+
+  TimeTraceProfilerEntry(TimePointType &&S, TimePointType &&E, std::string &&N,
+                         TimeTraceMetadata &&Mt, bool Ae)
       : Start(std::move(S)), End(std::move(E)), Name(std::move(N)),
-        Detail(std::move(Dt)), AsyncEvent(Ae) {}
+        Metadata(std::move(Mt)), AsyncEvent(Ae) {}
 
   // Calculate timings for FlameGraph. Cast time points to microsecond precision
   // rather than casting duration. This avoids truncation issues causing inner
@@ -97,10 +105,12 @@ struct llvm::TimeTraceProfilerEntry {
 };
 
 struct llvm::TimeTraceProfiler {
-  TimeTraceProfiler(unsigned TimeTraceGranularity = 0, StringRef ProcName = "")
+  TimeTraceProfiler(unsigned TimeTraceGranularity = 0, StringRef ProcName = "",
+                    bool TimeTraceVerbose = false)
       : BeginningOfTime(system_clock::now()), StartTime(ClockType::now()),
         ProcName(ProcName), Pid(sys::Process::getProcessId()),
-        Tid(llvm::get_threadid()), TimeTraceGranularity(TimeTraceGranularity) {
+        Tid(llvm::get_threadid()), TimeTraceGranularity(TimeTraceGranularity),
+        TimeTraceVerbose(TimeTraceVerbose) {
     llvm::get_thread_name(ThreadName);
   }
 
@@ -113,6 +123,15 @@ struct llvm::TimeTraceProfiler {
     return Stack.back().get();
   }
 
+  TimeTraceProfilerEntry *
+  begin(std::string Name, llvm::function_ref<TimeTraceMetadata()> Metadata,
+        bool AsyncEvent = false) {
+    Stack.emplace_back(std::make_unique<TimeTraceProfilerEntry>(
+        ClockType::now(), TimePointType(), std::move(Name), Metadata(),
+        AsyncEvent));
+    return Stack.back().get();
+  }
+
   void end() {
     assert(!Stack.empty() && "Must call begin() first");
     end(*Stack.back());
@@ -184,8 +203,15 @@ struct llvm::TimeTraceProfiler {
           J.attribute("dur", DurUs);
         }
         J.attribute("name", E.Name);
-        if (!E.Detail.empty()) {
-          J.attributeObject("args", [&] { J.attribute("detail", E.Detail); });
+        if (!E.Metadata.isEmpty()) {
+          J.attributeObject("args", [&] {
+            if (!E.Metadata.Detail.empty())
+              J.attribute("detail", E.Metadata.Detail);
+            if (!E.Metadata.File.empty())
+              J.attribute("file", E.Metadata.File);
+            if (E.Metadata.Line > 0)
+              J.attribute("line", E.Metadata.Line);
+          });
         }
       });
 
@@ -307,14 +333,25 @@ struct llvm::TimeTraceProfiler {
 
   // Minimum time granularity (in microseconds)
   const unsigned TimeTraceGranularity;
+
+  // Make time trace capture verbose event details (e.g. source filenames). This
+  // can increase the size of the output by 2-3 times.
+  const bool TimeTraceVerbose;
 };
 
+bool llvm::isTimeTraceVerbose() {
+  return getTimeTraceProfilerInstance() &&
+         getTimeTraceProfilerInstance()->TimeTraceVerbose;
+}
+
 void llvm::timeTraceProfilerInitialize(unsigned TimeTraceGranularity,
-                                       StringRef ProcName) {
+                                       StringRef ProcName,
+                                       bool TimeTraceVerbose) {
   assert(TimeTraceProfilerInstance == nullptr &&
          "Profiler should not be initialized");
   TimeTraceProfilerInstance = new TimeTraceProfiler(
-      TimeTraceGranularity, llvm::sys::path::filename(ProcName));
+      TimeTraceGranularity, llvm::sys::path::filename(ProcName),
+      TimeTraceVerbose);
 }
 
 // Removes all TimeTraceProfilerInstances.
@@ -381,6 +418,14 @@ llvm::timeTraceProfilerBegin(StringRef Name,
   return nullptr;
 }
 
+TimeTraceProfilerEntry *
+llvm::timeTraceProfilerBegin(StringRef Name,
+                             llvm::function_ref<TimeTraceMetadata()> Metadata) {
+  if (TimeTraceProfilerInstance != nullptr)
+    return TimeTraceProfilerInstance->begin(std::string(Name), Metadata, false);
+  return nullptr;
+}
+
 TimeTraceProfilerEntry *llvm::timeTraceAsyncProfilerBegin(StringRef Name,
                                                           StringRef Detail) {
   if (TimeTraceProfilerInstance != nullptr)


        


More information about the cfe-commits mailing list