Trace.cpp 18 KB

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