contrib/llvm/lib/XRay/Trace.cpp

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