[compiler-rt] r318733 - [XRay] Use optimistic logging model for FDR mode
Dean Michael Berris via llvm-commits
llvm-commits at lists.llvm.org
Mon Nov 20 23:16:58 PST 2017
Author: dberris
Date: Mon Nov 20 23:16:57 2017
New Revision: 318733
URL: http://llvm.org/viewvc/llvm-project?rev=318733&view=rev
Log:
[XRay] Use optimistic logging model for FDR mode
Summary:
Before this change, the FDR mode implementation relied on at thread-exit
handling to return buffers back to the (global) buffer queue. This
introduces issues with the initialisation of the thread_local objects
which, even through the use of pthread_setspecific(...) may eventually
call into an allocation function. Similar to previous changes in this
line, we're finding that there is a huge potential for deadlocks when
initialising these thread-locals when the memory allocation
implementation is also xray-instrumented.
In this change, we limit the call to pthread_setspecific(...) to provide
a non-null value to associate to the key created with
pthread_key_create(...). While this doesn't completely eliminate the
potential for the deadlock(s), it does allow us to still clean up at
thread exit when we need to. The change is that we don't need to do more
work when starting and ending a thread's lifetime. We also have a test
to make sure that we actually can safely recycle the buffers in case we
end up re-using the buffer(s) available from the queue on multiple
thread entry/exits.
This change cuts across both LLVM and compiler-rt to allow us to update
both the XRay runtime implementation as well as the library support for
loading these new versions of the FDR mode logging. Version 2 of the FDR
logging implementation makes the following changes:
* Introduction of a new 'BufferExtents' metadata record that's outside
of the buffer's contents but are written before the actual buffer.
This data is associated to the Buffer handed out by the BufferQueue
rather than a record that occupies bytes in the actual buffer.
* Removal of the "end of buffer" records. This is in-line with the
changes we described above, to allow for optimistic logging without
explicit record writing at thread exit.
The optimistic logging model operates under the following assumptions:
* Threads writing to the buffers will potentially race with the thread
attempting to flush the log. To avoid this situation from occuring,
we make sure that when we've finalized the logging implementation,
that threads will see this finalization state on the next write, and
either choose to not write records the thread would have written or
write the record(s) in two phases -- first write the record(s), then
update the extents metadata.
* We change the buffer queue implementation so that once it's handed
out a buffer to a thread, that we assume that buffer is marked
"used" to be able to capture partial writes. None of this will be
safe to handle if threads are racing to write the extents records
and the reader thread is attempting to flush the log. The optimism
comes from the finalization routine being required to complete
before we attempt to flush the log.
This is a fairly significant semantics change for the FDR
implementation. This is why we've decided to update the version number
for FDR mode logs. The tools, however, still need to be able to support
older versions of the log until we finally deprecate those earlier
versions.
Reviewers: dblaikie, pelikan, kpw
Subscribers: llvm-commits, hiraditya
Differential Revision: https://reviews.llvm.org/D39526
Modified:
compiler-rt/trunk/lib/xray/tests/unit/fdr_logging_test.cc
compiler-rt/trunk/lib/xray/xray_buffer_queue.cc
compiler-rt/trunk/lib/xray/xray_buffer_queue.h
compiler-rt/trunk/lib/xray/xray_fdr_log_records.h
compiler-rt/trunk/lib/xray/xray_fdr_logging.cc
compiler-rt/trunk/lib/xray/xray_fdr_logging_impl.h
compiler-rt/trunk/lib/xray/xray_flags.inc
Modified: compiler-rt/trunk/lib/xray/tests/unit/fdr_logging_test.cc
URL: http://llvm.org/viewvc/llvm-project/compiler-rt/trunk/lib/xray/tests/unit/fdr_logging_test.cc?rev=318733&r1=318732&r2=318733&view=diff
==============================================================================
--- compiler-rt/trunk/lib/xray/tests/unit/fdr_logging_test.cc (original)
+++ compiler-rt/trunk/lib/xray/tests/unit/fdr_logging_test.cc Mon Nov 20 23:16:57 2017
@@ -17,8 +17,10 @@
#include <iostream>
#include <sys/mman.h>
#include <sys/stat.h>
+#include <sys/syscall.h>
#include <sys/types.h>
#include <system_error>
+#include <thread>
#include <unistd.h>
#include "xray/xray_records.h"
@@ -34,14 +36,23 @@ struct ScopedFileCloserAndDeleter {
: Fd(Fd), Filename(Filename) {}
~ScopedFileCloserAndDeleter() {
+ if (Map)
+ munmap(Map, Size);
if (Fd) {
close(Fd);
unlink(Filename);
}
}
+ void registerMap(void *M, size_t S) {
+ Map = M;
+ Size = S;
+ }
+
int Fd;
const char *Filename;
+ void *Map = nullptr;
+ size_t Size = 0;
};
TEST(FDRLoggingTest, Simple) {
@@ -51,7 +62,7 @@ TEST(FDRLoggingTest, Simple) {
Options.Fd = mkstemp(TmpFilename);
ASSERT_NE(Options.Fd, -1);
ASSERT_EQ(fdrLoggingInit(kBufferSize, kBufferMax, &Options,
- sizeof(FDRLoggingOptions)),
+ sizeof(FDRLoggingOptions)),
XRayLogInitStatus::XRAY_LOG_INITIALIZED);
fdrLoggingHandleArg0(1, XRayEntryType::ENTRY);
fdrLoggingHandleArg0(1, XRayEntryType::EXIT);
@@ -67,20 +78,25 @@ TEST(FDRLoggingTest, Simple) {
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));
+ void *Map = mmap(NULL, Size, PROT_READ, MAP_PRIVATE, Fd, 0);
+ const char *Contents = static_cast<const char *>(Map);
+ Guard.registerMap(Map, Size);
ASSERT_NE(Contents, nullptr);
XRayFileHeader H;
memcpy(&H, Contents, sizeof(XRayFileHeader));
- ASSERT_EQ(H.Version, 1);
+ ASSERT_EQ(H.Version, 2);
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, uint8_t(MetadataRecord::RecordKinds::NewBuffer));
+ // We require one buffer at least to have the "extents" metadata record,
+ // followed by the NewBuffer record.
+ MetadataRecord MDR0, MDR1;
+ memcpy(&MDR0, Contents + sizeof(XRayFileHeader), sizeof(MetadataRecord));
+ memcpy(&MDR1, Contents + sizeof(XRayFileHeader) + sizeof(MetadataRecord),
+ sizeof(MetadataRecord));
+ ASSERT_EQ(MDR0.RecordKind,
+ uint8_t(MetadataRecord::RecordKinds::BufferExtents));
+ ASSERT_EQ(MDR1.RecordKind, uint8_t(MetadataRecord::RecordKinds::NewBuffer));
}
TEST(FDRLoggingTest, Multiple) {
@@ -89,7 +105,7 @@ TEST(FDRLoggingTest, Multiple) {
Options.Fd = mkstemp(TmpFilename);
ASSERT_NE(Options.Fd, -1);
ASSERT_EQ(fdrLoggingInit(kBufferSize, kBufferMax, &Options,
- sizeof(FDRLoggingOptions)),
+ sizeof(FDRLoggingOptions)),
XRayLogInitStatus::XRAY_LOG_INITIALIZED);
for (uint64_t I = 0; I < 100; ++I) {
fdrLoggingHandleArg0(1, XRayEntryType::ENTRY);
@@ -107,18 +123,77 @@ TEST(FDRLoggingTest, Multiple) {
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));
+ void *Map = mmap(NULL, Size, PROT_READ, MAP_PRIVATE, Fd, 0);
+ const char *Contents = static_cast<const char *>(Map);
+ Guard.registerMap(Map, Size);
+ ASSERT_NE(Contents, nullptr);
+
+ XRayFileHeader H;
+ memcpy(&H, Contents, sizeof(XRayFileHeader));
+ ASSERT_EQ(H.Version, 2);
+ ASSERT_EQ(H.Type, FileTypes::FDR_LOG);
+
+ MetadataRecord MDR0, MDR1;
+ memcpy(&MDR0, Contents + sizeof(XRayFileHeader), sizeof(MetadataRecord));
+ memcpy(&MDR1, Contents + sizeof(XRayFileHeader) + sizeof(MetadataRecord),
+ sizeof(MetadataRecord));
+ ASSERT_EQ(MDR0.RecordKind,
+ uint8_t(MetadataRecord::RecordKinds::BufferExtents));
+ ASSERT_EQ(MDR1.RecordKind, uint8_t(MetadataRecord::RecordKinds::NewBuffer));
+}
+
+TEST(FDRLoggingTest, MultiThreadedCycling) {
+ FDRLoggingOptions Options;
+ char TmpFilename[] = "fdr-logging-test.XXXXXX";
+ Options.Fd = mkstemp(TmpFilename);
+ ASSERT_NE(Options.Fd, -1);
+ ASSERT_EQ(fdrLoggingInit(kBufferSize, 1, &Options, sizeof(FDRLoggingOptions)),
+ XRayLogInitStatus::XRAY_LOG_INITIALIZED);
+
+ // Now we want to create one thread, do some logging, then create another one,
+ // in succession and making sure that we're able to get thread records from
+ // the latest thread (effectively being able to recycle buffers).
+ std::array<pid_t, 2> Threads;
+ for (uint64_t I = 0; I < 2; ++I) {
+ std::thread t{[I, &Threads] {
+ fdrLoggingHandleArg0(I + 1, XRayEntryType::ENTRY);
+ fdrLoggingHandleArg0(I + 1, XRayEntryType::EXIT);
+ Threads[I] = syscall(SYS_gettid);
+ }};
+ t.join();
+ }
+ ASSERT_EQ(fdrLoggingFinalize(), XRayLogInitStatus::XRAY_LOG_FINALIZED);
+ ASSERT_EQ(fdrLoggingFlush(), XRayLogFlushStatus::XRAY_LOG_FLUSHED);
+
+ // 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.
+ void *Map = mmap(NULL, Size, PROT_READ, MAP_PRIVATE, Fd, 0);
+ const char *Contents = static_cast<const char *>(Map);
+ Guard.registerMap(Map, Size);
ASSERT_NE(Contents, nullptr);
XRayFileHeader H;
memcpy(&H, Contents, sizeof(XRayFileHeader));
- ASSERT_EQ(H.Version, 1);
+ ASSERT_EQ(H.Version, 2);
ASSERT_EQ(H.Type, FileTypes::FDR_LOG);
- MetadataRecord MDR0;
+ MetadataRecord MDR0, MDR1;
memcpy(&MDR0, Contents + sizeof(XRayFileHeader), sizeof(MetadataRecord));
- ASSERT_EQ(MDR0.RecordKind, uint8_t(MetadataRecord::RecordKinds::NewBuffer));
+ memcpy(&MDR1, Contents + sizeof(XRayFileHeader) + sizeof(MetadataRecord),
+ sizeof(MetadataRecord));
+ ASSERT_EQ(MDR0.RecordKind,
+ uint8_t(MetadataRecord::RecordKinds::BufferExtents));
+ ASSERT_EQ(MDR1.RecordKind, uint8_t(MetadataRecord::RecordKinds::NewBuffer));
+ pid_t Latest = 0;
+ memcpy(&Latest, MDR1.Data, sizeof(pid_t));
+ ASSERT_EQ(Latest, Threads[1]);
}
} // namespace
Modified: compiler-rt/trunk/lib/xray/xray_buffer_queue.cc
URL: http://llvm.org/viewvc/llvm-project/compiler-rt/trunk/lib/xray/xray_buffer_queue.cc?rev=318733&r1=318732&r2=318733&view=diff
==============================================================================
--- compiler-rt/trunk/lib/xray/xray_buffer_queue.cc (original)
+++ compiler-rt/trunk/lib/xray/xray_buffer_queue.cc Mon Nov 20 23:16:57 2017
@@ -21,24 +21,25 @@ using namespace __xray;
using namespace __sanitizer;
BufferQueue::BufferQueue(size_t B, size_t N, bool &Success)
- : BufferSize(B),
- Buffers(new BufferRep[N]()),
- BufferCount(N),
- Finalizing{0},
- OwnedBuffers(new void *[N]()),
- Next(Buffers),
- First(Buffers),
+ : BufferSize(B), Buffers(new BufferRep[N]()), BufferCount(N), Finalizing{0},
+ OwnedBuffers(new void *[N]()), Next(Buffers), First(Buffers),
LiveBuffers(0) {
for (size_t i = 0; i < N; ++i) {
auto &T = Buffers[i];
- void *Tmp = InternalAlloc(BufferSize);
+ void *Tmp = InternalAlloc(BufferSize, nullptr, 64);
if (Tmp == nullptr) {
Success = false;
return;
}
+ void *Extents = InternalAlloc(sizeof(BufferExtents), nullptr, 64);
+ if (Extents == nullptr) {
+ Success = false;
+ return;
+ }
auto &Buf = T.Buff;
Buf.Buffer = Tmp;
Buf.Size = B;
+ Buf.Extents = reinterpret_cast<BufferExtents *>(Extents);
OwnedBuffers[i] = Tmp;
}
Success = true;
@@ -48,14 +49,17 @@ BufferQueue::ErrorCode BufferQueue::getB
if (__sanitizer::atomic_load(&Finalizing, __sanitizer::memory_order_acquire))
return ErrorCode::QueueFinalizing;
__sanitizer::SpinMutexLock Guard(&Mutex);
- if (LiveBuffers == BufferCount) return ErrorCode::NotEnoughMemory;
+ if (LiveBuffers == BufferCount)
+ return ErrorCode::NotEnoughMemory;
auto &T = *Next;
auto &B = T.Buff;
Buf = B;
+ T.Used = true;
++LiveBuffers;
- if (++Next == (Buffers + BufferCount)) Next = Buffers;
+ if (++Next == (Buffers + BufferCount))
+ Next = Buffers;
return ErrorCode::Ok;
}
@@ -69,13 +73,15 @@ BufferQueue::ErrorCode BufferQueue::rele
break;
}
}
- if (!Found) return ErrorCode::UnrecognizedBuffer;
+ if (!Found)
+ return ErrorCode::UnrecognizedBuffer;
__sanitizer::SpinMutexLock Guard(&Mutex);
// This points to a semantic bug, we really ought to not be releasing more
// buffers than we actually get.
- if (LiveBuffers == 0) return ErrorCode::NotEnoughMemory;
+ if (LiveBuffers == 0)
+ return ErrorCode::NotEnoughMemory;
// Now that the buffer has been released, we mark it as "used".
First->Buff = Buf;
@@ -83,7 +89,8 @@ BufferQueue::ErrorCode BufferQueue::rele
Buf.Buffer = nullptr;
Buf.Size = 0;
--LiveBuffers;
- if (++First == (Buffers + BufferCount)) First = Buffers;
+ if (++First == (Buffers + BufferCount))
+ First = Buffers;
return ErrorCode::Ok;
}
@@ -100,6 +107,7 @@ BufferQueue::~BufferQueue() {
auto &T = *I;
auto &Buf = T.Buff;
InternalFree(Buf.Buffer);
+ InternalFree(Buf.Extents);
}
delete[] Buffers;
delete[] OwnedBuffers;
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=318733&r1=318732&r2=318733&view=diff
==============================================================================
--- compiler-rt/trunk/lib/xray/xray_buffer_queue.h (original)
+++ compiler-rt/trunk/lib/xray/xray_buffer_queue.h Mon Nov 20 23:16:57 2017
@@ -28,9 +28,14 @@ namespace __xray {
/// trace collection.
class BufferQueue {
public:
+ struct alignas(64) BufferExtents {
+ __sanitizer::atomic_uint64_t Size;
+ };
+
struct Buffer {
void *Buffer = nullptr;
size_t Size = 0;
+ BufferExtents* Extents;
};
private:
Modified: compiler-rt/trunk/lib/xray/xray_fdr_log_records.h
URL: http://llvm.org/viewvc/llvm-project/compiler-rt/trunk/lib/xray/xray_fdr_log_records.h?rev=318733&r1=318732&r2=318733&view=diff
==============================================================================
--- compiler-rt/trunk/lib/xray/xray_fdr_log_records.h (original)
+++ compiler-rt/trunk/lib/xray/xray_fdr_log_records.h Mon Nov 20 23:16:57 2017
@@ -31,7 +31,9 @@ struct alignas(16) MetadataRecord {
WalltimeMarker,
CustomEventMarker,
CallArgument,
+ BufferExtents,
};
+
// Use 7 bits to identify this record type.
/* RecordKinds */ uint8_t RecordKind : 7;
char Data[15];
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=318733&r1=318732&r2=318733&view=diff
==============================================================================
--- compiler-rt/trunk/lib/xray/xray_fdr_logging.cc (original)
+++ compiler-rt/trunk/lib/xray/xray_fdr_logging.cc Mon Nov 20 23:16:57 2017
@@ -15,9 +15,9 @@
//
//===----------------------------------------------------------------------===//
#include "xray_fdr_logging.h"
+#include <errno.h>
#include <sys/syscall.h>
#include <sys/time.h>
-#include <errno.h>
#include <time.h>
#include <unistd.h>
@@ -35,10 +35,7 @@
namespace __xray {
// Global BufferQueue.
-// NOTE: This is a pointer to avoid having to do atomic operations at
-// initialization time. This is OK to leak as there will only be one bufferqueue
-// for the runtime, initialized once through the fdrInit(...) sequence.
-std::shared_ptr<BufferQueue> *BQ = nullptr;
+BufferQueue *BQ = nullptr;
__sanitizer::atomic_sint32_t LogFlushStatus = {
XRayLogFlushStatus::XRAY_LOG_NOT_FLUSHING};
@@ -51,19 +48,37 @@ __sanitizer::SpinMutex FDROptionsMutex;
XRayLogFlushStatus fdrLoggingFlush() XRAY_NEVER_INSTRUMENT {
if (__sanitizer::atomic_load(&LoggingStatus,
__sanitizer::memory_order_acquire) !=
- XRayLogInitStatus::XRAY_LOG_FINALIZED)
+ XRayLogInitStatus::XRAY_LOG_FINALIZED) {
+ if (__sanitizer::Verbosity())
+ Report("Not flushing log, implementation is not finalized.\n");
return XRayLogFlushStatus::XRAY_LOG_NOT_FLUSHING;
+ }
s32 Result = XRayLogFlushStatus::XRAY_LOG_NOT_FLUSHING;
if (!__sanitizer::atomic_compare_exchange_strong(
&LogFlushStatus, &Result, XRayLogFlushStatus::XRAY_LOG_FLUSHING,
- __sanitizer::memory_order_release))
+ __sanitizer::memory_order_release)) {
+
+ if (__sanitizer::Verbosity())
+ Report("Not flushing log, implementation is still finalizing.\n");
return static_cast<XRayLogFlushStatus>(Result);
+ }
- // Make a copy of the BufferQueue pointer to prevent other threads that may be
- // resetting it from blowing away the queue prematurely while we're dealing
- // with it.
- auto LocalBQ = *BQ;
+ if (BQ == nullptr) {
+ if (__sanitizer::Verbosity())
+ Report("Cannot flush when global buffer queue is null.\n");
+ return XRayLogFlushStatus::XRAY_LOG_NOT_FLUSHING;
+ }
+
+ // We wait a number of microseconds to allow threads to see that we've
+ // finalised before attempting to flush the log.
+ struct timespec TS;
+ TS.tv_sec = flags()->xray_fdr_log_grace_period_us / 1000000;
+ TS.tv_nsec = (flags()->xray_fdr_log_grace_period_us % 1000000) * 1000;
+ struct timespec Rem;
+ while (clock_nanosleep(CLOCK_REALTIME, 0, &TS, &Rem) &&
+ (Rem.tv_sec != 0 || Rem.tv_nsec != 0))
+ TS = Rem;
// We write out the file in the following format:
//
@@ -94,34 +109,44 @@ XRayLogFlushStatus fdrLoggingFlush() XRA
TSCSupported ? getTSCFrequency() : __xray::NanosecondsPerSecond;
XRayFileHeader Header;
- Header.Version = 1;
+
+ // Version 2 of the log writes the extents of the buffer, instead of relying
+ // on an end-of-buffer record.
+ Header.Version = 2;
Header.Type = FileTypes::FDR_LOG;
Header.CycleFrequency = CycleFrequency;
+
// FIXME: Actually check whether we have 'constant_tsc' and 'nonstop_tsc'
// before setting the values in the header.
Header.ConstantTSC = 1;
Header.NonstopTSC = 1;
- Header.FdrData = FdrAdditionalHeaderData{LocalBQ->ConfiguredBufferSize()};
+ Header.FdrData = FdrAdditionalHeaderData{BQ->ConfiguredBufferSize()};
retryingWriteAll(Fd, reinterpret_cast<char *>(&Header),
reinterpret_cast<char *>(&Header) + sizeof(Header));
- LocalBQ->apply([&](const BufferQueue::Buffer &B) {
- uint64_t BufferSize = B.Size;
- if (BufferSize > 0) {
+ BQ->apply([&](const BufferQueue::Buffer &B) {
+ // Starting at version 2 of the FDR logging implementation, we only write
+ // the records identified by the extents of the buffer. We use the Extents
+ // from the Buffer and write that out as the first record in the buffer.
+ // We still use a Metadata record, but fill in the extents instead for the
+ // data.
+ MetadataRecord ExtentsRecord;
+ auto BufferExtents = __sanitizer::atomic_load(
+ &B.Extents->Size, __sanitizer::memory_order_acquire);
+ assert(BufferExtents <= B.Size);
+ ExtentsRecord.Type = uint8_t(RecordType::Metadata);
+ ExtentsRecord.RecordKind =
+ uint8_t(MetadataRecord::RecordKinds::BufferExtents);
+ std::memcpy(ExtentsRecord.Data, &BufferExtents, sizeof(BufferExtents));
+ if (BufferExtents > 0) {
+ retryingWriteAll(Fd, reinterpret_cast<char *>(&ExtentsRecord),
+ reinterpret_cast<char *>(&ExtentsRecord) +
+ sizeof(MetadataRecord));
retryingWriteAll(Fd, reinterpret_cast<char *>(B.Buffer),
- reinterpret_cast<char *>(B.Buffer) + B.Size);
+ reinterpret_cast<char *>(B.Buffer) + BufferExtents);
}
});
- // The buffer for this particular thread would have been finalised after
- // we've written everything to disk, and we'd lose the thread's trace.
- auto &TLD = __xray::__xray_fdr_internal::getThreadLocalData();
- if (TLD.Buffer.Buffer != nullptr) {
- __xray::__xray_fdr_internal::writeEOBMetadata();
- auto Start = reinterpret_cast<char *>(TLD.Buffer.Buffer);
- retryingWriteAll(Fd, Start, Start + TLD.Buffer.Size);
- }
-
__sanitizer::atomic_store(&LogFlushStatus,
XRayLogFlushStatus::XRAY_LOG_FLUSHED,
__sanitizer::memory_order_release);
@@ -133,12 +158,15 @@ XRayLogInitStatus fdrLoggingFinalize() X
if (!__sanitizer::atomic_compare_exchange_strong(
&LoggingStatus, &CurrentStatus,
XRayLogInitStatus::XRAY_LOG_FINALIZING,
- __sanitizer::memory_order_release))
+ __sanitizer::memory_order_release)) {
+ if (__sanitizer::Verbosity())
+ Report("Cannot finalize log, implementation not initialized.\n");
return static_cast<XRayLogInitStatus>(CurrentStatus);
+ }
// Do special things to make the log finalize itself, and not allow any more
// operations to be performed until re-initialized.
- (*BQ)->finalize();
+ BQ->finalize();
__sanitizer::atomic_store(&LoggingStatus,
XRayLogInitStatus::XRAY_LOG_FINALIZED,
@@ -155,7 +183,8 @@ XRayLogInitStatus fdrLoggingReset() XRAY
return static_cast<XRayLogInitStatus>(CurrentStatus);
// Release the in-memory buffer queue.
- BQ->reset();
+ delete BQ;
+ BQ = nullptr;
// Spin until the flushing status is flushed.
s32 CurrentFlushingStatus = XRayLogFlushStatus::XRAY_LOG_FLUSHED;
@@ -173,8 +202,8 @@ XRayLogInitStatus fdrLoggingReset() XRAY
}
struct TSCAndCPU {
- uint64_t TSC;
- unsigned char CPU;
+ uint64_t TSC = 0;
+ unsigned char CPU = 0;
};
static TSCAndCPU getTimestamp() XRAY_NEVER_INSTRUMENT {
@@ -205,15 +234,15 @@ static TSCAndCPU getTimestamp() XRAY_NEV
void fdrLoggingHandleArg0(int32_t FuncId,
XRayEntryType Entry) XRAY_NEVER_INSTRUMENT {
auto TC = getTimestamp();
- __xray_fdr_internal::processFunctionHook(FuncId, Entry, TC.TSC,
- TC.CPU, 0, clock_gettime, *BQ);
+ __xray_fdr_internal::processFunctionHook(FuncId, Entry, TC.TSC, TC.CPU, 0,
+ clock_gettime, BQ);
}
void fdrLoggingHandleArg1(int32_t FuncId, XRayEntryType Entry,
uint64_t Arg) XRAY_NEVER_INSTRUMENT {
auto TC = getTimestamp();
- __xray_fdr_internal::processFunctionHook(
- FuncId, Entry, TC.TSC, TC.CPU, Arg, clock_gettime, *BQ);
+ __xray_fdr_internal::processFunctionHook(FuncId, Entry, TC.TSC, TC.CPU, Arg,
+ clock_gettime, BQ);
}
void fdrLoggingHandleCustomEvent(void *Event,
@@ -223,10 +252,8 @@ void fdrLoggingHandleCustomEvent(void *E
auto &TSC = TC.TSC;
auto &CPU = TC.CPU;
RecursionGuard Guard{Running};
- if (!Guard) {
- assert(Running && "RecursionGuard is buggy!");
+ if (!Guard)
return;
- }
if (EventSize > std::numeric_limits<int32_t>::max()) {
using Empty = struct {};
static Empty Once = [&] {
@@ -238,7 +265,7 @@ void fdrLoggingHandleCustomEvent(void *E
}
int32_t ReducedEventSize = static_cast<int32_t>(EventSize);
auto &TLD = getThreadLocalData();
- if (!isLogInitializedAndReady(TLD.LocalBQ, TSC, CPU, clock_gettime))
+ if (!isLogInitializedAndReady(TLD.BQ, TSC, CPU, clock_gettime))
return;
// Here we need to prepare the log to handle:
@@ -246,7 +273,7 @@ void fdrLoggingHandleCustomEvent(void *E
// - The additional data we're going to write. Currently, that's the size of
// the event we're going to dump into the log as free-form bytes.
if (!prepareBuffer(TSC, CPU, clock_gettime, MetadataRecSize + EventSize)) {
- TLD.LocalBQ = nullptr;
+ TLD.BQ = nullptr;
return;
}
@@ -264,21 +291,29 @@ void fdrLoggingHandleCustomEvent(void *E
std::memcpy(TLD.RecordPtr, &CustomEvent, sizeof(CustomEvent));
TLD.RecordPtr += sizeof(CustomEvent);
std::memcpy(TLD.RecordPtr, Event, ReducedEventSize);
+ incrementExtents(MetadataRecSize + EventSize);
endBufferIfFull();
}
XRayLogInitStatus fdrLoggingInit(std::size_t BufferSize, std::size_t BufferMax,
void *Options,
size_t OptionsSize) XRAY_NEVER_INSTRUMENT {
- if (OptionsSize != sizeof(FDRLoggingOptions))
+ if (OptionsSize != sizeof(FDRLoggingOptions)) {
+ if (__sanitizer::Verbosity())
+ Report("Cannot initialize FDR logging; wrong size for options: %d\n",
+ OptionsSize);
return static_cast<XRayLogInitStatus>(__sanitizer::atomic_load(
&LoggingStatus, __sanitizer::memory_order_acquire));
+ }
s32 CurrentStatus = XRayLogInitStatus::XRAY_LOG_UNINITIALIZED;
if (!__sanitizer::atomic_compare_exchange_strong(
&LoggingStatus, &CurrentStatus,
XRayLogInitStatus::XRAY_LOG_INITIALIZING,
- __sanitizer::memory_order_release))
+ __sanitizer::memory_order_release)) {
+ if (__sanitizer::Verbosity())
+ Report("Cannot initialize already initialized implementation.\n");
return static_cast<XRayLogInitStatus>(CurrentStatus);
+ }
{
__sanitizer::SpinMutexLock Guard(&FDROptionsMutex);
@@ -286,15 +321,37 @@ XRayLogInitStatus fdrLoggingInit(std::si
}
bool Success = false;
+
+ if (BQ != nullptr) {
+ delete BQ;
+ BQ = nullptr;
+ }
+
if (BQ == nullptr)
- BQ = new std::shared_ptr<BufferQueue>();
+ BQ = new BufferQueue(BufferSize, BufferMax, Success);
- *BQ = std::make_shared<BufferQueue>(BufferSize, BufferMax, Success);
if (!Success) {
Report("BufferQueue init failed.\n");
+ if (BQ != nullptr) {
+ delete BQ;
+ BQ = nullptr;
+ }
return XRayLogInitStatus::XRAY_LOG_UNINITIALIZED;
}
+ static bool UNUSED Once = [] {
+ pthread_key_create(&__xray_fdr_internal::Key, +[](void *) {
+ auto &TLD = __xray_fdr_internal::getThreadLocalData();
+ if (TLD.BQ == nullptr)
+ return;
+ auto EC = TLD.BQ->releaseBuffer(TLD.Buffer);
+ if (EC != BufferQueue::ErrorCode::Ok)
+ Report("At thread exit, failed to release buffer at %p; error=%s\n",
+ TLD.Buffer.Buffer, BufferQueue::getErrorString(EC));
+ });
+ return false;
+ }();
+
// Arg1 handler should go in first to avoid concurrent code accidentally
// falling back to arg0 when it should have ran arg1.
__xray_set_handler_arg1(fdrLoggingHandleArg1);
@@ -305,7 +362,9 @@ XRayLogInitStatus fdrLoggingInit(std::si
__sanitizer::atomic_store(&LoggingStatus,
XRayLogInitStatus::XRAY_LOG_INITIALIZED,
__sanitizer::memory_order_release);
- Report("XRay FDR init successful.\n");
+
+ if (__sanitizer::Verbosity())
+ Report("XRay FDR init successful.\n");
return XRayLogInitStatus::XRAY_LOG_INITIALIZED;
}
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=318733&r1=318732&r2=318733&view=diff
==============================================================================
--- compiler-rt/trunk/lib/xray/xray_fdr_logging_impl.h (original)
+++ compiler-rt/trunk/lib/xray/xray_fdr_logging_impl.h Mon Nov 20 23:16:57 2017
@@ -24,11 +24,9 @@
#include <pthread.h>
#include <sys/syscall.h>
#include <time.h>
+#include <type_traits>
#include <unistd.h>
-// FIXME: Implement analogues to std::shared_ptr and std::weak_ptr
-#include <memory>
-
#include "sanitizer_common/sanitizer_common.h"
#include "xray/xray_log_interface.h"
#include "xray_buffer_queue.h"
@@ -54,42 +52,19 @@ __sanitizer::atomic_sint32_t LoggingStat
/// cooperation with xray_fdr_logging class, so be careful and think twice.
namespace __xray_fdr_internal {
-/// Writes the new buffer record and wallclock time that begin a buffer for a
-/// thread to MemPtr and increments MemPtr. Bypasses the thread local state
-/// machine and writes directly to memory without checks.
-static void writeNewBufferPreamble(pid_t Tid, timespec TS, char *&MemPtr);
-
-/// Write a metadata record to switch to a new CPU to MemPtr and increments
-/// MemPtr. Bypasses the thread local state machine and writes directly to
-/// memory without checks.
-static void writeNewCPUIdMetadata(uint16_t CPU, uint64_t TSC, char *&MemPtr);
-
-/// Writes an EOB metadata record to MemPtr and increments MemPtr. Bypasses the
-/// thread local state machine and writes directly to memory without checks.
-static void writeEOBMetadata(char *&MemPtr);
-
-/// Writes a TSC Wrap metadata record to MemPtr and increments MemPtr. Bypasses
-/// the thread local state machine and directly writes to memory without checks.
-static void writeTSCWrapMetadata(uint64_t TSC, char *&MemPtr);
-
-/// Writes a Function Record to MemPtr and increments MemPtr. Bypasses the
-/// thread local state machine and writes the function record directly to
-/// memory.
+/// Writes the new buffer record and wallclock time that begin a buffer for the
+/// current thread.
+static void writeNewBufferPreamble(pid_t Tid, timespec TS);
+
+/// Writes a Function Record to the buffer associated with the current thread.
static void writeFunctionRecord(int FuncId, uint32_t TSCDelta,
- XRayEntryType EntryType, char *&MemPtr);
+ XRayEntryType EntryType);
/// Sets up a new buffer in thread_local storage and writes a preamble. The
/// wall_clock_reader function is used to populate the WallTimeRecord entry.
static void setupNewBuffer(int (*wall_clock_reader)(clockid_t,
struct timespec *));
-/// Called to record CPU time for a new CPU within the current thread.
-static void writeNewCPUIdMetadata(uint16_t CPU, uint64_t TSC);
-
-/// Called to close the buffer when the thread exhausts the buffer or when the
-/// thread exits (via a thread local variable destructor).
-static void writeEOBMetadata();
-
/// TSC Wrap records are written when a TSC delta encoding scheme overflows.
static void writeTSCWrapMetadata(uint64_t TSC);
@@ -119,15 +94,18 @@ struct alignas(64) ThreadLocalData {
// Make sure a thread that's ever called handleArg0 has a thread-local
// live reference to the buffer queue for this particular instance of
// FDRLogging, and that we're going to clean it up when the thread exits.
- std::shared_ptr<BufferQueue> LocalBQ = nullptr;
+ BufferQueue *BQ = nullptr;
};
-// Forward-declare, defined later.
-static ThreadLocalData &getThreadLocalData();
+static_assert(std::is_trivially_destructible<ThreadLocalData>::value,
+ "ThreadLocalData must be trivially destructible");
static constexpr auto MetadataRecSize = sizeof(MetadataRecord);
static constexpr auto FunctionRecSize = sizeof(FunctionRecord);
+// Use a global pthread key to identify thread-local data for logging.
+static pthread_key_t Key;
+
// This function will initialize the thread-local data structure used by the FDR
// logging implementation and return a reference to it. The implementation
// details require a bit of care to maintain.
@@ -149,15 +127,9 @@ static constexpr auto FunctionRecSize =
// ThreadLocalData struct. This data will be uninitialized memory by
// design.
//
-// 2. Using pthread_once(...) to initialize the thread-local data structures
-// on first use, for every thread. We don't use std::call_once so we don't
-// have a reliance on the C++ runtime library.
-//
-// 3. Registering a cleanup function that gets run at the end of a thread's
-// lifetime through pthread_create_key(...). The cleanup function would
-// allow us to release the thread-local resources in a manner that would
-// let the rest of the XRay runtime implementation handle the records
-// written for this thread's active buffer.
+// 2. Not requiring a thread exit handler/implementation, keeping the
+// thread-local as purely a collection of references/data that do not
+// require cleanup.
//
// We're doing this to avoid using a `thread_local` object that has a
// non-trivial destructor, because the C++ runtime might call std::malloc(...)
@@ -168,55 +140,15 @@ static constexpr auto FunctionRecSize =
// critical section, calling a function that might be XRay instrumented (and
// thus in turn calling into malloc by virtue of registration of the
// thread_local's destructor).
-//
-// With the approach taken where, we attempt to avoid the potential for
-// deadlocks by relying instead on pthread's memory management routines.
static ThreadLocalData &getThreadLocalData() {
- thread_local pthread_key_t key;
-
- // We need aligned, uninitialized storage for the TLS object which is
- // trivially destructible. We're going to use this as raw storage and
- // placement-new the ThreadLocalData object into it later.
- alignas(alignof(ThreadLocalData)) thread_local unsigned char
- TLSBuffer[sizeof(ThreadLocalData)];
-
- // Ensure that we only actually ever do the pthread initialization once.
- thread_local bool UNUSED Unused = [] {
- new (&TLSBuffer) ThreadLocalData();
- auto result = pthread_key_create(&key, +[](void *) {
- auto &TLD = *reinterpret_cast<ThreadLocalData *>(&TLSBuffer);
- auto &RecordPtr = TLD.RecordPtr;
- auto &Buffers = TLD.LocalBQ;
- auto &Buffer = TLD.Buffer;
- if (RecordPtr == nullptr)
- return;
-
- // We make sure that upon exit, a thread will write out the EOB
- // MetadataRecord in the thread-local log, and also release the buffer
- // to the queue.
- assert((RecordPtr + MetadataRecSize) -
- static_cast<char *>(Buffer.Buffer) >=
- static_cast<ptrdiff_t>(MetadataRecSize));
- if (Buffers) {
- writeEOBMetadata();
- auto EC = Buffers->releaseBuffer(Buffer);
- if (EC != BufferQueue::ErrorCode::Ok)
- Report("Failed to release buffer at %p; error=%s\n", Buffer.Buffer,
- BufferQueue::getErrorString(EC));
- Buffers = nullptr;
- return;
- }
- });
- if (result != 0) {
- Report("Failed to allocate thread-local data through pthread; error=%d",
- result);
- return false;
- }
- pthread_setspecific(key, &TLSBuffer);
- return true;
+ static_assert(alignof(ThreadLocalData) >= 64,
+ "ThreadLocalData must be cache line aligned.");
+ thread_local ThreadLocalData TLD;
+ thread_local bool UNUSED ThreadOnce = [] {
+ pthread_setspecific(Key, &TLD);
+ return false;
}();
-
- return *reinterpret_cast<ThreadLocalData *>(TLSBuffer);
+ return TLD;
}
//-----------------------------------------------------------------------------|
@@ -253,27 +185,27 @@ public:
} // namespace
-inline void writeNewBufferPreamble(pid_t Tid, timespec TS,
- char *&MemPtr) XRAY_NEVER_INSTRUMENT {
+static void writeNewBufferPreamble(pid_t Tid,
+ timespec TS) XRAY_NEVER_INSTRUMENT {
static constexpr int InitRecordsCount = 2;
- alignas(alignof(MetadataRecord)) unsigned char
- Records[InitRecordsCount * MetadataRecSize];
+ auto &TLD = getThreadLocalData();
+ MetadataRecord Metadata[InitRecordsCount];
{
// Write out a MetadataRecord to signify that this is the start of a new
// buffer, associated with a particular thread, with a new CPU. For the
// data, we have 15 bytes to squeeze as much information as we can. At this
// point we only write down the following bytes:
// - Thread ID (pid_t, 4 bytes)
- auto &NewBuffer = *reinterpret_cast<MetadataRecord *>(Records);
+ auto &NewBuffer = Metadata[0];
NewBuffer.Type = uint8_t(RecordType::Metadata);
NewBuffer.RecordKind = uint8_t(MetadataRecord::RecordKinds::NewBuffer);
std::memcpy(&NewBuffer.Data, &Tid, sizeof(pid_t));
}
+
// Also write the WalltimeMarker record.
{
static_assert(sizeof(time_t) <= 8, "time_t needs to be at most 8 bytes");
- auto &WalltimeMarker =
- *reinterpret_cast<MetadataRecord *>(Records + MetadataRecSize);
+ auto &WalltimeMarker = Metadata[1];
WalltimeMarker.Type = uint8_t(RecordType::Metadata);
WalltimeMarker.RecordKind =
uint8_t(MetadataRecord::RecordKinds::WalltimeMarker);
@@ -286,30 +218,47 @@ inline void writeNewBufferPreamble(pid_t
std::memcpy(WalltimeMarker.Data, &Seconds, sizeof(Seconds));
std::memcpy(WalltimeMarker.Data + sizeof(Seconds), &Micros, sizeof(Micros));
}
- std::memcpy(MemPtr, Records, sizeof(MetadataRecord) * InitRecordsCount);
- MemPtr += sizeof(MetadataRecord) * InitRecordsCount;
- auto &TLD = getThreadLocalData();
+
TLD.NumConsecutiveFnEnters = 0;
TLD.NumTailCalls = 0;
+ if (TLD.BQ == nullptr || TLD.BQ->finalizing())
+ return;
+ std::memcpy(TLD.RecordPtr, Metadata, sizeof(Metadata));
+ TLD.RecordPtr += sizeof(Metadata);
+ // Since we write out the extents as the first metadata record of the
+ // buffer, we need to write out the extents including the extents record.
+ __sanitizer::atomic_store(&TLD.Buffer.Extents->Size, sizeof(Metadata),
+ __sanitizer::memory_order_release);
}
inline void setupNewBuffer(int (*wall_clock_reader)(
clockid_t, struct timespec *)) XRAY_NEVER_INSTRUMENT {
auto &TLD = getThreadLocalData();
- auto &Buffer = TLD.Buffer;
- auto &RecordPtr = TLD.RecordPtr;
- RecordPtr = static_cast<char *>(Buffer.Buffer);
+ auto &B = TLD.Buffer;
+ TLD.RecordPtr = static_cast<char *>(B.Buffer);
pid_t Tid = syscall(SYS_gettid);
timespec TS{0, 0};
// This is typically clock_gettime, but callers have injection ability.
wall_clock_reader(CLOCK_MONOTONIC, &TS);
- writeNewBufferPreamble(Tid, TS, RecordPtr);
+ writeNewBufferPreamble(Tid, TS);
TLD.NumConsecutiveFnEnters = 0;
TLD.NumTailCalls = 0;
}
-inline void writeNewCPUIdMetadata(uint16_t CPU, uint64_t TSC,
- char *&MemPtr) XRAY_NEVER_INSTRUMENT {
+static void incrementExtents(size_t Add) {
+ auto &TLD = getThreadLocalData();
+ __sanitizer::atomic_fetch_add(&TLD.Buffer.Extents->Size, Add,
+ __sanitizer::memory_order_acq_rel);
+}
+
+static void decrementExtents(size_t Subtract) {
+ auto &TLD = getThreadLocalData();
+ __sanitizer::atomic_fetch_sub(&TLD.Buffer.Extents->Size, Subtract,
+ __sanitizer::memory_order_acq_rel);
+}
+
+inline void writeNewCPUIdMetadata(uint16_t CPU,
+ uint64_t TSC) XRAY_NEVER_INSTRUMENT {
auto &TLD = getThreadLocalData();
MetadataRecord NewCPUId;
NewCPUId.Type = uint8_t(RecordType::Metadata);
@@ -321,35 +270,14 @@ inline void writeNewCPUIdMetadata(uint16
// Total = 10 bytes.
std::memcpy(&NewCPUId.Data, &CPU, sizeof(CPU));
std::memcpy(&NewCPUId.Data[sizeof(CPU)], &TSC, sizeof(TSC));
- std::memcpy(MemPtr, &NewCPUId, sizeof(MetadataRecord));
- MemPtr += sizeof(MetadataRecord);
- TLD.NumConsecutiveFnEnters = 0;
- TLD.NumTailCalls = 0;
-}
-
-inline void writeNewCPUIdMetadata(uint16_t CPU,
- uint64_t TSC) XRAY_NEVER_INSTRUMENT {
- writeNewCPUIdMetadata(CPU, TSC, getThreadLocalData().RecordPtr);
-}
-
-inline void writeEOBMetadata(char *&MemPtr) XRAY_NEVER_INSTRUMENT {
- auto &TLD = getThreadLocalData();
- MetadataRecord EOBMeta;
- EOBMeta.Type = uint8_t(RecordType::Metadata);
- EOBMeta.RecordKind = uint8_t(MetadataRecord::RecordKinds::EndOfBuffer);
- // For now we don't write any bytes into the Data field.
- std::memcpy(MemPtr, &EOBMeta, sizeof(MetadataRecord));
- MemPtr += sizeof(MetadataRecord);
+ std::memcpy(TLD.RecordPtr, &NewCPUId, sizeof(MetadataRecord));
+ TLD.RecordPtr += sizeof(MetadataRecord);
TLD.NumConsecutiveFnEnters = 0;
TLD.NumTailCalls = 0;
+ incrementExtents(sizeof(MetadataRecord));
}
-inline void writeEOBMetadata() XRAY_NEVER_INSTRUMENT {
- writeEOBMetadata(getThreadLocalData().RecordPtr);
-}
-
-inline void writeTSCWrapMetadata(uint64_t TSC,
- char *&MemPtr) XRAY_NEVER_INSTRUMENT {
+inline void writeTSCWrapMetadata(uint64_t TSC) XRAY_NEVER_INSTRUMENT {
auto &TLD = getThreadLocalData();
MetadataRecord TSCWrap;
TSCWrap.Type = uint8_t(RecordType::Metadata);
@@ -359,14 +287,11 @@ inline void writeTSCWrapMetadata(uint64_
// - Full TSC (uint64_t, 8 bytes)
// Total = 8 bytes.
std::memcpy(&TSCWrap.Data, &TSC, sizeof(TSC));
- std::memcpy(MemPtr, &TSCWrap, sizeof(MetadataRecord));
- MemPtr += sizeof(MetadataRecord);
+ std::memcpy(TLD.RecordPtr, &TSCWrap, sizeof(MetadataRecord));
+ TLD.RecordPtr += sizeof(MetadataRecord);
TLD.NumConsecutiveFnEnters = 0;
TLD.NumTailCalls = 0;
-}
-
-inline void writeTSCWrapMetadata(uint64_t TSC) XRAY_NEVER_INSTRUMENT {
- writeTSCWrapMetadata(TSC, getThreadLocalData().RecordPtr);
+ incrementExtents(sizeof(MetadataRecord));
}
// Call Argument metadata records store the arguments to a function in the
@@ -380,11 +305,12 @@ static inline void writeCallArgumentMeta
std::memcpy(CallArg.Data, &A, sizeof(A));
std::memcpy(TLD.RecordPtr, &CallArg, sizeof(MetadataRecord));
TLD.RecordPtr += sizeof(MetadataRecord);
+ incrementExtents(sizeof(MetadataRecord));
}
-static inline void writeFunctionRecord(int FuncId, uint32_t TSCDelta,
- XRayEntryType EntryType,
- char *&MemPtr) XRAY_NEVER_INSTRUMENT {
+static inline void
+writeFunctionRecord(int FuncId, uint32_t TSCDelta,
+ XRayEntryType EntryType) XRAY_NEVER_INSTRUMENT {
FunctionRecord FuncRecord;
FuncRecord.Type = uint8_t(RecordType::Function);
// Only take 28 bits of the function id.
@@ -439,8 +365,9 @@ static inline void writeFunctionRecord(i
}
}
- std::memcpy(MemPtr, &FuncRecord, sizeof(FunctionRecord));
- MemPtr += sizeof(FunctionRecord);
+ std::memcpy(TLD.RecordPtr, &FuncRecord, sizeof(FunctionRecord));
+ TLD.RecordPtr += sizeof(FunctionRecord);
+ incrementExtents(sizeof(FunctionRecord));
}
static uint64_t thresholdTicks() {
@@ -458,6 +385,7 @@ static void rewindRecentCall(uint64_t TS
uint64_t &LastFunctionEntryTSC, int32_t FuncId) {
auto &TLD = getThreadLocalData();
TLD.RecordPtr -= FunctionRecSize;
+ decrementExtents(FunctionRecSize);
FunctionRecord FuncRecord;
std::memcpy(&FuncRecord, TLD.RecordPtr, FunctionRecSize);
assert(FuncRecord.RecordKind ==
@@ -511,6 +439,7 @@ static void rewindRecentCall(uint64_t TS
RewindingTSC -= ExpectedFunctionEntry.TSCDelta;
TLD.RecordPtr -= 2 * FunctionRecSize;
LastTSC = RewindingTSC;
+ decrementExtents(2 * FunctionRecSize);
}
}
@@ -531,12 +460,10 @@ inline bool prepareBuffer(uint64_t TSC,
size_t MaxSize) XRAY_NEVER_INSTRUMENT {
auto &TLD = getThreadLocalData();
char *BufferStart = static_cast<char *>(TLD.Buffer.Buffer);
- if ((TLD.RecordPtr + MaxSize) >
- (BufferStart + TLD.Buffer.Size - MetadataRecSize)) {
- writeEOBMetadata();
- if (!releaseThreadLocalBuffer(*TLD.LocalBQ))
+ if ((TLD.RecordPtr + MaxSize) > (BufferStart + TLD.Buffer.Size)) {
+ if (!releaseThreadLocalBuffer(*TLD.BQ))
return false;
- auto EC = TLD.LocalBQ->getBuffer(TLD.Buffer);
+ auto EC = TLD.BQ->getBuffer(TLD.Buffer);
if (EC != BufferQueue::ErrorCode::Ok) {
Report("Failed to acquire a buffer; error=%s\n",
BufferQueue::getErrorString(EC));
@@ -550,10 +477,10 @@ inline bool prepareBuffer(uint64_t TSC,
return true;
}
-inline bool isLogInitializedAndReady(
- std::shared_ptr<BufferQueue> &LBQ, uint64_t TSC, unsigned char CPU,
- int (*wall_clock_reader)(clockid_t,
- struct timespec *)) XRAY_NEVER_INSTRUMENT {
+inline bool
+isLogInitializedAndReady(BufferQueue *LBQ, uint64_t TSC, unsigned char CPU,
+ int (*wall_clock_reader)(clockid_t, struct timespec *))
+ XRAY_NEVER_INSTRUMENT {
// Bail out right away if logging is not initialized yet.
// We should take the opportunity to release the buffer though.
auto Status = __sanitizer::atomic_load(&LoggingStatus,
@@ -563,11 +490,9 @@ inline bool isLogInitializedAndReady(
if (TLD.RecordPtr != nullptr &&
(Status == XRayLogInitStatus::XRAY_LOG_FINALIZING ||
Status == XRayLogInitStatus::XRAY_LOG_FINALIZED)) {
- writeEOBMetadata();
if (!releaseThreadLocalBuffer(*LBQ))
return false;
TLD.RecordPtr = nullptr;
- LBQ = nullptr;
return false;
}
return false;
@@ -577,7 +502,6 @@ inline bool isLogInitializedAndReady(
__sanitizer::memory_order_acquire) !=
XRayLogInitStatus::XRAY_LOG_INITIALIZED ||
LBQ->finalizing()) {
- writeEOBMetadata();
if (!releaseThreadLocalBuffer(*LBQ))
return false;
TLD.RecordPtr = nullptr;
@@ -650,9 +574,9 @@ inline uint32_t writeCurrentCPUTSC(Threa
inline void endBufferIfFull() XRAY_NEVER_INSTRUMENT {
auto &TLD = getThreadLocalData();
auto BufferStart = static_cast<char *>(TLD.Buffer.Buffer);
- if ((TLD.RecordPtr + MetadataRecSize) - BufferStart == MetadataRecSize) {
- writeEOBMetadata();
- if (!releaseThreadLocalBuffer(*TLD.LocalBQ))
+ if ((TLD.RecordPtr + MetadataRecSize) - BufferStart <=
+ ptrdiff_t{MetadataRecSize}) {
+ if (!releaseThreadLocalBuffer(*TLD.BQ))
return;
TLD.RecordPtr = nullptr;
}
@@ -666,10 +590,11 @@ thread_local volatile bool Running = fal
/// walk backward through its buffer and erase trivial functions to avoid
/// polluting the log and may use the buffer queue to obtain or release a
/// buffer.
-inline void processFunctionHook(
- int32_t FuncId, XRayEntryType Entry, uint64_t TSC, unsigned char CPU,
- uint64_t Arg1, int (*wall_clock_reader)(clockid_t, struct timespec *),
- const std::shared_ptr<BufferQueue> &BQ) XRAY_NEVER_INSTRUMENT {
+inline void processFunctionHook(int32_t FuncId, XRayEntryType Entry,
+ uint64_t TSC, unsigned char CPU, uint64_t Arg1,
+ int (*wall_clock_reader)(clockid_t,
+ struct timespec *),
+ BufferQueue *BQ) XRAY_NEVER_INSTRUMENT {
// Prevent signal handler recursion, so in case we're already in a log writing
// mode and the signal handler comes in (and is also instrumented) then we
// don't want to be clobbering potentially partial writes already happening in
@@ -685,10 +610,10 @@ inline void processFunctionHook(
// In case the reference has been cleaned up before, we make sure we
// initialize it to the provided BufferQueue.
- if (TLD.LocalBQ == nullptr)
- TLD.LocalBQ = BQ;
+ if (TLD.BQ == nullptr)
+ TLD.BQ = BQ;
- if (!isLogInitializedAndReady(TLD.LocalBQ, TSC, CPU, wall_clock_reader))
+ if (!isLogInitializedAndReady(TLD.BQ, TSC, CPU, wall_clock_reader))
return;
// Before we go setting up writing new function entries, we need to be really
@@ -720,16 +645,13 @@ inline void processFunctionHook(
// id" MetadataRecord before writing out the actual FunctionRecord.
// 4. The second MetadataRecord is the optional function call argument.
//
- // - An End-of-Buffer (EOB) MetadataRecord is 16 bytes.
- //
- // So the math we need to do is to determine whether writing 24 bytes past the
- // current pointer leaves us with enough bytes to write the EOB
- // MetadataRecord. If we don't have enough space after writing as much as 24
- // bytes in the end of the buffer, we need to write out the EOB, get a new
- // Buffer, set it up properly before doing any further writing.
+ // So the math we need to do is to determine whether writing 40 bytes past the
+ // current pointer exceeds the buffer's maximum size. If we don't have enough
+ // space to write 40 bytes in the buffer, we need get a new Buffer, set it up
+ // properly before doing any further writing.
size_t MaxSize = FunctionRecSize + 2 * MetadataRecSize;
if (!prepareBuffer(TSC, CPU, wall_clock_reader, MaxSize)) {
- TLD.LocalBQ = nullptr;
+ TLD.BQ = nullptr;
return;
}
@@ -768,7 +690,7 @@ inline void processFunctionHook(
}
}
- writeFunctionRecord(FuncId, RecordTSCDelta, Entry, TLD.RecordPtr);
+ writeFunctionRecord(FuncId, RecordTSCDelta, Entry);
if (Entry == XRayEntryType::LOG_ARGS_ENTRY)
writeCallArgumentMetadata(Arg1);
Modified: compiler-rt/trunk/lib/xray/xray_flags.inc
URL: http://llvm.org/viewvc/llvm-project/compiler-rt/trunk/lib/xray/xray_flags.inc?rev=318733&r1=318732&r2=318733&view=diff
==============================================================================
--- compiler-rt/trunk/lib/xray/xray_flags.inc (original)
+++ compiler-rt/trunk/lib/xray/xray_flags.inc Mon Nov 20 23:16:57 2017
@@ -25,3 +25,7 @@ XRAY_FLAG(bool, xray_fdr_log, false,
XRAY_FLAG(int, xray_fdr_log_func_duration_threshold_us, 5,
"FDR logging will try to skip functions that execute for fewer "
"microseconds than this threshold.")
+XRAY_FLAG(int, xray_fdr_log_grace_period_us, 100000,
+ "FDR logging will wait this much time in microseconds before "
+ "actually flushing the log; this gives a chance for threads to "
+ "notice that the log has been finalized and clean up.")
More information about the llvm-commits
mailing list