mirror of
https://github.com/RPCS3/llvm-mirror.git
synced 2024-10-19 11:02:59 +02:00
Fix time-trace breaking flame graph assumptions
-ftime-trace could break flame-graph assumptions on Windows, with an inner scope overrunning outer scopes. This was due to the way that times were truncated. Changed this so time_points for the flame-graph are truncated instead of durations, preserving the relative order of event starts and ends. I have tried to retain the extra precision for the totals, which count thousands or millions of events. Added assert to check this property holds in future. Fixes PR43043 Differential Revision: https://reviews.llvm.org/D66411 llvm-svn: 371039
This commit is contained in:
parent
322242289e
commit
6be57efcf5
@ -27,20 +27,35 @@ namespace llvm {
|
||||
TimeTraceProfiler *TimeTraceProfilerInstance = nullptr;
|
||||
|
||||
typedef duration<steady_clock::rep, steady_clock::period> DurationType;
|
||||
typedef time_point<steady_clock> TimePointType;
|
||||
typedef std::pair<size_t, DurationType> CountAndDurationType;
|
||||
typedef std::pair<std::string, CountAndDurationType>
|
||||
NameAndCountAndDurationType;
|
||||
|
||||
struct Entry {
|
||||
time_point<steady_clock> Start;
|
||||
DurationType Duration;
|
||||
TimePointType Start;
|
||||
TimePointType End;
|
||||
std::string Name;
|
||||
std::string Detail;
|
||||
|
||||
Entry(time_point<steady_clock> &&S, DurationType &&D, std::string &&N,
|
||||
std::string &&Dt)
|
||||
: Start(std::move(S)), Duration(std::move(D)), Name(std::move(N)),
|
||||
Entry(TimePointType &&S, TimePointType &&E, std::string &&N, std::string &&Dt)
|
||||
: Start(std::move(S)), End(std::move(E)), Name(std::move(N)),
|
||||
Detail(std::move(Dt)){};
|
||||
|
||||
// Calculate timings for FlameGraph. Cast time points to microsecond precision
|
||||
// rather than casting duration. This avoid truncation issues causing inner
|
||||
// scopes overruning outer scopes.
|
||||
steady_clock::rep getFlameGraphStartUs(TimePointType StartTime) const {
|
||||
return (time_point_cast<microseconds>(Start) -
|
||||
time_point_cast<microseconds>(StartTime))
|
||||
.count();
|
||||
}
|
||||
|
||||
steady_clock::rep getFlameGraphDurUs() const {
|
||||
return (time_point_cast<microseconds>(End) -
|
||||
time_point_cast<microseconds>(Start))
|
||||
.count();
|
||||
}
|
||||
};
|
||||
|
||||
struct TimeTraceProfiler {
|
||||
@ -49,17 +64,27 @@ struct TimeTraceProfiler {
|
||||
}
|
||||
|
||||
void begin(std::string Name, llvm::function_ref<std::string()> Detail) {
|
||||
Stack.emplace_back(steady_clock::now(), DurationType{}, std::move(Name),
|
||||
Stack.emplace_back(steady_clock::now(), TimePointType(), std::move(Name),
|
||||
Detail());
|
||||
}
|
||||
|
||||
void end() {
|
||||
assert(!Stack.empty() && "Must call begin() first");
|
||||
auto &E = Stack.back();
|
||||
E.Duration = steady_clock::now() - E.Start;
|
||||
E.End = steady_clock::now();
|
||||
|
||||
// Check that end times monotonically increase.
|
||||
assert((Entries.empty() ||
|
||||
(E.getFlameGraphStartUs(StartTime) + E.getFlameGraphDurUs() >=
|
||||
Entries.back().getFlameGraphStartUs(StartTime) +
|
||||
Entries.back().getFlameGraphDurUs())) &&
|
||||
"TimeProfiler scope ended earlier than previous scope");
|
||||
|
||||
// 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>(E.Duration).count() >= TimeTraceGranularity)
|
||||
if (duration_cast<microseconds>(Duration).count() >= TimeTraceGranularity)
|
||||
Entries.emplace_back(E);
|
||||
|
||||
// Track total time taken by each "name", but only the topmost levels of
|
||||
@ -72,7 +97,7 @@ struct TimeTraceProfiler {
|
||||
}) == Stack.rend()) {
|
||||
auto &CountAndTotal = CountAndTotalPerName[E.Name];
|
||||
CountAndTotal.first++;
|
||||
CountAndTotal.second += E.Duration;
|
||||
CountAndTotal.second += Duration;
|
||||
}
|
||||
|
||||
Stack.pop_back();
|
||||
@ -88,8 +113,8 @@ struct TimeTraceProfiler {
|
||||
|
||||
// Emit all events for the main flame graph.
|
||||
for (const auto &E : Entries) {
|
||||
auto StartUs = duration_cast<microseconds>(E.Start - StartTime).count();
|
||||
auto DurUs = duration_cast<microseconds>(E.Duration).count();
|
||||
auto StartUs = E.getFlameGraphStartUs(StartTime);
|
||||
auto DurUs = E.getFlameGraphDurUs();
|
||||
|
||||
J.object([&]{
|
||||
J.attribute("pid", 1);
|
||||
@ -154,7 +179,7 @@ struct TimeTraceProfiler {
|
||||
SmallVector<Entry, 16> Stack;
|
||||
SmallVector<Entry, 128> Entries;
|
||||
StringMap<CountAndDurationType> CountAndTotalPerName;
|
||||
time_point<steady_clock> StartTime;
|
||||
TimePointType StartTime;
|
||||
|
||||
// Minimum time granularity (in microseconds)
|
||||
unsigned TimeTraceGranularity;
|
||||
|
Loading…
Reference in New Issue
Block a user