Skip to content

Commit

Permalink
[XRay] basic mode PID and TID always fetch
Browse files Browse the repository at this point in the history
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
  • Loading branch information
deanberris committed Jul 11, 2018
1 parent 02867f0 commit 8299e4b
Show file tree
Hide file tree
Showing 3 changed files with 112 additions and 9 deletions.
9 changes: 6 additions & 3 deletions compiler-rt/include/xray/xray_records.h
Expand Up @@ -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");
Expand All @@ -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;
Expand Down
12 changes: 6 additions & 6 deletions compiler-rt/lib/xray/xray_basic_logging.cc
Expand Up @@ -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;
Expand Down Expand Up @@ -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<XRayRecord *>(
Expand Down Expand Up @@ -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<XRayRecord *>(TLD.InMemoryBuffer);
Expand Down Expand Up @@ -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) {
Expand Down Expand Up @@ -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;
}
Expand Down
100 changes: 100 additions & 0 deletions 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 <stdio.h>
#include <unistd.h>
#include <stdint.h>
#include <sys/syscall.h>

//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]+}} }

0 comments on commit 8299e4b

Please sign in to comment.