[compiler-rt] r298982 - [XRay] [compiler-rt] Write buffer length to FDR log before writing buffer.

[Dean Michael Berris via llvm-commits]

Author: dberris
Date: Wed Mar 29 00:56:37 2017
New Revision: 298982

URL: http://llvm.org/viewvc/llvm-project?rev=298982&view=rev
Log:
[XRay] [compiler-rt] Write buffer length to FDR log before writing buffer.

Summary:
Currently the FDR log writer, upon flushing, dumps a sequence of buffers from
its freelist to disk. A reader can read the first buffer up to an EOB record,
but then it is unclear how far ahead to scan to find the next threads traces.

There are a few ways to handle this problem.
1. The reader has externalized knowledge of the buffer size.
2. The size of buffers is in the file header or otherwise encoded in the log.
3. Only write out the portion of the buffer with records. When released, the
   buffers are marked with a size.
4. The reader looks for memory that matches a pattern and synchronizes on it.

2 and 3 seem the most flexible and 2 does not rule 3 out.

This is an implementation of 2.

In addition, the function handler for fdr more aggressively checks for
finalization and makes an attempt to release its buffer.

Reviewers: pelikan, dberris

Reviewed By: dberris

Subscribers: llvm-commits

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

Modified:
    compiler-rt/trunk/include/xray/xray_records.h
    compiler-rt/trunk/lib/xray/xray_buffer_queue.h
    compiler-rt/trunk/lib/xray/xray_fdr_logging.cc
    compiler-rt/trunk/lib/xray/xray_fdr_logging_impl.h

Modified: compiler-rt/trunk/include/xray/xray_records.h
URL: http://llvm.org/viewvc/llvm-project/compiler-rt/trunk/include/xray/xray_records.h?rev=298982&r1=298981&r2=298982&view=diff
==============================================================================
--- compiler-rt/trunk/include/xray/xray_records.h (original)
+++ compiler-rt/trunk/include/xray/xray_records.h Wed Mar 29 00:56:37 2017
@@ -24,6 +24,14 @@ enum FileTypes {
   FDR_LOG = 1,
 };
 
+// FDR mode use of the union field in the XRayFileHeader.
+struct alignas(16) FdrAdditionalHeaderData {
+  uint64_t ThreadBufferSize;
+};
+
+static_assert(sizeof(FdrAdditionalHeaderData) == 16,
+              "FdrAdditionalHeaderData != 16 bytes");
+
 // 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 {
@@ -42,10 +50,15 @@ 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 'clock_gettime'. This
-  // allows readers of the file to determine when the file was created or
-  // written down.
-  struct timespec TS;
+  union {
+    char FreeForm[16];
+    // The current civiltime timestamp, as retrived from 'clock_gettime'. This
+    // allows readers of the file to determine when the file was created or
+    // written down.
+    struct timespec TS;
+
+    struct FdrAdditionalHeaderData FdrData;
+  };
 } __attribute__((packed));
 
 static_assert(sizeof(XRayFileHeader) == 32, "XRayFileHeader != 32 bytes");

Modified: compiler-rt/trunk/lib/xray/xray_buffer_queue.h
URL: http://llvm.org/viewvc/llvm-project/compiler-rt/trunk/lib/xray/xray_buffer_queue.h?rev=298982&r1=298981&r2=298982&view=diff
==============================================================================
--- compiler-rt/trunk/lib/xray/xray_buffer_queue.h (original)
+++ compiler-rt/trunk/lib/xray/xray_buffer_queue.h Wed Mar 29 00:56:37 2017
@@ -98,6 +98,9 @@ public:
                                     __sanitizer::memory_order_acquire);
   }
 
+  /// Returns the configured size of the buffers in the buffer queue.
+  size_t ConfiguredBufferSize() const { return BufferSize; }
+
   /// Sets the state of the BufferQueue to finalizing, which ensures that:
   ///
   ///   - All subsequent attempts to retrieve a Buffer will fail.

Modified: compiler-rt/trunk/lib/xray/xray_fdr_logging.cc
URL: http://llvm.org/viewvc/llvm-project/compiler-rt/trunk/lib/xray/xray_fdr_logging.cc?rev=298982&r1=298981&r2=298982&view=diff
==============================================================================
--- compiler-rt/trunk/lib/xray/xray_fdr_logging.cc (original)
+++ compiler-rt/trunk/lib/xray/xray_fdr_logging.cc Wed Mar 29 00:56:37 2017
@@ -125,12 +125,16 @@ XRayLogFlushStatus fdrLoggingFlush() XRA
   // before setting the values in the header.
   Header.ConstantTSC = 1;
   Header.NonstopTSC = 1;
-  clock_gettime(CLOCK_REALTIME, &Header.TS);
+  Header.FdrData = FdrAdditionalHeaderData{LocalBQ->ConfiguredBufferSize()};
   retryingWriteAll(Fd, reinterpret_cast<char *>(&Header),
                    reinterpret_cast<char *>(&Header) + sizeof(Header));
+
   LocalBQ->apply([&](const BufferQueue::Buffer &B) {
-    retryingWriteAll(Fd, reinterpret_cast<char *>(B.Buffer),
-                     reinterpret_cast<char *>(B.Buffer) + B.Size);
+    uint64_t BufferSize = B.Size;
+    if (BufferSize > 0) {
+      retryingWriteAll(Fd, reinterpret_cast<char *>(B.Buffer),
+                       reinterpret_cast<char *>(B.Buffer) + B.Size);
+    }
   });
   __sanitizer::atomic_store(&LogFlushStatus,
                             XRayLogFlushStatus::XRAY_LOG_FLUSHED,

Modified: compiler-rt/trunk/lib/xray/xray_fdr_logging_impl.h
URL: http://llvm.org/viewvc/llvm-project/compiler-rt/trunk/lib/xray/xray_fdr_logging_impl.h?rev=298982&r1=298981&r2=298982&view=diff
==============================================================================
--- compiler-rt/trunk/lib/xray/xray_fdr_logging_impl.h (original)
+++ compiler-rt/trunk/lib/xray/xray_fdr_logging_impl.h Wed Mar 29 00:56:37 2017
@@ -311,10 +311,24 @@ static inline void processFunctionHook(
     __sanitizer::atomic_sint32_t &LoggingStatus,
     const std::shared_ptr<BufferQueue> &BQ) XRAY_NEVER_INSTRUMENT {
   // Bail out right away if logging is not initialized yet.
-  if (__sanitizer::atomic_load(&LoggingStatus,
-                               __sanitizer::memory_order_acquire) !=
-      XRayLogInitStatus::XRAY_LOG_INITIALIZED)
+  // We should take the opportunity to release the buffer though.
+  auto Status = __sanitizer::atomic_load(&LoggingStatus,
+                                         __sanitizer::memory_order_acquire);
+  if (Status != XRayLogInitStatus::XRAY_LOG_INITIALIZED) {
+    if (RecordPtr != nullptr &&
+        (Status == XRayLogInitStatus::XRAY_LOG_FINALIZING ||
+         Status == XRayLogInitStatus::XRAY_LOG_FINALIZED)) {
+      writeEOBMetadata();
+      auto EC = BQ->releaseBuffer(Buffer);
+      if (EC != BufferQueue::ErrorCode::Ok) {
+        Report("Failed to release buffer at %p; error=%s\n", Buffer.Buffer,
+               BufferQueue::getErrorString(EC));
+        return;
+      }
+      RecordPtr = nullptr;
+    }
     return;
+  }
 
   // We use a thread_local variable to keep track of which CPUs we've already
   // run, and the TSC times for these CPUs. This allows us to stop repeating the