xray-converter.cpp revision 341825 
1//===- xray-converter.cpp: XRay Trace Conversion --------------------------===//
2//
3//                     The LLVM Compiler Infrastructure
4//
5// This file is distributed under the University of Illinois Open Source
6// License. See LICENSE.TXT for details.
7//
8//===----------------------------------------------------------------------===//
9//
10// Implements the trace conversion functions.
11//
12//===----------------------------------------------------------------------===//
13#include "xray-converter.h"
14
15#include "trie-node.h"
16#include "xray-registry.h"
17#include "llvm/DebugInfo/Symbolize/Symbolize.h"
18#include "llvm/Support/EndianStream.h"
19#include "llvm/Support/FileSystem.h"
20#include "llvm/Support/FormatVariadic.h"
21#include "llvm/Support/ScopedPrinter.h"
22#include "llvm/Support/YAMLTraits.h"
23#include "llvm/Support/raw_ostream.h"
24#include "llvm/XRay/InstrumentationMap.h"
25#include "llvm/XRay/Trace.h"
26#include "llvm/XRay/YAMLXRayRecord.h"
27
28using namespace llvm;
29using namespace xray;
30
31// llvm-xray convert
32// ----------------------------------------------------------------------------
33static cl::SubCommand Convert("convert", "Trace Format Conversion");
34static cl::opt<std::string> ConvertInput(cl::Positional,
35                                         cl::desc("<xray log file>"),
36                                         cl::Required, cl::sub(Convert));
37enum class ConvertFormats { BINARY, YAML, CHROME_TRACE_EVENT };
38static cl::opt<ConvertFormats> ConvertOutputFormat(
39    "output-format", cl::desc("output format"),
40    cl::values(clEnumValN(ConvertFormats::BINARY, "raw", "output in binary"),
41               clEnumValN(ConvertFormats::YAML, "yaml", "output in yaml"),
42               clEnumValN(ConvertFormats::CHROME_TRACE_EVENT, "trace_event",
43                          "Output in chrome's trace event format. "
44                          "May be visualized with the Catapult trace viewer.")),
45    cl::sub(Convert));
46static cl::alias ConvertOutputFormat2("f", cl::aliasopt(ConvertOutputFormat),
47                                      cl::desc("Alias for -output-format"),
48                                      cl::sub(Convert));
49static cl::opt<std::string>
50    ConvertOutput("output", cl::value_desc("output file"), cl::init("-"),
51                  cl::desc("output file; use '-' for stdout"),
52                  cl::sub(Convert));
53static cl::alias ConvertOutput2("o", cl::aliasopt(ConvertOutput),
54                                cl::desc("Alias for -output"),
55                                cl::sub(Convert));
56
57static cl::opt<bool>
58    ConvertSymbolize("symbolize",
59                     cl::desc("symbolize function ids from the input log"),
60                     cl::init(false), cl::sub(Convert));
61static cl::alias ConvertSymbolize2("y", cl::aliasopt(ConvertSymbolize),
62                                   cl::desc("Alias for -symbolize"),
63                                   cl::sub(Convert));
64
65static cl::opt<std::string>
66    ConvertInstrMap("instr_map",
67                    cl::desc("binary with the instrumentation map, or "
68                             "a separate instrumentation map"),
69                    cl::value_desc("binary with xray_instr_map"),
70                    cl::sub(Convert), cl::init(""));
71static cl::alias ConvertInstrMap2("m", cl::aliasopt(ConvertInstrMap),
72                                  cl::desc("Alias for -instr_map"),
73                                  cl::sub(Convert));
74static cl::opt<bool> ConvertSortInput(
75    "sort",
76    cl::desc("determines whether to sort input log records by timestamp"),
77    cl::sub(Convert), cl::init(true));
78static cl::alias ConvertSortInput2("s", cl::aliasopt(ConvertSortInput),
79                                   cl::desc("Alias for -sort"),
80                                   cl::sub(Convert));
81
82using llvm::yaml::Output;
83
84void TraceConverter::exportAsYAML(const Trace &Records, raw_ostream &OS) {
85  YAMLXRayTrace Trace;
86  const auto &FH = Records.getFileHeader();
87  Trace.Header = {FH.Version, FH.Type, FH.ConstantTSC, FH.NonstopTSC,
88                  FH.CycleFrequency};
89  Trace.Records.reserve(Records.size());
90  for (const auto &R : Records) {
91    Trace.Records.push_back({R.RecordType, R.CPU, R.Type, R.FuncId,
92                             Symbolize ? FuncIdHelper.SymbolOrNumber(R.FuncId)
93                                       : llvm::to_string(R.FuncId),
94                             R.TSC, R.TId, R.PId, R.CallArgs});
95  }
96  Output Out(OS, nullptr, 0);
97  Out << Trace;
98}
99
100void TraceConverter::exportAsRAWv1(const Trace &Records, raw_ostream &OS) {
101  // First write out the file header, in the correct endian-appropriate format
102  // (XRay assumes currently little endian).
103  support::endian::Writer Writer(OS, support::endianness::little);
104  const auto &FH = Records.getFileHeader();
105  Writer.write(FH.Version);
106  Writer.write(FH.Type);
107  uint32_t Bitfield{0};
108  if (FH.ConstantTSC)
109    Bitfield |= 1uL;
110  if (FH.NonstopTSC)
111    Bitfield |= 1uL << 1;
112  Writer.write(Bitfield);
113  Writer.write(FH.CycleFrequency);
114
115  // There's 16 bytes of padding at the end of the file header.
116  static constexpr uint32_t Padding4B = 0;
117  Writer.write(Padding4B);
118  Writer.write(Padding4B);
119  Writer.write(Padding4B);
120  Writer.write(Padding4B);
121
122  // Then write out the rest of the records, still in an endian-appropriate
123  // format.
124  for (const auto &R : Records) {
125    Writer.write(R.RecordType);
126    // The on disk naive raw format uses 8 bit CPUs, but the record has 16.
127    // There's no choice but truncation.
128    Writer.write(static_cast<uint8_t>(R.CPU));
129    switch (R.Type) {
130    case RecordTypes::ENTER:
131    case RecordTypes::ENTER_ARG:
132      Writer.write(uint8_t{0});
133      break;
134    case RecordTypes::EXIT:
135      Writer.write(uint8_t{1});
136      break;
137    case RecordTypes::TAIL_EXIT:
138      Writer.write(uint8_t{2});
139      break;
140    }
141    Writer.write(R.FuncId);
142    Writer.write(R.TSC);
143    Writer.write(R.TId);
144
145    if (FH.Version >= 3)
146      Writer.write(R.PId);
147    else
148      Writer.write(Padding4B);
149
150    Writer.write(Padding4B);
151    Writer.write(Padding4B);
152  }
153}
154
155namespace {
156
157// A structure that allows building a dictionary of stack ids for the Chrome
158// trace event format.
159struct StackIdData {
160  // Each Stack of function calls has a unique ID.
161  unsigned id;
162
163  // Bookkeeping so that IDs can be maintained uniquely across threads.
164  // Traversal keeps sibling pointers to other threads stacks. This is helpful
165  // to determine when a thread encounters a new stack and should assign a new
166  // unique ID.
167  SmallVector<TrieNode<StackIdData> *, 4> siblings;
168};
169
170using StackTrieNode = TrieNode<StackIdData>;
171
172// A helper function to find the sibling nodes for an encountered function in a
173// thread of execution. Relies on the invariant that each time a new node is
174// traversed in a thread, sibling bidirectional pointers are maintained.
175SmallVector<StackTrieNode *, 4>
176findSiblings(StackTrieNode *parent, int32_t FnId, uint32_t TId,
177             const DenseMap<uint32_t, SmallVector<StackTrieNode *, 4>>
178                 &StackRootsByThreadId) {
179
180  SmallVector<StackTrieNode *, 4> Siblings{};
181
182  if (parent == nullptr) {
183    for (auto map_iter : StackRootsByThreadId) {
184      // Only look for siblings in other threads.
185      if (map_iter.first != TId)
186        for (auto node_iter : map_iter.second) {
187          if (node_iter->FuncId == FnId)
188            Siblings.push_back(node_iter);
189        }
190    }
191    return Siblings;
192  }
193
194  for (auto *ParentSibling : parent->ExtraData.siblings)
195    for (auto node_iter : ParentSibling->Callees)
196      if (node_iter->FuncId == FnId)
197        Siblings.push_back(node_iter);
198
199  return Siblings;
200}
201
202// Given a function being invoked in a thread with id TId, finds and returns the
203// StackTrie representing the function call stack. If no node exists, creates
204// the node. Assigns unique IDs to stacks newly encountered among all threads
205// and keeps sibling links up to when creating new nodes.
206StackTrieNode *findOrCreateStackNode(
207    StackTrieNode *Parent, int32_t FuncId, uint32_t TId,
208    DenseMap<uint32_t, SmallVector<StackTrieNode *, 4>> &StackRootsByThreadId,
209    DenseMap<unsigned, StackTrieNode *> &StacksByStackId, unsigned *id_counter,
210    std::forward_list<StackTrieNode> &NodeStore) {
211  SmallVector<StackTrieNode *, 4> &ParentCallees =
212      Parent == nullptr ? StackRootsByThreadId[TId] : Parent->Callees;
213  auto match = find_if(ParentCallees, [FuncId](StackTrieNode *ParentCallee) {
214    return FuncId == ParentCallee->FuncId;
215  });
216  if (match != ParentCallees.end())
217    return *match;
218
219  SmallVector<StackTrieNode *, 4> siblings =
220      findSiblings(Parent, FuncId, TId, StackRootsByThreadId);
221  if (siblings.empty()) {
222    NodeStore.push_front({FuncId, Parent, {}, {(*id_counter)++, {}}});
223    StackTrieNode *CurrentStack = &NodeStore.front();
224    StacksByStackId[*id_counter - 1] = CurrentStack;
225    ParentCallees.push_back(CurrentStack);
226    return CurrentStack;
227  }
228  unsigned stack_id = siblings[0]->ExtraData.id;
229  NodeStore.push_front({FuncId, Parent, {}, {stack_id, std::move(siblings)}});
230  StackTrieNode *CurrentStack = &NodeStore.front();
231  for (auto *sibling : CurrentStack->ExtraData.siblings)
232    sibling->ExtraData.siblings.push_back(CurrentStack);
233  ParentCallees.push_back(CurrentStack);
234  return CurrentStack;
235}
236
237void writeTraceViewerRecord(uint16_t Version, raw_ostream &OS, int32_t FuncId,
238                            uint32_t TId, uint32_t PId, bool Symbolize,
239                            const FuncIdConversionHelper &FuncIdHelper,
240                            double EventTimestampUs,
241                            const StackTrieNode &StackCursor,
242                            StringRef FunctionPhenotype) {
243  OS << "    ";
244  if (Version >= 3) {
245    OS << llvm::formatv(
246        R"({ "name" : "{0}", "ph" : "{1}", "tid" : "{2}", "pid" : "{3}", )"
247        R"("ts" : "{4:f4}", "sf" : "{5}" })",
248        (Symbolize ? FuncIdHelper.SymbolOrNumber(FuncId)
249                   : llvm::to_string(FuncId)),
250        FunctionPhenotype, TId, PId, EventTimestampUs,
251        StackCursor.ExtraData.id);
252  } else {
253    OS << llvm::formatv(
254        R"({ "name" : "{0}", "ph" : "{1}", "tid" : "{2}", "pid" : "1", )"
255        R"("ts" : "{3:f3}", "sf" : "{4}" })",
256        (Symbolize ? FuncIdHelper.SymbolOrNumber(FuncId)
257                   : llvm::to_string(FuncId)),
258        FunctionPhenotype, TId, EventTimestampUs, StackCursor.ExtraData.id);
259  }
260}
261
262} // namespace
263
264void TraceConverter::exportAsChromeTraceEventFormat(const Trace &Records,
265                                                    raw_ostream &OS) {
266  const auto &FH = Records.getFileHeader();
267  auto Version = FH.Version;
268  auto CycleFreq = FH.CycleFrequency;
269
270  unsigned id_counter = 0;
271
272  OS << "{\n  \"traceEvents\": [";
273  DenseMap<uint32_t, StackTrieNode *> StackCursorByThreadId{};
274  DenseMap<uint32_t, SmallVector<StackTrieNode *, 4>> StackRootsByThreadId{};
275  DenseMap<unsigned, StackTrieNode *> StacksByStackId{};
276  std::forward_list<StackTrieNode> NodeStore{};
277  int loop_count = 0;
278  for (const auto &R : Records) {
279    if (loop_count++ == 0)
280      OS << "\n";
281    else
282      OS << ",\n";
283
284    // Chrome trace event format always wants data in micros.
285    // CyclesPerMicro = CycleHertz / 10^6
286    // TSC / CyclesPerMicro == TSC * 10^6 / CycleHertz == MicroTimestamp
287    // Could lose some precision here by converting the TSC to a double to
288    // multiply by the period in micros. 52 bit mantissa is a good start though.
289    // TODO: Make feature request to Chrome Trace viewer to accept ticks and a
290    // frequency or do some more involved calculation to avoid dangers of
291    // conversion.
292    double EventTimestampUs = double(1000000) / CycleFreq * double(R.TSC);
293    StackTrieNode *&StackCursor = StackCursorByThreadId[R.TId];
294    switch (R.Type) {
295    case RecordTypes::ENTER:
296    case RecordTypes::ENTER_ARG:
297      StackCursor = findOrCreateStackNode(StackCursor, R.FuncId, R.TId,
298                                          StackRootsByThreadId, StacksByStackId,
299                                          &id_counter, NodeStore);
300      // Each record is represented as a json dictionary with function name,
301      // type of B for begin or E for end, thread id, process id,
302      // timestamp in microseconds, and a stack frame id. The ids are logged
303      // in an id dictionary after the events.
304      writeTraceViewerRecord(Version, OS, R.FuncId, R.TId, R.PId, Symbolize,
305                             FuncIdHelper, EventTimestampUs, *StackCursor, "B");
306      break;
307    case RecordTypes::EXIT:
308    case RecordTypes::TAIL_EXIT:
309      // No entries to record end for.
310      if (StackCursor == nullptr)
311        break;
312      // Should we emit an END record anyway or account this condition?
313      // (And/Or in loop termination below)
314      StackTrieNode *PreviousCursor = nullptr;
315      do {
316        if (PreviousCursor != nullptr) {
317          OS << ",\n";
318        }
319        writeTraceViewerRecord(Version, OS, StackCursor->FuncId, R.TId, R.PId,
320                               Symbolize, FuncIdHelper, EventTimestampUs,
321                               *StackCursor, "E");
322        PreviousCursor = StackCursor;
323        StackCursor = StackCursor->Parent;
324      } while (PreviousCursor->FuncId != R.FuncId && StackCursor != nullptr);
325      break;
326    }
327  }
328  OS << "\n  ],\n"; // Close the Trace Events array.
329  OS << "  "
330     << "\"displayTimeUnit\": \"ns\",\n";
331
332  // The stackFrames dictionary substantially reduces size of the output file by
333  // avoiding repeating the entire call stack of function names for each entry.
334  OS << R"(  "stackFrames": {)";
335  int stack_frame_count = 0;
336  for (auto map_iter : StacksByStackId) {
337    if (stack_frame_count++ == 0)
338      OS << "\n";
339    else
340      OS << ",\n";
341    OS << "    ";
342    OS << llvm::formatv(
343        R"("{0}" : { "name" : "{1}")", map_iter.first,
344        (Symbolize ? FuncIdHelper.SymbolOrNumber(map_iter.second->FuncId)
345                   : llvm::to_string(map_iter.second->FuncId)));
346    if (map_iter.second->Parent != nullptr)
347      OS << llvm::formatv(R"(, "parent": "{0}")",
348                          map_iter.second->Parent->ExtraData.id);
349    OS << " }";
350  }
351  OS << "\n  }\n"; // Close the stack frames map.
352  OS << "}\n";     // Close the JSON entry.
353}
354
355namespace llvm {
356namespace xray {
357
358static CommandRegistration Unused(&Convert, []() -> Error {
359  // FIXME: Support conversion to BINARY when upgrading XRay trace versions.
360  InstrumentationMap Map;
361  if (!ConvertInstrMap.empty()) {
362    auto InstrumentationMapOrError = loadInstrumentationMap(ConvertInstrMap);
363    if (!InstrumentationMapOrError)
364      return joinErrors(make_error<StringError>(
365                            Twine("Cannot open instrumentation map '") +
366                                ConvertInstrMap + "'",
367                            std::make_error_code(std::errc::invalid_argument)),
368                        InstrumentationMapOrError.takeError());
369    Map = std::move(*InstrumentationMapOrError);
370  }
371
372  const auto &FunctionAddresses = Map.getFunctionAddresses();
373  symbolize::LLVMSymbolizer::Options Opts(
374      symbolize::FunctionNameKind::LinkageName, true, true, false, "");
375  symbolize::LLVMSymbolizer Symbolizer(Opts);
376  llvm::xray::FuncIdConversionHelper FuncIdHelper(ConvertInstrMap, Symbolizer,
377                                                  FunctionAddresses);
378  llvm::xray::TraceConverter TC(FuncIdHelper, ConvertSymbolize);
379  std::error_code EC;
380  raw_fd_ostream OS(ConvertOutput, EC,
381                    ConvertOutputFormat == ConvertFormats::BINARY
382                        ? sys::fs::OpenFlags::F_None
383                        : sys::fs::OpenFlags::F_Text);
384  if (EC)
385    return make_error<StringError>(
386        Twine("Cannot open file '") + ConvertOutput + "' for writing.", EC);
387
388  auto TraceOrErr = loadTraceFile(ConvertInput, ConvertSortInput);
389  if (!TraceOrErr)
390    return joinErrors(
391        make_error<StringError>(
392            Twine("Failed loading input file '") + ConvertInput + "'.",
393            std::make_error_code(std::errc::executable_format_error)),
394        TraceOrErr.takeError());
395
396  auto &T = *TraceOrErr;
397  switch (ConvertOutputFormat) {
398  case ConvertFormats::YAML:
399    TC.exportAsYAML(T, OS);
400    break;
401  case ConvertFormats::BINARY:
402    TC.exportAsRAWv1(T, OS);
403    break;
404  case ConvertFormats::CHROME_TRACE_EVENT:
405    TC.exportAsChromeTraceEventFormat(T, OS);
406    break;
407  }
408  return Error::success();
409});
410
411} // namespace xray
412} // namespace llvm
413