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