Add TaskScheduler.NumTasksBetweenWaits.[pool] histogram.

base/task_scheduler/scheduler_worker_pool_impl.cc

 // Copyright 2016 The Chromium 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 "base/task_scheduler/scheduler_worker_pool_impl.h"
 
 #include <stddef.h>
 
 #include <algorithm>
 #include <utility>
@@ skipping 16 matching lines @@
 #include "base/time/time.h"
 
 namespace base {
 namespace internal {
 
 namespace {
 
 constexpr char kPoolNameSuffix[] = "Pool";
 constexpr char kDetachDurationHistogramPrefix[] =
     "TaskScheduler.DetachDuration.";
+constexpr char kNumTasksBetweenWaitsHistogramPrefix[] =
+    "TaskScheduler.NumTasksBetweenWaits.";
 constexpr char kTaskLatencyHistogramPrefix[] = "TaskScheduler.TaskLatency.";
 
 // SchedulerWorker that owns the current thread, if any.
 LazyInstance<ThreadLocalPointer<const SchedulerWorker>>::Leaky
     tls_current_worker = LAZY_INSTANCE_INITIALIZER;
 
 // SchedulerWorkerPool that owns the current thread, if any.
 LazyInstance<ThreadLocalPointer<const SchedulerWorkerPool>>::Leaky
     tls_current_worker_pool = LAZY_INSTANCE_INITIALIZER;
 
@@ skipping 212 matching lines @@
   // Single-threaded PriorityQueue for the worker.
   PriorityQueue single_threaded_priority_queue_;
 
   // True if the last Sequence returned by GetWork() was extracted from
   // |single_threaded_priority_queue_|.
   bool last_sequence_is_single_threaded_ = false;
 
   // Time when GetWork() first returned nullptr.
   TimeTicks idle_start_time_;
 
+  // Indicates whether the last call to GetWork() returned nullptr.
+  bool last_get_work_returned_nullptr_ = true;
+
+  // Indicates whether the SchedulerWorker was detached since the last call to
+  // GetWork().
+  bool did_detach_since_last_get_work_ = false;
+
+  // Number of tasks executed since the last time the
+  // TaskScheduler.NumTasksBetweenWaits histogram was recorded.
+  size_t num_tasks_since_last_wait_ = 0;
+
   subtle::Atomic32 num_single_threaded_runners_ = 0;
 
   const int index_;
 
   DISALLOW_COPY_AND_ASSIGN(SchedulerWorkerDelegateImpl);
 };
 
 SchedulerWorkerPoolImpl::~SchedulerWorkerPoolImpl() {
   // SchedulerWorkerPool should never be deleted in production unless its
   // initialization failed.
@@ skipping 184 matching lines @@
 void SchedulerWorkerPoolImpl::SchedulerWorkerDelegateImpl::OnMainEntry(
     SchedulerWorker* worker,
     const TimeDelta& detach_duration) {
 #if DCHECK_IS_ON()
   // Wait for |outer_->workers_created_| to avoid traversing
   // |outer_->workers_| while it is being filled by Initialize().
   outer_->workers_created_.Wait();
   DCHECK(ContainsWorker(outer_->workers_, worker));
 #endif
 
-  if (!detach_duration.is_max())
+  DCHECK_EQ(num_tasks_since_last_wait_, 0U);
+
+  if (!detach_duration.is_max()) {
     outer_->detach_duration_histogram_->AddTime(detach_duration);
+    did_detach_since_last_get_work_ = true;
+  }
 
   PlatformThread::SetName(
       StringPrintf("TaskScheduler%sWorker%d", outer_->name_.c_str(), index_));
 
   DCHECK(!tls_current_worker.Get().Get());
   DCHECK(!tls_current_worker_pool.Get().Get());
   tls_current_worker.Get().Set(worker);
   tls_current_worker_pool.Get().Set(outer_);
 
-  // New threads haven't run GetWork() yet, so reset the idle_start_time_.
+  // New threads haven't run GetWork() yet, so reset the |idle_start_time_|.
   idle_start_time_ = TimeTicks();
 
   ThreadRestrictions::SetIOAllowed(
       outer_->io_restriction_ ==
           SchedulerWorkerPoolParams::IORestriction::ALLOWED);
 }
 
 scoped_refptr<Sequence>
 SchedulerWorkerPoolImpl::SchedulerWorkerDelegateImpl::GetWork(
     SchedulerWorker* worker) {
   DCHECK(ContainsWorker(outer_->workers_, worker));
 
+  // Record the TaskScheduler.NumTasksBetweenWaits histogram if the
+  // SchedulerWorker waited on its WaitableEvent since the last GetWork().
+  //
+  // Note: When GetWork() returns nullptr for the first time after returning a
+  // Sequence, SchedulerWorker waits on its WaitableEvent. When the wait stops
+  // (either because WakeUp() was called or because the sleep timeout expired),
+  // GetWork() is called and the histogram is recorded. If GetWork() returns
+  // nullptr again, the SchedulerWorker may detach. If a detach happens,
+  // |did_detach_since_last_get_work_| is set to true and the next call to

[robliao, 2016/09/23 00:55:30]

I would say here that did_detach_since_last_get_work_ will be set to true after
a thread has detached and the thread is woken up again in OnMainEntry.

[fdoray, 2016/09/23 19:30:02]

Done.

+  // GetWork() won't record the histogram (which is correct since the
+  // SchedulerWorker didn't wait on its WaitableEvent since the last time the
+  // histogram was recorded).
+  if (last_get_work_returned_nullptr_ && !did_detach_since_last_get_work_) {
+    outer_->num_tasks_between_waits_histogram_->Add(num_tasks_since_last_wait_);
+    num_tasks_since_last_wait_ = 0;
+  }
+  did_detach_since_last_get_work_ = false;
+
   scoped_refptr<Sequence> sequence;
   {
     std::unique_ptr<PriorityQueue::Transaction> shared_transaction(
         outer_->shared_priority_queue_.BeginTransaction());
     std::unique_ptr<PriorityQueue::Transaction> single_threaded_transaction(
         single_threaded_priority_queue_.BeginTransaction());
 
     if (shared_transaction->IsEmpty() &&
         single_threaded_transaction->IsEmpty()) {
       single_threaded_transaction.reset();
 
       // |shared_transaction| is kept alive while |worker| is added to
       // |idle_workers_stack_| to avoid this race:
       // 1. This thread creates a Transaction, finds |shared_priority_queue_|
       //    empty and ends the Transaction.
       // 2. Other thread creates a Transaction, inserts a Sequence into
       //    |shared_priority_queue_| and ends the Transaction. This can't happen
       //    if the Transaction of step 1 is still active because because there
       //    can only be one active Transaction per PriorityQueue at a time.
       // 3. Other thread calls WakeUpOneWorker(). No thread is woken up because
       //    |idle_workers_stack_| is empty.
       // 4. This thread adds itself to |idle_workers_stack_| and goes to sleep.
       //    No thread runs the Sequence inserted in step 2.
       outer_->AddToIdleWorkersStack(worker);
       if (idle_start_time_.is_null())
         idle_start_time_ = TimeTicks::Now();
+      last_get_work_returned_nullptr_ = true;
       return nullptr;
     }
 
     // True if both PriorityQueues have Sequences and the Sequence at the top of
     // the shared PriorityQueue is more important.
     const bool shared_sequence_is_more_important =
         !shared_transaction->IsEmpty() &&
         !single_threaded_transaction->IsEmpty() &&
         shared_transaction->PeekSortKey() >
             single_threaded_transaction->PeekSortKey();
 
     if (single_threaded_transaction->IsEmpty() ||
         shared_sequence_is_more_important) {
       sequence = shared_transaction->PopSequence();
       last_sequence_is_single_threaded_ = false;
     } else {
       DCHECK(!single_threaded_transaction->IsEmpty());
       sequence = single_threaded_transaction->PopSequence();
       last_sequence_is_single_threaded_ = true;
     }
   }
   DCHECK(sequence);
 
   idle_start_time_ = TimeTicks();
+  outer_->RemoveFromIdleWorkersStack(worker);

[robliao, 2016/09/23 00:55:30]

Nit: The ordering here isn't sensitive, right? Let's group the local state
update together and do the removal last (or vice versa, as long as its grouped).

idle_start_time_ = ...
last_get_work_returned_nullptr_ = ...

[fdoray, 2016/09/23 19:30:02]

Local state update is now grouped together, and the order is consistent with the
"return nullptr" above.

+  last_get_work_returned_nullptr_ = false;
 
-  outer_->RemoveFromIdleWorkersStack(worker);
   return sequence;
 }
 
 void SchedulerWorkerPoolImpl::SchedulerWorkerDelegateImpl::DidRunTask(
     const Task* task,
     const TimeDelta& task_latency) {
+  ++num_tasks_since_last_wait_;
+
   const int priority_index = static_cast<int>(task->traits.priority());
 
   // As explained in the header file, histograms are allocated on demand. It
   // doesn't matter if an element of |task_latency_histograms_| is set multiple
   // times since GetTaskLatencyHistogram() is idempotent. As explained in the
   // comment at the top of histogram_macros.h, barriers are required.
   HistogramBase* task_latency_histogram = reinterpret_cast<HistogramBase*>(
       subtle::Acquire_Load(&outer_->task_latency_histograms_[priority_index]));
   if (!task_latency_histogram) {
     task_latency_histogram =
@@ skipping 52 matching lines @@
       suggested_reclaim_time_(suggested_reclaim_time),
       idle_workers_stack_lock_(shared_priority_queue_.container_lock()),
       idle_workers_stack_cv_for_testing_(
           idle_workers_stack_lock_.CreateConditionVariable()),
       join_for_testing_returned_(WaitableEvent::ResetPolicy::MANUAL,
                                  WaitableEvent::InitialState::NOT_SIGNALED),
 #if DCHECK_IS_ON()
       workers_created_(WaitableEvent::ResetPolicy::MANUAL,
                        WaitableEvent::InitialState::NOT_SIGNALED),
 #endif
+      // Mimics the UMA_HISTOGRAM_LONG_TIMES macro.
       detach_duration_histogram_(Histogram::FactoryTimeGet(
           kDetachDurationHistogramPrefix + name_ + kPoolNameSuffix,
           TimeDelta::FromMilliseconds(1),
           TimeDelta::FromHours(1),
           50,
           HistogramBase::kUmaTargetedHistogramFlag)),
+      // Mimics the UMA_HISTOGRAM_COUNTS_10000 macro.

[robliao, 2016/09/23 00:55:30]

Worth mentioning why we chose the 10000 macro to count number of tasks executed
between waits.

[fdoray, 2016/09/23 19:30:02]

Done.

+      num_tasks_between_waits_histogram_(Histogram::FactoryGet(
+          kNumTasksBetweenWaitsHistogramPrefix + name_ + kPoolNameSuffix,
+          1,
+          10000,
+          50,
+          HistogramBase::kUmaTargetedHistogramFlag)),
       task_tracker_(task_tracker),
       delayed_task_manager_(delayed_task_manager) {
   DCHECK(task_tracker_);
   DCHECK(delayed_task_manager_);
 }
 
 bool SchedulerWorkerPoolImpl::Initialize(
     ThreadPriority priority_hint,
     size_t max_threads,
     const ReEnqueueSequenceCallback& re_enqueue_sequence_callback) {
@@ skipping 57 matching lines @@
   AutoSchedulerLock auto_lock(idle_workers_stack_lock_);
   idle_workers_stack_.Remove(worker);
 }
 
 bool SchedulerWorkerPoolImpl::CanWorkerDetachForTesting() {
   return !worker_detachment_disallowed_.IsSet();
 }
 
 }  // namespace internal
 }  // namespace base