xref: /freebsd/contrib/llvm-project/llvm/lib/XRay/Trace.cpp (revision 02e9120893770924227138ba49df1edb3896112a)
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 }
476