[XRay] Update XRayRecord to support Custom/Typed Events

Summary:
This change cuts across LLVM and compiler-rt to add support for
rendering custom events in the XRayRecord type, to allow for including
user-provided annotations in the output YAML (as raw bytes).

This work enables us to add custom event and typed event records into
the `llvm::xray::Trace` type for user-provided events. This can then be
programmatically handled through the C++ API and can be included in some
of the tooling as well. For now we support printing the raw data we
encounter in the custom events in the converted output.

Future work will allow us to start interpreting these custom and typed
events through a yet-to-be-defined API for extending the trace analysis
library.

Reviewers: mboerger

Subscribers: hiraditya, llvm-commits

Differential Revision: https://reviews.llvm.org/D54139

git-svn-id: https://llvm.org/svn/llvm-project/llvm/trunk@346214 91177308-0d34-0410-b5e6-96231b3b80d8

diff --git a/include/llvm/XRay/FDRTraceExpander.h b/include/llvm/XRay/FDRTraceExpander.h
index 7f8236b..64c4599 100644 (file)
--- a/include/llvm/XRay/FDRTraceExpander.h
+++ b/include/llvm/XRay/FDRTraceExpander.h
@@ -27,10 +27,10 @@ class TraceExpander : public RecordVisitor {
   int32_t PID = 0;
   int32_t TID = 0;
   uint64_t BaseTSC = 0;
-  XRayRecord CurrentRecord{0, 0, RecordTypes::ENTER, 0, 0, 0, 0, {}};
+  XRayRecord CurrentRecord{0, 0, RecordTypes::ENTER, 0, 0, 0, 0, {}, {}};
   uint16_t CPUId = 0;
   uint16_t LogVersion = 0;
-  bool BuildingFunction = false;
+  bool BuildingRecord = false;
   bool IgnoringRecords = false;
 
   void resetCurrentRecord();

diff --git a/include/llvm/XRay/XRayRecord.h b/include/llvm/XRay/XRayRecord.h
index 7687344..7685ec9 100644 (file)
--- a/include/llvm/XRay/XRayRecord.h
+++ b/include/llvm/XRay/XRayRecord.h
@@ -17,6 +17,7 @@
 
 #include <cstdint>
 #include <vector>
+#include <string>
 
 namespace llvm {
 namespace xray {
@@ -54,10 +55,23 @@ struct XRayFileHeader {
 /// This may or may not correspond to actual record types in the raw trace (as
 /// the loader implementation may synthesize this information in the process of
 /// of loading).
-enum class RecordTypes { ENTER, EXIT, TAIL_EXIT, ENTER_ARG };
+enum class RecordTypes {
+  ENTER,
+  EXIT,
+  TAIL_EXIT,
+  ENTER_ARG,
+  CUSTOM_EVENT,
+  TYPED_EVENT
+};
 
+/// An XRayRecord is the denormalized view of data associated in a trace. These
+/// records may not correspond to actual entries in the raw traces, but they are
+/// the logical representation of records in a higher-level event log.
 struct XRayRecord {
-  /// The type of record.
+  /// RecordType values are used as "sub-types" which have meaning in the
+  /// context of the `Type` below. For function call and custom event records,
+  /// the RecordType is always 0, while for typed events we store the type in
+  /// the RecordType field.
   uint16_t RecordType;
 
   /// The CPU where the thread is running. We assume number of CPUs <= 65536.
@@ -66,7 +80,7 @@ struct XRayRecord {
   /// Identifies the type of record.
   RecordTypes Type;
 
-  /// The function ID for the record.
+  /// The function ID for the record, if this is a function call record.
   int32_t FuncId;
 
   /// Get the full 8 bytes of the TSC when we get the log record.
@@ -80,6 +94,9 @@ struct XRayRecord {
 
   /// The function call arguments.
   std::vector<uint64_t> CallArgs;
+
+  /// For custom and typed events, we provide the raw data from the trace.
+  std::string Data;
 };
 
 } // namespace xray

diff --git a/include/llvm/XRay/YAMLXRayRecord.h b/include/llvm/XRay/YAMLXRayRecord.h
index 0de9ea0..6150196 100644 (file)
--- a/include/llvm/XRay/YAMLXRayRecord.h
+++ b/include/llvm/XRay/YAMLXRayRecord.h
@@ -39,6 +39,7 @@ struct YAMLXRayRecord {
   uint32_t TId;
   uint32_t PId;
   std::vector<uint64_t> CallArgs;
+  std::string Data;
 };
 
 struct YAMLXRayTrace {
@@ -58,6 +59,8 @@ template <> struct ScalarEnumerationTraits<xray::RecordTypes> {
     IO.enumCase(Type, "function-exit", xray::RecordTypes::EXIT);
     IO.enumCase(Type, "function-tail-exit", xray::RecordTypes::TAIL_EXIT);
     IO.enumCase(Type, "function-enter-arg", xray::RecordTypes::ENTER_ARG);
+    IO.enumCase(Type, "custom-event", xray::RecordTypes::CUSTOM_EVENT);
+    IO.enumCase(Type, "typed-event", xray::RecordTypes::TYPED_EVENT);
   }
 };
 
@@ -73,16 +76,16 @@ template <> struct MappingTraits<xray::YAMLXRayFileHeader> {
 
 template <> struct MappingTraits<xray::YAMLXRayRecord> {
   static void mapping(IO &IO, xray::YAMLXRayRecord &Record) {
-    // FIXME: Make this type actually be descriptive
     IO.mapRequired("type", Record.RecordType);
-    IO.mapRequired("func-id", Record.FuncId);
+    IO.mapOptional("func-id", Record.FuncId);
     IO.mapOptional("function", Record.Function);
     IO.mapOptional("args", Record.CallArgs);
     IO.mapRequired("cpu", Record.CPU);
-    IO.mapRequired("thread", Record.TId);
+    IO.mapOptional("thread", Record.TId, 0U);
     IO.mapOptional("process", Record.PId, 0U);
     IO.mapRequired("kind", Record.Type);
     IO.mapRequired("tsc", Record.TSC);
+    IO.mapOptional("data", Record.Data);
   }
 
   static constexpr bool flow = true;

diff --git a/lib/XRay/FDRTraceExpander.cpp b/lib/XRay/FDRTraceExpander.cpp
index 8e15db5..adddb55 100644 (file)
--- a/lib/XRay/FDRTraceExpander.cpp
+++ b/lib/XRay/FDRTraceExpander.cpp
@@ -12,10 +12,11 @@ namespace llvm {
 namespace xray {
 
 void TraceExpander::resetCurrentRecord() {
-  if (BuildingFunction)
+  if (BuildingRecord)
     C(CurrentRecord);
-  BuildingFunction = false;
+  BuildingRecord = false;
   CurrentRecord.CallArgs.clear();
+  CurrentRecord.Data.clear();
 }
 
 Error TraceExpander::visit(BufferExtents &) {
@@ -36,9 +37,18 @@ Error TraceExpander::visit(TSCWrapRecord &R) {
   return Error::success();
 }
 
-Error TraceExpander::visit(CustomEventRecord &) {
-  // TODO: Support custom event records in the future.
+Error TraceExpander::visit(CustomEventRecord &R) {
   resetCurrentRecord();
+  if (!IgnoringRecords) {
+    CurrentRecord.TSC = R.tsc();
+    CurrentRecord.CPU = R.cpu();
+    CurrentRecord.PId = PID;
+    CurrentRecord.TId = TID;
+    CurrentRecord.Type = RecordTypes::CUSTOM_EVENT;
+    std::copy(R.data().begin(), R.data().end(),
+              std::back_inserter(CurrentRecord.Data));
+    BuildingRecord = true;
+  }
   return Error::success();
 }
 
@@ -78,7 +88,7 @@ Error TraceExpander::visit(FunctionRecord &R) {
     CurrentRecord.PId = PID;
     CurrentRecord.TId = TID;
     CurrentRecord.CPU = CPUId;
-    BuildingFunction = true;
+    BuildingRecord = true;
   }
   return Error::success();
 }

diff --git a/lib/XRay/Profile.cpp b/lib/XRay/Profile.cpp
index fdd1953..e8a0828 100644 (file)
--- a/lib/XRay/Profile.cpp
+++ b/lib/XRay/Profile.cpp
@@ -374,6 +374,12 @@ Expected<Profile> profileFromTrace(const Trace &T) {
       }
 
       break;
+
+    case RecordTypes::CUSTOM_EVENT:
+    case RecordTypes::TYPED_EVENT:
+      // TODO: Support an extension point to allow handling of custom and typed
+      // events in profiles.
+      break;
     }
   }
 

diff --git a/lib/XRay/RecordPrinter.cpp b/lib/XRay/RecordPrinter.cpp
index 0d5ee2d..61a292c 100644 (file)
--- a/lib/XRay/RecordPrinter.cpp
+++ b/lib/XRay/RecordPrinter.cpp
@@ -81,6 +81,10 @@ Error RecordPrinter::visit(FunctionRecord &R) {
     OS << formatv("<Function Tail Exit: #{0} delta = +{1}>", R.functionId(),
                   R.delta());
     break;
+  case RecordTypes::CUSTOM_EVENT:
+  case RecordTypes::TYPED_EVENT:
+    // TODO: Flag as a bug?
+    break;
   }
   OS << Delim;
   return Error::success();

diff --git a/lib/XRay/Trace.cpp b/lib/XRay/Trace.cpp
index e7b878c..37cd147 100644 (file)
--- a/lib/XRay/Trace.cpp
+++ b/lib/XRay/Trace.cpp
@@ -352,8 +352,9 @@ Error loadYAMLLog(StringRef Data, XRayFileHeader &FileHeader,
   Records.clear();
   std::transform(Trace.Records.begin(), Trace.Records.end(),
                  std::back_inserter(Records), [&](const YAMLXRayRecord &R) {
-                   return XRayRecord{R.RecordType, R.CPU, R.Type, R.FuncId,
-                                     R.TSC,        R.TId, R.PId,  R.CallArgs};
+                   return XRayRecord{R.RecordType, R.CPU,      R.Type,
+                                     R.FuncId,     R.TSC,      R.TId,
+                                     R.PId,        R.CallArgs, R.Data};
                  });
   return Error::success();
 }

diff --git a/test/tools/llvm-xray/X86/convert-basic-arg1-to-yaml.txt b/test/tools/llvm-xray/X86/convert-basic-arg1-to-yaml.txt
index 88a9dc2..52ec125 100644 (file)
--- a/test/tools/llvm-xray/X86/convert-basic-arg1-to-yaml.txt
+++ b/test/tools/llvm-xray/X86/convert-basic-arg1-to-yaml.txt
@@ -8,8 +8,8 @@
 ; CHECK-NEXT:   nonstop-tsc:     true
 ; CHECK-NEXT:   cycle-frequency: 3500000000
 ; CHECK-NEXT: records:
-; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 17, thread: 8715, kind: function-enter, tsc: 22555670288232728 }
-; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 17, thread: 8715, kind: function-exit, tsc: 22555670288334784 }
-; CHECK-NEXT:   - { type: 0, func-id: 2, function: '2', args: [ 1 ], cpu: 17, thread: 8715, kind: function-enter-arg, tsc: 22555670288335768 }
-; CHECK-NEXT:   - { type: 0, func-id: 2, function: '2', cpu: 17, thread: 8715, kind: function-exit, tsc: 22555670288365224 }
+; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 17, thread: 8715, kind: function-enter, tsc: 22555670288232728, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 17, thread: 8715, kind: function-exit, tsc: 22555670288334784, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 2, function: '2', args: [ 1 ], cpu: 17, thread: 8715, kind: function-enter-arg, tsc: 22555670288335768, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 2, function: '2', cpu: 17, thread: 8715, kind: function-exit, tsc: 22555670288365224, data: '' }
 ; CHECK-NEXT: ...

diff --git a/test/tools/llvm-xray/X86/convert-basic-log-arg1-version3-to-yaml.txt b/test/tools/llvm-xray/X86/convert-basic-log-arg1-version3-to-yaml.txt
index 65232b7..84c757c 100644 (file)
--- a/test/tools/llvm-xray/X86/convert-basic-log-arg1-version3-to-yaml.txt
+++ b/test/tools/llvm-xray/X86/convert-basic-log-arg1-version3-to-yaml.txt
@@ -8,10 +8,10 @@
 ; CHECK-NEXT:   nonstop-tsc:     true
 ; CHECK-NEXT:   cycle-frequency: 3900000000
 ; CHECK-NEXT: records:
-; CHECK-NEXT:   - { type: 0, func-id: 3, function: '3', cpu: 0, thread: 2590, process: 2590, kind: function-enter, tsc: 2033303630902004 }
-; CHECK-NEXT:   - { type: 0, func-id: 3, function: '3', cpu: 0, thread: 2590, process: 2590, kind: function-exit, tsc: 2033403115246844 }
-; CHECK-NEXT:   - { type: 0, func-id: 2, function: '2', cpu: 0, thread: 2590, process: 2590, kind: function-enter, tsc: 2033490200702516 }
-; CHECK-NEXT:   - { type: 0, func-id: 2, function: '2', cpu: 0, thread: 2590, process: 2590, kind: function-exit, tsc: 2033504122687120 }
-; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', args: [ 67 ], cpu: 0, thread: 2590, process: 2590, kind: function-enter-arg, tsc: 2033505343905936 }
-; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 0, thread: 2590, process: 2590, kind: function-exit, tsc: 2033505343936752 }
+; CHECK-NEXT:   - { type: 0, func-id: 3, function: '3', cpu: 0, thread: 2590, process: 2590, kind: function-enter, tsc: 2033303630902004, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 3, function: '3', cpu: 0, thread: 2590, process: 2590, kind: function-exit, tsc: 2033403115246844, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 2, function: '2', cpu: 0, thread: 2590, process: 2590, kind: function-enter, tsc: 2033490200702516, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 2, function: '2', cpu: 0, thread: 2590, process: 2590, kind: function-exit, tsc: 2033504122687120, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', args: [ 67 ], cpu: 0, thread: 2590, process: 2590, kind: function-enter-arg, tsc: 2033505343905936, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 0, thread: 2590, process: 2590, kind: function-exit, tsc: 2033505343936752, data: '' }
 ; CHECK-NEXT: ...

diff --git a/test/tools/llvm-xray/X86/convert-basic-log-version3-to-yaml.txt b/test/tools/llvm-xray/X86/convert-basic-log-version3-to-yaml.txt
index 21a3b7e..d2af2fc 100644 (file)
--- a/test/tools/llvm-xray/X86/convert-basic-log-version3-to-yaml.txt
+++ b/test/tools/llvm-xray/X86/convert-basic-log-version3-to-yaml.txt
@@ -8,12 +8,12 @@
 ; CHECK-NEXT:   nonstop-tsc:     true
 ; CHECK-NEXT:   cycle-frequency: 3900000000
 ; CHECK-NEXT: records:
-; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 7, thread: 25518, process: 25518, kind: function-enter, tsc: 2070767347414784 }
-; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 7, thread: 25518, process: 25518, kind: function-exit, tsc: 2070767347496472 }
-; CHECK-NEXT:   - { type: 0, func-id: 2, function: '2', cpu: 7, thread: 25518, process: 25518, kind: function-enter, tsc: 2070768324320264 }
-; CHECK-NEXT:   - { type: 0, func-id: 2, function: '2', cpu: 7, thread: 25518, process: 25518, kind: function-exit, tsc: 2070768324344100 }
-; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 7, thread: 25518, process: 25518, kind: function-enter, tsc: 2070768921602152 }
-; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 7, thread: 25518, process: 25518, kind: function-exit, tsc: 2070768921625968 }
-; CHECK-NEXT:   - { type: 0, func-id: 2, function: '2', cpu: 7, thread: 25518, process: 25518, kind: function-enter, tsc: 2070769627174140 }
-; CHECK-NEXT:   - { type: 0, func-id: 2, function: '2', cpu: 7, thread: 25518, process: 25518, kind: function-exit, tsc: 2070769627197624 }
+; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 7, thread: 25518, process: 25518, kind: function-enter, tsc: 2070767347414784, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 7, thread: 25518, process: 25518, kind: function-exit, tsc: 2070767347496472, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 2, function: '2', cpu: 7, thread: 25518, process: 25518, kind: function-enter, tsc: 2070768324320264, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 2, function: '2', cpu: 7, thread: 25518, process: 25518, kind: function-exit, tsc: 2070768324344100, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 7, thread: 25518, process: 25518, kind: function-enter, tsc: 2070768921602152, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 7, thread: 25518, process: 25518, kind: function-exit, tsc: 2070768921625968, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 2, function: '2', cpu: 7, thread: 25518, process: 25518, kind: function-enter, tsc: 2070769627174140, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 2, function: '2', cpu: 7, thread: 25518, process: 25518, kind: function-exit, tsc: 2070769627197624, data: '' }
 ; CHECK-NEXT: ...

diff --git a/test/tools/llvm-xray/X86/convert-fdr-arg1-to-yaml.txt b/test/tools/llvm-xray/X86/convert-fdr-arg1-to-yaml.txt
index 06b5eb8..5927964 100644 (file)
--- a/test/tools/llvm-xray/X86/convert-fdr-arg1-to-yaml.txt
+++ b/test/tools/llvm-xray/X86/convert-fdr-arg1-to-yaml.txt
@@ -8,6 +8,6 @@
 ; CHECK-NEXT:   nonstop-tsc:     true
 ; CHECK-NEXT:   cycle-frequency: 3500000000
 ; CHECK-NEXT: records:
-; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', args: [ 1 ], cpu: 49, thread: 14648, kind: function-enter-arg, tsc: 18828908666543318 }
-; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 49, thread: 14648, kind: function-exit, tsc: 18828908666595604 }
+; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', args: [ 1 ], cpu: 49, thread: 14648, kind: function-enter-arg, tsc: 18828908666543318, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 49, thread: 14648, kind: function-exit, tsc: 18828908666595604, data: '' }
 ; CHECK-NEXT: ...

diff --git a/test/tools/llvm-xray/X86/convert-fdr-log-arg1-version3-to-yaml.txt b/test/tools/llvm-xray/X86/convert-fdr-log-arg1-version3-to-yaml.txt
index a3a3ed6..afeac68 100644 (file)
--- a/test/tools/llvm-xray/X86/convert-fdr-log-arg1-version3-to-yaml.txt
+++ b/test/tools/llvm-xray/X86/convert-fdr-log-arg1-version3-to-yaml.txt
@@ -8,10 +8,10 @@
 ; CHECK-NEXT:   nonstop-tsc:     true
 ; CHECK-NEXT:   cycle-frequency: 3900000000
 ; CHECK-NEXT: records:
-; CHECK-NEXT:   - { type: 0, func-id: 3, function: '3', cpu: 6, thread: 2631, process: 2631, kind: function-enter, tsc: 2034042117104344 }
-; CHECK-NEXT:   - { type: 0, func-id: 3, function: '3', cpu: 6, thread: 2631, process: 2631, kind: function-exit, tsc: 2034042117199088 }
-; CHECK-NEXT:   - { type: 0, func-id: 2, function: '2', cpu: 6, thread: 2631, process: 2631, kind: function-enter, tsc: 2034043145686378 }
-; CHECK-NEXT:   - { type: 0, func-id: 2, function: '2', cpu: 6, thread: 2631, process: 2631, kind: function-exit, tsc: 2034043145762200 }
-; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', args: [ 67 ], cpu: 6, thread: 2631, process: 2631, kind: function-enter-arg, tsc: 2034049739853430 }
-; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 6, thread: 2631, process: 2631, kind: function-exit, tsc: 2034049739878154 }
+; CHECK-NEXT:   - { type: 0, func-id: 3, function: '3', cpu: 6, thread: 2631, process: 2631, kind: function-enter, tsc: 2034042117104344, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 3, function: '3', cpu: 6, thread: 2631, process: 2631, kind: function-exit, tsc: 2034042117199088, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 2, function: '2', cpu: 6, thread: 2631, process: 2631, kind: function-enter, tsc: 2034043145686378, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 2, function: '2', cpu: 6, thread: 2631, process: 2631, kind: function-exit, tsc: 2034043145762200, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', args: [ 67 ], cpu: 6, thread: 2631, process: 2631, kind: function-enter-arg, tsc: 2034049739853430, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 6, thread: 2631, process: 2631, kind: function-exit, tsc: 2034049739878154, data: '' }
 ; CHECK-NEXT: ...

diff --git a/test/tools/llvm-xray/X86/convert-fdr-log-version3-to-yaml.txt b/test/tools/llvm-xray/X86/convert-fdr-log-version3-to-yaml.txt
index 46287b2..fc70015 100644 (file)
--- a/test/tools/llvm-xray/X86/convert-fdr-log-version3-to-yaml.txt
+++ b/test/tools/llvm-xray/X86/convert-fdr-log-version3-to-yaml.txt
@@ -8,10 +8,10 @@
 ; CHECK-NEXT:   nonstop-tsc:     true
 ; CHECK-NEXT:   cycle-frequency: 3900000000
 ; CHECK-NEXT: records:
-; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 4, thread: 25190, process: 25190, kind: function-enter, tsc: 2069294857657498 }
-; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 4, thread: 25190, process: 25190, kind: function-exit, tsc: 2069294857707502 }
-; CHECK-NEXT:   - { type: 0, func-id: 2, function: '2', cpu: 4, thread: 25190, process: 25190, kind: function-enter, tsc: 2069295590705912 }
-; CHECK-NEXT:   - { type: 0, func-id: 2, function: '2', cpu: 4, thread: 25190, process: 25190, kind: function-exit, tsc: 2069295590734308 }
-; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 4, thread: 25190, process: 25190, kind: function-enter, tsc: 2069296377598128 }
-; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 4, thread: 25190, process: 25190, kind: function-exit, tsc: 2069296377627032 }
+; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 4, thread: 25190, process: 25190, kind: function-enter, tsc: 2069294857657498, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 4, thread: 25190, process: 25190, kind: function-exit, tsc: 2069294857707502, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 2, function: '2', cpu: 4, thread: 25190, process: 25190, kind: function-enter, tsc: 2069295590705912, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 2, function: '2', cpu: 4, thread: 25190, process: 25190, kind: function-exit, tsc: 2069295590734308, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 4, thread: 25190, process: 25190, kind: function-enter, tsc: 2069296377598128, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 4, thread: 25190, process: 25190, kind: function-exit, tsc: 2069296377627032, data: '' }
 ; CHECK-NEXT: ...

diff --git a/test/tools/llvm-xray/X86/convert-fdr-to-yaml.txt b/test/tools/llvm-xray/X86/convert-fdr-to-yaml.txt
index 731ab30..99bc7e1 100644 (file)
--- a/test/tools/llvm-xray/X86/convert-fdr-to-yaml.txt
+++ b/test/tools/llvm-xray/X86/convert-fdr-to-yaml.txt
@@ -8,17 +8,17 @@
 ; CHECK-NEXT:   nonstop-tsc:     true
 ; CHECK-NEXT:   cycle-frequency: 5678
 ; CHECK-NEXT: records:
-; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 5, thread: 5, kind: function-enter, tsc: 7238225556407340 }
-; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 5, thread: 5, kind: function-exit, tsc: 7238225556407346 }
-; CHECK-NEXT:   - { type: 0, func-id: 2, function: '2', cpu: 5, thread: 5, kind: function-enter, tsc: 7238225556407347 }
-; CHECK-NEXT:   - { type: 0, func-id: 3, function: '3', cpu: 5, thread: 5, kind: function-enter, tsc: 7238225556407387 }
-; CHECK-NEXT:   - { type: 0, func-id: 3, function: '3', cpu: 5, thread: 5, kind: function-exit, tsc: 7238225556407437 }
-; CHECK-NEXT:   - { type: 0, func-id: 2, function: '2', cpu: 5, thread: 5, kind: function-exit, tsc: 7238225556407467 }
-; CHECK-NEXT:   - { type: 0, func-id: 4, function: '4', cpu: 5, thread: 5, kind: function-enter, tsc: 7238225556407492 }
-; CHECK-NEXT:   - { type: 0, func-id: 5, function: '5', cpu: 5, thread: 5, kind: function-enter, tsc: 7238225556407517 }
-; CHECK-NEXT:   - { type: 0, func-id: 5, function: '5', cpu: 5, thread: 5, kind: function-tail-exit, tsc: 7238225556407542 }
-; CHECK-NEXT:   - { type: 0, func-id: 268435455, function: '268435455', cpu: 5, thread: 5, kind: function-enter, tsc: 7238225556407552 }
-; CHECK-NEXT:   - { type: 0, func-id: 268435455, function: '268435455', cpu: 5, thread: 5, kind: function-exit, tsc: 7238225556407562 }
-; CHECK-NEXT:   - { type: 0, func-id: 6, function: '6', cpu: 6, thread: 5, kind: function-enter, tsc: 7238225556407682 }
-; CHECK-NEXT:   - { type: 0, func-id: 6, function: '6', cpu: 6, thread: 5, kind: function-exit, tsc: 7238225556407755 }
+; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 5, thread: 5, kind: function-enter, tsc: 7238225556407340, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 5, thread: 5, kind: function-exit, tsc: 7238225556407346, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 2, function: '2', cpu: 5, thread: 5, kind: function-enter, tsc: 7238225556407347, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 3, function: '3', cpu: 5, thread: 5, kind: function-enter, tsc: 7238225556407387, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 3, function: '3', cpu: 5, thread: 5, kind: function-exit, tsc: 7238225556407437, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 2, function: '2', cpu: 5, thread: 5, kind: function-exit, tsc: 7238225556407467, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 4, function: '4', cpu: 5, thread: 5, kind: function-enter, tsc: 7238225556407492, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 5, function: '5', cpu: 5, thread: 5, kind: function-enter, tsc: 7238225556407517, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 5, function: '5', cpu: 5, thread: 5, kind: function-tail-exit, tsc: 7238225556407542, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 268435455, function: '268435455', cpu: 5, thread: 5, kind: function-enter, tsc: 7238225556407552, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 268435455, function: '268435455', cpu: 5, thread: 5, kind: function-exit, tsc: 7238225556407562, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 6, function: '6', cpu: 6, thread: 5, kind: function-enter, tsc: 7238225556407682, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 6, function: '6', cpu: 6, thread: 5, kind: function-exit, tsc: 7238225556407755, data: '' }
 ; CHECK-NEXT: ...

diff --git a/test/tools/llvm-xray/X86/convert-roundtrip.yaml b/test/tools/llvm-xray/X86/convert-roundtrip.yaml
index 4c5dfd1..bbebd67 100644 (file)
--- a/test/tools/llvm-xray/X86/convert-roundtrip.yaml
+++ b/test/tools/llvm-xray/X86/convert-roundtrip.yaml
@@ -19,6 +19,6 @@ records:
 #CHECK-NEXT:    nonstop-tsc: true
 #CHECK-NEXT:    cycle-frequency: 2601000000
 #CHECK-NEXT:  records:
-#CHECK-NEXT:    - { type: 0, func-id: 1, function: '1', cpu: 1, thread: 111, kind: function-enter, tsc: 10001 }
-#CHECK-NEXT:    - { type: 0, func-id: 1, function: '1', cpu: 1, thread: 111, kind: function-exit, tsc: 10100 }
+#CHECK-NEXT:    - { type: 0, func-id: 1, function: '1', cpu: 1, thread: 111, kind: function-enter, tsc: 10001, data: '' }
+#CHECK-NEXT:    - { type: 0, func-id: 1, function: '1', cpu: 1, thread: 111, kind: function-exit, tsc: 10100, data: '' }
 #CHECK-NEXT:  ...

diff --git a/test/tools/llvm-xray/X86/convert-to-yaml.txt b/test/tools/llvm-xray/X86/convert-to-yaml.txt
index 66a5618..f807fae 100644 (file)
--- a/test/tools/llvm-xray/X86/convert-to-yaml.txt
+++ b/test/tools/llvm-xray/X86/convert-to-yaml.txt
@@ -8,10 +8,10 @@
 ; CHECK-NEXT:   nonstop-tsc:     true
 ; CHECK-NEXT:   cycle-frequency: 2601000000
 ; CHECK-NEXT: records:
-; CHECK-NEXT:   - { type: 0, func-id: 3, function: '3', cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841453914 }
-; CHECK-NEXT:   - { type: 0, func-id: 2, function: '2', cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841454542 }
-; CHECK-NEXT:   - { type: 0, func-id: 2, function: '2', cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841454670 }
-; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841454762 }
-; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841454802 }
-; CHECK-NEXT:   - { type: 0, func-id: 3, function: '3', cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841494828 }
+; CHECK-NEXT:   - { type: 0, func-id: 3, function: '3', cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841453914, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 2, function: '2', cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841454542, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 2, function: '2', cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841454670, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841454762, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841454802, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 3, function: '3', cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841494828, data: '' }
 ; CHECK-NEXT: ...

diff --git a/test/tools/llvm-xray/X86/convert-with-debug-syms.txt b/test/tools/llvm-xray/X86/convert-with-debug-syms.txt
index 76cee99..dbb98e3 100644 (file)
--- a/test/tools/llvm-xray/X86/convert-with-debug-syms.txt
+++ b/test/tools/llvm-xray/X86/convert-with-debug-syms.txt
@@ -8,10 +8,10 @@
 ; CHECK-NEXT:   nonstop-tsc:     true
 ; CHECK-NEXT:   cycle-frequency: 2601000000
 ; CHECK-NEXT: records:
-; CHECK-NEXT:   - { type: 0, func-id: 3, function: main, cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841453914 }
-; CHECK-NEXT:   - { type: 0, func-id: 2, function: {{.*foo.*}}, cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841454542 }
-; CHECK-NEXT:   - { type: 0, func-id: 2, function: {{.*foo.*}}, cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841454670 }
-; CHECK-NEXT:   - { type: 0, func-id: 1, function: {{.*bar.*}}, cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841454762 }
-; CHECK-NEXT:   - { type: 0, func-id: 1, function: {{.*bar.*}}, cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841454802 }
-; CHECK-NEXT:   - { type: 0, func-id: 3, function: main, cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841494828 }
+; CHECK-NEXT:   - { type: 0, func-id: 3, function: main, cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841453914, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 2, function: {{.*foo.*}}, cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841454542, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 2, function: {{.*foo.*}}, cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841454670, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 1, function: {{.*bar.*}}, cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841454762, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 1, function: {{.*bar.*}}, cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841454802, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 3, function: main, cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841494828, data: '' }
 ; CHECK-NEXT: ...

diff --git a/test/tools/llvm-xray/X86/convert-with-standalone-instrmap.txt b/test/tools/llvm-xray/X86/convert-with-standalone-instrmap.txt
index 700fa38..9a12182 100644 (file)
--- a/test/tools/llvm-xray/X86/convert-with-standalone-instrmap.txt
+++ b/test/tools/llvm-xray/X86/convert-with-standalone-instrmap.txt
@@ -8,10 +8,10 @@
 ; CHECK-NEXT:   nonstop-tsc:     true
 ; CHECK-NEXT:   cycle-frequency: 2601000000
 ; CHECK-NEXT: records:
-; CHECK-NEXT:   - { type: 0, func-id: 3, function: '@(41caa0)', cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841453914 }
-; CHECK-NEXT:   - { type: 0, func-id: 2, function: '@(41ca70)', cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841454542 }
-; CHECK-NEXT:   - { type: 0, func-id: 2, function: '@(41ca70)', cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841454670 }
-; CHECK-NEXT:   - { type: 0, func-id: 1, function: '@(41ca40)', cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841454762 }
-; CHECK-NEXT:   - { type: 0, func-id: 1, function: '@(41ca40)', cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841454802 }
-; CHECK-NEXT:   - { type: 0, func-id: 3, function: '@(41caa0)', cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841494828 }
+; CHECK-NEXT:   - { type: 0, func-id: 3, function: '@(41caa0)', cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841453914, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 2, function: '@(41ca70)', cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841454542, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 2, function: '@(41ca70)', cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841454670, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 1, function: '@(41ca40)', cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841454762, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 1, function: '@(41ca40)', cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841454802, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 3, function: '@(41caa0)', cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841494828, data: '' }
 ; CHECK-NEXT: ...

diff --git a/test/tools/llvm-xray/X86/convert-with-yaml-instrmap.txt b/test/tools/llvm-xray/X86/convert-with-yaml-instrmap.txt
index 6837072..1efcb35 100644 (file)
--- a/test/tools/llvm-xray/X86/convert-with-yaml-instrmap.txt
+++ b/test/tools/llvm-xray/X86/convert-with-yaml-instrmap.txt
@@ -8,10 +8,10 @@
 ; CHECK-NEXT:   nonstop-tsc:     true
 ; CHECK-NEXT:   cycle-frequency: 2601000000
 ; CHECK-NEXT: records:
-; CHECK-NEXT:   - { type: 0, func-id: 3, function: '3', cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841453914 }
-; CHECK-NEXT:   - { type: 0, func-id: 2, function: '2', cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841454542 }
-; CHECK-NEXT:   - { type: 0, func-id: 2, function: '2', cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841454670 }
-; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841454762 }
-; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841454802 }
-; CHECK-NEXT:   - { type: 0, func-id: 3, function: '3', cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841494828 }
+; CHECK-NEXT:   - { type: 0, func-id: 3, function: '3', cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841453914, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 2, function: '2', cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841454542, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 2, function: '2', cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841454670, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 37, thread: 84697, kind: function-enter, tsc: 3315356841454762, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 1, function: '1', cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841454802, data: '' }
+; CHECK-NEXT:   - { type: 0, func-id: 3, function: '3', cpu: 37, thread: 84697, kind: function-exit, tsc: 3315356841494828, data: '' }
 ; CHECK-NEXT: ...

diff --git a/tools/llvm-xray/xray-account.cpp b/tools/llvm-xray/xray-account.cpp
index 93bb271..3f01605 100644 (file)
--- a/tools/llvm-xray/xray-account.cpp
+++ b/tools/llvm-xray/xray-account.cpp
@@ -146,6 +146,10 @@ bool LatencyAccountant::accountRecord(const XRayRecord &Record) {
 
   auto &ThreadStack = PerThreadFunctionStack[Record.TId];
   switch (Record.Type) {
+  case RecordTypes::CUSTOM_EVENT:
+  case RecordTypes::TYPED_EVENT:
+    // TODO: Support custom and typed event accounting in the future.
+    return true;
   case RecordTypes::ENTER:
   case RecordTypes::ENTER_ARG: {
     ThreadStack.emplace_back(Record.FuncId, Record.TSC);
@@ -417,19 +421,25 @@ namespace llvm {
 template <> struct format_provider<llvm::xray::RecordTypes> {
   static void format(const llvm::xray::RecordTypes &T, raw_ostream &Stream,
                      StringRef Style) {
-    switch(T) {
-      case RecordTypes::ENTER:
-        Stream << "enter";
-        break;
-      case RecordTypes::ENTER_ARG:
-        Stream << "enter-arg";
-        break;
-      case RecordTypes::EXIT:
-        Stream << "exit";
-        break;
-      case RecordTypes::TAIL_EXIT:
-        Stream << "tail-exit";
-        break;
+    switch (T) {
+    case RecordTypes::ENTER:
+      Stream << "enter";
+      break;
+    case RecordTypes::ENTER_ARG:
+      Stream << "enter-arg";
+      break;
+    case RecordTypes::EXIT:
+      Stream << "exit";
+      break;
+    case RecordTypes::TAIL_EXIT:
+      Stream << "tail-exit";
+      break;
+    case RecordTypes::CUSTOM_EVENT:
+      Stream << "custom-event";
+      break;
+    case RecordTypes::TYPED_EVENT:
+      Stream << "typed-event";
+      break;
     }
   }
 };

diff --git a/tools/llvm-xray/xray-converter.cpp b/tools/llvm-xray/xray-converter.cpp
index 1faa49c..3f153b9 100644 (file)
--- a/tools/llvm-xray/xray-converter.cpp
+++ b/tools/llvm-xray/xray-converter.cpp
@@ -92,9 +92,10 @@ void TraceConverter::exportAsYAML(const Trace &Records, raw_ostream &OS) {
     Trace.Records.push_back({R.RecordType, R.CPU, R.Type, R.FuncId,
                              Symbolize ? FuncIdHelper.SymbolOrNumber(R.FuncId)
                                        : llvm::to_string(R.FuncId),
-                             R.TSC, R.TId, R.PId, R.CallArgs});
+                             R.TSC, R.TId, R.PId, R.CallArgs, R.Data});
   }
   Output Out(OS, nullptr, 0);
+  Out.setWriteDefaultValues(false);
   Out << Trace;
 }
 
@@ -123,21 +124,27 @@ void TraceConverter::exportAsRAWv1(const Trace &Records, raw_ostream &OS) {
   // Then write out the rest of the records, still in an endian-appropriate
   // format.
   for (const auto &R : Records) {
-    Writer.write(R.RecordType);
-    // The on disk naive raw format uses 8 bit CPUs, but the record has 16.
-    // There's no choice but truncation.
-    Writer.write(static_cast<uint8_t>(R.CPU));
     switch (R.Type) {
     case RecordTypes::ENTER:
     case RecordTypes::ENTER_ARG:
+      Writer.write(R.RecordType);
+      Writer.write(static_cast<uint8_t>(R.CPU));
       Writer.write(uint8_t{0});
       break;
     case RecordTypes::EXIT:
+      Writer.write(R.RecordType);
+      Writer.write(static_cast<uint8_t>(R.CPU));
       Writer.write(uint8_t{1});
       break;
     case RecordTypes::TAIL_EXIT:
+      Writer.write(R.RecordType);
+      Writer.write(static_cast<uint8_t>(R.CPU));
       Writer.write(uint8_t{2});
       break;
+    case RecordTypes::CUSTOM_EVENT:
+    case RecordTypes::TYPED_EVENT:
+      // Skip custom and typed event records for v1 logs.
+      continue;
     }
     Writer.write(R.FuncId);
     Writer.write(R.TSC);
@@ -264,6 +271,10 @@ void TraceConverter::exportAsChromeTraceEventFormat(const Trace &Records,
     double EventTimestampUs = double(1000000) / CycleFreq * double(R.TSC);
     StackTrieNode *&StackCursor = StackCursorByThreadId[R.TId];
     switch (R.Type) {
+    case RecordTypes::CUSTOM_EVENT:
+    case RecordTypes::TYPED_EVENT:
+      // TODO: Support typed and custom event rendering on Chrome Trace Viewer.
+      break;
     case RecordTypes::ENTER:
     case RecordTypes::ENTER_ARG:
       StackCursor = findOrCreateStackNode(StackCursor, R.FuncId, R.TId,

diff --git a/tools/llvm-xray/xray-graph.cpp b/tools/llvm-xray/xray-graph.cpp
index c619bf8..fe49cca 100644 (file)
--- a/tools/llvm-xray/xray-graph.cpp
+++ b/tools/llvm-xray/xray-graph.cpp
@@ -246,6 +246,10 @@ Error GraphRenderer::accountRecord(const XRayRecord &Record) {
     updateStat(G[Record.FuncId].S, D);
     break;
   }
+  case RecordTypes::CUSTOM_EVENT:
+  case RecordTypes::TYPED_EVENT:
+    // TODO: Support custom and typed events in the graph processing?
+    break;
   }
 
   return Error::success();

diff --git a/tools/llvm-xray/xray-stacks.cpp b/tools/llvm-xray/xray-stacks.cpp
index 1a60697..059940b 100644 (file)
--- a/tools/llvm-xray/xray-stacks.cpp
+++ b/tools/llvm-xray/xray-stacks.cpp
@@ -366,6 +366,9 @@ public:
                                     AccountRecordState *state) {
     auto &TS = ThreadStackMap[R.TId];
     switch (R.Type) {
+    case RecordTypes::CUSTOM_EVENT:
+    case RecordTypes::TYPED_EVENT:
+      return AccountRecordStatus::OK;
     case RecordTypes::ENTER:
     case RecordTypes::ENTER_ARG: {
       state->wasLastRecordExit = false;