Bug Summary

File:projects/compiler-rt/lib/xray/xray_fdr_logging.cc
Warning:line 264, column 3
Null pointer passed as an argument to a 'nonnull' parameter

Annotated Source Code

/build/llvm-toolchain-snapshot-6.0~svn318693/projects/compiler-rt/lib/xray/xray_fdr_logging.cc

→
1//===-- xray_fdr_logging.cc ------------------------------------*- C++ -*-===//
2//
3// The LLVM Compiler Infrastructure
4//
5// This file is distributed under the University of Illinois Open Source
6// License. See LICENSE.TXT for details.
7//
8//===----------------------------------------------------------------------===//
9//
10// This file is a part of XRay, a dynamic runtime instrumentation system.
11//
12// Here we implement the Flight Data Recorder mode for XRay, where we use
13// compact structures to store records in memory as well as when writing out the
14// data to files.
15//
16//===----------------------------------------------------------------------===//
17#include "xray_fdr_logging.h"
18#include <sys/syscall.h>
19#include <sys/time.h>
20#include <errno(*__errno_location ()).h>
21#include <time.h>
22#include <unistd.h>
23
24#include "sanitizer_common/sanitizer_atomic.h"
25#include "sanitizer_common/sanitizer_common.h"
26#include "xray/xray_interface.h"
27#include "xray/xray_records.h"
28#include "xray_buffer_queue.h"
29#include "xray_defs.h"
30#include "xray_fdr_logging_impl.h"
31#include "xray_flags.h"
32#include "xray_tsc.h"
33#include "xray_utils.h"
34
35namespace __xray {
36
37// Global BufferQueue.
38// NOTE: This is a pointer to avoid having to do atomic operations at
39// initialization time. This is OK to leak as there will only be one bufferqueue
40// for the runtime, initialized once through the fdrInit(...) sequence.
41std::shared_ptr<BufferQueue> *BQ = nullptr;
42
43__sanitizer::atomic_sint32_t LogFlushStatus = {
44 XRayLogFlushStatus::XRAY_LOG_NOT_FLUSHING};
45
46FDRLoggingOptions FDROptions;
47
48__sanitizer::SpinMutex FDROptionsMutex;
49
50// Must finalize before flushing.
51XRayLogFlushStatus fdrLoggingFlush() XRAY_NEVER_INSTRUMENT {
52 if (__sanitizer::atomic_load(&LoggingStatus,
53 __sanitizer::memory_order_acquire) !=
54 XRayLogInitStatus::XRAY_LOG_FINALIZED)
55 return XRayLogFlushStatus::XRAY_LOG_NOT_FLUSHING;
56
57 s32 Result = XRayLogFlushStatus::XRAY_LOG_NOT_FLUSHING;
58 if (!__sanitizer::atomic_compare_exchange_strong(
59 &LogFlushStatus, &Result, XRayLogFlushStatus::XRAY_LOG_FLUSHING,
60 __sanitizer::memory_order_release))
61 return static_cast<XRayLogFlushStatus>(Result);
62
63 // Make a copy of the BufferQueue pointer to prevent other threads that may be
64 // resetting it from blowing away the queue prematurely while we're dealing
65 // with it.
66 auto LocalBQ = *BQ;
67
68 // We write out the file in the following format:
69 //
70 // 1) We write down the XRay file header with version 1, type FDR_LOG.
71 // 2) Then we use the 'apply' member of the BufferQueue that's live, to
72 // ensure that at this point in time we write down the buffers that have
73 // been released (and marked "used") -- we dump the full buffer for now
74 // (fixed-sized) and let the tools reading the buffers deal with the data
75 // afterwards.
76 //
77 int Fd = -1;
78 {
79 __sanitizer::SpinMutexLock Guard(&FDROptionsMutex);
80 Fd = FDROptions.Fd;
81 }
82 if (Fd == -1)
83 Fd = getLogFD();
84 if (Fd == -1) {
85 auto Result = XRayLogFlushStatus::XRAY_LOG_NOT_FLUSHING;
86 __sanitizer::atomic_store(&LogFlushStatus, Result,
87 __sanitizer::memory_order_release);
88 return Result;
89 }
90
91 // Test for required CPU features and cache the cycle frequency
92 static bool TSCSupported = probeRequiredCPUFeatures();
93 static uint64_t CycleFrequency =
94 TSCSupported ? getTSCFrequency() : __xray::NanosecondsPerSecond;
95
96 XRayFileHeader Header;
97 Header.Version = 1;
98 Header.Type = FileTypes::FDR_LOG;
99 Header.CycleFrequency = CycleFrequency;
100 // FIXME: Actually check whether we have 'constant_tsc' and 'nonstop_tsc'
101 // before setting the values in the header.
102 Header.ConstantTSC = 1;
103 Header.NonstopTSC = 1;
104 Header.FdrData = FdrAdditionalHeaderData{LocalBQ->ConfiguredBufferSize()};
105 retryingWriteAll(Fd, reinterpret_cast<char *>(&Header),
106 reinterpret_cast<char *>(&Header) + sizeof(Header));
107
108 LocalBQ->apply([&](const BufferQueue::Buffer &B) {
109 uint64_t BufferSize = B.Size;
110 if (BufferSize > 0) {
111 retryingWriteAll(Fd, reinterpret_cast<char *>(B.Buffer),
112 reinterpret_cast<char *>(B.Buffer) + B.Size);
113 }
114 });
115
116 // The buffer for this particular thread would have been finalised after
117 // we've written everything to disk, and we'd lose the thread's trace.
118 auto &TLD = __xray::__xray_fdr_internal::getThreadLocalData();
119 if (TLD.Buffer.Buffer != nullptr) {
120 __xray::__xray_fdr_internal::writeEOBMetadata();
121 auto Start = reinterpret_cast<char *>(TLD.Buffer.Buffer);
122 retryingWriteAll(Fd, Start, Start + TLD.Buffer.Size);
123 }
124
125 __sanitizer::atomic_store(&LogFlushStatus,
126 XRayLogFlushStatus::XRAY_LOG_FLUSHED,
127 __sanitizer::memory_order_release);
128 return XRayLogFlushStatus::XRAY_LOG_FLUSHED;
129}
130
131XRayLogInitStatus fdrLoggingFinalize() XRAY_NEVER_INSTRUMENT {
132 s32 CurrentStatus = XRayLogInitStatus::XRAY_LOG_INITIALIZED;
133 if (!__sanitizer::atomic_compare_exchange_strong(
134 &LoggingStatus, &CurrentStatus,
135 XRayLogInitStatus::XRAY_LOG_FINALIZING,
136 __sanitizer::memory_order_release))
137 return static_cast<XRayLogInitStatus>(CurrentStatus);
138
139 // Do special things to make the log finalize itself, and not allow any more
140 // operations to be performed until re-initialized.
141 (*BQ)->finalize();
142
143 __sanitizer::atomic_store(&LoggingStatus,
144 XRayLogInitStatus::XRAY_LOG_FINALIZED,
145 __sanitizer::memory_order_release);
146 return XRayLogInitStatus::XRAY_LOG_FINALIZED;
147}
148
149XRayLogInitStatus fdrLoggingReset() XRAY_NEVER_INSTRUMENT {
150 s32 CurrentStatus = XRayLogInitStatus::XRAY_LOG_FINALIZED;
151 if (__sanitizer::atomic_compare_exchange_strong(
152 &LoggingStatus, &CurrentStatus,
153 XRayLogInitStatus::XRAY_LOG_INITIALIZED,
154 __sanitizer::memory_order_release))
155 return static_cast<XRayLogInitStatus>(CurrentStatus);
156
157 // Release the in-memory buffer queue.
158 BQ->reset();
159
160 // Spin until the flushing status is flushed.
161 s32 CurrentFlushingStatus = XRayLogFlushStatus::XRAY_LOG_FLUSHED;
162 while (__sanitizer::atomic_compare_exchange_weak(
163 &LogFlushStatus, &CurrentFlushingStatus,
164 XRayLogFlushStatus::XRAY_LOG_NOT_FLUSHING,
165 __sanitizer::memory_order_release)) {
166 if (CurrentFlushingStatus == XRayLogFlushStatus::XRAY_LOG_NOT_FLUSHING)
167 break;
168 CurrentFlushingStatus = XRayLogFlushStatus::XRAY_LOG_FLUSHED;
169 }
170
171 // At this point, we know that the status is flushed, and that we can assume
172 return XRayLogInitStatus::XRAY_LOG_UNINITIALIZED;
173}
174
175struct TSCAndCPU {
176 uint64_t TSC;
177 unsigned char CPU;
178};
179
180static TSCAndCPU getTimestamp() XRAY_NEVER_INSTRUMENT {
181 // We want to get the TSC as early as possible, so that we can check whether
182 // we've seen this CPU before. We also do it before we load anything else, to
183 // allow for forward progress with the scheduling.
184 TSCAndCPU Result;
185
186 // Test once for required CPU features
187 static bool TSCSupported = probeRequiredCPUFeatures();
188
189 if (TSCSupported) {
190 Result.TSC = __xray::readTSC(Result.CPU);
191 } else {
192 // FIXME: This code needs refactoring as it appears in multiple locations
193 timespec TS;
194 int result = clock_gettime(CLOCK_REALTIME0, &TS);
195 if (result != 0) {
196 Report("clock_gettime(2) return %d, errno=%d", result, int(errno(*__errno_location ())));
197 TS = {0, 0};
198 }
199 Result.CPU = 0;
200 Result.TSC = TS.tv_sec * __xray::NanosecondsPerSecond + TS.tv_nsec;
201 }
202 return Result;
203}
204
205void fdrLoggingHandleArg0(int32_t FuncId,
206 XRayEntryType Entry) XRAY_NEVER_INSTRUMENT {
207 auto TC = getTimestamp();
208 __xray_fdr_internal::processFunctionHook(FuncId, Entry, TC.TSC,
209 TC.CPU, 0, clock_gettime, *BQ);
210}
211
212void fdrLoggingHandleArg1(int32_t FuncId, XRayEntryType Entry,
213 uint64_t Arg) XRAY_NEVER_INSTRUMENT {
214 auto TC = getTimestamp();
215 __xray_fdr_internal::processFunctionHook(
216 FuncId, Entry, TC.TSC, TC.CPU, Arg, clock_gettime, *BQ);
217}
218
219void fdrLoggingHandleCustomEvent(void *Event,
220 std::size_t EventSize) XRAY_NEVER_INSTRUMENT {
221 using namespace __xray_fdr_internal;
222 auto TC = getTimestamp();
223 auto &TSC = TC.TSC;
224 auto &CPU = TC.CPU;
225 RecursionGuard Guard{Running};
226 if (!Guard) {
1
Taking false branch
→
227 assert(Running && "RecursionGuard is buggy!")(static_cast <bool> (Running && "RecursionGuard is buggy!"
) ? void (0) : __assert_fail ("Running && \"RecursionGuard is buggy!\""
, "/build/llvm-toolchain-snapshot-6.0~svn318693/projects/compiler-rt/lib/xray/xray_fdr_logging.cc"
, 227, __extension__ __PRETTY_FUNCTION__));
228 return;
229 }
230 if (EventSize > std::numeric_limits<int32_t>::max()) {
2
←
Assuming the condition is false
→
3
←
Taking false branch
→
231 using Empty = struct {};
232 static Empty Once = [&] {
233 Report("Event size too large = %zu ; > max = %d\n", EventSize,
234 std::numeric_limits<int32_t>::max());
235 return Empty();
236 }();
237 (void)Once;
238 }
239 int32_t ReducedEventSize = static_cast<int32_t>(EventSize);
240 auto &TLD = getThreadLocalData();
241 if (!isLogInitializedAndReady(TLD.LocalBQ, TSC, CPU, clock_gettime))
4
←
Calling 'isLogInitializedAndReady'
→
15
←
Returning from 'isLogInitializedAndReady'
→
16
←
Taking false branch
→
242 return;
243
244 // Here we need to prepare the log to handle:
245 // - The metadata record we're going to write. (16 bytes)
246 // - The additional data we're going to write. Currently, that's the size of
247 // the event we're going to dump into the log as free-form bytes.
248 if (!prepareBuffer(TSC, CPU, clock_gettime, MetadataRecSize + EventSize)) {
17
←
Taking false branch
→
249 TLD.LocalBQ = nullptr;
250 return;
251 }
252
253 // Write the custom event metadata record, which consists of the following
254 // information:
255 // - 8 bytes (64-bits) for the full TSC when the event started.
256 // - 4 bytes (32-bits) for the length of the data.
257 MetadataRecord CustomEvent;
258 CustomEvent.Type = uint8_t(RecordType::Metadata);
259 CustomEvent.RecordKind =
260 uint8_t(MetadataRecord::RecordKinds::CustomEventMarker);
261 constexpr auto TSCSize = sizeof(TC.TSC);
262 std::memcpy(&CustomEvent.Data, &ReducedEventSize, sizeof(int32_t));
263 std::memcpy(&CustomEvent.Data[sizeof(int32_t)], &TSC, TSCSize);
264 std::memcpy(TLD.RecordPtr, &CustomEvent, sizeof(CustomEvent));
18
←
Null pointer passed as an argument to a 'nonnull' parameter
265 TLD.RecordPtr += sizeof(CustomEvent);
266 std::memcpy(TLD.RecordPtr, Event, ReducedEventSize);
267 endBufferIfFull();
268}
269
270XRayLogInitStatus fdrLoggingInit(std::size_t BufferSize, std::size_t BufferMax,
271 void *Options,
272 size_t OptionsSize) XRAY_NEVER_INSTRUMENT {
273 if (OptionsSize != sizeof(FDRLoggingOptions))
274 return static_cast<XRayLogInitStatus>(__sanitizer::atomic_load(
275 &LoggingStatus, __sanitizer::memory_order_acquire));
276 s32 CurrentStatus = XRayLogInitStatus::XRAY_LOG_UNINITIALIZED;
277 if (!__sanitizer::atomic_compare_exchange_strong(
278 &LoggingStatus, &CurrentStatus,
279 XRayLogInitStatus::XRAY_LOG_INITIALIZING,
280 __sanitizer::memory_order_release))
281 return static_cast<XRayLogInitStatus>(CurrentStatus);
282
283 {
284 __sanitizer::SpinMutexLock Guard(&FDROptionsMutex);
285 memcpy(&FDROptions, Options, OptionsSize);
286 }
287
288 bool Success = false;
289 if (BQ == nullptr)
290 BQ = new std::shared_ptr<BufferQueue>();
291
292 *BQ = std::make_shared<BufferQueue>(BufferSize, BufferMax, Success);
293 if (!Success) {
294 Report("BufferQueue init failed.\n");
295 return XRayLogInitStatus::XRAY_LOG_UNINITIALIZED;
296 }
297
298 // Arg1 handler should go in first to avoid concurrent code accidentally
299 // falling back to arg0 when it should have ran arg1.
300 __xray_set_handler_arg1(fdrLoggingHandleArg1);
301 // Install the actual handleArg0 handler after initialising the buffers.
302 __xray_set_handler(fdrLoggingHandleArg0);
303 __xray_set_customevent_handler(fdrLoggingHandleCustomEvent);
304
305 __sanitizer::atomic_store(&LoggingStatus,
306 XRayLogInitStatus::XRAY_LOG_INITIALIZED,
307 __sanitizer::memory_order_release);
308 Report("XRay FDR init successful.\n");
309 return XRayLogInitStatus::XRAY_LOG_INITIALIZED;
310}
311
312} // namespace __xray
313
314static auto UNUSED__attribute__((unused)) Unused = [] {
315 using namespace __xray;
316 if (flags()->xray_fdr_log) {
317 XRayLogImpl Impl{
318 fdrLoggingInit,
319 fdrLoggingFinalize,
320 fdrLoggingHandleArg0,
321 fdrLoggingFlush,
322 };
323 __xray_set_log_impl(Impl);
324 }
325 return true;
326}();
←

/build/llvm-toolchain-snapshot-6.0~svn318693/projects/compiler-rt/lib/xray/xray_fdr_logging_impl.h

1//===-- xray_fdr_logging_impl.h ---------------------------------*- C++ -*-===//
2//
3// The LLVM Compiler Infrastructure
4//
5// This file is distributed under the University of Illinois Open Source
6// License. See LICENSE.TXT for details.
7//
8//===----------------------------------------------------------------------===//
9//
10// This file is a part of XRay, a dynamic runtime instrumentation system.
11//
12// Here we implement the thread local state management and record i/o for Flight
13// Data Recorder mode for XRay, where we use compact structures to store records
14// in memory as well as when writing out the data to files.
15//
16//===----------------------------------------------------------------------===//
17#ifndef XRAY_XRAY_FDR_LOGGING_IMPL_H
18#define XRAY_XRAY_FDR_LOGGING_IMPL_H
19
20#include <cassert>
21#include <cstddef>
22#include <cstring>
23#include <limits>
24#include <pthread.h>
25#include <sys/syscall.h>
26#include <time.h>
27#include <unistd.h>
28
29// FIXME: Implement analogues to std::shared_ptr and std::weak_ptr
30#include <memory>
31
32#include "sanitizer_common/sanitizer_common.h"
33#include "xray/xray_log_interface.h"
34#include "xray_buffer_queue.h"
35#include "xray_defs.h"
36#include "xray_fdr_log_records.h"
37#include "xray_flags.h"
38#include "xray_tsc.h"
39
40namespace __xray {
41
42__sanitizer::atomic_sint32_t LoggingStatus = {
43 XRayLogInitStatus::XRAY_LOG_UNINITIALIZED};
44
45/// We expose some of the state transitions when FDR logging mode is operating
46/// such that we can simulate a series of log events that may occur without
47/// and test with determinism without worrying about the real CPU time.
48///
49/// Because the code uses thread_local allocation extensively as part of its
50/// design, callers that wish to test events occuring on different threads
51/// will actually have to run them on different threads.
52///
53/// This also means that it is possible to break invariants maintained by
54/// cooperation with xray_fdr_logging class, so be careful and think twice.
55namespace __xray_fdr_internal {
56
57/// Writes the new buffer record and wallclock time that begin a buffer for a
58/// thread to MemPtr and increments MemPtr. Bypasses the thread local state
59/// machine and writes directly to memory without checks.
60static void writeNewBufferPreamble(pid_t Tid, timespec TS, char *&MemPtr);
61
62/// Write a metadata record to switch to a new CPU to MemPtr and increments
63/// MemPtr. Bypasses the thread local state machine and writes directly to
64/// memory without checks.
65static void writeNewCPUIdMetadata(uint16_t CPU, uint64_t TSC, char *&MemPtr);
66
67/// Writes an EOB metadata record to MemPtr and increments MemPtr. Bypasses the
68/// thread local state machine and writes directly to memory without checks.
69static void writeEOBMetadata(char *&MemPtr);
70
71/// Writes a TSC Wrap metadata record to MemPtr and increments MemPtr. Bypasses
72/// the thread local state machine and directly writes to memory without checks.
73static void writeTSCWrapMetadata(uint64_t TSC, char *&MemPtr);
74
75/// Writes a Function Record to MemPtr and increments MemPtr. Bypasses the
76/// thread local state machine and writes the function record directly to
77/// memory.
78static void writeFunctionRecord(int FuncId, uint32_t TSCDelta,
79 XRayEntryType EntryType, char *&MemPtr);
80
81/// Sets up a new buffer in thread_local storage and writes a preamble. The
82/// wall_clock_reader function is used to populate the WallTimeRecord entry.
83static void setupNewBuffer(int (*wall_clock_reader)(clockid_t,
84 struct timespec *));
85
86/// Called to record CPU time for a new CPU within the current thread.
87static void writeNewCPUIdMetadata(uint16_t CPU, uint64_t TSC);
88
89/// Called to close the buffer when the thread exhausts the buffer or when the
90/// thread exits (via a thread local variable destructor).
91static void writeEOBMetadata();
92
93/// TSC Wrap records are written when a TSC delta encoding scheme overflows.
94static void writeTSCWrapMetadata(uint64_t TSC);
95
96// Group together thread-local-data in a struct, then hide it behind a function
97// call so that it can be initialized on first use instead of as a global. We
98// force the alignment to 64-bytes for x86 cache line alignment, as this
99// structure is used in the hot path of implementation.
100struct alignas(64) ThreadLocalData {
101 BufferQueue::Buffer Buffer;
102 char *RecordPtr = nullptr;
103 // The number of FunctionEntry records immediately preceding RecordPtr.
104 uint8_t NumConsecutiveFnEnters = 0;
105
106 // The number of adjacent, consecutive pairs of FunctionEntry, Tail Exit
107 // records preceding RecordPtr.
108 uint8_t NumTailCalls = 0;
109
110 // We use a thread_local variable to keep track of which CPUs we've already
111 // run, and the TSC times for these CPUs. This allows us to stop repeating the
112 // CPU field in the function records.
113 //
114 // We assume that we'll support only 65536 CPUs for x86_64.
115 uint16_t CurrentCPU = std::numeric_limits<uint16_t>::max();
116 uint64_t LastTSC = 0;
117 uint64_t LastFunctionEntryTSC = 0;
118
119 // Make sure a thread that's ever called handleArg0 has a thread-local
120 // live reference to the buffer queue for this particular instance of
121 // FDRLogging, and that we're going to clean it up when the thread exits.
122 std::shared_ptr<BufferQueue> LocalBQ = nullptr;
123};
124
125// Forward-declare, defined later.
126static ThreadLocalData &getThreadLocalData();
127
128static constexpr auto MetadataRecSize = sizeof(MetadataRecord);
129static constexpr auto FunctionRecSize = sizeof(FunctionRecord);
130
131// This function will initialize the thread-local data structure used by the FDR
132// logging implementation and return a reference to it. The implementation
133// details require a bit of care to maintain.
134//
135// First, some requirements on the implementation in general:
136//
137// - XRay handlers should not call any memory allocation routines that may
138// delegate to an instrumented implementation. This means functions like
139// malloc() and free() should not be called while instrumenting.
140//
141// - We would like to use some thread-local data initialized on first-use of
142// the XRay instrumentation. These allow us to implement unsynchronized
143// routines that access resources associated with the thread.
144//
145// The implementation here uses a few mechanisms that allow us to provide both
146// the requirements listed above. We do this by:
147//
148// 1. Using a thread-local aligned storage buffer for representing the
149// ThreadLocalData struct. This data will be uninitialized memory by
150// design.
151//
152// 2. Using pthread_once(...) to initialize the thread-local data structures
153// on first use, for every thread. We don't use std::call_once so we don't
154// have a reliance on the C++ runtime library.
155//
156// 3. Registering a cleanup function that gets run at the end of a thread's
157// lifetime through pthread_create_key(...). The cleanup function would
158// allow us to release the thread-local resources in a manner that would
159// let the rest of the XRay runtime implementation handle the records
160// written for this thread's active buffer.
161//
162// We're doing this to avoid using a `thread_local` object that has a
163// non-trivial destructor, because the C++ runtime might call std::malloc(...)
164// to register calls to destructors. Deadlocks may arise when, for example, an
165// externally provided malloc implementation is XRay instrumented, and
166// initializing the thread-locals involves calling into malloc. A malloc
167// implementation that does global synchronization might be holding a lock for a
168// critical section, calling a function that might be XRay instrumented (and
169// thus in turn calling into malloc by virtue of registration of the
170// thread_local's destructor).
171//
172// With the approach taken where, we attempt to avoid the potential for
173// deadlocks by relying instead on pthread's memory management routines.
174static ThreadLocalData &getThreadLocalData() {
175 thread_local pthread_key_t key;
176
177 // We need aligned, uninitialized storage for the TLS object which is
178 // trivially destructible. We're going to use this as raw storage and
179 // placement-new the ThreadLocalData object into it later.
180 alignas(alignof(ThreadLocalData)) thread_local unsigned char
181 TLSBuffer[sizeof(ThreadLocalData)];
182
183 // Ensure that we only actually ever do the pthread initialization once.
184 thread_local bool UNUSED__attribute__((unused)) Unused = [] {
185 new (&TLSBuffer) ThreadLocalData();
186 auto result = pthread_key_create(&key, +[](void *) {
187 auto &TLD = *reinterpret_cast<ThreadLocalData *>(&TLSBuffer);
188 auto &RecordPtr = TLD.RecordPtr;
189 auto &Buffers = TLD.LocalBQ;
190 auto &Buffer = TLD.Buffer;
191 if (RecordPtr == nullptr)
192 return;
193
194 // We make sure that upon exit, a thread will write out the EOB
195 // MetadataRecord in the thread-local log, and also release the buffer
196 // to the queue.
197 assert((RecordPtr + MetadataRecSize) -(static_cast <bool> ((RecordPtr + MetadataRecSize) - static_cast
<char *>(Buffer.Buffer) >= static_cast<ptrdiff_t>
(MetadataRecSize)) ? void (0) : __assert_fail ("(RecordPtr + MetadataRecSize) - static_cast<char *>(Buffer.Buffer) >= static_cast<ptrdiff_t>(MetadataRecSize)"
, "/build/llvm-toolchain-snapshot-6.0~svn318693/projects/compiler-rt/lib/xray/xray_fdr_logging_impl.h"
, 199, __extension__ __PRETTY_FUNCTION__))
198 static_cast<char *>(Buffer.Buffer) >=(static_cast <bool> ((RecordPtr + MetadataRecSize) - static_cast
<char *>(Buffer.Buffer) >= static_cast<ptrdiff_t>
(MetadataRecSize)) ? void (0) : __assert_fail ("(RecordPtr + MetadataRecSize) - static_cast<char *>(Buffer.Buffer) >= static_cast<ptrdiff_t>(MetadataRecSize)"
, "/build/llvm-toolchain-snapshot-6.0~svn318693/projects/compiler-rt/lib/xray/xray_fdr_logging_impl.h"
, 199, __extension__ __PRETTY_FUNCTION__))
199 static_cast<ptrdiff_t>(MetadataRecSize))(static_cast <bool> ((RecordPtr + MetadataRecSize) - static_cast
<char *>(Buffer.Buffer) >= static_cast<ptrdiff_t>
(MetadataRecSize)) ? void (0) : __assert_fail ("(RecordPtr + MetadataRecSize) - static_cast<char *>(Buffer.Buffer) >= static_cast<ptrdiff_t>(MetadataRecSize)"
, "/build/llvm-toolchain-snapshot-6.0~svn318693/projects/compiler-rt/lib/xray/xray_fdr_logging_impl.h"
, 199, __extension__ __PRETTY_FUNCTION__));
200 if (Buffers) {
201 writeEOBMetadata();
202 auto EC = Buffers->releaseBuffer(Buffer);
203 if (EC != BufferQueue::ErrorCode::Ok)
204 Report("Failed to release buffer at %p; error=%s\n", Buffer.Buffer,
205 BufferQueue::getErrorString(EC));
206 Buffers = nullptr;
207 return;
208 }
209 });
210 if (result != 0) {
211 Report("Failed to allocate thread-local data through pthread; error=%d",
212 result);
213 return false;
214 }
215 pthread_setspecific(key, &TLSBuffer);
216 return true;
217 }();
218
219 return *reinterpret_cast<ThreadLocalData *>(TLSBuffer);
220}
221
222//-----------------------------------------------------------------------------|
223// The rest of the file is implementation. |
224//-----------------------------------------------------------------------------|
225// Functions are implemented in the header for inlining since we don't want |
226// to grow the stack when we've hijacked the binary for logging. |
227//-----------------------------------------------------------------------------|
228
229namespace {
230
231class RecursionGuard {
232 volatile bool &Running;
233 const bool Valid;
234
235public:
236 explicit RecursionGuard(volatile bool &R) : Running(R), Valid(!R) {
237 if (Valid)
238 Running = true;
239 }
240
241 RecursionGuard(const RecursionGuard &) = delete;
242 RecursionGuard(RecursionGuard &&) = delete;
243 RecursionGuard &operator=(const RecursionGuard &) = delete;
244 RecursionGuard &operator=(RecursionGuard &&) = delete;
245
246 explicit operator bool() const { return Valid; }
247
248 ~RecursionGuard() noexcept {
249 if (Valid)
250 Running = false;
251 }
252};
253
254} // namespace
255
256inline void writeNewBufferPreamble(pid_t Tid, timespec TS,
257 char *&MemPtr) XRAY_NEVER_INSTRUMENT {
258 static constexpr int InitRecordsCount = 2;
259 alignas(alignof(MetadataRecord)) unsigned char
260 Records[InitRecordsCount * MetadataRecSize];
261 {
262 // Write out a MetadataRecord to signify that this is the start of a new
263 // buffer, associated with a particular thread, with a new CPU. For the
264 // data, we have 15 bytes to squeeze as much information as we can. At this
265 // point we only write down the following bytes:
266 // - Thread ID (pid_t, 4 bytes)
267 auto &NewBuffer = *reinterpret_cast<MetadataRecord *>(Records);
268 NewBuffer.Type = uint8_t(RecordType::Metadata);
269 NewBuffer.RecordKind = uint8_t(MetadataRecord::RecordKinds::NewBuffer);
270 std::memcpy(&NewBuffer.Data, &Tid, sizeof(pid_t));
271 }
272 // Also write the WalltimeMarker record.
273 {
274 static_assert(sizeof(time_t) <= 8, "time_t needs to be at most 8 bytes");
275 auto &WalltimeMarker =
276 *reinterpret_cast<MetadataRecord *>(Records + MetadataRecSize);
277 WalltimeMarker.Type = uint8_t(RecordType::Metadata);
278 WalltimeMarker.RecordKind =
279 uint8_t(MetadataRecord::RecordKinds::WalltimeMarker);
280
281 // We only really need microsecond precision here, and enforce across
282 // platforms that we need 64-bit seconds and 32-bit microseconds encoded in
283 // the Metadata record.
284 int32_t Micros = TS.tv_nsec / 1000;
285 int64_t Seconds = TS.tv_sec;
286 std::memcpy(WalltimeMarker.Data, &Seconds, sizeof(Seconds));
287 std::memcpy(WalltimeMarker.Data + sizeof(Seconds), &Micros, sizeof(Micros));
288 }
289 std::memcpy(MemPtr, Records, sizeof(MetadataRecord) * InitRecordsCount);
290 MemPtr += sizeof(MetadataRecord) * InitRecordsCount;
291 auto &TLD = getThreadLocalData();
292 TLD.NumConsecutiveFnEnters = 0;
293 TLD.NumTailCalls = 0;
294}
295
296inline void setupNewBuffer(int (*wall_clock_reader)(
297 clockid_t, struct timespec *)) XRAY_NEVER_INSTRUMENT {
298 auto &TLD = getThreadLocalData();
299 auto &Buffer = TLD.Buffer;
300 auto &RecordPtr = TLD.RecordPtr;
301 RecordPtr = static_cast<char *>(Buffer.Buffer);
302 pid_t Tid = syscall(SYS_gettid186);
303 timespec TS{0, 0};
304 // This is typically clock_gettime, but callers have injection ability.
305 wall_clock_reader(CLOCK_MONOTONIC1, &TS);
306 writeNewBufferPreamble(Tid, TS, RecordPtr);
307 TLD.NumConsecutiveFnEnters = 0;
308 TLD.NumTailCalls = 0;
309}
310
311inline void writeNewCPUIdMetadata(uint16_t CPU, uint64_t TSC,
312 char *&MemPtr) XRAY_NEVER_INSTRUMENT {
313 auto &TLD = getThreadLocalData();
314 MetadataRecord NewCPUId;
315 NewCPUId.Type = uint8_t(RecordType::Metadata);
316 NewCPUId.RecordKind = uint8_t(MetadataRecord::RecordKinds::NewCPUId);
317
318 // The data for the New CPU will contain the following bytes:
319 // - CPU ID (uint16_t, 2 bytes)
320 // - Full TSC (uint64_t, 8 bytes)
321 // Total = 10 bytes.
322 std::memcpy(&NewCPUId.Data, &CPU, sizeof(CPU));
323 std::memcpy(&NewCPUId.Data[sizeof(CPU)], &TSC, sizeof(TSC));
324 std::memcpy(MemPtr, &NewCPUId, sizeof(MetadataRecord));
325 MemPtr += sizeof(MetadataRecord);
326 TLD.NumConsecutiveFnEnters = 0;
327 TLD.NumTailCalls = 0;
328}
329
330inline void writeNewCPUIdMetadata(uint16_t CPU,
331 uint64_t TSC) XRAY_NEVER_INSTRUMENT {
332 writeNewCPUIdMetadata(CPU, TSC, getThreadLocalData().RecordPtr);
333}
334
335inline void writeEOBMetadata(char *&MemPtr) XRAY_NEVER_INSTRUMENT {
336 auto &TLD = getThreadLocalData();
337 MetadataRecord EOBMeta;
338 EOBMeta.Type = uint8_t(RecordType::Metadata);
339 EOBMeta.RecordKind = uint8_t(MetadataRecord::RecordKinds::EndOfBuffer);
340 // For now we don't write any bytes into the Data field.
341 std::memcpy(MemPtr, &EOBMeta, sizeof(MetadataRecord));
342 MemPtr += sizeof(MetadataRecord);
343 TLD.NumConsecutiveFnEnters = 0;
344 TLD.NumTailCalls = 0;
345}
346
347inline void writeEOBMetadata() XRAY_NEVER_INSTRUMENT {
348 writeEOBMetadata(getThreadLocalData().RecordPtr);
349}
350
351inline void writeTSCWrapMetadata(uint64_t TSC,
352 char *&MemPtr) XRAY_NEVER_INSTRUMENT {
353 auto &TLD = getThreadLocalData();
354 MetadataRecord TSCWrap;
355 TSCWrap.Type = uint8_t(RecordType::Metadata);
356 TSCWrap.RecordKind = uint8_t(MetadataRecord::RecordKinds::TSCWrap);
357
358 // The data for the TSCWrap record contains the following bytes:
359 // - Full TSC (uint64_t, 8 bytes)
360 // Total = 8 bytes.
361 std::memcpy(&TSCWrap.Data, &TSC, sizeof(TSC));
362 std::memcpy(MemPtr, &TSCWrap, sizeof(MetadataRecord));
363 MemPtr += sizeof(MetadataRecord);
364 TLD.NumConsecutiveFnEnters = 0;
365 TLD.NumTailCalls = 0;
366}
367
368inline void writeTSCWrapMetadata(uint64_t TSC) XRAY_NEVER_INSTRUMENT {
369 writeTSCWrapMetadata(TSC, getThreadLocalData().RecordPtr);
370}
371
372// Call Argument metadata records store the arguments to a function in the
373// order of their appearance; holes are not supported by the buffer format.
374static inline void writeCallArgumentMetadata(uint64_t A) XRAY_NEVER_INSTRUMENT {
375 auto &TLD = getThreadLocalData();
376 MetadataRecord CallArg;
377 CallArg.Type = uint8_t(RecordType::Metadata);
378 CallArg.RecordKind = uint8_t(MetadataRecord::RecordKinds::CallArgument);
379
380 std::memcpy(CallArg.Data, &A, sizeof(A));
381 std::memcpy(TLD.RecordPtr, &CallArg, sizeof(MetadataRecord));
382 TLD.RecordPtr += sizeof(MetadataRecord);
383}
384
385static inline void writeFunctionRecord(int FuncId, uint32_t TSCDelta,
386 XRayEntryType EntryType,
387 char *&MemPtr) XRAY_NEVER_INSTRUMENT {
388 FunctionRecord FuncRecord;
389 FuncRecord.Type = uint8_t(RecordType::Function);
390 // Only take 28 bits of the function id.
391 FuncRecord.FuncId = FuncId & ~(0x0F << 28);
392 FuncRecord.TSCDelta = TSCDelta;
393
394 auto &TLD = getThreadLocalData();
395 switch (EntryType) {
396 case XRayEntryType::ENTRY:
397 ++TLD.NumConsecutiveFnEnters;
398 FuncRecord.RecordKind = uint8_t(FunctionRecord::RecordKinds::FunctionEnter);
399 break;
400 case XRayEntryType::LOG_ARGS_ENTRY:
401 // We should not rewind functions with logged args.
402 TLD.NumConsecutiveFnEnters = 0;
403 TLD.NumTailCalls = 0;
404 FuncRecord.RecordKind = uint8_t(FunctionRecord::RecordKinds::FunctionEnter);
405 break;
406 case XRayEntryType::EXIT:
407 // If we've decided to log the function exit, we will never erase the log
408 // before it.
409 TLD.NumConsecutiveFnEnters = 0;
410 TLD.NumTailCalls = 0;
411 FuncRecord.RecordKind = uint8_t(FunctionRecord::RecordKinds::FunctionExit);
412 break;
413 case XRayEntryType::TAIL:
414 // If we just entered the function we're tail exiting from or erased every
415 // invocation since then, this function entry tail pair is a candidate to
416 // be erased when the child function exits.
417 if (TLD.NumConsecutiveFnEnters > 0) {
418 ++TLD.NumTailCalls;
419 TLD.NumConsecutiveFnEnters = 0;
420 } else {
421 // We will never be able to erase this tail call since we have logged
422 // something in between the function entry and tail exit.
423 TLD.NumTailCalls = 0;
424 TLD.NumConsecutiveFnEnters = 0;
425 }
426 FuncRecord.RecordKind =
427 uint8_t(FunctionRecord::RecordKinds::FunctionTailExit);
428 break;
429 case XRayEntryType::CUSTOM_EVENT: {
430 // This is a bug in patching, so we'll report it once and move on.
431 static bool Once = [&] {
432 Report("Internal error: patched an XRay custom event call as a function; "
433 "func id = %d\n",
434 FuncId);
435 return true;
436 }();
437 (void)Once;
438 return;
439 }
440 }
441
442 std::memcpy(MemPtr, &FuncRecord, sizeof(FunctionRecord));
443 MemPtr += sizeof(FunctionRecord);
444}
445
446static uint64_t thresholdTicks() {
447 static uint64_t TicksPerSec = probeRequiredCPUFeatures()
448 ? getTSCFrequency()
449 : __xray::NanosecondsPerSecond;
450 static const uint64_t ThresholdTicks =
451 TicksPerSec * flags()->xray_fdr_log_func_duration_threshold_us / 1000000;
452 return ThresholdTicks;
453}
454
455// Re-point the thread local pointer into this thread's Buffer before the recent
456// "Function Entry" record and any "Tail Call Exit" records after that.
457static void rewindRecentCall(uint64_t TSC, uint64_t &LastTSC,
458 uint64_t &LastFunctionEntryTSC, int32_t FuncId) {
459 auto &TLD = getThreadLocalData();
460 TLD.RecordPtr -= FunctionRecSize;
461 FunctionRecord FuncRecord;
462 std::memcpy(&FuncRecord, TLD.RecordPtr, FunctionRecSize);
463 assert(FuncRecord.RecordKind ==(static_cast <bool> (FuncRecord.RecordKind == uint8_t(FunctionRecord
::RecordKinds::FunctionEnter) && "Expected to find function entry recording when rewinding."
) ? void (0) : __assert_fail ("FuncRecord.RecordKind == uint8_t(FunctionRecord::RecordKinds::FunctionEnter) && \"Expected to find function entry recording when rewinding.\""
, "/build/llvm-toolchain-snapshot-6.0~svn318693/projects/compiler-rt/lib/xray/xray_fdr_logging_impl.h"
, 465, __extension__ __PRETTY_FUNCTION__))
464 uint8_t(FunctionRecord::RecordKinds::FunctionEnter) &&(static_cast <bool> (FuncRecord.RecordKind == uint8_t(FunctionRecord
::RecordKinds::FunctionEnter) && "Expected to find function entry recording when rewinding."
) ? void (0) : __assert_fail ("FuncRecord.RecordKind == uint8_t(FunctionRecord::RecordKinds::FunctionEnter) && \"Expected to find function entry recording when rewinding.\""
, "/build/llvm-toolchain-snapshot-6.0~svn318693/projects/compiler-rt/lib/xray/xray_fdr_logging_impl.h"
, 465, __extension__ __PRETTY_FUNCTION__))
465 "Expected to find function entry recording when rewinding.")(static_cast <bool> (FuncRecord.RecordKind == uint8_t(FunctionRecord
::RecordKinds::FunctionEnter) && "Expected to find function entry recording when rewinding."
) ? void (0) : __assert_fail ("FuncRecord.RecordKind == uint8_t(FunctionRecord::RecordKinds::FunctionEnter) && \"Expected to find function entry recording when rewinding.\""
, "/build/llvm-toolchain-snapshot-6.0~svn318693/projects/compiler-rt/lib/xray/xray_fdr_logging_impl.h"
, 465, __extension__ __PRETTY_FUNCTION__));
466 assert(FuncRecord.FuncId == (FuncId & ~(0x0F << 28)) &&(static_cast <bool> (FuncRecord.FuncId == (FuncId &
~(0x0F << 28)) && "Expected matching function id when rewinding Exit"
) ? void (0) : __assert_fail ("FuncRecord.FuncId == (FuncId & ~(0x0F << 28)) && \"Expected matching function id when rewinding Exit\""
, "/build/llvm-toolchain-snapshot-6.0~svn318693/projects/compiler-rt/lib/xray/xray_fdr_logging_impl.h"
, 467, __extension__ __PRETTY_FUNCTION__))
467 "Expected matching function id when rewinding Exit")(static_cast <bool> (FuncRecord.FuncId == (FuncId &
~(0x0F << 28)) && "Expected matching function id when rewinding Exit"
) ? void (0) : __assert_fail ("FuncRecord.FuncId == (FuncId & ~(0x0F << 28)) && \"Expected matching function id when rewinding Exit\""
, "/build/llvm-toolchain-snapshot-6.0~svn318693/projects/compiler-rt/lib/xray/xray_fdr_logging_impl.h"
, 467, __extension__ __PRETTY_FUNCTION__));
468 --TLD.NumConsecutiveFnEnters;
469 LastTSC -= FuncRecord.TSCDelta;
470
471 // We unwound one call. Update the state and return without writing a log.
472 if (TLD.NumConsecutiveFnEnters != 0) {
473 LastFunctionEntryTSC -= FuncRecord.TSCDelta;
474 return;
475 }
476
477 // Otherwise we've rewound the stack of all function entries, we might be
478 // able to rewind further by erasing tail call functions that are being
479 // exited from via this exit.
480 LastFunctionEntryTSC = 0;
481 auto RewindingTSC = LastTSC;
482 auto RewindingRecordPtr = TLD.RecordPtr - FunctionRecSize;
483 while (TLD.NumTailCalls > 0) {
484 // Rewind the TSC back over the TAIL EXIT record.
485 FunctionRecord ExpectedTailExit;
486 std::memcpy(&ExpectedTailExit, RewindingRecordPtr, FunctionRecSize);
487
488 assert(ExpectedTailExit.RecordKind ==(static_cast <bool> (ExpectedTailExit.RecordKind == uint8_t
(FunctionRecord::RecordKinds::FunctionTailExit) && "Expected to find tail exit when rewinding."
) ? void (0) : __assert_fail ("ExpectedTailExit.RecordKind == uint8_t(FunctionRecord::RecordKinds::FunctionTailExit) && \"Expected to find tail exit when rewinding.\""
, "/build/llvm-toolchain-snapshot-6.0~svn318693/projects/compiler-rt/lib/xray/xray_fdr_logging_impl.h"
, 490, __extension__ __PRETTY_FUNCTION__))
489 uint8_t(FunctionRecord::RecordKinds::FunctionTailExit) &&(static_cast <bool> (ExpectedTailExit.RecordKind == uint8_t
(FunctionRecord::RecordKinds::FunctionTailExit) && "Expected to find tail exit when rewinding."
) ? void (0) : __assert_fail ("ExpectedTailExit.RecordKind == uint8_t(FunctionRecord::RecordKinds::FunctionTailExit) && \"Expected to find tail exit when rewinding.\""
, "/build/llvm-toolchain-snapshot-6.0~svn318693/projects/compiler-rt/lib/xray/xray_fdr_logging_impl.h"
, 490, __extension__ __PRETTY_FUNCTION__))
490 "Expected to find tail exit when rewinding.")(static_cast <bool> (ExpectedTailExit.RecordKind == uint8_t
(FunctionRecord::RecordKinds::FunctionTailExit) && "Expected to find tail exit when rewinding."
) ? void (0) : __assert_fail ("ExpectedTailExit.RecordKind == uint8_t(FunctionRecord::RecordKinds::FunctionTailExit) && \"Expected to find tail exit when rewinding.\""
, "/build/llvm-toolchain-snapshot-6.0~svn318693/projects/compiler-rt/lib/xray/xray_fdr_logging_impl.h"
, 490, __extension__ __PRETTY_FUNCTION__));
491 RewindingRecordPtr -= FunctionRecSize;
492 RewindingTSC -= ExpectedTailExit.TSCDelta;
493 FunctionRecord ExpectedFunctionEntry;
494 std::memcpy(&ExpectedFunctionEntry, RewindingRecordPtr, FunctionRecSize);
495 assert(ExpectedFunctionEntry.RecordKind ==(static_cast <bool> (ExpectedFunctionEntry.RecordKind ==
uint8_t(FunctionRecord::RecordKinds::FunctionEnter) &&
"Expected to find function entry when rewinding tail call.")
? void (0) : __assert_fail ("ExpectedFunctionEntry.RecordKind == uint8_t(FunctionRecord::RecordKinds::FunctionEnter) && \"Expected to find function entry when rewinding tail call.\""
, "/build/llvm-toolchain-snapshot-6.0~svn318693/projects/compiler-rt/lib/xray/xray_fdr_logging_impl.h"
, 497, __extension__ __PRETTY_FUNCTION__))
496 uint8_t(FunctionRecord::RecordKinds::FunctionEnter) &&(static_cast <bool> (ExpectedFunctionEntry.RecordKind ==
uint8_t(FunctionRecord::RecordKinds::FunctionEnter) &&
"Expected to find function entry when rewinding tail call.")
? void (0) : __assert_fail ("ExpectedFunctionEntry.RecordKind == uint8_t(FunctionRecord::RecordKinds::FunctionEnter) && \"Expected to find function entry when rewinding tail call.\""
, "/build/llvm-toolchain-snapshot-6.0~svn318693/projects/compiler-rt/lib/xray/xray_fdr_logging_impl.h"
, 497, __extension__ __PRETTY_FUNCTION__))
497 "Expected to find function entry when rewinding tail call.")(static_cast <bool> (ExpectedFunctionEntry.RecordKind ==
uint8_t(FunctionRecord::RecordKinds::FunctionEnter) &&
"Expected to find function entry when rewinding tail call.")
? void (0) : __assert_fail ("ExpectedFunctionEntry.RecordKind == uint8_t(FunctionRecord::RecordKinds::FunctionEnter) && \"Expected to find function entry when rewinding tail call.\""
, "/build/llvm-toolchain-snapshot-6.0~svn318693/projects/compiler-rt/lib/xray/xray_fdr_logging_impl.h"
, 497, __extension__ __PRETTY_FUNCTION__));
498 assert(ExpectedFunctionEntry.FuncId == ExpectedTailExit.FuncId &&(static_cast <bool> (ExpectedFunctionEntry.FuncId == ExpectedTailExit
.FuncId && "Expected funcids to match when rewinding tail call."
) ? void (0) : __assert_fail ("ExpectedFunctionEntry.FuncId == ExpectedTailExit.FuncId && \"Expected funcids to match when rewinding tail call.\""
, "/build/llvm-toolchain-snapshot-6.0~svn318693/projects/compiler-rt/lib/xray/xray_fdr_logging_impl.h"
, 499, __extension__ __PRETTY_FUNCTION__))
499 "Expected funcids to match when rewinding tail call.")(static_cast <bool> (ExpectedFunctionEntry.FuncId == ExpectedTailExit
.FuncId && "Expected funcids to match when rewinding tail call."
) ? void (0) : __assert_fail ("ExpectedFunctionEntry.FuncId == ExpectedTailExit.FuncId && \"Expected funcids to match when rewinding tail call.\""
, "/build/llvm-toolchain-snapshot-6.0~svn318693/projects/compiler-rt/lib/xray/xray_fdr_logging_impl.h"
, 499, __extension__ __PRETTY_FUNCTION__));
500
501 // This tail call exceeded the threshold duration. It will not be erased.
502 if ((TSC - RewindingTSC) >= thresholdTicks()) {
503 TLD.NumTailCalls = 0;
504 return;
505 }
506
507 // We can erase a tail exit pair that we're exiting through since
508 // its duration is under threshold.
509 --TLD.NumTailCalls;
510 RewindingRecordPtr -= FunctionRecSize;
511 RewindingTSC -= ExpectedFunctionEntry.TSCDelta;
512 TLD.RecordPtr -= 2 * FunctionRecSize;
513 LastTSC = RewindingTSC;
514 }
515}
516
517inline bool releaseThreadLocalBuffer(BufferQueue &BQArg) {
518 auto &TLD = getThreadLocalData();
519 auto EC = BQArg.releaseBuffer(TLD.Buffer);
520 if (EC != BufferQueue::ErrorCode::Ok) {
521 Report("Failed to release buffer at %p; error=%s\n", TLD.Buffer.Buffer,
522 BufferQueue::getErrorString(EC));
523 return false;
524 }
525 return true;
526}
527
528inline bool prepareBuffer(uint64_t TSC, unsigned char CPU,
529 int (*wall_clock_reader)(clockid_t,
530 struct timespec *),
531 size_t MaxSize) XRAY_NEVER_INSTRUMENT {
532 auto &TLD = getThreadLocalData();
533 char *BufferStart = static_cast<char *>(TLD.Buffer.Buffer);
534 if ((TLD.RecordPtr + MaxSize) >
535 (BufferStart + TLD.Buffer.Size - MetadataRecSize)) {
536 writeEOBMetadata();
537 if (!releaseThreadLocalBuffer(*TLD.LocalBQ))
538 return false;
539 auto EC = TLD.LocalBQ->getBuffer(TLD.Buffer);
540 if (EC != BufferQueue::ErrorCode::Ok) {
541 Report("Failed to acquire a buffer; error=%s\n",
542 BufferQueue::getErrorString(EC));
543 return false;
544 }
545 setupNewBuffer(wall_clock_reader);
546
547 // Always write the CPU metadata as the first record in the buffer.
548 writeNewCPUIdMetadata(CPU, TSC);
549 }
550 return true;
551}
552
553inline bool isLogInitializedAndReady(
554 std::shared_ptr<BufferQueue> &LBQ, uint64_t TSC, unsigned char CPU,
555 int (*wall_clock_reader)(clockid_t,
556 struct timespec *)) XRAY_NEVER_INSTRUMENT {
557 // Bail out right away if logging is not initialized yet.
558 // We should take the opportunity to release the buffer though.
559 auto Status = __sanitizer::atomic_load(&LoggingStatus,
560 __sanitizer::memory_order_acquire);
561 auto &TLD = getThreadLocalData();
562 if (Status != XRayLogInitStatus::XRAY_LOG_INITIALIZED) {
5
←
Assuming 'Status' is equal to XRAY_LOG_INITIALIZED
→
6
←
Taking false branch
→
563 if (TLD.RecordPtr != nullptr &&
564 (Status == XRayLogInitStatus::XRAY_LOG_FINALIZING ||
565 Status == XRayLogInitStatus::XRAY_LOG_FINALIZED)) {
566 writeEOBMetadata();
567 if (!releaseThreadLocalBuffer(*LBQ))
568 return false;
569 TLD.RecordPtr = nullptr;
570 LBQ = nullptr;
571 return false;
572 }
573 return false;
574 }
575
576 if (__sanitizer::atomic_load(&LoggingStatus,
8
←
Taking true branch
→
577 __sanitizer::memory_order_acquire) !=
578 XRayLogInitStatus::XRAY_LOG_INITIALIZED ||
579 LBQ->finalizing()) {
7
←
Assuming the condition is true
→
580 writeEOBMetadata();
581 if (!releaseThreadLocalBuffer(*LBQ))
9
←
Taking false branch
→
582 return false;
583 TLD.RecordPtr = nullptr;
10
←
Null pointer value stored to field 'RecordPtr'
→
584 }
585
586 if (TLD.Buffer.Buffer == nullptr) {
11
←
Assuming the condition is false
→
12
←
Taking false branch
→
587 auto EC = LBQ->getBuffer(TLD.Buffer);
588 if (EC != BufferQueue::ErrorCode::Ok) {
589 auto LS = __sanitizer::atomic_load(&LoggingStatus,
590 __sanitizer::memory_order_acquire);
591 if (LS != XRayLogInitStatus::XRAY_LOG_FINALIZING &&
592 LS != XRayLogInitStatus::XRAY_LOG_FINALIZED)
593 Report("Failed to acquire a buffer; error=%s\n",
594 BufferQueue::getErrorString(EC));
595 return false;
596 }
597
598 setupNewBuffer(wall_clock_reader);
599
600 // Always write the CPU metadata as the first record in the buffer.
601 writeNewCPUIdMetadata(CPU, TSC);
602 }
603
604 if (TLD.CurrentCPU == std::numeric_limits<uint16_t>::max()) {
13
←
Assuming the condition is false
→
14
←
Taking false branch
→
605 // This means this is the first CPU this thread has ever run on. We set
606 // the current CPU and record this as the first TSC we've seen.
607 TLD.CurrentCPU = CPU;
608 writeNewCPUIdMetadata(CPU, TSC);
609 }
610
611 return true;
612} // namespace __xray_fdr_internal
613
614// Compute the TSC difference between the time of measurement and the previous
615// event. There are a few interesting situations we need to account for:
616//
617// - The thread has migrated to a different CPU. If this is the case, then
618// we write down the following records:
619//
620// 1. A 'NewCPUId' Metadata record.
621// 2. A FunctionRecord with a 0 for the TSCDelta field.
622//
623// - The TSC delta is greater than the 32 bits we can store in a
624// FunctionRecord. In this case we write down the following records:
625//
626// 1. A 'TSCWrap' Metadata record.
627// 2. A FunctionRecord with a 0 for the TSCDelta field.
628//
629// - The TSC delta is representable within the 32 bits we can store in a
630// FunctionRecord. In this case we write down just a FunctionRecord with
631// the correct TSC delta.
632inline uint32_t writeCurrentCPUTSC(ThreadLocalData &TLD, uint64_t TSC,
633 uint8_t CPU) {
634 if (CPU != TLD.CurrentCPU) {
635 // We've moved to a new CPU.
636 writeNewCPUIdMetadata(CPU, TSC);
637 return 0;
638 }
639 // If the delta is greater than the range for a uint32_t, then we write out
640 // the TSC wrap metadata entry with the full TSC, and the TSC for the
641 // function record be 0.
642 uint64_t Delta = TSC - TLD.LastTSC;
643 if (Delta <= std::numeric_limits<uint32_t>::max())
644 return Delta;
645
646 writeTSCWrapMetadata(TSC);
647 return 0;
648}
649
650inline void endBufferIfFull() XRAY_NEVER_INSTRUMENT {
651 auto &TLD = getThreadLocalData();
652 auto BufferStart = static_cast<char *>(TLD.Buffer.Buffer);
653 if ((TLD.RecordPtr + MetadataRecSize) - BufferStart == MetadataRecSize) {
654 writeEOBMetadata();
655 if (!releaseThreadLocalBuffer(*TLD.LocalBQ))
656 return;
657 TLD.RecordPtr = nullptr;
658 }
659}
660
661thread_local volatile bool Running = false;
662
663/// Here's where the meat of the processing happens. The writer captures
664/// function entry, exit and tail exit points with a time and will create
665/// TSCWrap, NewCPUId and Function records as necessary. The writer might
666/// walk backward through its buffer and erase trivial functions to avoid
667/// polluting the log and may use the buffer queue to obtain or release a
668/// buffer.
669inline void processFunctionHook(
670 int32_t FuncId, XRayEntryType Entry, uint64_t TSC, unsigned char CPU,
671 uint64_t Arg1, int (*wall_clock_reader)(clockid_t, struct timespec *),
672 const std::shared_ptr<BufferQueue> &BQ) XRAY_NEVER_INSTRUMENT {
673 // Prevent signal handler recursion, so in case we're already in a log writing
674 // mode and the signal handler comes in (and is also instrumented) then we
675 // don't want to be clobbering potentially partial writes already happening in
676 // the thread. We use a simple thread_local latch to only allow one on-going
677 // handleArg0 to happen at any given time.
678 RecursionGuard Guard{Running};
679 if (!Guard) {
680 assert(Running == true && "RecursionGuard is buggy!")(static_cast <bool> (Running == true && "RecursionGuard is buggy!"
) ? void (0) : __assert_fail ("Running == true && \"RecursionGuard is buggy!\""
, "/build/llvm-toolchain-snapshot-6.0~svn318693/projects/compiler-rt/lib/xray/xray_fdr_logging_impl.h"
, 680, __extension__ __PRETTY_FUNCTION__));
681 return;
682 }
683
684 auto &TLD = getThreadLocalData();
685
686 // In case the reference has been cleaned up before, we make sure we
687 // initialize it to the provided BufferQueue.
688 if (TLD.LocalBQ == nullptr)
689 TLD.LocalBQ = BQ;
690
691 if (!isLogInitializedAndReady(TLD.LocalBQ, TSC, CPU, wall_clock_reader))
692 return;
693
694 // Before we go setting up writing new function entries, we need to be really
695 // careful about the pointer math we're doing. This means we need to ensure
696 // that the record we are about to write is going to fit into the buffer,
697 // without overflowing the buffer.
698 //
699 // To do this properly, we use the following assumptions:
700 //
701 // - The least number of bytes we will ever write is 8
702 // (sizeof(FunctionRecord)) only if the delta between the previous entry
703 // and this entry is within 32 bits.
704 // - The most number of bytes we will ever write is 8 + 16 + 16 = 40.
705 // This is computed by:
706 //
707 // MaxSize = sizeof(FunctionRecord) + 2 * sizeof(MetadataRecord)
708 //
709 // These arise in the following cases:
710 //
711 // 1. When the delta between the TSC we get and the previous TSC for the
712 // same CPU is outside of the uint32_t range, we end up having to
713 // write a MetadataRecord to indicate a "tsc wrap" before the actual
714 // FunctionRecord.
715 // 2. When we learn that we've moved CPUs, we need to write a
716 // MetadataRecord to indicate a "cpu change", and thus write out the
717 // current TSC for that CPU before writing out the actual
718 // FunctionRecord.
719 // 3. When we learn about a new CPU ID, we need to write down a "new cpu
720 // id" MetadataRecord before writing out the actual FunctionRecord.
721 // 4. The second MetadataRecord is the optional function call argument.
722 //
723 // - An End-of-Buffer (EOB) MetadataRecord is 16 bytes.
724 //
725 // So the math we need to do is to determine whether writing 24 bytes past the
726 // current pointer leaves us with enough bytes to write the EOB
727 // MetadataRecord. If we don't have enough space after writing as much as 24
728 // bytes in the end of the buffer, we need to write out the EOB, get a new
729 // Buffer, set it up properly before doing any further writing.
730 size_t MaxSize = FunctionRecSize + 2 * MetadataRecSize;
731 if (!prepareBuffer(TSC, CPU, wall_clock_reader, MaxSize)) {
732 TLD.LocalBQ = nullptr;
733 return;
734 }
735
736 // By this point, we are now ready to write up to 40 bytes (explained above).
737 assert((TLD.RecordPtr + MaxSize) - static_cast<char *>(TLD.Buffer.Buffer) >=(static_cast <bool> ((TLD.RecordPtr + MaxSize) - static_cast
<char *>(TLD.Buffer.Buffer) >= static_cast<ptrdiff_t
>(MetadataRecSize) && "Misconfigured BufferQueue provided; Buffer size not large enough."
) ? void (0) : __assert_fail ("(TLD.RecordPtr + MaxSize) - static_cast<char *>(TLD.Buffer.Buffer) >= static_cast<ptrdiff_t>(MetadataRecSize) && \"Misconfigured BufferQueue provided; Buffer size not large enough.\""
, "/build/llvm-toolchain-snapshot-6.0~svn318693/projects/compiler-rt/lib/xray/xray_fdr_logging_impl.h"
, 739, __extension__ __PRETTY_FUNCTION__))
738 static_cast<ptrdiff_t>(MetadataRecSize) &&(static_cast <bool> ((TLD.RecordPtr + MaxSize) - static_cast
<char *>(TLD.Buffer.Buffer) >= static_cast<ptrdiff_t
>(MetadataRecSize) && "Misconfigured BufferQueue provided; Buffer size not large enough."
) ? void (0) : __assert_fail ("(TLD.RecordPtr + MaxSize) - static_cast<char *>(TLD.Buffer.Buffer) >= static_cast<ptrdiff_t>(MetadataRecSize) && \"Misconfigured BufferQueue provided; Buffer size not large enough.\""
, "/build/llvm-toolchain-snapshot-6.0~svn318693/projects/compiler-rt/lib/xray/xray_fdr_logging_impl.h"
, 739, __extension__ __PRETTY_FUNCTION__))
739 "Misconfigured BufferQueue provided; Buffer size not large enough.")(static_cast <bool> ((TLD.RecordPtr + MaxSize) - static_cast
<char *>(TLD.Buffer.Buffer) >= static_cast<ptrdiff_t
>(MetadataRecSize) && "Misconfigured BufferQueue provided; Buffer size not large enough."
) ? void (0) : __assert_fail ("(TLD.RecordPtr + MaxSize) - static_cast<char *>(TLD.Buffer.Buffer) >= static_cast<ptrdiff_t>(MetadataRecSize) && \"Misconfigured BufferQueue provided; Buffer size not large enough.\""
, "/build/llvm-toolchain-snapshot-6.0~svn318693/projects/compiler-rt/lib/xray/xray_fdr_logging_impl.h"
, 739, __extension__ __PRETTY_FUNCTION__));
740
741 auto RecordTSCDelta = writeCurrentCPUTSC(TLD, TSC, CPU);
742 TLD.LastTSC = TSC;
743 TLD.CurrentCPU = CPU;
744 switch (Entry) {
745 case XRayEntryType::ENTRY:
746 case XRayEntryType::LOG_ARGS_ENTRY:
747 // Update the thread local state for the next invocation.
748 TLD.LastFunctionEntryTSC = TSC;
749 break;
750 case XRayEntryType::TAIL:
751 case XRayEntryType::EXIT:
752 // Break out and write the exit record if we can't erase any functions.
753 if (TLD.NumConsecutiveFnEnters == 0 ||
754 (TSC - TLD.LastFunctionEntryTSC) >= thresholdTicks())
755 break;
756 rewindRecentCall(TSC, TLD.LastTSC, TLD.LastFunctionEntryTSC, FuncId);
757 return; // without writing log.
758 case XRayEntryType::CUSTOM_EVENT: {
759 // This is a bug in patching, so we'll report it once and move on.
760 static bool Once = [&] {
761 Report("Internal error: patched an XRay custom event call as a function; "
762 "func id = %d",
763 FuncId);
764 return true;
765 }();
766 (void)Once;
767 return;
768 }
769 }
770
771 writeFunctionRecord(FuncId, RecordTSCDelta, Entry, TLD.RecordPtr);
772 if (Entry == XRayEntryType::LOG_ARGS_ENTRY)
773 writeCallArgumentMetadata(Arg1);
774
775 // If we've exhausted the buffer by this time, we then release the buffer to
776 // make sure that other threads may start using this buffer.
777 endBufferIfFull();
778}
779
780} // namespace __xray_fdr_internal
781} // namespace __xray
782
783#endif // XRAY_XRAY_FDR_LOGGING_IMPL_H