V8 API Reference, 7.2.502.16 (for Deno 0.2.4)
counters.cc
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/builtins/builtins-definitions.h"
11 #include "src/counters-inl.h"
12 #include "src/isolate.h"
13 #include "src/log-inl.h"
14 #include "src/log.h"
15 
16 namespace v8 {
17 namespace internal {
18 
19 StatsTable::StatsTable(Counters* counters)
20  : lookup_function_(nullptr),
21  create_histogram_function_(nullptr),
22  add_histogram_sample_function_(nullptr) {}
23 
24 void StatsTable::SetCounterFunction(CounterLookupCallback f) {
25  lookup_function_ = f;
26 }
27 
28 int* StatsCounterBase::FindLocationInStatsTable() const {
29  return counters_->FindLocation(name_);
30 }
31 
32 StatsCounterThreadSafe::StatsCounterThreadSafe(Counters* counters,
33  const char* name)
34  : StatsCounterBase(counters, name) {}
35 
36 void StatsCounterThreadSafe::Set(int Value) {
37  if (ptr_) {
38  base::MutexGuard Guard(&mutex_);
39  SetLoc(ptr_, Value);
40  }
41 }
42 
43 void StatsCounterThreadSafe::Increment() {
44  if (ptr_) {
45  base::MutexGuard Guard(&mutex_);
46  IncrementLoc(ptr_);
47  }
48 }
49 
50 void StatsCounterThreadSafe::Increment(int value) {
51  if (ptr_) {
52  base::MutexGuard Guard(&mutex_);
53  IncrementLoc(ptr_, value);
54  }
55 }
56 
57 void StatsCounterThreadSafe::Decrement() {
58  if (ptr_) {
59  base::MutexGuard Guard(&mutex_);
60  DecrementLoc(ptr_);
61  }
62 }
63 
64 void StatsCounterThreadSafe::Decrement(int value) {
65  if (ptr_) {
66  base::MutexGuard Guard(&mutex_);
67  DecrementLoc(ptr_, value);
68  }
69 }
70 
71 void Histogram::AddSample(int sample) {
72  if (Enabled()) {
73  counters_->AddHistogramSample(histogram_, sample);
74  }
75 }
76 
77 void* Histogram::CreateHistogram() const {
78  return counters_->CreateHistogram(name_, min_, max_, num_buckets_);
79 }
80 
81 void TimedHistogram::Start(base::ElapsedTimer* timer, Isolate* isolate) {
82  if (Enabled()) timer->Start();
83  if (isolate) Logger::CallEventLogger(isolate, name(), Logger::START, true);
84 }
85 
86 void TimedHistogram::Stop(base::ElapsedTimer* timer, Isolate* isolate) {
87  if (Enabled()) {
88  int64_t sample = resolution_ == HistogramTimerResolution::MICROSECOND
89  ? timer->Elapsed().InMicroseconds()
90  : timer->Elapsed().InMilliseconds();
91  timer->Stop();
92  AddSample(static_cast<int>(sample));
93  }
94  if (isolate != nullptr) {
95  Logger::CallEventLogger(isolate, name(), Logger::END, true);
96  }
97 }
98 
99 void TimedHistogram::RecordAbandon(base::ElapsedTimer* timer,
100  Isolate* isolate) {
101  if (Enabled()) {
102  DCHECK(timer->IsStarted());
103  timer->Stop();
104  int64_t sample = resolution_ == HistogramTimerResolution::MICROSECOND
105  ? base::TimeDelta::Max().InMicroseconds()
106  : base::TimeDelta::Max().InMilliseconds();
107  AddSample(static_cast<int>(sample));
108  }
109  if (isolate != nullptr) {
110  Logger::CallEventLogger(isolate, name(), Logger::END, true);
111  }
112 }
113 
114 Counters::Counters(Isolate* isolate)
115  : isolate_(isolate),
116  stats_table_(this),
117 // clang format off
118 #define SC(name, caption) name##_(this, "c:" #caption),
119  STATS_COUNTER_TS_LIST(SC)
120 #undef SC
121  // clang format on
122  runtime_call_stats_(),
123  worker_thread_runtime_call_stats_() {
124  static const struct {
125  Histogram Counters::*member;
126  const char* caption;
127  int min;
128  int max;
129  int num_buckets;
130  } kHistograms[] = {
131 #define HR(name, caption, min, max, num_buckets) \
132  {&Counters::name##_, #caption, min, max, num_buckets},
133  HISTOGRAM_RANGE_LIST(HR)
134 #undef HR
135  };
136  for (const auto& histogram : kHistograms) {
137  this->*histogram.member =
138  Histogram(histogram.caption, histogram.min, histogram.max,
139  histogram.num_buckets, this);
140  }
141 
142  const int DefaultTimedHistogramNumBuckets = 50;
143 
144  static const struct {
145  HistogramTimer Counters::*member;
146  const char* caption;
147  int max;
148  HistogramTimerResolution res;
149  } kHistogramTimers[] = {
150 #define HT(name, caption, max, res) \
151  {&Counters::name##_, #caption, max, HistogramTimerResolution::res},
152  HISTOGRAM_TIMER_LIST(HT)
153 #undef HT
154  };
155  for (const auto& timer : kHistogramTimers) {
156  this->*timer.member = HistogramTimer(timer.caption, 0, timer.max, timer.res,
157  DefaultTimedHistogramNumBuckets, this);
158  }
159 
160  static const struct {
161  TimedHistogram Counters::*member;
162  const char* caption;
163  int max;
164  HistogramTimerResolution res;
165  } kTimedHistograms[] = {
166 #define HT(name, caption, max, res) \
167  {&Counters::name##_, #caption, max, HistogramTimerResolution::res},
168  TIMED_HISTOGRAM_LIST(HT)
169 #undef HT
170  };
171  for (const auto& timer : kTimedHistograms) {
172  this->*timer.member = TimedHistogram(timer.caption, 0, timer.max, timer.res,
173  DefaultTimedHistogramNumBuckets, this);
174  }
175 
176  static const struct {
177  AggregatableHistogramTimer Counters::*member;
178  const char* caption;
179  } kAggregatableHistogramTimers[] = {
180 #define AHT(name, caption) {&Counters::name##_, #caption},
181  AGGREGATABLE_HISTOGRAM_TIMER_LIST(AHT)
182 #undef AHT
183  };
184  for (const auto& aht : kAggregatableHistogramTimers) {
185  this->*aht.member = AggregatableHistogramTimer(
186  aht.caption, 0, 10000000, DefaultTimedHistogramNumBuckets, this);
187  }
188 
189  static const struct {
190  Histogram Counters::*member;
191  const char* caption;
192  } kHistogramPercentages[] = {
193 #define HP(name, caption) {&Counters::name##_, #caption},
194  HISTOGRAM_PERCENTAGE_LIST(HP)
195 #undef HP
196  };
197  for (const auto& percentage : kHistogramPercentages) {
198  this->*percentage.member = Histogram(percentage.caption, 0, 101, 100, this);
199  }
200 
201  // Exponential histogram assigns bucket limits to points
202  // p[1], p[2], ... p[n] such that p[i+1] / p[i] = constant.
203  // The constant factor is equal to the n-th root of (high / low),
204  // where the n is the number of buckets, the low is the lower limit,
205  // the high is the upper limit.
206  // For n = 50, low = 1000, high = 500000: the factor = 1.13.
207  static const struct {
208  Histogram Counters::*member;
209  const char* caption;
210  } kLegacyMemoryHistograms[] = {
211 #define HM(name, caption) {&Counters::name##_, #caption},
212  HISTOGRAM_LEGACY_MEMORY_LIST(HM)
213 #undef HM
214  };
215  for (const auto& histogram : kLegacyMemoryHistograms) {
216  this->*histogram.member =
217  Histogram(histogram.caption, 1000, 500000, 50, this);
218  }
219 
220  // clang-format off
221  static const struct {
222  StatsCounter Counters::*member;
223  const char* caption;
224  } kStatsCounters[] = {
225 #define SC(name, caption) {&Counters::name##_, "c:" #caption},
226  STATS_COUNTER_LIST_1(SC) STATS_COUNTER_LIST_2(SC)
227 #undef SC
228 #define SC(name) \
229  {&Counters::count_of_##name##_, "c:" "V8.CountOf_" #name}, \
230  {&Counters::size_of_##name##_, "c:" "V8.SizeOf_" #name},
231  INSTANCE_TYPE_LIST(SC)
232 #undef SC
233 #define SC(name) \
234  {&Counters::count_of_CODE_TYPE_##name##_, \
235  "c:" "V8.CountOf_CODE_TYPE-" #name}, \
236  {&Counters::size_of_CODE_TYPE_##name##_, \
237  "c:" "V8.SizeOf_CODE_TYPE-" #name},
238  CODE_KIND_LIST(SC)
239 #undef SC
240 #define SC(name) \
241  {&Counters::count_of_FIXED_ARRAY_##name##_, \
242  "c:" "V8.CountOf_FIXED_ARRAY-" #name}, \
243  {&Counters::size_of_FIXED_ARRAY_##name##_, \
244  "c:" "V8.SizeOf_FIXED_ARRAY-" #name},
245  FIXED_ARRAY_SUB_INSTANCE_TYPE_LIST(SC)
246 #undef SC
247  };
248  // clang-format on
249  for (const auto& counter : kStatsCounters) {
250  this->*counter.member = StatsCounter(this, counter.caption);
251  }
252 }
253 
254 void Counters::ResetCounterFunction(CounterLookupCallback f) {
255  stats_table_.SetCounterFunction(f);
256 
257 #define SC(name, caption) name##_.Reset();
258  STATS_COUNTER_LIST_1(SC)
259  STATS_COUNTER_LIST_2(SC)
260 #undef SC
261 
262 #define SC(name, caption) name##_.Reset();
263  STATS_COUNTER_TS_LIST(SC)
264 #undef SC
265 
266 #define SC(name) \
267  count_of_##name##_.Reset(); \
268  size_of_##name##_.Reset();
269  INSTANCE_TYPE_LIST(SC)
270 #undef SC
271 
272 #define SC(name) \
273  count_of_CODE_TYPE_##name##_.Reset(); \
274  size_of_CODE_TYPE_##name##_.Reset();
275  CODE_KIND_LIST(SC)
276 #undef SC
277 
278 #define SC(name) \
279  count_of_FIXED_ARRAY_##name##_.Reset(); \
280  size_of_FIXED_ARRAY_##name##_.Reset();
281  FIXED_ARRAY_SUB_INSTANCE_TYPE_LIST(SC)
282 #undef SC
283 }
284 
285 void Counters::ResetCreateHistogramFunction(CreateHistogramCallback f) {
286  stats_table_.SetCreateHistogramFunction(f);
287 
288 #define HR(name, caption, min, max, num_buckets) name##_.Reset();
289  HISTOGRAM_RANGE_LIST(HR)
290 #undef HR
291 
292 #define HT(name, caption, max, res) name##_.Reset();
293  HISTOGRAM_TIMER_LIST(HT)
294 #undef HT
295 
296 #define HT(name, caption, max, res) name##_.Reset();
297  TIMED_HISTOGRAM_LIST(HT)
298 #undef HT
299 
300 #define AHT(name, caption) name##_.Reset();
301  AGGREGATABLE_HISTOGRAM_TIMER_LIST(AHT)
302 #undef AHT
303 
304 #define HP(name, caption) name##_.Reset();
305  HISTOGRAM_PERCENTAGE_LIST(HP)
306 #undef HP
307 
308 #define HM(name, caption) name##_.Reset();
309  HISTOGRAM_LEGACY_MEMORY_LIST(HM)
310 #undef HM
311 }
312 
313 base::TimeTicks (*RuntimeCallTimer::Now)() =
314  &base::TimeTicks::HighResolutionNow;
315 
317  public:
318  void Print(std::ostream& os) {
319  if (total_call_count == 0) return;
320  std::sort(entries.rbegin(), entries.rend());
321  os << std::setw(50) << "Runtime Function/C++ Builtin" << std::setw(12)
322  << "Time" << std::setw(18) << "Count" << std::endl
323  << std::string(88, '=') << std::endl;
324  for (Entry& entry : entries) {
325  entry.SetTotal(total_time, total_call_count);
326  entry.Print(os);
327  }
328  os << std::string(88, '-') << std::endl;
329  Entry("Total", total_time, total_call_count).Print(os);
330  }
331 
332  // By default, the compiler will usually inline this, which results in a large
333  // binary size increase: std::vector::push_back expands to a large amount of
334  // instructions, and this function is invoked repeatedly by macros.
335  V8_NOINLINE void Add(RuntimeCallCounter* counter) {
336  if (counter->count() == 0) return;
337  entries.push_back(
338  Entry(counter->name(), counter->time(), counter->count()));
339  total_time += counter->time();
340  total_call_count += counter->count();
341  }
342 
343  private:
344  class Entry {
345  public:
346  Entry(const char* name, base::TimeDelta time, uint64_t count)
347  : name_(name),
348  time_(time.InMicroseconds()),
349  count_(count),
350  time_percent_(100),
351  count_percent_(100) {}
352 
353  bool operator<(const Entry& other) const {
354  if (time_ < other.time_) return true;
355  if (time_ > other.time_) return false;
356  return count_ < other.count_;
357  }
358 
359  V8_NOINLINE void Print(std::ostream& os) {
360  os.precision(2);
361  os << std::fixed << std::setprecision(2);
362  os << std::setw(50) << name_;
363  os << std::setw(10) << static_cast<double>(time_) / 1000 << "ms ";
364  os << std::setw(6) << time_percent_ << "%";
365  os << std::setw(10) << count_ << " ";
366  os << std::setw(6) << count_percent_ << "%";
367  os << std::endl;
368  }
369 
370  V8_NOINLINE void SetTotal(base::TimeDelta total_time,
371  uint64_t total_count) {
372  if (total_time.InMicroseconds() == 0) {
373  time_percent_ = 0;
374  } else {
375  time_percent_ = 100.0 * time_ / total_time.InMicroseconds();
376  }
377  count_percent_ = 100.0 * count_ / total_count;
378  }
379 
380  private:
381  const char* name_;
382  int64_t time_;
383  uint64_t count_;
384  double time_percent_;
385  double count_percent_;
386  };
387 
388  uint64_t total_call_count = 0;
389  base::TimeDelta total_time;
390  std::vector<Entry> entries;
391 };
392 
393 void RuntimeCallCounter::Reset() {
394  count_ = 0;
395  time_ = 0;
396 }
397 
398 void RuntimeCallCounter::Dump(v8::tracing::TracedValue* value) {
399  value->BeginArray(name_);
400  value->AppendDouble(count_);
401  value->AppendDouble(time_);
402  value->EndArray();
403 }
404 
405 void RuntimeCallCounter::Add(RuntimeCallCounter* other) {
406  count_ += other->count();
407  time_ += other->time().InMicroseconds();
408 }
409 
410 void RuntimeCallTimer::Snapshot() {
411  base::TimeTicks now = Now();
412  // Pause only / topmost timer in the timer stack.
413  Pause(now);
414  // Commit all the timer's elapsed time to the counters.
415  RuntimeCallTimer* timer = this;
416  while (timer != nullptr) {
417  timer->CommitTimeToCounter();
418  timer = timer->parent();
419  }
420  Resume(now);
421 }
422 
423 RuntimeCallStats::RuntimeCallStats() : in_use_(false) {
424  static const char* const kNames[] = {
425 #define CALL_BUILTIN_COUNTER(name) "GC_" #name,
426  FOR_EACH_GC_COUNTER(CALL_BUILTIN_COUNTER) //
427 #undef CALL_BUILTIN_COUNTER
428 #define CALL_RUNTIME_COUNTER(name) #name,
429  FOR_EACH_MANUAL_COUNTER(CALL_RUNTIME_COUNTER) //
430 #undef CALL_RUNTIME_COUNTER
431 #define CALL_RUNTIME_COUNTER(name, nargs, ressize) #name,
432  FOR_EACH_INTRINSIC(CALL_RUNTIME_COUNTER) //
433 #undef CALL_RUNTIME_COUNTER
434 #define CALL_BUILTIN_COUNTER(name) #name,
435  BUILTIN_LIST_C(CALL_BUILTIN_COUNTER) //
436 #undef CALL_BUILTIN_COUNTER
437 #define CALL_BUILTIN_COUNTER(name) "API_" #name,
438  FOR_EACH_API_COUNTER(CALL_BUILTIN_COUNTER) //
439 #undef CALL_BUILTIN_COUNTER
440 #define CALL_BUILTIN_COUNTER(name) #name,
441  FOR_EACH_HANDLER_COUNTER(CALL_BUILTIN_COUNTER) //
442 #undef CALL_BUILTIN_COUNTER
443  };
444  for (int i = 0; i < kNumberOfCounters; i++) {
445  this->counters_[i] = RuntimeCallCounter(kNames[i]);
446  }
447 }
448 
449 void RuntimeCallStats::Enter(RuntimeCallTimer* timer,
450  RuntimeCallCounterId counter_id) {
451  DCHECK(IsCalledOnTheSameThread());
452  RuntimeCallCounter* counter = GetCounter(counter_id);
453  DCHECK_NOT_NULL(counter->name());
454  timer->Start(counter, current_timer());
455  current_timer_.SetValue(timer);
456  current_counter_.SetValue(counter);
457 }
458 
459 void RuntimeCallStats::Leave(RuntimeCallTimer* timer) {
460  DCHECK(IsCalledOnTheSameThread());
461  RuntimeCallTimer* stack_top = current_timer();
462  if (stack_top == nullptr) return; // Missing timer is a result of Reset().
463  CHECK(stack_top == timer);
464  current_timer_.SetValue(timer->Stop());
465  RuntimeCallTimer* cur_timer = current_timer();
466  current_counter_.SetValue(cur_timer ? cur_timer->counter() : nullptr);
467 }
468 
469 void RuntimeCallStats::Add(RuntimeCallStats* other) {
470  for (int i = 0; i < kNumberOfCounters; i++) {
471  GetCounter(i)->Add(other->GetCounter(i));
472  }
473 }
474 
475 // static
476 void RuntimeCallStats::CorrectCurrentCounterId(
477  RuntimeCallCounterId counter_id) {
478  DCHECK(IsCalledOnTheSameThread());
479  RuntimeCallTimer* timer = current_timer();
480  if (timer == nullptr) return;
481  RuntimeCallCounter* counter = GetCounter(counter_id);
482  timer->set_counter(counter);
483  current_counter_.SetValue(counter);
484 }
485 
486 bool RuntimeCallStats::IsCalledOnTheSameThread() {
487  if (!thread_id_.Equals(ThreadId::Invalid()))
488  return thread_id_.Equals(ThreadId::Current());
489  thread_id_ = ThreadId::Current();
490  return true;
491 }
492 
493 void RuntimeCallStats::Print() {
494  StdoutStream os;
495  Print(os);
496 }
497 
498 void RuntimeCallStats::Print(std::ostream& os) {
499  RuntimeCallStatEntries entries;
500  if (current_timer_.Value() != nullptr) {
501  current_timer_.Value()->Snapshot();
502  }
503  for (int i = 0; i < kNumberOfCounters; i++) {
504  entries.Add(GetCounter(i));
505  }
506  entries.Print(os);
507 }
508 
509 void RuntimeCallStats::Reset() {
510  if (V8_LIKELY(FLAG_runtime_stats == 0)) return;
511 
512  // In tracing, we only what to trace the time spent on top level trace events,
513  // if runtime counter stack is not empty, we should clear the whole runtime
514  // counter stack, and then reset counters so that we can dump counters into
515  // top level trace events accurately.
516  while (current_timer_.Value()) {
517  current_timer_.SetValue(current_timer_.Value()->Stop());
518  }
519 
520  for (int i = 0; i < kNumberOfCounters; i++) {
521  GetCounter(i)->Reset();
522  }
523 
524  in_use_ = true;
525 }
526 
527 void RuntimeCallStats::Dump(v8::tracing::TracedValue* value) {
528  for (int i = 0; i < kNumberOfCounters; i++) {
529  if (GetCounter(i)->count() > 0) GetCounter(i)->Dump(value);
530  }
531  in_use_ = false;
532 }
533 
534 WorkerThreadRuntimeCallStats::WorkerThreadRuntimeCallStats()
535  : tls_key_(base::Thread::CreateThreadLocalKey()) {}
536 
537 WorkerThreadRuntimeCallStats::~WorkerThreadRuntimeCallStats() {
538  base::Thread::DeleteThreadLocalKey(tls_key_);
539 }
540 
541 RuntimeCallStats* WorkerThreadRuntimeCallStats::NewTable() {
542  DCHECK(FLAG_runtime_stats);
543  std::unique_ptr<RuntimeCallStats> new_table =
544  base::make_unique<RuntimeCallStats>();
545  RuntimeCallStats* result = new_table.get();
546 
547  base::MutexGuard lock(&mutex_);
548  tables_.push_back(std::move(new_table));
549  return result;
550 }
551 
552 void WorkerThreadRuntimeCallStats::AddToMainTable(
553  RuntimeCallStats* main_call_stats) {
554  base::MutexGuard lock(&mutex_);
555  for (auto& worker_stats : tables_) {
556  DCHECK_NE(main_call_stats, worker_stats.get());
557  main_call_stats->Add(worker_stats.get());
558  worker_stats->Reset();
559  }
560 }
561 
562 WorkerThreadRuntimeCallStatsScope::WorkerThreadRuntimeCallStatsScope(
563  WorkerThreadRuntimeCallStats* worker_stats)
564  : table_(nullptr) {
565  if (V8_LIKELY(!FLAG_runtime_stats)) return;
566 
567  table_ = reinterpret_cast<RuntimeCallStats*>(
568  base::Thread::GetThreadLocal(worker_stats->GetKey()));
569  if (table_ == nullptr) {
570  table_ = worker_stats->NewTable();
571  base::Thread::SetThreadLocal(worker_stats->GetKey(), table_);
572  }
573 
574  if (FLAG_runtime_stats &
575  v8::tracing::TracingCategoryObserver::ENABLED_BY_TRACING) {
576  table_->Reset();
577  }
578 }
579 
580 WorkerThreadRuntimeCallStatsScope::~WorkerThreadRuntimeCallStatsScope() {
581  if (V8_LIKELY(table_ == nullptr)) return;
582 
583  if ((FLAG_runtime_stats &
584  v8::tracing::TracingCategoryObserver::ENABLED_BY_TRACING)) {
585  auto value = v8::tracing::TracedValue::Create();
586  table_->Dump(value.get());
587  TRACE_EVENT_INSTANT1(TRACE_DISABLED_BY_DEFAULT("v8.runtime_stats"),
588  "V8.RuntimeStats", TRACE_EVENT_SCOPE_THREAD,
589  "runtime-call-stats", std::move(value));
590  }
591 }
592 
593 } // namespace internal
594 } // namespace v8
Definition: libplatform.h:13