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 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     TraceOrError = loadTrace(BigEndianDE, Sort);
 414   }
 415   return TraceOrError;
 416 }
 417
 418 Expected<Trace> llvm::xray::loadTrace(const DataExtractor &DE, bool Sort) {
 419   // Attempt to detect the file type using file magic. We have a slight bias
 420   // towards the binary format, and we do this by making sure that the first 4
 421   // bytes of the binary file is some combination of the following byte
 422   // patterns: (observe the code loading them assumes they're little endian)
 423   //
 424   //   0x01 0x00 0x00 0x00 - version 1, "naive" format
 425   //   0x01 0x00 0x01 0x00 - version 1, "flight data recorder" format
 426   //   0x02 0x00 0x01 0x00 - version 2, "flight data recorder" format
 427   //
 428   // YAML files don't typically have those first four bytes as valid text so we
 429   // try loading assuming YAML if we don't find these bytes.
 430   //
 431   // Only if we can't load either the binary or the YAML format will we yield an
 432   // error.
 433   DataExtractor HeaderExtractor(DE.getData(), DE.isLittleEndian(), 8);
 434   uint64_t OffsetPtr = 0;
 435   uint16_t Version = HeaderExtractor.getU16(&OffsetPtr);
 436   uint16_t Type = HeaderExtractor.getU16(&OffsetPtr);
 437
 438   enum BinaryFormatType { NAIVE_FORMAT = 0, FLIGHT_DATA_RECORDER_FORMAT = 1 };
 439
 440   Trace T;
 441   switch (Type) {
 442   case NAIVE_FORMAT:
 443     if (Version == 1 || Version == 2 || Version == 3) {
 444       if (auto E = loadNaiveFormatLog(DE.getData(), DE.isLittleEndian(),
 445                                       T.FileHeader, T.Records))
 446         return std::move(E);
 447     } else {
 448       return make_error<StringError>(
 449           Twine("Unsupported version for Basic/Naive Mode logging: ") +
 450               Twine(Version),
 451           std::make_error_code(std::errc::executable_format_error));
 452     }
 453     break;
 454   case FLIGHT_DATA_RECORDER_FORMAT:
 455     if (Version >= 1 && Version <= 5) {
 456       if (auto E = loadFDRLog(DE.getData(), DE.isLittleEndian(), T.FileHeader,
 457                               T.Records))
 458         return std::move(E);
 459     } else {
 460       return make_error<StringError>(
 461           Twine("Unsupported version for FDR Mode logging: ") + Twine(Version),
 462           std::make_error_code(std::errc::executable_format_error));
 463     }
 464     break;
 465   default:
 466     if (auto E = loadYAMLLog(DE.getData(), T.FileHeader, T.Records))
 467       return std::move(E);
 468   }
 469
 470   if (Sort)
 471     llvm::stable_sort(T.Records, [&](const XRayRecord &L, const XRayRecord &R) {
 472       return L.TSC < R.TSC;
 473     });
 474
 475   return std::move(T);
 476 }