[XRay][tools] Support arg1 logging entries in the basic logging mode

Summary:
The arg1 logging handler changed in compiler-rt to start writing a
different type for entries encountered when logging the first argument
of XRay-instrumented functions. This change allows the trace loader to
support reading these record types as well as prepare for when the
basic (naive) mode implementation starts writing down the argument
payloads.

Without this change, binaries with arg1 logging support enabled start
writing unreadable logs for any of the XRay tracing tools.

Reviewers: pelikan

Subscribers: llvm-commits

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

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

diff --git a/lib/XRay/Trace.cpp b/lib/XRay/Trace.cpp
index e1eb7a7f117232c9f0ccce122534376d1debe8f0..e90396959fb2be7348da3bfd0e66b8b7fa7e96a1 100644 (file)
--- a/lib/XRay/Trace.cpp
+++ b/lib/XRay/Trace.cpp
@@ -82,29 +82,59 @@ Error loadNaiveFormatLog(StringRef Data, XRayFileHeader &FileHeader,
   for (auto S = Data.drop_front(32); !S.empty(); S = S.drop_front(32)) {
     DataExtractor RecordExtractor(S, true, 8);
     uint32_t OffsetPtr = 0;
-    Records.emplace_back();
-    auto &Record = Records.back();
-    Record.RecordType = RecordExtractor.getU16(&OffsetPtr);
-    Record.CPU = RecordExtractor.getU8(&OffsetPtr);
-    auto Type = RecordExtractor.getU8(&OffsetPtr);
-    switch (Type) {
-    case 0:
-      Record.Type = RecordTypes::ENTER;
-      break;
-    case 1:
-      Record.Type = RecordTypes::EXIT;
+    switch (auto RecordType = RecordExtractor.getU16(&OffsetPtr)) {
+    case 0: { // Normal records.
+      Records.emplace_back();
+      auto &Record = Records.back();
+      Record.RecordType = RecordType;
+      Record.CPU = RecordExtractor.getU8(&OffsetPtr);
+      auto Type = RecordExtractor.getU8(&OffsetPtr);
+      switch (Type) {
+      case 0:
+        Record.Type = RecordTypes::ENTER;
+        break;
+      case 1:
+        Record.Type = RecordTypes::EXIT;
+        break;
+      case 2:
+        Record.Type = RecordTypes::TAIL_EXIT;
+        break;
+      case 3:
+        Record.Type = RecordTypes::ENTER_ARG;
+        break;
+      default:
+        return make_error<StringError>(
+            Twine("Unknown record type '") + Twine(int{Type}) + "'",
+            std::make_error_code(std::errc::executable_format_error));
+      }
+      Record.FuncId = RecordExtractor.getSigned(&OffsetPtr, sizeof(int32_t));
+      Record.TSC = RecordExtractor.getU64(&OffsetPtr);
+      Record.TId = RecordExtractor.getU32(&OffsetPtr);
       break;
-    case 2:
-      Record.Type = RecordTypes::TAIL_EXIT;
+    }
+    case 1: { // Arg payload record.
+      auto &Record = Records.back();
+      // Advance two bytes to avoid padding.
+      OffsetPtr += 2;
+      int32_t FuncId = RecordExtractor.getSigned(&OffsetPtr, sizeof(int32_t));
+      auto TId = RecordExtractor.getU32(&OffsetPtr);
+      if (Record.FuncId != FuncId || Record.TId != TId)
+        return make_error<StringError>(
+            Twine("Corrupted log, found payload following non-matching "
+                  "function + thread record. Record for ") +
+                Twine(Record.FuncId) + " != " + Twine(FuncId),
+            std::make_error_code(std::errc::executable_format_error));
+      // Advance another four bytes to avoid padding.
+      OffsetPtr += 4;
+      auto Arg = RecordExtractor.getU64(&OffsetPtr);
+      Record.CallArgs.push_back(Arg);
       break;
+    }
     default:
       return make_error<StringError>(
-          Twine("Unknown record type '") + Twine(int{Type}) + "'",
+          Twine("Unknown record type == ") + Twine(RecordType),
           std::make_error_code(std::errc::executable_format_error));
     }
-    Record.FuncId = RecordExtractor.getSigned(&OffsetPtr, sizeof(int32_t));
-    Record.TSC = RecordExtractor.getU64(&OffsetPtr);
-    Record.TId = RecordExtractor.getU32(&OffsetPtr);
   }
   return Error::success();
 }
@@ -234,8 +264,8 @@ Error processCustomEventMarker(FDRState &State, uint8_t RecordFirstByte,
   uint32_t DataSize = RecordExtractor.getU32(&OffsetPtr);
   uint64_t TSC = RecordExtractor.getU64(&OffsetPtr);
 
-  // FIXME: Actually represent the record through the API. For now we only skip
-  // through the data.
+  // FIXME: Actually represent the record through the API. For now we only
+  // skip through the data.
   (void)TSC;
   RecordSize = 16 + DataSize;
   return Error::success();
@@ -507,8 +537,8 @@ 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.CallArgs};
+                   return XRayRecord{R.RecordType, R.CPU, R.Type,    R.FuncId,
+                                     R.TSC,        R.TId, R.CallArgs};
                  });
   return Error::success();
 }

diff --git a/test/tools/llvm-xray/X86/Inputs/naive-with-arg1-entries.xray b/test/tools/llvm-xray/X86/Inputs/naive-with-arg1-entries.xray
new file mode 100644 (file)
index 0000000..0260659
Binary files /dev/null and b/test/tools/llvm-xray/X86/Inputs/naive-with-arg1-entries.xray differ

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
new file mode 100644 (file)
index 0000000..88a9dc2
--- /dev/null
+++ b/test/tools/llvm-xray/X86/convert-basic-arg1-to-yaml.txt
@@ -0,0 +1,15 @@
+; RUN: llvm-xray convert %S/Inputs/naive-with-arg1-entries.xray -f=yaml -o - | FileCheck %s
+
+; CHECK:      ---
+; CHECK-NEXT: header:
+; CHECK-NEXT:   version:         2
+; CHECK-NEXT:   type:            0
+; CHECK-NEXT:   constant-tsc:    true
+; 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: ...