[XRay][compiler-rt] Add PID field to llvm-xray tool and add PID metadata record entry in FDR mode

Summary:
llvm-xray changes:
- account-mode - process-id  {...} shows after thread-id
- convert-mode - process {...} shows after thread
- parses FDR and basic mode pid entries
- Checks version number for FDR log parsing.

Basic logging changes:
- Update header version from 2 -> 3

FDR logging changes:
- Update header version from 2 -> 3
- in writeBufferPreamble, there is an additional PID Metadata record (after thread id record and tsc record)

Test cases changes:
- fdr-mode.cc, fdr-single-thread.cc, fdr-thread-order.cc modified to catch process id output in the log.

Reviewers: dberris

Reviewed By: dberris

Subscribers: hiraditya, llvm-commits, #sanitizers

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

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

8 files changed, 55 insertions, 40 deletions

diff --git a/lib/xray/tests/unit/fdr_logging_test.cc b/lib/xray/tests/unit/fdr_logging_test.cc
index 2ab1c9087..b6961efbc 100644
--- a/lib/xray/tests/unit/fdr_logging_test.cc
+++ b/lib/xray/tests/unit/fdr_logging_test.cc
@@ -87,7 +87,7 @@ TEST(FDRLoggingTest, Simple) {
 
   XRayFileHeader H;
   memcpy(&H, Contents, sizeof(XRayFileHeader));
-  ASSERT_EQ(H.Version, 2);
+  ASSERT_EQ(H.Version, 3);
   ASSERT_EQ(H.Type, FileTypes::FDR_LOG);
 
   // We require one buffer at least to have the "extents" metadata record,
@@ -132,7 +132,7 @@ TEST(FDRLoggingTest, Multiple) {
 
   XRayFileHeader H;
   memcpy(&H, Contents, sizeof(XRayFileHeader));
-  ASSERT_EQ(H.Version, 2);
+  ASSERT_EQ(H.Version, 3);
   ASSERT_EQ(H.Type, FileTypes::FDR_LOG);
 
   MetadataRecord MDR0, MDR1;
@@ -183,7 +183,7 @@ TEST(FDRLoggingTest, MultiThreadedCycling) {
 
   XRayFileHeader H;
   memcpy(&H, Contents, sizeof(XRayFileHeader));
-  ASSERT_EQ(H.Version, 2);
+  ASSERT_EQ(H.Version, 3);
   ASSERT_EQ(H.Type, FileTypes::FDR_LOG);
 
   MetadataRecord MDR0, MDR1;
diff --git a/lib/xray/xray_basic_logging.cc b/lib/xray/xray_basic_logging.cc
index 529fde8d5..266615aa6 100644
--- a/lib/xray/xray_basic_logging.cc
+++ b/lib/xray/xray_basic_logging.cc
@@ -90,7 +90,9 @@ static int openLogFile() XRAY_NEVER_INSTRUMENT {
   // header will only be written once, at the start, and let the threads
   // logging do writes which just append.
   XRayFileHeader Header;
-  Header.Version = 2; // Version 2 includes tail exit records.
+  // Version 2 includes tail exit records.
+  // Version 3 includes pid inside records.
+  Header.Version = 3;
   Header.Type = FileTypes::NAIVE_LOG;
   Header.CycleFrequency = atomic_load(&CycleFrequency, memory_order_acquire);
 
diff --git a/lib/xray/xray_fdr_log_records.h b/lib/xray/xray_fdr_log_records.h
index 1a5518d7a..87096d4fc 100644
--- a/lib/xray/xray_fdr_log_records.h
+++ b/lib/xray/xray_fdr_log_records.h
@@ -33,6 +33,7 @@ struct alignas(16) MetadataRecord {
     CallArgument,
     BufferExtents,
     TypedEventMarker,
+    Pid,
   };
 
   // Use 7 bits to identify this record type.
diff --git a/lib/xray/xray_fdr_logging.cc b/lib/xray/xray_fdr_logging.cc
index 7299e3b6a..3565f2571 100644
--- a/lib/xray/xray_fdr_logging.cc
+++ b/lib/xray/xray_fdr_logging.cc
@@ -125,9 +125,9 @@ static ThreadLocalData &getThreadLocalData() {
   return TLD;
 }
 
-static void writeNewBufferPreamble(tid_t Tid,
-                                   timespec TS) XRAY_NEVER_INSTRUMENT {
-  static constexpr int InitRecordsCount = 2;
+static void writeNewBufferPreamble(tid_t Tid, timespec TS,
+                                   pid_t Pid) XRAY_NEVER_INSTRUMENT {
+  static constexpr int InitRecordsCount = 3;
   auto &TLD = getThreadLocalData();
   MetadataRecord Metadata[InitRecordsCount];
   {
@@ -161,6 +161,16 @@ static void writeNewBufferPreamble(tid_t Tid,
                     sizeof(Micros));
   }
 
+  // Also write the Pid record.
+  {
+    // Write out a MetadataRecord that contains the current pid
+    auto &PidMetadata = Metadata[2];
+    PidMetadata.Type = uint8_t(RecordType::Metadata);
+    PidMetadata.RecordKind = uint8_t(MetadataRecord::RecordKinds::Pid);
+    int32_t pid = static_cast<int32_t>(Pid);
+    internal_memcpy(&PidMetadata.Data, &pid, sizeof(pid));
+  }
+
   TLD.NumConsecutiveFnEnters = 0;
   TLD.NumTailCalls = 0;
   if (TLD.BQ == nullptr || TLD.BQ->finalizing())
@@ -180,9 +190,10 @@ static void setupNewBuffer(int (*wall_clock_reader)(
   TLD.RecordPtr = static_cast<char *>(B.Data);
   tid_t Tid = GetTid();
   timespec TS{0, 0};
+  pid_t Pid = internal_getpid();
   // This is typically clock_gettime, but callers have injection ability.
   wall_clock_reader(CLOCK_MONOTONIC, &TS);
-  writeNewBufferPreamble(Tid, TS);
+  writeNewBufferPreamble(Tid, TS, Pid);
   TLD.NumConsecutiveFnEnters = 0;
   TLD.NumTailCalls = 0;
 }
@@ -663,7 +674,8 @@ static XRayFileHeader &fdrCommonHeaderInfo() {
     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.
-    H.Version = 2;
+    // Version 3 includes PID metadata record
+    H.Version = 3;
     H.Type = FileTypes::FDR_LOG;
 
     // Test for required CPU features and cache the cycle frequency
diff --git a/test/xray/TestCases/Posix/fdr-mode.cc b/test/xray/TestCases/Posix/fdr-mode.cc
index b64c5e45a..b12d97c00 100644
--- a/test/xray/TestCases/Posix/fdr-mode.cc
+++ b/test/xray/TestCases/Posix/fdr-mode.cc
@@ -81,32 +81,32 @@ int main(int argc, char *argv[]) {
 }
 
 // Check that we're able to see two threads, each entering and exiting fA().
-// TRACE-DAG: - { type: 0, func-id: [[FIDA:[0-9]+]], function: {{.*fA.*}}, cpu: {{.*}}, thread: [[THREAD1:[0-9]+]], kind: function-enter, tsc: {{[0-9]+}} }
-// TRACE:     - { type: 0, func-id: [[FIDA]], function: {{.*fA.*}}, cpu: {{.*}}, thread: [[THREAD1]], kind: function-{{exit|tail-exit}}, tsc: {{[0-9]+}} }
-// TRACE-DAG: - { type: 0, func-id: [[FIDA]], function: {{.*fA.*}}, cpu: {{.*}}, thread: [[THREAD2:[0-9]+]], kind: function-enter, tsc: {{[0-9]+}} }
-// TRACE:     - { type: 0, func-id: [[FIDA]], function: {{.*fA.*}}, cpu: {{.*}}, thread: [[THREAD2]], kind: function-{{exit|tail-exit}}, tsc: {{[0-9]+}} }
+// TRACE-DAG: - { type: 0, func-id: [[FIDA:[0-9]+]], function: {{.*fA.*}}, cpu: {{.*}}, thread: [[THREAD1:[0-9]+]], process: [[PROCESS:[0-9]+]], kind: function-enter, tsc: {{[0-9]+}} }
+// TRACE:     - { type: 0, func-id: [[FIDA]], function: {{.*fA.*}}, cpu: {{.*}}, thread: [[THREAD1]], process: [[PROCESS]], kind: function-{{exit|tail-exit}}, tsc: {{[0-9]+}} }
+// TRACE-DAG: - { type: 0, func-id: [[FIDA]], function: {{.*fA.*}}, cpu: {{.*}}, thread: [[THREAD2:[0-9]+]], process: [[PROCESS]], kind: function-enter, tsc: {{[0-9]+}} }
+// TRACE:     - { type: 0, func-id: [[FIDA]], function: {{.*fA.*}}, cpu: {{.*}}, thread: [[THREAD2]], process: [[PROCESS]], kind: function-{{exit|tail-exit}}, tsc: {{[0-9]+}} }
 //
 // Do the same as above for fC()
-// TRACE-DAG: - { type: 0, func-id: [[FIDC:[0-9]+]], function: {{.*fC.*}}, cpu: {{.*}}, thread: [[THREAD1:[0-9]+]], kind: function-enter, tsc: {{[0-9]+}} }
-// TRACE:     - { type: 0, func-id: [[FIDC]], function: {{.*fC.*}}, cpu: {{.*}}, thread: [[THREAD1]], kind: function-{{exit|tail-exit}}, tsc: {{[0-9]+}} }
-// TRACE-DAG: - { type: 0, func-id: [[FIDC]], function: {{.*fC.*}}, cpu: {{.*}}, thread: [[THREAD2:[0-9]+]], kind: function-enter, tsc: {{[0-9]+}} }
-// TRACE:     - { type: 0, func-id: [[FIDC]], function: {{.*fC.*}}, cpu: {{.*}}, thread: [[THREAD2]], kind: function-{{exit|tail-exit}}, tsc: {{[0-9]+}} }
+// TRACE-DAG: - { type: 0, func-id: [[FIDC:[0-9]+]], function: {{.*fC.*}}, cpu: {{.*}}, thread: [[THREAD1:[0-9]+]], process: [[PROCESS]], kind: function-enter, tsc: {{[0-9]+}} }
+// TRACE:     - { type: 0, func-id: [[FIDC]], function: {{.*fC.*}}, cpu: {{.*}}, thread: [[THREAD1]], process: [[PROCESS]], kind: function-{{exit|tail-exit}}, tsc: {{[0-9]+}} }
+// TRACE-DAG: - { type: 0, func-id: [[FIDC]], function: {{.*fC.*}}, cpu: {{.*}}, thread: [[THREAD2:[0-9]+]], process: [[PROCESS]], kind: function-enter, tsc: {{[0-9]+}} }
+// TRACE:     - { type: 0, func-id: [[FIDC]], function: {{.*fC.*}}, cpu: {{.*}}, thread: [[THREAD2]], process: [[PROCESS]], kind: function-{{exit|tail-exit}}, tsc: {{[0-9]+}} }
 
 // Do the same as above for fB()
-// TRACE-DAG: - { type: 0, func-id: [[FIDB:[0-9]+]], function: {{.*fB.*}}, cpu: {{.*}}, thread: [[THREAD1:[0-9]+]], kind: function-enter, tsc: {{[0-9]+}} }
-// TRACE:     - { type: 0, func-id: [[FIDB]], function: {{.*fB.*}}, cpu: {{.*}}, thread: [[THREAD1]], kind: function-{{exit|tail-exit}}, tsc: {{[0-9]+}} }
-// TRACE-DAG: - { type: 0, func-id: [[FIDB]], function: {{.*fB.*}}, cpu: {{.*}}, thread: [[THREAD2:[0-9]+]], kind: function-enter, tsc: {{[0-9]+}} }
-// TRACE:     - { type: 0, func-id: [[FIDB]], function: {{.*fB.*}}, cpu: {{.*}}, thread: [[THREAD2]], kind: function-{{exit|tail-exit}}, tsc: {{[0-9]+}} }
+// TRACE-DAG: - { type: 0, func-id: [[FIDB:[0-9]+]], function: {{.*fB.*}}, cpu: {{.*}}, thread: [[THREAD1:[0-9]+]], process: [[PROCESS]], kind: function-enter, tsc: {{[0-9]+}} }
+// TRACE:     - { type: 0, func-id: [[FIDB]], function: {{.*fB.*}}, cpu: {{.*}}, thread: [[THREAD1]], process: [[PROCESS]], kind: function-{{exit|tail-exit}}, tsc: {{[0-9]+}} }
+// TRACE-DAG: - { type: 0, func-id: [[FIDB]], function: {{.*fB.*}}, cpu: {{.*}}, thread: [[THREAD2:[0-9]+]], process: [[PROCESS]], kind: function-enter, tsc: {{[0-9]+}} }
+// TRACE:     - { type: 0, func-id: [[FIDB]], function: {{.*fB.*}}, cpu: {{.*}}, thread: [[THREAD2]], process: [[PROCESS]], kind: function-{{exit|tail-exit}}, tsc: {{[0-9]+}} }
 
-// TRACE-DAG: - { type: 0, func-id: [[FIDARG:[0-9]+]], function: 'fArg(int)', args: [ 1 ], cpu: {{.*}}, thread: [[THREAD2]], kind: function-enter-arg, tsc: {{[0-9]+}} }
-// TRACE-DAG: - { type: 0, func-id: [[FIDARG]], function: 'fArg(int)', cpu: {{.*}}, thread: [[THREAD2]], kind: function-exit, tsc: {{[0-9]+}} }
+// TRACE-DAG: - { type: 0, func-id: [[FIDARG:[0-9]+]], function: 'fArg(int)', args: [ 1 ], cpu: {{.*}}, thread: [[THREAD2]], process: [[PROCESS]], kind: function-enter-arg, tsc: {{[0-9]+}} }
+// TRACE-DAG: - { type: 0, func-id: [[FIDARG]], function: 'fArg(int)', cpu: {{.*}}, thread: [[THREAD2]], process: [[PROCESS]], kind: function-exit, tsc: {{[0-9]+}} }
 
 // Assert that when unwriting is enabled with a high threshold time, all the function records are erased. A CPU switch could erroneously fail this test, but
 // is unlikely given the test program.
 // Even with a high threshold, arg1 logging is never unwritten.
 // UNWRITE: header:
 // UNWRITE: records:
-// UNWRITE-NEXT: - { type: 0, func-id: [[FIDARG:[0-9]+]], function: 'fArg(int)', args: [ 1 ], cpu: {{.*}}, thread: [[THREAD2:[0-9]+]], kind: function-enter-arg, tsc: {{[0-9]+}} }
-// UNWRITE-NEXT: - { type: 0, func-id: [[FIDARG]], function: 'fArg(int)', cpu: {{.*}}, thread: [[THREAD2]], kind: function-exit, tsc: {{[0-9]+}} }
+// UNWRITE-NEXT: - { type: 0, func-id: [[FIDARG:[0-9]+]], function: 'fArg(int)', args: [ 1 ], cpu: {{.*}}, thread: [[THREAD2:[0-9]+]], process: [[PROCESS:[0-9]+]], kind: function-enter-arg, tsc: {{[0-9]+}} }
+// UNWRITE-NEXT: - { type: 0, func-id: [[FIDARG]], function: 'fArg(int)', cpu: {{.*}}, thread: [[THREAD2]], process: [[PROCESS]], kind: function-exit, tsc: {{[0-9]+}} }
 // UNWRITE-NOT: function-enter
 // UNWRITE-NOT: function-{{exit|tail-exit}}
diff --git a/test/xray/TestCases/Posix/fdr-single-thread.cc b/test/xray/TestCases/Posix/fdr-single-thread.cc
index 438d5ce0f..480502b0a 100644
--- a/test/xray/TestCases/Posix/fdr-single-thread.cc
+++ b/test/xray/TestCases/Posix/fdr-single-thread.cc
@@ -34,5 +34,5 @@ int main(int argc, char *argv[]) {
 }
 
 // CHECK: records:
-// CHECK-NEXT: - { type: 0, func-id: [[FID1:[0-9]+]], function: {{.*fn.*}}, cpu: {{.*}}, thread: [[THREAD1:[0-9]+]], kind: function-enter, tsc: {{[0-9]+}} }
-// CHECK-NEXT: - { type: 0, func-id: [[FID1:[0-9]+]], function: {{.*fn.*}}, cpu: {{.*}}, thread: [[THREAD1:[0-9]+]], kind: function-exit, tsc: {{[0-9]+}} }
+// CHECK-NEXT: - { type: 0, func-id: [[FID1:[0-9]+]], function: {{.*fn.*}}, cpu: {{.*}}, thread: [[THREAD1:[0-9]+]], process: [[PROCESS:[0-9]+]], kind: function-enter, tsc: {{[0-9]+}} }
+// CHECK-NEXT: - { type: 0, func-id: [[FID1:[0-9]+]], function: {{.*fn.*}}, cpu: {{.*}}, thread: [[THREAD1:[0-9]+]], process: [[PROCESS:[0-9]+]], kind: function-exit, tsc: {{[0-9]+}} }
diff --git a/test/xray/TestCases/Posix/fdr-thread-order.cc b/test/xray/TestCases/Posix/fdr-thread-order.cc
index 4335e2118..1d6b01759 100644
--- a/test/xray/TestCases/Posix/fdr-thread-order.cc
+++ b/test/xray/TestCases/Posix/fdr-thread-order.cc
@@ -61,7 +61,7 @@ int main(int argc, char *argv[]) {
 }
 
 // We want to make sure that the order of the function log doesn't matter.
-// TRACE-DAG: - { type: 0, func-id: [[FID1:[0-9]+]], function: {{.*f1.*}}, cpu: {{.*}}, thread: [[THREAD1:[0-9]+]], kind: function-enter, tsc: {{[0-9]+}} }
-// TRACE-DAG: - { type: 0, func-id: [[FID2:[0-9]+]], function: {{.*f2.*}}, cpu: {{.*}}, thread: [[THREAD2:[0-9]+]], kind: function-enter, tsc: {{[0-9]+}} }
-// TRACE-DAG: - { type: 0, func-id: [[FID1]], function: {{.*f1.*}}, cpu: {{.*}}, thread: [[THREAD1]], kind: {{function-exit|function-tail-exit}}, tsc: {{[0-9]+}} }
-// TRACE-DAG: - { type: 0, func-id: [[FID2]], function: {{.*f2.*}}, cpu: {{.*}}, thread: [[THREAD2]], kind: {{function-exit|function-tail-exit}}, tsc: {{[0-9]+}} }
+// TRACE-DAG: - { type: 0, func-id: [[FID1:[0-9]+]], function: {{.*f1.*}}, cpu: {{.*}}, thread: [[THREAD1:[0-9]+]], process: [[PROCESS:[0-9]+]], kind: function-enter, tsc: {{[0-9]+}} }
+// TRACE-DAG: - { type: 0, func-id: [[FID2:[0-9]+]], function: {{.*f2.*}}, cpu: {{.*}}, thread: [[THREAD2:[0-9]+]], process: [[PROCESS]], kind: function-enter, tsc: {{[0-9]+}} }
+// TRACE-DAG: - { type: 0, func-id: [[FID1]], function: {{.*f1.*}}, cpu: {{.*}}, thread: [[THREAD1]], process: [[PROCESS]], kind: {{function-exit|function-tail-exit}}, tsc: {{[0-9]+}} }
+// TRACE-DAG: - { type: 0, func-id: [[FID2]], function: {{.*f2.*}}, cpu: {{.*}}, thread: [[THREAD2]], process: [[PROCESS]], kind: {{function-exit|function-tail-exit}}, tsc: {{[0-9]+}} }
diff --git a/test/xray/TestCases/Posix/fork_basic_logging.cc b/test/xray/TestCases/Posix/fork_basic_logging.cc
index 414fc3293..0f893872a 100644
--- a/test/xray/TestCases/Posix/fork_basic_logging.cc
+++ b/test/xray/TestCases/Posix/fork_basic_logging.cc
@@ -81,20 +81,20 @@ int main()
 }
 
 // Make sure we know which thread is the parent process
-// TRACE-DAG: - { type: 0, func-id: [[LSGT:[0-9]+]], function: {{.*log_syscall_gettid.*}}, cpu: {{.*}}, thread: [[THREAD1:[0-9]+]], kind: function-enter, tsc: {{[0-9]+}} }
+// TRACE-DAG: - { type: 0, func-id: [[LSGT:[0-9]+]], function: {{.*log_syscall_gettid.*}}, cpu: {{.*}}, thread: [[THREAD1:[0-9]+]], process: [[PROCESS1:[0-9]+]], kind: function-enter, tsc: {{[0-9]+}} }
 
-// TRACE-DAG: - { type: 0, func-id: [[PPOC:[0-9]+]], function: {{.*print_parent_or_child.*}}, cpu: {{.*}}, thread: [[THREAD1]], kind: function-enter, tsc: {{[0-9]+}} }
+// TRACE-DAG: - { type: 0, func-id: [[PPOC:[0-9]+]], function: {{.*print_parent_or_child.*}}, cpu: {{.*}}, thread: [[THREAD1]], process: [[PROCESS1]], kind: function-enter, tsc: {{[0-9]+}} }
 //
 // The parent will print its pid first
-// TRACE-DAG: - { type: 0, func-id: [[PPTARG:[0-9]+]], function: {{.*print_parent_tid.*}}, args: [ [[THREAD1]] ], cpu: {{.*}}, thread: [[THREAD1]], kind: function-enter-arg, tsc: {{[0-9]+}} }
-// TRACE-DAG: - { type: 0, func-id: [[PPTARG]], function: {{.*print_parent_tid.*}}, cpu: {{.*}}, thread: [[THREAD1]], kind: function-exit, tsc: {{[0-9]+}} }
+// TRACE-DAG: - { type: 0, func-id: [[PPTARG:[0-9]+]], function: {{.*print_parent_tid.*}}, args: [ [[THREAD1]] ], cpu: {{.*}}, thread: [[THREAD1]], process: [[PROCESS1]], kind: function-enter-arg, tsc: {{[0-9]+}} }
+// TRACE-DAG: - { type: 0, func-id: [[PPTARG]], function: {{.*print_parent_tid.*}}, cpu: {{.*}}, thread: [[THREAD1]], process: [[PROCESS1]], kind: function-exit, tsc: {{[0-9]+}} }
 //
-// TRACE:     - { type: 0, func-id: [[PPOC]], function: {{.*print_parent_or_child.*}}, cpu: {{.*}}, thread: [[THREAD1]], kind: function-{{exit|tail-exit}}, tsc: {{[0-9]+}} }
+// TRACE:     - { type: 0, func-id: [[PPOC]], function: {{.*print_parent_or_child.*}}, cpu: {{.*}}, thread: [[THREAD1]], process: [[PROCESS1]], kind: function-{{exit|tail-exit}}, tsc: {{[0-9]+}} }
 
-// TRACE-DAG: - { type: 0, func-id: [[PPOC]], function: {{.*print_parent_or_child.*}}, cpu: {{.*}}, thread: [[THREAD2:[0-9]+]], kind: function-enter, tsc: {{[0-9]+}} }
+// TRACE-DAG: - { type: 0, func-id: [[PPOC]], function: {{.*print_parent_or_child.*}}, cpu: {{.*}}, thread: [[THREAD2:[0-9]+]], process: [[PROCESS2:[0-9]+]], kind: function-enter, tsc: {{[0-9]+}} }
 //
 // The child will print its pid now
-// TRACE-DAG: - { type: 0, func-id: [[PCTARG:[0-9]+]], function: {{.*print_child_tid.*}}, args: [ [[THREAD2]] ], cpu: {{.*}}, thread: [[THREAD2]], kind: function-enter-arg, tsc: {{[0-9]+}} }
-// TRACE-DAG: - { type: 0, func-id: [[PCTARG]], function: {{.*print_child_tid.*}}, cpu: {{.*}}, thread: [[THREAD2]], kind: function-exit, tsc: {{[0-9]+}} }
+// TRACE-DAG: - { type: 0, func-id: [[PCTARG:[0-9]+]], function: {{.*print_child_tid.*}}, args: [ [[THREAD2]] ], cpu: {{.*}}, thread: [[THREAD2]], process: [[PROCESS2]], kind: function-enter-arg, tsc: {{[0-9]+}} }
+// TRACE-DAG: - { type: 0, func-id: [[PCTARG]], function: {{.*print_child_tid.*}}, cpu: {{.*}}, thread: [[THREAD2]], process: [[PROCESS2]], kind: function-exit, tsc: {{[0-9]+}} }
 //
-// TRACE:     - { type: 0, func-id: [[PPOC]], function: {{.*print_parent_or_child.*}}, cpu: {{.*}}, thread: [[THREAD2]], kind: function-{{exit|tail-exit}}, tsc: {{[0-9]+}} }
+// TRACE:     - { type: 0, func-id: [[PPOC]], function: {{.*print_parent_or_child.*}}, cpu: {{.*}}, thread: [[THREAD2]], process: [[PROCESS2]], kind: function-{{exit|tail-exit}}, tsc: {{[0-9]+}} }