LLVM  9.0.0svn
TimeProfiler.cpp
Go to the documentation of this file.
1 //===-- TimeProfiler.cpp - Hierarchical Time Profiler ---------------------===//
2 //
3 // Part of the LLVM Project, under the Apache License v2.0 with LLVM Exceptions.
4 // See https://llvm.org/LICENSE.txt for license information.
5 // SPDX-License-Identifier: Apache-2.0 WITH LLVM-exception
6 //
7 //===----------------------------------------------------------------------===//
8 //
9 // This file implements hierarchical time profiler.
10 //
11 //===----------------------------------------------------------------------===//
12 
14 #include "llvm/ADT/StringMap.h"
17 #include "llvm/Support/JSON.h"
18 #include <cassert>
19 #include <chrono>
20 #include <string>
21 #include <vector>
22 
23 using namespace std::chrono;
24 
25 namespace llvm {
26 
27 static cl::opt<unsigned> TimeTraceGranularity(
28  "time-trace-granularity",
29  cl::desc(
30  "Minimum time granularity (in microseconds) traced by time profiler"),
31  cl::init(500));
32 
34 
35 typedef duration<steady_clock::rep, steady_clock::period> DurationType;
36 typedef std::pair<size_t, DurationType> CountAndDurationType;
37 typedef std::pair<std::string, CountAndDurationType>
39 
40 struct Entry {
41  time_point<steady_clock> Start;
42  DurationType Duration;
43  std::string Name;
44  std::string Detail;
45 
46  Entry(time_point<steady_clock> &&S, DurationType &&D, std::string &&N,
47  std::string &&Dt)
48  : Start(std::move(S)), Duration(std::move(D)), Name(std::move(N)),
49  Detail(std::move(Dt)){};
50 };
51 
54  StartTime = steady_clock::now();
55  }
56 
57  void begin(std::string Name, llvm::function_ref<std::string()> Detail) {
58  Stack.emplace_back(steady_clock::now(), DurationType{}, std::move(Name),
59  Detail());
60  }
61 
62  void end() {
63  assert(!Stack.empty() && "Must call begin() first");
64  auto &E = Stack.back();
65  E.Duration = steady_clock::now() - E.Start;
66 
67  // Only include sections longer than TimeTraceGranularity msec.
68  if (duration_cast<microseconds>(E.Duration).count() > TimeTraceGranularity)
69  Entries.emplace_back(E);
70 
71  // Track total time taken by each "name", but only the topmost levels of
72  // them; e.g. if there's a template instantiation that instantiates other
73  // templates from within, we only want to add the topmost one. "topmost"
74  // happens to be the ones that don't have any currently open entries above
75  // itself.
76  if (std::find_if(++Stack.rbegin(), Stack.rend(), [&](const Entry &Val) {
77  return Val.Name == E.Name;
78  }) == Stack.rend()) {
79  auto &CountAndTotal = CountAndTotalPerName[E.Name];
80  CountAndTotal.first++;
81  CountAndTotal.second += E.Duration;
82  }
83 
84  Stack.pop_back();
85  }
86 
88  assert(Stack.empty() &&
89  "All profiler sections should be ended when calling Write");
90  json::OStream J(OS);
91  J.objectBegin();
92  J.attributeBegin("traceEvents");
93  J.arrayBegin();
94 
95  // Emit all events for the main flame graph.
96  for (const auto &E : Entries) {
97  auto StartUs = duration_cast<microseconds>(E.Start - StartTime).count();
98  auto DurUs = duration_cast<microseconds>(E.Duration).count();
99 
100  J.object([&]{
101  J.attribute("pid", 1);
102  J.attribute("tid", 0);
103  J.attribute("ph", "X");
104  J.attribute("ts", StartUs);
105  J.attribute("dur", DurUs);
106  J.attribute("name", E.Name);
107  J.attributeObject("args", [&] { J.attribute("detail", E.Detail); });
108  });
109  }
110 
111  // Emit totals by section name as additional "thread" events, sorted from
112  // longest one.
113  int Tid = 1;
114  std::vector<NameAndCountAndDurationType> SortedTotals;
115  SortedTotals.reserve(CountAndTotalPerName.size());
116  for (const auto &E : CountAndTotalPerName)
117  SortedTotals.emplace_back(E.getKey(), E.getValue());
118 
119  llvm::sort(SortedTotals.begin(), SortedTotals.end(),
120  [](const NameAndCountAndDurationType &A,
122  return A.second.second > B.second.second;
123  });
124  for (const auto &E : SortedTotals) {
125  auto DurUs = duration_cast<microseconds>(E.second.second).count();
126  auto Count = CountAndTotalPerName[E.first].first;
127 
128  J.object([&]{
129  J.attribute("pid", 1);
130  J.attribute("tid", Tid);
131  J.attribute("ph", "X");
132  J.attribute("ts", 0);
133  J.attribute("dur", DurUs);
134  J.attribute("name", "Total " + E.first);
135  J.attributeObject("args", [&] {
136  J.attribute("count", int64_t(Count));
137  J.attribute("avg ms", int64_t(DurUs / Count / 1000));
138  });
139  });
140 
141  ++Tid;
142  }
143 
144  // Emit metadata event with process name.
145  J.object([&] {
146  J.attribute("cat", "");
147  J.attribute("pid", 1);
148  J.attribute("tid", 0);
149  J.attribute("ts", 0);
150  J.attribute("ph", "M");
151  J.attribute("name", "process_name");
152  J.attributeObject("args", [&] { J.attribute("name", "clang"); });
153  });
154 
155  J.arrayEnd();
156  J.attributeEnd();
157  J.objectEnd();
158  }
159 
163  time_point<steady_clock> StartTime;
164 };
165 
167  assert(TimeTraceProfilerInstance == nullptr &&
168  "Profiler should not be initialized");
169  TimeTraceProfilerInstance = new TimeTraceProfiler();
170 }
171 
174  TimeTraceProfilerInstance = nullptr;
175 }
176 
178  assert(TimeTraceProfilerInstance != nullptr &&
179  "Profiler object can't be null");
180  TimeTraceProfilerInstance->Write(OS);
181 }
182 
184  if (TimeTraceProfilerInstance != nullptr)
185  TimeTraceProfilerInstance->begin(Name, [&]() { return Detail; });
186 }
187 
189  llvm::function_ref<std::string()> Detail) {
190  if (TimeTraceProfilerInstance != nullptr)
191  TimeTraceProfilerInstance->begin(Name, Detail);
192 }
193 
195  if (TimeTraceProfilerInstance != nullptr)
196  TimeTraceProfilerInstance->end();
197 }
198 
199 } // namespace llvm
void Write(raw_pwrite_stream &OS)
This class represents lattice values for constants.
Definition: AllocatorList.h:23
amdgpu Simplify well known AMD library false FunctionCallee Value const Twine & Name
StringMap< CountAndDurationType > CountAndTotalPerName
std::pair< size_t, DurationType > CountAndDurationType
An efficient, type-erasing, non-owning reference to a callable.
Definition: STLExtras.h:116
void timeTraceProfilerEnd()
Manually end the last time section.
std::string Name
Definition: BitVector.h:937
json::OStream allows writing well-formed JSON without materializing all structures as json::Value ahe...
Definition: JSON.h:751
void timeTraceProfilerInitialize()
Initialize the time trace profiler.
SmallVector< Entry, 16 > Stack
std::pair< std::string, CountAndDurationType > NameAndCountAndDurationType
auto count(R &&Range, const E &Element) -> typename std::iterator_traits< decltype(adl_begin(Range))>::difference_type
Wrapper function around std::count to count the number of times an element Element occurs in the give...
Definition: STLExtras.h:1258
std::string Detail
void begin(std::string Name, llvm::function_ref< std::string()> Detail)
void timeTraceProfilerCleanup()
Cleanup the time trace profiler, if it was initialized.
initializer< Ty > init(const Ty &Val)
Definition: CommandLine.h:432
duration< steady_clock::rep, steady_clock::period > DurationType
static GCRegistry::Add< OcamlGC > B("ocaml", "ocaml 3.10-compatible GC")
void timeTraceProfilerBegin(StringRef Name, StringRef Detail)
Manually begin a time section, with the given Name and Detail.
static GCRegistry::Add< CoreCLRGC > E("coreclr", "CoreCLR-compatible GC")
static sys::TimePoint< std::chrono::seconds > now(bool Deterministic)
auto find_if(R &&Range, UnaryPredicate P) -> decltype(adl_begin(Range))
Provide wrappers to std::find_if which take ranges instead of having to pass begin/end explicitly...
Definition: STLExtras.h:1220
time_point< steady_clock > StartTime
void sort(IteratorTy Start, IteratorTy End)
Definition: STLExtras.h:1122
Entry(time_point< steady_clock > &&S, DurationType &&D, std::string &&N, std::string &&Dt)
time_point< steady_clock > Start
This is a &#39;vector&#39; (really, a variable-sized array), optimized for the case when the array is small...
Definition: SmallVector.h:837
static GCRegistry::Add< StatepointGC > D("statepoint-example", "an example strategy for statepoint")
void timeTraceProfilerWrite(raw_pwrite_stream &OS)
Write profiling data to output file.
TimeTraceProfiler * TimeTraceProfilerInstance
DurationType Duration
#define N
SmallVector< Entry, 128 > Entries
This file supports working with JSON data.
An abstract base class for streams implementations that also support a pwrite operation.
Definition: raw_ostream.h:340
assert(ImpDefSCC.getReg()==AMDGPU::SCC &&ImpDefSCC.isDef())
StringRef - Represent a constant reference to a string, i.e.
Definition: StringRef.h:48
static cl::opt< unsigned > TimeTraceGranularity("time-trace-granularity", cl::desc("Minimum time granularity (in microseconds) traced by time profiler"), cl::init(500))