blob: d4b4345d764afdea274c520ac1f618236a401cbe [file] [log] [blame]
Dean Michael Berriscfd7eec2018-06-12 03:29:39 +00001//===-- xray_profiling.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// This is the implementation of a profiling handler.
13//
14//===----------------------------------------------------------------------===//
15#include <memory>
Dean Michael Berrisaea8ece2018-06-12 04:06:25 +000016#include <time.h>
Dean Michael Berriscfd7eec2018-06-12 03:29:39 +000017
18#include "sanitizer_common/sanitizer_atomic.h"
19#include "sanitizer_common/sanitizer_flags.h"
20#include "xray/xray_interface.h"
21#include "xray/xray_log_interface.h"
22
23#include "xray_flags.h"
24#include "xray_profile_collector.h"
25#include "xray_profiling_flags.h"
26#include "xray_recursion_guard.h"
27#include "xray_tsc.h"
28#include "xray_utils.h"
29#include <pthread.h>
30
31namespace __xray {
32
33namespace {
34
35atomic_sint32_t ProfilerLogFlushStatus = {
36 XRayLogFlushStatus::XRAY_LOG_NOT_FLUSHING};
37
38atomic_sint32_t ProfilerLogStatus = {XRayLogInitStatus::XRAY_LOG_UNINITIALIZED};
39
40SpinMutex ProfilerOptionsMutex;
41
42struct alignas(64) ProfilingData {
43 FunctionCallTrie::Allocators *Allocators = nullptr;
44 FunctionCallTrie *FCT = nullptr;
45};
46
47static pthread_key_t ProfilingKey;
48
Dean Michael Berris9d6b7a52018-07-18 01:53:39 +000049thread_local std::aligned_storage<sizeof(ProfilingData)>::type ThreadStorage{};
Dean Michael Berris9d6b7a52018-07-18 01:53:39 +000050static ProfilingData &getThreadLocalData() XRAY_NEVER_INSTRUMENT {
Dean Michael Berris4719c522018-07-18 02:08:39 +000051 thread_local auto ThreadOnce = [] {
Dean Michael Berriscfd7eec2018-06-12 03:29:39 +000052 new (&ThreadStorage) ProfilingData{};
53 pthread_setspecific(ProfilingKey, &ThreadStorage);
Dean Michael Berris4719c522018-07-18 02:08:39 +000054 return false;
55 }();
56 (void)ThreadOnce;
Dean Michael Berriscfd7eec2018-06-12 03:29:39 +000057
58 auto &TLD = *reinterpret_cast<ProfilingData *>(&ThreadStorage);
59
60 // We need to check whether the global flag to finalizing/finalized has been
61 // switched. If it is, then we ought to not actually initialise the data.
62 auto Status = atomic_load(&ProfilerLogStatus, memory_order_acquire);
63 if (Status == XRayLogInitStatus::XRAY_LOG_FINALIZING ||
64 Status == XRayLogInitStatus::XRAY_LOG_FINALIZED)
65 return TLD;
66
67 // If we're live, then we re-initialize TLD if the pointers are not null.
68 if (UNLIKELY(TLD.Allocators == nullptr && TLD.FCT == nullptr)) {
69 TLD.Allocators = reinterpret_cast<FunctionCallTrie::Allocators *>(
70 InternalAlloc(sizeof(FunctionCallTrie::Allocators)));
71 new (TLD.Allocators) FunctionCallTrie::Allocators();
72 *TLD.Allocators = FunctionCallTrie::InitAllocators();
73 TLD.FCT = reinterpret_cast<FunctionCallTrie *>(
74 InternalAlloc(sizeof(FunctionCallTrie)));
75 new (TLD.FCT) FunctionCallTrie(*TLD.Allocators);
76 }
77
78 return TLD;
79}
80
Dean Michael Berris9d6b7a52018-07-18 01:53:39 +000081static void cleanupTLD() XRAY_NEVER_INSTRUMENT {
82 auto &TLD = *reinterpret_cast<ProfilingData *>(&ThreadStorage);
83 if (TLD.Allocators != nullptr && TLD.FCT != nullptr) {
84 TLD.FCT->~FunctionCallTrie();
85 TLD.Allocators->~Allocators();
86 InternalFree(TLD.FCT);
87 InternalFree(TLD.Allocators);
88 TLD.FCT = nullptr;
89 TLD.Allocators = nullptr;
90 }
91}
92
Dean Michael Berriscfd7eec2018-06-12 03:29:39 +000093} // namespace
94
95const char *profilingCompilerDefinedFlags() XRAY_NEVER_INSTRUMENT {
96#ifdef XRAY_PROFILER_DEFAULT_OPTIONS
97 return SANITIZER_STRINGIFY(XRAY_PROFILER_DEFAULT_OPTIONS);
98#else
99 return "";
100#endif
101}
102
103atomic_sint32_t ProfileFlushStatus = {
104 XRayLogFlushStatus::XRAY_LOG_NOT_FLUSHING};
105
106XRayLogFlushStatus profilingFlush() XRAY_NEVER_INSTRUMENT {
Dean Michael Berriscfd7eec2018-06-12 03:29:39 +0000107 if (atomic_load(&ProfilerLogStatus, memory_order_acquire) !=
108 XRayLogInitStatus::XRAY_LOG_FINALIZED) {
109 if (Verbosity())
110 Report("Not flushing profiles, profiling not been finalized.\n");
111 return XRayLogFlushStatus::XRAY_LOG_NOT_FLUSHING;
112 }
113
114 s32 Result = XRayLogFlushStatus::XRAY_LOG_NOT_FLUSHING;
115 if (!atomic_compare_exchange_strong(&ProfilerLogFlushStatus, &Result,
116 XRayLogFlushStatus::XRAY_LOG_FLUSHING,
117 memory_order_acq_rel)) {
118 if (Verbosity())
119 Report("Not flushing profiles, implementation still finalizing.\n");
120 }
121
Dean Michael Berrisaea8ece2018-06-12 04:06:25 +0000122 // At this point, we'll create the file that will contain the profile, but
123 // only if the options say so.
124 if (!profilingFlags()->no_flush) {
Dean Michael Berris41cea192018-07-19 09:20:19 +0000125 // First check whether we have data in the profile collector service
126 // before we try and write anything down.
127 XRayBuffer B = profileCollectorService::nextBuffer({nullptr, 0});
128 if (B.Data == nullptr) {
129 if (Verbosity())
130 Report("profiling: No data to flush.\n");
Dean Michael Berrisaea8ece2018-06-12 04:06:25 +0000131 } else {
Dean Michael Berris41cea192018-07-19 09:20:19 +0000132 int Fd = getLogFD();
133 if (Fd == -1) {
134 if (Verbosity())
135 Report("profiling: Failed to flush to file, dropping data.\n");
136 } else {
Dean Michael Berris3bd20d42018-07-31 04:16:54 +0000137 // Now for each of the buffers, write out the profile data as we would
Dean Michael Berris41cea192018-07-19 09:20:19 +0000138 // see it in memory, verbatim.
139 while (B.Data != nullptr && B.Size != 0) {
140 retryingWriteAll(Fd, reinterpret_cast<const char *>(B.Data),
141 reinterpret_cast<const char *>(B.Data) + B.Size);
142 B = profileCollectorService::nextBuffer(B);
143 }
144 // Then we close out the file.
145 internal_close(Fd);
Dean Michael Berrisaea8ece2018-06-12 04:06:25 +0000146 }
Dean Michael Berrisaea8ece2018-06-12 04:06:25 +0000147 }
148 }
149
Dean Michael Berriscfd7eec2018-06-12 03:29:39 +0000150 profileCollectorService::reset();
151
Dean Michael Berris9d6b7a52018-07-18 01:53:39 +0000152 // Flush the current thread's local data structures as well.
153 cleanupTLD();
154
Dean Michael Berriscfd7eec2018-06-12 03:29:39 +0000155 atomic_store(&ProfilerLogStatus, XRayLogFlushStatus::XRAY_LOG_FLUSHED,
156 memory_order_release);
157
158 return XRayLogFlushStatus::XRAY_LOG_FLUSHED;
159}
160
161namespace {
162
163thread_local atomic_uint8_t ReentranceGuard{0};
164
Dean Michael Berris9d6b7a52018-07-18 01:53:39 +0000165static void postCurrentThreadFCT(ProfilingData &TLD) {
Dean Michael Berriscfd7eec2018-06-12 03:29:39 +0000166 if (TLD.Allocators == nullptr || TLD.FCT == nullptr)
167 return;
168
169 profileCollectorService::post(*TLD.FCT, GetTid());
Dean Michael Berris9d6b7a52018-07-18 01:53:39 +0000170 cleanupTLD();
Dean Michael Berriscfd7eec2018-06-12 03:29:39 +0000171}
172
173} // namespace
174
175void profilingHandleArg0(int32_t FuncId,
176 XRayEntryType Entry) XRAY_NEVER_INSTRUMENT {
177 unsigned char CPU;
178 auto TSC = readTSC(CPU);
179 RecursionGuard G(ReentranceGuard);
180 if (!G)
181 return;
182
183 auto Status = atomic_load(&ProfilerLogStatus, memory_order_acquire);
184 auto &TLD = getThreadLocalData();
185 if (UNLIKELY(Status == XRayLogInitStatus::XRAY_LOG_FINALIZED ||
186 Status == XRayLogInitStatus::XRAY_LOG_FINALIZING)) {
187 postCurrentThreadFCT(TLD);
188 return;
189 }
190
191 switch (Entry) {
192 case XRayEntryType::ENTRY:
193 case XRayEntryType::LOG_ARGS_ENTRY:
194 TLD.FCT->enterFunction(FuncId, TSC);
195 break;
196 case XRayEntryType::EXIT:
197 case XRayEntryType::TAIL:
198 TLD.FCT->exitFunction(FuncId, TSC);
199 break;
200 default:
201 // FIXME: Handle bugs.
202 break;
203 }
204}
205
206void profilingHandleArg1(int32_t FuncId, XRayEntryType Entry,
207 uint64_t) XRAY_NEVER_INSTRUMENT {
208 return profilingHandleArg0(FuncId, Entry);
209}
210
211XRayLogInitStatus profilingFinalize() XRAY_NEVER_INSTRUMENT {
212 s32 CurrentStatus = XRayLogInitStatus::XRAY_LOG_INITIALIZED;
213 if (!atomic_compare_exchange_strong(&ProfilerLogStatus, &CurrentStatus,
214 XRayLogInitStatus::XRAY_LOG_FINALIZING,
215 memory_order_release)) {
216 if (Verbosity())
217 Report("Cannot finalize profile, the profiling is not initialized.\n");
218 return static_cast<XRayLogInitStatus>(CurrentStatus);
219 }
220
221 // Wait a grace period to allow threads to see that we're finalizing.
222 SleepForMillis(profilingFlags()->grace_period_ms);
223
224 // We also want to make sure that the current thread's data is cleaned up,
225 // if we have any.
226 auto &TLD = getThreadLocalData();
227 postCurrentThreadFCT(TLD);
228
229 // Then we force serialize the log data.
230 profileCollectorService::serialize();
231
232 atomic_store(&ProfilerLogStatus, XRayLogInitStatus::XRAY_LOG_FINALIZED,
233 memory_order_release);
234 return XRayLogInitStatus::XRAY_LOG_FINALIZED;
235}
236
237XRayLogInitStatus
238profilingLoggingInit(size_t BufferSize, size_t BufferMax, void *Options,
239 size_t OptionsSize) XRAY_NEVER_INSTRUMENT {
240 if (BufferSize != 0 || BufferMax != 0) {
241 if (Verbosity())
242 Report("__xray_log_init() being used, and is unsupported. Use "
243 "__xray_log_init_mode(...) instead. Bailing out.");
244 return XRayLogInitStatus::XRAY_LOG_UNINITIALIZED;
245 }
246
247 s32 CurrentStatus = XRayLogInitStatus::XRAY_LOG_UNINITIALIZED;
248 if (!atomic_compare_exchange_strong(&ProfilerLogStatus, &CurrentStatus,
249 XRayLogInitStatus::XRAY_LOG_INITIALIZING,
250 memory_order_release)) {
251 if (Verbosity())
252 Report("Cannot initialize already initialised profiling "
253 "implementation.\n");
254 return static_cast<XRayLogInitStatus>(CurrentStatus);
255 }
256
257 {
258 SpinMutexLock Lock(&ProfilerOptionsMutex);
259 FlagParser ConfigParser;
Dean Michael Berris0dd4f9f2018-07-10 08:25:44 +0000260 ProfilerFlags Flags;
261 Flags.setDefaults();
262 registerProfilerFlags(&ConfigParser, &Flags);
Dean Michael Berrisaea8ece2018-06-12 04:06:25 +0000263 ConfigParser.ParseString(profilingCompilerDefinedFlags());
264 const char *Env = GetEnv("XRAY_PROFILING_OPTIONS");
265 if (Env == nullptr)
266 Env = "";
267 ConfigParser.ParseString(Env);
268
269 // Then parse the configuration string provided.
Dean Michael Berriscfd7eec2018-06-12 03:29:39 +0000270 ConfigParser.ParseString(static_cast<const char *>(Options));
271 if (Verbosity())
272 ReportUnrecognizedFlags();
Dean Michael Berris0dd4f9f2018-07-10 08:25:44 +0000273 *profilingFlags() = Flags;
Dean Michael Berriscfd7eec2018-06-12 03:29:39 +0000274 }
275
276 // We need to reset the profile data collection implementation now.
277 profileCollectorService::reset();
278
Dean Michael Berris5d92d3e2018-07-13 04:04:18 +0000279 // We need to set up the exit handlers.
Dean Michael Berriscfd7eec2018-06-12 03:29:39 +0000280 static pthread_once_t Once = PTHREAD_ONCE_INIT;
281 pthread_once(&Once, +[] {
282 pthread_key_create(&ProfilingKey, +[](void *P) {
283 // This is the thread-exit handler.
284 auto &TLD = *reinterpret_cast<ProfilingData *>(P);
285 if (TLD.Allocators == nullptr && TLD.FCT == nullptr)
286 return;
287
288 postCurrentThreadFCT(TLD);
289 });
Dean Michael Berris5d92d3e2018-07-13 04:04:18 +0000290
291 // We also need to set up an exit handler, so that we can get the profile
292 // information at exit time. We use the C API to do this, to not rely on C++
293 // ABI functions for registering exit handlers.
294 Atexit(+[] {
295 // Finalize and flush.
Dean Michael Berris9d6b7a52018-07-18 01:53:39 +0000296 if (profilingFinalize() != XRAY_LOG_FINALIZED) {
297 cleanupTLD();
Dean Michael Berris5d92d3e2018-07-13 04:04:18 +0000298 return;
Dean Michael Berris9d6b7a52018-07-18 01:53:39 +0000299 }
300 if (profilingFlush() != XRAY_LOG_FLUSHED) {
301 cleanupTLD();
Dean Michael Berris5d92d3e2018-07-13 04:04:18 +0000302 return;
Dean Michael Berris9d6b7a52018-07-18 01:53:39 +0000303 }
Dean Michael Berris5d92d3e2018-07-13 04:04:18 +0000304 if (Verbosity())
305 Report("XRay Profile flushed at exit.");
306 });
Dean Michael Berriscfd7eec2018-06-12 03:29:39 +0000307 });
308
309 __xray_log_set_buffer_iterator(profileCollectorService::nextBuffer);
310 __xray_set_handler(profilingHandleArg0);
311 __xray_set_handler_arg1(profilingHandleArg1);
312
313 atomic_store(&ProfilerLogStatus, XRayLogInitStatus::XRAY_LOG_INITIALIZED,
314 memory_order_release);
315 if (Verbosity())
316 Report("XRay Profiling init successful.\n");
317
318 return XRayLogInitStatus::XRAY_LOG_INITIALIZED;
319}
320
321bool profilingDynamicInitializer() XRAY_NEVER_INSTRUMENT {
322 // Set up the flag defaults from the static defaults and the
323 // compiler-provided defaults.
324 {
325 SpinMutexLock Lock(&ProfilerOptionsMutex);
326 auto *F = profilingFlags();
327 F->setDefaults();
328 FlagParser ProfilingParser;
329 registerProfilerFlags(&ProfilingParser, F);
Dean Michael Berrisaea8ece2018-06-12 04:06:25 +0000330 ProfilingParser.ParseString(profilingCompilerDefinedFlags());
Dean Michael Berriscfd7eec2018-06-12 03:29:39 +0000331 }
332
333 XRayLogImpl Impl{
334 profilingLoggingInit,
335 profilingFinalize,
336 profilingHandleArg0,
337 profilingFlush,
338 };
339 auto RegistrationResult = __xray_log_register_mode("xray-profiling", Impl);
Dean Michael Berris5d92d3e2018-07-13 04:04:18 +0000340 if (RegistrationResult != XRayLogRegisterStatus::XRAY_REGISTRATION_OK) {
341 if (Verbosity())
342 Report("Cannot register XRay Profiling mode to 'xray-profiling'; error = "
343 "%d\n",
344 RegistrationResult);
345 return false;
346 }
347
Dean Michael Berriscfd7eec2018-06-12 03:29:39 +0000348 if (!internal_strcmp(flags()->xray_mode, "xray-profiling"))
Dean Michael Berris5d92d3e2018-07-13 04:04:18 +0000349 __xray_log_select_mode("xray_profiling");
Dean Michael Berriscfd7eec2018-06-12 03:29:39 +0000350 return true;
351}
352
353} // namespace __xray
354
355static auto UNUSED Unused = __xray::profilingDynamicInitializer();