Index: lib/xray/tests/unit/fdr_logging_test.cc =================================================================== --- lib/xray/tests/unit/fdr_logging_test.cc +++ lib/xray/tests/unit/fdr_logging_test.cc @@ -87,7 +87,7 @@ 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 @@ 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 @@ 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; Index: lib/xray/xray_basic_logging.cc =================================================================== --- lib/xray/xray_basic_logging.cc +++ lib/xray/xray_basic_logging.cc @@ -90,7 +90,9 @@ // 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); Index: lib/xray/xray_fdr_log_records.h =================================================================== --- lib/xray/xray_fdr_log_records.h +++ lib/xray/xray_fdr_log_records.h @@ -33,6 +33,7 @@ CallArgument, BufferExtents, TypedEventMarker, + Pid, }; // Use 7 bits to identify this record type. Index: lib/xray/xray_fdr_logging.cc =================================================================== --- lib/xray/xray_fdr_logging.cc +++ lib/xray/xray_fdr_logging.cc @@ -125,9 +125,9 @@ 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 @@ 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(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 @@ TLD.RecordPtr = static_cast(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 @@ XRayFileHeader &H = reinterpret_cast(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 Index: test/xray/TestCases/Posix/fdr-mode.cc =================================================================== --- test/xray/TestCases/Posix/fdr-mode.cc +++ test/xray/TestCases/Posix/fdr-mode.cc @@ -81,32 +81,32 @@ } // 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}} Index: test/xray/TestCases/Posix/fdr-single-thread.cc =================================================================== --- test/xray/TestCases/Posix/fdr-single-thread.cc +++ test/xray/TestCases/Posix/fdr-single-thread.cc @@ -34,5 +34,5 @@ } // 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]+}} } Index: test/xray/TestCases/Posix/fdr-thread-order.cc =================================================================== --- test/xray/TestCases/Posix/fdr-thread-order.cc +++ test/xray/TestCases/Posix/fdr-thread-order.cc @@ -61,7 +61,7 @@ } // 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]+}} } Index: test/xray/TestCases/Posix/fork_basic_logging.cc =================================================================== --- test/xray/TestCases/Posix/fork_basic_logging.cc +++ test/xray/TestCases/Posix/fork_basic_logging.cc @@ -81,20 +81,20 @@ } // 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]+}} }