Skip to content

Commit 677c264

Browse files
author
fel-cab
committed
Changing TimeProfiler.cpp clock from microseconds to nanoseconds to improve LIBOMPTARGET profiling, as it allows to measure more events. It was part of PR llvm#68016
1 parent 481df27 commit 677c264

File tree

1 file changed

+25
-25
lines changed

1 file changed

+25
-25
lines changed

llvm/lib/Support/TimeProfiler.cpp

Lines changed: 25 additions & 25 deletions
Original file line numberDiff line numberDiff line change
@@ -30,7 +30,7 @@ namespace {
3030

3131
using std::chrono::duration;
3232
using std::chrono::duration_cast;
33-
using std::chrono::microseconds;
33+
using std::chrono::nanoseconds;
3434
using std::chrono::steady_clock;
3535
using std::chrono::system_clock;
3636
using std::chrono::time_point;
@@ -76,18 +76,18 @@ struct TimeTraceProfilerEntry {
7676
: Start(std::move(S)), End(std::move(E)), Name(std::move(N)),
7777
Detail(std::move(Dt)) {}
7878

79-
// Calculate timings for FlameGraph. Cast time points to microsecond precision
79+
// Calculate timings for FlameGraph. Cast time points to nanosecond precision
8080
// rather than casting duration. This avoids truncation issues causing inner
8181
// scopes overruning outer scopes.
82-
ClockType::rep getFlameGraphStartUs(TimePointType StartTime) const {
83-
return (time_point_cast<microseconds>(Start) -
84-
time_point_cast<microseconds>(StartTime))
82+
ClockType::rep getFlameGraphStartNs(TimePointType StartTime) const {
83+
return (time_point_cast<nanoseconds>(Start) -
84+
time_point_cast<nanoseconds>(StartTime))
8585
.count();
8686
}
8787

88-
ClockType::rep getFlameGraphDurUs() const {
89-
return (time_point_cast<microseconds>(End) -
90-
time_point_cast<microseconds>(Start))
88+
ClockType::rep getFlameGraphDurNs() const {
89+
return (time_point_cast<nanoseconds>(End) -
90+
time_point_cast<nanoseconds>(Start))
9191
.count();
9292
}
9393
};
@@ -114,16 +114,16 @@ struct llvm::TimeTraceProfiler {
114114

115115
// Check that end times monotonically increase.
116116
assert((Entries.empty() ||
117-
(E.getFlameGraphStartUs(StartTime) + E.getFlameGraphDurUs() >=
118-
Entries.back().getFlameGraphStartUs(StartTime) +
119-
Entries.back().getFlameGraphDurUs())) &&
117+
(E.getFlameGraphStartNs(StartTime) + E.getFlameGraphDurNs() >=
118+
Entries.back().getFlameGraphStartNs(StartTime) +
119+
Entries.back().getFlameGraphDurNs())) &&
120120
"TimeProfiler scope ended earlier than previous scope");
121121

122122
// Calculate duration at full precision for overall counts.
123123
DurationType Duration = E.End - E.Start;
124124

125125
// Only include sections longer or equal to TimeTraceGranularity msec.
126-
if (duration_cast<microseconds>(Duration).count() >= TimeTraceGranularity)
126+
if (duration_cast<nanoseconds>(Duration).count() >= TimeTraceGranularity)
127127
Entries.emplace_back(E);
128128

129129
// Track total time taken by each "name", but only the topmost levels of
@@ -162,15 +162,15 @@ struct llvm::TimeTraceProfiler {
162162

163163
// Emit all events for the main flame graph.
164164
auto writeEvent = [&](const auto &E, uint64_t Tid) {
165-
auto StartUs = E.getFlameGraphStartUs(StartTime);
166-
auto DurUs = E.getFlameGraphDurUs();
165+
auto StartNs = E.getFlameGraphStartNs(StartTime);
166+
auto DurNs = E.getFlameGraphDurNs();
167167

168168
J.object([&] {
169169
J.attribute("pid", Pid);
170170
J.attribute("tid", int64_t(Tid));
171171
J.attribute("ph", "X");
172-
J.attribute("ts", StartUs);
173-
J.attribute("dur", DurUs);
172+
J.attribute("ts", StartNs / 1000);
173+
J.attribute("dur", DurNs / 1000);
174174
J.attribute("name", E.Name);
175175
if (!E.Detail.empty()) {
176176
J.attributeObject("args", [&] { J.attribute("detail", E.Detail); });
@@ -218,19 +218,19 @@ struct llvm::TimeTraceProfiler {
218218
// Report totals on separate threads of tracing file.
219219
uint64_t TotalTid = MaxTid + 1;
220220
for (const NameAndCountAndDurationType &Total : SortedTotals) {
221-
auto DurUs = duration_cast<microseconds>(Total.second.second).count();
221+
auto DurNs = duration_cast<nanoseconds>(Total.second.second).count();
222222
auto Count = AllCountAndTotalPerName[Total.first].first;
223223

224224
J.object([&] {
225225
J.attribute("pid", Pid);
226226
J.attribute("tid", int64_t(TotalTid));
227227
J.attribute("ph", "X");
228228
J.attribute("ts", 0);
229-
J.attribute("dur", DurUs);
230-
J.attribute("name", "Total " + Total.first);
229+
J.attribute("dur", DurNs / 1000);
230+
J.attribute("name", "Total: " + Total.first);
231231
J.attributeObject("args", [&] {
232232
J.attribute("count", int64_t(Count));
233-
J.attribute("avg ms", int64_t(DurUs / Count / 1000));
233+
J.attribute("avg us", int64_t(DurNs / Count / 1000));
234234
});
235235
});
236236

@@ -261,10 +261,10 @@ struct llvm::TimeTraceProfiler {
261261
// Emit the absolute time when this TimeProfiler started.
262262
// This can be used to combine the profiling data from
263263
// multiple processes and preserve actual time intervals.
264-
J.attribute("beginningOfTime",
265-
time_point_cast<microseconds>(BeginningOfTime)
266-
.time_since_epoch()
267-
.count());
264+
J.attribute("beginningOfTime", time_point_cast<nanoseconds>(BeginningOfTime)
265+
.time_since_epoch()
266+
.count() /
267+
1000);
268268

269269
J.objectEnd();
270270
}
@@ -281,7 +281,7 @@ struct llvm::TimeTraceProfiler {
281281
SmallString<0> ThreadName;
282282
const uint64_t Tid;
283283

284-
// Minimum time granularity (in microseconds)
284+
// Minimum time granularity (in nanoseconds)
285285
const unsigned TimeTraceGranularity;
286286
};
287287

0 commit comments

Comments
 (0)