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