contrib/compiler-rt/lib/xray/xray_profiling.cc

   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>
  16 #include <time.h>
  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 constexpr uptr XRayProfilingVersion = 0x20180424;
  36
  37 struct XRayProfilingFileHeader {
  38   const u64 MagicBytes = 0x7872617970726f66; // Identifier for XRay profiling
  39                                              // files 'xrayprof' in hex.
  40   const uptr Version = XRayProfilingVersion;
  41   uptr Timestamp = 0; // System time in nanoseconds.
  42   uptr PID = 0;       // Process ID.
  43 };
  44
  45 atomic_sint32_t ProfilerLogFlushStatus = {
  46     XRayLogFlushStatus::XRAY_LOG_NOT_FLUSHING};
  47
  48 atomic_sint32_t ProfilerLogStatus = {XRayLogInitStatus::XRAY_LOG_UNINITIALIZED};
  49
  50 SpinMutex ProfilerOptionsMutex;
  51
  52 struct alignas(64) ProfilingData {
  53   FunctionCallTrie::Allocators *Allocators = nullptr;
  54   FunctionCallTrie *FCT = nullptr;
  55 };
  56
  57 static pthread_key_t ProfilingKey;
  58
  59 thread_local std::aligned_storage<sizeof(ProfilingData)>::type ThreadStorage{};
  60 static ProfilingData &getThreadLocalData() XRAY_NEVER_INSTRUMENT {
  61   thread_local auto ThreadOnce = [] {
  62     new (&ThreadStorage) ProfilingData{};
  63     pthread_setspecific(ProfilingKey, &ThreadStorage);
  64     return false;
  65   }();
  66   (void)ThreadOnce;
  67
  68   auto &TLD = *reinterpret_cast<ProfilingData *>(&ThreadStorage);
  69
  70   // We need to check whether the global flag to finalizing/finalized has been
  71   // switched. If it is, then we ought to not actually initialise the data.
  72   auto Status = atomic_load(&ProfilerLogStatus, memory_order_acquire);
  73   if (Status == XRayLogInitStatus::XRAY_LOG_FINALIZING ||
  74       Status == XRayLogInitStatus::XRAY_LOG_FINALIZED)
  75     return TLD;
  76
  77   // If we're live, then we re-initialize TLD if the pointers are not null.
  78   if (UNLIKELY(TLD.Allocators == nullptr && TLD.FCT == nullptr)) {
  79     TLD.Allocators = reinterpret_cast<FunctionCallTrie::Allocators *>(
  80         InternalAlloc(sizeof(FunctionCallTrie::Allocators)));
  81     new (TLD.Allocators) FunctionCallTrie::Allocators();
  82     *TLD.Allocators = FunctionCallTrie::InitAllocators();
  83     TLD.FCT = reinterpret_cast<FunctionCallTrie *>(
  84         InternalAlloc(sizeof(FunctionCallTrie)));
  85     new (TLD.FCT) FunctionCallTrie(*TLD.Allocators);
  86   }
  87
  88   return TLD;
  89 }
  90
  91 static void cleanupTLD() XRAY_NEVER_INSTRUMENT {
  92   auto &TLD = *reinterpret_cast<ProfilingData *>(&ThreadStorage);
  93   if (TLD.Allocators != nullptr && TLD.FCT != nullptr) {
  94     TLD.FCT->~FunctionCallTrie();
  95     TLD.Allocators->~Allocators();
  96     InternalFree(TLD.FCT);
  97     InternalFree(TLD.Allocators);
  98     TLD.FCT = nullptr;
  99     TLD.Allocators = nullptr;
 100   }
 101 }
 102
 103 } // namespace
 104
 105 const char *profilingCompilerDefinedFlags() XRAY_NEVER_INSTRUMENT {
 106 #ifdef XRAY_PROFILER_DEFAULT_OPTIONS
 107   return SANITIZER_STRINGIFY(XRAY_PROFILER_DEFAULT_OPTIONS);
 108 #else
 109   return "";
 110 #endif
 111 }
 112
 113 atomic_sint32_t ProfileFlushStatus = {
 114     XRayLogFlushStatus::XRAY_LOG_NOT_FLUSHING};
 115
 116 XRayLogFlushStatus profilingFlush() XRAY_NEVER_INSTRUMENT {
 117   if (atomic_load(&ProfilerLogStatus, memory_order_acquire) !=
 118       XRayLogInitStatus::XRAY_LOG_FINALIZED) {
 119     if (Verbosity())
 120       Report("Not flushing profiles, profiling not been finalized.\n");
 121     return XRayLogFlushStatus::XRAY_LOG_NOT_FLUSHING;
 122   }
 123
 124   s32 Result = XRayLogFlushStatus::XRAY_LOG_NOT_FLUSHING;
 125   if (!atomic_compare_exchange_strong(&ProfilerLogFlushStatus, &Result,
 126                                       XRayLogFlushStatus::XRAY_LOG_FLUSHING,
 127                                       memory_order_acq_rel)) {
 128     if (Verbosity())
 129       Report("Not flushing profiles, implementation still finalizing.\n");
 130   }
 131
 132   // At this point, we'll create the file that will contain the profile, but
 133   // only if the options say so.
 134   if (!profilingFlags()->no_flush) {
 135     // First check whether we have data in the profile collector service
 136     // before we try and write anything down.
 137     XRayBuffer B = profileCollectorService::nextBuffer({nullptr, 0});
 138     if (B.Data == nullptr) {
 139       if (Verbosity())
 140         Report("profiling: No data to flush.\n");
 141     } else {
 142       int Fd = getLogFD();
 143       if (Fd == -1) {
 144         if (Verbosity())
 145           Report("profiling: Failed to flush to file, dropping data.\n");
 146       } else {
 147         XRayProfilingFileHeader Header;
 148         Header.Timestamp = NanoTime();
 149         Header.PID = internal_getpid();
 150         retryingWriteAll(Fd, reinterpret_cast<const char *>(&Header),
 151                          reinterpret_cast<const char *>(&Header) +
 152                              sizeof(Header));
 153
 154         // Now for each of the threads, write out the profile data as we would
 155         // see it in memory, verbatim.
 156         while (B.Data != nullptr && B.Size != 0) {
 157           retryingWriteAll(Fd, reinterpret_cast<const char *>(B.Data),
 158                            reinterpret_cast<const char *>(B.Data) + B.Size);
 159           B = profileCollectorService::nextBuffer(B);
 160         }
 161         // Then we close out the file.
 162         internal_close(Fd);
 163       }
 164     }
 165   }
 166
 167   profileCollectorService::reset();
 168
 169   // Flush the current thread's local data structures as well.
 170   cleanupTLD();
 171
 172   atomic_store(&ProfilerLogStatus, XRayLogFlushStatus::XRAY_LOG_FLUSHED,
 173                memory_order_release);
 174
 175   return XRayLogFlushStatus::XRAY_LOG_FLUSHED;
 176 }
 177
 178 namespace {
 179
 180 thread_local atomic_uint8_t ReentranceGuard{0};
 181
 182 static void postCurrentThreadFCT(ProfilingData &TLD) {
 183   if (TLD.Allocators == nullptr || TLD.FCT == nullptr)
 184     return;
 185
 186   profileCollectorService::post(*TLD.FCT, GetTid());
 187   cleanupTLD();
 188 }
 189
 190 } // namespace
 191
 192 void profilingHandleArg0(int32_t FuncId,
 193                          XRayEntryType Entry) XRAY_NEVER_INSTRUMENT {
 194   unsigned char CPU;
 195   auto TSC = readTSC(CPU);
 196   RecursionGuard G(ReentranceGuard);
 197   if (!G)
 198     return;
 199
 200   auto Status = atomic_load(&ProfilerLogStatus, memory_order_acquire);
 201   auto &TLD = getThreadLocalData();
 202   if (UNLIKELY(Status == XRayLogInitStatus::XRAY_LOG_FINALIZED ||
 203                Status == XRayLogInitStatus::XRAY_LOG_FINALIZING)) {
 204     postCurrentThreadFCT(TLD);
 205     return;
 206   }
 207
 208   switch (Entry) {
 209   case XRayEntryType::ENTRY:
 210   case XRayEntryType::LOG_ARGS_ENTRY:
 211     TLD.FCT->enterFunction(FuncId, TSC);
 212     break;
 213   case XRayEntryType::EXIT:
 214   case XRayEntryType::TAIL:
 215     TLD.FCT->exitFunction(FuncId, TSC);
 216     break;
 217   default:
 218     // FIXME: Handle bugs.
 219     break;
 220   }
 221 }
 222
 223 void profilingHandleArg1(int32_t FuncId, XRayEntryType Entry,
 224                          uint64_t) XRAY_NEVER_INSTRUMENT {
 225   return profilingHandleArg0(FuncId, Entry);
 226 }
 227
 228 XRayLogInitStatus profilingFinalize() XRAY_NEVER_INSTRUMENT {
 229   s32 CurrentStatus = XRayLogInitStatus::XRAY_LOG_INITIALIZED;
 230   if (!atomic_compare_exchange_strong(&ProfilerLogStatus, &CurrentStatus,
 231                                       XRayLogInitStatus::XRAY_LOG_FINALIZING,
 232                                       memory_order_release)) {
 233     if (Verbosity())
 234       Report("Cannot finalize profile, the profiling is not initialized.\n");
 235     return static_cast<XRayLogInitStatus>(CurrentStatus);
 236   }
 237
 238   // Wait a grace period to allow threads to see that we're finalizing.
 239   SleepForMillis(profilingFlags()->grace_period_ms);
 240
 241   // We also want to make sure that the current thread's data is cleaned up,
 242   // if we have any.
 243   auto &TLD = getThreadLocalData();
 244   postCurrentThreadFCT(TLD);
 245
 246   // Then we force serialize the log data.
 247   profileCollectorService::serialize();
 248
 249   atomic_store(&ProfilerLogStatus, XRayLogInitStatus::XRAY_LOG_FINALIZED,
 250                memory_order_release);
 251   return XRayLogInitStatus::XRAY_LOG_FINALIZED;
 252 }
 253
 254 XRayLogInitStatus
 255 profilingLoggingInit(size_t BufferSize, size_t BufferMax, void *Options,
 256                      size_t OptionsSize) XRAY_NEVER_INSTRUMENT {
 257   if (BufferSize != 0 || BufferMax != 0) {
 258     if (Verbosity())
 259       Report("__xray_log_init() being used, and is unsupported. Use "
 260              "__xray_log_init_mode(...) instead. Bailing out.");
 261     return XRayLogInitStatus::XRAY_LOG_UNINITIALIZED;
 262   }
 263
 264   s32 CurrentStatus = XRayLogInitStatus::XRAY_LOG_UNINITIALIZED;
 265   if (!atomic_compare_exchange_strong(&ProfilerLogStatus, &CurrentStatus,
 266                                       XRayLogInitStatus::XRAY_LOG_INITIALIZING,
 267                                       memory_order_release)) {
 268     if (Verbosity())
 269       Report("Cannot initialize already initialised profiling "
 270              "implementation.\n");
 271     return static_cast<XRayLogInitStatus>(CurrentStatus);
 272   }
 273
 274   {
 275     SpinMutexLock Lock(&ProfilerOptionsMutex);
 276     FlagParser ConfigParser;
 277     ProfilerFlags Flags;
 278     Flags.setDefaults();
 279     registerProfilerFlags(&ConfigParser, &Flags);
 280     ConfigParser.ParseString(profilingCompilerDefinedFlags());
 281     const char *Env = GetEnv("XRAY_PROFILING_OPTIONS");
 282     if (Env == nullptr)
 283       Env = "";
 284     ConfigParser.ParseString(Env);
 285
 286     // Then parse the configuration string provided.
 287     ConfigParser.ParseString(static_cast<const char *>(Options));
 288     if (Verbosity())
 289       ReportUnrecognizedFlags();
 290     *profilingFlags() = Flags;
 291   }
 292
 293   // We need to reset the profile data collection implementation now.
 294   profileCollectorService::reset();
 295
 296   // We need to set up the exit handlers.
 297   static pthread_once_t Once = PTHREAD_ONCE_INIT;
 298   pthread_once(&Once, +[] {
 299     pthread_key_create(&ProfilingKey, +[](void *P) {
 300       // This is the thread-exit handler.
 301       auto &TLD = *reinterpret_cast<ProfilingData *>(P);
 302       if (TLD.Allocators == nullptr && TLD.FCT == nullptr)
 303         return;
 304
 305       postCurrentThreadFCT(TLD);
 306     });
 307
 308     // We also need to set up an exit handler, so that we can get the profile
 309     // information at exit time. We use the C API to do this, to not rely on C++
 310     // ABI functions for registering exit handlers.
 311     Atexit(+[] {
 312       // Finalize and flush.
 313       if (profilingFinalize() != XRAY_LOG_FINALIZED) {
 314         cleanupTLD();
 315         return;
 316       }
 317       if (profilingFlush() != XRAY_LOG_FLUSHED) {
 318         cleanupTLD();
 319         return;
 320       }
 321       if (Verbosity())
 322         Report("XRay Profile flushed at exit.");
 323     });
 324   });
 325
 326   __xray_log_set_buffer_iterator(profileCollectorService::nextBuffer);
 327   __xray_set_handler(profilingHandleArg0);
 328   __xray_set_handler_arg1(profilingHandleArg1);
 329
 330   atomic_store(&ProfilerLogStatus, XRayLogInitStatus::XRAY_LOG_INITIALIZED,
 331                memory_order_release);
 332   if (Verbosity())
 333     Report("XRay Profiling init successful.\n");
 334
 335   return XRayLogInitStatus::XRAY_LOG_INITIALIZED;
 336 }
 337
 338 bool profilingDynamicInitializer() XRAY_NEVER_INSTRUMENT {
 339   // Set up the flag defaults from the static defaults and the
 340   // compiler-provided defaults.
 341   {
 342     SpinMutexLock Lock(&ProfilerOptionsMutex);
 343     auto *F = profilingFlags();
 344     F->setDefaults();
 345     FlagParser ProfilingParser;
 346     registerProfilerFlags(&ProfilingParser, F);
 347     ProfilingParser.ParseString(profilingCompilerDefinedFlags());
 348   }
 349
 350   XRayLogImpl Impl{
 351       profilingLoggingInit,
 352       profilingFinalize,
 353       profilingHandleArg0,
 354       profilingFlush,
 355   };
 356   auto RegistrationResult = __xray_log_register_mode("xray-profiling", Impl);
 357   if (RegistrationResult != XRayLogRegisterStatus::XRAY_REGISTRATION_OK) {
 358     if (Verbosity())
 359       Report("Cannot register XRay Profiling mode to 'xray-profiling'; error = "
 360              "%d\n",
 361              RegistrationResult);
 362     return false;
 363   }
 364
 365   if (!internal_strcmp(flags()->xray_mode, "xray-profiling"))
 366     __xray_log_select_mode("xray_profiling");
 367   return true;
 368 }
 369
 370 } // namespace __xray
 371
 372 static auto UNUSED Unused = __xray::profilingDynamicInitializer();