Home | History | Annotate | Download | only in src
      1 // Copyright 2012 the V8 project authors. All rights reserved.
      2 // Use of this source code is governed by a BSD-style license that can be
      3 // found in the LICENSE file.
      4 
      5 #include "src/counters.h"
      6 
      7 #include <iomanip>
      8 
      9 #include "src/base/platform/platform.h"
     10 #include "src/isolate.h"
     11 #include "src/log-inl.h"
     12 #include "src/log.h"
     13 
     14 namespace v8 {
     15 namespace internal {
     16 
     17 StatsTable::StatsTable()
     18     : lookup_function_(NULL),
     19       create_histogram_function_(NULL),
     20       add_histogram_sample_function_(NULL) {}
     21 
     22 
     23 int* StatsCounter::FindLocationInStatsTable() const {
     24   return isolate_->stats_table()->FindLocation(name_);
     25 }
     26 
     27 
     28 void Histogram::AddSample(int sample) {
     29   if (Enabled()) {
     30     isolate()->stats_table()->AddHistogramSample(histogram_, sample);
     31   }
     32 }
     33 
     34 void* Histogram::CreateHistogram() const {
     35   return isolate()->stats_table()->
     36       CreateHistogram(name_, min_, max_, num_buckets_);
     37 }
     38 
     39 
     40 // Start the timer.
     41 void HistogramTimer::Start() {
     42   if (Enabled()) {
     43     timer_.Start();
     44   }
     45   Logger::CallEventLogger(isolate(), name(), Logger::START, true);
     46 }
     47 
     48 
     49 // Stop the timer and record the results.
     50 void HistogramTimer::Stop() {
     51   if (Enabled()) {
     52     int64_t sample = resolution_ == MICROSECOND
     53                          ? timer_.Elapsed().InMicroseconds()
     54                          : timer_.Elapsed().InMilliseconds();
     55     // Compute the delta between start and stop, in microseconds.
     56     AddSample(static_cast<int>(sample));
     57     timer_.Stop();
     58   }
     59   Logger::CallEventLogger(isolate(), name(), Logger::END, true);
     60 }
     61 
     62 
     63 Counters::Counters(Isolate* isolate) {
     64 #define HR(name, caption, min, max, num_buckets) \
     65   name##_ = Histogram(#caption, min, max, num_buckets, isolate);
     66   HISTOGRAM_RANGE_LIST(HR)
     67 #undef HR
     68 
     69 #define HT(name, caption, max, res) \
     70   name##_ = HistogramTimer(#caption, 0, max, HistogramTimer::res, 50, isolate);
     71     HISTOGRAM_TIMER_LIST(HT)
     72 #undef HT
     73 
     74 #define AHT(name, caption) \
     75   name##_ = AggregatableHistogramTimer(#caption, 0, 10000000, 50, isolate);
     76     AGGREGATABLE_HISTOGRAM_TIMER_LIST(AHT)
     77 #undef AHT
     78 
     79 #define HP(name, caption) \
     80     name##_ = Histogram(#caption, 0, 101, 100, isolate);
     81     HISTOGRAM_PERCENTAGE_LIST(HP)
     82 #undef HP
     83 
     84 
     85 // Exponential histogram assigns bucket limits to points
     86 // p[1], p[2], ... p[n] such that p[i+1] / p[i] = constant.
     87 // The constant factor is equal to the n-th root of (high / low),
     88 // where the n is the number of buckets, the low is the lower limit,
     89 // the high is the upper limit.
     90 // For n = 50, low = 1000, high = 500000: the factor = 1.13.
     91 #define HM(name, caption) \
     92     name##_ = Histogram(#caption, 1000, 500000, 50, isolate);
     93   HISTOGRAM_LEGACY_MEMORY_LIST(HM)
     94 #undef HM
     95 // For n = 100, low = 4000, high = 2000000: the factor = 1.06.
     96 #define HM(name, caption) \
     97   name##_ = Histogram(#caption, 4000, 2000000, 100, isolate);
     98   HISTOGRAM_MEMORY_LIST(HM)
     99 #undef HM
    100 
    101 #define HM(name, caption) \
    102   aggregated_##name##_ = AggregatedMemoryHistogram<Histogram>(&name##_);
    103     HISTOGRAM_MEMORY_LIST(HM)
    104 #undef HM
    105 
    106 #define SC(name, caption) \
    107     name##_ = StatsCounter(isolate, "c:" #caption);
    108 
    109     STATS_COUNTER_LIST_1(SC)
    110     STATS_COUNTER_LIST_2(SC)
    111 #undef SC
    112 
    113 #define SC(name) \
    114     count_of_##name##_ = StatsCounter(isolate, "c:" "V8.CountOf_" #name); \
    115     size_of_##name##_ = StatsCounter(isolate, "c:" "V8.SizeOf_" #name);
    116     INSTANCE_TYPE_LIST(SC)
    117 #undef SC
    118 
    119 #define SC(name) \
    120     count_of_CODE_TYPE_##name##_ = \
    121         StatsCounter(isolate, "c:" "V8.CountOf_CODE_TYPE-" #name); \
    122     size_of_CODE_TYPE_##name##_ = \
    123         StatsCounter(isolate, "c:" "V8.SizeOf_CODE_TYPE-" #name);
    124     CODE_KIND_LIST(SC)
    125 #undef SC
    126 
    127 #define SC(name) \
    128     count_of_FIXED_ARRAY_##name##_ = \
    129         StatsCounter(isolate, "c:" "V8.CountOf_FIXED_ARRAY-" #name); \
    130     size_of_FIXED_ARRAY_##name##_ = \
    131         StatsCounter(isolate, "c:" "V8.SizeOf_FIXED_ARRAY-" #name);
    132     FIXED_ARRAY_SUB_INSTANCE_TYPE_LIST(SC)
    133 #undef SC
    134 
    135 #define SC(name) \
    136     count_of_CODE_AGE_##name##_ = \
    137         StatsCounter(isolate, "c:" "V8.CountOf_CODE_AGE-" #name); \
    138     size_of_CODE_AGE_##name##_ = \
    139         StatsCounter(isolate, "c:" "V8.SizeOf_CODE_AGE-" #name);
    140     CODE_AGE_LIST_COMPLETE(SC)
    141 #undef SC
    142 }
    143 
    144 
    145 void Counters::ResetCounters() {
    146 #define SC(name, caption) name##_.Reset();
    147   STATS_COUNTER_LIST_1(SC)
    148   STATS_COUNTER_LIST_2(SC)
    149 #undef SC
    150 
    151 #define SC(name)              \
    152   count_of_##name##_.Reset(); \
    153   size_of_##name##_.Reset();
    154   INSTANCE_TYPE_LIST(SC)
    155 #undef SC
    156 
    157 #define SC(name)                        \
    158   count_of_CODE_TYPE_##name##_.Reset(); \
    159   size_of_CODE_TYPE_##name##_.Reset();
    160   CODE_KIND_LIST(SC)
    161 #undef SC
    162 
    163 #define SC(name)                          \
    164   count_of_FIXED_ARRAY_##name##_.Reset(); \
    165   size_of_FIXED_ARRAY_##name##_.Reset();
    166   FIXED_ARRAY_SUB_INSTANCE_TYPE_LIST(SC)
    167 #undef SC
    168 
    169 #define SC(name)                       \
    170   count_of_CODE_AGE_##name##_.Reset(); \
    171   size_of_CODE_AGE_##name##_.Reset();
    172   CODE_AGE_LIST_COMPLETE(SC)
    173 #undef SC
    174 }
    175 
    176 
    177 void Counters::ResetHistograms() {
    178 #define HR(name, caption, min, max, num_buckets) name##_.Reset();
    179   HISTOGRAM_RANGE_LIST(HR)
    180 #undef HR
    181 
    182 #define HT(name, caption, max, res) name##_.Reset();
    183     HISTOGRAM_TIMER_LIST(HT)
    184 #undef HT
    185 
    186 #define AHT(name, caption) name##_.Reset();
    187     AGGREGATABLE_HISTOGRAM_TIMER_LIST(AHT)
    188 #undef AHT
    189 
    190 #define HP(name, caption) name##_.Reset();
    191     HISTOGRAM_PERCENTAGE_LIST(HP)
    192 #undef HP
    193 
    194 #define HM(name, caption) name##_.Reset();
    195     HISTOGRAM_LEGACY_MEMORY_LIST(HM)
    196 #undef HM
    197 }
    198 
    199 class RuntimeCallStatEntries {
    200  public:
    201   void Print(std::ostream& os) {
    202     if (total_call_count == 0) return;
    203     std::sort(entries.rbegin(), entries.rend());
    204     os << std::setw(50) << "Runtime Function/C++ Builtin" << std::setw(12)
    205        << "Time" << std::setw(18) << "Count" << std::endl
    206        << std::string(88, '=') << std::endl;
    207     for (Entry& entry : entries) {
    208       entry.SetTotal(total_time, total_call_count);
    209       entry.Print(os);
    210     }
    211     os << std::string(88, '-') << std::endl;
    212     Entry("Total", total_time, total_call_count).Print(os);
    213   }
    214 
    215   void Add(RuntimeCallCounter* counter) {
    216     if (counter->count == 0) return;
    217     entries.push_back(Entry(counter->name, counter->time, counter->count));
    218     total_time += counter->time;
    219     total_call_count += counter->count;
    220   }
    221 
    222  private:
    223   class Entry {
    224    public:
    225     Entry(const char* name, base::TimeDelta time, uint64_t count)
    226         : name_(name),
    227           time_(time.InMicroseconds()),
    228           count_(count),
    229           time_percent_(100),
    230           count_percent_(100) {}
    231 
    232     bool operator<(const Entry& other) const {
    233       if (time_ < other.time_) return true;
    234       if (time_ > other.time_) return false;
    235       return count_ < other.count_;
    236     }
    237 
    238     void Print(std::ostream& os) {
    239       os.precision(2);
    240       os << std::fixed << std::setprecision(2);
    241       os << std::setw(50) << name_;
    242       os << std::setw(10) << static_cast<double>(time_) / 1000 << "ms ";
    243       os << std::setw(6) << time_percent_ << "%";
    244       os << std::setw(10) << count_ << " ";
    245       os << std::setw(6) << count_percent_ << "%";
    246       os << std::endl;
    247     }
    248 
    249     void SetTotal(base::TimeDelta total_time, uint64_t total_count) {
    250       if (total_time.InMicroseconds() == 0) {
    251         time_percent_ = 0;
    252       } else {
    253         time_percent_ = 100.0 * time_ / total_time.InMicroseconds();
    254       }
    255       count_percent_ = 100.0 * count_ / total_count;
    256     }
    257 
    258    private:
    259     const char* name_;
    260     int64_t time_;
    261     uint64_t count_;
    262     double time_percent_;
    263     double count_percent_;
    264   };
    265 
    266   uint64_t total_call_count = 0;
    267   base::TimeDelta total_time;
    268   std::vector<Entry> entries;
    269 };
    270 
    271 void RuntimeCallCounter::Reset() {
    272   count = 0;
    273   time = base::TimeDelta();
    274 }
    275 
    276 // static
    277 void RuntimeCallStats::Enter(Isolate* isolate, RuntimeCallTimer* timer,
    278                              CounterId counter_id) {
    279   RuntimeCallStats* stats = isolate->counters()->runtime_call_stats();
    280   RuntimeCallCounter* counter = &(stats->*counter_id);
    281   timer->Start(counter, stats->current_timer_);
    282   stats->current_timer_ = timer;
    283 }
    284 
    285 // static
    286 void RuntimeCallStats::Leave(Isolate* isolate, RuntimeCallTimer* timer) {
    287   RuntimeCallStats* stats = isolate->counters()->runtime_call_stats();
    288 
    289   if (stats->current_timer_ == timer) {
    290     stats->current_timer_ = timer->Stop();
    291   } else {
    292     // Must be a Threading cctest. Walk the chain of Timers to find the
    293     // buried one that's leaving. We don't care about keeping nested timings
    294     // accurate, just avoid crashing by keeping the chain intact.
    295     RuntimeCallTimer* next = stats->current_timer_;
    296     while (next->parent_ != timer) next = next->parent_;
    297     next->parent_ = timer->Stop();
    298   }
    299 }
    300 
    301 // static
    302 void RuntimeCallStats::CorrectCurrentCounterId(Isolate* isolate,
    303                                                CounterId counter_id) {
    304   RuntimeCallStats* stats = isolate->counters()->runtime_call_stats();
    305   DCHECK_NOT_NULL(stats->current_timer_);
    306   RuntimeCallCounter* counter = &(stats->*counter_id);
    307   stats->current_timer_->counter_ = counter;
    308 }
    309 
    310 void RuntimeCallStats::Print(std::ostream& os) {
    311   RuntimeCallStatEntries entries;
    312 
    313 #define PRINT_COUNTER(name) entries.Add(&this->name);
    314   FOR_EACH_MANUAL_COUNTER(PRINT_COUNTER)
    315 #undef PRINT_COUNTER
    316 
    317 #define PRINT_COUNTER(name, nargs, ressize) entries.Add(&this->Runtime_##name);
    318   FOR_EACH_INTRINSIC(PRINT_COUNTER)
    319 #undef PRINT_COUNTER
    320 
    321 #define PRINT_COUNTER(name) entries.Add(&this->Builtin_##name);
    322   BUILTIN_LIST_C(PRINT_COUNTER)
    323 #undef PRINT_COUNTER
    324 
    325 #define PRINT_COUNTER(name) entries.Add(&this->API_##name);
    326   FOR_EACH_API_COUNTER(PRINT_COUNTER)
    327 #undef PRINT_COUNTER
    328 
    329 #define PRINT_COUNTER(name) entries.Add(&this->Handler_##name);
    330   FOR_EACH_HANDLER_COUNTER(PRINT_COUNTER)
    331 #undef PRINT_COUNTER
    332 
    333   entries.Print(os);
    334 }
    335 
    336 void RuntimeCallStats::Reset() {
    337   if (!FLAG_runtime_call_stats) return;
    338 #define RESET_COUNTER(name) this->name.Reset();
    339   FOR_EACH_MANUAL_COUNTER(RESET_COUNTER)
    340 #undef RESET_COUNTER
    341 
    342 #define RESET_COUNTER(name, nargs, result_size) this->Runtime_##name.Reset();
    343   FOR_EACH_INTRINSIC(RESET_COUNTER)
    344 #undef RESET_COUNTER
    345 
    346 #define RESET_COUNTER(name) this->Builtin_##name.Reset();
    347   BUILTIN_LIST_C(RESET_COUNTER)
    348 #undef RESET_COUNTER
    349 
    350 #define RESET_COUNTER(name) this->API_##name.Reset();
    351   FOR_EACH_API_COUNTER(RESET_COUNTER)
    352 #undef RESET_COUNTER
    353 
    354 #define RESET_COUNTER(name) this->Handler_##name.Reset();
    355   FOR_EACH_HANDLER_COUNTER(RESET_COUNTER)
    356 #undef RESET_COUNTER
    357 }
    358 
    359 }  // namespace internal
    360 }  // namespace v8
    361