[XRay] Add CPU ID in Custom Event FDR Records

[dberris]

Summary

This change cuts across compiler-rt and llvm, to increment the FDR log
version number to 4, and include the CPU ID in the custom event records.

This is a step towards allowing us to change the llvm::xray::Trace
object to start representing both custom and typed events in the stream
of records. Follow-on changes will allow us to change the kinds of
records we're presenting in the stream of traces, to incorporate the
data in custom/typed events.

A follow-on change will handle the typed event case, where it may not
fit within the 15-byte buffer for metadata records.

This work is part of the larger effort to enable writing analysis and
processing tools using a common in-memory representation of the events
found in traces. The work will focus on porting existing tools in LLVM
to use the common representation and informing the design of a
library/framework for expressing trace event analysis as C++ programs.

[mboerger]

LGTM

compiler-rt/lib/xray/xray_fdr_controller.h

bool customEvent(uint64_t TSC, uint16_t CPU, const void *Event,
     if (finalized() ||
         !prepareBuffer((2 * sizeof(MetadataRecord)) + EventSize) ||
         functionPreamble(TSC, CPU) == PreambleResult::InvalidBuffer)
       return returnBuffer();
 
     LatestTSC = 0;
     UndoableFunctionEnters = 0;
     UndoableTailExits = 0;
-    return W.writeCustomEvent(TSC, Event, EventSize);
+    return W.writeCustomEvent(TSC, CPU, Event, EventSize);
   }
 
   bool typedEvent(uint64_t TSC, uint16_t CPU, uint16_t EventType,
                   const void *Event, int32_t EventSize) XRAY_NEVER_INSTRUMENT {
     if (finalized() ||
         !prepareBuffer((2 * sizeof(MetadataRecord)) + EventSize) ||
         functionPreamble(TSC, CPU) == PreambleResult::InvalidBuffer)
       return returnBuffer();

compiler-rt/lib/xray/xray_fdr_log_writer.h

bool writeFunction(FunctionRecordKind Kind, int32_t FuncId, int32_t Delta) {
     R.Type = 0;
     R.RecordKind = uint8_t(Kind);
     R.FuncId = FuncId;
     R.TSCDelta = Delta;
     writeRecord(R);
     return true;
   }
 
-  bool writeCustomEvent(uint64_t TSC, const void *Event, int32_t EventSize) {
+  bool writeCustomEvent(uint64_t TSC, uint16_t CPU, const void *Event,
+                        int32_t EventSize) {
     writeMetadata<MetadataRecord::RecordKinds::CustomEventMarker>(EventSize,
-                                                                  TSC);
+                                                                  TSC, CPU);
     internal_memcpy(NextRecord, Event, EventSize);
     NextRecord += EventSize;
     atomic_fetch_add(&Buffer.Extents, EventSize, memory_order_acq_rel);
     return true;
   }
 
   bool writeTypedEvent(uint64_t TSC, uint16_t EventType, const void *Event,
                        int32_t EventSize) {

compiler-rt/lib/xray/xray_fdr_logging.cc

static XRayFileHeader &fdrCommonHeaderInfo() {
   static pthread_once_t OnceInit = PTHREAD_ONCE_INIT;
   static bool TSCSupported = true;
   static uint64_t CycleFrequency = NanosecondsPerSecond;
   pthread_once(&OnceInit, +[] {
     XRayFileHeader &H = reinterpret_cast<XRayFileHeader &>(HStorage);
     // Version 2 of the log writes the extents of the buffer, instead of
     // relying on an end-of-buffer record.
     // Version 3 includes PID metadata record
-    H.Version = 3;
+    // Version 4 includes CPU data in the custom event records
+    H.Version = 4;
     H.Type = FileTypes::FDR_LOG;
 
     // Test for required CPU features and cache the cycle frequency
     TSCSupported = probeRequiredCPUFeatures();
     if (TSCSupported)
       CycleFrequency = getTSCFrequency();
     H.CycleFrequency = CycleFrequency;
 

llvm/include/llvm/XRay/FDRRecords.h

public:
   uint64_t tsc() const { return BaseTSC; }
 
   Error apply(RecordVisitor &V) override;
 };
 
 class CustomEventRecord : public MetadataRecord {
   int32_t Size = 0;
   uint64_t TSC = 0;
+  uint16_t CPU = 0;
   std::string Data{};
   friend class RecordInitializer;
 
 public:
   CustomEventRecord() = default;
-  explicit CustomEventRecord(uint64_t S, uint64_t T, std::string D)
-      : MetadataRecord(), Size(S), TSC(T), Data(std::move(D)) {}
+  explicit CustomEventRecord(uint64_t S, uint64_t T, uint16_t C, std::string D)
+      : MetadataRecord(), Size(S), TSC(T), CPU(C), Data(std::move(D)) {}
 
   MetadataType metadataType() const override {
     return MetadataType::CustomEvent;
   }
 
   int32_t size() const { return Size; }
   uint64_t tsc() const { return TSC; }
+  uint16_t cpu() const { return CPU; }
   StringRef data() const { return Data; }
 
   Error apply(RecordVisitor &V) override;
 };
 
 class CallArgRecord : public MetadataRecord {
   uint64_t Arg;
   friend class RecordInitializer;
public:
   virtual Error visit(NewBufferRecord &) = 0;
   virtual Error visit(EndBufferRecord &) = 0;
   virtual Error visit(FunctionRecord &) = 0;
 };
 
 class RecordInitializer : public RecordVisitor {
   DataExtractor &E;
   uint32_t &OffsetPtr;
+  uint16_t Version;
 
 public:
+  static constexpr uint16_t DefaultVersion = 4u;
+
+  explicit RecordInitializer(DataExtractor &DE, uint32_t &OP, uint16_t V)
+      : RecordVisitor(), E(DE), OffsetPtr(OP), Version(V) {}
+
   explicit RecordInitializer(DataExtractor &DE, uint32_t &OP)
-      : RecordVisitor(), E(DE), OffsetPtr(OP) {}
+      : RecordInitializer(DE, OP, DefaultVersion) {}
 
   Error visit(BufferExtents &) override;
   Error visit(WallclockRecord &) override;
   Error visit(NewCPUIDRecord &) override;
   Error visit(TSCWrapRecord &) override;
   Error visit(CustomEventRecord &) override;
   Error visit(CallArgRecord &) override;
   Error visit(PIDRecord &) override;

llvm/lib/XRay/FDRTraceWriter.cpp

Error FDRTraceWriter::visit(NewCPUIDRecord &R) {
   return writeMetadata<2u>(OS, R.cpuid(), R.tsc());
 }
 
 Error FDRTraceWriter::visit(TSCWrapRecord &R) {
   return writeMetadata<3u>(OS, R.tsc());
 }
 
 Error FDRTraceWriter::visit(CustomEventRecord &R) {
-  if (auto E = writeMetadata<5u>(OS, R.size(), R.tsc()))
+  if (auto E = writeMetadata<5u>(OS, R.size(), R.tsc(), R.cpu()))
     return E;
-  ArrayRef<char> Bytes(R.data().data(), R.data().size());
+  auto D = R.data();
+  ArrayRef<char> Bytes(D.data(), D.size());
   OS.write(Bytes);
   return Error::success();
 }
 
 Error FDRTraceWriter::visit(CallArgRecord &R) {
   return writeMetadata<6u>(OS, R.arg());
 }
 
Error FDRTraceWriter::visit(FunctionRecord &R) {
   uint32_t TypeRecordFuncId = uint32_t{R.functionId() & ~uint32_t{0x0Fu << 28}};
   TypeRecordFuncId <<= 3;
   TypeRecordFuncId |= static_cast<uint32_t>(R.recordType());
   TypeRecordFuncId <<= 1;
   TypeRecordFuncId &= ~uint32_t{0x01};
   OS.write(TypeRecordFuncId);
   OS.write(R.delta());
   return Error::success();
-} // namespace xray
+}
 
 } // namespace xray
 } // namespace llvm

llvm/lib/XRay/FileHeaderReader.cpp

return createStringError(
         OffsetPtr);
 
   std::memcpy(&FileHeader.FreeFormData,
               HeaderExtractor.getData().bytes_begin() + OffsetPtr, 16);
 
   // Manually advance the offset pointer 16 bytes, after getting a raw memcpy
   // from the underlying data.
   OffsetPtr += 16;
-  if (FileHeader.Version != 1 && FileHeader.Version != 2 &&
-      FileHeader.Version != 3)
+  if (FileHeader.Version < 1 || FileHeader.Version > 4)
     return createStringError(std::make_error_code(std::errc::invalid_argument),
                              "Unsupported XRay file version: %d at offset %d",
                              FileHeader.Version, OffsetPtr);
   return std::move(FileHeader);
 }
 
 } // namespace xray
 } // namespace llvm

llvm/lib/XRay/RecordInitializer.cpp

Error RecordInitializer::visit(CustomEventRecord &R) {
 
   PreReadOffset = OffsetPtr;
   R.TSC = E.getU64(&OffsetPtr);
   if (PreReadOffset == OffsetPtr)
     return createStringError(
         std::make_error_code(std::errc::invalid_argument),
         "Cannot read a custom event TSC field at offset %d.", OffsetPtr);
 
+  // For version 4 onwards, of the FDR log, we want to also capture the CPU ID
+  // of the custom event.
+  if (Version >= 4) {
+    PreReadOffset = OffsetPtr;
+    R.CPU = E.getU16(&OffsetPtr);
+    if (PreReadOffset == OffsetPtr)
+      return createStringError(
+          std::make_error_code(std::errc::invalid_argument),
+          "Missing CPU field at offset %d", OffsetPtr);
+  }
+
+  assert(OffsetPtr > BeginOffset &&
+         OffsetPtr - BeginOffset <= MetadataRecord::kMetadataBodySize);
   OffsetPtr += MetadataRecord::kMetadataBodySize - (OffsetPtr - BeginOffset);
 
   // Next we read in a fixed chunk of data from the given offset.
   if (!E.isValidOffsetForDataOfSize(OffsetPtr, R.Size))
     return createStringError(
         std::make_error_code(std::errc::bad_address),
         "Cannot read %d bytes of custom event data from offset %d.", R.Size,
         OffsetPtr);

llvm/lib/XRay/RecordPrinter.cpp

 }
 
 Error RecordPrinter::visit(TSCWrapRecord &R) {
   OS << formatv("<TSC Wrap: base = {0}>", R.tsc()) << Delim;
   return Error::success();
 }
 
 Error RecordPrinter::visit(CustomEventRecord &R) {
-  OS << formatv("<Custom Event: tsc = {0}, size = {1}, data = '{2}'>", R.tsc(),
-                R.size(), R.data())
+  OS << formatv(
+            "<Custom Event: tsc = {0}, cpu = {1}, size = {2}, data = '{3}'>",
+            R.tsc(), R.cpu(), R.size(), R.data())
      << Delim;
   return Error::success();
 }
 
 Error RecordPrinter::visit(CallArgRecord &R) {
   OS << formatv("<Call Argument: data = {0} (hex = {0:x})>", R.arg()) << Delim;
   return Error::success();
 }

llvm/lib/XRay/Trace.cpp

Error loadFDRLog(StringRef Data, bool IsLittleEndian,
   // This is now the meat of the algorithm. Here we sort the blocks according to
   // the Walltime record in each of the blocks for the same thread. This allows
   // us to more consistently recreate the execution trace in temporal order.
   // After the sort, we then reconstitute `Trace` records using a stateful
   // visitor associated with a single process+thread pair.
   {
     for (auto &PTB : Index) {
       auto &Blocks = PTB.second;
-      llvm::sort(
-          Blocks,
-          [](const BlockIndexer::Block &L, const BlockIndexer::Block &R) {
-            return (L.WallclockTime->seconds() < R.WallclockTime->seconds() &&
-                    L.WallclockTime->nanos() < R.WallclockTime->nanos());
-          });
+      llvm::sort(Blocks, [](const BlockIndexer::Block &L,
+                            const BlockIndexer::Block &R) {
       auto Adder = [&](const XRayRecord &R) { Records.push_back(R); };
       TraceExpander Expander(Adder, FileHeader.Version);
       for (auto &B : Blocks) {
         for (auto *R : B.Records)
           if (auto E = R->apply(Expander))
             return E;
       }
       if (auto E = Expander.flush())
case NAIVE_FORMAT:
     } else {
       return make_error<StringError>(
           Twine("Unsupported version for Basic/Naive Mode logging: ") +
               Twine(Version),
           std::make_error_code(std::errc::executable_format_error));
     }
     break;
   case FLIGHT_DATA_RECORDER_FORMAT:
-    if (Version == 1 || Version == 2 || Version == 3) {
+    if (Version >= 1 && Version <= 4) {
       if (auto E = loadFDRLog(DE.getData(), DE.isLittleEndian(), T.FileHeader,
                               T.Records))
         return std::move(E);
     } else {
       return make_error<StringError>(
           Twine("Unsupported version for FDR Mode logging: ") + Twine(Version),
           std::make_error_code(std::errc::executable_format_error));
     }

llvm/unittests/XRay/FDRProducerConsumerTest.cpp

template <> std::unique_ptr<Record> MakeRecord<TSCWrapRecord>() {
   return make_unique<TSCWrapRecord>(1);
 }
 
 template <> std::unique_ptr<Record> MakeRecord<WallclockRecord>() {
   return make_unique<WallclockRecord>(1, 2);
 }
 
 template <> std::unique_ptr<Record> MakeRecord<CustomEventRecord>() {
-  return make_unique<CustomEventRecord>(4, 1, "data");
+  return make_unique<CustomEventRecord>(4, 1, 2, "data");
 }
 
 template <> std::unique_ptr<Record> MakeRecord<CallArgRecord>() {
   return make_unique<CallArgRecord>(1);
 }
 
 template <> std::unique_ptr<Record> MakeRecord<PIDRecord>() {
   return make_unique<PIDRecord>(1);

llvm/unittests/XRay/FDRRecordPrinterTest.cpp

static std::unique_ptr<Record> construct() {
     return make_unique<TSCWrapRecord>(1);
   }
 
   static const char *expected() { return "<TSC Wrap: base = 1>"; }
 };
 
 template <> struct Helper<CustomEventRecord> {
   static std::unique_ptr<Record> construct() {
-    return make_unique<CustomEventRecord>(4, 1, "data");
+    return make_unique<CustomEventRecord>(4, 1, 2, "data");
   }
 
   static const char *expected() {
-    return "<Custom Event: tsc = 1, size = 4, data = 'data'>";
+    return "<Custom Event: tsc = 1, cpu = 2, size = 4, data = 'data'>";
   }
 };
 
 template <> struct Helper<CallArgRecord> {
   static std::unique_ptr<Record> construct() {
     return make_unique<CallArgRecord>(1);
   }