[XRay][compiler-rt] XRay Flight Data Recorder Mode

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: 293015

4 files changed, 169 insertions, 10 deletions

diff --git a/compiler-rt/lib/xray/tests/CMakeLists.txt b/compiler-rt/lib/xray/tests/CMakeLists.txt
index 6cb17934c89..2ef277302bf 100644
--- a/compiler-rt/lib/xray/tests/CMakeLists.txt
+++ b/compiler-rt/lib/xray/tests/CMakeLists.txt
@@ -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}
@@ -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}
@@ -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()
diff --git a/compiler-rt/lib/xray/tests/unit/CMakeLists.txt b/compiler-rt/lib/xray/tests/unit/CMakeLists.txt
index 3e5412d41e6..62d01f23958 100644
--- a/compiler-rt/lib/xray/tests/unit/CMakeLists.txt
+++ b/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)
diff --git a/compiler-rt/lib/xray/tests/unit/buffer_queue_test.cc b/compiler-rt/lib/xray/tests/unit/buffer_queue_test.cc
index d46f19402c2..de855fd8519 100644
--- a/compiler-rt/lib/xray/tests/unit/buffer_queue_test.cc
+++ b/compiler-rt/lib/xray/tests/unit/buffer_queue_test.cc
@@ -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);
@@ -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;
@@ -42,7 +50,9 @@ 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;
@@ -50,7 +60,9 @@ TEST(BufferQueueTest, ReleaseUnknown) {
 }
 
 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);
@@ -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)) {
@@ -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
diff --git a/compiler-rt/lib/xray/tests/unit/fdr_logging_test.cc b/compiler-rt/lib/xray/tests/unit/fdr_logging_test.cc
new file mode 100644
index 00000000000..34366927f1b
--- /dev/null
+++ b/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