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