Skip to content

Commit 6d3e447

Browse files
Added instant events and marking defered templated instantiation.
1 parent f4e7e5d commit 6d3e447

File tree

5 files changed

+145
-24
lines changed

5 files changed

+145
-24
lines changed

clang/lib/Sema/SemaExpr.cpp

Lines changed: 18 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -18,6 +18,7 @@
1818
#include "clang/AST/ASTLambda.h"
1919
#include "clang/AST/ASTMutationListener.h"
2020
#include "clang/AST/CXXInheritance.h"
21+
#include "clang/AST/Decl.h"
2122
#include "clang/AST/DeclObjC.h"
2223
#include "clang/AST/DeclTemplate.h"
2324
#include "clang/AST/EvaluatedExprVisitor.h"
@@ -64,6 +65,7 @@
6465
#include "llvm/Support/Casting.h"
6566
#include "llvm/Support/ConvertUTF.h"
6667
#include "llvm/Support/SaveAndRestore.h"
68+
#include "llvm/Support/TimeProfiler.h"
6769
#include "llvm/Support/TypeSize.h"
6870
#include <optional>
6971

@@ -18046,6 +18048,22 @@ void Sema::MarkFunctionReferenced(SourceLocation Loc, FunctionDecl *Func,
1804618048
std::make_pair(Func, PointOfInstantiation));
1804718049
// Notify the consumer that a function was implicitly instantiated.
1804818050
Consumer.HandleCXXImplicitFunctionInstantiation(Func);
18051+
18052+
llvm::TimeTraceScope TimeScope(
18053+
"DeferInstantiation",
18054+
[&]() {
18055+
llvm::TimeTraceMetadata M;
18056+
llvm::raw_string_ostream OS(M.Detail);
18057+
Func->getNameForDiagnostic(OS, getPrintingPolicy(),
18058+
/*Qualified=*/true);
18059+
if (llvm::isTimeTraceVerbose()) {
18060+
auto Loc = SourceMgr.getExpansionLoc(Func->getLocation());
18061+
M.File = SourceMgr.getFilename(Loc);
18062+
M.Line = SourceMgr.getExpansionLineNumber(Loc);
18063+
}
18064+
return M;
18065+
},
18066+
llvm::TimeTraceEventType::InstantEvent);
1804918067
}
1805018068
}
1805118069
} else {

clang/lib/Sema/SemaTemplateInstantiateDecl.cpp

Lines changed: 17 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -4983,6 +4983,23 @@ void Sema::InstantiateFunctionDefinition(SourceLocation PointOfInstantiation,
49834983
Function->setInstantiationIsPending(true);
49844984
PendingInstantiations.push_back(
49854985
std::make_pair(Function, PointOfInstantiation));
4986+
4987+
llvm::TimeTraceScope TimeScope(
4988+
"DeferInstantiation",
4989+
[&]() {
4990+
llvm::TimeTraceMetadata M;
4991+
llvm::raw_string_ostream OS(M.Detail);
4992+
Function->getNameForDiagnostic(OS, getPrintingPolicy(),
4993+
/*Qualified=*/true);
4994+
if (llvm::isTimeTraceVerbose()) {
4995+
auto Loc = SourceMgr.getExpansionLoc(Function->getLocation());
4996+
M.File = SourceMgr.getFilename(Loc);
4997+
M.Line = SourceMgr.getExpansionLineNumber(Loc);
4998+
}
4999+
return M;
5000+
},
5001+
llvm::TimeTraceEventType::InstantEvent);
5002+
49865003
} else if (TSK == TSK_ImplicitInstantiation) {
49875004
if (AtEndOfTU && !getDiagnostics().hasErrorOccurred() &&
49885005
!getSourceManager().isInSystemHeader(PatternDecl->getBeginLoc())) {

clang/unittests/Support/TimeProfilerTest.cpp

Lines changed: 49 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -238,13 +238,55 @@ Frontend (test.cc)
238238
buildTraceGraph(Json));
239239
}
240240

241+
TEST(TimeProfilerTest, ClassTemplateInstantiations) {
242+
std::string Code = R"(
243+
template<class T>
244+
struct S
245+
{
246+
void foo() {}
247+
void bar();
248+
};
249+
250+
template struct S<double>; // explicit instantiation of S<double>
251+
252+
void user() {
253+
S<int> a; // implicit instantiation of S<int>
254+
S<float>* b;
255+
b->foo(); // implicit instatiation of S<float> and S<float>::foo()
256+
}
257+
)";
258+
259+
setupProfiler();
260+
ASSERT_TRUE(compileFromString(Code, "-std=c++20", "test.cc"));
261+
std::string Json = teardownProfiler();
262+
ASSERT_EQ(R"(
263+
Frontend (test.cc)
264+
| ParseClass (S)
265+
| InstantiateClass (S<double>, test.cc:9)
266+
| InstantiateFunction (S<double>::foo, test.cc:5)
267+
| ParseDeclarationOrFunctionDefinition (test.cc:11:5)
268+
| | ParseFunctionDefinition (user)
269+
| | | InstantiateClass (S<int>, test.cc:3)
270+
| | | InstantiateClass (S<float>, test.cc:3)
271+
| | | DeferInstantiation (S<float>::foo, test.cc:5)
272+
| PerformPendingInstantiations
273+
| | InstantiateFunction (S<float>::foo, test.cc:5)
274+
)",
275+
buildTraceGraph(Json));
276+
}
277+
241278
TEST(TimeProfilerTest, TemplateInstantiations) {
242279
std::string B_H = R"(
243280
template <typename T>
244-
T fooB(T t) {
281+
T fooC(T t) {
245282
return T();
246283
}
247284
285+
template <typename T>
286+
constexpr T fooB(T t) {
287+
return fooC(t);
288+
}
289+
248290
#define MacroTemp(x) template <typename T> void foo##x(T) { T(); }
249291
)";
250292

@@ -267,14 +309,19 @@ TEST(TimeProfilerTest, TemplateInstantiations) {
267309
std::string Json = teardownProfiler();
268310
ASSERT_EQ(R"(
269311
Frontend (test.cc)
312+
| ParseFunctionDefinition (fooC)
270313
| ParseFunctionDefinition (fooB)
271314
| ParseFunctionDefinition (fooMTA)
272315
| ParseFunctionDefinition (fooA)
273316
| ParseDeclarationOrFunctionDefinition (test.cc:3:5)
274317
| | ParseFunctionDefinition (user)
318+
| | | DeferInstantiation (fooA<int>, a.h:7)
275319
| PerformPendingInstantiations
276320
| | InstantiateFunction (fooA<int>, a.h:7)
277-
| | | InstantiateFunction (fooB<int>, b.h:3)
321+
| | | InstantiateFunction (fooB<int>, b.h:8)
322+
| | | | DeferInstantiation (fooC<int>, b.h:3)
323+
| | | DeferInstantiation (fooMTA<int>, a.h:4)
324+
| | | InstantiateFunction (fooC<int>, b.h:3)
278325
| | | InstantiateFunction (fooMTA<int>, a.h:4)
279326
)",
280327
buildTraceGraph(Json));

llvm/include/llvm/Support/TimeProfiler.h

Lines changed: 17 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -83,6 +83,8 @@ namespace llvm {
8383

8484
class raw_pwrite_stream;
8585

86+
enum class TimeTraceEventType { CompleteEvent, InstantEvent, AsyncEvent };
87+
8688
struct TimeTraceMetadata {
8789
std::string Detail;
8890
// Source file and line number information for the event.
@@ -152,6 +154,10 @@ timeTraceProfilerBegin(StringRef Name,
152154
TimeTraceProfilerEntry *timeTraceAsyncProfilerBegin(StringRef Name,
153155
StringRef Detail);
154156

157+
// Mark an instant event.
158+
TimeTraceProfilerEntry *timeTraceInstantEventProfilerBegin(StringRef Name,
159+
llvm::function_ref<TimeTraceMetadata()> Metadata);
160+
155161
/// Manually end the last time section.
156162
void timeTraceProfilerEnd();
157163
void timeTraceProfilerEnd(TimeTraceProfilerEntry *E);
@@ -181,9 +187,18 @@ class TimeTraceScope {
181187
Entry = timeTraceProfilerBegin(Name, Detail);
182188
}
183189
TimeTraceScope(StringRef Name,
184-
llvm::function_ref<TimeTraceMetadata()> Metadata) {
185-
if (getTimeTraceProfilerInstance() != nullptr)
190+
llvm::function_ref<TimeTraceMetadata()> Metadata, TimeTraceEventType Et = TimeTraceEventType::CompleteEvent) {
191+
if (getTimeTraceProfilerInstance() == nullptr)
192+
return;
193+
assert((Et == TimeTraceEventType::InstantEvent ||
194+
Et == TimeTraceEventType::CompleteEvent) &&
195+
"Event Type not supported.");
196+
197+
if (Et == TimeTraceEventType::CompleteEvent) {
186198
Entry = timeTraceProfilerBegin(Name, Metadata);
199+
} else {
200+
Entry = timeTraceInstantEventProfilerBegin(Name, Metadata);
201+
}
187202
}
188203
~TimeTraceScope() {
189204
if (getTimeTraceProfilerInstance() != nullptr)

llvm/lib/Support/TimeProfiler.cpp

Lines changed: 44 additions & 20 deletions
Original file line numberDiff line numberDiff line change
@@ -13,6 +13,7 @@
1313
#include "llvm/Support/TimeProfiler.h"
1414
#include "llvm/ADT/STLExtras.h"
1515
#include "llvm/ADT/STLFunctionalExtras.h"
16+
#include "llvm/ADT/SmallVector.h"
1617
#include "llvm/ADT/StringMap.h"
1718
#include "llvm/Support/JSON.h"
1819
#include "llvm/Support/Path.h"
@@ -70,23 +71,23 @@ using NameAndCountAndDurationType =
7071

7172
/// Represents an open or completed time section entry to be captured.
7273
struct llvm::TimeTraceProfilerEntry {
73-
const TimePointType Start;
74+
TimePointType Start;
7475
TimePointType End;
75-
const std::string Name;
76+
std::string Name;
7677
TimeTraceMetadata Metadata;
78+
TimeTraceEventType EventType;
7779

78-
const bool AsyncEvent = false;
7980
TimeTraceProfilerEntry(TimePointType &&S, TimePointType &&E, std::string &&N,
80-
std::string &&Dt, bool Ae)
81+
std::string &&Dt, TimeTraceEventType Et)
8182
: Start(std::move(S)), End(std::move(E)), Name(std::move(N)), Metadata(),
82-
AsyncEvent(Ae) {
83+
EventType(Et) {
8384
Metadata.Detail = std::move(Dt);
8485
}
8586

8687
TimeTraceProfilerEntry(TimePointType &&S, TimePointType &&E, std::string &&N,
87-
TimeTraceMetadata &&Mt, bool Ae)
88+
TimeTraceMetadata &&Mt, TimeTraceEventType Et)
8889
: Start(std::move(S)), End(std::move(E)), Name(std::move(N)),
89-
Metadata(std::move(Mt)), AsyncEvent(Ae) {}
90+
Metadata(std::move(Mt)), EventType(Et) {}
9091

9192
// Calculate timings for FlameGraph. Cast time points to microsecond precision
9293
// rather than casting duration. This avoids truncation issues causing inner
@@ -116,19 +117,19 @@ struct llvm::TimeTraceProfiler {
116117

117118
TimeTraceProfilerEntry *begin(std::string Name,
118119
llvm::function_ref<std::string()> Detail,
119-
bool AsyncEvent = false) {
120+
TimeTraceEventType Et = TimeTraceEventType::CompleteEvent) {
120121
Stack.emplace_back(std::make_unique<TimeTraceProfilerEntry>(
121122
ClockType::now(), TimePointType(), std::move(Name), Detail(),
122-
AsyncEvent));
123+
Et));
123124
return Stack.back().get();
124125
}
125126

126127
TimeTraceProfilerEntry *
127128
begin(std::string Name, llvm::function_ref<TimeTraceMetadata()> Metadata,
128-
bool AsyncEvent = false) {
129+
TimeTraceEventType Et = TimeTraceEventType::CompleteEvent) {
129130
Stack.emplace_back(std::make_unique<TimeTraceProfilerEntry>(
130131
ClockType::now(), TimePointType(), std::move(Name), Metadata(),
131-
AsyncEvent));
132+
Et));
132133
return Stack.back().get();
133134
}
134135

@@ -144,9 +145,22 @@ struct llvm::TimeTraceProfiler {
144145
// Calculate duration at full precision for overall counts.
145146
DurationType Duration = E.End - E.Start;
146147

147-
// Only include sections longer or equal to TimeTraceGranularity msec.
148-
if (duration_cast<microseconds>(Duration).count() >= TimeTraceGranularity)
148+
// Only include Instant Events or events with a duration longer or equal to
149+
// TimeTraceGranularity msec.
150+
if (E.EventType == TimeTraceEventType::InstantEvent ||
151+
duration_cast<microseconds>(Duration).count() >= TimeTraceGranularity) {
149152
Entries.emplace_back(E);
153+
} else {
154+
// if the event is not included, exclude also all instant events that
155+
// happened during this event.
156+
for (SmallVector<TimeTraceProfilerEntry, 128>::iterator it = Entries.begin(); it != Entries.end();) {
157+
if (TimeTraceEventType::InstantEvent == it->EventType &&
158+
it->Start > E.Start && it->Start < E.End)
159+
it = Entries.erase(it);
160+
else
161+
++it;
162+
}
163+
}
150164

151165
// Track total time taken by each "name", but only the topmost levels of
152166
// them; e.g. if there's a template instantiation that instantiates other
@@ -194,13 +208,15 @@ struct llvm::TimeTraceProfiler {
194208
J.attribute("pid", Pid);
195209
J.attribute("tid", int64_t(Tid));
196210
J.attribute("ts", StartUs);
197-
if (E.AsyncEvent) {
211+
if (E.EventType == TimeTraceEventType::AsyncEvent) {
198212
J.attribute("cat", E.Name);
199213
J.attribute("ph", "b");
200214
J.attribute("id", 0);
201-
} else {
215+
} else if (E.EventType == TimeTraceEventType::CompleteEvent) {
202216
J.attribute("ph", "X");
203217
J.attribute("dur", DurUs);
218+
} else { // instant event
219+
J.attribute("ph", "i");
204220
}
205221
J.attribute("name", E.Name);
206222
if (!E.Metadata.isEmpty()) {
@@ -215,7 +231,7 @@ struct llvm::TimeTraceProfiler {
215231
}
216232
});
217233

218-
if (E.AsyncEvent) {
234+
if (E.EventType == TimeTraceEventType::AsyncEvent) {
219235
J.object([&] {
220236
J.attribute("pid", Pid);
221237
J.attribute("tid", int64_t(Tid));
@@ -406,31 +422,39 @@ TimeTraceProfilerEntry *llvm::timeTraceProfilerBegin(StringRef Name,
406422
StringRef Detail) {
407423
if (TimeTraceProfilerInstance != nullptr)
408424
return TimeTraceProfilerInstance->begin(
409-
std::string(Name), [&]() { return std::string(Detail); }, false);
425+
std::string(Name), [&]() { return std::string(Detail); }, TimeTraceEventType::CompleteEvent);
410426
return nullptr;
411427
}
412428

413429
TimeTraceProfilerEntry *
414430
llvm::timeTraceProfilerBegin(StringRef Name,
415431
llvm::function_ref<std::string()> Detail) {
416432
if (TimeTraceProfilerInstance != nullptr)
417-
return TimeTraceProfilerInstance->begin(std::string(Name), Detail, false);
433+
return TimeTraceProfilerInstance->begin(std::string(Name), Detail, TimeTraceEventType::CompleteEvent);
418434
return nullptr;
419435
}
420436

421437
TimeTraceProfilerEntry *
422438
llvm::timeTraceProfilerBegin(StringRef Name,
423439
llvm::function_ref<TimeTraceMetadata()> Metadata) {
424440
if (TimeTraceProfilerInstance != nullptr)
425-
return TimeTraceProfilerInstance->begin(std::string(Name), Metadata, false);
441+
return TimeTraceProfilerInstance->begin(std::string(Name), Metadata, TimeTraceEventType::CompleteEvent);
442+
return nullptr;
443+
}
444+
445+
TimeTraceProfilerEntry *
446+
llvm::timeTraceInstantEventProfilerBegin(StringRef Name,
447+
llvm::function_ref<TimeTraceMetadata()> Metadata) {
448+
if (TimeTraceProfilerInstance != nullptr)
449+
return TimeTraceProfilerInstance->begin(std::string(Name), Metadata, TimeTraceEventType::InstantEvent);
426450
return nullptr;
427451
}
428452

429453
TimeTraceProfilerEntry *llvm::timeTraceAsyncProfilerBegin(StringRef Name,
430454
StringRef Detail) {
431455
if (TimeTraceProfilerInstance != nullptr)
432456
return TimeTraceProfilerInstance->begin(
433-
std::string(Name), [&]() { return std::string(Detail); }, true);
457+
std::string(Name), [&]() { return std::string(Detail); }, TimeTraceEventType::AsyncEvent);
434458
return nullptr;
435459
}
436460

0 commit comments

Comments
 (0)