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
28using namespace llvm;
29using namespace llvm::xray;
30using llvm::yaml::Input;
31
32namespace {
33
34Error 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///
268Error 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
351Error 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
381Expected<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
420Expected<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}
479