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 (StringRef Data, bool IsLittleEndian, |
35 | XRayFileHeader &, |
36 | std::vector<XRayRecord> &Records) { |
37 | if (Data.size() < 32) |
38 | return make_error<StringError>( |
39 | Args: "Not enough bytes for an XRay log." , |
40 | Args: std::make_error_code(e: std::errc::invalid_argument)); |
41 | |
42 | if (Data.size() - 32 == 0 || Data.size() % 32 != 0) |
43 | return make_error<StringError>( |
44 | Args: "Invalid-sized XRay data." , |
45 | Args: std::make_error_code(e: std::errc::invalid_argument)); |
46 | |
47 | DataExtractor Reader(Data, IsLittleEndian, 8); |
48 | uint64_t OffsetPtr = 0; |
49 | auto = readBinaryFormatHeader(HeaderExtractor&: Reader, OffsetPtr); |
50 | if (!FileHeaderOrError) |
51 | return FileHeaderOrError.takeError(); |
52 | FileHeader = std::move(FileHeaderOrError.get()); |
53 | |
54 | size_t NumReservations = llvm::divideCeil(Numerator: Reader.size() - OffsetPtr, Denominator: 32U); |
55 | Records.reserve(n: 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(offset: OffsetPtr)) { |
68 | if (!Reader.isValidOffsetForDataOfSize(offset: OffsetPtr, length: 32)) |
69 | return createStringError( |
70 | EC: std::make_error_code(e: std::errc::executable_format_error), |
71 | Fmt: "Not enough bytes to read a full record at offset %" PRId64 "." , |
72 | Vals: OffsetPtr); |
73 | auto PreReadOffset = OffsetPtr; |
74 | auto RecordType = Reader.getU16(offset_ptr: &OffsetPtr); |
75 | if (OffsetPtr == PreReadOffset) |
76 | return createStringError( |
77 | EC: std::make_error_code(e: std::errc::executable_format_error), |
78 | Fmt: "Failed reading record type at offset %" PRId64 "." , Vals: 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(offset_ptr: &OffsetPtr); |
88 | if (OffsetPtr == PreReadOffset) |
89 | return createStringError( |
90 | EC: std::make_error_code(e: std::errc::executable_format_error), |
91 | Fmt: "Failed reading CPU field at offset %" PRId64 "." , Vals: OffsetPtr); |
92 | |
93 | PreReadOffset = OffsetPtr; |
94 | auto Type = Reader.getU8(offset_ptr: &OffsetPtr); |
95 | if (OffsetPtr == PreReadOffset) |
96 | return createStringError( |
97 | EC: std::make_error_code(e: std::errc::executable_format_error), |
98 | Fmt: "Failed reading record type field at offset %" PRId64 "." , |
99 | Vals: 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 | EC: std::make_error_code(e: std::errc::executable_format_error), |
117 | Fmt: "Unknown record type '%d' at offset %" PRId64 "." , Vals: Type, Vals: OffsetPtr); |
118 | } |
119 | |
120 | PreReadOffset = OffsetPtr; |
121 | Record.FuncId = Reader.getSigned(offset_ptr: &OffsetPtr, size: sizeof(int32_t)); |
122 | if (OffsetPtr == PreReadOffset) |
123 | return createStringError( |
124 | EC: std::make_error_code(e: std::errc::executable_format_error), |
125 | Fmt: "Failed reading function id field at offset %" PRId64 "." , |
126 | Vals: OffsetPtr); |
127 | |
128 | PreReadOffset = OffsetPtr; |
129 | Record.TSC = Reader.getU64(offset_ptr: &OffsetPtr); |
130 | if (OffsetPtr == PreReadOffset) |
131 | return createStringError( |
132 | EC: std::make_error_code(e: std::errc::executable_format_error), |
133 | Fmt: "Failed reading TSC field at offset %" PRId64 "." , Vals: OffsetPtr); |
134 | |
135 | PreReadOffset = OffsetPtr; |
136 | Record.TId = Reader.getU32(offset_ptr: &OffsetPtr); |
137 | if (OffsetPtr == PreReadOffset) |
138 | return createStringError( |
139 | EC: std::make_error_code(e: std::errc::executable_format_error), |
140 | Fmt: "Failed reading thread id field at offset %" PRId64 "." , Vals: OffsetPtr); |
141 | |
142 | PreReadOffset = OffsetPtr; |
143 | Record.PId = Reader.getU32(offset_ptr: &OffsetPtr); |
144 | if (OffsetPtr == PreReadOffset) |
145 | return createStringError( |
146 | EC: std::make_error_code(e: std::errc::executable_format_error), |
147 | Fmt: "Failed reading process id at offset %" PRId64 "." , Vals: 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(offset_ptr: &OffsetPtr, size: sizeof(int32_t)); |
159 | if (OffsetPtr == PreReadOffset) |
160 | return createStringError( |
161 | EC: std::make_error_code(e: std::errc::executable_format_error), |
162 | Fmt: "Failed reading function id field at offset %" PRId64 "." , |
163 | Vals: OffsetPtr); |
164 | |
165 | PreReadOffset = OffsetPtr; |
166 | auto TId = Reader.getU32(offset_ptr: &OffsetPtr); |
167 | if (OffsetPtr == PreReadOffset) |
168 | return createStringError( |
169 | EC: std::make_error_code(e: std::errc::executable_format_error), |
170 | Fmt: "Failed reading thread id field at offset %" PRId64 "." , Vals: OffsetPtr); |
171 | |
172 | PreReadOffset = OffsetPtr; |
173 | auto PId = Reader.getU32(offset_ptr: &OffsetPtr); |
174 | if (OffsetPtr == PreReadOffset) |
175 | return createStringError( |
176 | EC: std::make_error_code(e: std::errc::executable_format_error), |
177 | Fmt: "Failed reading process id field at offset %" PRId64 "." , |
178 | Vals: 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 | EC: std::make_error_code(e: std::errc::executable_format_error), |
185 | Fmt: "Corrupted log, found arg payload following non-matching " |
186 | "function+thread record. Record for function %d != %d at offset " |
187 | "%" PRId64 "." , |
188 | Vals: Record.FuncId, Vals: FuncId, Vals: OffsetPtr); |
189 | |
190 | PreReadOffset = OffsetPtr; |
191 | auto Arg = Reader.getU64(offset_ptr: &OffsetPtr); |
192 | if (OffsetPtr == PreReadOffset) |
193 | return createStringError( |
194 | EC: std::make_error_code(e: std::errc::executable_format_error), |
195 | Fmt: "Failed reading argument payload at offset %" PRId64 "." , |
196 | Vals: OffsetPtr); |
197 | |
198 | Record.CallArgs.push_back(x: Arg); |
199 | break; |
200 | } |
201 | default: |
202 | return createStringError( |
203 | EC: std::make_error_code(e: std::errc::executable_format_error), |
204 | Fmt: "Unknown record type '%d' at offset %" PRId64 "." , Vals: RecordType, |
205 | Vals: 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 | /// |
268 | Error (StringRef Data, bool IsLittleEndian, |
269 | XRayFileHeader &, std::vector<XRayRecord> &Records) { |
270 | |
271 | if (Data.size() < 32) |
272 | return createStringError(EC: std::make_error_code(e: std::errc::invalid_argument), |
273 | S: "Not enough bytes for an XRay FDR log." ); |
274 | DataExtractor DE(Data, IsLittleEndian, 8); |
275 | |
276 | uint64_t OffsetPtr = 0; |
277 | auto = readBinaryFormatHeader(HeaderExtractor&: 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(offset: OffsetPtr, length: 1)) { |
289 | auto R = P.produce(); |
290 | if (!R) |
291 | return R.takeError(); |
292 | if (auto E = C.consume(R: 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(V&: 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(V&: 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(C&: Blocks, Comp: [](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(x: R); }; |
337 | TraceExpander Expander(Adder, FileHeader.Version); |
338 | for (auto &B : Blocks) { |
339 | for (auto *R : B.Records) |
340 | if (auto E = R->apply(V&: Expander)) |
341 | return E; |
342 | } |
343 | if (auto E = Expander.flush()) |
344 | return E; |
345 | } |
346 | } |
347 | |
348 | return Error::success(); |
349 | } |
350 | |
351 | Error (StringRef Data, XRayFileHeader &, |
352 | std::vector<XRayRecord> &Records) { |
353 | YAMLXRayTrace Trace; |
354 | Input In(Data); |
355 | In >> Trace; |
356 | if (In.error()) |
357 | return make_error<StringError>(Args: "Failed loading YAML Data." , Args: 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 | Args: Twine("Unsupported XRay file version: " ) + Twine(FileHeader.Version), |
368 | Args: std::make_error_code(e: std::errc::invalid_argument)); |
369 | |
370 | Records.clear(); |
371 | std::transform(first: Trace.Records.begin(), last: Trace.Records.end(), |
372 | result: std::back_inserter(x&: Records), unary_op: [&](const YAMLXRayRecord &R) { |
373 | return XRayRecord{.RecordType: R.RecordType, .CPU: R.CPU, .Type: R.Type, |
374 | .FuncId: R.FuncId, .TSC: R.TSC, .TId: R.TId, |
375 | .PId: R.PId, .CallArgs: R.CallArgs, .Data: R.Data}; |
376 | }); |
377 | return Error::success(); |
378 | } |
379 | } // namespace |
380 | |
381 | Expected<Trace> llvm::xray::loadTraceFile(StringRef Filename, bool Sort) { |
382 | Expected<sys::fs::file_t> FdOrErr = sys::fs::openNativeFileForRead(Name: Filename); |
383 | if (!FdOrErr) |
384 | return FdOrErr.takeError(); |
385 | |
386 | uint64_t FileSize; |
387 | if (auto EC = sys::fs::file_size(Path: Filename, Result&: FileSize)) { |
388 | return make_error<StringError>( |
389 | Args: Twine("Cannot read log from '" ) + Filename + "'" , Args&: EC); |
390 | } |
391 | if (FileSize < 4) { |
392 | return make_error<StringError>( |
393 | Args: Twine("File '" ) + Filename + "' too small for XRay." , |
394 | Args: std::make_error_code(e: 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(F&: *FdOrErr); |
403 | if (EC) { |
404 | return make_error<StringError>( |
405 | Args: Twine("Cannot read log from '" ) + Filename + "'" , Args&: 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(Extractor: LittleEndianDE, Sort); |
412 | if (!TraceOrError) { |
413 | DataExtractor BigEndianDE(Data, false, 8); |
414 | consumeError(Err: TraceOrError.takeError()); |
415 | TraceOrError = loadTrace(Extractor: BigEndianDE, Sort); |
416 | } |
417 | return TraceOrError; |
418 | } |
419 | |
420 | Expected<Trace> llvm::xray::(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 (DE.getData(), DE.isLittleEndian(), 8); |
436 | uint64_t OffsetPtr = 0; |
437 | uint16_t Version = HeaderExtractor.getU16(offset_ptr: &OffsetPtr); |
438 | uint16_t Type = HeaderExtractor.getU16(offset_ptr: &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(Data: DE.getData(), IsLittleEndian: DE.isLittleEndian(), |
447 | FileHeader&: T.FileHeader, Records&: T.Records)) |
448 | return std::move(E); |
449 | } else { |
450 | return make_error<StringError>( |
451 | Args: Twine("Unsupported version for Basic/Naive Mode logging: " ) + |
452 | Twine(Version), |
453 | Args: std::make_error_code(e: 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(Data: DE.getData(), IsLittleEndian: DE.isLittleEndian(), FileHeader&: T.FileHeader, |
459 | Records&: T.Records)) |
460 | return std::move(E); |
461 | } else { |
462 | return make_error<StringError>( |
463 | Args: Twine("Unsupported version for FDR Mode logging: " ) + Twine(Version), |
464 | Args: std::make_error_code(e: std::errc::executable_format_error)); |
465 | } |
466 | break; |
467 | default: |
468 | if (auto E = loadYAMLLog(Data: DE.getData(), FileHeader&: T.FileHeader, Records&: T.Records)) |
469 | return std::move(E); |
470 | } |
471 | |
472 | if (Sort) |
473 | llvm::stable_sort(Range&: T.Records, C: [&](const XRayRecord &L, const XRayRecord &R) { |
474 | return L.TSC < R.TSC; |
475 | }); |
476 | |
477 | return std::move(T); |
478 | } |
479 | |