Home | History | Annotate | Line # | Download | only in llvm-xray
      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   int NumOutputRecords = 0;
    273 
    274   OS << "{\n  \"traceEvents\": [\n";
    275   DenseMap<uint32_t, StackTrieNode *> StackCursorByThreadId{};
    276   DenseMap<uint32_t, SmallVector<StackTrieNode *, 4>> StackRootsByThreadId{};
    277   DenseMap<unsigned, StackTrieNode *> StacksByStackId{};
    278   std::forward_list<StackTrieNode> NodeStore{};
    279   for (const auto &R : Records) {
    280     // Chrome trace event format always wants data in micros.
    281     // CyclesPerMicro = CycleHertz / 10^6
    282     // TSC / CyclesPerMicro == TSC * 10^6 / CycleHertz == MicroTimestamp
    283     // Could lose some precision here by converting the TSC to a double to
    284     // multiply by the period in micros. 52 bit mantissa is a good start though.
    285     // TODO: Make feature request to Chrome Trace viewer to accept ticks and a
    286     // frequency or do some more involved calculation to avoid dangers of
    287     // conversion.
    288     double EventTimestampUs = double(1000000) / CycleFreq * double(R.TSC);
    289     StackTrieNode *&StackCursor = StackCursorByThreadId[R.TId];
    290     switch (R.Type) {
    291     case RecordTypes::CUSTOM_EVENT:
    292     case RecordTypes::TYPED_EVENT:
    293       // TODO: Support typed and custom event rendering on Chrome Trace Viewer.
    294       break;
    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       if (NumOutputRecords++ > 0) {
    305         OS << ",\n";
    306       }
    307       writeTraceViewerRecord(Version, OS, R.FuncId, R.TId, R.PId, Symbolize,
    308                              FuncIdHelper, EventTimestampUs, *StackCursor, "B");
    309       break;
    310     case RecordTypes::EXIT:
    311     case RecordTypes::TAIL_EXIT:
    312       // No entries to record end for.
    313       if (StackCursor == nullptr)
    314         break;
    315       // Should we emit an END record anyway or account this condition?
    316       // (And/Or in loop termination below)
    317       StackTrieNode *PreviousCursor = nullptr;
    318       do {
    319         if (NumOutputRecords++ > 0) {
    320           OS << ",\n";
    321         }
    322         writeTraceViewerRecord(Version, OS, StackCursor->FuncId, R.TId, R.PId,
    323                                Symbolize, FuncIdHelper, EventTimestampUs,
    324                                *StackCursor, "E");
    325         PreviousCursor = StackCursor;
    326         StackCursor = StackCursor->Parent;
    327       } while (PreviousCursor->FuncId != R.FuncId && StackCursor != nullptr);
    328       break;
    329     }
    330   }
    331   OS << "\n  ],\n"; // Close the Trace Events array.
    332   OS << "  "
    333      << "\"displayTimeUnit\": \"ns\",\n";
    334 
    335   // The stackFrames dictionary substantially reduces size of the output file by
    336   // avoiding repeating the entire call stack of function names for each entry.
    337   OS << R"(  "stackFrames": {)";
    338   int stack_frame_count = 0;
    339   for (auto map_iter : StacksByStackId) {
    340     if (stack_frame_count++ == 0)
    341       OS << "\n";
    342     else
    343       OS << ",\n";
    344     OS << "    ";
    345     OS << llvm::formatv(
    346         R"("{0}" : { "name" : "{1}")", map_iter.first,
    347         (Symbolize ? FuncIdHelper.SymbolOrNumber(map_iter.second->FuncId)
    348                    : llvm::to_string(map_iter.second->FuncId)));
    349     if (map_iter.second->Parent != nullptr)
    350       OS << llvm::formatv(R"(, "parent": "{0}")",
    351                           map_iter.second->Parent->ExtraData.id);
    352     OS << " }";
    353   }
    354   OS << "\n  }\n"; // Close the stack frames map.
    355   OS << "}\n";     // Close the JSON entry.
    356 }
    357 
    358 namespace llvm {
    359 namespace xray {
    360 
    361 static CommandRegistration Unused(&Convert, []() -> Error {
    362   // FIXME: Support conversion to BINARY when upgrading XRay trace versions.
    363   InstrumentationMap Map;
    364   if (!ConvertInstrMap.empty()) {
    365     auto InstrumentationMapOrError = loadInstrumentationMap(ConvertInstrMap);
    366     if (!InstrumentationMapOrError)
    367       return joinErrors(make_error<StringError>(
    368                             Twine("Cannot open instrumentation map '") +
    369                                 ConvertInstrMap + "'",
    370                             std::make_error_code(std::errc::invalid_argument)),
    371                         InstrumentationMapOrError.takeError());
    372     Map = std::move(*InstrumentationMapOrError);
    373   }
    374 
    375   const auto &FunctionAddresses = Map.getFunctionAddresses();
    376   symbolize::LLVMSymbolizer Symbolizer;
    377   llvm::xray::FuncIdConversionHelper FuncIdHelper(ConvertInstrMap, Symbolizer,
    378                                                   FunctionAddresses);
    379   llvm::xray::TraceConverter TC(FuncIdHelper, ConvertSymbolize);
    380   std::error_code EC;
    381   raw_fd_ostream OS(ConvertOutput, EC,
    382                     ConvertOutputFormat == ConvertFormats::BINARY
    383                         ? sys::fs::OpenFlags::OF_None
    384                         : sys::fs::OpenFlags::OF_TextWithCRLF);
    385   if (EC)
    386     return make_error<StringError>(
    387         Twine("Cannot open file '") + ConvertOutput + "' for writing.", EC);
    388 
    389   auto TraceOrErr = loadTraceFile(ConvertInput, ConvertSortInput);
    390   if (!TraceOrErr)
    391     return joinErrors(
    392         make_error<StringError>(
    393             Twine("Failed loading input file '") + ConvertInput + "'.",
    394             std::make_error_code(std::errc::executable_format_error)),
    395         TraceOrErr.takeError());
    396 
    397   auto &T = *TraceOrErr;
    398   switch (ConvertOutputFormat) {
    399   case ConvertFormats::YAML:
    400     TC.exportAsYAML(T, OS);
    401     break;
    402   case ConvertFormats::BINARY:
    403     TC.exportAsRAWv1(T, OS);
    404     break;
    405   case ConvertFormats::CHROME_TRACE_EVENT:
    406     TC.exportAsChromeTraceEventFormat(T, OS);
    407     break;
    408   }
    409   return Error::success();
    410 });
    411 
    412 } // namespace xray
    413 } // namespace llvm
    414