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