[compiler-rt][XRay] Initial per-thread inmemory logging implementation

[dberris]

Summary

Depends on D21612 which implements the building blocks for the compiler-rt
implementation of the XRay runtime. We use a naive in-memory log of fixed-size
entries that get written out to a log file when the buffers are full, and when
the thread exits.

This implementation lays some foundations on to allowing for more complex XRay
records to be written to the log in subsequent changes. It also defines the format
that the function call accounting tool in D21987 will start building upon.

Once D21987 lands, we should be able to start defining more tests using that tool
once the function call accounting tool becomes part of the llvm distribution.

[majnemer]

lib/xray/xray_inmemory_log.cc

107 ↗

(On Diff #62718)

Could you please use the __rdtscp intrinsic?
Might be good to only do so if you are on X86 with a fallback of __builtin_readcyclecounter ?

116 ↗

(On Diff #62718)

What if you get a partial write?

[dberris]

lib/xray/xray_inmemory_log.cc

107 ↗

(On Diff #62718)

Using the __rdtscp intrinsic, let's cross the bridge for non-x86 later?

116 ↗

(On Diff #62718)

Good catch! Makes the code a bit more complicated, but more correct AFAICT now.

[dberris]

• Use __rdtscp() and account for partial writes

[majnemer]

lib/xray/xray_inmemory_log.cc

123 ↗

(On Diff #62722)

Isn't this code dead because your while condition requires Written to be non-zero?

[dberris]

• Remove dead code

[dberris]

lib/xray/xray_inmemory_log.cc

124 ↗

(On Diff #62724)

Whoops, yes. Good catch. :)

[dberris]

• Remove demo logging, use in-memory logging

[majnemer]

lib/xray/xray_inmemory_log.cc

119 ↗

(On Diff #62725)

Should we handle errno == EINTR?

[dberris]

lib/xray/xray_inmemory_log.cc

119 ↗

(On Diff #62725)

Yes, and refactor this a bit so we do the right thing both times. :)

[dberris]

• Refactor a bit, make retrying write work consistently at thread exit and when buffer is full

[mehdi_amini]

lib/xray/xray_inmemory_log.cc

63 ↗

(On Diff #62726)

Early exit:

if (!Offset) return;

65 ↗

(On Diff #62726)

This while condition isn't clear to me: Written would be 0 if nothing is written, which seem unexpected.
What about a while (1)?

74 ↗

(On Diff #62726)

If you want to handle partial write properly, I think you need to update start and offset as well.

I feel the interface for RetryingWrite would be more usual of C++ std algorithm with a Begin / End instead of start/offset.

108 ↗

(On Diff #62726)

Shouldn't error be printed to stderr?

111 ↗

(On Diff #62726)

This looks like debugging, is it intended to be here?
Do you really want unconditionally always on? And is stdout the right output?

[dberris]

• Handle partial writes better.

lib/xray/xray_inmemory_log.cc

111 ↗

(On Diff #62726)

Yep, this is for debugging. I'm still thinking about how to control this filename either through an API or through environment variables.

[majnemer]

lib/xray/xray_inmemory_log.cc

80 ↗

(On Diff #62821)

ISTM that this assert can fail in practice.

I'd maintain the buffer you are trying to write as just a char * to correctly handle this.

[majnemer]

lib/xray/xray_inmemory_log.cc

71 ↗

(On Diff #62821)

I don't believe write can actually return zero for this case.

[mehdi_amini]

lib/xray/xray_inmemory_log.cc

71 ↗

(On Diff #62821)

When does write can actually return zero according to the spec?

[majnemer]

lib/xray/xray_inmemory_log.cc

71 ↗

(On Diff #62821)

From my recollection, it should only be possible if you pass write a count of zero bytes.

[dberris]

lib/xray/xray_inmemory_log.cc

71 ↗

(On Diff #62821)

Ah, that's right. I was confused by the documentation too. Fixed.

80 ↗

(On Diff #62821)

Good catch. Done.

[dberris]

• Rebase
• Support partial writes better-er

[mehdi_amini]

lib/xray/xray_inmemory_log.cc

72 ↗

(On Diff #63181)

I does not matter much for this patch, but for my own curiosity, do you have a pointer to the doc that mentions the zero returned case?

122 ↗

(On Diff #63181)

stderr maybe?

[dberris]

Rebase

[dberris]

This is still not ready, but the patch we're dependent on is ready (D21612). I will continue to iterate on this to clean it up a bit more, and add more useful information into the head of the log to help with things like figuring out how much walltime elapsed between two TSC ticks where the binary was run, a version identifier for the log, etc.

lib/xray/xray_inmemory_log.cc

73 ↗

(On Diff #64106)

Link I can find: http://linux.die.net/man/2/write

It says pretty much that it will only return 0 if the size provided was 0. I don't know why anybody would do that, but I guess the API allows it so there's a special case for that. :)

123 ↗

(On Diff #64106)

Yeah, I think a better way of doing this is to provide the log file base name as a flag (with a sane default, maybe synthesized as "/tmp/<pid>.xray"), then that means we don't need to write it out unless we're being verbose.

[dberris]

Rebase

[dberris]

• Expose the log record definitions and write out headers at the beginning of the log file

[dberris]

Rebase

[dberris]

• Undo changes in assembler

[dberris]

Question for Reid/Medhi/Eric:

Now that D21612 has landed I'm thinking of adding tests here to be able to do some sanity-checking of the generated log file. That though means that the "best" means of doing this is by using a tool that will output the information in a verifiable manner. We have some options in that regard:

• Implement a stand-alone tool in compiler-rt just for testing. This seems brittle but should be simple enough to do.
• Land D21987 in LLVM and then potentially depend on that from compiler-rt (although I'm not sure if the dependency chain would be correct).

I'm leaning towards the first solution, but I'd like to hear your thoughts on how best to go about this too.

Cheers

[dberris]

• WIP: Adding one test, but still failing

I'm currently getting the following error:

		lit.py: /usr/local/google/home/dberris/xray/llvm/utils/lit/lit/TestingConfig.py:115: fatal: unable to parse config file '/usr/local/google/home/dberris/xray/llvm/projects/compiler-rt/test/xray/lit.cfg', traceback: Traceback (most recent call last):
			File "/usr/local/google/home/dberris/xray/llvm/utils/lit/lit/TestingConfig.py", line 102, in load_from_path
				exec(compile(data, path, 'exec'), cfg_globals, None)
			File "/usr/local/google/home/dberris/xray/llvm/projects/compiler-rt/test/xray/lit.cfg", line 6, in <module>
				config.name = 'XRay' + config.name_suffix
		AttributeError: TestingConfig instance has no attribute 'name_suffix'

I'm not seeing what the difference is though with other testing set-ups for other compiler-rt tests.

[dberris]

• Fixup CMake config and lit configuration
• Fixup test case to clean up after itself

This is now ready for another look.

[dberris]

• Remove redundant/wrong addition of COMPILER_RT_BUILD_XRAY

[dberris]

• Rename xray_trampoline_x86.S to xray_trampoline_x86_64.S

Based on review comments from D21612.

[dberris]

ping?

[dberris]

Rebase; depends on D23051.

[dberris]

Rebase again, with fix to math for stack adjustment.

[dberris]

Rebase; Depends on D23154.

[dberris]

Rebase

[majnemer]

include/xray/xray_records.h

41–42 ↗

(On Diff #67112)

Should these be bitfields?

lib/xray/xray_inmemory_log.cc

47 ↗

(On Diff #67112)

Are we following LLVM convention for XRay? If so, I'd make this function start with a lowercase letter.

52–53 ↗

(On Diff #67112)

This should be Written < 0. I don't believe errno will be set to anything good if write returns 0; I think you'd observe a previous errno value.

73 ↗

(On Diff #67112)

Why noexcept?

90 ↗

(On Diff #67112)

Ditto regarding llvm convention.

90 ↗

(On Diff #67112)

Should the long be a long long?

91 ↗

(On Diff #67112)

Should we pass in O_CLOEXEC?

95–96 ↗

(On Diff #67112)

How do you feel about these potentially failing?

98 ↗

(On Diff #67112)

Shouldn't this be s64?

156 ↗

(On Diff #67112)

Any reason not to just use 0?

175 ↗

(On Diff #67112)

I'd just use unsigned here to match how __rdtscp is defined.

[dberris]

Rebase + style comments and some correctness fixes

include/xray/xray_records.h

41–42 ↗

(On Diff #67112)

Good idea, yep.

lib/xray/xray_inmemory_log.cc

47 ↗

(On Diff #67112)

Yes, we should be -- sorry I haven't quite internalised the rules. :/

52–53 ↗

(On Diff #67112)

Good catch, thanks. Done.

73 ↗

(On Diff #67112)

Habbit... removed.

91 ↗

(On Diff #67112)

Good idea -- yes, done.

95–96 ↗

(On Diff #67112)

Not very good... is it better now?

[dberris]

Rebase

[majnemer]

include/xray/xray_records.h

40–42 ↗

(On Diff #68126)

Why not give these bitfields an underlying type of bool?

lib/xray/xray_inmemory_log.cc

71 ↗

(On Diff #68126)

Should we assert that Fd > 0?

77 ↗

(On Diff #68126)

Why do we have this fsync? Might deserve a comment.

95–99 ↗

(On Diff #68126)

This seems wrong in the face of partial reads. Perhaps a retryingRead is called for?

[dberris]

• Address review comments
• Make use of the naive log configurable
• Add test to make sure options from args works

[dberris]

lib/xray/xray_inmemory_log.cc

71 ↗

(On Diff #68126)

Instead of asserting, I check that Fd is valid before using it in the write in the destructor.

77 ↗

(On Diff #68126)

Explained a little in a comment, essentially because we're not doing any sort of reference counting (for simplicity's sake) we rely on the sync to flush the data at a thread's exit. We can implement reference counting, but that would complicate this a bit more than necessary IMO.

[majnemer]

include/xray/xray_records.h

39–42 ↗

(On Diff #68136)

You could gain another byte for Padding by sending this between Type and CycleFrequency.

lib/xray/xray_inmemory_log.cc

70 ↗

(On Diff #68136)

ssize_t?

[dberris]

• Re-order some flags in XRayFileHeader

[dberris]

• Use ssize_t for BytesRead

[rSerge]

Please, see inline.

include/xray/xray_records.h

47 ↗

(On Diff #68142)

So CycleFrequency is an 8-byte variable not aligned to 8 bytes. This may cause portability issues to other CPUs, not only performance drops for unaligned memory access, but they say on some CPUs unaligned access is completely forbidden.

lib/xray/xray_inmemory_log.cc

71 ↗

(On Diff #68142)

So the loop runs while BytesRead<0 ? Shouldn't it run while BytesToRead > 0?
Then in an if, before checking errno, you can check whether BytesRead < 0.

90 ↗

(On Diff #68142)

So retryingWrite writes all bytes, while retryingRead reads some bytes up to the given number of bytes, right? Then their parameters should indicate this, or the functions should be renamed to e.g. retryingWriteAll and retryingReadSome .

130 ↗

(On Diff #68142)

This crashes if Buffer contains formatting, e.g. %d (random memory read) or worse %n (random memory write), but no formatting arguments are given. Consider changing to `fprintf(stderr, "%s", Buffer);

135 ↗

(On Diff #68142)

(Minor) Why not to have BuffLen as a local static const? This would remove "action at a distance" anti-pattern.

137 ↗

(On Diff #68142)

Why not thread_local ? How do you ensure no 2 threads race to check whether Fd is initialized and, if not, initializing it?

139 ↗

(On Diff #68142)

Why do you call it Printf? f in printf stays for formatted, I guess. But PrintToStdErr doesn't support formatting. Consider renaming to SetPrintAndReportCallback .

141 ↗

(On Diff #68142)

Would be UB in a race condition.

142 ↗

(On Diff #68142)

How the magic 246 number is calculated?

143 ↗

(On Diff #68142)

Is 255 logically equal to sizeof(TmpFilename)-1 ? The latter would be preferred over a magic number, and it's easier then to change just one place - the declaration of TmpFilename variable.

147 ↗

(On Diff #68142)

Consider making "XXXXXX" a constant, replacing 6 with its sizeof-1.

159–163 ↗

(On Diff #68142)

What if the system has multiple CPU sockets, with different CPUs installed so that TSC frequencies are different for different cores?

166 ↗

(On Diff #68142)

Why not to report an error?

[dberris]

Address comments

[dberris]

include/xray/xray_records.h

47 ↗

(On Diff #68142)

Are you aware of specific CPUs where this would be an issue?

I'm happy to change it, but I'd like to understand whether this is an actual problem, or just a hypothetical one.

Note that we don't read this, we only ever write it down, so the performance hit isn't as important as maximising the packing of the bytes that eventually make it to disk. The 15 byte padding gives us 15 more bytes to use for later extending the information in the file header.

lib/xray/xray_inmemory_log.cc

137 ↗

(On Diff #68142)

C++11 ensures this for us, that the first time this function is called, this static variable is initialised exactly once -- this is meant to be synchronised across all threads too.

139 ↗

(On Diff #68142)

This API is defined by the common sanitizer tools -- I'm just a using it. :)

There are places where Report(...) is called with a format string and additional arguments (like printf), and underneath it dispatches to a callback when these formatted print's are actually invoked. We're providing something that deals with the string that's post-formatted.

141 ↗

(On Diff #68142)

C++11 ensures this is not a racy initialisation.

142 ↗

(On Diff #68142)

I was being conservative here, giving an allowance of 10 bytes difference between the size of the temporary filename's buffer size total and the base filename provided as a flag. Fixed it to do relative calculations instead of magic numbers.

159–163 ↗

(On Diff #68142)

I'm not sure how this works in non-x86, but we assume that all the CPUs will run in the same rate, and use that as an approximation for the TSC frequency rate. This means if we're on this branch of the conditional, we don't get the reliable number and take a guess anyway.

[sdardis]

include/xray/xray_records.h

48 ↗

(On Diff #68969)

Apologies for the drive-by comment.

Pre MIPSR6 requires different instructions (e.g. swl/swr to store 4 bytes) to write unaligned data if it is not naturally aligned to its size. Attempting to access 2/4/8 byte words with a normal load/store triggers a CPU level address exception if unaligned.

For MIPSR6 unaligned support is required, but it is implementation dependent how this is achieved. For example, an implementation could support unaligned access within a cacheline but require OS intervention if the unaligned access crosses a cacheline.

IIRC x86, PowerPC, AArch64 have native support for unaligned access. SPARC, ARM typically don't.

[dberris]

include/xray/xray_records.h

48 ↗

(On Diff #68969)

Apologies for the drive-by comment.

No need for apologies, comments most appreciated!

Pre MIPSR6 requires different instructions (e.g. swl/swr to store 4 bytes) to write unaligned data if it is not naturally aligned to its size. Attempting to access 2/4/8 byte words with a normal load/store triggers a CPU level address exception if unaligned.

For MIPSR6 unaligned support is required, but it is implementation dependent how this is achieved. For example, an implementation could support unaligned access within a cacheline but require OS intervention if the unaligned access crosses a cacheline.

IIRC x86, PowerPC, AArch64 have native support for unaligned access. SPARC, ARM typically don't.

Cool, this is good to know. Happy to change this implementation to be more portable to more platforms. :)

[dberris]

• Undo changes to CMakeLists.txt
• Align CycleFrequency to 8 byte boundaries.

[dberris]

Address comments on alignment of CycleFrequency.

[rSerge]

Looks good to me.

lib/xray/xray_inmemory_log.cc

160–164 ↗

(On Diff #68988)

I meant a x86/x86_64 system, consumer motherboards can easily have 2 sockets to install 2 different CPUs. Non-x86/x86_64 system is a harder question: a replacement for TSC/RDTSC would be needed.

[dberris]

Rebase before landing.

compiler-rt/trunk/include/xray/xray_records.h

+//===-- xray_records.h ------------------------------------------*- C++ -*-===//
+//
+//                     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 dynamic runtime instrumentation system.
+//
+// This header exposes some record types useful for the XRay in-memory logging
+// implementation.
+//
+//===----------------------------------------------------------------------===//
+
+#ifndef XRAY_XRAY_RECORDS_H
+#define XRAY_XRAY_RECORDS_H
+
+namespace __xray {
+
+enum FileTypes {
+  NAIVE_LOG = 0,
+};
+
+// This data structure is used to describe the contents of the file. We use this
+// for versioning the supported XRay file formats.
+struct alignas(32) XRayFileHeader {
+  uint16_t Version = 0;
+
+  // The type of file we're writing out. See the FileTypes enum for more
+  // information. This allows different implementations of the XRay logging to
+  // have different files for different information being stored.
+  uint16_t Type = 0;
+
+  // What follows are a set of flags that indicate useful things for when
+  // reading the data in the file.
+  bool ConstantTSC : 1;
+  bool NonstopTSC : 1;
+
+  // The frequency by which TSC increases per-second.
+  alignas(8) uint64_t CycleFrequency = 0;
+} __attribute__((packed));
+
+static_assert(sizeof(XRayFileHeader) == 32, "XRayFileHeader != 32 bytes");
+
+enum RecordTypes {
+  NORMAL = 0,
+};
+
+struct alignas(32) XRayRecord {
+  // This is the type of the record being written. We use 16 bits to allow us to
+  // treat this as a discriminant, and so that the first 4 bytes get packed
+  // properly. See RecordTypes for more supported types.
+  uint16_t RecordType = 0;
+
+  // The CPU where the thread is running. We assume number of CPUs <= 256.
+  uint8_t CPU = 0;
+
+  // The type of the event. Usually either ENTER = 0 or EXIT = 1.
+  uint8_t Type = 0;
+
+  // The function ID for the record.
+  int32_t FuncId = 0;
+
+  // Get the full 8 bytes of the TSC when we get the log record.
+  uint64_t TSC = 0;
+
+  // The thread ID for the currently running thread.
+  uint32_t TId = 0;
+
+  // Use some bytes in the end of the record for buffers.
+  char Buffer[4] = {};
+} __attribute__((packed));
+
+static_assert(sizeof(XRayRecord) == 32, "XRayRecord != 32 bytes");
+
+} // namespace __xray
+
+#endif // XRAY_XRAY_RECORDS_H

compiler-rt/trunk/lib/xray/CMakeLists.txt

 # Build for the XRay runtime support library.
 
 set(XRAY_SOURCES
   xray_init.cc
   xray_interface.cc
   xray_flags.cc
+  xray_inmemory_log.cc
 )
 
 set(x86_64_SOURCES
-    xray_trampoline_x86.S
+    xray_trampoline_x86_64.S
     ${XRAY_SOURCES})
 
 include_directories(..)
 include_directories(../../include)
 
 set(XRAY_CFLAGS ${SANITIZER_COMMON_CFLAGS})
 
 set(XRAY_COMMON_DEFINITIONS XRAY_HAS_EXCEPTIONS=1)
 
 add_compiler_rt_object_libraries(RTXray
-    ARCHS ${XRAY_SUPPORTED_ARCH}
-    SOURCES ${XRAY_SOURCES} CFLAGS ${XRAY_CFLAGS}
-    DEFS ${XRAY_COMMON_DEFINITIONS})
+    ARCHS ${XRAY_SUPPORTED_ARCH}
+    SOURCES ${XRAY_SOURCES} CFLAGS ${XRAY_CFLAGS}
+    DEFS ${XRAY_COMMON_DEFINITIONS})
 
 add_custom_target(xray)
 set(XRAY_COMMON_RUNTIME_OBJECT_LIBS
     RTSanitizerCommon
     RTSanitizerCommonLibc)
 
 foreach (arch ${XRAY_SUPPORTED_ARCH})
     if (CAN_TARGET_${arch})

compiler-rt/trunk/lib/xray/xray_flags.inc

 //
 //===----------------------------------------------------------------------===//
 #ifndef XRAY_FLAG
 #error "Define XRAY_FLAG prior to including this file!"
 #endif
 
 XRAY_FLAG(bool, patch_premain, true,
           "Whether to patch instrumentation points before main.")
+XRAY_FLAG(bool, xray_naive_log, true,
+          "Whether to install the naive log implementation.")
+XRAY_FLAG(const char *, xray_logfile_base, "xray-log.",
+          "Filename base for the xray logfile.")

compiler-rt/trunk/lib/xray/xray_inmemory_log.cc

+//===-- xray_inmemory_log.cc ------------------------------------*- C++ -*-===//
+//
+//                     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 dynamic runtime instrumentation system.
+//
+// Implementation of a simple in-memory log of XRay events. This defines a
+// logging function that's compatible with the XRay handler interface, and
+// routines for exporting data to files.
+//
+//===----------------------------------------------------------------------===//
+
+#include <cassert>
+#include <fcntl.h>
+#include <mutex>
+#include <sys/stat.h>
+#include <sys/syscall.h>
+#include <sys/types.h>
+#include <thread>
+#include <unistd.h>
+#include <x86intrin.h>
+
+#include "sanitizer_common/sanitizer_libc.h"
+#include "xray/xray_records.h"
+#include "xray_flags.h"
+#include "xray_interface_internal.h"
+
+// __xray_InMemoryRawLog will use a thread-local aligned buffer capped to a
+// certain size (32kb by default) and use it as if it were a circular buffer for
+// events. We store simple fixed-sized entries in the log for external analysis.
+
+extern "C" {
+void __xray_InMemoryRawLog(int32_t FuncId, XRayEntryType Type);
+}
+
+namespace __xray {
+
+std::mutex LogMutex;
+
+static void retryingWriteAll(int Fd, char *Begin, char *End) {
+  if (Begin == End)
+    return;
+  auto TotalBytes = std::distance(Begin, End);
+  while (auto Written = write(Fd, Begin, TotalBytes)) {
+    if (Written < 0) {
+      if (errno == EINTR)
+        continue; // Try again.
+      Report("Failed to write; errno = %d", errno);
+      return;
+    }
+
+    // FIXME: Figure out whether/how to assert properly.
+    assert(static_cast<uint64_t>(Written) <= TotalBytes);
+    TotalBytes -= Written;
+    if (TotalBytes == 0)
+      break;
+    Begin += Written;
+  }
+}
+
+static std::pair<ssize_t, bool> retryingReadSome(int Fd, char *Begin,
+                                                 char *End) {
+  auto BytesToRead = std::distance(Begin, End);
+  ssize_t BytesRead;
+  ssize_t TotalBytesRead = 0;
+  while (BytesToRead && (BytesRead = read(Fd, Begin, BytesToRead))) {
+    if (BytesRead == -1) {
+      if (errno == EINTR)
+        continue;
+      Report("Read error; errno = %d", errno);
+      return std::make_pair(TotalBytesRead, false);
+    }
+
+    TotalBytesRead += BytesRead;
+    BytesToRead -= BytesRead;
+    Begin += BytesRead;
+  }
+  return std::make_pair(TotalBytesRead, true);
+}
+
+static bool readValueFromFile(const char *Filename, long long *Value) {
+  int Fd = open(Filename, O_RDONLY | O_CLOEXEC);
+  if (Fd == -1)
+    return false;
+  static constexpr size_t BufSize = 256;
+  char Line[BufSize] = {};
+  ssize_t BytesRead;
+  bool Success;
+  std::tie(BytesRead, Success) = retryingReadSome(Fd, Line, Line + BufSize);
+  if (!Success)
+    return false;
+  close(Fd);
+  char *End = nullptr;
+  long long Tmp = internal_simple_strtoll(Line, &End, 10);
+  bool Result = false;
+  if (Line[0] != '\0' && (*End == '\n' || *End == '\0')) {
+    *Value = Tmp;
+    Result = true;
+  }
+  return Result;
+}
+
+class ThreadExitFlusher {
+  int Fd;
+  XRayRecord *Start;
+  size_t &Offset;
+
+public:
+  explicit ThreadExitFlusher(int Fd, XRayRecord *Start, size_t &Offset)
+      : Fd(Fd), Start(Start), Offset(Offset) {}
+
+  ~ThreadExitFlusher() {
+    std::lock_guard<std::mutex> L(LogMutex);
+    if (Fd > 0 && Start != nullptr) {
+      retryingWriteAll(Fd, reinterpret_cast<char *>(Start),
+                       reinterpret_cast<char *>(Start + Offset));
+      // Because this thread's exit could be the last one trying to write to the
+      // file and that we're not able to close out the file properly, we sync
+      // instead and hope that the pending writes are flushed as the thread
+      // exits.
+      fsync(Fd);
+    }
+  }
+};
+
+} // namespace __xray
+
+using namespace __xray;
+
+void PrintToStdErr(const char *Buffer) { fprintf(stderr, "%s", Buffer); }
+
+void __xray_InMemoryRawLog(int32_t FuncId, XRayEntryType Type) {
+  using Buffer =
+      std::aligned_storage<sizeof(XRayRecord), alignof(XRayRecord)>::type;
+  static constexpr size_t BuffLen = 1024;
+  thread_local static Buffer InMemoryBuffer[BuffLen] = {};
+  thread_local static size_t Offset = 0;
+  static int Fd = [] {
+    // FIXME: Figure out how to make this less stderr-dependent.
+    SetPrintfAndReportCallback(PrintToStdErr);
+    // Open a temporary file once for the log.
+    static char TmpFilename[256] = {};
+    static char TmpWildcardPattern[] = "XXXXXX";
+    auto E = internal_strncat(TmpFilename, flags()->xray_logfile_base,
+                              sizeof(TmpFilename) - 10);
+    if (static_cast<size_t>((E + 6) - TmpFilename) >
+        (sizeof(TmpFilename) - 1)) {
+      Report("XRay log file base too long: %s", flags()->xray_logfile_base);
+      return -1;
+    }
+    internal_strncat(TmpFilename, TmpWildcardPattern,
+                     sizeof(TmpWildcardPattern) - 1);
+    int Fd = mkstemp(TmpFilename);
+    if (Fd == -1) {
+      Report("XRay: Failed opening temporary file '%s'; not logging events.",
+             TmpFilename);
+      return -1;
+    }
+    if (Verbosity())
+      fprintf(stderr, "XRay: Log file in '%s'\n", TmpFilename);
+
+    // Get the cycle frequency from SysFS on Linux.
+    long long CPUFrequency = -1;
+    if (readValueFromFile("/sys/devices/system/cpu/cpu0/tsc_freq_khz",
+                          &CPUFrequency)) {
+      CPUFrequency *= 1000;
+    } else if (readValueFromFile(
+                   "/sys/devices/system/cpu/cpu0/cpufreq/cpuinfo_max_freq",
+                   &CPUFrequency)) {
+      CPUFrequency *= 1000;
+    } else {
+      Report("Unable to determine CPU frequency for TSC accounting.");
+    }
+
+    // Since we're here, we get to write the header. We set it up so that the
+    // header will only be written once, at the start, and let the threads
+    // logging do writes which just append.
+    XRayFileHeader Header;
+    Header.Version = 1;
+    Header.Type = FileTypes::NAIVE_LOG;
+    Header.CycleFrequency =
+        CPUFrequency == -1 ? 0 : static_cast<uint64_t>(CPUFrequency);
+
+    // FIXME: Actually check whether we have 'constant_tsc' and 'nonstop_tsc'
+    // before setting the values in the header.
+    Header.ConstantTSC = 1;
+    Header.NonstopTSC = 1;
+    retryingWriteAll(Fd, reinterpret_cast<char *>(&Header),
+                     reinterpret_cast<char *>(&Header) + sizeof(Header));
+    return Fd;
+  }();
+  if (Fd == -1)
+    return;
+  thread_local __xray::ThreadExitFlusher Flusher(
+      Fd, reinterpret_cast<__xray::XRayRecord *>(InMemoryBuffer), Offset);
+  thread_local pid_t TId = syscall(SYS_gettid);
+
+  // First we get the useful data, and stuff it into the already aligned buffer
+  // through a pointer offset.
+  auto &R = reinterpret_cast<__xray::XRayRecord *>(InMemoryBuffer)[Offset];
+  unsigned CPU;
+  R.RecordType = RecordTypes::NORMAL;
+  R.TSC = __rdtscp(&CPU);
+  R.CPU = CPU;
+  R.TId = TId;
+  R.Type = Type;
+  R.FuncId = FuncId;
+  ++Offset;
+  if (Offset == BuffLen) {
+    std::lock_guard<std::mutex> L(LogMutex);
+    auto RecordBuffer = reinterpret_cast<__xray::XRayRecord *>(InMemoryBuffer);
+    retryingWriteAll(Fd, reinterpret_cast<char *>(RecordBuffer),
+                     reinterpret_cast<char *>(RecordBuffer + Offset));
+    Offset = 0;
+  }
+}
+
+static auto Unused = [] {
+  if (flags()->xray_naive_log)
+    __xray_set_handler(__xray_InMemoryRawLog);
+  return true;
+}();

compiler-rt/trunk/lib/xray/xray_trampoline_x86.S

-//===-- xray_trampoline_x86.s -----------------------------------*- ASM -*-===//
-//
-//                     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 dynamic runtime instrumentation system.
-//
-// This implements the X86-specific assembler for the trampolines.
-//
-//===----------------------------------------------------------------------===//
-
-  .text
-  .file "xray_trampoline_x86.S"
-  .globl __xray_FunctionEntry
-  .align 16, 0x90
-  .type __xray_FunctionEntry,@function
-
-__xray_FunctionEntry:
-  .cfi_startproc
-  // Save caller provided registers before doing any actual work.
-  pushq %rbp
-  .cfi_def_cfa_offset 16
-  subq $200, %rsp
-  movupd  %xmm0, 184(%rsp)
-  movupd  %xmm1, 168(%rsp)
-  movupd  %xmm2, 152(%rsp)
-  movupd  %xmm3, 136(%rsp)
-  movupd  %xmm4, 120(%rsp)
-  movupd  %xmm5, 104(%rsp)
-  movupd  %xmm6, 88(%rsp)
-  movupd  %xmm7, 72(%rsp)
-  movq  %rdi, 64(%rsp)
-  movq  %rax, 56(%rsp)
-  movq  %rdx, 48(%rsp)
-  movq  %rsi, 40(%rsp)
-  movq  %rcx, 32(%rsp)
-  movq  %r8, 24(%rsp)
-  movq  %r9, 16(%rsp)
-
-  // de-mangled, that's __xray::XRayPatchedFunction, and we're doing an acquire
-  // load (on x86 is a normal mov instruction).
-  movq  _ZN6__xray19XRayPatchedFunctionE(%rip), %rax
-  testq %rax, %rax
-  je  .Ltmp0
-
-  // assume that %r10d has the function id.
-  movl  %r10d, %edi
-  xor %esi,%esi
-  callq *%rax
-.Ltmp0:
-  // restore the registers
-  movupd  184(%rsp), %xmm0
-  movupd  168(%rsp), %xmm1
-  movupd  152(%rsp), %xmm2
-  movupd  136(%rsp), %xmm3
-  movupd  120(%rsp), %xmm4
-  movupd  104(%rsp), %xmm5
-  movupd  88(%rsp) , %xmm6
-  movupd  72(%rsp) , %xmm7
-  movq  64(%rsp), %rdi
-  movq  56(%rsp), %rax
-  movq  48(%rsp), %rdx
-  movq  40(%rsp), %rsi
-  movq  32(%rsp), %rcx
-  movq  24(%rsp), %r8
-  movq  16(%rsp), %r9
-  addq  $200, %rsp
-  popq  %rbp
-  retq
-.Ltmp1:
-  .size __xray_FunctionEntry, .Ltmp1-__xray_FunctionEntry
-  .cfi_endproc
-
-  .globl __xray_FunctionExit
-  .align 16, 0x90
-  .type __xray_FunctionExit,@function
-__xray_FunctionExit:
-  .cfi_startproc
-  // Save the important registers first. Since we're assuming that this
-  // function is only jumped into, we only preserve the registers for
-  // returning.
-  pushq %rbp
-  .cfi_def_cfa_offset 16
-  subq  $56, %rsp
-  .cfi_def_cfa_offset 32
-  movupd  %xmm0, 40(%rsp)
-  movupd  %xmm1, 24(%rsp)
-  movq  %rax, 16(%rsp)
-  movq  %rdx, 8(%rsp)
-  movq  _ZN6__xray19XRayPatchedFunctionE(%rip), %rax
-  testq %rax,%rax
-  je  .Ltmp2
-
-  movl  %r10d, %edi
-  movl  $1, %esi
-  callq *%rax
-.Ltmp2:
-  // Restore the important registers.
-  movupd  40(%rsp), %xmm0
-  movupd  24(%rsp), %xmm1
-  movq  16(%rsp), %rax
-  movq  8(%rsp), %rdx
-  addq  $56, %rsp
-  popq  %rbp
-  retq
-.Ltmp3:
-  .size __xray_FunctionExit, .Ltmp3-__xray_FunctionExit
-  .cfi_endproc

compiler-rt/trunk/lib/xray/xray_trampoline_x86_64.S

+//===-- xray_trampoline_x86.s -----------------------------------*- ASM -*-===//
+//
+//                     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 dynamic runtime instrumentation system.
+//
+// This implements the X86-specific assembler for the trampolines.
+//
+//===----------------------------------------------------------------------===//
+
+  .text
+  .file "xray_trampoline_x86.S"
+  .globl __xray_FunctionEntry
+  .align 16, 0x90
+  .type __xray_FunctionEntry,@function
+
+__xray_FunctionEntry:
+  .cfi_startproc
+  // Save caller provided registers before doing any actual work.
+  pushq %rbp
+  .cfi_def_cfa_offset 16
+  subq $200, %rsp
+  movupd  %xmm0, 184(%rsp)
+  movupd  %xmm1, 168(%rsp)
+  movupd  %xmm2, 152(%rsp)
+  movupd  %xmm3, 136(%rsp)
+  movupd  %xmm4, 120(%rsp)
+  movupd  %xmm5, 104(%rsp)
+  movupd  %xmm6, 88(%rsp)
+  movupd  %xmm7, 72(%rsp)
+  movq  %rdi, 64(%rsp)
+  movq  %rax, 56(%rsp)
+  movq  %rdx, 48(%rsp)
+  movq  %rsi, 40(%rsp)
+  movq  %rcx, 32(%rsp)
+  movq  %r8, 24(%rsp)
+  movq  %r9, 16(%rsp)
+
+  // de-mangled, that's __xray::XRayPatchedFunction, and we're doing an acquire
+  // load (on x86 is a normal mov instruction).
+  movq  _ZN6__xray19XRayPatchedFunctionE(%rip), %rax
+  testq %rax, %rax
+  je  .Ltmp0
+
+  // assume that %r10d has the function id.
+  movl  %r10d, %edi
+  xor %esi,%esi
+  callq *%rax
+.Ltmp0:
+  // restore the registers
+  movupd  184(%rsp), %xmm0
+  movupd  168(%rsp), %xmm1
+  movupd  152(%rsp), %xmm2
+  movupd  136(%rsp), %xmm3
+  movupd  120(%rsp), %xmm4
+  movupd  104(%rsp), %xmm5
+  movupd  88(%rsp) , %xmm6
+  movupd  72(%rsp) , %xmm7
+  movq  64(%rsp), %rdi
+  movq  56(%rsp), %rax
+  movq  48(%rsp), %rdx
+  movq  40(%rsp), %rsi
+  movq  32(%rsp), %rcx
+  movq  24(%rsp), %r8
+  movq  16(%rsp), %r9
+  addq  $200, %rsp
+  popq  %rbp
+  retq
+.Ltmp1:
+  .size __xray_FunctionEntry, .Ltmp1-__xray_FunctionEntry
+  .cfi_endproc
+
+  .globl __xray_FunctionExit
+  .align 16, 0x90
+  .type __xray_FunctionExit,@function
+__xray_FunctionExit:
+  .cfi_startproc
+  // Save the important registers first. Since we're assuming that this
+  // function is only jumped into, we only preserve the registers for
+  // returning.
+  pushq %rbp
+  .cfi_def_cfa_offset 16
+  subq  $56, %rsp
+  .cfi_def_cfa_offset 32
+  movupd  %xmm0, 40(%rsp)
+  movupd  %xmm1, 24(%rsp)
+  movq  %rax, 16(%rsp)
+  movq  %rdx, 8(%rsp)
+  movq  _ZN6__xray19XRayPatchedFunctionE(%rip), %rax
+  testq %rax,%rax
+  je  .Ltmp2
+
+  movl  %r10d, %edi
+  movl  $1, %esi
+  callq *%rax
+.Ltmp2:
+  // Restore the important registers.
+  movupd  40(%rsp), %xmm0
+  movupd  24(%rsp), %xmm1
+  movq  16(%rsp), %rax
+  movq  8(%rsp), %rdx
+  addq  $56, %rsp
+  popq  %rbp
+  retq
+.Ltmp3:
+  .size __xray_FunctionExit, .Ltmp3-__xray_FunctionExit
+  .cfi_endproc

compiler-rt/trunk/test/lit.common.cfg

possibly_dangerous_env_vars = ['ASAN_OPTIONS', 'DFSAN_OPTIONS', 'LSAN_OPTIONS',
                                'COMPILER_PATH', 'RC_DEBUG_OPTIONS',
                                'CINDEXTEST_PREAMBLE_FILE', 'LIBRARY_PATH',
                                'CPATH', 'C_INCLUDE_PATH', 'CPLUS_INCLUDE_PATH',
                                'OBJC_INCLUDE_PATH', 'OBJCPLUS_INCLUDE_PATH',
                                'LIBCLANG_TIMING', 'LIBCLANG_OBJTRACKING',
                                'LIBCLANG_LOGGING', 'LIBCLANG_BGPRIO_INDEX',
                                'LIBCLANG_BGPRIO_EDIT', 'LIBCLANG_NOTHREADS',
                                'LIBCLANG_RESOURCE_USAGE',
-                               'LIBCLANG_CODE_COMPLETION_LOGGING']
+                               'LIBCLANG_CODE_COMPLETION_LOGGING',
+                               'XRAY_OPTIONS']
 # Clang/Win32 may refer to %INCLUDE%. vsvarsall.bat sets it.
 if platform.system() != 'Windows':
     possibly_dangerous_env_vars.append('INCLUDE')
 for name in possibly_dangerous_env_vars:
   if name in config.environment:
     del config.environment[name]
 
 # Tweak PATH to include llvm tools dir.

compiler-rt/trunk/test/xray/TestCases/Linux/fixedsize-logging.cc

+// Check to make sure that we have a log file with a fixed-size.
+
+// RUN: %clangxx_xray -std=c++11 %s -o %t
+// RUN: XRAY_OPTIONS="verbosity=1 xray_logfile_base=fixedsize-logging-" %run %t 2>&1 | FileCheck %s
+//
+// After all that, clean up the output xray log.
+//
+// RUN: rm fixedsize-logging-*
+
+#include <cstdio>
+
+[[clang::xray_always_instrument]] void foo() {
+  printf("foo() is always instrumented!");
+}
+
+int main() {
+  // CHECK: XRay: Log file in 'fixedsize-logging-{{.*}}'
+  foo();
+  // CHECK: foo() is always instrumented!
+}

compiler-rt/trunk/test/xray/TestCases/Linux/optional-inmemory-log.cc

+// Make sure that we don't get the inmemory logging implementation enabled when
+// we turn it off via options.
+
+// RUN: %clangxx_xray -std=c++11 %s -o %t
+// RUN: XRAY_OPTIONS="verbosity=1 xray_naive_log=false xray_logfile_base=optional-inmemory-log.xray-" %run %t 2>&1 | FileCheck %s
+//
+// Make sure we clean out the logs in case there was a bug.
+//
+// RUN: rm -f optional-inmemory-log.xray-*
+
+#include <cstdio>
+
+[[clang::xray_always_instrument]] void foo() {
+  printf("foo() is always instrumented!");
+}
+
+int main() {
+  // CHECK-NOT: XRay: Log file in 'optional-inmemory-log.xray-{{.*}}'
+  foo();
+  // CHECK: foo() is always instrumented!
+}