Skip to content

Commit

Permalink
[XRay][compiler-rt] XRay Flight Data Recorder Mode
Browse files Browse the repository at this point in the history
Summary:
In this change we introduce the notion of a "flight data recorder" mode
for XRay logging, where XRay logs in-memory first, and write out data
on-demand as required (as opposed to the naive implementation that keeps
logging while tracing is "on"). This depends on D26232 where we
implement the core data structure for holding the buffers that threads
will be using to write out records of operation.

This implementation only currently works on x86_64 and depends heavily
on the TSC math to write out smaller records to the inmemory buffers.

Also, this implementation defines two different kinds of records with
different sizes (compared to the current naive implementation): a
MetadataRecord (16 bytes) and a FunctionRecord (8 bytes). MetadataRecord
entries are meant to write out information like the thread ID for which
the metadata record is defined for, whether the execution of a thread
moved to a different CPU, etc. while a FunctionRecord represents the
different kinds of function call entry/exit records we might encounter
in the course of a thread's execution along with a delta from the last
time the logging handler was called.

While this implementation is not exactly what is described in the
original XRay whitepaper, this one gives us an initial implementation
that we can iterate and build upon.

Reviewers: echristo, rSerge, majnemer

Subscribers: mehdi_amini, llvm-commits, mgorny

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

llvm-svn: 290852
  • Loading branch information
deanberris committed Jan 3, 2017
1 parent edd09b3 commit 33d305b
Show file tree
Hide file tree
Showing 18 changed files with 1,189 additions and 127 deletions.
51 changes: 51 additions & 0 deletions compiler-rt/include/xray/xray_log_interface.h
@@ -0,0 +1,51 @@
//===-- xray_log_interface.h ----------------------------------------------===//
//
// The LLVM Compiler Infrastructure
//
// This file is distributed under the University of Illinois Open Source
// License. See LICENSE.TXT for details.
//
//===----------------------------------------------------------------------===//
//
// This file is a part of XRay, a function call tracing system.
//
// APIs for installing a new logging implementation.
//===----------------------------------------------------------------------===//
#ifndef XRAY_XRAY_LOG_INTERFACE_H
#define XRAY_XRAY_LOG_INTERFACE_H

#include "xray/xray_interface.h"
#include <stddef.h>

extern "C" {

enum XRayLogInitStatus {
XRAY_LOG_UNINITIALIZED,
XRAY_LOG_INITIALIZING,
XRAY_LOG_INITIALIZED,
XRAY_LOG_FINALIZING,
XRAY_LOG_FINALIZED,
};

enum XRayLogFlushStatus {
XRAY_LOG_NOT_FLUSHING,
XRAY_LOG_FLUSHING,
XRAY_LOG_FLUSHED
};

struct XRayLogImpl {
XRayLogInitStatus (*log_init)(size_t, size_t, void *, size_t);
XRayLogInitStatus (*log_finalize)();
void (*handle_arg0)(int32_t, XRayEntryType);
XRayLogFlushStatus (*flush_log)();
};

void __xray_set_log_impl(XRayLogImpl Impl);
XRayLogInitStatus __xray_log_init(size_t BufferSize, size_t MaxBuffers,
void *Args, size_t ArgsSize);
XRayLogInitStatus __xray_log_finalize();
XRayLogFlushStatus __xray_log_flushLog();

} // extern "C"

#endif // XRAY_XRAY_LOG_INTERFACE_H
6 changes: 6 additions & 0 deletions compiler-rt/include/xray/xray_records.h
Expand Up @@ -21,6 +21,7 @@ namespace __xray {

enum FileTypes {
NAIVE_LOG = 0,
FDR_LOG = 1,
};

// This data structure is used to describe the contents of the file. We use this
Expand All @@ -40,6 +41,11 @@ struct alignas(32) XRayFileHeader {

// The frequency by which TSC increases per-second.
alignas(8) uint64_t CycleFrequency = 0;

// The current civiltime timestamp, as retrived from 'gettimeofday'. This
// allows readers of the file to determine when the file was created or
// written down.
struct timespec TS;
} __attribute__((packed));

static_assert(sizeof(XRayFileHeader) == 32, "XRayFileHeader != 32 bytes");
Expand Down
37 changes: 12 additions & 25 deletions compiler-rt/lib/xray/CMakeLists.txt
@@ -1,15 +1,15 @@
# Build for the XRay runtime support library.

# Core XRay runtime library implementation files.
# XRay runtime library implementation files.
set(XRAY_SOURCES
xray_inmemory_log.cc
xray_init.cc
xray_interface.cc
xray_flags.cc
xray_inmemory_log.cc)

# XRay flight data recorder (FDR) implementation files.
set(XRAY_FDR_SOURCES
xray_buffer_queue.cc)
xray_interface.cc
xray_buffer_queue.cc
xray_log_interface.cc
xray_fdr_logging.cc
xray_utils.cc)

set(x86_64_SOURCES
xray_x86_64.cc
Expand All @@ -21,12 +21,13 @@ set(arm_SOURCES
xray_trampoline_arm.S
${XRAY_SOURCES})

set(armhf_SOURCES ${arm_SOURCES})
set(armhf_SOURCES
${arm_SOURCES})

set(aarch64_SOURCES
xray_AArch64.cc
xray_trampoline_AArch64.S
${XRAY_SOURCES})
xray_AArch64.cc
xray_trampoline_AArch64.S
${XRAY_SOURCES})

include_directories(..)
include_directories(../../include)
Expand All @@ -41,13 +42,7 @@ add_compiler_rt_object_libraries(RTXray
SOURCES ${XRAY_SOURCES} CFLAGS ${XRAY_CFLAGS}
DEFS ${XRAY_COMMON_DEFINITIONS})

add_compiler_rt_object_libraries(RTXrayFDR
ARCHS ${XRAY_SUPPORTED_ARCH}
SOURCES ${XRAY_FDR_SOURCES} CFLAGS ${XRAY_CFLAGS}
DEFS ${XRAY_COMMON_DEFINITIONS})

add_compiler_rt_component(xray)
add_compiler_rt_component(xray-fdr)

set(XRAY_COMMON_RUNTIME_OBJECT_LIBS
RTSanitizerCommon
Expand All @@ -63,14 +58,6 @@ foreach(arch ${XRAY_SUPPORTED_ARCH})
DEFS ${XRAY_COMMON_DEFINITIONS}
OBJECT_LIBS ${XRAY_COMMON_RUNTIME_OBJECT_LIBS}
PARENT_TARGET xray)
add_compiler_rt_runtime(clang_rt.xray-fdr
STATIC
ARCHS ${arch}
SOURCES ${XRAY_FDR_SOURCES}
CFLAGS ${XRAY_CFLAGS}
DEFS ${XRAY_COMMON_DEFINITIONS}
OBJECT_LIBS ${XRAY_COMMON_RUNTIME_OBJECT_LIBS}
PARENT_TARGET xray-fdr)
endif()
endforeach()

Expand Down
10 changes: 6 additions & 4 deletions compiler-rt/lib/xray/tests/CMakeLists.txt
Expand Up @@ -8,14 +8,15 @@ set(XRAY_UNITTEST_CFLAGS
${COMPILER_RT_UNITTEST_CFLAGS}
${COMPILER_RT_GTEST_CFLAGS}
-I${COMPILER_RT_SOURCE_DIR}/include
-I${COMPILER_RT_SOURCE_DIR}/lib/xray)
-I${COMPILER_RT_SOURCE_DIR}/lib/xray
-I${COMPILER_RT_SOURCE_DIR}/lib)

macro(xray_compile obj_list source arch)
get_filename_component(basename ${source} NAME)
set(output_obj "${basename}.${arch}.o")
get_target_flags_for_arch(${arch} TARGET_CFLAGS)
if(NOT COMPILER_RT_STANDALONE_BUILD)
list(APPEND COMPILE_DEPS gtest_main xray-fdr)
list(APPEND COMPILE_DEPS gtest_main xray)
endif()
clang_compile(${output_obj} ${source}
CFLAGS ${XRAY_UNITTEST_CFLAGS} ${TARGET_CFLAGS}
Expand All @@ -38,7 +39,7 @@ macro(add_xray_unittest testname)
get_target_flags_for_arch(${arch} TARGET_LINK_FLAGS)
set(TEST_DEPS ${TEST_OBJECTS})
if(NOT COMPILER_RT_STANDALONE_BUILD)
list(APPEND TEST_DEPS gtest_main xray-fdr)
list(APPEND TEST_DEPS gtest_main xray)
endif()
if(NOT APPLE)
add_compiler_rt_test(XRayUnitTests ${testname}
Expand All @@ -47,7 +48,8 @@ macro(add_xray_unittest testname)
LINK_FLAGS ${TARGET_LINK_FLAGS}
-lstdc++ -lm ${CMAKE_THREAD_LIBS_INIT}
-lpthread
-L${COMPILER_RT_LIBRARY_OUTPUT_DIR} -lclang_rt.xray-fdr-${arch})
-L${COMPILER_RT_LIBRARY_OUTPUT_DIR} -lclang_rt.xray-${arch}
-latomic -ldl -lrt)
endif()
# FIXME: Figure out how to run even just the unit tests on APPLE.
endforeach()
Expand Down
2 changes: 2 additions & 0 deletions compiler-rt/lib/xray/tests/unit/CMakeLists.txt
@@ -1,2 +1,4 @@
add_xray_unittest(XRayBufferQueueTest SOURCES
buffer_queue_test.cc xray_unit_test_main.cc)
add_xray_unittest(XRayFDRLoggingTest SOURCES
fdr_logging_test.cc xray_unit_test_main.cc)
40 changes: 34 additions & 6 deletions compiler-rt/lib/xray/tests/unit/buffer_queue_test.cc
Expand Up @@ -21,10 +21,16 @@ namespace __xray {

static constexpr size_t kSize = 4096;

TEST(BufferQueueTest, API) { BufferQueue Buffers(kSize, 1); }
TEST(BufferQueueTest, API) {
bool Success = false;
BufferQueue Buffers(kSize, 1, Success);
ASSERT_TRUE(Success);
}

TEST(BufferQueueTest, GetAndRelease) {
BufferQueue Buffers(kSize, 1);
bool Success = false;
BufferQueue Buffers(kSize, 1, Success);
ASSERT_TRUE(Success);
BufferQueue::Buffer Buf;
ASSERT_EQ(Buffers.getBuffer(Buf), std::error_code());
ASSERT_NE(nullptr, Buf.Buffer);
Expand All @@ -33,7 +39,9 @@ TEST(BufferQueueTest, GetAndRelease) {
}

TEST(BufferQueueTest, GetUntilFailed) {
BufferQueue Buffers(kSize, 1);
bool Success = false;
BufferQueue Buffers(kSize, 1, Success);
ASSERT_TRUE(Success);
BufferQueue::Buffer Buf0;
EXPECT_EQ(Buffers.getBuffer(Buf0), std::error_code());
BufferQueue::Buffer Buf1;
Expand All @@ -42,15 +50,19 @@ TEST(BufferQueueTest, GetUntilFailed) {
}

TEST(BufferQueueTest, ReleaseUnknown) {
BufferQueue Buffers(kSize, 1);
bool Success = false;
BufferQueue Buffers(kSize, 1, Success);
ASSERT_TRUE(Success);
BufferQueue::Buffer Buf;
Buf.Buffer = reinterpret_cast<void *>(0xdeadbeef);
Buf.Size = kSize;
EXPECT_EQ(std::errc::argument_out_of_domain, Buffers.releaseBuffer(Buf));
}

TEST(BufferQueueTest, ErrorsWhenFinalising) {
BufferQueue Buffers(kSize, 2);
bool Success = false;
BufferQueue Buffers(kSize, 2, Success);
ASSERT_TRUE(Success);
BufferQueue::Buffer Buf;
ASSERT_EQ(Buffers.getBuffer(Buf), std::error_code());
ASSERT_NE(nullptr, Buf.Buffer);
Expand All @@ -62,7 +74,9 @@ TEST(BufferQueueTest, ErrorsWhenFinalising) {
}

TEST(BufferQueueTest, MultiThreaded) {
BufferQueue Buffers(kSize, 100);
bool Success = false;
BufferQueue Buffers(kSize, 100, Success);
ASSERT_TRUE(Success);
auto F = [&] {
BufferQueue::Buffer B;
while (!Buffers.getBuffer(B)) {
Expand All @@ -78,4 +92,18 @@ TEST(BufferQueueTest, MultiThreaded) {
F();
}

TEST(BufferQueueTest, Apply) {
bool Success = false;
BufferQueue Buffers(kSize, 10, Success);
ASSERT_TRUE(Success);
auto Count = 0;
BufferQueue::Buffer B;
for (int I = 0; I < 10; ++I) {
ASSERT_FALSE(Buffers.getBuffer(B));
ASSERT_FALSE(Buffers.releaseBuffer(B));
}
Buffers.apply([&](const BufferQueue::Buffer &B) { ++Count; });
ASSERT_EQ(Count, 10);
}

} // namespace __xray
127 changes: 127 additions & 0 deletions compiler-rt/lib/xray/tests/unit/fdr_logging_test.cc
@@ -0,0 +1,127 @@
//===-- fdr_logging_test.cc -----------------------------------------------===//
//
// The LLVM Compiler Infrastructure
//
// This file is distributed under the University of Illinois Open Source
// License. See LICENSE.TXT for details.
//
//===----------------------------------------------------------------------===//
//
// This file is a part of XRay, a function call tracing system.
//
//===----------------------------------------------------------------------===//
#include "xray_fdr_logging.h"
#include "gtest/gtest.h"

#include <fcntl.h>
#include <iostream>
#include <sys/mman.h>
#include <sys/stat.h>
#include <sys/types.h>
#include <system_error>
#include <unistd.h>

#include "xray/xray_records.h"

namespace __xray {
namespace {

constexpr auto kBufferSize = 16384;
constexpr auto kBufferMax = 10;

struct ScopedFileCloserAndDeleter {
explicit ScopedFileCloserAndDeleter(int Fd, const char *Filename)
: Fd(Fd), Filename(Filename) {}

~ScopedFileCloserAndDeleter() {
if (Fd) {
close(Fd);
unlink(Filename);
}
}

int Fd;
const char *Filename;
};

TEST(FDRLoggingTest, Simple) {
FDRLoggingOptions Options;
Options.ReportErrors = true;
char TmpFilename[] = "fdr-logging-test.XXXXXX";
Options.Fd = mkstemp(TmpFilename);
ASSERT_NE(Options.Fd, -1);
ASSERT_EQ(FDRLogging_init(kBufferSize, kBufferMax, &Options,
sizeof(FDRLoggingOptions)),
XRayLogInitStatus::XRAY_LOG_INITIALIZED);
FDRLogging_handleArg0(1, XRayEntryType::ENTRY);
FDRLogging_handleArg0(1, XRayEntryType::EXIT);
ASSERT_EQ(FDRLogging_finalize(), XRayLogInitStatus::XRAY_LOG_FINALIZED);
ASSERT_EQ(FDRLogging_flush(), XRayLogFlushStatus::XRAY_LOG_FLUSHED);
ASSERT_EQ(FDRLogging_reset(), XRayLogInitStatus::XRAY_LOG_UNINITIALIZED);

// To do this properly, we have to close the file descriptor then re-open the
// file for reading this time.
ASSERT_EQ(close(Options.Fd), 0);
int Fd = open(TmpFilename, O_RDONLY);
ASSERT_NE(-1, Fd);
ScopedFileCloserAndDeleter Guard(Fd, TmpFilename);
auto Size = lseek(Fd, 0, SEEK_END);
ASSERT_NE(Size, 0);
// Map the file contents.
const char *Contents = static_cast<const char *>(
mmap(NULL, Size, PROT_READ, MAP_PRIVATE, Fd, 0));
ASSERT_NE(Contents, nullptr);

XRayFileHeader H;
memcpy(&H, Contents, sizeof(XRayFileHeader));
ASSERT_EQ(H.Version, 1);
ASSERT_EQ(H.Type, FileTypes::FDR_LOG);

// We require one buffer at least to have the "start of buffer" metadata
// record.
MetadataRecord MDR;
memcpy(&MDR, Contents + sizeof(XRayFileHeader), sizeof(MetadataRecord));
ASSERT_EQ(MDR.RecordKind, MetadataRecord::RecordKinds::NewBuffer);
}

TEST(FDRLoggingTest, Multiple) {
FDRLoggingOptions Options;
char TmpFilename[] = "fdr-logging-test.XXXXXX";
Options.Fd = mkstemp(TmpFilename);
ASSERT_NE(Options.Fd, -1);
ASSERT_EQ(FDRLogging_init(kBufferSize, kBufferMax, &Options,
sizeof(FDRLoggingOptions)),
XRayLogInitStatus::XRAY_LOG_INITIALIZED);
for (uint64_t I = 0; I < 100; ++I) {
FDRLogging_handleArg0(1, XRayEntryType::ENTRY);
FDRLogging_handleArg0(1, XRayEntryType::EXIT);
}
ASSERT_EQ(FDRLogging_finalize(), XRayLogInitStatus::XRAY_LOG_FINALIZED);
ASSERT_EQ(FDRLogging_flush(), XRayLogFlushStatus::XRAY_LOG_FLUSHED);
ASSERT_EQ(FDRLogging_reset(), XRayLogInitStatus::XRAY_LOG_UNINITIALIZED);

// To do this properly, we have to close the file descriptor then re-open the
// file for reading this time.
ASSERT_EQ(close(Options.Fd), 0);
int Fd = open(TmpFilename, O_RDONLY);
ASSERT_NE(-1, Fd);
ScopedFileCloserAndDeleter Guard(Fd, TmpFilename);
auto Size = lseek(Fd, 0, SEEK_END);
ASSERT_NE(Size, 0);
// Map the file contents.
const char *Contents = static_cast<const char *>(
mmap(NULL, Size, PROT_READ, MAP_PRIVATE, Fd, 0));
ASSERT_NE(Contents, nullptr);

XRayFileHeader H;
memcpy(&H, Contents, sizeof(XRayFileHeader));
ASSERT_EQ(H.Version, 1);
ASSERT_EQ(H.Type, FileTypes::FDR_LOG);

MetadataRecord MDR0;
memcpy(&MDR0, Contents + sizeof(XRayFileHeader), sizeof(MetadataRecord));
ASSERT_EQ(MDR0.RecordKind, MetadataRecord::RecordKinds::NewBuffer);
}

} // namespace
} // namespace __xray

0 comments on commit 33d305b

Please sign in to comment.