Home | History | Annotate | Line # | Download | only in XRay
      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