hphp/runtime/vm/jit/timer.cpp

   1 /*
   2    +----------------------------------------------------------------------+
   3    | HipHop for PHP                                                       |
   4    +----------------------------------------------------------------------+
   5    | Copyright (c) 2010-2016 Facebook, Inc. (http://www.facebook.com)     |
   6    +----------------------------------------------------------------------+
   7    | This source file is subject to version 3.01 of the PHP license,      |
   8    | that is bundled with this package in the file LICENSE, and is        |
   9    | available through the world-wide-web at the following url:           |
  10    | http://www.php.net/license/3_01.txt                                  |
  11    | If you did not receive a copy of the PHP license and are unable to   |
  12    | obtain it through the world-wide-web, please send a note to          |
  13    | license@php.net so we can mail you a copy immediately.               |
  14    +----------------------------------------------------------------------+
  15 */
  16
  17 #include "hphp/runtime/vm/jit/timer.h"
  18
  19 #include <map>
  20 #include <algorithm>
  21 #include <array>
  22 #include <iterator>
  23
  24 #include <folly/Format.h>
  25
  26 #include "hphp/runtime/base/execution-context.h"
  27 #include "hphp/util/timer.h"
  28 #include "hphp/util/trace.h"
  29 #include "hphp/util/vdso.h"
  30
  31 TRACE_SET_MOD(jittime);
  32
  33 namespace HPHP { namespace jit {
  34
  35 namespace {
  36
  37 //////////////////////////////////////////////////////////////////////
  38
  39 __thread Timer::Counter s_counters[Timer::kNumTimers];
  40
  41 struct TimerName { const char* str; Timer::Name name; };
  42 const TimerName s_names[] = {
  43 # define TIMER_NAME(name) {#name, Timer::name},
  44   JIT_TIMERS
  45 # undef TIMER_NAME
  46 };
  47
  48 int64_t getCPUTimeNanos() {
  49   if (!RuntimeOption::EvalJitTimer) return -1;
  50
  51 #ifdef CLOCK_THREAD_CPUTIME_ID
  52   auto const ns = Vdso::ClockGetTimeNS(CLOCK_THREAD_CPUTIME_ID);
  53   if (ns != -1) return ns;
  54 #endif
  55
  56 #ifdef RUSAGE_THREAD
  57   return HPHP::Timer::GetRusageMicros(HPHP::Timer::TotalCPU,
  58                                       HPHP::Timer::Thread) * 1000;
  59 #else
  60   return -1;
  61 #endif
  62 }
  63
  64 //////////////////////////////////////////////////////////////////////
  65
  66 }
  67
  68 Timer::Timer(Name name)
  69   : m_name(name)
  70   , m_start(getCPUTimeNanos())
  71   , m_finished(false)
  72 {
  73 }
  74
  75 Timer::~Timer() {
  76   if (!RuntimeOption::EvalJitTimer || m_finished) return;
  77   stop();
  78 }
  79
  80 int64_t Timer::stop() {
  81   if (!RuntimeOption::EvalJitTimer) return 0;
  82
  83   assertx(!m_finished);
  84   auto const finish = getCPUTimeNanos();
  85   auto const elapsed = finish - m_start;
  86
  87   auto& counter = s_counters[m_name];
  88   counter.total += elapsed;
  89   ++counter.count;
  90   counter.max = std::max(counter.max, elapsed);
  91   m_finished = true;
  92   return elapsed;
  93 }
  94
  95 Timer::CounterVec Timer::Counters() {
  96   CounterVec ret;
  97   for (auto& pair : s_names) {
  98     ret.emplace_back(pair.str, s_counters[pair.name]);
  99   }
 100   return ret;
 101 }
 102
 103 Timer::Counter Timer::CounterValue(Timer::Name name) {
 104   return s_counters[name];
 105 }
 106
 107 void Timer::RequestInit() {
 108   memset(&s_counters, 0, sizeof(s_counters));
 109 }
 110
 111 void Timer::RequestExit() {
 112   Dump();
 113 }
 114
 115 void Timer::Dump() {
 116   if (!Trace::moduleEnabledRelease(Trace::jittime)) return;
 117   Trace::traceRelease("%s", Show().c_str());
 118 }
 119
 120 std::string Timer::Show() {
 121   auto const header = "{:<30} | {:>15} {:>15} {:>15} {:>15}\n";
 122   auto const row    = "{:<30} | {:>15} {:>13,}us {:>13,}ns {:>13,}ns\n";
 123
 124   std::array<TimerName,kNumTimers> names_copy;
 125   std::copy(s_names, s_names + kNumTimers, begin(names_copy));
 126
 127   auto totalSort = [] (const TimerName& a, const TimerName& b) {
 128     return s_counters[a.name].total > s_counters[b.name].total;
 129   };
 130   auto nameSort = [] (const TimerName& a, const TimerName& b) {
 131     return strcmp(a.str, b.str) < 0;
 132   };
 133   std::sort(
 134     begin(names_copy), end(names_copy),
 135     getenv("HHVM_JIT_TIMER_NAME_SORT") ? nameSort : totalSort
 136   );
 137
 138   std::string rows;
 139   for (auto const& pair : names_copy) {
 140     auto const& counter = s_counters[pair.name];
 141     if (counter.total == 0 && counter.count == 0) continue;
 142
 143     folly::format(
 144       &rows,
 145       row,
 146       pair.str,
 147       counter.count,
 148       counter.total / 1000,
 149       counter.mean(),
 150       counter.max
 151     );
 152   }
 153
 154   if (rows.empty()) return rows;
 155
 156   std::string ret;
 157   auto const url = g_context->getRequestUrl(75);
 158   folly::format(&ret, "\nJIT timers for {}\n", url);
 159   folly::format(&ret, header, "name", "count", "total", "average", "max");
 160   folly::format(&ret, "{:-^30}-+{:-^64}\n{}\n", "", "", rows);
 161   return ret;
 162 }
 163
 164 } }