1 //===- Trace.cpp - XRay Trace Loading implementation. ---------------------===// 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 // XRay log reader implementation. 10 // 11 //===----------------------------------------------------------------------===// 12 #include "llvm/XRay/Trace.h" 13 #include "llvm/ADT/STLExtras.h" 14 #include "llvm/Support/DataExtractor.h" 15 #include "llvm/Support/Error.h" 16 #include "llvm/Support/FileSystem.h" 17 #include "llvm/XRay/BlockIndexer.h" 18 #include "llvm/XRay/BlockVerifier.h" 19 #include "llvm/XRay/FDRRecordConsumer.h" 20 #include "llvm/XRay/FDRRecordProducer.h" 21 #include "llvm/XRay/FDRRecords.h" 22 #include "llvm/XRay/FDRTraceExpander.h" 23 #include "llvm/XRay/FileHeaderReader.h" 24 #include "llvm/XRay/YAMLXRayRecord.h" 25 #include <memory> 26 #include <vector> 27 28 using namespace llvm; 29 using namespace llvm::xray; 30 using llvm::yaml::Input; 31 32 namespace { 33 using XRayRecordStorage = 34 std::aligned_storage<sizeof(XRayRecord), alignof(XRayRecord)>::type; 35 36 Error loadNaiveFormatLog(StringRef Data, bool IsLittleEndian, 37 XRayFileHeader &FileHeader, 38 std::vector<XRayRecord> &Records) { 39 if (Data.size() < 32) 40 return make_error<StringError>( 41 "Not enough bytes for an XRay log.", 42 std::make_error_code(std::errc::invalid_argument)); 43 44 if (Data.size() - 32 == 0 || Data.size() % 32 != 0) 45 return make_error<StringError>( 46 "Invalid-sized XRay data.", 47 std::make_error_code(std::errc::invalid_argument)); 48 49 DataExtractor Reader(Data, IsLittleEndian, 8); 50 uint64_t OffsetPtr = 0; 51 auto FileHeaderOrError = readBinaryFormatHeader(Reader, OffsetPtr); 52 if (!FileHeaderOrError) 53 return FileHeaderOrError.takeError(); 54 FileHeader = std::move(FileHeaderOrError.get()); 55 56 // Each record after the header will be 32 bytes, in the following format: 57 // 58 // (2) uint16 : record type 59 // (1) uint8 : cpu id 60 // (1) uint8 : type 61 // (4) sint32 : function id 62 // (8) uint64 : tsc 63 // (4) uint32 : thread id 64 // (4) uint32 : process id 65 // (8) - : padding 66 while (Reader.isValidOffset(OffsetPtr)) { 67 if (!Reader.isValidOffsetForDataOfSize(OffsetPtr, 32)) 68 return createStringError( 69 std::make_error_code(std::errc::executable_format_error), 70 "Not enough bytes to read a full record at offset %" PRId64 ".", 71 OffsetPtr); 72 auto PreReadOffset = OffsetPtr; 73 auto RecordType = Reader.getU16(&OffsetPtr); 74 if (OffsetPtr == PreReadOffset) 75 return createStringError( 76 std::make_error_code(std::errc::executable_format_error), 77 "Failed reading record type at offset %" PRId64 ".", OffsetPtr); 78 79 switch (RecordType) { 80 case 0: { // Normal records. 81 Records.emplace_back(); 82 auto &Record = Records.back(); 83 Record.RecordType = RecordType; 84 85 PreReadOffset = OffsetPtr; 86 Record.CPU = Reader.getU8(&OffsetPtr); 87 if (OffsetPtr == PreReadOffset) 88 return createStringError( 89 std::make_error_code(std::errc::executable_format_error), 90 "Failed reading CPU field at offset %" PRId64 ".", OffsetPtr); 91 92 PreReadOffset = OffsetPtr; 93 auto Type = Reader.getU8(&OffsetPtr); 94 if (OffsetPtr == PreReadOffset) 95 return createStringError( 96 std::make_error_code(std::errc::executable_format_error), 97 "Failed reading record type field at offset %" PRId64 ".", 98 OffsetPtr); 99 100 switch (Type) { 101 case 0: 102 Record.Type = RecordTypes::ENTER; 103 break; 104 case 1: 105 Record.Type = RecordTypes::EXIT; 106 break; 107 case 2: 108 Record.Type = RecordTypes::TAIL_EXIT; 109 break; 110 case 3: 111 Record.Type = RecordTypes::ENTER_ARG; 112 break; 113 default: 114 return createStringError( 115 std::make_error_code(std::errc::executable_format_error), 116 "Unknown record type '%d' at offset %" PRId64 ".", Type, OffsetPtr); 117 } 118 119 PreReadOffset = OffsetPtr; 120 Record.FuncId = Reader.getSigned(&OffsetPtr, sizeof(int32_t)); 121 if (OffsetPtr == PreReadOffset) 122 return createStringError( 123 std::make_error_code(std::errc::executable_format_error), 124 "Failed reading function id field at offset %" PRId64 ".", 125 OffsetPtr); 126 127 PreReadOffset = OffsetPtr; 128 Record.TSC = Reader.getU64(&OffsetPtr); 129 if (OffsetPtr == PreReadOffset) 130 return createStringError( 131 std::make_error_code(std::errc::executable_format_error), 132 "Failed reading TSC field at offset %" PRId64 ".", OffsetPtr); 133 134 PreReadOffset = OffsetPtr; 135 Record.TId = Reader.getU32(&OffsetPtr); 136 if (OffsetPtr == PreReadOffset) 137 return createStringError( 138 std::make_error_code(std::errc::executable_format_error), 139 "Failed reading thread id field at offset %" PRId64 ".", OffsetPtr); 140 141 PreReadOffset = OffsetPtr; 142 Record.PId = Reader.getU32(&OffsetPtr); 143 if (OffsetPtr == PreReadOffset) 144 return createStringError( 145 std::make_error_code(std::errc::executable_format_error), 146 "Failed reading process id at offset %" PRId64 ".", OffsetPtr); 147 148 break; 149 } 150 case 1: { // Arg payload record. 151 auto &Record = Records.back(); 152 153 // We skip the next two bytes of the record, because we don't need the 154 // type and the CPU record for arg payloads. 155 OffsetPtr += 2; 156 PreReadOffset = OffsetPtr; 157 int32_t FuncId = Reader.getSigned(&OffsetPtr, sizeof(int32_t)); 158 if (OffsetPtr == PreReadOffset) 159 return createStringError( 160 std::make_error_code(std::errc::executable_format_error), 161 "Failed reading function id field at offset %" PRId64 ".", 162 OffsetPtr); 163 164 PreReadOffset = OffsetPtr; 165 auto TId = Reader.getU32(&OffsetPtr); 166 if (OffsetPtr == PreReadOffset) 167 return createStringError( 168 std::make_error_code(std::errc::executable_format_error), 169 "Failed reading thread id field at offset %" PRId64 ".", OffsetPtr); 170 171 PreReadOffset = OffsetPtr; 172 auto PId = Reader.getU32(&OffsetPtr); 173 if (OffsetPtr == PreReadOffset) 174 return createStringError( 175 std::make_error_code(std::errc::executable_format_error), 176 "Failed reading process id field at offset %" PRId64 ".", 177 OffsetPtr); 178 179 // Make a check for versions above 3 for the Pid field 180 if (Record.FuncId != FuncId || Record.TId != TId || 181 (FileHeader.Version >= 3 ? Record.PId != PId : false)) 182 return createStringError( 183 std::make_error_code(std::errc::executable_format_error), 184 "Corrupted log, found arg payload following non-matching " 185 "function+thread record. Record for function %d != %d at offset " 186 "%" PRId64 ".", 187 Record.FuncId, FuncId, OffsetPtr); 188 189 PreReadOffset = OffsetPtr; 190 auto Arg = Reader.getU64(&OffsetPtr); 191 if (OffsetPtr == PreReadOffset) 192 return createStringError( 193 std::make_error_code(std::errc::executable_format_error), 194 "Failed reading argument payload at offset %" PRId64 ".", 195 OffsetPtr); 196 197 Record.CallArgs.push_back(Arg); 198 break; 199 } 200 default: 201 return createStringError( 202 std::make_error_code(std::errc::executable_format_error), 203 "Unknown record type '%d' at offset %" PRId64 ".", RecordType, 204 OffsetPtr); 205 } 206 // Advance the offset pointer enough bytes to align to 32-byte records for 207 // basic mode logs. 208 OffsetPtr += 8; 209 } 210 return Error::success(); 211 } 212 213 /// Reads a log in FDR mode for version 1 of this binary format. FDR mode is 214 /// defined as part of the compiler-rt project in xray_fdr_logging.h, and such 215 /// a log consists of the familiar 32 bit XRayHeader, followed by sequences of 216 /// of interspersed 16 byte Metadata Records and 8 byte Function Records. 217 /// 218 /// The following is an attempt to document the grammar of the format, which is 219 /// parsed by this function for little-endian machines. Since the format makes 220 /// use of BitFields, when we support big-endian architectures, we will need to 221 /// adjust not only the endianness parameter to llvm's RecordExtractor, but also 222 /// the bit twiddling logic, which is consistent with the little-endian 223 /// convention that BitFields within a struct will first be packed into the 224 /// least significant bits the address they belong to. 225 /// 226 /// We expect a format complying with the grammar in the following pseudo-EBNF 227 /// in Version 1 of the FDR log. 228 /// 229 /// FDRLog: XRayFileHeader ThreadBuffer* 230 /// XRayFileHeader: 32 bytes to identify the log as FDR with machine metadata. 231 /// Includes BufferSize 232 /// ThreadBuffer: NewBuffer WallClockTime NewCPUId FunctionSequence EOB 233 /// BufSize: 8 byte unsigned integer indicating how large the buffer is. 234 /// NewBuffer: 16 byte metadata record with Thread Id. 235 /// WallClockTime: 16 byte metadata record with human readable time. 236 /// Pid: 16 byte metadata record with Pid 237 /// NewCPUId: 16 byte metadata record with CPUId and a 64 bit TSC reading. 238 /// EOB: 16 byte record in a thread buffer plus mem garbage to fill BufSize. 239 /// FunctionSequence: NewCPUId | TSCWrap | FunctionRecord 240 /// TSCWrap: 16 byte metadata record with a full 64 bit TSC reading. 241 /// FunctionRecord: 8 byte record with FunctionId, entry/exit, and TSC delta. 242 /// 243 /// In Version 2, we make the following changes: 244 /// 245 /// ThreadBuffer: BufferExtents NewBuffer WallClockTime NewCPUId 246 /// FunctionSequence 247 /// BufferExtents: 16 byte metdata record describing how many usable bytes are 248 /// in the buffer. This is measured from the start of the buffer 249 /// and must always be at least 48 (bytes). 250 /// 251 /// In Version 3, we make the following changes: 252 /// 253 /// ThreadBuffer: BufferExtents NewBuffer WallClockTime Pid NewCPUId 254 /// FunctionSequence 255 /// EOB: *deprecated* 256 /// 257 /// In Version 4, we make the following changes: 258 /// 259 /// CustomEventRecord now includes the CPU data. 260 /// 261 /// In Version 5, we make the following changes: 262 /// 263 /// CustomEventRecord and TypedEventRecord now use TSC delta encoding similar to 264 /// what FunctionRecord instances use, and we no longer need to include the CPU 265 /// id in the CustomEventRecord. 266 /// 267 Error loadFDRLog(StringRef Data, bool IsLittleEndian, 268 XRayFileHeader &FileHeader, std::vector<XRayRecord> &Records) { 269 270 if (Data.size() < 32) 271 return createStringError(std::make_error_code(std::errc::invalid_argument), 272 "Not enough bytes for an XRay FDR log."); 273 DataExtractor DE(Data, IsLittleEndian, 8); 274 275 uint64_t OffsetPtr = 0; 276 auto FileHeaderOrError = readBinaryFormatHeader(DE, OffsetPtr); 277 if (!FileHeaderOrError) 278 return FileHeaderOrError.takeError(); 279 FileHeader = std::move(FileHeaderOrError.get()); 280 281 // First we load the records into memory. 282 std::vector<std::unique_ptr<Record>> FDRRecords; 283 284 { 285 FileBasedRecordProducer P(FileHeader, DE, OffsetPtr); 286 LogBuilderConsumer C(FDRRecords); 287 while (DE.isValidOffsetForDataOfSize(OffsetPtr, 1)) { 288 auto R = P.produce(); 289 if (!R) 290 return R.takeError(); 291 if (auto E = C.consume(std::move(R.get()))) 292 return E; 293 } 294 } 295 296 // Next we index the records into blocks. 297 BlockIndexer::Index Index; 298 { 299 BlockIndexer Indexer(Index); 300 for (auto &R : FDRRecords) 301 if (auto E = R->apply(Indexer)) 302 return E; 303 if (auto E = Indexer.flush()) 304 return E; 305 } 306 307 // Then we verify the consistency of the blocks. 308 { 309 for (auto &PTB : Index) { 310 auto &Blocks = PTB.second; 311 for (auto &B : Blocks) { 312 BlockVerifier Verifier; 313 for (auto *R : B.Records) 314 if (auto E = R->apply(Verifier)) 315 return E; 316 if (auto E = Verifier.verify()) 317 return E; 318 } 319 } 320 } 321 322 // This is now the meat of the algorithm. Here we sort the blocks according to 323 // the Walltime record in each of the blocks for the same thread. This allows 324 // us to more consistently recreate the execution trace in temporal order. 325 // After the sort, we then reconstitute `Trace` records using a stateful 326 // visitor associated with a single process+thread pair. 327 { 328 for (auto &PTB : Index) { 329 auto &Blocks = PTB.second; 330 llvm::sort(Blocks, [](const BlockIndexer::Block &L, 331 const BlockIndexer::Block &R) { 332 return (L.WallclockTime->seconds() < R.WallclockTime->seconds() && 333 L.WallclockTime->nanos() < R.WallclockTime->nanos()); 334 }); 335 auto Adder = [&](const XRayRecord &R) { Records.push_back(R); }; 336 TraceExpander Expander(Adder, FileHeader.Version); 337 for (auto &B : Blocks) { 338 for (auto *R : B.Records) 339 if (auto E = R->apply(Expander)) 340 return E; 341 } 342 if (auto E = Expander.flush()) 343 return E; 344 } 345 } 346 347 return Error::success(); 348 } 349 350 Error loadYAMLLog(StringRef Data, XRayFileHeader &FileHeader, 351 std::vector<XRayRecord> &Records) { 352 YAMLXRayTrace Trace; 353 Input In(Data); 354 In >> Trace; 355 if (In.error()) 356 return make_error<StringError>("Failed loading YAML Data.", In.error()); 357 358 FileHeader.Version = Trace.Header.Version; 359 FileHeader.Type = Trace.Header.Type; 360 FileHeader.ConstantTSC = Trace.Header.ConstantTSC; 361 FileHeader.NonstopTSC = Trace.Header.NonstopTSC; 362 FileHeader.CycleFrequency = Trace.Header.CycleFrequency; 363 364 if (FileHeader.Version != 1) 365 return make_error<StringError>( 366 Twine("Unsupported XRay file version: ") + Twine(FileHeader.Version), 367 std::make_error_code(std::errc::invalid_argument)); 368 369 Records.clear(); 370 std::transform(Trace.Records.begin(), Trace.Records.end(), 371 std::back_inserter(Records), [&](const YAMLXRayRecord &R) { 372 return XRayRecord{R.RecordType, R.CPU, R.Type, 373 R.FuncId, R.TSC, R.TId, 374 R.PId, R.CallArgs, R.Data}; 375 }); 376 return Error::success(); 377 } 378 } // namespace 379 380 Expected<Trace> llvm::xray::loadTraceFile(StringRef Filename, bool Sort) { 381 Expected<sys::fs::file_t> FdOrErr = sys::fs::openNativeFileForRead(Filename); 382 if (!FdOrErr) 383 return FdOrErr.takeError(); 384 385 uint64_t FileSize; 386 if (auto EC = sys::fs::file_size(Filename, FileSize)) { 387 return make_error<StringError>( 388 Twine("Cannot read log from '") + Filename + "'", EC); 389 } 390 if (FileSize < 4) { 391 return make_error<StringError>( 392 Twine("File '") + Filename + "' too small for XRay.", 393 std::make_error_code(std::errc::executable_format_error)); 394 } 395 396 // Map the opened file into memory and use a StringRef to access it later. 397 std::error_code EC; 398 sys::fs::mapped_file_region MappedFile( 399 *FdOrErr, sys::fs::mapped_file_region::mapmode::readonly, FileSize, 0, 400 EC); 401 sys::fs::closeFile(*FdOrErr); 402 if (EC) { 403 return make_error<StringError>( 404 Twine("Cannot read log from '") + Filename + "'", EC); 405 } 406 auto Data = StringRef(MappedFile.data(), MappedFile.size()); 407 408 // TODO: Lift the endianness and implementation selection here. 409 DataExtractor LittleEndianDE(Data, true, 8); 410 auto TraceOrError = loadTrace(LittleEndianDE, Sort); 411 if (!TraceOrError) { 412 DataExtractor BigEndianDE(Data, false, 8); 413 consumeError(TraceOrError.takeError()); 414 TraceOrError = loadTrace(BigEndianDE, Sort); 415 } 416 return TraceOrError; 417 } 418 419 Expected<Trace> llvm::xray::loadTrace(const DataExtractor &DE, bool Sort) { 420 // Attempt to detect the file type using file magic. We have a slight bias 421 // towards the binary format, and we do this by making sure that the first 4 422 // bytes of the binary file is some combination of the following byte 423 // patterns: (observe the code loading them assumes they're little endian) 424 // 425 // 0x01 0x00 0x00 0x00 - version 1, "naive" format 426 // 0x01 0x00 0x01 0x00 - version 1, "flight data recorder" format 427 // 0x02 0x00 0x01 0x00 - version 2, "flight data recorder" format 428 // 429 // YAML files don't typically have those first four bytes as valid text so we 430 // try loading assuming YAML if we don't find these bytes. 431 // 432 // Only if we can't load either the binary or the YAML format will we yield an 433 // error. 434 DataExtractor HeaderExtractor(DE.getData(), DE.isLittleEndian(), 8); 435 uint64_t OffsetPtr = 0; 436 uint16_t Version = HeaderExtractor.getU16(&OffsetPtr); 437 uint16_t Type = HeaderExtractor.getU16(&OffsetPtr); 438 439 enum BinaryFormatType { NAIVE_FORMAT = 0, FLIGHT_DATA_RECORDER_FORMAT = 1 }; 440 441 Trace T; 442 switch (Type) { 443 case NAIVE_FORMAT: 444 if (Version == 1 || Version == 2 || Version == 3) { 445 if (auto E = loadNaiveFormatLog(DE.getData(), DE.isLittleEndian(), 446 T.FileHeader, T.Records)) 447 return std::move(E); 448 } else { 449 return make_error<StringError>( 450 Twine("Unsupported version for Basic/Naive Mode logging: ") + 451 Twine(Version), 452 std::make_error_code(std::errc::executable_format_error)); 453 } 454 break; 455 case FLIGHT_DATA_RECORDER_FORMAT: 456 if (Version >= 1 && Version <= 5) { 457 if (auto E = loadFDRLog(DE.getData(), DE.isLittleEndian(), T.FileHeader, 458 T.Records)) 459 return std::move(E); 460 } else { 461 return make_error<StringError>( 462 Twine("Unsupported version for FDR Mode logging: ") + Twine(Version), 463 std::make_error_code(std::errc::executable_format_error)); 464 } 465 break; 466 default: 467 if (auto E = loadYAMLLog(DE.getData(), T.FileHeader, T.Records)) 468 return std::move(E); 469 } 470 471 if (Sort) 472 llvm::stable_sort(T.Records, [&](const XRayRecord &L, const XRayRecord &R) { 473 return L.TSC < R.TSC; 474 }); 475 476 return std::move(T); 477 } 478