llvm/lib/XRay/Trace.cpp

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