1336809Sdim//===- xray-converter.cpp: XRay Trace Conversion --------------------------===//
2336809Sdim//
3353358Sdim// Part of the LLVM Project, under the Apache License v2.0 with LLVM Exceptions.
4353358Sdim// See https://llvm.org/LICENSE.txt for license information.
5353358Sdim// SPDX-License-Identifier: Apache-2.0 WITH LLVM-exception
6336809Sdim//
7336809Sdim//===----------------------------------------------------------------------===//
8336809Sdim//
9336809Sdim// Implements the trace conversion functions.
10336809Sdim//
11336809Sdim//===----------------------------------------------------------------------===//
12336809Sdim#include "xray-converter.h"
13336809Sdim
14336809Sdim#include "trie-node.h"
15336809Sdim#include "xray-registry.h"
16336809Sdim#include "llvm/DebugInfo/Symbolize/Symbolize.h"
17336809Sdim#include "llvm/Support/EndianStream.h"
18336809Sdim#include "llvm/Support/FileSystem.h"
19336809Sdim#include "llvm/Support/FormatVariadic.h"
20336809Sdim#include "llvm/Support/ScopedPrinter.h"
21336809Sdim#include "llvm/Support/YAMLTraits.h"
22336809Sdim#include "llvm/Support/raw_ostream.h"
23336809Sdim#include "llvm/XRay/InstrumentationMap.h"
24336809Sdim#include "llvm/XRay/Trace.h"
25336809Sdim#include "llvm/XRay/YAMLXRayRecord.h"
26336809Sdim
27336809Sdimusing namespace llvm;
28336809Sdimusing namespace xray;
29336809Sdim
30336809Sdim// llvm-xray convert
31336809Sdim// ----------------------------------------------------------------------------
32336809Sdimstatic cl::SubCommand Convert("convert", "Trace Format Conversion");
33336809Sdimstatic cl::opt<std::string> ConvertInput(cl::Positional,
34336809Sdim                                         cl::desc("<xray log file>"),
35336809Sdim                                         cl::Required, cl::sub(Convert));
36336809Sdimenum class ConvertFormats { BINARY, YAML, CHROME_TRACE_EVENT };
37336809Sdimstatic cl::opt<ConvertFormats> ConvertOutputFormat(
38336809Sdim    "output-format", cl::desc("output format"),
39336809Sdim    cl::values(clEnumValN(ConvertFormats::BINARY, "raw", "output in binary"),
40336809Sdim               clEnumValN(ConvertFormats::YAML, "yaml", "output in yaml"),
41336809Sdim               clEnumValN(ConvertFormats::CHROME_TRACE_EVENT, "trace_event",
42336809Sdim                          "Output in chrome's trace event format. "
43336809Sdim                          "May be visualized with the Catapult trace viewer.")),
44336809Sdim    cl::sub(Convert));
45336809Sdimstatic cl::alias ConvertOutputFormat2("f", cl::aliasopt(ConvertOutputFormat),
46360784Sdim                                      cl::desc("Alias for -output-format"));
47336809Sdimstatic cl::opt<std::string>
48336809Sdim    ConvertOutput("output", cl::value_desc("output file"), cl::init("-"),
49336809Sdim                  cl::desc("output file; use '-' for stdout"),
50336809Sdim                  cl::sub(Convert));
51336809Sdimstatic cl::alias ConvertOutput2("o", cl::aliasopt(ConvertOutput),
52360784Sdim                                cl::desc("Alias for -output"));
53336809Sdim
54336809Sdimstatic cl::opt<bool>
55336809Sdim    ConvertSymbolize("symbolize",
56336809Sdim                     cl::desc("symbolize function ids from the input log"),
57336809Sdim                     cl::init(false), cl::sub(Convert));
58336809Sdimstatic cl::alias ConvertSymbolize2("y", cl::aliasopt(ConvertSymbolize),
59360784Sdim                                   cl::desc("Alias for -symbolize"));
60336809Sdim
61336809Sdimstatic cl::opt<std::string>
62336809Sdim    ConvertInstrMap("instr_map",
63336809Sdim                    cl::desc("binary with the instrumentation map, or "
64336809Sdim                             "a separate instrumentation map"),
65336809Sdim                    cl::value_desc("binary with xray_instr_map"),
66336809Sdim                    cl::sub(Convert), cl::init(""));
67336809Sdimstatic cl::alias ConvertInstrMap2("m", cl::aliasopt(ConvertInstrMap),
68360784Sdim                                  cl::desc("Alias for -instr_map"));
69336809Sdimstatic cl::opt<bool> ConvertSortInput(
70336809Sdim    "sort",
71336809Sdim    cl::desc("determines whether to sort input log records by timestamp"),
72336809Sdim    cl::sub(Convert), cl::init(true));
73336809Sdimstatic cl::alias ConvertSortInput2("s", cl::aliasopt(ConvertSortInput),
74360784Sdim                                   cl::desc("Alias for -sort"));
75336809Sdim
76336809Sdimusing llvm::yaml::Output;
77336809Sdim
78336809Sdimvoid TraceConverter::exportAsYAML(const Trace &Records, raw_ostream &OS) {
79336809Sdim  YAMLXRayTrace Trace;
80336809Sdim  const auto &FH = Records.getFileHeader();
81336809Sdim  Trace.Header = {FH.Version, FH.Type, FH.ConstantTSC, FH.NonstopTSC,
82336809Sdim                  FH.CycleFrequency};
83336809Sdim  Trace.Records.reserve(Records.size());
84336809Sdim  for (const auto &R : Records) {
85336809Sdim    Trace.Records.push_back({R.RecordType, R.CPU, R.Type, R.FuncId,
86336809Sdim                             Symbolize ? FuncIdHelper.SymbolOrNumber(R.FuncId)
87336809Sdim                                       : llvm::to_string(R.FuncId),
88344779Sdim                             R.TSC, R.TId, R.PId, R.CallArgs, R.Data});
89336809Sdim  }
90336809Sdim  Output Out(OS, nullptr, 0);
91344779Sdim  Out.setWriteDefaultValues(false);
92336809Sdim  Out << Trace;
93336809Sdim}
94336809Sdim
95336809Sdimvoid TraceConverter::exportAsRAWv1(const Trace &Records, raw_ostream &OS) {
96336809Sdim  // First write out the file header, in the correct endian-appropriate format
97336809Sdim  // (XRay assumes currently little endian).
98336809Sdim  support::endian::Writer Writer(OS, support::endianness::little);
99336809Sdim  const auto &FH = Records.getFileHeader();
100336809Sdim  Writer.write(FH.Version);
101336809Sdim  Writer.write(FH.Type);
102336809Sdim  uint32_t Bitfield{0};
103336809Sdim  if (FH.ConstantTSC)
104336809Sdim    Bitfield |= 1uL;
105336809Sdim  if (FH.NonstopTSC)
106336809Sdim    Bitfield |= 1uL << 1;
107336809Sdim  Writer.write(Bitfield);
108336809Sdim  Writer.write(FH.CycleFrequency);
109336809Sdim
110336809Sdim  // There's 16 bytes of padding at the end of the file header.
111336809Sdim  static constexpr uint32_t Padding4B = 0;
112336809Sdim  Writer.write(Padding4B);
113336809Sdim  Writer.write(Padding4B);
114336809Sdim  Writer.write(Padding4B);
115336809Sdim  Writer.write(Padding4B);
116336809Sdim
117336809Sdim  // Then write out the rest of the records, still in an endian-appropriate
118336809Sdim  // format.
119336809Sdim  for (const auto &R : Records) {
120336809Sdim    switch (R.Type) {
121336809Sdim    case RecordTypes::ENTER:
122336809Sdim    case RecordTypes::ENTER_ARG:
123344779Sdim      Writer.write(R.RecordType);
124344779Sdim      Writer.write(static_cast<uint8_t>(R.CPU));
125336809Sdim      Writer.write(uint8_t{0});
126336809Sdim      break;
127336809Sdim    case RecordTypes::EXIT:
128344779Sdim      Writer.write(R.RecordType);
129344779Sdim      Writer.write(static_cast<uint8_t>(R.CPU));
130336809Sdim      Writer.write(uint8_t{1});
131336809Sdim      break;
132336809Sdim    case RecordTypes::TAIL_EXIT:
133344779Sdim      Writer.write(R.RecordType);
134344779Sdim      Writer.write(static_cast<uint8_t>(R.CPU));
135336809Sdim      Writer.write(uint8_t{2});
136336809Sdim      break;
137344779Sdim    case RecordTypes::CUSTOM_EVENT:
138344779Sdim    case RecordTypes::TYPED_EVENT:
139344779Sdim      // Skip custom and typed event records for v1 logs.
140344779Sdim      continue;
141336809Sdim    }
142336809Sdim    Writer.write(R.FuncId);
143336809Sdim    Writer.write(R.TSC);
144336809Sdim    Writer.write(R.TId);
145336809Sdim
146336809Sdim    if (FH.Version >= 3)
147336809Sdim      Writer.write(R.PId);
148336809Sdim    else
149336809Sdim      Writer.write(Padding4B);
150336809Sdim
151336809Sdim    Writer.write(Padding4B);
152336809Sdim    Writer.write(Padding4B);
153336809Sdim  }
154336809Sdim}
155336809Sdim
156336809Sdimnamespace {
157336809Sdim
158336809Sdim// A structure that allows building a dictionary of stack ids for the Chrome
159336809Sdim// trace event format.
160336809Sdimstruct StackIdData {
161336809Sdim  // Each Stack of function calls has a unique ID.
162336809Sdim  unsigned id;
163336809Sdim
164336809Sdim  // Bookkeeping so that IDs can be maintained uniquely across threads.
165336809Sdim  // Traversal keeps sibling pointers to other threads stacks. This is helpful
166336809Sdim  // to determine when a thread encounters a new stack and should assign a new
167336809Sdim  // unique ID.
168336809Sdim  SmallVector<TrieNode<StackIdData> *, 4> siblings;
169336809Sdim};
170336809Sdim
171336809Sdimusing StackTrieNode = TrieNode<StackIdData>;
172336809Sdim
173336809Sdim// A helper function to find the sibling nodes for an encountered function in a
174336809Sdim// thread of execution. Relies on the invariant that each time a new node is
175336809Sdim// traversed in a thread, sibling bidirectional pointers are maintained.
176336809SdimSmallVector<StackTrieNode *, 4>
177336809SdimfindSiblings(StackTrieNode *parent, int32_t FnId, uint32_t TId,
178336809Sdim             const DenseMap<uint32_t, SmallVector<StackTrieNode *, 4>>
179336809Sdim                 &StackRootsByThreadId) {
180336809Sdim
181336809Sdim  SmallVector<StackTrieNode *, 4> Siblings{};
182336809Sdim
183336809Sdim  if (parent == nullptr) {
184336809Sdim    for (auto map_iter : StackRootsByThreadId) {
185336809Sdim      // Only look for siblings in other threads.
186336809Sdim      if (map_iter.first != TId)
187336809Sdim        for (auto node_iter : map_iter.second) {
188336809Sdim          if (node_iter->FuncId == FnId)
189336809Sdim            Siblings.push_back(node_iter);
190336809Sdim        }
191336809Sdim    }
192336809Sdim    return Siblings;
193336809Sdim  }
194336809Sdim
195336809Sdim  for (auto *ParentSibling : parent->ExtraData.siblings)
196336809Sdim    for (auto node_iter : ParentSibling->Callees)
197336809Sdim      if (node_iter->FuncId == FnId)
198336809Sdim        Siblings.push_back(node_iter);
199336809Sdim
200336809Sdim  return Siblings;
201336809Sdim}
202336809Sdim
203336809Sdim// Given a function being invoked in a thread with id TId, finds and returns the
204336809Sdim// StackTrie representing the function call stack. If no node exists, creates
205336809Sdim// the node. Assigns unique IDs to stacks newly encountered among all threads
206336809Sdim// and keeps sibling links up to when creating new nodes.
207336809SdimStackTrieNode *findOrCreateStackNode(
208336809Sdim    StackTrieNode *Parent, int32_t FuncId, uint32_t TId,
209336809Sdim    DenseMap<uint32_t, SmallVector<StackTrieNode *, 4>> &StackRootsByThreadId,
210336809Sdim    DenseMap<unsigned, StackTrieNode *> &StacksByStackId, unsigned *id_counter,
211336809Sdim    std::forward_list<StackTrieNode> &NodeStore) {
212336809Sdim  SmallVector<StackTrieNode *, 4> &ParentCallees =
213336809Sdim      Parent == nullptr ? StackRootsByThreadId[TId] : Parent->Callees;
214336809Sdim  auto match = find_if(ParentCallees, [FuncId](StackTrieNode *ParentCallee) {
215336809Sdim    return FuncId == ParentCallee->FuncId;
216336809Sdim  });
217336809Sdim  if (match != ParentCallees.end())
218336809Sdim    return *match;
219336809Sdim
220336809Sdim  SmallVector<StackTrieNode *, 4> siblings =
221336809Sdim      findSiblings(Parent, FuncId, TId, StackRootsByThreadId);
222336809Sdim  if (siblings.empty()) {
223336809Sdim    NodeStore.push_front({FuncId, Parent, {}, {(*id_counter)++, {}}});
224336809Sdim    StackTrieNode *CurrentStack = &NodeStore.front();
225336809Sdim    StacksByStackId[*id_counter - 1] = CurrentStack;
226336809Sdim    ParentCallees.push_back(CurrentStack);
227336809Sdim    return CurrentStack;
228336809Sdim  }
229336809Sdim  unsigned stack_id = siblings[0]->ExtraData.id;
230336809Sdim  NodeStore.push_front({FuncId, Parent, {}, {stack_id, std::move(siblings)}});
231336809Sdim  StackTrieNode *CurrentStack = &NodeStore.front();
232336809Sdim  for (auto *sibling : CurrentStack->ExtraData.siblings)
233336809Sdim    sibling->ExtraData.siblings.push_back(CurrentStack);
234336809Sdim  ParentCallees.push_back(CurrentStack);
235336809Sdim  return CurrentStack;
236336809Sdim}
237336809Sdim
238336809Sdimvoid writeTraceViewerRecord(uint16_t Version, raw_ostream &OS, int32_t FuncId,
239336809Sdim                            uint32_t TId, uint32_t PId, bool Symbolize,
240336809Sdim                            const FuncIdConversionHelper &FuncIdHelper,
241336809Sdim                            double EventTimestampUs,
242336809Sdim                            const StackTrieNode &StackCursor,
243336809Sdim                            StringRef FunctionPhenotype) {
244336809Sdim  OS << "    ";
245336809Sdim  if (Version >= 3) {
246336809Sdim    OS << llvm::formatv(
247336809Sdim        R"({ "name" : "{0}", "ph" : "{1}", "tid" : "{2}", "pid" : "{3}", )"
248336809Sdim        R"("ts" : "{4:f4}", "sf" : "{5}" })",
249336809Sdim        (Symbolize ? FuncIdHelper.SymbolOrNumber(FuncId)
250336809Sdim                   : llvm::to_string(FuncId)),
251336809Sdim        FunctionPhenotype, TId, PId, EventTimestampUs,
252336809Sdim        StackCursor.ExtraData.id);
253336809Sdim  } else {
254336809Sdim    OS << llvm::formatv(
255336809Sdim        R"({ "name" : "{0}", "ph" : "{1}", "tid" : "{2}", "pid" : "1", )"
256336809Sdim        R"("ts" : "{3:f3}", "sf" : "{4}" })",
257336809Sdim        (Symbolize ? FuncIdHelper.SymbolOrNumber(FuncId)
258336809Sdim                   : llvm::to_string(FuncId)),
259336809Sdim        FunctionPhenotype, TId, EventTimestampUs, StackCursor.ExtraData.id);
260336809Sdim  }
261336809Sdim}
262336809Sdim
263336809Sdim} // namespace
264336809Sdim
265336809Sdimvoid TraceConverter::exportAsChromeTraceEventFormat(const Trace &Records,
266336809Sdim                                                    raw_ostream &OS) {
267336809Sdim  const auto &FH = Records.getFileHeader();
268336809Sdim  auto Version = FH.Version;
269336809Sdim  auto CycleFreq = FH.CycleFrequency;
270336809Sdim
271336809Sdim  unsigned id_counter = 0;
272336809Sdim
273336809Sdim  OS << "{\n  \"traceEvents\": [";
274336809Sdim  DenseMap<uint32_t, StackTrieNode *> StackCursorByThreadId{};
275336809Sdim  DenseMap<uint32_t, SmallVector<StackTrieNode *, 4>> StackRootsByThreadId{};
276336809Sdim  DenseMap<unsigned, StackTrieNode *> StacksByStackId{};
277336809Sdim  std::forward_list<StackTrieNode> NodeStore{};
278336809Sdim  int loop_count = 0;
279336809Sdim  for (const auto &R : Records) {
280336809Sdim    if (loop_count++ == 0)
281336809Sdim      OS << "\n";
282336809Sdim    else
283336809Sdim      OS << ",\n";
284336809Sdim
285336809Sdim    // Chrome trace event format always wants data in micros.
286336809Sdim    // CyclesPerMicro = CycleHertz / 10^6
287336809Sdim    // TSC / CyclesPerMicro == TSC * 10^6 / CycleHertz == MicroTimestamp
288336809Sdim    // Could lose some precision here by converting the TSC to a double to
289336809Sdim    // multiply by the period in micros. 52 bit mantissa is a good start though.
290336809Sdim    // TODO: Make feature request to Chrome Trace viewer to accept ticks and a
291336809Sdim    // frequency or do some more involved calculation to avoid dangers of
292336809Sdim    // conversion.
293336809Sdim    double EventTimestampUs = double(1000000) / CycleFreq * double(R.TSC);
294336809Sdim    StackTrieNode *&StackCursor = StackCursorByThreadId[R.TId];
295336809Sdim    switch (R.Type) {
296344779Sdim    case RecordTypes::CUSTOM_EVENT:
297344779Sdim    case RecordTypes::TYPED_EVENT:
298344779Sdim      // TODO: Support typed and custom event rendering on Chrome Trace Viewer.
299344779Sdim      break;
300336809Sdim    case RecordTypes::ENTER:
301336809Sdim    case RecordTypes::ENTER_ARG:
302336809Sdim      StackCursor = findOrCreateStackNode(StackCursor, R.FuncId, R.TId,
303336809Sdim                                          StackRootsByThreadId, StacksByStackId,
304336809Sdim                                          &id_counter, NodeStore);
305336809Sdim      // Each record is represented as a json dictionary with function name,
306336809Sdim      // type of B for begin or E for end, thread id, process id,
307336809Sdim      // timestamp in microseconds, and a stack frame id. The ids are logged
308336809Sdim      // in an id dictionary after the events.
309336809Sdim      writeTraceViewerRecord(Version, OS, R.FuncId, R.TId, R.PId, Symbolize,
310336809Sdim                             FuncIdHelper, EventTimestampUs, *StackCursor, "B");
311336809Sdim      break;
312336809Sdim    case RecordTypes::EXIT:
313336809Sdim    case RecordTypes::TAIL_EXIT:
314336809Sdim      // No entries to record end for.
315336809Sdim      if (StackCursor == nullptr)
316336809Sdim        break;
317336809Sdim      // Should we emit an END record anyway or account this condition?
318336809Sdim      // (And/Or in loop termination below)
319336809Sdim      StackTrieNode *PreviousCursor = nullptr;
320336809Sdim      do {
321336809Sdim        if (PreviousCursor != nullptr) {
322336809Sdim          OS << ",\n";
323336809Sdim        }
324336809Sdim        writeTraceViewerRecord(Version, OS, StackCursor->FuncId, R.TId, R.PId,
325336809Sdim                               Symbolize, FuncIdHelper, EventTimestampUs,
326336809Sdim                               *StackCursor, "E");
327336809Sdim        PreviousCursor = StackCursor;
328336809Sdim        StackCursor = StackCursor->Parent;
329336809Sdim      } while (PreviousCursor->FuncId != R.FuncId && StackCursor != nullptr);
330336809Sdim      break;
331336809Sdim    }
332336809Sdim  }
333336809Sdim  OS << "\n  ],\n"; // Close the Trace Events array.
334336809Sdim  OS << "  "
335336809Sdim     << "\"displayTimeUnit\": \"ns\",\n";
336336809Sdim
337336809Sdim  // The stackFrames dictionary substantially reduces size of the output file by
338336809Sdim  // avoiding repeating the entire call stack of function names for each entry.
339336809Sdim  OS << R"(  "stackFrames": {)";
340336809Sdim  int stack_frame_count = 0;
341336809Sdim  for (auto map_iter : StacksByStackId) {
342336809Sdim    if (stack_frame_count++ == 0)
343336809Sdim      OS << "\n";
344336809Sdim    else
345336809Sdim      OS << ",\n";
346336809Sdim    OS << "    ";
347336809Sdim    OS << llvm::formatv(
348336809Sdim        R"("{0}" : { "name" : "{1}")", map_iter.first,
349336809Sdim        (Symbolize ? FuncIdHelper.SymbolOrNumber(map_iter.second->FuncId)
350336809Sdim                   : llvm::to_string(map_iter.second->FuncId)));
351336809Sdim    if (map_iter.second->Parent != nullptr)
352336809Sdim      OS << llvm::formatv(R"(, "parent": "{0}")",
353336809Sdim                          map_iter.second->Parent->ExtraData.id);
354336809Sdim    OS << " }";
355336809Sdim  }
356336809Sdim  OS << "\n  }\n"; // Close the stack frames map.
357336809Sdim  OS << "}\n";     // Close the JSON entry.
358336809Sdim}
359336809Sdim
360336809Sdimnamespace llvm {
361336809Sdimnamespace xray {
362336809Sdim
363336809Sdimstatic CommandRegistration Unused(&Convert, []() -> Error {
364336809Sdim  // FIXME: Support conversion to BINARY when upgrading XRay trace versions.
365336809Sdim  InstrumentationMap Map;
366336809Sdim  if (!ConvertInstrMap.empty()) {
367336809Sdim    auto InstrumentationMapOrError = loadInstrumentationMap(ConvertInstrMap);
368336809Sdim    if (!InstrumentationMapOrError)
369336809Sdim      return joinErrors(make_error<StringError>(
370336809Sdim                            Twine("Cannot open instrumentation map '") +
371336809Sdim                                ConvertInstrMap + "'",
372336809Sdim                            std::make_error_code(std::errc::invalid_argument)),
373336809Sdim                        InstrumentationMapOrError.takeError());
374336809Sdim    Map = std::move(*InstrumentationMapOrError);
375336809Sdim  }
376336809Sdim
377336809Sdim  const auto &FunctionAddresses = Map.getFunctionAddresses();
378353358Sdim  symbolize::LLVMSymbolizer Symbolizer;
379336809Sdim  llvm::xray::FuncIdConversionHelper FuncIdHelper(ConvertInstrMap, Symbolizer,
380336809Sdim                                                  FunctionAddresses);
381336809Sdim  llvm::xray::TraceConverter TC(FuncIdHelper, ConvertSymbolize);
382336809Sdim  std::error_code EC;
383336809Sdim  raw_fd_ostream OS(ConvertOutput, EC,
384336809Sdim                    ConvertOutputFormat == ConvertFormats::BINARY
385360784Sdim                        ? sys::fs::OpenFlags::OF_None
386360784Sdim                        : sys::fs::OpenFlags::OF_Text);
387336809Sdim  if (EC)
388336809Sdim    return make_error<StringError>(
389336809Sdim        Twine("Cannot open file '") + ConvertOutput + "' for writing.", EC);
390336809Sdim
391336809Sdim  auto TraceOrErr = loadTraceFile(ConvertInput, ConvertSortInput);
392336809Sdim  if (!TraceOrErr)
393336809Sdim    return joinErrors(
394336809Sdim        make_error<StringError>(
395336809Sdim            Twine("Failed loading input file '") + ConvertInput + "'.",
396336809Sdim            std::make_error_code(std::errc::executable_format_error)),
397336809Sdim        TraceOrErr.takeError());
398336809Sdim
399336809Sdim  auto &T = *TraceOrErr;
400336809Sdim  switch (ConvertOutputFormat) {
401336809Sdim  case ConvertFormats::YAML:
402336809Sdim    TC.exportAsYAML(T, OS);
403336809Sdim    break;
404336809Sdim  case ConvertFormats::BINARY:
405336809Sdim    TC.exportAsRAWv1(T, OS);
406336809Sdim    break;
407336809Sdim  case ConvertFormats::CHROME_TRACE_EVENT:
408336809Sdim    TC.exportAsChromeTraceEventFormat(T, OS);
409336809Sdim    break;
410336809Sdim  }
411336809Sdim  return Error::success();
412336809Sdim});
413336809Sdim
414336809Sdim} // namespace xray
415336809Sdim} // namespace llvm
416