[clang] [llvm] Added instant events and marking defered templated instantiation. (PR #103039)
via llvm-commits
llvm-commits at lists.llvm.org
Mon Oct 7 05:35:19 PDT 2024
https://github.com/ivanaivanovska updated https://github.com/llvm/llvm-project/pull/103039
>From 6d3e4470dfe21f8f3832a2d38b4c4327aa7422a3 Mon Sep 17 00:00:00 2001
From: Ivana Ivanovska <iivanovska at google.com>
Date: Tue, 13 Aug 2024 10:30:34 +0000
Subject: [PATCH 1/6] Added instant events and marking defered templated
instantiation.
---
clang/lib/Sema/SemaExpr.cpp | 18 ++++++
.../lib/Sema/SemaTemplateInstantiateDecl.cpp | 17 +++++
clang/unittests/Support/TimeProfilerTest.cpp | 51 ++++++++++++++-
llvm/include/llvm/Support/TimeProfiler.h | 19 +++++-
llvm/lib/Support/TimeProfiler.cpp | 64 +++++++++++++------
5 files changed, 145 insertions(+), 24 deletions(-)
diff --git a/clang/lib/Sema/SemaExpr.cpp b/clang/lib/Sema/SemaExpr.cpp
index 95f53dfefbcc52..9e88fe5a94289d 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,22 @@ 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::TimeTraceScope TimeScope(
+ "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;
+ },
+ llvm::TimeTraceEventType::InstantEvent);
}
}
} else {
diff --git a/clang/lib/Sema/SemaTemplateInstantiateDecl.cpp b/clang/lib/Sema/SemaTemplateInstantiateDecl.cpp
index 0e064be2391838..191f46ed00b7cc 100644
--- a/clang/lib/Sema/SemaTemplateInstantiateDecl.cpp
+++ b/clang/lib/Sema/SemaTemplateInstantiateDecl.cpp
@@ -4983,6 +4983,23 @@ void Sema::InstantiateFunctionDefinition(SourceLocation PointOfInstantiation,
Function->setInstantiationIsPending(true);
PendingInstantiations.push_back(
std::make_pair(Function, PointOfInstantiation));
+
+ llvm::TimeTraceScope TimeScope(
+ "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;
+ },
+ llvm::TimeTraceEventType::InstantEvent);
+
} 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..f4952b18e4f6ef 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,10 @@ timeTraceProfilerBegin(StringRef Name,
TimeTraceProfilerEntry *timeTraceAsyncProfilerBegin(StringRef Name,
StringRef Detail);
+// Mark an instant event.
+TimeTraceProfilerEntry *timeTraceInstantEventProfilerBegin(StringRef Name,
+ llvm::function_ref<TimeTraceMetadata()> Metadata);
+
/// Manually end the last time section.
void timeTraceProfilerEnd();
void timeTraceProfilerEnd(TimeTraceProfilerEntry *E);
@@ -181,9 +187,18 @@ class TimeTraceScope {
Entry = timeTraceProfilerBegin(Name, Detail);
}
TimeTraceScope(StringRef Name,
- llvm::function_ref<TimeTraceMetadata()> Metadata) {
- if (getTimeTraceProfilerInstance() != nullptr)
+ llvm::function_ref<TimeTraceMetadata()> Metadata, TimeTraceEventType Et = TimeTraceEventType::CompleteEvent) {
+ if (getTimeTraceProfilerInstance() == nullptr)
+ return;
+ assert((Et == TimeTraceEventType::InstantEvent ||
+ Et == TimeTraceEventType::CompleteEvent) &&
+ "Event Type not supported.");
+
+ if (Et == TimeTraceEventType::CompleteEvent) {
Entry = timeTraceProfilerBegin(Name, Metadata);
+ } else {
+ Entry = timeTraceInstantEventProfilerBegin(Name, Metadata);
+ }
}
~TimeTraceScope() {
if (getTimeTraceProfilerInstance() != nullptr)
diff --git a/llvm/lib/Support/TimeProfiler.cpp b/llvm/lib/Support/TimeProfiler.cpp
index c2014028ddadca..738f5f5842bb0d 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"
@@ -70,23 +71,23 @@ using NameAndCountAndDurationType =
/// Represents an open or completed time section entry to be captured.
struct llvm::TimeTraceProfilerEntry {
- const TimePointType Start;
+ TimePointType Start;
TimePointType End;
- const std::string Name;
+ std::string Name;
TimeTraceMetadata Metadata;
+ TimeTraceEventType EventType;
- const bool AsyncEvent = false;
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
@@ -116,19 +117,19 @@ struct llvm::TimeTraceProfiler {
TimeTraceProfilerEntry *begin(std::string Name,
llvm::function_ref<std::string()> Detail,
- bool AsyncEvent = false) {
+ TimeTraceEventType Et = TimeTraceEventType::CompleteEvent) {
Stack.emplace_back(std::make_unique<TimeTraceProfilerEntry>(
ClockType::now(), TimePointType(), std::move(Name), Detail(),
- AsyncEvent));
+ Et));
return Stack.back().get();
}
TimeTraceProfilerEntry *
begin(std::string Name, llvm::function_ref<TimeTraceMetadata()> Metadata,
- bool AsyncEvent = false) {
+ TimeTraceEventType Et = TimeTraceEventType::CompleteEvent) {
Stack.emplace_back(std::make_unique<TimeTraceProfilerEntry>(
ClockType::now(), TimePointType(), std::move(Name), Metadata(),
- AsyncEvent));
+ Et));
return Stack.back().get();
}
@@ -144,9 +145,22 @@ struct llvm::TimeTraceProfiler {
// Calculate duration at full precision for overall counts.
DurationType Duration = E.End - E.Start;
- // Only include sections longer or equal to TimeTraceGranularity msec.
- if (duration_cast<microseconds>(Duration).count() >= TimeTraceGranularity)
+ // Only include Instant Events or events with a duration longer or equal to
+ // TimeTraceGranularity msec.
+ if (E.EventType == TimeTraceEventType::InstantEvent ||
+ duration_cast<microseconds>(Duration).count() >= TimeTraceGranularity) {
Entries.emplace_back(E);
+ } else {
+ // if the event is not included, exclude also all instant events that
+ // happened during this event.
+ for (SmallVector<TimeTraceProfilerEntry, 128>::iterator it = Entries.begin(); it != Entries.end();) {
+ if (TimeTraceEventType::InstantEvent == it->EventType &&
+ it->Start > E.Start && it->Start < E.End)
+ it = Entries.erase(it);
+ else
+ ++it;
+ }
+ }
// 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
@@ -194,13 +208,15 @@ struct llvm::TimeTraceProfiler {
J.attribute("pid", Pid);
J.attribute("tid", int64_t(Tid));
J.attribute("ts", StartUs);
- if (E.AsyncEvent) {
+ if (E.EventType == TimeTraceEventType::AsyncEvent) {
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 +231,7 @@ struct llvm::TimeTraceProfiler {
}
});
- if (E.AsyncEvent) {
+ if (E.EventType == TimeTraceEventType::AsyncEvent) {
J.object([&] {
J.attribute("pid", Pid);
J.attribute("tid", int64_t(Tid));
@@ -406,7 +422,7 @@ 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 +430,7 @@ 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 +438,15 @@ 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;
+}
+
+TimeTraceProfilerEntry *
+llvm::timeTraceInstantEventProfilerBegin(StringRef Name,
+ llvm::function_ref<TimeTraceMetadata()> Metadata) {
+ if (TimeTraceProfilerInstance != nullptr)
+ return TimeTraceProfilerInstance->begin(std::string(Name), Metadata, TimeTraceEventType::InstantEvent);
return nullptr;
}
@@ -430,7 +454,7 @@ 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;
}
>From 3a8d8ee992bbd22b2ac342042a5c61f2e96687d3 Mon Sep 17 00:00:00 2001
From: Ivana Ivanovska <iivanovska at google.com>
Date: Wed, 28 Aug 2024 09:57:49 +0000
Subject: [PATCH 2/6] Refactored TimeTraceProfilerEntry to allow easier
extensibility. Implemented inserting Instant Events with a single function.
---
clang/lib/Sema/Sema.cpp | 8 +-
clang/lib/Sema/SemaExpr.cpp | 27 +-
.../lib/Sema/SemaTemplateInstantiateDecl.cpp | 28 +-
llvm/include/llvm/Support/TimeProfiler.h | 40 +--
llvm/lib/Support/TimeProfiler.cpp | 324 +++++++++++-------
llvm/unittests/Support/TimeProfilerTest.cpp | 2 +-
6 files changed, 255 insertions(+), 174 deletions(-)
diff --git a/clang/lib/Sema/Sema.cpp b/clang/lib/Sema/Sema.cpp
index 29acd06af603be..d8305861bf21c6 100644
--- a/clang/lib/Sema/Sema.cpp
+++ b/clang/lib/Sema/Sema.cpp
@@ -160,7 +160,7 @@ namespace sema {
class SemaPPCallbacks : public PPCallbacks {
Sema *S = nullptr;
llvm::SmallVector<SourceLocation, 8> IncludeStack;
- llvm::SmallVector<llvm::TimeTraceProfilerEntry *, 8> ProfilerStack;
+ llvm::SmallVector<std::shared_ptr<llvm::DurableEvent>, 8> ProfilerStack;
public:
void set(Sema &S) { this->S = &S; }
@@ -192,8 +192,10 @@ class SemaPPCallbacks : public PPCallbacks {
}
case ExitFile:
if (!IncludeStack.empty()) {
- if (llvm::timeTraceProfilerEnabled())
- llvm::timeTraceProfilerEnd(ProfilerStack.pop_back_val());
+ if (llvm::timeTraceProfilerEnabled()) {
+ auto E = ProfilerStack.pop_back_val();
+ llvm::timeTraceProfilerEnd(E);
+ }
S->DiagnoseNonDefaultPragmaAlignPack(
Sema::PragmaAlignPackDiagnoseKind::ChangedStateAtExit,
diff --git a/clang/lib/Sema/SemaExpr.cpp b/clang/lib/Sema/SemaExpr.cpp
index 9e88fe5a94289d..a7dd01c936bac8 100644
--- a/clang/lib/Sema/SemaExpr.cpp
+++ b/clang/lib/Sema/SemaExpr.cpp
@@ -18049,21 +18049,18 @@ void Sema::MarkFunctionReferenced(SourceLocation Loc, FunctionDecl *Func,
// Notify the consumer that a function was implicitly instantiated.
Consumer.HandleCXXImplicitFunctionInstantiation(Func);
- llvm::TimeTraceScope TimeScope(
- "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;
- },
- llvm::TimeTraceEventType::InstantEvent);
+ 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 191f46ed00b7cc..550add5495c833 100644
--- a/clang/lib/Sema/SemaTemplateInstantiateDecl.cpp
+++ b/clang/lib/Sema/SemaTemplateInstantiateDecl.cpp
@@ -4984,22 +4984,18 @@ void Sema::InstantiateFunctionDefinition(SourceLocation PointOfInstantiation,
PendingInstantiations.push_back(
std::make_pair(Function, PointOfInstantiation));
- llvm::TimeTraceScope TimeScope(
- "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;
- },
- llvm::TimeTraceEventType::InstantEvent);
-
+ 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/llvm/include/llvm/Support/TimeProfiler.h b/llvm/include/llvm/Support/TimeProfiler.h
index f4952b18e4f6ef..323d7c8c5f8c55 100644
--- a/llvm/include/llvm/Support/TimeProfiler.h
+++ b/llvm/include/llvm/Support/TimeProfiler.h
@@ -94,13 +94,17 @@ struct TimeTraceMetadata {
bool isEmpty() const { return Detail.empty() && File.empty(); }
};
+struct TimeTraceProfilerEntry;
+struct InstantEvent;
+struct DurableEvent;
+struct CompleteEvent;
+struct AsyncEvent;
+
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.
@@ -136,13 +140,13 @@ Error timeTraceProfilerWrite(StringRef PreferredFileName,
/// Profiler copies the string data, so the pointers can be given into
/// temporaries. Time sections can be hierarchical; every Begin must have a
/// matching End pair but they can nest.
-TimeTraceProfilerEntry *timeTraceProfilerBegin(StringRef Name,
- StringRef Detail);
-TimeTraceProfilerEntry *
+std::shared_ptr<DurableEvent> timeTraceProfilerBegin(StringRef Name,
+ StringRef Detail);
+std::shared_ptr<DurableEvent>
timeTraceProfilerBegin(StringRef Name,
llvm::function_ref<std::string()> Detail);
-TimeTraceProfilerEntry *
+std::shared_ptr<DurableEvent>
timeTraceProfilerBegin(StringRef Name,
llvm::function_ref<TimeTraceMetadata()> MetaData);
@@ -151,16 +155,17 @@ timeTraceProfilerBegin(StringRef Name,
/// separately from other traces. See
/// https://docs.google.com/document/d/1CvAClvFfyA5R-PhYUmn5OOQtYMH4h6I0nSsKchNAySU/preview#heading=h.jh64i9l3vwa1
/// for more details.
-TimeTraceProfilerEntry *timeTraceAsyncProfilerBegin(StringRef Name,
- StringRef Detail);
+std::shared_ptr<DurableEvent> timeTraceAsyncProfilerBegin(StringRef Name,
+ StringRef Detail);
// Mark an instant event.
-TimeTraceProfilerEntry *timeTraceInstantEventProfilerBegin(StringRef Name,
+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);
+void timeTraceProfilerEnd(std::shared_ptr<DurableEvent> &E);
/// The TimeTraceScope is a helper class to call the begin and end functions
/// of the time trace profiler. When the object is constructed, it begins
@@ -187,18 +192,9 @@ class TimeTraceScope {
Entry = timeTraceProfilerBegin(Name, Detail);
}
TimeTraceScope(StringRef Name,
- llvm::function_ref<TimeTraceMetadata()> Metadata, TimeTraceEventType Et = TimeTraceEventType::CompleteEvent) {
- if (getTimeTraceProfilerInstance() == nullptr)
- return;
- assert((Et == TimeTraceEventType::InstantEvent ||
- Et == TimeTraceEventType::CompleteEvent) &&
- "Event Type not supported.");
-
- if (Et == TimeTraceEventType::CompleteEvent) {
+ llvm::function_ref<TimeTraceMetadata()> Metadata) {
+ if (getTimeTraceProfilerInstance() != nullptr)
Entry = timeTraceProfilerBegin(Name, Metadata);
- } else {
- Entry = timeTraceInstantEventProfilerBegin(Name, Metadata);
- }
}
~TimeTraceScope() {
if (getTimeTraceProfilerInstance() != nullptr)
@@ -206,7 +202,7 @@ class TimeTraceScope {
}
private:
- TimeTraceProfilerEntry *Entry = nullptr;
+ std::shared_ptr<DurableEvent> Entry = nullptr;
};
} // end namespace llvm
diff --git a/llvm/lib/Support/TimeProfiler.cpp b/llvm/lib/Support/TimeProfiler.cpp
index 738f5f5842bb0d..ac0c1d89bb8176 100644
--- a/llvm/lib/Support/TimeProfiler.cpp
+++ b/llvm/lib/Support/TimeProfiler.cpp
@@ -69,25 +69,20 @@ using NameAndCountAndDurationType =
} // anonymous namespace
-/// Represents an open or completed time section entry to be captured.
+/// Represents an entry to be captured.
struct llvm::TimeTraceProfilerEntry {
- TimePointType Start;
- TimePointType End;
- std::string Name;
+ const TimePointType Start;
+ const std::string Name;
TimeTraceMetadata Metadata;
- TimeTraceEventType EventType;
- TimeTraceProfilerEntry(TimePointType &&S, TimePointType &&E, std::string &&N,
- std::string &&Dt, TimeTraceEventType Et)
- : Start(std::move(S)), End(std::move(E)), Name(std::move(N)), Metadata(),
- EventType(Et) {
+ TimeTraceProfilerEntry(TimePointType &&S, std::string &&N, std::string &&Dt)
+ : Start(std::move(S)), Name(std::move(N)), Metadata() {
Metadata.Detail = std::move(Dt);
}
- TimeTraceProfilerEntry(TimePointType &&S, TimePointType &&E, std::string &&N,
- TimeTraceMetadata &&Mt, TimeTraceEventType Et)
- : Start(std::move(S)), End(std::move(E)), Name(std::move(N)),
- Metadata(std::move(Mt)), EventType(Et) {}
+ TimeTraceProfilerEntry(TimePointType &&S, std::string &&N,
+ TimeTraceMetadata &&Mt)
+ : Start(std::move(S)), Name(std::move(N)), Metadata(std::move(Mt)) {}
// Calculate timings for FlameGraph. Cast time points to microsecond precision
// rather than casting duration. This avoids truncation issues causing inner
@@ -98,11 +93,128 @@ struct llvm::TimeTraceProfilerEntry {
.count();
}
+ virtual void writeEvent(json::OStream &J, sys::Process::Pid Pid, uint64_t Tid,
+ TimePointType StartTime) const {
+ J.object([&] {
+ J.attribute("pid", Pid);
+ J.attribute("tid", int64_t(Tid));
+ J.attribute("ts", getFlameGraphStartUs(StartTime));
+ writeAdditionalEventFileds(J);
+ J.attribute("name", Name);
+ if (!Metadata.isEmpty()) {
+ J.attributeObject("args", [&] {
+ if (!Metadata.Detail.empty())
+ J.attribute("detail", Metadata.Detail);
+ if (!Metadata.File.empty())
+ J.attribute("file", Metadata.File);
+ if (Metadata.Line > 0)
+ J.attribute("line", Metadata.Line);
+ });
+ }
+ });
+ }
+
+ virtual void writeAdditionalEventFileds(json::OStream &J) const {}
+
+ virtual ~TimeTraceProfilerEntry() = default;
+};
+
+struct llvm::InstantEvent : llvm::TimeTraceProfilerEntry {
+ InstantEvent(TimePointType &&S, std::string &&N, std::string &&Dt)
+ : TimeTraceProfilerEntry(std::move(S), std::move(N), std::move(Dt)) {}
+
+ InstantEvent(TimePointType &&S, std::string &&N, TimeTraceMetadata &&Mt)
+ : TimeTraceProfilerEntry(std::move(S), std::move(N), std::move(Mt)) {}
+
+ void writeAdditionalEventFileds(json::OStream &J) const override {
+ J.attribute("ph", "i");
+ }
+};
+
+struct llvm::DurableEvent : llvm::TimeTraceProfilerEntry {
+ DurableEvent(TimePointType &&S, TimePointType &&E, std::string &&N,
+ std::string &&Dt)
+ : TimeTraceProfilerEntry(std::move(S), std::move(N), std::move(Dt)),
+ InstantEvents{}, End(std::move(E)) {}
+
+ DurableEvent(TimePointType &&S, TimePointType &&E, std::string &&N,
+ TimeTraceMetadata &&Mt)
+ : TimeTraceProfilerEntry(std::move(S), std::move(N), std::move(Mt)),
+ InstantEvents{}, End(std::move(E)) {}
+
+ virtual void writeEvent(json::OStream &J, sys::Process::Pid Pid, uint64_t Tid,
+ TimePointType StartTime) const override {
+ TimeTraceProfilerEntry::writeEvent(J, Pid, Tid, StartTime);
+ writeInstantEvents(J, Pid, Tid, StartTime);
+ }
+
+ void writeInstantEvents(json::OStream &J, sys::Process::Pid Pid, uint64_t Tid,
+ TimePointType StartTime) const {
+ for (auto IE : InstantEvents) {
+ IE->writeEvent(J, Pid, Tid, StartTime);
+ }
+ }
+
+ virtual void writeAdditionalEventFileds(json::OStream &J) const override {}
+
ClockType::rep getFlameGraphDurUs() const {
return (time_point_cast<microseconds>(End) -
time_point_cast<microseconds>(Start))
.count();
}
+
+ std::vector<std::shared_ptr<InstantEvent>> InstantEvents;
+ TimePointType End;
+};
+
+struct llvm::CompleteEvent : llvm::DurableEvent {
+ CompleteEvent(TimePointType &&S, TimePointType &&E, std::string &&N,
+ std::string &&Dt)
+ : DurableEvent(std::move(S), std::move(E), std::move(N), std::move(Dt)) {}
+
+ CompleteEvent(TimePointType &&S, TimePointType &&E, std::string &&N,
+ TimeTraceMetadata &&Mt)
+ : DurableEvent(std::move(S), std::move(E), std::move(N), std::move(Mt)) {}
+
+ virtual void writeAdditionalEventFileds(json::OStream &J) const override {
+ J.attribute("ph", "X");
+ J.attribute("dur", getFlameGraphDurUs());
+ }
+};
+
+struct llvm::AsyncEvent : llvm::DurableEvent {
+ AsyncEvent(TimePointType &&S, TimePointType &&E, std::string &&N,
+ std::string &&Dt)
+ : DurableEvent(std::move(S), std::move(E), std::move(N), std::move(Dt)) {}
+
+ AsyncEvent(TimePointType &&S, TimePointType &&E, std::string &&N,
+ TimeTraceMetadata &&Mt)
+ : DurableEvent(std::move(S), std::move(E), std::move(N), std::move(Mt)) {}
+
+ void writeEvent(json::OStream &J, sys::Process::Pid Pid, uint64_t Tid,
+ TimePointType StartTime) const override {
+ DurableEvent::writeEvent(J, Pid, Tid, StartTime);
+ writeEndEvent(J, Pid, Tid, StartTime);
+ }
+
+ void writeEndEvent(json::OStream &J, sys::Process::Pid Pid, uint64_t Tid,
+ TimePointType StartTime) const {
+ J.object([&] {
+ J.attribute("pid", Pid);
+ J.attribute("tid", int64_t(Tid));
+ J.attribute("ts", getFlameGraphStartUs(StartTime) + getFlameGraphDurUs());
+ J.attribute("cat", Name);
+ J.attribute("ph", "e");
+ J.attribute("id", 0);
+ J.attribute("name", Name);
+ });
+ }
+
+ void writeAdditionalEventFileds(json::OStream &J) const override {
+ J.attribute("cat", Name);
+ J.attribute("ph", "b");
+ J.attribute("id", 0);
+ }
};
struct llvm::TimeTraceProfiler {
@@ -114,52 +226,68 @@ struct llvm::TimeTraceProfiler {
TimeTraceVerbose(TimeTraceVerbose) {
llvm::get_thread_name(ThreadName);
}
-
- TimeTraceProfilerEntry *begin(std::string Name,
- llvm::function_ref<std::string()> Detail,
- TimeTraceEventType Et = TimeTraceEventType::CompleteEvent) {
- Stack.emplace_back(std::make_unique<TimeTraceProfilerEntry>(
- ClockType::now(), TimePointType(), std::move(Name), Detail(),
- Et));
- return Stack.back().get();
+ std::shared_ptr<DurableEvent> begin(std::string Name,
+ llvm::function_ref<std::string()> Detail,
+ bool AsyncEventType) {
+ if (AsyncEventType) {
+ Stack.emplace_back(std::make_shared<AsyncEvent>(
+ ClockType::now(), TimePointType(), std::move(Name), Detail()));
+ } else {
+ Stack.emplace_back(std::make_shared<CompleteEvent>(
+ ClockType::now(), TimePointType(), std::move(Name), Detail()));
+ }
+ return Stack.back();
}
- TimeTraceProfilerEntry *
+ std::shared_ptr<DurableEvent>
begin(std::string Name, llvm::function_ref<TimeTraceMetadata()> Metadata,
- TimeTraceEventType Et = TimeTraceEventType::CompleteEvent) {
- Stack.emplace_back(std::make_unique<TimeTraceProfilerEntry>(
- ClockType::now(), TimePointType(), std::move(Name), Metadata(),
- Et));
- return Stack.back().get();
+ bool AsyncEventType) {
+
+ if (AsyncEventType) {
+ Stack.emplace_back(std::make_shared<AsyncEvent>(
+ ClockType::now(), TimePointType(), std::move(Name), Metadata()));
+ } else {
+ Stack.emplace_back(std::make_shared<CompleteEvent>(
+ ClockType::now(), TimePointType(), std::move(Name), Metadata()));
+ }
+ return Stack.back();
+ }
+
+ void insert(std::string Name, llvm::function_ref<std::string()> Detail) {
+ if (Stack.empty())
+ return;
+
+ Stack.back().get()->InstantEvents.emplace_back(
+ std::make_shared<InstantEvent>(ClockType::now(), std::move(Name),
+ Detail()));
+ }
+
+ void insert(std::string Name,
+ llvm::function_ref<TimeTraceMetadata()> Metadata) {
+ if (Stack.empty())
+ return;
+
+ Stack.back().get()->InstantEvents.emplace_back(
+ std::make_shared<InstantEvent>(ClockType::now(), std::move(Name),
+ Metadata()));
}
void end() {
assert(!Stack.empty() && "Must call begin() first");
- end(*Stack.back());
+ end(Stack.back());
}
- void end(TimeTraceProfilerEntry &E) {
+ void end(std::shared_ptr<DurableEvent> &E) {
assert(!Stack.empty() && "Must call begin() first");
- E.End = ClockType::now();
+ E->End = ClockType::now();
// Calculate duration at full precision for overall counts.
- DurationType Duration = E.End - E.Start;
+ DurationType Duration = E->End - E->Start;
- // Only include Instant Events or events with a duration longer or equal to
+ // Only include events with a duration longer or equal to
// TimeTraceGranularity msec.
- if (E.EventType == TimeTraceEventType::InstantEvent ||
- duration_cast<microseconds>(Duration).count() >= TimeTraceGranularity) {
+ if (duration_cast<microseconds>(Duration).count() >= TimeTraceGranularity) {
Entries.emplace_back(E);
- } else {
- // if the event is not included, exclude also all instant events that
- // happened during this event.
- for (SmallVector<TimeTraceProfilerEntry, 128>::iterator it = Entries.begin(); it != Entries.end();) {
- if (TimeTraceEventType::InstantEvent == it->EventType &&
- it->Start > E.Start && it->Start < E.End)
- it = Entries.erase(it);
- else
- ++it;
- }
}
// Track total time taken by each "name", but only the topmost levels of
@@ -168,18 +296,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::shared_ptr<DurableEvent> &Val) {
+ return Val->Name == E->Name;
})) {
- auto &CountAndTotal = CountAndTotalPerName[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::shared_ptr<DurableEvent> &Val) {
+ return Val.get() == E.get();
+ });
}
// Write events from this TimeTraceProfilerInstance and
@@ -200,54 +327,13 @@ struct llvm::TimeTraceProfiler {
J.arrayBegin();
// Emit all events for the main flame graph.
- auto writeEvent = [&](const auto &E, uint64_t Tid) {
- auto StartUs = E.getFlameGraphStartUs(StartTime);
- auto DurUs = E.getFlameGraphDurUs();
-
- J.object([&] {
- J.attribute("pid", Pid);
- J.attribute("tid", int64_t(Tid));
- J.attribute("ts", StartUs);
- if (E.EventType == TimeTraceEventType::AsyncEvent) {
- J.attribute("cat", E.Name);
- J.attribute("ph", "b");
- J.attribute("id", 0);
- } 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()) {
- 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);
- });
- }
- });
-
- if (E.EventType == TimeTraceEventType::AsyncEvent) {
- J.object([&] {
- J.attribute("pid", Pid);
- J.attribute("tid", int64_t(Tid));
- J.attribute("ts", StartUs + DurUs);
- J.attribute("cat", E.Name);
- J.attribute("ph", "e");
- J.attribute("id", 0);
- J.attribute("name", E.Name);
- });
- }
- };
- for (const TimeTraceProfilerEntry &E : Entries)
- writeEvent(E, this->Tid);
+ for (const auto &E : Entries) {
+ E->writeEvent(J, Pid, this->Tid, StartTime);
+ }
for (const TimeTraceProfiler *TTP : Instances.List)
- for (const TimeTraceProfilerEntry &E : TTP->Entries)
- writeEvent(E, TTP->Tid);
+ for (const auto &E : TTP->Entries) {
+ E->writeEvent(J, Pid, TTP->Tid, StartTime);
+ }
// Emit totals by section name as additional "thread" events, sorted from
// longest one.
@@ -335,8 +421,8 @@ struct llvm::TimeTraceProfiler {
J.objectEnd();
}
- SmallVector<std::unique_ptr<TimeTraceProfilerEntry>, 16> Stack;
- SmallVector<TimeTraceProfilerEntry, 128> Entries;
+ SmallVector<std::shared_ptr<DurableEvent>, 16> Stack;
+ SmallVector<std::shared_ptr<DurableEvent>, 128> Entries;
StringMap<CountAndDurationType> CountAndTotalPerName;
// System clock time when the session was begun.
const time_point<system_clock> BeginningOfTime;
@@ -418,43 +504,47 @@ Error llvm::timeTraceProfilerWrite(StringRef PreferredFileName,
return Error::success();
}
-TimeTraceProfilerEntry *llvm::timeTraceProfilerBegin(StringRef Name,
- StringRef Detail) {
+std::shared_ptr<DurableEvent> llvm::timeTraceProfilerBegin(StringRef Name,
+ StringRef Detail) {
if (TimeTraceProfilerInstance != nullptr)
return TimeTraceProfilerInstance->begin(
- std::string(Name), [&]() { return std::string(Detail); }, TimeTraceEventType::CompleteEvent);
+ std::string(Name), [&]() { return std::string(Detail); }, false);
return nullptr;
}
-TimeTraceProfilerEntry *
+std::shared_ptr<DurableEvent>
llvm::timeTraceProfilerBegin(StringRef Name,
llvm::function_ref<std::string()> Detail) {
if (TimeTraceProfilerInstance != nullptr)
- return TimeTraceProfilerInstance->begin(std::string(Name), Detail, TimeTraceEventType::CompleteEvent);
+ return TimeTraceProfilerInstance->begin(std::string(Name), Detail, false);
return nullptr;
}
-TimeTraceProfilerEntry *
+std::shared_ptr<DurableEvent>
llvm::timeTraceProfilerBegin(StringRef Name,
llvm::function_ref<TimeTraceMetadata()> Metadata) {
if (TimeTraceProfilerInstance != nullptr)
- return TimeTraceProfilerInstance->begin(std::string(Name), Metadata, TimeTraceEventType::CompleteEvent);
+ return TimeTraceProfilerInstance->begin(std::string(Name), Metadata, false);
return nullptr;
}
-TimeTraceProfilerEntry *
-llvm::timeTraceInstantEventProfilerBegin(StringRef Name,
- llvm::function_ref<TimeTraceMetadata()> Metadata) {
+void llvm::timeTraceProfilerInsert(StringRef Name, StringRef Detail) {
if (TimeTraceProfilerInstance != nullptr)
- return TimeTraceProfilerInstance->begin(std::string(Name), Metadata, TimeTraceEventType::InstantEvent);
- return 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);
}
-TimeTraceProfilerEntry *llvm::timeTraceAsyncProfilerBegin(StringRef Name,
- StringRef Detail) {
+std::shared_ptr<DurableEvent>
+llvm::timeTraceAsyncProfilerBegin(StringRef Name, StringRef Detail) {
if (TimeTraceProfilerInstance != nullptr)
return TimeTraceProfilerInstance->begin(
- std::string(Name), [&]() { return std::string(Detail); }, TimeTraceEventType::AsyncEvent);
+ std::string(Name), [&]() { return std::string(Detail); }, true);
return nullptr;
}
@@ -463,7 +553,7 @@ void llvm::timeTraceProfilerEnd() {
TimeTraceProfilerInstance->end();
}
-void llvm::timeTraceProfilerEnd(TimeTraceProfilerEntry *E) {
+void llvm::timeTraceProfilerEnd(std::shared_ptr<DurableEvent> &E) {
if (TimeTraceProfilerInstance != nullptr)
- TimeTraceProfilerInstance->end(*E);
+ TimeTraceProfilerInstance->end(E);
}
diff --git a/llvm/unittests/Support/TimeProfilerTest.cpp b/llvm/unittests/Support/TimeProfilerTest.cpp
index bb820ec99a393e..250e0e4f4704b8 100644
--- a/llvm/unittests/Support/TimeProfilerTest.cpp
+++ b/llvm/unittests/Support/TimeProfilerTest.cpp
@@ -57,7 +57,7 @@ TEST(TimeProfiler, Begin_End_Smoke) {
TEST(TimeProfiler, Async_Begin_End_Smoke) {
setupProfiler();
- auto *Profiler = timeTraceAsyncProfilerBegin("event", "detail");
+ auto Profiler = timeTraceAsyncProfilerBegin("event", "detail");
timeTraceProfilerEnd(Profiler);
std::string json = teardownProfiler();
>From ce972c51b98fbfbcf08530db5db17675b79cf8a6 Mon Sep 17 00:00:00 2001
From: Ivana Ivanovska <iivanovska at google.com>
Date: Thu, 29 Aug 2024 12:17:01 +0000
Subject: [PATCH 3/6] Reverted refactoring. Implemented review comments.
---
clang/lib/Sema/Sema.cpp | 8 +-
llvm/include/llvm/Support/TimeProfiler.h | 24 +-
llvm/lib/Support/TimeProfiler.cpp | 316 ++++++++------------
llvm/unittests/Support/TimeProfilerTest.cpp | 2 +-
4 files changed, 145 insertions(+), 205 deletions(-)
diff --git a/clang/lib/Sema/Sema.cpp b/clang/lib/Sema/Sema.cpp
index d8305861bf21c6..29acd06af603be 100644
--- a/clang/lib/Sema/Sema.cpp
+++ b/clang/lib/Sema/Sema.cpp
@@ -160,7 +160,7 @@ namespace sema {
class SemaPPCallbacks : public PPCallbacks {
Sema *S = nullptr;
llvm::SmallVector<SourceLocation, 8> IncludeStack;
- llvm::SmallVector<std::shared_ptr<llvm::DurableEvent>, 8> ProfilerStack;
+ llvm::SmallVector<llvm::TimeTraceProfilerEntry *, 8> ProfilerStack;
public:
void set(Sema &S) { this->S = &S; }
@@ -192,10 +192,8 @@ class SemaPPCallbacks : public PPCallbacks {
}
case ExitFile:
if (!IncludeStack.empty()) {
- if (llvm::timeTraceProfilerEnabled()) {
- auto E = ProfilerStack.pop_back_val();
- llvm::timeTraceProfilerEnd(E);
- }
+ if (llvm::timeTraceProfilerEnabled())
+ llvm::timeTraceProfilerEnd(ProfilerStack.pop_back_val());
S->DiagnoseNonDefaultPragmaAlignPack(
Sema::PragmaAlignPackDiagnoseKind::ChangedStateAtExit,
diff --git a/llvm/include/llvm/Support/TimeProfiler.h b/llvm/include/llvm/Support/TimeProfiler.h
index 323d7c8c5f8c55..9a6bcdefee6c20 100644
--- a/llvm/include/llvm/Support/TimeProfiler.h
+++ b/llvm/include/llvm/Support/TimeProfiler.h
@@ -94,17 +94,13 @@ struct TimeTraceMetadata {
bool isEmpty() const { return Detail.empty() && File.empty(); }
};
-struct TimeTraceProfilerEntry;
-struct InstantEvent;
-struct DurableEvent;
-struct CompleteEvent;
-struct AsyncEvent;
-
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.
@@ -140,13 +136,13 @@ Error timeTraceProfilerWrite(StringRef PreferredFileName,
/// Profiler copies the string data, so the pointers can be given into
/// temporaries. Time sections can be hierarchical; every Begin must have a
/// matching End pair but they can nest.
-std::shared_ptr<DurableEvent> timeTraceProfilerBegin(StringRef Name,
- StringRef Detail);
-std::shared_ptr<DurableEvent>
+TimeTraceProfilerEntry *timeTraceProfilerBegin(StringRef Name,
+ StringRef Detail);
+TimeTraceProfilerEntry *
timeTraceProfilerBegin(StringRef Name,
llvm::function_ref<std::string()> Detail);
-std::shared_ptr<DurableEvent>
+TimeTraceProfilerEntry *
timeTraceProfilerBegin(StringRef Name,
llvm::function_ref<TimeTraceMetadata()> MetaData);
@@ -155,8 +151,8 @@ timeTraceProfilerBegin(StringRef Name,
/// separately from other traces. See
/// https://docs.google.com/document/d/1CvAClvFfyA5R-PhYUmn5OOQtYMH4h6I0nSsKchNAySU/preview#heading=h.jh64i9l3vwa1
/// for more details.
-std::shared_ptr<DurableEvent> timeTraceAsyncProfilerBegin(StringRef Name,
- StringRef Detail);
+TimeTraceProfilerEntry *timeTraceAsyncProfilerBegin(StringRef Name,
+ StringRef Detail);
// Mark an instant event.
void timeTraceProfilerInsert(StringRef Name,
@@ -165,7 +161,7 @@ void timeTraceProfilerInsert(StringRef Name, StringRef Detail);
/// Manually end the last time section.
void timeTraceProfilerEnd();
-void timeTraceProfilerEnd(std::shared_ptr<DurableEvent> &E);
+void timeTraceProfilerEnd(TimeTraceProfilerEntry *E);
/// The TimeTraceScope is a helper class to call the begin and end functions
/// of the time trace profiler. When the object is constructed, it begins
@@ -202,7 +198,7 @@ class TimeTraceScope {
}
private:
- std::shared_ptr<DurableEvent> Entry = nullptr;
+ TimeTraceProfilerEntry *Entry = nullptr;
};
} // end namespace llvm
diff --git a/llvm/lib/Support/TimeProfiler.cpp b/llvm/lib/Support/TimeProfiler.cpp
index ac0c1d89bb8176..31faa36c29f14d 100644
--- a/llvm/lib/Support/TimeProfiler.cpp
+++ b/llvm/lib/Support/TimeProfiler.cpp
@@ -69,20 +69,25 @@ using NameAndCountAndDurationType =
} // anonymous namespace
-/// Represents an entry to be captured.
+/// Represents an open or completed time section entry to be captured.
struct llvm::TimeTraceProfilerEntry {
const TimePointType Start;
+ TimePointType End;
const std::string Name;
TimeTraceMetadata Metadata;
- TimeTraceProfilerEntry(TimePointType &&S, std::string &&N, std::string &&Dt)
- : Start(std::move(S)), Name(std::move(N)), Metadata() {
+ TimeTraceEventType EventType;
+ TimeTraceProfilerEntry(TimePointType &&S, TimePointType &&E, std::string &&N,
+ std::string &&Dt, TimeTraceEventType Et)
+ : Start(std::move(S)), End(std::move(E)), Name(std::move(N)), Metadata(),
+ EventType(Et) {
Metadata.Detail = std::move(Dt);
}
- TimeTraceProfilerEntry(TimePointType &&S, std::string &&N,
- TimeTraceMetadata &&Mt)
- : Start(std::move(S)), Name(std::move(N)), Metadata(std::move(Mt)) {}
+ TimeTraceProfilerEntry(TimePointType &&S, TimePointType &&E, std::string &&N,
+ TimeTraceMetadata &&Mt, TimeTraceEventType Et)
+ : Start(std::move(S)), End(std::move(E)), Name(std::move(N)),
+ 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
@@ -93,128 +98,28 @@ struct llvm::TimeTraceProfilerEntry {
.count();
}
- virtual void writeEvent(json::OStream &J, sys::Process::Pid Pid, uint64_t Tid,
- TimePointType StartTime) const {
- J.object([&] {
- J.attribute("pid", Pid);
- J.attribute("tid", int64_t(Tid));
- J.attribute("ts", getFlameGraphStartUs(StartTime));
- writeAdditionalEventFileds(J);
- J.attribute("name", Name);
- if (!Metadata.isEmpty()) {
- J.attributeObject("args", [&] {
- if (!Metadata.Detail.empty())
- J.attribute("detail", Metadata.Detail);
- if (!Metadata.File.empty())
- J.attribute("file", Metadata.File);
- if (Metadata.Line > 0)
- J.attribute("line", Metadata.Line);
- });
- }
- });
- }
-
- virtual void writeAdditionalEventFileds(json::OStream &J) const {}
-
- virtual ~TimeTraceProfilerEntry() = default;
-};
-
-struct llvm::InstantEvent : llvm::TimeTraceProfilerEntry {
- InstantEvent(TimePointType &&S, std::string &&N, std::string &&Dt)
- : TimeTraceProfilerEntry(std::move(S), std::move(N), std::move(Dt)) {}
-
- InstantEvent(TimePointType &&S, std::string &&N, TimeTraceMetadata &&Mt)
- : TimeTraceProfilerEntry(std::move(S), std::move(N), std::move(Mt)) {}
-
- void writeAdditionalEventFileds(json::OStream &J) const override {
- J.attribute("ph", "i");
- }
-};
-
-struct llvm::DurableEvent : llvm::TimeTraceProfilerEntry {
- DurableEvent(TimePointType &&S, TimePointType &&E, std::string &&N,
- std::string &&Dt)
- : TimeTraceProfilerEntry(std::move(S), std::move(N), std::move(Dt)),
- InstantEvents{}, End(std::move(E)) {}
-
- DurableEvent(TimePointType &&S, TimePointType &&E, std::string &&N,
- TimeTraceMetadata &&Mt)
- : TimeTraceProfilerEntry(std::move(S), std::move(N), std::move(Mt)),
- InstantEvents{}, End(std::move(E)) {}
-
- virtual void writeEvent(json::OStream &J, sys::Process::Pid Pid, uint64_t Tid,
- TimePointType StartTime) const override {
- TimeTraceProfilerEntry::writeEvent(J, Pid, Tid, StartTime);
- writeInstantEvents(J, Pid, Tid, StartTime);
- }
-
- void writeInstantEvents(json::OStream &J, sys::Process::Pid Pid, uint64_t Tid,
- TimePointType StartTime) const {
- for (auto IE : InstantEvents) {
- IE->writeEvent(J, Pid, Tid, StartTime);
- }
- }
-
- virtual void writeAdditionalEventFileds(json::OStream &J) const override {}
-
ClockType::rep getFlameGraphDurUs() const {
return (time_point_cast<microseconds>(End) -
time_point_cast<microseconds>(Start))
.count();
}
-
- std::vector<std::shared_ptr<InstantEvent>> InstantEvents;
- TimePointType End;
};
-struct llvm::CompleteEvent : llvm::DurableEvent {
- CompleteEvent(TimePointType &&S, TimePointType &&E, std::string &&N,
- std::string &&Dt)
- : DurableEvent(std::move(S), std::move(E), std::move(N), std::move(Dt)) {}
-
- CompleteEvent(TimePointType &&S, TimePointType &&E, std::string &&N,
- TimeTraceMetadata &&Mt)
- : DurableEvent(std::move(S), std::move(E), std::move(N), std::move(Mt)) {}
-
- virtual void writeAdditionalEventFileds(json::OStream &J) const override {
- J.attribute("ph", "X");
- J.attribute("dur", getFlameGraphDurUs());
- }
-};
-
-struct llvm::AsyncEvent : llvm::DurableEvent {
- AsyncEvent(TimePointType &&S, TimePointType &&E, std::string &&N,
- std::string &&Dt)
- : DurableEvent(std::move(S), std::move(E), std::move(N), std::move(Dt)) {}
-
- AsyncEvent(TimePointType &&S, TimePointType &&E, std::string &&N,
- TimeTraceMetadata &&Mt)
- : DurableEvent(std::move(S), std::move(E), std::move(N), std::move(Mt)) {}
-
- void writeEvent(json::OStream &J, sys::Process::Pid Pid, uint64_t Tid,
- TimePointType StartTime) const override {
- DurableEvent::writeEvent(J, Pid, Tid, StartTime);
- writeEndEvent(J, Pid, Tid, StartTime);
- }
-
- void writeEndEvent(json::OStream &J, sys::Process::Pid Pid, uint64_t Tid,
- TimePointType StartTime) const {
- J.object([&] {
- J.attribute("pid", Pid);
- J.attribute("tid", int64_t(Tid));
- J.attribute("ts", getFlameGraphStartUs(StartTime) + getFlameGraphDurUs());
- J.attribute("cat", Name);
- J.attribute("ph", "e");
- J.attribute("id", 0);
- J.attribute("name", Name);
- });
- }
-
- void writeAdditionalEventFileds(json::OStream &J) const override {
- J.attribute("cat", Name);
- J.attribute("ph", "b");
- J.attribute("id", 0);
- }
+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 {
@@ -226,40 +131,32 @@ struct llvm::TimeTraceProfiler {
TimeTraceVerbose(TimeTraceVerbose) {
llvm::get_thread_name(ThreadName);
}
- std::shared_ptr<DurableEvent> begin(std::string Name,
- llvm::function_ref<std::string()> Detail,
- bool AsyncEventType) {
- if (AsyncEventType) {
- Stack.emplace_back(std::make_shared<AsyncEvent>(
- ClockType::now(), TimePointType(), std::move(Name), Detail()));
- } else {
- Stack.emplace_back(std::make_shared<CompleteEvent>(
- ClockType::now(), TimePointType(), std::move(Name), Detail()));
- }
- return Stack.back();
+
+ 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(),
+ EventType));
+ return Stack.back()->Event.get();
}
- std::shared_ptr<DurableEvent>
+ TimeTraceProfilerEntry *
begin(std::string Name, llvm::function_ref<TimeTraceMetadata()> Metadata,
- bool AsyncEventType) {
-
- if (AsyncEventType) {
- Stack.emplace_back(std::make_shared<AsyncEvent>(
- ClockType::now(), TimePointType(), std::move(Name), Metadata()));
- } else {
- Stack.emplace_back(std::make_shared<CompleteEvent>(
- ClockType::now(), TimePointType(), std::move(Name), Metadata()));
- }
- return Stack.back();
+ 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(
- std::make_shared<InstantEvent>(ClockType::now(), std::move(Name),
- Detail()));
+ Stack.back().get()->InstantEvents.emplace_back(TimeTraceProfilerEntry(
+ ClockType::now(), TimePointType(), std::move(Name), Detail(),
+ TimeTraceEventType::InstantEvent));
}
void insert(std::string Name,
@@ -267,27 +164,31 @@ struct llvm::TimeTraceProfiler {
if (Stack.empty())
return;
- Stack.back().get()->InstantEvents.emplace_back(
- std::make_shared<InstantEvent>(ClockType::now(), std::move(Name),
- Metadata()));
+ Stack.back().get()->InstantEvents.emplace_back(TimeTraceProfilerEntry(
+ ClockType::now(), TimePointType(), std::move(Name), Metadata(),
+ TimeTraceEventType::InstantEvent));
}
void end() {
assert(!Stack.empty() && "Must call begin() first");
- end(Stack.back());
+ end(*Stack.back()->Event);
}
- void end(std::shared_ptr<DurableEvent> &E) {
+ void end(TimeTraceProfilerEntry &E) {
assert(!Stack.empty() && "Must call begin() first");
- E->End = ClockType::now();
+ E.End = ClockType::now();
// Calculate duration at full precision for overall counts.
- DurationType Duration = E->End - E->Start;
+ DurationType Duration = E.End - E.Start;
- // Only include events with a duration longer or equal to
- // TimeTraceGranularity msec.
+ // Only include sections longer or equal to TimeTraceGranularity msec.
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
@@ -296,16 +197,16 @@ 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::shared_ptr<DurableEvent> &Val) {
- return Val->Name == E->Name;
+ [&](const std::unique_ptr<InProgressEntry> &Val) {
+ return Val->Event->Name == E.Name;
})) {
- auto &CountAndTotal = CountAndTotalPerName[E->Name];
+ auto &CountAndTotal = CountAndTotalPerName[E.Name];
CountAndTotal.first++;
CountAndTotal.second += Duration;
};
- llvm::erase_if(Stack, [&](const std::shared_ptr<DurableEvent> &Val) {
- return Val.get() == E.get();
+ llvm::erase_if(Stack, [&](const std::unique_ptr<InProgressEntry> &Val) {
+ return Val->Event.get() == &E;
});
}
@@ -327,13 +228,54 @@ struct llvm::TimeTraceProfiler {
J.arrayBegin();
// Emit all events for the main flame graph.
- for (const auto &E : Entries) {
- E->writeEvent(J, Pid, this->Tid, StartTime);
- }
- for (const TimeTraceProfiler *TTP : Instances.List)
- for (const auto &E : TTP->Entries) {
- E->writeEvent(J, Pid, TTP->Tid, StartTime);
+ auto writeEvent = [&](const auto &E, uint64_t Tid) {
+ auto StartUs = E.getFlameGraphStartUs(StartTime);
+ auto DurUs = E.getFlameGraphDurUs();
+
+ J.object([&] {
+ J.attribute("pid", Pid);
+ J.attribute("tid", int64_t(Tid));
+ J.attribute("ts", StartUs);
+ if (TimeTraceEventType::AsyncEvent == E.EventType) {
+ J.attribute("cat", E.Name);
+ J.attribute("ph", "b");
+ J.attribute("id", 0);
+ } 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()) {
+ 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);
+ });
+ }
+ });
+
+ if (TimeTraceEventType::AsyncEvent == E.EventType) {
+ J.object([&] {
+ J.attribute("pid", Pid);
+ J.attribute("tid", int64_t(Tid));
+ J.attribute("ts", StartUs + DurUs);
+ J.attribute("cat", E.Name);
+ J.attribute("ph", "e");
+ J.attribute("id", 0);
+ J.attribute("name", E.Name);
+ });
}
+ };
+ for (const TimeTraceProfilerEntry &E : Entries)
+ writeEvent(E, this->Tid);
+ for (const TimeTraceProfiler *TTP : Instances.List)
+ for (const TimeTraceProfilerEntry &E : TTP->Entries)
+ writeEvent(E, TTP->Tid);
// Emit totals by section name as additional "thread" events, sorted from
// longest one.
@@ -421,8 +363,8 @@ struct llvm::TimeTraceProfiler {
J.objectEnd();
}
- SmallVector<std::shared_ptr<DurableEvent>, 16> Stack;
- SmallVector<std::shared_ptr<DurableEvent>, 128> Entries;
+ SmallVector<std::unique_ptr<InProgressEntry>, 16> Stack;
+ SmallVector<TimeTraceProfilerEntry, 128> Entries;
StringMap<CountAndDurationType> CountAndTotalPerName;
// System clock time when the session was begun.
const time_point<system_clock> BeginningOfTime;
@@ -504,27 +446,39 @@ Error llvm::timeTraceProfilerWrite(StringRef PreferredFileName,
return Error::success();
}
-std::shared_ptr<DurableEvent> llvm::timeTraceProfilerBegin(StringRef Name,
- StringRef Detail) {
+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;
}
-std::shared_ptr<DurableEvent>
+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;
}
-std::shared_ptr<DurableEvent>
+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;
+}
+
+TimeTraceProfilerEntry *llvm::timeTraceAsyncProfilerBegin(StringRef Name,
+ StringRef Detail) {
+ if (TimeTraceProfilerInstance != nullptr)
+ return TimeTraceProfilerInstance->begin(
+ std::string(Name), [&]() { return std::string(Detail); },
+ TimeTraceEventType::AsyncEvent);
return nullptr;
}
@@ -540,20 +494,12 @@ void llvm::timeTraceProfilerInsert(
TimeTraceProfilerInstance->insert(std::string(Name), Metadata);
}
-std::shared_ptr<DurableEvent>
-llvm::timeTraceAsyncProfilerBegin(StringRef Name, StringRef Detail) {
- if (TimeTraceProfilerInstance != nullptr)
- return TimeTraceProfilerInstance->begin(
- std::string(Name), [&]() { return std::string(Detail); }, true);
- return nullptr;
-}
-
void llvm::timeTraceProfilerEnd() {
if (TimeTraceProfilerInstance != nullptr)
TimeTraceProfilerInstance->end();
}
-void llvm::timeTraceProfilerEnd(std::shared_ptr<DurableEvent> &E) {
+void llvm::timeTraceProfilerEnd(TimeTraceProfilerEntry *E) {
if (TimeTraceProfilerInstance != nullptr)
- TimeTraceProfilerInstance->end(E);
+ TimeTraceProfilerInstance->end(*E);
}
diff --git a/llvm/unittests/Support/TimeProfilerTest.cpp b/llvm/unittests/Support/TimeProfilerTest.cpp
index 250e0e4f4704b8..bb820ec99a393e 100644
--- a/llvm/unittests/Support/TimeProfilerTest.cpp
+++ b/llvm/unittests/Support/TimeProfilerTest.cpp
@@ -57,7 +57,7 @@ TEST(TimeProfiler, Begin_End_Smoke) {
TEST(TimeProfiler, Async_Begin_End_Smoke) {
setupProfiler();
- auto Profiler = timeTraceAsyncProfilerBegin("event", "detail");
+ auto *Profiler = timeTraceAsyncProfilerBegin("event", "detail");
timeTraceProfilerEnd(Profiler);
std::string json = teardownProfiler();
>From 475f1c2e4de3c42387df6b09d7d498ef97210dbf Mon Sep 17 00:00:00 2001
From: Ivana Ivanovska <iivanovska at google.com>
Date: Fri, 30 Aug 2024 12:38:09 +0000
Subject: [PATCH 4/6] Applied review comments.
---
clang/lib/Sema/SemaExpr.cpp | 21 +++---
.../lib/Sema/SemaTemplateInstantiateDecl.cpp | 21 +++---
clang/unittests/Support/TimeProfilerTest.cpp | 8 +--
llvm/include/llvm/Support/TimeProfiler.h | 18 ++++--
llvm/lib/Support/TimeProfiler.cpp | 64 +++++++++----------
5 files changed, 65 insertions(+), 67 deletions(-)
diff --git a/clang/lib/Sema/SemaExpr.cpp b/clang/lib/Sema/SemaExpr.cpp
index a7dd01c936bac8..d6ec07954e88a5 100644
--- a/clang/lib/Sema/SemaExpr.cpp
+++ b/clang/lib/Sema/SemaExpr.cpp
@@ -18049,18 +18049,15 @@ void Sema::MarkFunctionReferenced(SourceLocation Loc, FunctionDecl *Func,
// 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;
- });
+ if (llvm::isTimeTraceVerbose()) {
+ llvm::timeTraceInstantEvent("DeferInstantiation", [&] {
+ std::string Name;
+ llvm::raw_string_ostream OS(Name);
+ Func->getNameForDiagnostic(OS, getPrintingPolicy(),
+ /*Qualified=*/true);
+ return Name;
+ });
+ }
}
}
} else {
diff --git a/clang/lib/Sema/SemaTemplateInstantiateDecl.cpp b/clang/lib/Sema/SemaTemplateInstantiateDecl.cpp
index 550add5495c833..946cac74d83754 100644
--- a/clang/lib/Sema/SemaTemplateInstantiateDecl.cpp
+++ b/clang/lib/Sema/SemaTemplateInstantiateDecl.cpp
@@ -4984,18 +4984,15 @@ void Sema::InstantiateFunctionDefinition(SourceLocation PointOfInstantiation,
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;
- });
+ if (llvm::isTimeTraceVerbose()) {
+ llvm::timeTraceInstantEvent("DeferInstantiation", [&] {
+ std::string Name;
+ llvm::raw_string_ostream OS(Name);
+ Function->getNameForDiagnostic(OS, getPrintingPolicy(),
+ /*Qualified=*/true);
+ return Name;
+ });
+ }
} 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 ccda12e943dd73..339b470153e64e 100644
--- a/clang/unittests/Support/TimeProfilerTest.cpp
+++ b/clang/unittests/Support/TimeProfilerTest.cpp
@@ -268,7 +268,7 @@ Frontend (test.cc)
| | ParseFunctionDefinition (user)
| | | InstantiateClass (S<int>, test.cc:3)
| | | InstantiateClass (S<float>, test.cc:3)
-| | | DeferInstantiation (S<float>::foo, test.cc:5)
+| | | DeferInstantiation (S<float>::foo)
| PerformPendingInstantiations
| | InstantiateFunction (S<float>::foo, test.cc:5)
)",
@@ -315,12 +315,12 @@ Frontend (test.cc)
| ParseFunctionDefinition (fooA)
| ParseDeclarationOrFunctionDefinition (test.cc:3:5)
| | ParseFunctionDefinition (user)
-| | | DeferInstantiation (fooA<int>, a.h:7)
+| | | DeferInstantiation (fooA<int>)
| PerformPendingInstantiations
| | InstantiateFunction (fooA<int>, a.h:7)
| | | InstantiateFunction (fooB<int>, b.h:8)
-| | | | DeferInstantiation (fooC<int>, b.h:3)
-| | | DeferInstantiation (fooMTA<int>, a.h:4)
+| | | | DeferInstantiation (fooC<int>)
+| | | DeferInstantiation (fooMTA<int>)
| | | InstantiateFunction (fooC<int>, b.h:3)
| | | InstantiateFunction (fooMTA<int>, a.h:4)
)",
diff --git a/llvm/include/llvm/Support/TimeProfiler.h b/llvm/include/llvm/Support/TimeProfiler.h
index 9a6bcdefee6c20..67d792a8ec6574 100644
--- a/llvm/include/llvm/Support/TimeProfiler.h
+++ b/llvm/include/llvm/Support/TimeProfiler.h
@@ -83,7 +83,18 @@ namespace llvm {
class raw_pwrite_stream;
-enum class TimeTraceEventType { CompleteEvent, InstantEvent, AsyncEvent };
+// Type of the time trace event.
+enum class TimeTraceEventType {
+ // Complete events have a duration (start and end time points) and are marked
+ // by the "X" phase type.
+ CompleteEvent,
+ // Instant events don't have a duration, they happen at an instant in time.
+ // They are marked with "i" phase type. The field End is ignored for them.
+ InstantEvent,
+ // Async events mark asynchronous operations and are specified by the "b"
+ // (start) and "e" (end) phase types.
+ AsyncEvent
+};
struct TimeTraceMetadata {
std::string Detail;
@@ -155,9 +166,8 @@ 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);
+void timeTraceInstantEvent(StringRef Name,
+ llvm::function_ref<std::string()> Detail);
/// Manually end the last time section.
void timeTraceProfilerEnd();
diff --git a/llvm/lib/Support/TimeProfiler.cpp b/llvm/lib/Support/TimeProfiler.cpp
index 31faa36c29f14d..29afc80be5cbdd 100644
--- a/llvm/lib/Support/TimeProfiler.cpp
+++ b/llvm/lib/Support/TimeProfiler.cpp
@@ -76,7 +76,7 @@ struct llvm::TimeTraceProfilerEntry {
const std::string Name;
TimeTraceMetadata Metadata;
- TimeTraceEventType EventType;
+ const TimeTraceEventType EventType = TimeTraceEventType::CompleteEvent;
TimeTraceProfilerEntry(TimePointType &&S, TimePointType &&E, std::string &&N,
std::string &&Dt, TimeTraceEventType Et)
: Start(std::move(S)), End(std::move(E)), Name(std::move(N)), Metadata(),
@@ -105,20 +105,22 @@ struct llvm::TimeTraceProfilerEntry {
}
};
+// Represents a currently open (in-progress) time trace entry. InstantEvents
+// that happen during an open event are associated with the duration of this
+// parent event and they are dropped if parent duration is shorter than
+// the granularity.
struct InProgressEntry {
- std::unique_ptr<TimeTraceProfilerEntry> Event;
+ 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)),
+ InProgressEntry(TimePointType S, TimePointType E, std::string N,
+ std::string Dt, TimeTraceEventType Et)
+ : Event(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)),
+ InProgressEntry(TimePointType S, TimePointType E, std::string N,
+ TimeTraceMetadata Mt, TimeTraceEventType Et)
+ : Event(std::move(S), std::move(E), std::move(N), std::move(Mt), Et),
InstantEvents() {}
};
@@ -135,19 +137,25 @@ struct llvm::TimeTraceProfiler {
TimeTraceProfilerEntry *
begin(std::string Name, llvm::function_ref<std::string()> Detail,
TimeTraceEventType EventType = TimeTraceEventType::CompleteEvent) {
+ assert(EventType != TimeTraceEventType::InstantEvent &&
+ "Instant Events don't have begin and end, they can only be "
+ "instantiated once");
Stack.emplace_back(std::make_unique<InProgressEntry>(
ClockType::now(), TimePointType(), std::move(Name), Detail(),
EventType));
- return Stack.back()->Event.get();
+ return &Stack.back()->Event;
}
TimeTraceProfilerEntry *
begin(std::string Name, llvm::function_ref<TimeTraceMetadata()> Metadata,
TimeTraceEventType EventType = TimeTraceEventType::CompleteEvent) {
+ assert(EventType != TimeTraceEventType::InstantEvent &&
+ "Instant Events don't have begin and end, they can only be "
+ "instantiated once.");
Stack.emplace_back(std::make_unique<InProgressEntry>(
ClockType::now(), TimePointType(), std::move(Name), Metadata(),
EventType));
- return Stack.back()->Event.get();
+ return &Stack.back()->Event;
}
void insert(std::string Name, llvm::function_ref<std::string()> Detail) {
@@ -159,19 +167,9 @@ struct llvm::TimeTraceProfiler {
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(),
- TimeTraceEventType::InstantEvent));
- }
-
void end() {
assert(!Stack.empty() && "Must call begin() first");
- end(*Stack.back()->Event);
+ end(Stack.back()->Event);
}
void end(TimeTraceProfilerEntry &E) {
@@ -184,7 +182,7 @@ struct llvm::TimeTraceProfiler {
// Only include sections longer or equal to TimeTraceGranularity msec.
if (duration_cast<microseconds>(Duration).count() >= TimeTraceGranularity) {
Entries.emplace_back(E);
- if (Stack.back()->Event.get() == &E) {
+ if (&Stack.back()->Event == &E) {
for (auto &IE : Stack.back()->InstantEvents) {
Entries.emplace_back(IE);
}
@@ -198,7 +196,7 @@ struct llvm::TimeTraceProfiler {
// itself.
if (llvm::none_of(llvm::drop_begin(llvm::reverse(Stack)),
[&](const std::unique_ptr<InProgressEntry> &Val) {
- return Val->Event->Name == E.Name;
+ return Val->Event.Name == E.Name;
})) {
auto &CountAndTotal = CountAndTotalPerName[E.Name];
CountAndTotal.first++;
@@ -206,7 +204,7 @@ struct llvm::TimeTraceProfiler {
};
llvm::erase_if(Stack, [&](const std::unique_ptr<InProgressEntry> &Val) {
- return Val->Event.get() == &E;
+ return &Val->Event == &E;
});
}
@@ -244,6 +242,8 @@ struct llvm::TimeTraceProfiler {
J.attribute("ph", "X");
J.attribute("dur", DurUs);
} else { // instant event
+ assert(E.EventType == TimeTraceEventType::InstantEvent &&
+ "InstantEvent expected");
J.attribute("ph", "i");
}
J.attribute("name", E.Name);
@@ -482,16 +482,10 @@ TimeTraceProfilerEntry *llvm::timeTraceAsyncProfilerBegin(StringRef Name,
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) {
+void llvm::timeTraceInstantEvent(StringRef Name,
+ llvm::function_ref<std::string()> Detail) {
if (TimeTraceProfilerInstance != nullptr)
- TimeTraceProfilerInstance->insert(std::string(Name), Metadata);
+ TimeTraceProfilerInstance->insert(std::string(Name), Detail);
}
void llvm::timeTraceProfilerEnd() {
>From 9291d17268c6d59aa7f64e3782b3e8bf86760edc Mon Sep 17 00:00:00 2001
From: Ivana Ivanovska <iivanovska at google.com>
Date: Mon, 7 Oct 2024 09:06:34 +0000
Subject: [PATCH 5/6] Applied review comments, changed looking for the specific
event in the Stack.
---
llvm/lib/Support/TimeProfiler.cpp | 24 ++++++++++++------------
1 file changed, 12 insertions(+), 12 deletions(-)
diff --git a/llvm/lib/Support/TimeProfiler.cpp b/llvm/lib/Support/TimeProfiler.cpp
index 29afc80be5cbdd..ded591b1fdb93a 100644
--- a/llvm/lib/Support/TimeProfiler.cpp
+++ b/llvm/lib/Support/TimeProfiler.cpp
@@ -138,8 +138,7 @@ struct llvm::TimeTraceProfiler {
begin(std::string Name, llvm::function_ref<std::string()> Detail,
TimeTraceEventType EventType = TimeTraceEventType::CompleteEvent) {
assert(EventType != TimeTraceEventType::InstantEvent &&
- "Instant Events don't have begin and end, they can only be "
- "instantiated once");
+ "Instant Events don't have begin and end.");
Stack.emplace_back(std::make_unique<InProgressEntry>(
ClockType::now(), TimePointType(), std::move(Name), Detail(),
EventType));
@@ -150,8 +149,7 @@ struct llvm::TimeTraceProfiler {
begin(std::string Name, llvm::function_ref<TimeTraceMetadata()> Metadata,
TimeTraceEventType EventType = TimeTraceEventType::CompleteEvent) {
assert(EventType != TimeTraceEventType::InstantEvent &&
- "Instant Events don't have begin and end, they can only be "
- "instantiated once.");
+ "Instant Events don't have begin and end.");
Stack.emplace_back(std::make_unique<InProgressEntry>(
ClockType::now(), TimePointType(), std::move(Name), Metadata(),
EventType));
@@ -179,13 +177,17 @@ struct llvm::TimeTraceProfiler {
// Calculate duration at full precision for overall counts.
DurationType Duration = E.End - E.Start;
+ const auto *Iter =
+ llvm::find_if(Stack, [&](const std::unique_ptr<InProgressEntry> &Val) {
+ return &Val->Event == &E;
+ });
+ assert(Iter != Stack.end() && "Event not in the Stack");
+
// Only include sections longer or equal to TimeTraceGranularity msec.
if (duration_cast<microseconds>(Duration).count() >= TimeTraceGranularity) {
Entries.emplace_back(E);
- if (&Stack.back()->Event == &E) {
- for (auto &IE : Stack.back()->InstantEvents) {
- Entries.emplace_back(IE);
- }
+ for (auto &IE : Iter->get()->InstantEvents) {
+ Entries.emplace_back(IE);
}
}
@@ -203,9 +205,7 @@ struct llvm::TimeTraceProfiler {
CountAndTotal.second += Duration;
};
- llvm::erase_if(Stack, [&](const std::unique_ptr<InProgressEntry> &Val) {
- return &Val->Event == &E;
- });
+ Stack.erase(Iter);
}
// Write events from this TimeTraceProfilerInstance and
@@ -234,7 +234,7 @@ struct llvm::TimeTraceProfiler {
J.attribute("pid", Pid);
J.attribute("tid", int64_t(Tid));
J.attribute("ts", StartUs);
- if (TimeTraceEventType::AsyncEvent == E.EventType) {
+ if (E.EventType == TimeTraceEventType::AsyncEvent) {
J.attribute("cat", E.Name);
J.attribute("ph", "b");
J.attribute("id", 0);
>From a28003b0de9f185cd8cc9428b3037635b6d40405 Mon Sep 17 00:00:00 2001
From: Ivana Ivanovska <iivanovska at google.com>
Date: Mon, 7 Oct 2024 12:29:52 +0000
Subject: [PATCH 6/6] Renamed `timeTraceInstantEvent` into
`timeTraceAddInstantEvent`
---
clang/lib/Sema/SemaExpr.cpp | 2 +-
clang/lib/Sema/SemaTemplateInstantiateDecl.cpp | 2 +-
llvm/include/llvm/Support/TimeProfiler.h | 4 ++--
llvm/lib/Support/TimeProfiler.cpp | 4 ++--
4 files changed, 6 insertions(+), 6 deletions(-)
diff --git a/clang/lib/Sema/SemaExpr.cpp b/clang/lib/Sema/SemaExpr.cpp
index d6ec07954e88a5..6589bf7ebf37e2 100644
--- a/clang/lib/Sema/SemaExpr.cpp
+++ b/clang/lib/Sema/SemaExpr.cpp
@@ -18050,7 +18050,7 @@ void Sema::MarkFunctionReferenced(SourceLocation Loc, FunctionDecl *Func,
Consumer.HandleCXXImplicitFunctionInstantiation(Func);
if (llvm::isTimeTraceVerbose()) {
- llvm::timeTraceInstantEvent("DeferInstantiation", [&] {
+ llvm::timeTraceAddInstantEvent("DeferInstantiation", [&] {
std::string Name;
llvm::raw_string_ostream OS(Name);
Func->getNameForDiagnostic(OS, getPrintingPolicy(),
diff --git a/clang/lib/Sema/SemaTemplateInstantiateDecl.cpp b/clang/lib/Sema/SemaTemplateInstantiateDecl.cpp
index 946cac74d83754..846a86dd53ca5c 100644
--- a/clang/lib/Sema/SemaTemplateInstantiateDecl.cpp
+++ b/clang/lib/Sema/SemaTemplateInstantiateDecl.cpp
@@ -4985,7 +4985,7 @@ void Sema::InstantiateFunctionDefinition(SourceLocation PointOfInstantiation,
std::make_pair(Function, PointOfInstantiation));
if (llvm::isTimeTraceVerbose()) {
- llvm::timeTraceInstantEvent("DeferInstantiation", [&] {
+ llvm::timeTraceAddInstantEvent("DeferInstantiation", [&] {
std::string Name;
llvm::raw_string_ostream OS(Name);
Function->getNameForDiagnostic(OS, getPrintingPolicy(),
diff --git a/llvm/include/llvm/Support/TimeProfiler.h b/llvm/include/llvm/Support/TimeProfiler.h
index 67d792a8ec6574..8c0ecf9b7c911f 100644
--- a/llvm/include/llvm/Support/TimeProfiler.h
+++ b/llvm/include/llvm/Support/TimeProfiler.h
@@ -166,8 +166,8 @@ TimeTraceProfilerEntry *timeTraceAsyncProfilerBegin(StringRef Name,
StringRef Detail);
// Mark an instant event.
-void timeTraceInstantEvent(StringRef Name,
- llvm::function_ref<std::string()> Detail);
+void timeTraceAddInstantEvent(StringRef Name,
+ llvm::function_ref<std::string()> Detail);
/// Manually end the last time section.
void timeTraceProfilerEnd();
diff --git a/llvm/lib/Support/TimeProfiler.cpp b/llvm/lib/Support/TimeProfiler.cpp
index ded591b1fdb93a..70483eb51396fb 100644
--- a/llvm/lib/Support/TimeProfiler.cpp
+++ b/llvm/lib/Support/TimeProfiler.cpp
@@ -482,8 +482,8 @@ TimeTraceProfilerEntry *llvm::timeTraceAsyncProfilerBegin(StringRef Name,
return nullptr;
}
-void llvm::timeTraceInstantEvent(StringRef Name,
- llvm::function_ref<std::string()> Detail) {
+void llvm::timeTraceAddInstantEvent(StringRef Name,
+ llvm::function_ref<std::string()> Detail) {
if (TimeTraceProfilerInstance != nullptr)
TimeTraceProfilerInstance->insert(std::string(Name), Detail);
}
More information about the llvm-commits
mailing list