[compiler-rt] r346293 - [XRay] Use TSC delta encoding for custom/typed events
Dean Michael Berris via llvm-commits
llvm-commits at lists.llvm.org
Tue Nov 6 20:37:42 PST 2018
Author: dberris
Date: Tue Nov 6 20:37:42 2018
New Revision: 346293
URL: http://llvm.org/viewvc/llvm-project?rev=346293&view=rev
Log:
[XRay] Use TSC delta encoding for custom/typed events
Summary:
This change updates the version number for FDR logs to 5, and update the
trace processing to support changes in the custom event records.
In the runtime, since we're already writing down the record preamble to
handle CPU migrations and TSC wraparound, we can use the same TSC delta
encoding in the custom event and typed event records that we use in
function event records. We do the same change to typed events (which
were unsupported before this change in the trace processing) which now
show up in the trace.
Future changes should increase our testing coverage to make custom and
typed events as first class entities in the FDR mode log processing
tools.
This change is also a good example of how we end up supporting new
record types in the FDR mode implementation. This shows the places where
new record types are added and supported.
Depends on D54139.
Reviewers: mboerger
Subscribers: hiraditya, arphaman, jfb, llvm-commits
Differential Revision: https://reviews.llvm.org/D54140
Modified:
compiler-rt/trunk/lib/xray/xray_fdr_controller.h
compiler-rt/trunk/lib/xray/xray_fdr_log_writer.h
compiler-rt/trunk/lib/xray/xray_fdr_logging.cc
Modified: compiler-rt/trunk/lib/xray/xray_fdr_controller.h
URL: http://llvm.org/viewvc/llvm-project/compiler-rt/trunk/lib/xray/xray_fdr_controller.h?rev=346293&r1=346292&r2=346293&view=diff
==============================================================================
--- compiler-rt/trunk/lib/xray/xray_fdr_controller.h (original)
+++ compiler-rt/trunk/lib/xray/xray_fdr_controller.h Tue Nov 6 20:37:42 2018
@@ -23,7 +23,7 @@
namespace __xray {
-template <size_t Version = 3> class FDRController {
+template <size_t Version = 5> class FDRController {
BufferQueue *BQ;
BufferQueue::Buffer &B;
FDRLogWriter &W;
@@ -144,8 +144,8 @@ template <size_t Version = 3> class FDRC
}
enum class PreambleResult { NoChange, WroteMetadata, InvalidBuffer };
- PreambleResult functionPreamble(uint64_t TSC,
- uint16_t CPU) XRAY_NEVER_INSTRUMENT {
+ PreambleResult recordPreamble(uint64_t TSC,
+ uint16_t CPU) XRAY_NEVER_INSTRUMENT {
if (UNLIKELY(LatestCPU != CPU || LatestTSC == 0)) {
// We update our internal tracking state for the Latest TSC and CPU we've
// seen, then write out the appropriate metadata and function records.
@@ -248,7 +248,7 @@ public:
!prepareBuffer(sizeof(MetadataRecord) + sizeof(FunctionRecord)))
return returnBuffer();
- auto PreambleStatus = functionPreamble(TSC, CPU);
+ auto PreambleStatus = recordPreamble(TSC, CPU);
if (PreambleStatus == PreambleResult::InvalidBuffer)
return returnBuffer();
@@ -270,7 +270,7 @@ public:
if (!prepareBuffer(sizeof(MetadataRecord) + sizeof(FunctionRecord)))
return returnBuffer();
- auto PreambleStatus = functionPreamble(TSC, CPU);
+ auto PreambleStatus = recordPreamble(TSC, CPU);
if (PreambleStatus == PreambleResult::InvalidBuffer)
return returnBuffer();
@@ -291,7 +291,7 @@ public:
uint64_t Arg) XRAY_NEVER_INSTRUMENT {
if (finalized() ||
!prepareBuffer((2 * sizeof(MetadataRecord)) + sizeof(FunctionRecord)) ||
- functionPreamble(TSC, CPU) == PreambleResult::InvalidBuffer)
+ recordPreamble(TSC, CPU) == PreambleResult::InvalidBuffer)
return returnBuffer();
auto Delta = TSC - LatestTSC;
@@ -311,7 +311,7 @@ public:
!prepareBuffer(sizeof(MetadataRecord) + sizeof(FunctionRecord)))
return returnBuffer();
- auto PreambleStatus = functionPreamble(TSC, CPU);
+ auto PreambleStatus = recordPreamble(TSC, CPU);
if (PreambleStatus == PreambleResult::InvalidBuffer)
return returnBuffer();
@@ -332,26 +332,28 @@ public:
int32_t EventSize) XRAY_NEVER_INSTRUMENT {
if (finalized() ||
!prepareBuffer((2 * sizeof(MetadataRecord)) + EventSize) ||
- functionPreamble(TSC, CPU) == PreambleResult::InvalidBuffer)
+ recordPreamble(TSC, CPU) == PreambleResult::InvalidBuffer)
return returnBuffer();
- LatestTSC = 0;
+ auto Delta = TSC - LatestTSC;
+ LatestTSC = TSC;
UndoableFunctionEnters = 0;
UndoableTailExits = 0;
- return W.writeCustomEvent(TSC, CPU, Event, EventSize);
+ return W.writeCustomEvent(Delta, Event, EventSize);
}
bool typedEvent(uint64_t TSC, uint16_t CPU, uint16_t EventType,
const void *Event, int32_t EventSize) XRAY_NEVER_INSTRUMENT {
if (finalized() ||
!prepareBuffer((2 * sizeof(MetadataRecord)) + EventSize) ||
- functionPreamble(TSC, CPU) == PreambleResult::InvalidBuffer)
+ recordPreamble(TSC, CPU) == PreambleResult::InvalidBuffer)
return returnBuffer();
- LatestTSC = 0;
+ auto Delta = TSC - LatestTSC;
+ LatestTSC = TSC;
UndoableFunctionEnters = 0;
UndoableTailExits = 0;
- return W.writeTypedEvent(TSC, EventType, Event, EventSize);
+ return W.writeTypedEvent(Delta, EventType, Event, EventSize);
}
bool flush() XRAY_NEVER_INSTRUMENT {
Modified: compiler-rt/trunk/lib/xray/xray_fdr_log_writer.h
URL: http://llvm.org/viewvc/llvm-project/compiler-rt/trunk/lib/xray/xray_fdr_log_writer.h?rev=346293&r1=346292&r2=346293&view=diff
==============================================================================
--- compiler-rt/trunk/lib/xray/xray_fdr_log_writer.h (original)
+++ compiler-rt/trunk/lib/xray/xray_fdr_log_writer.h Tue Nov 6 20:37:42 2018
@@ -110,8 +110,7 @@ public:
return true;
}
- bool writeCustomEvent(uint64_t TSC, uint16_t CPU, const void *Event,
- int32_t EventSize) {
+ bool writeCustomEvent(int32_t Delta, const void *Event, int32_t EventSize) {
// We write the metadata record and the custom event data into the buffer
// first, before we atomically update the extents for the buffer. This
// allows us to ensure that any threads reading the extents of the buffer
@@ -119,7 +118,7 @@ public:
// (no partial writes accounted).
MetadataRecord R =
createMetadataRecord<MetadataRecord::RecordKinds::CustomEventMarker>(
- EventSize, TSC, CPU);
+ EventSize, Delta);
NextRecord = reinterpret_cast<char *>(internal_memcpy(
NextRecord, reinterpret_cast<char *>(&R), sizeof(R))) +
sizeof(R);
@@ -131,13 +130,13 @@ public:
return true;
}
- bool writeTypedEvent(uint64_t TSC, uint16_t EventType, const void *Event,
+ bool writeTypedEvent(int32_t Delta, uint16_t EventType, const void *Event,
int32_t EventSize) {
// We do something similar when writing out typed events, see
// writeCustomEvent(...) above for details.
MetadataRecord R =
createMetadataRecord<MetadataRecord::RecordKinds::TypedEventMarker>(
- EventSize, TSC, EventType);
+ EventSize, Delta, EventType);
NextRecord = reinterpret_cast<char *>(internal_memcpy(
NextRecord, reinterpret_cast<char *>(&R), sizeof(R))) +
sizeof(R);
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=346293&r1=346292&r2=346293&view=diff
==============================================================================
--- compiler-rt/trunk/lib/xray/xray_fdr_logging.cc (original)
+++ compiler-rt/trunk/lib/xray/xray_fdr_logging.cc Tue Nov 6 20:37:42 2018
@@ -47,6 +47,7 @@ static atomic_sint32_t LoggingStatus = {
XRayLogInitStatus::XRAY_LOG_UNINITIALIZED};
namespace {
+
// Group together thread-local-data in a struct, then hide it behind a function
// call so that it can be initialized on first use instead of as a global. We
// force the alignment to 64-bytes for x86 cache line alignment, as this
@@ -143,26 +144,31 @@ static XRayFileHeader &fdrCommonHeaderIn
static pthread_once_t OnceInit = PTHREAD_ONCE_INIT;
static bool TSCSupported = true;
static uint64_t CycleFrequency = NanosecondsPerSecond;
- pthread_once(&OnceInit, +[] {
- XRayFileHeader &H = reinterpret_cast<XRayFileHeader &>(HStorage);
- // Version 2 of the log writes the extents of the buffer, instead of
- // relying on an end-of-buffer record.
- // Version 3 includes PID metadata record
- // Version 4 includes CPU data in the custom event records
- H.Version = 4;
- H.Type = FileTypes::FDR_LOG;
-
- // Test for required CPU features and cache the cycle frequency
- TSCSupported = probeRequiredCPUFeatures();
- if (TSCSupported)
- CycleFrequency = getTSCFrequency();
- H.CycleFrequency = CycleFrequency;
-
- // FIXME: Actually check whether we have 'constant_tsc' and
- // 'nonstop_tsc' before setting the values in the header.
- H.ConstantTSC = 1;
- H.NonstopTSC = 1;
- });
+ pthread_once(
+ &OnceInit, +[] {
+ XRayFileHeader &H = reinterpret_cast<XRayFileHeader &>(HStorage);
+ // Version 2 of the log writes the extents of the buffer, instead of
+ // relying on an end-of-buffer record.
+ // Version 3 includes PID metadata record.
+ // Version 4 includes CPU data in the custom event records.
+ // Version 5 uses relative deltas for custom and typed event records,
+ // and removes the CPU data in custom event records (similar to how
+ // function records use deltas instead of full TSCs and rely on other
+ // metadata records for TSC wraparound and CPU migration).
+ H.Version = 5;
+ H.Type = FileTypes::FDR_LOG;
+
+ // Test for required CPU features and cache the cycle frequency
+ TSCSupported = probeRequiredCPUFeatures();
+ if (TSCSupported)
+ CycleFrequency = getTSCFrequency();
+ H.CycleFrequency = CycleFrequency;
+
+ // FIXME: Actually check whether we have 'constant_tsc' and
+ // 'nonstop_tsc' before setting the values in the header.
+ H.ConstantTSC = 1;
+ H.NonstopTSC = 1;
+ });
return reinterpret_cast<XRayFileHeader &>(HStorage);
}
@@ -200,9 +206,11 @@ XRayBuffer fdrIterator(const XRayBuffer
// buffers to expect).
static std::aligned_storage<sizeof(XRayFileHeader)>::type HeaderStorage;
static pthread_once_t HeaderOnce = PTHREAD_ONCE_INIT;
- pthread_once(&HeaderOnce, +[] {
- reinterpret_cast<XRayFileHeader &>(HeaderStorage) = fdrCommonHeaderInfo();
- });
+ pthread_once(
+ &HeaderOnce, +[] {
+ reinterpret_cast<XRayFileHeader &>(HeaderStorage) =
+ fdrCommonHeaderInfo();
+ });
// We use a convenience alias for code referring to Header from here on out.
auto &Header = reinterpret_cast<XRayFileHeader &>(HeaderStorage);
@@ -407,7 +415,8 @@ static TSCAndCPU getTimestamp() XRAY_NEV
// Test once for required CPU features
static pthread_once_t OnceProbe = PTHREAD_ONCE_INIT;
static bool TSCSupported = true;
- pthread_once(&OnceProbe, +[] { TSCSupported = probeRequiredCPUFeatures(); });
+ pthread_once(
+ &OnceProbe, +[] { TSCSupported = probeRequiredCPUFeatures(); });
if (TSCSupported) {
Result.TSC = __xray::readTSC(Result.CPU);
@@ -550,10 +559,11 @@ void fdrLoggingHandleCustomEvent(void *E
if (EventSize >
static_cast<std::size_t>(std::numeric_limits<int32_t>::max())) {
static pthread_once_t Once = PTHREAD_ONCE_INIT;
- pthread_once(&Once, +[] {
- Report("Custom event size too large; truncating to %d.\n",
- std::numeric_limits<int32_t>::max());
- });
+ pthread_once(
+ &Once, +[] {
+ Report("Custom event size too large; truncating to %d.\n",
+ std::numeric_limits<int32_t>::max());
+ });
}
auto &TLD = getThreadLocalData();
@@ -579,10 +589,11 @@ void fdrLoggingHandleTypedEvent(
if (EventSize >
static_cast<std::size_t>(std::numeric_limits<int32_t>::max())) {
static pthread_once_t Once = PTHREAD_ONCE_INIT;
- pthread_once(&Once, +[] {
- Report("Typed event size too large; truncating to %d.\n",
- std::numeric_limits<int32_t>::max());
- });
+ pthread_once(
+ &Once, +[] {
+ Report("Typed event size too large; truncating to %d.\n",
+ std::numeric_limits<int32_t>::max());
+ });
}
auto &TLD = getThreadLocalData();
@@ -660,25 +671,28 @@ XRayLogInitStatus fdrLoggingInit(size_t,
}
static pthread_once_t OnceInit = PTHREAD_ONCE_INIT;
- pthread_once(&OnceInit, +[] {
- atomic_store(&TicksPerSec,
- probeRequiredCPUFeatures() ? getTSCFrequency()
- : __xray::NanosecondsPerSecond,
- memory_order_release);
- pthread_key_create(&Key, +[](void *TLDPtr) {
- if (TLDPtr == nullptr)
- return;
- auto &TLD = *reinterpret_cast<ThreadLocalData *>(TLDPtr);
- if (TLD.BQ == nullptr)
- return;
- if (TLD.Buffer.Data == 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.Data, BufferQueue::getErrorString(EC));
- });
- });
+ pthread_once(
+ &OnceInit, +[] {
+ atomic_store(&TicksPerSec,
+ probeRequiredCPUFeatures() ? getTSCFrequency()
+ : __xray::NanosecondsPerSecond,
+ memory_order_release);
+ pthread_key_create(
+ &Key, +[](void *TLDPtr) {
+ if (TLDPtr == nullptr)
+ return;
+ auto &TLD = *reinterpret_cast<ThreadLocalData *>(TLDPtr);
+ if (TLD.BQ == nullptr)
+ return;
+ if (TLD.Buffer.Data == 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.Data, BufferQueue::getErrorString(EC));
+ });
+ });
atomic_store(&ThresholdTicks,
atomic_load_relaxed(&TicksPerSec) *
More information about the llvm-commits
mailing list