xref: /freebsd/contrib/llvm-project/llvm/lib/Support/TimeProfiler.cpp (revision 6966ac055c3b7a39266fb982493330df7a097997)
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 
13 #include "llvm/Support/TimeProfiler.h"
14 #include "llvm/ADT/StringMap.h"
15 #include "llvm/Support/CommandLine.h"
16 #include "llvm/Support/FileSystem.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 
33 TimeTraceProfiler *TimeTraceProfilerInstance = nullptr;
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>
38     NameAndCountAndDurationType;
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 
52 struct TimeTraceProfiler {
53   TimeTraceProfiler() {
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 
87   void Write(raw_pwrite_stream &OS) {
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,
121                   const NameAndCountAndDurationType &B) {
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 
160   SmallVector<Entry, 16> Stack;
161   SmallVector<Entry, 128> Entries;
162   StringMap<CountAndDurationType> CountAndTotalPerName;
163   time_point<steady_clock> StartTime;
164 };
165 
166 void timeTraceProfilerInitialize() {
167   assert(TimeTraceProfilerInstance == nullptr &&
168          "Profiler should not be initialized");
169   TimeTraceProfilerInstance = new TimeTraceProfiler();
170 }
171 
172 void timeTraceProfilerCleanup() {
173   delete TimeTraceProfilerInstance;
174   TimeTraceProfilerInstance = nullptr;
175 }
176 
177 void timeTraceProfilerWrite(raw_pwrite_stream &OS) {
178   assert(TimeTraceProfilerInstance != nullptr &&
179          "Profiler object can't be null");
180   TimeTraceProfilerInstance->Write(OS);
181 }
182 
183 void timeTraceProfilerBegin(StringRef Name, StringRef Detail) {
184   if (TimeTraceProfilerInstance != nullptr)
185     TimeTraceProfilerInstance->begin(Name, [&]() { return Detail; });
186 }
187 
188 void timeTraceProfilerBegin(StringRef Name,
189                             llvm::function_ref<std::string()> Detail) {
190   if (TimeTraceProfilerInstance != nullptr)
191     TimeTraceProfilerInstance->begin(Name, Detail);
192 }
193 
194 void timeTraceProfilerEnd() {
195   if (TimeTraceProfilerInstance != nullptr)
196     TimeTraceProfilerInstance->end();
197 }
198 
199 } // namespace llvm
200