lldb/source/Core/Timer.cpp

//===-- Timer.cpp -----------------------------------------------*- C++ -*-===//
//
//                     The LLVM Compiler Infrastructure
//
// This file is distributed under the University of Illinois Open Source
// License. See LICENSE.TXT for details.
//
//===----------------------------------------------------------------------===//
#include "lldb/Core/Timer.h"

#include <algorithm>
#include <map>
#include <mutex>
#include <vector>

#include "lldb/Core/Stream.h"
#include "lldb/Host/Host.h"

#include <stdio.h>

using namespace lldb_private;

#define TIMER_INDENT_AMOUNT 2

namespace {
typedef std::map<const char *, uint64_t> TimerCategoryMap;

struct TimerStack {
  TimerStack() : m_depth(0) {}

  uint32_t m_depth;
  std::vector<Timer *> m_stack;
};
} // end of anonymous namespace

std::atomic<bool> Timer::g_quiet(true);
std::atomic<unsigned> Timer::g_display_depth(0);
static std::mutex &GetFileMutex() {
  static std::mutex *g_file_mutex_ptr = nullptr;
  static std::once_flag g_once_flag;
  std::call_once(g_once_flag, []() {
    // leaked on purpose to ensure this mutex works after main thread has run
    // global C++ destructor chain
    g_file_mutex_ptr = new std::mutex();
  });
  return *g_file_mutex_ptr;
}

static std::mutex &GetCategoryMutex() {
  static std::mutex g_category_mutex;
  return g_category_mutex;
}

static TimerCategoryMap &GetCategoryMap() {
  static TimerCategoryMap g_category_map;
  return g_category_map;
}

static void ThreadSpecificCleanup(void *p) {
  delete static_cast<TimerStack *>(p);
}

static TimerStack *GetTimerStackForCurrentThread() {
  static lldb::thread_key_t g_key =
      Host::ThreadLocalStorageCreate(ThreadSpecificCleanup);

  void *timer_stack = Host::ThreadLocalStorageGet(g_key);
  if (timer_stack == NULL) {
    Host::ThreadLocalStorageSet(g_key, new TimerStack);
    timer_stack = Host::ThreadLocalStorageGet(g_key);
  }
  return (TimerStack *)timer_stack;
}

void Timer::SetQuiet(bool value) { g_quiet = value; }

Timer::Timer(const char *category, const char *format, ...)
    : m_category(category), m_total_start(), m_timer_start(), m_total_ticks(0),
      m_timer_ticks(0) {
  TimerStack *stack = GetTimerStackForCurrentThread();
  if (!stack)
    return;

  if (stack->m_depth++ < g_display_depth) {
    if (g_quiet == false) {
      std::lock_guard<std::mutex> lock(GetFileMutex());

      // Indent
      ::fprintf(stdout, "%*s", stack->m_depth * TIMER_INDENT_AMOUNT, "");
      // Print formatted string
      va_list args;
      va_start(args, format);
      ::vfprintf(stdout, format, args);
      va_end(args);

      // Newline
      ::fprintf(stdout, "\n");
    }
    TimeValue start_time(TimeValue::Now());
    m_total_start = start_time;
    m_timer_start = start_time;

    if (!stack->m_stack.empty())
      stack->m_stack.back()->ChildStarted(start_time);
    stack->m_stack.push_back(this);
  }
}

Timer::~Timer() {
  TimerStack *stack = GetTimerStackForCurrentThread();
  if (!stack)
    return;

  if (m_total_start.IsValid()) {
    TimeValue stop_time = TimeValue::Now();
    if (m_total_start.IsValid()) {
      m_total_ticks += (stop_time - m_total_start);
      m_total_start.Clear();
    }
    if (m_timer_start.IsValid()) {
      m_timer_ticks += (stop_time - m_timer_start);
      m_timer_start.Clear();
    }

    assert(stack->m_stack.back() == this);
    stack->m_stack.pop_back();
    if (stack->m_stack.empty() == false)
      stack->m_stack.back()->ChildStopped(stop_time);

    const uint64_t total_nsec_uint = GetTotalElapsedNanoSeconds();
    const uint64_t timer_nsec_uint = GetTimerElapsedNanoSeconds();
    const double total_nsec = total_nsec_uint;
    const double timer_nsec = timer_nsec_uint;

    if (g_quiet == false) {
      std::lock_guard<std::mutex> lock(GetFileMutex());
      ::fprintf(stdout, "%*s%.9f sec (%.9f sec)\n",
                (stack->m_depth - 1) * TIMER_INDENT_AMOUNT, "",
                total_nsec / 1000000000.0, timer_nsec / 1000000000.0);
    }

    // Keep total results for each category so we can dump results.
    std::lock_guard<std::mutex> guard(GetCategoryMutex());
    TimerCategoryMap &category_map = GetCategoryMap();
    category_map[m_category] += timer_nsec_uint;
  }
  if (stack->m_depth > 0)
    --stack->m_depth;
}

uint64_t Timer::GetTotalElapsedNanoSeconds() {
  uint64_t total_ticks = m_total_ticks;

  // If we are currently running, we need to add the current
  // elapsed time of the running timer...
  if (m_total_start.IsValid())
    total_ticks += (TimeValue::Now() - m_total_start);

  return total_ticks;
}

uint64_t Timer::GetTimerElapsedNanoSeconds() {
  uint64_t timer_ticks = m_timer_ticks;

  // If we are currently running, we need to add the current
  // elapsed time of the running timer...
  if (m_timer_start.IsValid())
    timer_ticks += (TimeValue::Now() - m_timer_start);

  return timer_ticks;
}

void Timer::ChildStarted(const TimeValue &start_time) {
  if (m_timer_start.IsValid()) {
    m_timer_ticks += (start_time - m_timer_start);
    m_timer_start.Clear();
  }
}

void Timer::ChildStopped(const TimeValue &stop_time) {
  if (!m_timer_start.IsValid())
    m_timer_start = stop_time;
}

void Timer::SetDisplayDepth(uint32_t depth) { g_display_depth = depth; }

/* binary function predicate:
 * - returns whether a person is less than another person
 */
static bool
CategoryMapIteratorSortCriterion(const TimerCategoryMap::const_iterator &lhs,
                                 const TimerCategoryMap::const_iterator &rhs) {
  return lhs->second > rhs->second;
}

void Timer::ResetCategoryTimes() {
  std::lock_guard<std::mutex> guard(GetCategoryMutex());
  TimerCategoryMap &category_map = GetCategoryMap();
  category_map.clear();
}

void Timer::DumpCategoryTimes(Stream *s) {
  std::lock_guard<std::mutex> guard(GetCategoryMutex());
  TimerCategoryMap &category_map = GetCategoryMap();
  std::vector<TimerCategoryMap::const_iterator> sorted_iterators;
  TimerCategoryMap::const_iterator pos, end = category_map.end();
  for (pos = category_map.begin(); pos != end; ++pos) {
    sorted_iterators.push_back(pos);
  }
  std::sort(sorted_iterators.begin(), sorted_iterators.end(),
            CategoryMapIteratorSortCriterion);

  const size_t count = sorted_iterators.size();
  for (size_t i = 0; i < count; ++i) {
    const double timer_nsec = sorted_iterators[i]->second;
    s->Printf("%.9f sec for %s\n", timer_nsec / 1000000000.0,
              sorted_iterators[i]->first);
  }
}