From: Dean Michael Berris Date: Wed, 11 Jul 2018 07:14:27 +0000 (+0000) Subject: [XRay] basic mode PID and TID always fetch X-Git-Tag: llvmorg-7.0.0-rc1~1749 X-Git-Url: http://review.tizen.org/git/?a=commitdiff_plain;h=8299e4b8dbe34e7986ba99db554956800aded4b0;p=platform%2Fupstream%2Fllvm.git [XRay] basic mode PID and TID always fetch Summary: XRayRecords now includes a PID field. Basic handlers fetch pid and tid each time they are called instead of caching the value. Added a testcase that calls fork and checks if the child TID is different from the parent TID to verify that the processes' TID are different in the trace. Reviewers: dberris, Maknee Reviewed By: dberris, Maknee Subscribers: kpw, llvm-commits, #sanitizers Differential Revision: https://reviews.llvm.org/D49025 llvm-svn: 336769 --- diff --git a/compiler-rt/include/xray/xray_records.h b/compiler-rt/include/xray/xray_records.h index 2b415bb..8cfdeee 100644 --- a/compiler-rt/include/xray/xray_records.h +++ b/compiler-rt/include/xray/xray_records.h @@ -95,8 +95,11 @@ struct alignas(32) XRayRecord { // The thread ID for the currently running thread. uint32_t TId = 0; + // The ID of process that is currently running + uint32_t PId = 0; + // Use some bytes in the end of the record for buffers. - char Buffer[12] = {}; + char Buffer[8] = {}; } __attribute__((packed)); static_assert(sizeof(XRayRecord) == 32, "XRayRecord != 32 bytes"); @@ -115,8 +118,8 @@ struct alignas(32) XRayArgPayload { // The thread ID for the currently running thread. uint32_t TId = 0; - // Add more padding. - uint8_t Padding2[4] = {}; + // The ID of process that is currently running + uint32_t PId = 0; // The argument payload. uint64_t Arg = 0; diff --git a/compiler-rt/lib/xray/xray_basic_logging.cc b/compiler-rt/lib/xray/xray_basic_logging.cc index 138679d..529fde8d 100644 --- a/compiler-rt/lib/xray/xray_basic_logging.cc +++ b/compiler-rt/lib/xray/xray_basic_logging.cc @@ -60,7 +60,6 @@ struct alignas(64) ThreadLocalData { size_t StackSize = 0; size_t StackEntries = 0; int Fd = -1; - tid_t TID = 0; }; static pthread_key_t PThreadKey; @@ -119,7 +118,6 @@ static ThreadLocalData &getThreadLocalData() XRAY_NEVER_INSTRUMENT { Report("Not initializing TLD since ThreadBufferSize == 0.\n"); return false; } - TLD.TID = GetTid(); pthread_setspecific(PThreadKey, &TLD); TLD.Fd = getGlobalFd(); TLD.InMemoryBuffer = reinterpret_cast( @@ -227,7 +225,8 @@ void InMemoryRawLog(int32_t FuncId, XRayEntryType Type, R.RecordType = RecordTypes::NORMAL; R.CPU = CPU; R.TSC = TSC; - R.TId = TLD.TID; + R.TId = GetTid(); + R.PId = internal_getpid(); R.Type = Type; R.FuncId = FuncId; auto FirstEntry = reinterpret_cast(TLD.InMemoryBuffer); @@ -274,7 +273,8 @@ void InMemoryRawLogWithArg(int32_t FuncId, XRayEntryType Type, uint64_t Arg1, XRayArgPayload R; R.RecordType = RecordTypes::ARG_PAYLOAD; R.FuncId = FuncId; - R.TId = TLD.TID; + R.TId = GetTid(); + R.PId = internal_getpid(); R.Arg = Arg1; internal_memcpy(FirstEntry + TLD.BufferOffset, &R, sizeof(R)); if (++TLD.BufferOffset == BuffLen) { @@ -334,12 +334,12 @@ static void TLDDestructor(void *P) XRAY_NEVER_INSTRUMENT { if (TLD.ShadowStack) InternalFree(TLD.ShadowStack); if (Verbosity()) - Report("Cleaned up log for TID: %d\n", TLD.TID); + Report("Cleaned up log for TID: %d\n", GetTid()); }); if (TLD.Fd == -1 || TLD.BufferOffset == 0) { if (Verbosity()) - Report("Skipping buffer for TID: %d; Fd = %d; Offset = %llu\n", TLD.TID, + Report("Skipping buffer for TID: %d; Fd = %d; Offset = %llu\n", GetTid(), TLD.Fd, TLD.BufferOffset); return; } diff --git a/compiler-rt/test/xray/TestCases/Posix/fork_basic_logging.cc b/compiler-rt/test/xray/TestCases/Posix/fork_basic_logging.cc new file mode 100644 index 0000000..414fc32 --- /dev/null +++ b/compiler-rt/test/xray/TestCases/Posix/fork_basic_logging.cc @@ -0,0 +1,100 @@ +// Check that when forking in basic logging mode, we get the different tids for child and parent +// RUN: %clangxx_xray -g -std=c++11 %s -o %t +// RUN: rm -f fork-basic-logging-test-* +// RUN: XRAY_OPTIONS="patch_premain=true xray_logfile_base=fork-basic-logging-test- \ +// RUN: xray_mode=xray-basic verbosity=1" \ +// RUN: %run %t 2>&1 | FileCheck %s +// RUN: %llvm_xray convert --symbolize --output-format=yaml -instr_map=%t \ +// RUN: "`ls -S fork-basic-logging-test-* | head -1`" \ +// RUN: | FileCheck %s --check-prefix=TRACE + +// REQUIRES: x86_64-target-arch +// REQUIRES: built-in-llvm-tree + +#include "xray/xray_log_interface.h" +#include +#include +#include +#include + +//modified from sanitizer + +static uintptr_t syscall_gettid() { + uint64_t retval; + asm volatile("syscall" : "=a"(retval) : "a"(__NR_gettid) : "rcx", "r11", + "memory", "cc"); + return retval; +} + +///////////// + +static uint64_t parent_tid; + +[[clang::xray_always_instrument]] +uint64_t __attribute__((noinline)) log_syscall_gettid() +{ + //don't optimize this function away + uint64_t tid = syscall_gettid(); + printf("Logging tid %lu\n", tid); + return tid; +} + +[[clang::xray_always_instrument, clang::xray_log_args(1)]] +void __attribute__((noinline)) print_parent_tid(uint64_t tid) +{ + printf("Parent with tid %lu", tid); +} + +[[clang::xray_always_instrument, clang::xray_log_args(1)]] +void __attribute__((noinline)) print_child_tid(uint64_t tid) +{ + printf("Child with tid %lu", tid); +} + +[[clang::xray_always_instrument]] void __attribute__((noinline)) print_parent_or_child() +{ + uint64_t tid = syscall_gettid(); + if(tid == parent_tid) + { + print_parent_tid(tid); + } + else + { + print_child_tid(tid); + } +} + +int main() +{ + parent_tid = log_syscall_gettid(); + if(fork()) + { + print_parent_or_child(); + // CHECK: Parent with tid + } + else + { + print_parent_or_child(); + // CHECK: Child with tid + } + return 0; +} + +// 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: [[PPOC:[0-9]+]], function: {{.*print_parent_or_child.*}}, cpu: {{.*}}, thread: [[THREAD1]], 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: - { type: 0, func-id: [[PPOC]], function: {{.*print_parent_or_child.*}}, cpu: {{.*}}, thread: [[THREAD1]], 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]+}} } +// +// 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: - { type: 0, func-id: [[PPOC]], function: {{.*print_parent_or_child.*}}, cpu: {{.*}}, thread: [[THREAD2]], kind: function-{{exit|tail-exit}}, tsc: {{[0-9]+}} }