Dean Michael Berris | cfd7eec | 2018-06-12 03:29:39 +0000 | [diff] [blame] | 1 | //===-- 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 Berris | aea8ece | 2018-06-12 04:06:25 +0000 | [diff] [blame] | 16 | #include <time.h> |
Dean Michael Berris | cfd7eec | 2018-06-12 03:29:39 +0000 | [diff] [blame] | 17 | |
| 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 | |
| 31 | namespace __xray { |
| 32 | |
| 33 | namespace { |
| 34 | |
| 35 | atomic_sint32_t ProfilerLogFlushStatus = { |
| 36 | XRayLogFlushStatus::XRAY_LOG_NOT_FLUSHING}; |
| 37 | |
| 38 | atomic_sint32_t ProfilerLogStatus = {XRayLogInitStatus::XRAY_LOG_UNINITIALIZED}; |
| 39 | |
| 40 | SpinMutex ProfilerOptionsMutex; |
| 41 | |
| 42 | struct alignas(64) ProfilingData { |
| 43 | FunctionCallTrie::Allocators *Allocators = nullptr; |
| 44 | FunctionCallTrie *FCT = nullptr; |
| 45 | }; |
| 46 | |
| 47 | static pthread_key_t ProfilingKey; |
| 48 | |
Dean Michael Berris | 9d6b7a5 | 2018-07-18 01:53:39 +0000 | [diff] [blame] | 49 | thread_local std::aligned_storage<sizeof(ProfilingData)>::type ThreadStorage{}; |
Dean Michael Berris | 9d6b7a5 | 2018-07-18 01:53:39 +0000 | [diff] [blame] | 50 | static ProfilingData &getThreadLocalData() XRAY_NEVER_INSTRUMENT { |
Dean Michael Berris | 4719c52 | 2018-07-18 02:08:39 +0000 | [diff] [blame] | 51 | thread_local auto ThreadOnce = [] { |
Dean Michael Berris | cfd7eec | 2018-06-12 03:29:39 +0000 | [diff] [blame] | 52 | new (&ThreadStorage) ProfilingData{}; |
| 53 | pthread_setspecific(ProfilingKey, &ThreadStorage); |
Dean Michael Berris | 4719c52 | 2018-07-18 02:08:39 +0000 | [diff] [blame] | 54 | return false; |
| 55 | }(); |
| 56 | (void)ThreadOnce; |
Dean Michael Berris | cfd7eec | 2018-06-12 03:29:39 +0000 | [diff] [blame] | 57 | |
| 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 Berris | 9d6b7a5 | 2018-07-18 01:53:39 +0000 | [diff] [blame] | 81 | static 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 Berris | cfd7eec | 2018-06-12 03:29:39 +0000 | [diff] [blame] | 93 | } // namespace |
| 94 | |
| 95 | const 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 | |
| 103 | atomic_sint32_t ProfileFlushStatus = { |
| 104 | XRayLogFlushStatus::XRAY_LOG_NOT_FLUSHING}; |
| 105 | |
| 106 | XRayLogFlushStatus profilingFlush() XRAY_NEVER_INSTRUMENT { |
Dean Michael Berris | cfd7eec | 2018-06-12 03:29:39 +0000 | [diff] [blame] | 107 | 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 Berris | aea8ece | 2018-06-12 04:06:25 +0000 | [diff] [blame] | 122 | // 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 Berris | 41cea19 | 2018-07-19 09:20:19 +0000 | [diff] [blame] | 125 | // 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 Berris | aea8ece | 2018-06-12 04:06:25 +0000 | [diff] [blame] | 131 | } else { |
Dean Michael Berris | 41cea19 | 2018-07-19 09:20:19 +0000 | [diff] [blame] | 132 | 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 Berris | 3bd20d4 | 2018-07-31 04:16:54 +0000 | [diff] [blame] | 137 | // Now for each of the buffers, write out the profile data as we would |
Dean Michael Berris | 41cea19 | 2018-07-19 09:20:19 +0000 | [diff] [blame] | 138 | // 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 Berris | aea8ece | 2018-06-12 04:06:25 +0000 | [diff] [blame] | 146 | } |
Dean Michael Berris | aea8ece | 2018-06-12 04:06:25 +0000 | [diff] [blame] | 147 | } |
| 148 | } |
| 149 | |
Dean Michael Berris | cfd7eec | 2018-06-12 03:29:39 +0000 | [diff] [blame] | 150 | profileCollectorService::reset(); |
| 151 | |
Dean Michael Berris | 9d6b7a5 | 2018-07-18 01:53:39 +0000 | [diff] [blame] | 152 | // Flush the current thread's local data structures as well. |
| 153 | cleanupTLD(); |
| 154 | |
Dean Michael Berris | cfd7eec | 2018-06-12 03:29:39 +0000 | [diff] [blame] | 155 | atomic_store(&ProfilerLogStatus, XRayLogFlushStatus::XRAY_LOG_FLUSHED, |
| 156 | memory_order_release); |
| 157 | |
| 158 | return XRayLogFlushStatus::XRAY_LOG_FLUSHED; |
| 159 | } |
| 160 | |
| 161 | namespace { |
| 162 | |
| 163 | thread_local atomic_uint8_t ReentranceGuard{0}; |
| 164 | |
Dean Michael Berris | 9d6b7a5 | 2018-07-18 01:53:39 +0000 | [diff] [blame] | 165 | static void postCurrentThreadFCT(ProfilingData &TLD) { |
Dean Michael Berris | cfd7eec | 2018-06-12 03:29:39 +0000 | [diff] [blame] | 166 | if (TLD.Allocators == nullptr || TLD.FCT == nullptr) |
| 167 | return; |
| 168 | |
| 169 | profileCollectorService::post(*TLD.FCT, GetTid()); |
Dean Michael Berris | 9d6b7a5 | 2018-07-18 01:53:39 +0000 | [diff] [blame] | 170 | cleanupTLD(); |
Dean Michael Berris | cfd7eec | 2018-06-12 03:29:39 +0000 | [diff] [blame] | 171 | } |
| 172 | |
| 173 | } // namespace |
| 174 | |
| 175 | void 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 | |
| 206 | void profilingHandleArg1(int32_t FuncId, XRayEntryType Entry, |
| 207 | uint64_t) XRAY_NEVER_INSTRUMENT { |
| 208 | return profilingHandleArg0(FuncId, Entry); |
| 209 | } |
| 210 | |
| 211 | XRayLogInitStatus 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 | |
| 237 | XRayLogInitStatus |
| 238 | profilingLoggingInit(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 Berris | 0dd4f9f | 2018-07-10 08:25:44 +0000 | [diff] [blame] | 260 | ProfilerFlags Flags; |
| 261 | Flags.setDefaults(); |
| 262 | registerProfilerFlags(&ConfigParser, &Flags); |
Dean Michael Berris | aea8ece | 2018-06-12 04:06:25 +0000 | [diff] [blame] | 263 | 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 Berris | cfd7eec | 2018-06-12 03:29:39 +0000 | [diff] [blame] | 270 | ConfigParser.ParseString(static_cast<const char *>(Options)); |
| 271 | if (Verbosity()) |
| 272 | ReportUnrecognizedFlags(); |
Dean Michael Berris | 0dd4f9f | 2018-07-10 08:25:44 +0000 | [diff] [blame] | 273 | *profilingFlags() = Flags; |
Dean Michael Berris | cfd7eec | 2018-06-12 03:29:39 +0000 | [diff] [blame] | 274 | } |
| 275 | |
| 276 | // We need to reset the profile data collection implementation now. |
| 277 | profileCollectorService::reset(); |
| 278 | |
Dean Michael Berris | 5d92d3e | 2018-07-13 04:04:18 +0000 | [diff] [blame] | 279 | // We need to set up the exit handlers. |
Dean Michael Berris | cfd7eec | 2018-06-12 03:29:39 +0000 | [diff] [blame] | 280 | 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 Berris | 5d92d3e | 2018-07-13 04:04:18 +0000 | [diff] [blame] | 290 | |
| 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 Berris | 9d6b7a5 | 2018-07-18 01:53:39 +0000 | [diff] [blame] | 296 | if (profilingFinalize() != XRAY_LOG_FINALIZED) { |
| 297 | cleanupTLD(); |
Dean Michael Berris | 5d92d3e | 2018-07-13 04:04:18 +0000 | [diff] [blame] | 298 | return; |
Dean Michael Berris | 9d6b7a5 | 2018-07-18 01:53:39 +0000 | [diff] [blame] | 299 | } |
| 300 | if (profilingFlush() != XRAY_LOG_FLUSHED) { |
| 301 | cleanupTLD(); |
Dean Michael Berris | 5d92d3e | 2018-07-13 04:04:18 +0000 | [diff] [blame] | 302 | return; |
Dean Michael Berris | 9d6b7a5 | 2018-07-18 01:53:39 +0000 | [diff] [blame] | 303 | } |
Dean Michael Berris | 5d92d3e | 2018-07-13 04:04:18 +0000 | [diff] [blame] | 304 | if (Verbosity()) |
| 305 | Report("XRay Profile flushed at exit."); |
| 306 | }); |
Dean Michael Berris | cfd7eec | 2018-06-12 03:29:39 +0000 | [diff] [blame] | 307 | }); |
| 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 | |
| 321 | bool 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 Berris | aea8ece | 2018-06-12 04:06:25 +0000 | [diff] [blame] | 330 | ProfilingParser.ParseString(profilingCompilerDefinedFlags()); |
Dean Michael Berris | cfd7eec | 2018-06-12 03:29:39 +0000 | [diff] [blame] | 331 | } |
| 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 Berris | 5d92d3e | 2018-07-13 04:04:18 +0000 | [diff] [blame] | 340 | 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 Berris | cfd7eec | 2018-06-12 03:29:39 +0000 | [diff] [blame] | 348 | if (!internal_strcmp(flags()->xray_mode, "xray-profiling")) |
Dean Michael Berris | 5d92d3e | 2018-07-13 04:04:18 +0000 | [diff] [blame] | 349 | __xray_log_select_mode("xray_profiling"); |
Dean Michael Berris | cfd7eec | 2018-06-12 03:29:39 +0000 | [diff] [blame] | 350 | return true; |
| 351 | } |
| 352 | |
| 353 | } // namespace __xray |
| 354 | |
| 355 | static auto UNUSED Unused = __xray::profilingDynamicInitializer(); |