1 | //===- unittests/Support/TimeProfilerTest.cpp -----------------------------===// |
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 | #include "clang/Frontend/CompilerInstance.h" |
10 | #include "clang/Frontend/FrontendActions.h" |
11 | #include "clang/Lex/PreprocessorOptions.h" |
12 | |
13 | #include "llvm/ADT/StringMap.h" |
14 | #include "llvm/Support/JSON.h" |
15 | #include "llvm/Support/Path.h" |
16 | #include "llvm/Support/TimeProfiler.h" |
17 | #include "llvm/Support/VirtualFileSystem.h" |
18 | #include <stack> |
19 | |
20 | #include "gtest/gtest.h" |
21 | #include <tuple> |
22 | |
23 | using namespace clang; |
24 | using namespace llvm; |
25 | |
26 | namespace { |
27 | |
28 | // Should be called before testing. |
29 | void setupProfiler() { |
30 | timeTraceProfilerInitialize(/*TimeTraceGranularity=*/0, ProcName: "test" , |
31 | /*TimeTraceVerbose=*/true); |
32 | } |
33 | |
34 | // Should be called after `compileFromString()`. |
35 | // Returns profiler's JSON dump. |
36 | std::string teardownProfiler() { |
37 | SmallVector<char, 1024> SmallVec; |
38 | raw_svector_ostream OS(SmallVec); |
39 | timeTraceProfilerWrite(OS); |
40 | timeTraceProfilerCleanup(); |
41 | return OS.str().str(); |
42 | } |
43 | |
44 | // Returns true if code compiles successfully. |
45 | // We only parse AST here. This is enough for constexpr evaluation. |
46 | bool compileFromString(StringRef Code, StringRef Standard, StringRef File, |
47 | llvm::StringMap<std::string> = {}) { |
48 | |
49 | llvm::IntrusiveRefCntPtr<llvm::vfs::InMemoryFileSystem> FS( |
50 | new llvm::vfs::InMemoryFileSystem()); |
51 | FS->addFile(Path: File, ModificationTime: 0, Buffer: MemoryBuffer::getMemBuffer(InputData: Code)); |
52 | for (const auto & : Headers) { |
53 | FS->addFile(Path: Header.getKey(), ModificationTime: 0, |
54 | Buffer: MemoryBuffer::getMemBuffer(InputData: Header.getValue())); |
55 | } |
56 | llvm::IntrusiveRefCntPtr<FileManager> Files( |
57 | new FileManager(FileSystemOptions(), FS)); |
58 | |
59 | auto Invocation = std::make_shared<CompilerInvocation>(); |
60 | std::vector<const char *> Args = {Standard.data(), File.data()}; |
61 | DiagnosticOptions InvocationDiagOpts; |
62 | auto InvocationDiags = |
63 | CompilerInstance::createDiagnostics(VFS&: *FS, Opts&: InvocationDiagOpts); |
64 | CompilerInvocation::CreateFromArgs(Res&: *Invocation, CommandLineArgs: Args, Diags&: *InvocationDiags); |
65 | |
66 | CompilerInstance Compiler(std::move(Invocation)); |
67 | Compiler.createDiagnostics(VFS&: Files->getVirtualFileSystem()); |
68 | Compiler.setFileManager(Files.get()); |
69 | |
70 | class TestFrontendAction : public ASTFrontendAction { |
71 | private: |
72 | std::unique_ptr<ASTConsumer> CreateASTConsumer(CompilerInstance &CI, |
73 | StringRef InFile) override { |
74 | return std::make_unique<ASTConsumer>(); |
75 | } |
76 | } Action; |
77 | return Compiler.ExecuteAction(Act&: Action); |
78 | } |
79 | |
80 | std::string GetMetadata(json::Object *Event) { |
81 | std::string M; |
82 | llvm::raw_string_ostream OS(M); |
83 | if (json::Object *Args = Event->getObject(K: "args" )) { |
84 | if (auto Detail = Args->getString(K: "detail" )) |
85 | OS << Detail; |
86 | // Use only filename to not include os-specific path separators. |
87 | if (auto File = Args->getString(K: "file" )) |
88 | OS << (M.empty() ? "" : ", " ) << llvm::sys::path::filename(path: *File); |
89 | if (auto Line = Args->getInteger(K: "line" )) |
90 | OS << ":" << *Line; |
91 | } |
92 | return M; |
93 | } |
94 | |
95 | // Returns pretty-printed trace graph. |
96 | std::string buildTraceGraph(StringRef Json) { |
97 | struct EventRecord { |
98 | int64_t TimestampBegin; |
99 | int64_t TimestampEnd; |
100 | std::string Name; |
101 | std::string Metadata; |
102 | }; |
103 | std::vector<EventRecord> Events; |
104 | |
105 | // Parse `EventRecord`s from JSON dump. |
106 | Expected<json::Value> Root = json::parse(JSON: Json); |
107 | if (!Root) |
108 | return "" ; |
109 | for (json::Value &TraceEventValue : |
110 | *Root->getAsObject()->getArray(K: "traceEvents" )) { |
111 | json::Object *TraceEventObj = TraceEventValue.getAsObject(); |
112 | |
113 | int64_t TimestampBegin = TraceEventObj->getInteger(K: "ts" ).value_or(u: 0); |
114 | int64_t TimestampEnd = |
115 | TimestampBegin + TraceEventObj->getInteger(K: "dur" ).value_or(u: 0); |
116 | std::string Name = TraceEventObj->getString(K: "name" ).value_or(u: "" ).str(); |
117 | std::string Metadata = GetMetadata(Event: TraceEventObj); |
118 | |
119 | // Source events are asynchronous events and may not perfectly nest the |
120 | // synchronous events. Skip testing them. |
121 | if (Name == "Source" ) |
122 | continue; |
123 | |
124 | // This is a "summary" event, like "Total PerformPendingInstantiations", |
125 | // skip it |
126 | if (TimestampBegin == 0) |
127 | continue; |
128 | |
129 | Events.emplace_back( |
130 | args: EventRecord{.TimestampBegin: TimestampBegin, .TimestampEnd: TimestampEnd, .Name: Name, .Metadata: Metadata}); |
131 | } |
132 | |
133 | // There can be nested events that are very fast, for example: |
134 | // {"name":"EvaluateAsBooleanCondition",... ,"ts":2380,"dur":1} |
135 | // {"name":"EvaluateAsRValue",... ,"ts":2380,"dur":1} |
136 | // Therefore we should reverse the events list, so that events that have |
137 | // started earlier are first in the list. |
138 | // Then do a stable sort, we need it for the trace graph. |
139 | std::reverse(first: Events.begin(), last: Events.end()); |
140 | llvm::stable_sort(Range&: Events, C: [](const auto &lhs, const auto &rhs) { |
141 | return std::make_pair(lhs.TimestampBegin, -lhs.TimestampEnd) < |
142 | std::make_pair(rhs.TimestampBegin, -rhs.TimestampEnd); |
143 | }); |
144 | |
145 | std::stringstream Stream; |
146 | // Write a newline for better testing with multiline string literal. |
147 | Stream << "\n" ; |
148 | |
149 | // Keep the current event stack. |
150 | std::stack<const EventRecord *> EventStack; |
151 | for (const auto &Event : Events) { |
152 | // Pop every event in the stack until meeting the parent event. |
153 | while (!EventStack.empty()) { |
154 | bool InsideCurrentEvent = |
155 | Event.TimestampBegin >= EventStack.top()->TimestampBegin && |
156 | Event.TimestampEnd <= EventStack.top()->TimestampEnd; |
157 | |
158 | // Presumably due to timer rounding, PerformPendingInstantiations often |
159 | // appear to be within the timer interval of the immediately previous |
160 | // event group. We always know these events occur at level 1, not level 2, |
161 | // in our tests, so pop an event in that case. |
162 | if (InsideCurrentEvent && Event.Name == "PerformPendingInstantiations" && |
163 | EventStack.size() == 2) { |
164 | InsideCurrentEvent = false; |
165 | } |
166 | |
167 | if (!InsideCurrentEvent) |
168 | EventStack.pop(); |
169 | else |
170 | break; |
171 | } |
172 | EventStack.push(x: &Event); |
173 | |
174 | // Write indentaion, name, detail, newline. |
175 | for (size_t i = 1; i < EventStack.size(); ++i) { |
176 | Stream << "| " ; |
177 | } |
178 | Stream.write(s: Event.Name.data(), n: Event.Name.size()); |
179 | if (!Event.Metadata.empty()) { |
180 | Stream << " (" ; |
181 | Stream.write(s: Event.Metadata.data(), n: Event.Metadata.size()); |
182 | Stream << ")" ; |
183 | } |
184 | Stream << "\n" ; |
185 | } |
186 | return Stream.str(); |
187 | } |
188 | |
189 | } // namespace |
190 | |
191 | TEST(TimeProfilerTest, ConstantEvaluationCxx20) { |
192 | std::string Code = R"( |
193 | void print(double value); |
194 | |
195 | namespace slow_namespace { |
196 | |
197 | consteval double slow_func() { |
198 | double d = 0.0; |
199 | for (int i = 0; i < 100; ++i) { // 8th line |
200 | d += i; // 9th line |
201 | } |
202 | return d; |
203 | } |
204 | |
205 | } // namespace slow_namespace |
206 | |
207 | void slow_test() { |
208 | constexpr auto slow_value = slow_namespace::slow_func(); // 17th line |
209 | print(slow_namespace::slow_func()); // 18th line |
210 | print(slow_value); |
211 | } |
212 | |
213 | int slow_arr[12 + 34 * 56 + // 22nd line |
214 | static_cast<int>(slow_namespace::slow_func())]; // 23rd line |
215 | |
216 | constexpr int slow_init_list[] = {1, 1, 2, 3, 5, 8, 13, 21}; // 25th line |
217 | )" ; |
218 | |
219 | setupProfiler(); |
220 | ASSERT_TRUE(compileFromString(Code, "-std=c++20" , "test.cc" )); |
221 | std::string Json = teardownProfiler(); |
222 | ASSERT_EQ(R"( |
223 | Frontend (test.cc) |
224 | | ParseDeclarationOrFunctionDefinition (test.cc:2:1) |
225 | | ParseDeclarationOrFunctionDefinition (test.cc:6:1) |
226 | | | ParseFunctionDefinition (slow_func) |
227 | | | | EvaluateAsRValue (<test.cc:8:21>) |
228 | | | | EvaluateForOverflow (<test.cc:8:21, col:25>) |
229 | | | | EvaluateForOverflow (<test.cc:8:30, col:32>) |
230 | | | | EvaluateAsRValue (<test.cc:9:14>) |
231 | | | | EvaluateForOverflow (<test.cc:9:9, col:14>) |
232 | | | | isPotentialConstantExpr (slow_namespace::slow_func) |
233 | | | | EvaluateAsBooleanCondition (<test.cc:8:21, col:25>) |
234 | | | | | EvaluateAsRValue (<test.cc:8:21, col:25>) |
235 | | | | EvaluateAsBooleanCondition (<test.cc:8:21, col:25>) |
236 | | | | | EvaluateAsRValue (<test.cc:8:21, col:25>) |
237 | | ParseDeclarationOrFunctionDefinition (test.cc:16:1) |
238 | | | ParseFunctionDefinition (slow_test) |
239 | | | | EvaluateAsInitializer (slow_value) |
240 | | | | EvaluateAsConstantExpr (<test.cc:17:33, col:59>) |
241 | | | | EvaluateAsConstantExpr (<test.cc:18:11, col:37>) |
242 | | ParseDeclarationOrFunctionDefinition (test.cc:22:1) |
243 | | | EvaluateAsConstantExpr (<test.cc:23:31, col:57>) |
244 | | | EvaluateAsRValue (<test.cc:22:14, line:23:58>) |
245 | | ParseDeclarationOrFunctionDefinition (test.cc:25:1) |
246 | | | EvaluateAsInitializer (slow_init_list) |
247 | | PerformPendingInstantiations |
248 | )" , |
249 | buildTraceGraph(Json)); |
250 | } |
251 | |
252 | TEST(TimeProfilerTest, ClassTemplateInstantiations) { |
253 | std::string Code = R"( |
254 | template<class T> |
255 | struct S |
256 | { |
257 | void foo() {} |
258 | void bar(); |
259 | }; |
260 | |
261 | template struct S<double>; // explicit instantiation of S<double> |
262 | |
263 | void user() { |
264 | S<int> a; // implicit instantiation of S<int> |
265 | S<float>* b; |
266 | b->foo(); // implicit instatiation of S<float> and S<float>::foo() |
267 | } |
268 | )" ; |
269 | |
270 | setupProfiler(); |
271 | ASSERT_TRUE(compileFromString(Code, "-std=c++20" , "test.cc" )); |
272 | std::string Json = teardownProfiler(); |
273 | ASSERT_EQ(R"( |
274 | Frontend (test.cc) |
275 | | ParseClass (S) |
276 | | InstantiateClass (S<double>, test.cc:9) |
277 | | InstantiateFunction (S<double>::foo, test.cc:5) |
278 | | ParseDeclarationOrFunctionDefinition (test.cc:11:5) |
279 | | | ParseFunctionDefinition (user) |
280 | | | | InstantiateClass (S<int>, test.cc:3) |
281 | | | | InstantiateClass (S<float>, test.cc:3) |
282 | | | | DeferInstantiation (S<float>::foo) |
283 | | PerformPendingInstantiations |
284 | | | InstantiateFunction (S<float>::foo, test.cc:5) |
285 | )" , |
286 | buildTraceGraph(Json)); |
287 | } |
288 | |
289 | TEST(TimeProfilerTest, TemplateInstantiations) { |
290 | std::string B_H = R"( |
291 | template <typename T> |
292 | T fooC(T t) { |
293 | return T(); |
294 | } |
295 | |
296 | template <typename T> |
297 | constexpr T fooB(T t) { |
298 | return fooC(t); |
299 | } |
300 | |
301 | #define MacroTemp(x) template <typename T> void foo##x(T) { T(); } |
302 | )" ; |
303 | |
304 | std::string A_H = R"( |
305 | #include "b.h" |
306 | |
307 | MacroTemp(MTA) |
308 | |
309 | template <typename T> |
310 | void fooA(T t) { fooB(t); fooMTA(t); } |
311 | )" ; |
312 | std::string Code = R"( |
313 | #include "a.h" |
314 | void user() { fooA(0); } |
315 | )" ; |
316 | |
317 | setupProfiler(); |
318 | ASSERT_TRUE(compileFromString(Code, "-std=c++20" , "test.cc" , |
319 | /*Headers=*/{{"a.h" , A_H}, {"b.h" , B_H}})); |
320 | std::string Json = teardownProfiler(); |
321 | ASSERT_EQ(R"( |
322 | Frontend (test.cc) |
323 | | ParseFunctionDefinition (fooC) |
324 | | ParseFunctionDefinition (fooB) |
325 | | ParseFunctionDefinition (fooMTA) |
326 | | ParseFunctionDefinition (fooA) |
327 | | ParseDeclarationOrFunctionDefinition (test.cc:3:5) |
328 | | | ParseFunctionDefinition (user) |
329 | | | | DeferInstantiation (fooA<int>) |
330 | | PerformPendingInstantiations |
331 | | | InstantiateFunction (fooA<int>, a.h:7) |
332 | | | | InstantiateFunction (fooB<int>, b.h:8) |
333 | | | | | DeferInstantiation (fooC<int>) |
334 | | | | DeferInstantiation (fooMTA<int>) |
335 | | | | InstantiateFunction (fooC<int>, b.h:3) |
336 | | | | InstantiateFunction (fooMTA<int>, a.h:4) |
337 | )" , |
338 | buildTraceGraph(Json)); |
339 | } |
340 | |
341 | TEST(TimeProfilerTest, ConstantEvaluationC99) { |
342 | std::string Code = R"( |
343 | struct { |
344 | short quantval[4]; // 3rd line |
345 | } value; |
346 | )" ; |
347 | |
348 | setupProfiler(); |
349 | ASSERT_TRUE(compileFromString(Code, "-std=c99" , "test.c" )); |
350 | std::string Json = teardownProfiler(); |
351 | ASSERT_EQ(R"( |
352 | Frontend (test.c) |
353 | | ParseDeclarationOrFunctionDefinition (test.c:2:1) |
354 | | | isIntegerConstantExpr (<test.c:3:18>) |
355 | | | EvaluateKnownConstIntCheckOverflow (<test.c:3:18>) |
356 | | PerformPendingInstantiations |
357 | )" , |
358 | buildTraceGraph(Json)); |
359 | } |
360 | |