counters.cc 10.2 KB
Newer Older
1
// Copyright 2012 the V8 project authors. All rights reserved.
2 3
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.
4

5
#include "src/counters.h"
6

7 8
#include <iomanip>

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 15
namespace v8 {
namespace internal {
16

17 18 19 20 21 22 23
StatsTable::StatsTable()
    : lookup_function_(NULL),
      create_histogram_function_(NULL),
      add_histogram_sample_function_(NULL) {}


int* StatsCounter::FindLocationInStatsTable() const {
24
  return isolate_->stats_table()->FindLocation(name_);
25 26
}

27

28 29
void Histogram::AddSample(int sample) {
  if (Enabled()) {
30
    isolate()->stats_table()->AddHistogramSample(histogram_, sample);
31 32 33 34
  }
}

void* Histogram::CreateHistogram() const {
35
  return isolate()->stats_table()->
36 37 38
      CreateHistogram(name_, min_, max_, num_buckets_);
}

39

40 41
// Start the timer.
void HistogramTimer::Start() {
42
  if (Enabled()) {
43
    timer_.Start();
44
  }
45
  Logger::CallEventLogger(isolate(), name(), Logger::START, true);
46 47
}

48

49 50
// Stop the timer and record the results.
void HistogramTimer::Stop() {
51
  if (Enabled()) {
yangguo's avatar
yangguo committed
52 53 54 55 56
    int64_t sample = resolution_ == MICROSECOND
                         ? timer_.Elapsed().InMicroseconds()
                         : timer_.Elapsed().InMilliseconds();
    // Compute the delta between start and stop, in microseconds.
    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 65 66 67 68
#define HR(name, caption, min, max, num_buckets) \
  name##_ = Histogram(#caption, min, max, num_buckets, isolate);
  HISTOGRAM_RANGE_LIST(HR)
#undef HR

yangguo's avatar
yangguo committed
69 70
#define HT(name, caption, max, res) \
  name##_ = HistogramTimer(#caption, 0, max, HistogramTimer::res, 50, isolate);
71 72 73
    HISTOGRAM_TIMER_LIST(HT)
#undef HT

74
#define AHT(name, caption) \
yangguo's avatar
yangguo committed
75
  name##_ = AggregatableHistogramTimer(#caption, 0, 10000000, 50, isolate);
76 77 78
    AGGREGATABLE_HISTOGRAM_TIMER_LIST(AHT)
#undef AHT

79 80 81 82 83
#define HP(name, caption) \
    name##_ = Histogram(#caption, 0, 101, 100, isolate);
    HISTOGRAM_PERCENTAGE_LIST(HP)
#undef HP

84 85 86 87 88 89 90

// Exponential histogram assigns bucket limits to points
// p[1], p[2], ... p[n] such that p[i+1] / p[i] = constant.
// The constant factor is equal to the n-th root of (high / low),
// where the n is the number of buckets, the low is the lower limit,
// the high is the upper limit.
// For n = 50, low = 1000, high = 500000: the factor = 1.13.
91 92
#define HM(name, caption) \
    name##_ = Histogram(#caption, 1000, 500000, 50, isolate);
93 94 95 96 97 98 99 100 101 102
  HISTOGRAM_LEGACY_MEMORY_LIST(HM)
#undef HM
// For n = 100, low = 4000, high = 2000000: the factor = 1.06.
#define HM(name, caption) \
  name##_ = Histogram(#caption, 4000, 2000000, 100, isolate);
  HISTOGRAM_MEMORY_LIST(HM)
#undef HM

#define HM(name, caption) \
  aggregated_##name##_ = AggregatedMemoryHistogram<Histogram>(&name##_);
103 104 105 106 107 108 109 110 111 112 113 114 115 116 117 118 119 120 121 122 123 124 125 126 127 128 129 130 131 132 133 134 135 136 137 138 139 140 141 142 143 144
    HISTOGRAM_MEMORY_LIST(HM)
#undef HM

#define SC(name, caption) \
    name##_ = StatsCounter(isolate, "c:" #caption);

    STATS_COUNTER_LIST_1(SC)
    STATS_COUNTER_LIST_2(SC)
#undef SC

#define SC(name) \
    count_of_##name##_ = StatsCounter(isolate, "c:" "V8.CountOf_" #name); \
    size_of_##name##_ = StatsCounter(isolate, "c:" "V8.SizeOf_" #name);
    INSTANCE_TYPE_LIST(SC)
#undef SC

#define SC(name) \
    count_of_CODE_TYPE_##name##_ = \
        StatsCounter(isolate, "c:" "V8.CountOf_CODE_TYPE-" #name); \
    size_of_CODE_TYPE_##name##_ = \
        StatsCounter(isolate, "c:" "V8.SizeOf_CODE_TYPE-" #name);
    CODE_KIND_LIST(SC)
#undef SC

#define SC(name) \
    count_of_FIXED_ARRAY_##name##_ = \
        StatsCounter(isolate, "c:" "V8.CountOf_FIXED_ARRAY-" #name); \
    size_of_FIXED_ARRAY_##name##_ = \
        StatsCounter(isolate, "c:" "V8.SizeOf_FIXED_ARRAY-" #name);
    FIXED_ARRAY_SUB_INSTANCE_TYPE_LIST(SC)
#undef SC

#define SC(name) \
    count_of_CODE_AGE_##name##_ = \
        StatsCounter(isolate, "c:" "V8.CountOf_CODE_AGE-" #name); \
    size_of_CODE_AGE_##name##_ = \
        StatsCounter(isolate, "c:" "V8.SizeOf_CODE_AGE-" #name);
    CODE_AGE_LIST_COMPLETE(SC)
#undef SC
}


145 146 147 148 149 150 151 152 153 154 155 156 157 158 159 160 161 162 163 164 165 166 167 168 169 170 171 172 173 174 175 176
void Counters::ResetCounters() {
#define SC(name, caption) name##_.Reset();
  STATS_COUNTER_LIST_1(SC)
  STATS_COUNTER_LIST_2(SC)
#undef SC

#define SC(name)              \
  count_of_##name##_.Reset(); \
  size_of_##name##_.Reset();
  INSTANCE_TYPE_LIST(SC)
#undef SC

#define SC(name)                        \
  count_of_CODE_TYPE_##name##_.Reset(); \
  size_of_CODE_TYPE_##name##_.Reset();
  CODE_KIND_LIST(SC)
#undef SC

#define SC(name)                          \
  count_of_FIXED_ARRAY_##name##_.Reset(); \
  size_of_FIXED_ARRAY_##name##_.Reset();
  FIXED_ARRAY_SUB_INSTANCE_TYPE_LIST(SC)
#undef SC

#define SC(name)                       \
  count_of_CODE_AGE_##name##_.Reset(); \
  size_of_CODE_AGE_##name##_.Reset();
  CODE_AGE_LIST_COMPLETE(SC)
#undef SC
}


177
void Counters::ResetHistograms() {
178 179 180 181
#define HR(name, caption, min, max, num_buckets) name##_.Reset();
  HISTOGRAM_RANGE_LIST(HR)
#undef HR

yangguo's avatar
yangguo committed
182
#define HT(name, caption, max, res) name##_.Reset();
183 184 185
    HISTOGRAM_TIMER_LIST(HT)
#undef HT

186 187 188 189
#define AHT(name, caption) name##_.Reset();
    AGGREGATABLE_HISTOGRAM_TIMER_LIST(AHT)
#undef AHT

190 191 192 193 194
#define HP(name, caption) name##_.Reset();
    HISTOGRAM_PERCENTAGE_LIST(HP)
#undef HP

#define HM(name, caption) name##_.Reset();
195
    HISTOGRAM_LEGACY_MEMORY_LIST(HM)
196 197 198
#undef HM
}

199 200 201
class RuntimeCallStatEntries {
 public:
  void Print(std::ostream& os) {
202 203
    if (total_call_count == 0) return;
    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 208 209
    for (Entry& entry : entries) {
      entry.SetTotal(total_time, total_call_count);
      entry.Print(os);
210
    }
211
    os << std::string(88, '-') << std::endl;
212
    Entry("Total", total_time, total_call_count).Print(os);
213 214
  }

215 216 217 218 219
  void Add(RuntimeCallCounter* counter) {
    if (counter->count == 0) return;
    entries.push_back(Entry(counter->name, counter->time, counter->count));
    total_time += counter->time;
    total_call_count += counter->count;
220 221 222 223 224 225 226
  }

 private:
  class Entry {
   public:
    Entry(const char* name, base::TimeDelta time, uint64_t count)
        : name_(name),
227
          time_(time.InMicroseconds()),
228 229 230 231 232 233 234 235 236 237 238 239
          count_(count),
          time_percent_(100),
          count_percent_(100) {}

    bool operator<(const Entry& other) const {
      if (time_ < other.time_) return true;
      if (time_ > other.time_) return false;
      return count_ < other.count_;
    }

    void Print(std::ostream& os) {
      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 244 245 246 247 248 249
      os << std::setw(6) << time_percent_ << "%";
      os << std::setw(10) << count_ << " ";
      os << std::setw(6) << count_percent_ << "%";
      os << std::endl;
    }

    void SetTotal(base::TimeDelta total_time, uint64_t total_count) {
250
      if (total_time.InMicroseconds() == 0) {
251 252
        time_percent_ = 0;
      } else {
253
        time_percent_ = 100.0 * time_ / total_time.InMicroseconds();
254
      }
255 256 257 258 259 260 261 262 263 264 265 266 267 268 269 270
      count_percent_ = 100.0 * count_ / total_count;
    }

   private:
    const char* name_;
    int64_t time_;
    uint64_t count_;
    double time_percent_;
    double count_percent_;
  };

  uint64_t total_call_count = 0;
  base::TimeDelta total_time;
  std::vector<Entry> entries;
};

271 272 273 274 275
void RuntimeCallCounter::Reset() {
  count = 0;
  time = base::TimeDelta();
}

276 277 278 279 280 281 282
// static
void RuntimeCallStats::Enter(Isolate* isolate, RuntimeCallTimer* timer,
                             CounterId counter_id) {
  RuntimeCallStats* stats = isolate->counters()->runtime_call_stats();
  RuntimeCallCounter* counter = &(stats->*counter_id);
  timer->Start(counter, stats->current_timer_);
  stats->current_timer_ = timer;
283 284
}

285 286 287
// static
void RuntimeCallStats::Leave(Isolate* isolate, RuntimeCallTimer* timer) {
  RuntimeCallStats* stats = isolate->counters()->runtime_call_stats();
288 289 290 291 292 293 294 295 296 297 298

  if (stats->current_timer_ == timer) {
    stats->current_timer_ = timer->Stop();
  } else {
    // Must be a Threading cctest. Walk the chain of Timers to find the
    // buried one that's leaving. We don't care about keeping nested timings
    // accurate, just avoid crashing by keeping the chain intact.
    RuntimeCallTimer* next = stats->current_timer_;
    while (next->parent_ != timer) next = next->parent_;
    next->parent_ = timer->Stop();
  }
299 300
}

301 302 303 304 305 306 307 308 309
// static
void RuntimeCallStats::CorrectCurrentCounterId(Isolate* isolate,
                                               CounterId counter_id) {
  RuntimeCallStats* stats = isolate->counters()->runtime_call_stats();
  DCHECK_NOT_NULL(stats->current_timer_);
  RuntimeCallCounter* counter = &(stats->*counter_id);
  stats->current_timer_->counter_ = counter;
}

310 311 312
void RuntimeCallStats::Print(std::ostream& os) {
  RuntimeCallStatEntries entries;

313 314 315 316
#define PRINT_COUNTER(name) entries.Add(&this->name);
  FOR_EACH_MANUAL_COUNTER(PRINT_COUNTER)
#undef PRINT_COUNTER

317
#define PRINT_COUNTER(name, nargs, ressize) entries.Add(&this->Runtime_##name);
318 319
  FOR_EACH_INTRINSIC(PRINT_COUNTER)
#undef PRINT_COUNTER
320

321
#define PRINT_COUNTER(name) entries.Add(&this->Builtin_##name);
322 323
  BUILTIN_LIST_C(PRINT_COUNTER)
#undef PRINT_COUNTER
324

325 326 327 328
#define PRINT_COUNTER(name) entries.Add(&this->API_##name);
  FOR_EACH_API_COUNTER(PRINT_COUNTER)
#undef PRINT_COUNTER

329 330 331 332
#define PRINT_COUNTER(name) entries.Add(&this->Handler_##name);
  FOR_EACH_HANDLER_COUNTER(PRINT_COUNTER)
#undef PRINT_COUNTER

333 334 335 336
  entries.Print(os);
}

void RuntimeCallStats::Reset() {
337
  if (!FLAG_runtime_call_stats) return;
338 339 340 341 342
#define RESET_COUNTER(name) this->name.Reset();
  FOR_EACH_MANUAL_COUNTER(RESET_COUNTER)
#undef RESET_COUNTER

#define RESET_COUNTER(name, nargs, result_size) this->Runtime_##name.Reset();
343 344
  FOR_EACH_INTRINSIC(RESET_COUNTER)
#undef RESET_COUNTER
345

346
#define RESET_COUNTER(name) this->Builtin_##name.Reset();
347 348
  BUILTIN_LIST_C(RESET_COUNTER)
#undef RESET_COUNTER
349 350 351 352 353 354 355 356

#define RESET_COUNTER(name) this->API_##name.Reset();
  FOR_EACH_API_COUNTER(RESET_COUNTER)
#undef RESET_COUNTER

#define RESET_COUNTER(name) this->Handler_##name.Reset();
  FOR_EACH_HANDLER_COUNTER(RESET_COUNTER)
#undef RESET_COUNTER
357 358
}

359 360
}  // namespace internal
}  // namespace v8