5 #include "src/counters.h" 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" 19 StatsTable::StatsTable(Counters* counters)
20 : lookup_function_(nullptr),
21 create_histogram_function_(nullptr),
22 add_histogram_sample_function_(nullptr) {}
24 void StatsTable::SetCounterFunction(CounterLookupCallback f) {
28 int* StatsCounterBase::FindLocationInStatsTable()
const {
29 return counters_->FindLocation(name_);
32 StatsCounterThreadSafe::StatsCounterThreadSafe(Counters* counters,
34 : StatsCounterBase(counters, name) {}
36 void StatsCounterThreadSafe::Set(
int Value) {
38 base::MutexGuard Guard(&mutex_);
43 void StatsCounterThreadSafe::Increment() {
45 base::MutexGuard Guard(&mutex_);
50 void StatsCounterThreadSafe::Increment(
int value) {
52 base::MutexGuard Guard(&mutex_);
53 IncrementLoc(ptr_, value);
57 void StatsCounterThreadSafe::Decrement() {
59 base::MutexGuard Guard(&mutex_);
64 void StatsCounterThreadSafe::Decrement(
int value) {
66 base::MutexGuard Guard(&mutex_);
67 DecrementLoc(ptr_, value);
71 void Histogram::AddSample(
int sample) {
73 counters_->AddHistogramSample(histogram_, sample);
77 void* Histogram::CreateHistogram()
const {
78 return counters_->CreateHistogram(name_, min_, max_, num_buckets_);
81 void TimedHistogram::Start(base::ElapsedTimer* timer, Isolate* isolate) {
82 if (Enabled()) timer->Start();
83 if (isolate) Logger::CallEventLogger(isolate, name(), Logger::START,
true);
86 void TimedHistogram::Stop(base::ElapsedTimer* timer, Isolate* isolate) {
88 int64_t sample = resolution_ == HistogramTimerResolution::MICROSECOND
89 ? timer->Elapsed().InMicroseconds()
90 : timer->Elapsed().InMilliseconds();
92 AddSample(static_cast<int>(sample));
94 if (isolate !=
nullptr) {
95 Logger::CallEventLogger(isolate, name(), Logger::END,
true);
99 void TimedHistogram::RecordAbandon(base::ElapsedTimer* timer,
102 DCHECK(timer->IsStarted());
104 int64_t sample = resolution_ == HistogramTimerResolution::MICROSECOND
105 ? base::TimeDelta::Max().InMicroseconds()
106 : base::TimeDelta::Max().InMilliseconds();
107 AddSample(static_cast<int>(sample));
109 if (isolate !=
nullptr) {
110 Logger::CallEventLogger(isolate, name(), Logger::END,
true);
114 Counters::Counters(Isolate* isolate)
118 #define SC(name, caption) name##_(this,
"c:" #caption),
119 STATS_COUNTER_TS_LIST(SC)
122 runtime_call_stats_(),
123 worker_thread_runtime_call_stats_() {
124 static const struct {
125 Histogram Counters::*member;
131 #define HR(name, caption, min, max, num_buckets) \ 132 {&Counters::name##_, #caption, min, max, num_buckets}, 133 HISTOGRAM_RANGE_LIST(HR)
136 for (
const auto& histogram : kHistograms) {
137 this->*histogram.member =
138 Histogram(histogram.caption, histogram.min, histogram.max,
139 histogram.num_buckets,
this);
142 const int DefaultTimedHistogramNumBuckets = 50;
144 static const struct {
145 HistogramTimer Counters::*member;
148 HistogramTimerResolution res;
149 } kHistogramTimers[] = {
150 #define HT(name, caption, max, res) \ 151 {&Counters::name##_, #caption, max, HistogramTimerResolution::res}, 152 HISTOGRAM_TIMER_LIST(HT)
155 for (
const auto& timer : kHistogramTimers) {
156 this->*timer.member = HistogramTimer(timer.caption, 0, timer.max, timer.res,
157 DefaultTimedHistogramNumBuckets,
this);
160 static const struct {
161 TimedHistogram Counters::*member;
164 HistogramTimerResolution res;
165 } kTimedHistograms[] = {
166 #define HT(name, caption, max, res) \ 167 {&Counters::name##_, #caption, max, HistogramTimerResolution::res}, 168 TIMED_HISTOGRAM_LIST(HT)
171 for (
const auto& timer : kTimedHistograms) {
172 this->*timer.member = TimedHistogram(timer.caption, 0, timer.max, timer.res,
173 DefaultTimedHistogramNumBuckets,
this);
176 static const struct {
177 AggregatableHistogramTimer Counters::*member;
179 } kAggregatableHistogramTimers[] = {
180 #define AHT(name, caption) {&Counters::name##_, #caption}, 181 AGGREGATABLE_HISTOGRAM_TIMER_LIST(AHT)
184 for (
const auto& aht : kAggregatableHistogramTimers) {
185 this->*aht.member = AggregatableHistogramTimer(
186 aht.caption, 0, 10000000, DefaultTimedHistogramNumBuckets,
this);
189 static const struct {
190 Histogram Counters::*member;
192 } kHistogramPercentages[] = {
193 #define HP(name, caption) {&Counters::name##_, #caption}, 194 HISTOGRAM_PERCENTAGE_LIST(HP)
197 for (
const auto& percentage : kHistogramPercentages) {
198 this->*percentage.member = Histogram(percentage.caption, 0, 101, 100,
this);
207 static const struct {
208 Histogram Counters::*member;
210 } kLegacyMemoryHistograms[] = {
211 #define HM(name, caption) {&Counters::name##_, #caption}, 212 HISTOGRAM_LEGACY_MEMORY_LIST(HM)
215 for (
const auto& histogram : kLegacyMemoryHistograms) {
216 this->*histogram.member =
217 Histogram(histogram.caption, 1000, 500000, 50,
this);
221 static const struct {
222 StatsCounter Counters::*member;
224 } kStatsCounters[] = {
225 #define SC(name, caption) {&Counters::name##_, "c:" #caption}, 226 STATS_COUNTER_LIST_1(SC) STATS_COUNTER_LIST_2(SC)
229 {&Counters::count_of_##name##_, "c:" "V8.CountOf_" #name}, \ 230 {&Counters::size_of_##name##_, "c:" "V8.SizeOf_" #name}, 231 INSTANCE_TYPE_LIST(SC)
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}, 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)
249 for (
const auto& counter : kStatsCounters) {
250 this->*counter.member = StatsCounter(
this, counter.caption);
254 void Counters::ResetCounterFunction(CounterLookupCallback f) {
255 stats_table_.SetCounterFunction(f);
257 #define SC(name, caption) name##_.Reset(); 258 STATS_COUNTER_LIST_1(SC)
259 STATS_COUNTER_LIST_2(SC)
262 #define SC(name, caption) name##_.Reset(); 263 STATS_COUNTER_TS_LIST(SC)
267 count_of_##name##_.Reset(); \ 268 size_of_##name##_.Reset(); 269 INSTANCE_TYPE_LIST(SC)
273 count_of_CODE_TYPE_##name##_.Reset(); \ 274 size_of_CODE_TYPE_##name##_.Reset(); 279 count_of_FIXED_ARRAY_##name##_.Reset(); \ 280 size_of_FIXED_ARRAY_##name##_.Reset(); 281 FIXED_ARRAY_SUB_INSTANCE_TYPE_LIST(SC)
285 void Counters::ResetCreateHistogramFunction(CreateHistogramCallback f) {
286 stats_table_.SetCreateHistogramFunction(f);
288 #define HR(name, caption, min, max, num_buckets) name##_.Reset(); 289 HISTOGRAM_RANGE_LIST(HR)
292 #define HT(name, caption, max, res) name##_.Reset(); 293 HISTOGRAM_TIMER_LIST(HT)
296 #define HT(name, caption, max, res) name##_.Reset(); 297 TIMED_HISTOGRAM_LIST(HT)
300 #define AHT(name, caption) name##_.Reset(); 301 AGGREGATABLE_HISTOGRAM_TIMER_LIST(AHT)
304 #define HP(name, caption) name##_.Reset(); 305 HISTOGRAM_PERCENTAGE_LIST(HP)
308 #define HM(name, caption) name##_.Reset(); 309 HISTOGRAM_LEGACY_MEMORY_LIST(HM)
313 base::TimeTicks (*RuntimeCallTimer::Now)() =
314 &base::TimeTicks::HighResolutionNow;
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);
328 os << std::string(88,
'-') << std::endl;
329 Entry(
"Total", total_time, total_call_count).Print(os);
336 if (counter->count() == 0)
return;
338 Entry(counter->name(), counter->time(), counter->count()));
339 total_time += counter->time();
340 total_call_count += counter->count();
348 time_(time.InMicroseconds()),
351 count_percent_(100) {}
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_;
359 V8_NOINLINE
void Print(std::ostream& os) {
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_ <<
"%";
371 uint64_t total_count) {
372 if (total_time.InMicroseconds() == 0) {
375 time_percent_ = 100.0 * time_ / total_time.InMicroseconds();
377 count_percent_ = 100.0 * count_ / total_count;
384 double time_percent_;
385 double count_percent_;
388 uint64_t total_call_count = 0;
390 std::vector<Entry> entries;
393 void RuntimeCallCounter::Reset() {
399 value->BeginArray(name_);
400 value->AppendDouble(count_);
401 value->AppendDouble(time_);
405 void RuntimeCallCounter::Add(RuntimeCallCounter* other) {
406 count_ += other->count();
407 time_ += other->time().InMicroseconds();
410 void RuntimeCallTimer::Snapshot() {
411 base::TimeTicks now = Now();
415 RuntimeCallTimer* timer =
this;
416 while (timer !=
nullptr) {
417 timer->CommitTimeToCounter();
418 timer = timer->parent();
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 444 for (
int i = 0;
i < kNumberOfCounters;
i++) {
445 this->counters_[
i] = RuntimeCallCounter(kNames[
i]);
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);
459 void RuntimeCallStats::Leave(RuntimeCallTimer* timer) {
460 DCHECK(IsCalledOnTheSameThread());
461 RuntimeCallTimer* stack_top = current_timer();
462 if (stack_top ==
nullptr)
return;
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);
469 void RuntimeCallStats::Add(RuntimeCallStats* other) {
470 for (
int i = 0;
i < kNumberOfCounters;
i++) {
471 GetCounter(
i)->Add(other->GetCounter(
i));
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);
486 bool RuntimeCallStats::IsCalledOnTheSameThread() {
487 if (!thread_id_.Equals(ThreadId::Invalid()))
488 return thread_id_.Equals(ThreadId::Current());
489 thread_id_ = ThreadId::Current();
493 void RuntimeCallStats::Print() {
498 void RuntimeCallStats::Print(std::ostream& os) {
499 RuntimeCallStatEntries entries;
500 if (current_timer_.Value() !=
nullptr) {
501 current_timer_.Value()->Snapshot();
503 for (
int i = 0;
i < kNumberOfCounters;
i++) {
504 entries.Add(GetCounter(
i));
509 void RuntimeCallStats::Reset() {
510 if (V8_LIKELY(FLAG_runtime_stats == 0))
return;
516 while (current_timer_.Value()) {
517 current_timer_.SetValue(current_timer_.Value()->Stop());
520 for (
int i = 0;
i < kNumberOfCounters;
i++) {
521 GetCounter(
i)->Reset();
528 for (
int i = 0;
i < kNumberOfCounters;
i++) {
529 if (GetCounter(
i)->count() > 0) GetCounter(
i)->Dump(value);
534 WorkerThreadRuntimeCallStats::WorkerThreadRuntimeCallStats()
535 : tls_key_(base::Thread::CreateThreadLocalKey()) {}
537 WorkerThreadRuntimeCallStats::~WorkerThreadRuntimeCallStats() {
538 base::Thread::DeleteThreadLocalKey(tls_key_);
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();
547 base::MutexGuard lock(&mutex_);
548 tables_.push_back(std::move(new_table));
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();
562 WorkerThreadRuntimeCallStatsScope::WorkerThreadRuntimeCallStatsScope(
563 WorkerThreadRuntimeCallStats* worker_stats)
565 if (V8_LIKELY(!FLAG_runtime_stats))
return;
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_);
574 if (FLAG_runtime_stats &
575 v8::tracing::TracingCategoryObserver::ENABLED_BY_TRACING) {
580 WorkerThreadRuntimeCallStatsScope::~WorkerThreadRuntimeCallStatsScope() {
581 if (V8_LIKELY(table_ ==
nullptr))
return;
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));