Fix use of history timers in background threads.

src/counters.cc

 // Copyright 2012 the V8 project authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "src/counters.h"
 
 #include <iomanip>
 
 #include "src/base/platform/platform.h"
 #include "src/builtins/builtins-definitions.h"
@@ skipping 59 matching lines @@
 void Histogram::AddSample(int sample) {
   if (Enabled()) {
     counters_->AddHistogramSample(histogram_, sample);
   }
 }
 
 void* Histogram::CreateHistogram() const {
   return counters_->CreateHistogram(name_, min_, max_, num_buckets_);
 }
 
-
-// Start the timer.
-void HistogramTimer::Start() {
-  if (Enabled()) {
-    timer_.Start();
-  }
-  Logger::CallEventLogger(counters()->isolate(), name(), Logger::START, true);
+void TimedHistogram::Start(base::ElapsedTimer* timer, Isolate* isolate) {
+  if (Enabled()) timer->Start();
+  if (isolate) Logger::CallEventLogger(isolate, name(), Logger::START, true);
 }
 
+void TimedHistogram::Stop(base::ElapsedTimer* timer, Isolate* isolate) {
+  if (Enabled()) {

[Camillo Bruni, 2017/06/12 08:14:03]

Given that this might be slightly performance critical I'd suggest putting the
ENABLED / FLAG_log_internal_timer_events / isolate check TimedHistogramScope in
counters-inl.h and then call Stop/Start that does the actual work.

I've done the same thing fort the RuntimeCallTimerScope and the actual Counter.

WDYT? (we could also postpone this to a follow-up CL)

[kschimpf, 2017/06/12 16:47:04]

This was previously in HistogramTimer as non-inlined code, so how are we adding
more overhead? Is there proof that we should be paying the code size penalty to
get performance?

On a side note, I do agree that the HistogramTimer::Start()/Stop() should be
inlined (to not add two levels of call).

[Camillo Bruni, 2017/06/22 07:26:13]

SGTM, let's see how this behaves in general first.

+    // Compute the delta between start and stop, in microseconds.
+    int64_t sample = resolution_ == HistogramTimerResolution::MICROSECOND
+                         ? timer->Elapsed().InMicroseconds()
+                         : timer->Elapsed().InMilliseconds();
+    timer->Stop();
+    AddSample(static_cast<int>(sample));
+  }
+  if (isolate != nullptr)

[Camillo Bruni, 2017/06/12 08:14:03]

nit: style violation, please add braces.

[kschimpf, 2017/06/12 16:47:04]

Done.

+    Logger::CallEventLogger(isolate, name(), Logger::END, true);
+}
 
-// Stop the timer and record the results.
+void HistogramTimer::Start() {
+  TimedHistogram::Start(&timer_, counters()->isolate());
+}
+
 void HistogramTimer::Stop() {
-  if (Enabled()) {
-    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));
-    timer_.Stop();
-  }
-  Logger::CallEventLogger(counters()->isolate(), name(), Logger::END, true);
+  TimedHistogram::Stop(&timer_, counters()->isolate());
 }
 
 Counters::Counters(Isolate* isolate)
     : isolate_(isolate),
       stats_table_(this),
 // clang format off
 #define SC(name, caption) name##_(this, "c:" #caption),
       STATS_COUNTER_TS_LIST(SC)
 #undef SC
       // clang format on
@@ skipping 13 matching lines @@
   for (const auto& histogram : kHistograms) {
     this->*histogram.member =
         Histogram(histogram.caption, histogram.min, histogram.max,
                   histogram.num_buckets, this);
   }
 
   static const struct {
     HistogramTimer Counters::*member;
     const char* caption;
     int max;
-    HistogramTimer::Resolution res;
+    HistogramTimerResolution res;
   } kHistogramTimers[] = {
 #define HT(name, caption, max, res) \
-  {&Counters::name##_, #caption, max, HistogramTimer::res},
+  {&Counters::name##_, #caption, max, HistogramTimerResolution::res},
       HISTOGRAM_TIMER_LIST(HT)
 #undef HT
   };
   for (const auto& timer : kHistogramTimers) {
     this->*timer.member =
         HistogramTimer(timer.caption, 0, timer.max, timer.res, 50, this);
   }
 
   static const struct {
+    TimedHistogram Counters::*member;
+    const char* caption;
+    int max;
+    HistogramTimerResolution res;
+  } kTimedHistograms[] = {
+#define HT(name, caption, max, res) \
+  {&Counters::name##_, #caption, max, HistogramTimerResolution::res},
+      TIMED_HISTOGRAM_LIST(HT)
+#undef HT
+  };
+  for (const auto& timer : kTimedHistograms) {
+    this->*timer.member =
+        TimedHistogram(timer.caption, 0, timer.max, timer.res, 50, this);
+  }
+
+  static const struct {
     AggregatableHistogramTimer Counters::*member;
     const char* caption;
   } kAggregatableHistogramTimers[] = {
 #define AHT(name, caption) {&Counters::name##_, #caption},
       AGGREGATABLE_HISTOGRAM_TIMER_LIST(AHT)
 #undef AHT
   };
   for (const auto& aht : kAggregatableHistogramTimers) {
     this->*aht.member =
         AggregatableHistogramTimer(aht.caption, 0, 10000000, 50, this);
@@ skipping 130 matching lines @@
   stats_table_.SetCreateHistogramFunction(f);
 
 #define HR(name, caption, min, max, num_buckets) name##_.Reset();
   HISTOGRAM_RANGE_LIST(HR)
 #undef HR
 
 #define HT(name, caption, max, res) name##_.Reset();
     HISTOGRAM_TIMER_LIST(HT)
 #undef HT
 
+#define HT(name, caption, max, res) name##_.Reset();
+    TIMED_HISTOGRAM_LIST(HT)
+#undef HT
+
 #define AHT(name, caption) name##_.Reset();
     AGGREGATABLE_HISTOGRAM_TIMER_LIST(AHT)
 #undef AHT
 
 #define HP(name, caption) name##_.Reset();
     HISTOGRAM_PERCENTAGE_LIST(HP)
 #undef HP
 
 #define HM(name, caption) name##_.Reset();
     HISTOGRAM_LEGACY_MEMORY_LIST(HM)
@@ skipping 247 matching lines @@
        RuntimeCallStats::counters) {
     RuntimeCallCounter* counter = &(this->*counter_id);
     if (counter->count() > 0) counter->Dump(value);
   }
 
   in_use_ = false;
 }
 
 }  // namespace internal
 }  // namespace v8