diff options
Diffstat (limited to 'compiler-rt/lib/xray/xray_fdr_logging.cc')
| -rw-r--r-- | compiler-rt/lib/xray/xray_fdr_logging.cc | 149 |
1 files changed, 104 insertions, 45 deletions
diff --git a/compiler-rt/lib/xray/xray_fdr_logging.cc b/compiler-rt/lib/xray/xray_fdr_logging.cc index cf27acc242e..035fc4061ac 100644 --- a/compiler-rt/lib/xray/xray_fdr_logging.cc +++ b/compiler-rt/lib/xray/xray_fdr_logging.cc @@ -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() XRAY_NEVER_INSTRUMENT { 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() XRAY_NEVER_INSTRUMENT { 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_NEVER_INSTRUMENT { 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_NEVER_INSTRUMENT { } 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_NEVER_INSTRUMENT { 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 *Event, 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 *Event, } 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 *Event, // - 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 *Event, 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::size_t BufferSize, std::size_t BufferMax, } 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::size_t BufferSize, std::size_t BufferMax, __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; } |
