1//===- xray-stacks.cpp: XRay Function Call Stack Accounting ---------------===//
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 stack-based accounting. It takes XRay traces, and
10// collates statistics across these traces to show a breakdown of time spent
11// at various points of the stack to provide insight into which functions
12// spend the most time in terms of a call stack. We provide a few
13// sorting/filtering options for zero'ing in on the useful stacks.
14//
15//===----------------------------------------------------------------------===//
16
17#include <forward_list>
18#include <numeric>
19
20#include "func-id-helper.h"
21#include "trie-node.h"
22#include "xray-registry.h"
23#include "llvm/ADT/StringExtras.h"
24#include "llvm/Support/CommandLine.h"
25#include "llvm/Support/Errc.h"
26#include "llvm/Support/ErrorHandling.h"
27#include "llvm/Support/FormatAdapters.h"
28#include "llvm/Support/FormatVariadic.h"
29#include "llvm/XRay/Graph.h"
30#include "llvm/XRay/InstrumentationMap.h"
31#include "llvm/XRay/Trace.h"
32
33using namespace llvm;
34using namespace llvm::xray;
35
36static cl::SubCommand Stack("stack", "Call stack accounting");
37static cl::list<std::string> StackInputs(cl::Positional,
38 cl::desc("<xray trace>"), cl::Required,
39 cl::sub(Stack), cl::OneOrMore);
40
41static cl::opt<bool>
42 StackKeepGoing("keep-going", cl::desc("Keep going on errors encountered"),
43 cl::sub(Stack), cl::init(Val: false));
44static cl::alias StackKeepGoing2("k", cl::aliasopt(StackKeepGoing),
45 cl::desc("Alias for -keep-going"));
46
47// TODO: Does there need to be an option to deduce tail or sibling calls?
48
49static cl::opt<std::string> StacksInstrMap(
50 "instr_map",
51 cl::desc("instrumentation map used to identify function ids. "
52 "Currently supports elf file instrumentation maps."),
53 cl::sub(Stack), cl::init(Val: ""));
54static cl::alias StacksInstrMap2("m", cl::aliasopt(StacksInstrMap),
55 cl::desc("Alias for -instr_map"));
56
57static cl::opt<bool>
58 SeparateThreadStacks("per-thread-stacks",
59 cl::desc("Report top stacks within each thread id"),
60 cl::sub(Stack), cl::init(Val: false));
61
62static cl::opt<bool>
63 AggregateThreads("aggregate-threads",
64 cl::desc("Aggregate stack times across threads"),
65 cl::sub(Stack), cl::init(Val: false));
66
67static cl::opt<bool>
68 DumpAllStacks("all-stacks",
69 cl::desc("Dump sum of timings for all stacks. "
70 "By default separates stacks per-thread."),
71 cl::sub(Stack), cl::init(Val: false));
72static cl::alias DumpAllStacksShort("all", cl::aliasopt(DumpAllStacks),
73 cl::desc("Alias for -all-stacks"));
74
75// TODO(kpw): Add other interesting formats. Perhaps chrome trace viewer format
76// possibly with aggregations or just a linear trace of timings.
77enum StackOutputFormat { HUMAN, FLAMETOOL };
78
79static cl::opt<StackOutputFormat> StacksOutputFormat(
80 "stack-format",
81 cl::desc("The format that output stacks should be "
82 "output in. Only applies with all-stacks."),
83 cl::values(
84 clEnumValN(HUMAN, "human",
85 "Human readable output. Only valid without -all-stacks."),
86 clEnumValN(FLAMETOOL, "flame",
87 "Format consumable by Brendan Gregg's FlameGraph tool. "
88 "Only valid with -all-stacks.")),
89 cl::sub(Stack), cl::init(Val: HUMAN));
90
91// Types of values for each stack in a CallTrie.
92enum class AggregationType {
93 TOTAL_TIME, // The total time spent in a stack and its callees.
94 INVOCATION_COUNT // The number of times the stack was invoked.
95};
96
97static cl::opt<AggregationType> RequestedAggregation(
98 "aggregation-type",
99 cl::desc("The type of aggregation to do on call stacks."),
100 cl::values(
101 clEnumValN(
102 AggregationType::TOTAL_TIME, "time",
103 "Capture the total time spent in an all invocations of a stack."),
104 clEnumValN(AggregationType::INVOCATION_COUNT, "count",
105 "Capture the number of times a stack was invoked. "
106 "In flamegraph mode, this count also includes invocations "
107 "of all callees.")),
108 cl::sub(Stack), cl::init(Val: AggregationType::TOTAL_TIME));
109
110namespace {
111
112/// A helper struct to work with formatv and XRayRecords. Makes it easier to
113/// use instrumentation map names or addresses in formatted output.
114struct format_xray_record : public FormatAdapter<XRayRecord> {
115 explicit format_xray_record(XRayRecord record,
116 const FuncIdConversionHelper &conv)
117 : FormatAdapter<XRayRecord>(std::move(record)), Converter(&conv) {}
118 void format(raw_ostream &Stream, StringRef Style) override {
119 Stream << formatv(
120 Fmt: "{FuncId: \"{0}\", ThreadId: \"{1}\", RecordType: \"{2}\"}",
121 Vals: Converter->SymbolOrNumber(FuncId: Item.FuncId), Vals&: Item.TId,
122 Vals: DecodeRecordType(recordType: Item.RecordType));
123 }
124
125private:
126 Twine DecodeRecordType(uint16_t recordType) {
127 switch (recordType) {
128 case 0:
129 return Twine("Fn Entry");
130 case 1:
131 return Twine("Fn Exit");
132 default:
133 // TODO: Add Tail exit when it is added to llvm/XRay/XRayRecord.h
134 return Twine("Unknown");
135 }
136 }
137
138 const FuncIdConversionHelper *Converter;
139};
140
141/// The stack command will take a set of XRay traces as arguments, and collects
142/// information about the stacks of instrumented functions that appear in the
143/// traces. We track the following pieces of information:
144///
145/// - Total time: amount of time/cycles accounted for in the traces.
146/// - Stack count: number of times a specific stack appears in the
147/// traces. Only instrumented functions show up in stacks.
148/// - Cumulative stack time: amount of time spent in a stack accumulated
149/// across the invocations in the traces.
150/// - Cumulative local time: amount of time spent in each instrumented
151/// function showing up in a specific stack, accumulated across the traces.
152///
153/// Example output for the kind of data we'd like to provide looks like the
154/// following:
155///
156/// Total time: 3.33234 s
157/// Stack ID: ...
158/// Stack Count: 2093
159/// # Function Local Time (%) Stack Time (%)
160/// 0 main 2.34 ms 0.07% 3.33234 s 100%
161/// 1 foo() 3.30000 s 99.02% 3.33 s 99.92%
162/// 2 bar() 30 ms 0.90% 30 ms 0.90%
163///
164/// We can also show distributions of the function call durations with
165/// statistics at each level of the stack. This works by doing the following
166/// algorithm:
167///
168/// 1. When unwinding, record the duration of each unwound function associated
169/// with the path up to which the unwinding stops. For example:
170///
171/// Step Duration (? means has start time)
172///
173/// push a <start time> a = ?
174/// push b <start time> a = ?, a->b = ?
175/// push c <start time> a = ?, a->b = ?, a->b->c = ?
176/// pop c <end time> a = ?, a->b = ?, emit duration(a->b->c)
177/// pop b <end time> a = ?, emit duration(a->b)
178/// push c <start time> a = ?, a->c = ?
179/// pop c <end time> a = ?, emit duration(a->c)
180/// pop a <end time> emit duration(a)
181///
182/// 2. We then account for the various stacks we've collected, and for each of
183/// them will have measurements that look like the following (continuing
184/// with the above simple example):
185///
186/// c : [<id("a->b->c"), [durations]>, <id("a->c"), [durations]>]
187/// b : [<id("a->b"), [durations]>]
188/// a : [<id("a"), [durations]>]
189///
190/// This allows us to compute, for each stack id, and each function that
191/// shows up in the stack, some important statistics like:
192///
193/// - median
194/// - 99th percentile
195/// - mean + stddev
196/// - count
197///
198/// 3. For cases where we don't have durations for some of the higher levels
199/// of the stack (perhaps instrumentation wasn't activated when the stack was
200/// entered), we can mark them appropriately.
201///
202/// Computing this data also allows us to implement lookup by call stack nodes,
203/// so that we can find functions that show up in multiple stack traces and
204/// show the statistical properties of that function in various contexts. We
205/// can compute information similar to the following:
206///
207/// Function: 'c'
208/// Stacks: 2 / 2
209/// Stack ID: ...
210/// Stack Count: ...
211/// # Function ...
212/// 0 a ...
213/// 1 b ...
214/// 2 c ...
215///
216/// Stack ID: ...
217/// Stack Count: ...
218/// # Function ...
219/// 0 a ...
220/// 1 c ...
221/// ----------------...
222///
223/// Function: 'b'
224/// Stacks: 1 / 2
225/// Stack ID: ...
226/// Stack Count: ...
227/// # Function ...
228/// 0 a ...
229/// 1 b ...
230/// 2 c ...
231///
232///
233/// To do this we require a Trie data structure that will allow us to represent
234/// all the call stacks of instrumented functions in an easily traversible
235/// manner when we do the aggregations and lookups. For instrumented call
236/// sequences like the following:
237///
238/// a()
239/// b()
240/// c()
241/// d()
242/// c()
243///
244/// We will have a representation like so:
245///
246/// a -> b -> c
247/// | |
248/// | +--> d
249/// |
250/// +--> c
251///
252/// We maintain a sequence of durations on the leaves and in the internal nodes
253/// as we go through and process every record from the XRay trace. We also
254/// maintain an index of unique functions, and provide a means of iterating
255/// through all the instrumented call stacks which we know about.
256
257struct StackDuration {
258 SmallVector<int64_t, 4> TerminalDurations;
259 SmallVector<int64_t, 4> IntermediateDurations;
260};
261} // namespace
262
263static StackDuration mergeStackDuration(const StackDuration &Left,
264 const StackDuration &Right) {
265 StackDuration Data{};
266 Data.TerminalDurations.reserve(N: Left.TerminalDurations.size() +
267 Right.TerminalDurations.size());
268 Data.IntermediateDurations.reserve(N: Left.IntermediateDurations.size() +
269 Right.IntermediateDurations.size());
270 // Aggregate the durations.
271 llvm::append_range(C&: Data.TerminalDurations, R: Left.TerminalDurations);
272 llvm::append_range(C&: Data.TerminalDurations, R: Right.TerminalDurations);
273
274 llvm::append_range(C&: Data.IntermediateDurations, R: Left.IntermediateDurations);
275 llvm::append_range(C&: Data.IntermediateDurations, R: Right.IntermediateDurations);
276 return Data;
277}
278
279using StackTrieNode = TrieNode<StackDuration>;
280
281template <AggregationType AggType>
282static std::size_t GetValueForStack(const StackTrieNode *Node);
283
284// When computing total time spent in a stack, we're adding the timings from
285// its callees and the timings from when it was a leaf.
286template <>
287std::size_t
288GetValueForStack<AggregationType::TOTAL_TIME>(const StackTrieNode *Node) {
289 auto TopSum = std::accumulate(first: Node->ExtraData.TerminalDurations.begin(),
290 last: Node->ExtraData.TerminalDurations.end(), init: 0uLL);
291 return std::accumulate(first: Node->ExtraData.IntermediateDurations.begin(),
292 last: Node->ExtraData.IntermediateDurations.end(), init: TopSum);
293}
294
295// Calculates how many times a function was invoked.
296// TODO: Hook up option to produce stacks
297template <>
298std::size_t
299GetValueForStack<AggregationType::INVOCATION_COUNT>(const StackTrieNode *Node) {
300 return Node->ExtraData.TerminalDurations.size() +
301 Node->ExtraData.IntermediateDurations.size();
302}
303
304// Make sure there are implementations for each enum value.
305template <AggregationType T> struct DependentFalseType : std::false_type {};
306
307template <AggregationType AggType>
308std::size_t GetValueForStack(const StackTrieNode *Node) {
309 static_assert(DependentFalseType<AggType>::value,
310 "No implementation found for aggregation type provided.");
311 return 0;
312}
313
314namespace {
315class StackTrie {
316 // Avoid the magic number of 4 propagated through the code with an alias.
317 // We use this SmallVector to track the root nodes in a call graph.
318 using RootVector = SmallVector<StackTrieNode *, 4>;
319
320 // We maintain pointers to the roots of the tries we see.
321 DenseMap<uint32_t, RootVector> Roots;
322
323 // We make sure all the nodes are accounted for in this list.
324 std::forward_list<StackTrieNode> NodeStore;
325
326 // A map of thread ids to pairs call stack trie nodes and their start times.
327 DenseMap<uint32_t, SmallVector<std::pair<StackTrieNode *, uint64_t>, 8>>
328 ThreadStackMap;
329
330 StackTrieNode *createTrieNode(uint32_t ThreadId, int32_t FuncId,
331 StackTrieNode *Parent) {
332 NodeStore.push_front(val: StackTrieNode{.FuncId: FuncId, .Parent: Parent, .Callees: {}, .ExtraData: {.TerminalDurations: {}, .IntermediateDurations: {}}});
333 auto I = NodeStore.begin();
334 auto *Node = &*I;
335 if (!Parent)
336 Roots[ThreadId].push_back(Elt: Node);
337 return Node;
338 }
339
340 StackTrieNode *findRootNode(uint32_t ThreadId, int32_t FuncId) {
341 const auto &RootsByThread = Roots[ThreadId];
342 auto I = find_if(Range: RootsByThread,
343 P: [&](StackTrieNode *N) { return N->FuncId == FuncId; });
344 return (I == RootsByThread.end()) ? nullptr : *I;
345 }
346
347public:
348 enum class AccountRecordStatus {
349 OK, // Successfully processed
350 ENTRY_NOT_FOUND, // An exit record had no matching call stack entry
351 UNKNOWN_RECORD_TYPE
352 };
353
354 struct AccountRecordState {
355 // We keep track of whether the call stack is currently unwinding.
356 bool wasLastRecordExit;
357
358 static AccountRecordState CreateInitialState() { return {.wasLastRecordExit: false}; }
359 };
360
361 AccountRecordStatus accountRecord(const XRayRecord &R,
362 AccountRecordState *state) {
363 auto &TS = ThreadStackMap[R.TId];
364 switch (R.Type) {
365 case RecordTypes::CUSTOM_EVENT:
366 case RecordTypes::TYPED_EVENT:
367 return AccountRecordStatus::OK;
368 case RecordTypes::ENTER:
369 case RecordTypes::ENTER_ARG: {
370 state->wasLastRecordExit = false;
371 // When we encounter a new function entry, we want to record the TSC for
372 // that entry, and the function id. Before doing so we check the top of
373 // the stack to see if there are callees that already represent this
374 // function.
375 if (TS.empty()) {
376 auto *Root = findRootNode(ThreadId: R.TId, FuncId: R.FuncId);
377 TS.emplace_back(Args: Root ? Root : createTrieNode(ThreadId: R.TId, FuncId: R.FuncId, Parent: nullptr),
378 Args: R.TSC);
379 return AccountRecordStatus::OK;
380 }
381
382 auto &Top = TS.back();
383 auto I = find_if(Range&: Top.first->Callees,
384 P: [&](StackTrieNode *N) { return N->FuncId == R.FuncId; });
385 if (I == Top.first->Callees.end()) {
386 // We didn't find the callee in the stack trie, so we're going to
387 // add to the stack then set up the pointers properly.
388 auto N = createTrieNode(ThreadId: R.TId, FuncId: R.FuncId, Parent: Top.first);
389 Top.first->Callees.emplace_back(Args&: N);
390
391 // Top may be invalidated after this statement.
392 TS.emplace_back(Args&: N, Args: R.TSC);
393 } else {
394 // We found the callee in the stack trie, so we'll use that pointer
395 // instead, add it to the stack associated with the TSC.
396 TS.emplace_back(Args&: *I, Args: R.TSC);
397 }
398 return AccountRecordStatus::OK;
399 }
400 case RecordTypes::EXIT:
401 case RecordTypes::TAIL_EXIT: {
402 bool wasLastRecordExit = state->wasLastRecordExit;
403 state->wasLastRecordExit = true;
404 // The exit case is more interesting, since we want to be able to deduce
405 // missing exit records. To do that properly, we need to look up the stack
406 // and see whether the exit record matches any of the entry records. If it
407 // does match, we attempt to record the durations as we pop the stack to
408 // where we see the parent.
409 if (TS.empty()) {
410 // Short circuit, and say we can't find it.
411
412 return AccountRecordStatus::ENTRY_NOT_FOUND;
413 }
414
415 auto FunctionEntryMatch = find_if(
416 Range: reverse(C&: TS), P: [&](const std::pair<StackTrieNode *, uint64_t> &E) {
417 return E.first->FuncId == R.FuncId;
418 });
419 auto status = AccountRecordStatus::OK;
420 if (FunctionEntryMatch == TS.rend()) {
421 status = AccountRecordStatus::ENTRY_NOT_FOUND;
422 } else {
423 // Account for offset of 1 between reverse and forward iterators. We
424 // want the forward iterator to include the function that is exited.
425 ++FunctionEntryMatch;
426 }
427 auto I = FunctionEntryMatch.base();
428 for (auto &E : make_range(x: I, y: TS.end() - 1))
429 E.first->ExtraData.IntermediateDurations.push_back(
430 Elt: std::max(a: E.second, b: R.TSC) - std::min(a: E.second, b: R.TSC));
431 auto &Deepest = TS.back();
432 if (wasLastRecordExit)
433 Deepest.first->ExtraData.IntermediateDurations.push_back(
434 Elt: std::max(a: Deepest.second, b: R.TSC) - std::min(a: Deepest.second, b: R.TSC));
435 else
436 Deepest.first->ExtraData.TerminalDurations.push_back(
437 Elt: std::max(a: Deepest.second, b: R.TSC) - std::min(a: Deepest.second, b: R.TSC));
438 TS.erase(CS: I, CE: TS.end());
439 return status;
440 }
441 }
442 return AccountRecordStatus::UNKNOWN_RECORD_TYPE;
443 }
444
445 bool isEmpty() const { return Roots.empty(); }
446
447 void printStack(raw_ostream &OS, const StackTrieNode *Top,
448 FuncIdConversionHelper &FN) {
449 // Traverse the pointers up to the parent, noting the sums, then print
450 // in reverse order (callers at top, callees down bottom).
451 SmallVector<const StackTrieNode *, 8> CurrentStack;
452 for (auto *F = Top; F != nullptr; F = F->Parent)
453 CurrentStack.push_back(Elt: F);
454 int Level = 0;
455 OS << formatv(Fmt: "{0,-5} {1,-60} {2,+12} {3,+16}\n", Vals: "lvl", Vals: "function",
456 Vals: "count", Vals: "sum");
457 for (auto *F : reverse(C: drop_begin(RangeOrContainer&: CurrentStack))) {
458 auto Sum = std::accumulate(first: F->ExtraData.IntermediateDurations.begin(),
459 last: F->ExtraData.IntermediateDurations.end(), init: 0LL);
460 auto FuncId = FN.SymbolOrNumber(FuncId: F->FuncId);
461 OS << formatv(Fmt: "#{0,-4} {1,-60} {2,+12} {3,+16}\n", Vals: Level++,
462 Vals: FuncId.size() > 60 ? FuncId.substr(pos: 0, n: 57) + "..." : FuncId,
463 Vals: F->ExtraData.IntermediateDurations.size(), Vals&: Sum);
464 }
465 auto *Leaf = *CurrentStack.begin();
466 auto LeafSum =
467 std::accumulate(first: Leaf->ExtraData.TerminalDurations.begin(),
468 last: Leaf->ExtraData.TerminalDurations.end(), init: 0LL);
469 auto LeafFuncId = FN.SymbolOrNumber(FuncId: Leaf->FuncId);
470 OS << formatv(Fmt: "#{0,-4} {1,-60} {2,+12} {3,+16}\n", Vals: Level++,
471 Vals: LeafFuncId.size() > 60 ? LeafFuncId.substr(pos: 0, n: 57) + "..."
472 : LeafFuncId,
473 Vals: Leaf->ExtraData.TerminalDurations.size(), Vals&: LeafSum);
474 OS << "\n";
475 }
476
477 /// Prints top stacks for each thread.
478 void printPerThread(raw_ostream &OS, FuncIdConversionHelper &FN) {
479 for (const auto &iter : Roots) {
480 OS << "Thread " << iter.first << ":\n";
481 print(OS, FN, RootValues: iter.second);
482 OS << "\n";
483 }
484 }
485
486 /// Prints timing sums for each stack in each threads.
487 template <AggregationType AggType>
488 void printAllPerThread(raw_ostream &OS, FuncIdConversionHelper &FN,
489 StackOutputFormat format) {
490 for (const auto &iter : Roots)
491 printAll<AggType>(OS, FN, iter.second, iter.first, true);
492 }
493
494 /// Prints top stacks from looking at all the leaves and ignoring thread IDs.
495 /// Stacks that consist of the same function IDs but were called in different
496 /// thread IDs are not considered unique in this printout.
497 void printIgnoringThreads(raw_ostream &OS, FuncIdConversionHelper &FN) {
498 RootVector RootValues;
499
500 for (const auto &RootNodeRange : make_second_range(c&: Roots))
501 llvm::append_range(C&: RootValues, R: RootNodeRange);
502
503 print(OS, FN, RootValues);
504 }
505
506 /// Creates a merged list of Tries for unique stacks that disregards their
507 /// thread IDs.
508 RootVector mergeAcrossThreads(std::forward_list<StackTrieNode> &NodeStore) {
509 RootVector MergedByThreadRoots;
510 for (const auto &MapIter : Roots) {
511 const auto &RootNodeVector = MapIter.second;
512 for (auto *Node : RootNodeVector) {
513 auto MaybeFoundIter =
514 find_if(Range&: MergedByThreadRoots, P: [Node](StackTrieNode *elem) {
515 return Node->FuncId == elem->FuncId;
516 });
517 if (MaybeFoundIter == MergedByThreadRoots.end()) {
518 MergedByThreadRoots.push_back(Elt: Node);
519 } else {
520 MergedByThreadRoots.push_back(Elt: mergeTrieNodes(
521 Left: **MaybeFoundIter, Right: *Node, NewParent: nullptr, NodeStore, MergeCallable&: mergeStackDuration));
522 MergedByThreadRoots.erase(CI: MaybeFoundIter);
523 }
524 }
525 }
526 return MergedByThreadRoots;
527 }
528
529 /// Print timing sums for all stacks merged by Thread ID.
530 template <AggregationType AggType>
531 void printAllAggregatingThreads(raw_ostream &OS, FuncIdConversionHelper &FN,
532 StackOutputFormat format) {
533 std::forward_list<StackTrieNode> AggregatedNodeStore;
534 RootVector MergedByThreadRoots = mergeAcrossThreads(NodeStore&: AggregatedNodeStore);
535 bool reportThreadId = false;
536 printAll<AggType>(OS, FN, MergedByThreadRoots,
537 /*threadId*/ 0, reportThreadId);
538 }
539
540 /// Merges the trie by thread id before printing top stacks.
541 void printAggregatingThreads(raw_ostream &OS, FuncIdConversionHelper &FN) {
542 std::forward_list<StackTrieNode> AggregatedNodeStore;
543 RootVector MergedByThreadRoots = mergeAcrossThreads(NodeStore&: AggregatedNodeStore);
544 print(OS, FN, RootValues: MergedByThreadRoots);
545 }
546
547 // TODO: Add a format option when more than one are supported.
548 template <AggregationType AggType>
549 void printAll(raw_ostream &OS, FuncIdConversionHelper &FN,
550 RootVector RootValues, uint32_t ThreadId, bool ReportThread) {
551 SmallVector<const StackTrieNode *, 16> S;
552 for (const auto *N : RootValues) {
553 S.clear();
554 S.push_back(Elt: N);
555 while (!S.empty()) {
556 auto *Top = S.pop_back_val();
557 printSingleStack<AggType>(OS, FN, ReportThread, ThreadId, Top);
558 llvm::append_range(C&: S, R: Top->Callees);
559 }
560 }
561 }
562
563 /// Prints values for stacks in a format consumable for the flamegraph.pl
564 /// tool. This is a line based format that lists each level in the stack
565 /// hierarchy in a semicolon delimited form followed by a space and a numeric
566 /// value. If breaking down by thread, the thread ID will be added as the
567 /// root level of the stack.
568 template <AggregationType AggType>
569 void printSingleStack(raw_ostream &OS, FuncIdConversionHelper &Converter,
570 bool ReportThread, uint32_t ThreadId,
571 const StackTrieNode *Node) {
572 if (ReportThread)
573 OS << "thread_" << ThreadId << ";";
574 SmallVector<const StackTrieNode *, 5> lineage{};
575 lineage.push_back(Elt: Node);
576 while (lineage.back()->Parent != nullptr)
577 lineage.push_back(Elt: lineage.back()->Parent);
578 while (!lineage.empty()) {
579 OS << Converter.SymbolOrNumber(FuncId: lineage.back()->FuncId) << ";";
580 lineage.pop_back();
581 }
582 OS << " " << GetValueForStack<AggType>(Node) << "\n";
583 }
584
585 void print(raw_ostream &OS, FuncIdConversionHelper &FN,
586 RootVector RootValues) {
587 // Go through each of the roots, and traverse the call stack, producing the
588 // aggregates as you go along. Remember these aggregates and stacks, and
589 // show summary statistics about:
590 //
591 // - Total number of unique stacks
592 // - Top 10 stacks by count
593 // - Top 10 stacks by aggregate duration
594 SmallVector<std::pair<const StackTrieNode *, uint64_t>, 11>
595 TopStacksByCount;
596 SmallVector<std::pair<const StackTrieNode *, uint64_t>, 11> TopStacksBySum;
597 auto greater_second =
598 [](const std::pair<const StackTrieNode *, uint64_t> &A,
599 const std::pair<const StackTrieNode *, uint64_t> &B) {
600 return A.second > B.second;
601 };
602 uint64_t UniqueStacks = 0;
603 for (const auto *N : RootValues) {
604 SmallVector<const StackTrieNode *, 16> S;
605 S.emplace_back(Args&: N);
606
607 while (!S.empty()) {
608 auto *Top = S.pop_back_val();
609
610 // We only start printing the stack (by walking up the parent pointers)
611 // when we get to a leaf function.
612 if (!Top->ExtraData.TerminalDurations.empty()) {
613 ++UniqueStacks;
614 auto TopSum =
615 std::accumulate(first: Top->ExtraData.TerminalDurations.begin(),
616 last: Top->ExtraData.TerminalDurations.end(), init: 0uLL);
617 {
618 auto E = std::make_pair(x&: Top, y&: TopSum);
619 TopStacksBySum.insert(
620 I: llvm::lower_bound(Range&: TopStacksBySum, Value&: E, C: greater_second), Elt: E);
621 if (TopStacksBySum.size() == 11)
622 TopStacksBySum.pop_back();
623 }
624 {
625 auto E =
626 std::make_pair(x&: Top, y: Top->ExtraData.TerminalDurations.size());
627 TopStacksByCount.insert(
628 I: llvm::lower_bound(Range&: TopStacksByCount, Value&: E, C: greater_second), Elt: E);
629 if (TopStacksByCount.size() == 11)
630 TopStacksByCount.pop_back();
631 }
632 }
633 llvm::append_range(C&: S, R: Top->Callees);
634 }
635 }
636
637 // Now print the statistics in the end.
638 OS << "\n";
639 OS << "Unique Stacks: " << UniqueStacks << "\n";
640 OS << "Top 10 Stacks by leaf sum:\n\n";
641 for (const auto &P : TopStacksBySum) {
642 OS << "Sum: " << P.second << "\n";
643 printStack(OS, Top: P.first, FN);
644 }
645 OS << "\n";
646 OS << "Top 10 Stacks by leaf count:\n\n";
647 for (const auto &P : TopStacksByCount) {
648 OS << "Count: " << P.second << "\n";
649 printStack(OS, Top: P.first, FN);
650 }
651 OS << "\n";
652 }
653};
654} // namespace
655
656static std::string CreateErrorMessage(StackTrie::AccountRecordStatus Error,
657 const XRayRecord &Record,
658 const FuncIdConversionHelper &Converter) {
659 switch (Error) {
660 case StackTrie::AccountRecordStatus::ENTRY_NOT_FOUND:
661 return std::string(
662 formatv(Fmt: "Found record {0} with no matching function entry\n",
663 Vals: format_xray_record(Record, Converter)));
664 default:
665 return std::string(formatv(Fmt: "Unknown error type for record {0}\n",
666 Vals: format_xray_record(Record, Converter)));
667 }
668}
669
670static CommandRegistration Unused(&Stack, []() -> Error {
671 // Load each file provided as a command-line argument. For each one of them
672 // account to a single StackTrie, and just print the whole trie for now.
673 StackTrie ST;
674 InstrumentationMap Map;
675 if (!StacksInstrMap.empty()) {
676 auto InstrumentationMapOrError = loadInstrumentationMap(Filename: StacksInstrMap);
677 if (!InstrumentationMapOrError)
678 return joinErrors(
679 E1: make_error<StringError>(
680 Args: Twine("Cannot open instrumentation map: ") + StacksInstrMap,
681 Args: std::make_error_code(e: std::errc::invalid_argument)),
682 E2: InstrumentationMapOrError.takeError());
683 Map = std::move(*InstrumentationMapOrError);
684 }
685
686 if (SeparateThreadStacks && AggregateThreads)
687 return make_error<StringError>(
688 Args: Twine("Can't specify options for per thread reporting and reporting "
689 "that aggregates threads."),
690 Args: std::make_error_code(e: std::errc::invalid_argument));
691
692 if (!DumpAllStacks && StacksOutputFormat != HUMAN)
693 return make_error<StringError>(
694 Args: Twine("Can't specify a non-human format without -all-stacks."),
695 Args: std::make_error_code(e: std::errc::invalid_argument));
696
697 if (DumpAllStacks && StacksOutputFormat == HUMAN)
698 return make_error<StringError>(
699 Args: Twine("You must specify a non-human format when reporting with "
700 "-all-stacks."),
701 Args: std::make_error_code(e: std::errc::invalid_argument));
702
703 symbolize::LLVMSymbolizer Symbolizer;
704 FuncIdConversionHelper FuncIdHelper(StacksInstrMap, Symbolizer,
705 Map.getFunctionAddresses());
706 // TODO: Someday, support output to files instead of just directly to
707 // standard output.
708 for (const auto &Filename : StackInputs) {
709 auto TraceOrErr = loadTraceFile(Filename);
710 if (!TraceOrErr) {
711 if (!StackKeepGoing)
712 return joinErrors(
713 E1: make_error<StringError>(
714 Args: Twine("Failed loading input file '") + Filename + "'",
715 Args: std::make_error_code(e: std::errc::invalid_argument)),
716 E2: TraceOrErr.takeError());
717 logAllUnhandledErrors(E: TraceOrErr.takeError(), OS&: errs());
718 continue;
719 }
720 auto &T = *TraceOrErr;
721 StackTrie::AccountRecordState AccountRecordState =
722 StackTrie::AccountRecordState::CreateInitialState();
723 for (const auto &Record : T) {
724 auto error = ST.accountRecord(R: Record, state: &AccountRecordState);
725 if (error != StackTrie::AccountRecordStatus::OK) {
726 if (!StackKeepGoing)
727 return make_error<StringError>(
728 Args: CreateErrorMessage(Error: error, Record, Converter: FuncIdHelper),
729 Args: make_error_code(E: errc::illegal_byte_sequence));
730 errs() << CreateErrorMessage(Error: error, Record, Converter: FuncIdHelper);
731 }
732 }
733 }
734 if (ST.isEmpty()) {
735 return make_error<StringError>(
736 Args: "No instrumented calls were accounted in the input file.",
737 Args: make_error_code(E: errc::result_out_of_range));
738 }
739
740 // Report the stacks in a long form mode for another tool to analyze.
741 if (DumpAllStacks) {
742 if (AggregateThreads) {
743 switch (RequestedAggregation) {
744 case AggregationType::TOTAL_TIME:
745 ST.printAllAggregatingThreads<AggregationType::TOTAL_TIME>(
746 OS&: outs(), FN&: FuncIdHelper, format: StacksOutputFormat);
747 break;
748 case AggregationType::INVOCATION_COUNT:
749 ST.printAllAggregatingThreads<AggregationType::INVOCATION_COUNT>(
750 OS&: outs(), FN&: FuncIdHelper, format: StacksOutputFormat);
751 break;
752 }
753 } else {
754 switch (RequestedAggregation) {
755 case AggregationType::TOTAL_TIME:
756 ST.printAllPerThread<AggregationType::TOTAL_TIME>(OS&: outs(), FN&: FuncIdHelper,
757 format: StacksOutputFormat);
758 break;
759 case AggregationType::INVOCATION_COUNT:
760 ST.printAllPerThread<AggregationType::INVOCATION_COUNT>(
761 OS&: outs(), FN&: FuncIdHelper, format: StacksOutputFormat);
762 break;
763 }
764 }
765 return Error::success();
766 }
767
768 // We're only outputting top stacks.
769 if (AggregateThreads) {
770 ST.printAggregatingThreads(OS&: outs(), FN&: FuncIdHelper);
771 } else if (SeparateThreadStacks) {
772 ST.printPerThread(OS&: outs(), FN&: FuncIdHelper);
773 } else {
774 ST.printIgnoringThreads(OS&: outs(), FN&: FuncIdHelper);
775 }
776 return Error::success();
777});
778