llvmbot wrote:
<!--LLVM PR SUMMARY COMMENT--> @llvm/pr-subscribers-llvm-support @llvm/pr-subscribers-clang Author: None (ivanaivanovska) <details> <summary>Changes</summary> Added an instant event type and issuing such events each time a template instantiation is deferred. --- Full diff: https://github.com/llvm/llvm-project/pull/103039.diff 5 Files Affected: - (modified) clang/lib/Sema/SemaExpr.cpp (+15) - (modified) clang/lib/Sema/SemaTemplateInstantiateDecl.cpp (+13) - (modified) clang/unittests/Support/TimeProfilerTest.cpp (+49-2) - (modified) llvm/include/llvm/Support/TimeProfiler.h (+7) - (modified) llvm/lib/Support/TimeProfiler.cpp (+91-31) ``````````diff diff --git a/clang/lib/Sema/SemaExpr.cpp b/clang/lib/Sema/SemaExpr.cpp index 95f53dfefbcc52..a7dd01c936bac8 100644 --- a/clang/lib/Sema/SemaExpr.cpp +++ b/clang/lib/Sema/SemaExpr.cpp @@ -18,6 +18,7 @@ #include "clang/AST/ASTLambda.h" #include "clang/AST/ASTMutationListener.h" #include "clang/AST/CXXInheritance.h" +#include "clang/AST/Decl.h" #include "clang/AST/DeclObjC.h" #include "clang/AST/DeclTemplate.h" #include "clang/AST/EvaluatedExprVisitor.h" @@ -64,6 +65,7 @@ #include "llvm/Support/Casting.h" #include "llvm/Support/ConvertUTF.h" #include "llvm/Support/SaveAndRestore.h" +#include "llvm/Support/TimeProfiler.h" #include "llvm/Support/TypeSize.h" #include <optional> @@ -18046,6 +18048,19 @@ void Sema::MarkFunctionReferenced(SourceLocation Loc, FunctionDecl *Func, std::make_pair(Func, PointOfInstantiation)); // Notify the consumer that a function was implicitly instantiated. Consumer.HandleCXXImplicitFunctionInstantiation(Func); + + llvm::timeTraceProfilerInsert("DeferInstantiation", [&]() { + llvm::TimeTraceMetadata M; + llvm::raw_string_ostream OS(M.Detail); + Func->getNameForDiagnostic(OS, getPrintingPolicy(), + /*Qualified=*/true); + if (llvm::isTimeTraceVerbose()) { + auto Loc = SourceMgr.getExpansionLoc(Func->getLocation()); + M.File = SourceMgr.getFilename(Loc); + M.Line = SourceMgr.getExpansionLineNumber(Loc); + } + return M; + }); } } } else { diff --git a/clang/lib/Sema/SemaTemplateInstantiateDecl.cpp b/clang/lib/Sema/SemaTemplateInstantiateDecl.cpp index 0e064be2391838..550add5495c833 100644 --- a/clang/lib/Sema/SemaTemplateInstantiateDecl.cpp +++ b/clang/lib/Sema/SemaTemplateInstantiateDecl.cpp @@ -4983,6 +4983,19 @@ void Sema::InstantiateFunctionDefinition(SourceLocation PointOfInstantiation, Function->setInstantiationIsPending(true); PendingInstantiations.push_back( std::make_pair(Function, PointOfInstantiation)); + + llvm::timeTraceProfilerInsert("DeferInstantiation", [&]() { + llvm::TimeTraceMetadata M; + llvm::raw_string_ostream OS(M.Detail); + Function->getNameForDiagnostic(OS, getPrintingPolicy(), + /*Qualified=*/true); + if (llvm::isTimeTraceVerbose()) { + auto Loc = SourceMgr.getExpansionLoc(Function->getLocation()); + M.File = SourceMgr.getFilename(Loc); + M.Line = SourceMgr.getExpansionLineNumber(Loc); + } + return M; + }); } else if (TSK == TSK_ImplicitInstantiation) { if (AtEndOfTU && !getDiagnostics().hasErrorOccurred() && !getSourceManager().isInSystemHeader(PatternDecl->getBeginLoc())) { diff --git a/clang/unittests/Support/TimeProfilerTest.cpp b/clang/unittests/Support/TimeProfilerTest.cpp index f53fe71d630bf5..ccda12e943dd73 100644 --- a/clang/unittests/Support/TimeProfilerTest.cpp +++ b/clang/unittests/Support/TimeProfilerTest.cpp @@ -238,13 +238,55 @@ Frontend (test.cc) buildTraceGraph(Json)); } +TEST(TimeProfilerTest, ClassTemplateInstantiations) { + std::string Code = R"( + template<class T> + struct S + { + void foo() {} + void bar(); + }; + + template struct S<double>; // explicit instantiation of S<double> + + void user() { + S<int> a; // implicit instantiation of S<int> + S<float>* b; + b->foo(); // implicit instatiation of S<float> and S<float>::foo() + } + )"; + + setupProfiler(); + ASSERT_TRUE(compileFromString(Code, "-std=c++20", "test.cc")); + std::string Json = teardownProfiler(); + ASSERT_EQ(R"( +Frontend (test.cc) +| ParseClass (S) +| InstantiateClass (S<double>, test.cc:9) +| InstantiateFunction (S<double>::foo, test.cc:5) +| ParseDeclarationOrFunctionDefinition (test.cc:11:5) +| | ParseFunctionDefinition (user) +| | | InstantiateClass (S<int>, test.cc:3) +| | | InstantiateClass (S<float>, test.cc:3) +| | | DeferInstantiation (S<float>::foo, test.cc:5) +| PerformPendingInstantiations +| | InstantiateFunction (S<float>::foo, test.cc:5) +)", + buildTraceGraph(Json)); +} + TEST(TimeProfilerTest, TemplateInstantiations) { std::string B_H = R"( template <typename T> - T fooB(T t) { + T fooC(T t) { return T(); } + template <typename T> + constexpr T fooB(T t) { + return fooC(t); + } + #define MacroTemp(x) template <typename T> void foo##x(T) { T(); } )"; @@ -267,14 +309,19 @@ TEST(TimeProfilerTest, TemplateInstantiations) { std::string Json = teardownProfiler(); ASSERT_EQ(R"( Frontend (test.cc) +| ParseFunctionDefinition (fooC) | ParseFunctionDefinition (fooB) | ParseFunctionDefinition (fooMTA) | ParseFunctionDefinition (fooA) | ParseDeclarationOrFunctionDefinition (test.cc:3:5) | | ParseFunctionDefinition (user) +| | | DeferInstantiation (fooA<int>, a.h:7) | PerformPendingInstantiations | | InstantiateFunction (fooA<int>, a.h:7) -| | | InstantiateFunction (fooB<int>, b.h:3) +| | | InstantiateFunction (fooB<int>, b.h:8) +| | | | DeferInstantiation (fooC<int>, b.h:3) +| | | DeferInstantiation (fooMTA<int>, a.h:4) +| | | InstantiateFunction (fooC<int>, b.h:3) | | | InstantiateFunction (fooMTA<int>, a.h:4) )", buildTraceGraph(Json)); diff --git a/llvm/include/llvm/Support/TimeProfiler.h b/llvm/include/llvm/Support/TimeProfiler.h index 9e2ba31991f542..9a6bcdefee6c20 100644 --- a/llvm/include/llvm/Support/TimeProfiler.h +++ b/llvm/include/llvm/Support/TimeProfiler.h @@ -83,6 +83,8 @@ namespace llvm { class raw_pwrite_stream; +enum class TimeTraceEventType { CompleteEvent, InstantEvent, AsyncEvent }; + struct TimeTraceMetadata { std::string Detail; // Source file and line number information for the event. @@ -152,6 +154,11 @@ timeTraceProfilerBegin(StringRef Name, TimeTraceProfilerEntry *timeTraceAsyncProfilerBegin(StringRef Name, StringRef Detail); +// Mark an instant event. +void timeTraceProfilerInsert(StringRef Name, + llvm::function_ref<TimeTraceMetadata()> Metadata); +void timeTraceProfilerInsert(StringRef Name, StringRef Detail); + /// Manually end the last time section. void timeTraceProfilerEnd(); void timeTraceProfilerEnd(TimeTraceProfilerEntry *E); diff --git a/llvm/lib/Support/TimeProfiler.cpp b/llvm/lib/Support/TimeProfiler.cpp index c2014028ddadca..31faa36c29f14d 100644 --- a/llvm/lib/Support/TimeProfiler.cpp +++ b/llvm/lib/Support/TimeProfiler.cpp @@ -13,6 +13,7 @@ #include "llvm/Support/TimeProfiler.h" #include "llvm/ADT/STLExtras.h" #include "llvm/ADT/STLFunctionalExtras.h" +#include "llvm/ADT/SmallVector.h" #include "llvm/ADT/StringMap.h" #include "llvm/Support/JSON.h" #include "llvm/Support/Path.h" @@ -75,18 +76,18 @@ struct llvm::TimeTraceProfilerEntry { const std::string Name; TimeTraceMetadata Metadata; - const bool AsyncEvent = false; + TimeTraceEventType EventType; TimeTraceProfilerEntry(TimePointType &&S, TimePointType &&E, std::string &&N, - std::string &&Dt, bool Ae) + std::string &&Dt, TimeTraceEventType Et) : Start(std::move(S)), End(std::move(E)), Name(std::move(N)), Metadata(), - AsyncEvent(Ae) { + EventType(Et) { Metadata.Detail = std::move(Dt); } TimeTraceProfilerEntry(TimePointType &&S, TimePointType &&E, std::string &&N, - TimeTraceMetadata &&Mt, bool Ae) + TimeTraceMetadata &&Mt, TimeTraceEventType Et) : Start(std::move(S)), End(std::move(E)), Name(std::move(N)), - Metadata(std::move(Mt)), AsyncEvent(Ae) {} + Metadata(std::move(Mt)), EventType(Et) {} // Calculate timings for FlameGraph. Cast time points to microsecond precision // rather than casting duration. This avoids truncation issues causing inner @@ -104,6 +105,23 @@ struct llvm::TimeTraceProfilerEntry { } }; +struct InProgressEntry { + std::unique_ptr<TimeTraceProfilerEntry> Event; + std::vector<TimeTraceProfilerEntry> InstantEvents; + + InProgressEntry(TimePointType &&S, TimePointType &&E, std::string &&N, + std::string &&Dt, TimeTraceEventType Et) + : Event(std::make_unique<TimeTraceProfilerEntry>( + std::move(S), std::move(E), std::move(N), std::move(Dt), Et)), + InstantEvents() {} + + InProgressEntry(TimePointType &&S, TimePointType &&E, std::string &&N, + TimeTraceMetadata &&Mt, TimeTraceEventType Et) + : Event(std::make_unique<TimeTraceProfilerEntry>( + std::move(S), std::move(E), std::move(N), std::move(Mt), Et)), + InstantEvents() {} +}; + struct llvm::TimeTraceProfiler { TimeTraceProfiler(unsigned TimeTraceGranularity = 0, StringRef ProcName = "", bool TimeTraceVerbose = false) @@ -114,27 +132,46 @@ struct llvm::TimeTraceProfiler { llvm::get_thread_name(ThreadName); } - TimeTraceProfilerEntry *begin(std::string Name, - llvm::function_ref<std::string()> Detail, - bool AsyncEvent = false) { - Stack.emplace_back(std::make_unique<TimeTraceProfilerEntry>( + TimeTraceProfilerEntry * + begin(std::string Name, llvm::function_ref<std::string()> Detail, + TimeTraceEventType EventType = TimeTraceEventType::CompleteEvent) { + Stack.emplace_back(std::make_unique<InProgressEntry>( ClockType::now(), TimePointType(), std::move(Name), Detail(), - AsyncEvent)); - return Stack.back().get(); + EventType)); + return Stack.back()->Event.get(); } TimeTraceProfilerEntry * begin(std::string Name, llvm::function_ref<TimeTraceMetadata()> Metadata, - bool AsyncEvent = false) { - Stack.emplace_back(std::make_unique<TimeTraceProfilerEntry>( + TimeTraceEventType EventType = TimeTraceEventType::CompleteEvent) { + Stack.emplace_back(std::make_unique<InProgressEntry>( + ClockType::now(), TimePointType(), std::move(Name), Metadata(), + EventType)); + return Stack.back()->Event.get(); + } + + void insert(std::string Name, llvm::function_ref<std::string()> Detail) { + if (Stack.empty()) + return; + + Stack.back().get()->InstantEvents.emplace_back(TimeTraceProfilerEntry( + ClockType::now(), TimePointType(), std::move(Name), Detail(), + TimeTraceEventType::InstantEvent)); + } + + void insert(std::string Name, + llvm::function_ref<TimeTraceMetadata()> Metadata) { + if (Stack.empty()) + return; + + Stack.back().get()->InstantEvents.emplace_back(TimeTraceProfilerEntry( ClockType::now(), TimePointType(), std::move(Name), Metadata(), - AsyncEvent)); - return Stack.back().get(); + TimeTraceEventType::InstantEvent)); } void end() { assert(!Stack.empty() && "Must call begin() first"); - end(*Stack.back()); + end(*Stack.back()->Event); } void end(TimeTraceProfilerEntry &E) { @@ -145,8 +182,14 @@ struct llvm::TimeTraceProfiler { DurationType Duration = E.End - E.Start; // Only include sections longer or equal to TimeTraceGranularity msec. - if (duration_cast<microseconds>(Duration).count() >= TimeTraceGranularity) + if (duration_cast<microseconds>(Duration).count() >= TimeTraceGranularity) { Entries.emplace_back(E); + if (Stack.back()->Event.get() == &E) { + for (auto &IE : Stack.back()->InstantEvents) { + Entries.emplace_back(IE); + } + } + } // Track total time taken by each "name", but only the topmost levels of // them; e.g. if there's a template instantiation that instantiates other @@ -154,18 +197,17 @@ struct llvm::TimeTraceProfiler { // happens to be the ones that don't have any currently open entries above // itself. if (llvm::none_of(llvm::drop_begin(llvm::reverse(Stack)), - [&](const std::unique_ptr<TimeTraceProfilerEntry> &Val) { - return Val->Name == E.Name; + [&](const std::unique_ptr<InProgressEntry> &Val) { + return Val->Event->Name == E.Name; })) { auto &CountAndTotal = CountAndTotalPerName[E.Name]; CountAndTotal.first++; CountAndTotal.second += Duration; }; - llvm::erase_if(Stack, - [&](const std::unique_ptr<TimeTraceProfilerEntry> &Val) { - return Val.get() == &E; - }); + llvm::erase_if(Stack, [&](const std::unique_ptr<InProgressEntry> &Val) { + return Val->Event.get() == &E; + }); } // Write events from this TimeTraceProfilerInstance and @@ -194,13 +236,15 @@ struct llvm::TimeTraceProfiler { J.attribute("pid", Pid); J.attribute("tid", int64_t(Tid)); J.attribute("ts", StartUs); - if (E.AsyncEvent) { + if (TimeTraceEventType::AsyncEvent == E.EventType) { J.attribute("cat", E.Name); J.attribute("ph", "b"); J.attribute("id", 0); - } else { + } else if (E.EventType == TimeTraceEventType::CompleteEvent) { J.attribute("ph", "X"); J.attribute("dur", DurUs); + } else { // instant event + J.attribute("ph", "i"); } J.attribute("name", E.Name); if (!E.Metadata.isEmpty()) { @@ -215,7 +259,7 @@ struct llvm::TimeTraceProfiler { } }); - if (E.AsyncEvent) { + if (TimeTraceEventType::AsyncEvent == E.EventType) { J.object([&] { J.attribute("pid", Pid); J.attribute("tid", int64_t(Tid)); @@ -319,7 +363,7 @@ struct llvm::TimeTraceProfiler { J.objectEnd(); } - SmallVector<std::unique_ptr<TimeTraceProfilerEntry>, 16> Stack; + SmallVector<std::unique_ptr<InProgressEntry>, 16> Stack; SmallVector<TimeTraceProfilerEntry, 128> Entries; StringMap<CountAndDurationType> CountAndTotalPerName; // System clock time when the session was begun. @@ -406,7 +450,8 @@ TimeTraceProfilerEntry *llvm::timeTraceProfilerBegin(StringRef Name, StringRef Detail) { if (TimeTraceProfilerInstance != nullptr) return TimeTraceProfilerInstance->begin( - std::string(Name), [&]() { return std::string(Detail); }, false); + std::string(Name), [&]() { return std::string(Detail); }, + TimeTraceEventType::CompleteEvent); return nullptr; } @@ -414,7 +459,8 @@ TimeTraceProfilerEntry * llvm::timeTraceProfilerBegin(StringRef Name, llvm::function_ref<std::string()> Detail) { if (TimeTraceProfilerInstance != nullptr) - return TimeTraceProfilerInstance->begin(std::string(Name), Detail, false); + return TimeTraceProfilerInstance->begin(std::string(Name), Detail, + TimeTraceEventType::CompleteEvent); return nullptr; } @@ -422,7 +468,8 @@ TimeTraceProfilerEntry * llvm::timeTraceProfilerBegin(StringRef Name, llvm::function_ref<TimeTraceMetadata()> Metadata) { if (TimeTraceProfilerInstance != nullptr) - return TimeTraceProfilerInstance->begin(std::string(Name), Metadata, false); + return TimeTraceProfilerInstance->begin(std::string(Name), Metadata, + TimeTraceEventType::CompleteEvent); return nullptr; } @@ -430,10 +477,23 @@ TimeTraceProfilerEntry *llvm::timeTraceAsyncProfilerBegin(StringRef Name, StringRef Detail) { if (TimeTraceProfilerInstance != nullptr) return TimeTraceProfilerInstance->begin( - std::string(Name), [&]() { return std::string(Detail); }, true); + std::string(Name), [&]() { return std::string(Detail); }, + TimeTraceEventType::AsyncEvent); return nullptr; } +void llvm::timeTraceProfilerInsert(StringRef Name, StringRef Detail) { + if (TimeTraceProfilerInstance != nullptr) + TimeTraceProfilerInstance->insert(std::string(Name), + [&]() { return std::string(Detail); }); +} + +void llvm::timeTraceProfilerInsert( + StringRef Name, llvm::function_ref<TimeTraceMetadata()> Metadata) { + if (TimeTraceProfilerInstance != nullptr) + TimeTraceProfilerInstance->insert(std::string(Name), Metadata); +} + void llvm::timeTraceProfilerEnd() { if (TimeTraceProfilerInstance != nullptr) TimeTraceProfilerInstance->end(); `````````` </details> https://github.com/llvm/llvm-project/pull/103039 _______________________________________________ cfe-commits mailing list cfe-commits@lists.llvm.org https://lists.llvm.org/cgi-bin/mailman/listinfo/cfe-commits
