[scheduler]: Avoid waking up the scheduler to end long idle periods.

components/scheduler/child/idle_helper.cc

 // Copyright 2015 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 "components/scheduler/child/idle_helper.h"
 
 #include "base/trace_event/trace_event.h"
 #include "base/trace_event/trace_event_argument.h"
 #include "components/scheduler/child/scheduler_helper.h"
 
 namespace scheduler {
 
 IdleHelper::IdleHelper(
     SchedulerHelper* helper,
     Delegate* delegate,
     size_t idle_queue_index,
     const char* tracing_category,
     const char* disabled_by_default_tracing_category,
     const char* idle_period_tracing_name,
     base::TimeDelta required_quiescence_duration_before_long_idle_period)
     : helper_(helper),
       delegate_(delegate),
       idle_queue_index_(idle_queue_index),
       idle_period_state_(IdlePeriodState::NOT_IN_IDLE_PERIOD),
       quiescence_monitored_task_queue_mask_(
           helper_->GetQuiescenceMonitoredTaskQueueMask() &
           ~(1ull << idle_queue_index_)),
       required_quiescence_duration_before_long_idle_period_(
           required_quiescence_duration_before_long_idle_period),
+      nestable_events_started_(false),
       tracing_category_(tracing_category),
       disabled_by_default_tracing_category_(
           disabled_by_default_tracing_category),
       idle_period_tracing_name_(idle_period_tracing_name),
       weak_factory_(this) {
   weak_idle_helper_ptr_ = weak_factory_.GetWeakPtr();
-  end_idle_period_closure_.Reset(
-      base::Bind(&IdleHelper::EndIdlePeriod, weak_idle_helper_ptr_));
   enable_next_long_idle_period_closure_.Reset(
       base::Bind(&IdleHelper::EnableLongIdlePeriod, weak_idle_helper_ptr_));
-  enable_next_long_idle_period_after_wakeup_closure_.Reset(base::Bind(
-      &IdleHelper::EnableLongIdlePeriodAfterWakeup, weak_idle_helper_ptr_));
 
   idle_task_runner_ = make_scoped_refptr(new SingleThreadIdleTaskRunner(
       helper_->TaskRunnerForQueue(idle_queue_index_),
       helper_->ControlAfterWakeUpTaskRunner(),
-      base::Bind(&IdleHelper::CurrentIdleTaskDeadlineCallback,
-                 weak_idle_helper_ptr_),
+      this,
       tracing_category));
 
   helper_->DisableQueue(idle_queue_index_);
   helper_->SetPumpPolicy(idle_queue_index_,
-                         TaskQueueManager::PumpPolicy::MANUAL);
+      TaskQueueManager::PumpPolicy::MANUAL);
+
+  helper_->AddTaskObserver(this);
 }
 
 IdleHelper::~IdleHelper() {
 }
 
 IdleHelper::Delegate::Delegate() {
 }
 
 IdleHelper::Delegate::~Delegate() {
 }
 
 scoped_refptr<SingleThreadIdleTaskRunner> IdleHelper::IdleTaskRunner() {
   helper_->CheckOnValidThread();
   return idle_task_runner_;
 }
 
-void IdleHelper::CurrentIdleTaskDeadlineCallback(
-    base::TimeTicks* deadline_out) const {
-  helper_->CheckOnValidThread();
-  *deadline_out = idle_period_deadline_;
-}
-
 IdleHelper::IdlePeriodState IdleHelper::ComputeNewLongIdlePeriodState(
     const base::TimeTicks now,
     base::TimeDelta* next_long_idle_period_delay_out) {
   helper_->CheckOnValidThread();
 
   if (!delegate_->CanEnterLongIdlePeriod(now,
                                          next_long_idle_period_delay_out)) {
     return IdlePeriodState::NOT_IN_IDLE_PERIOD;
   }
 
@@ skipping 42 matching lines @@
                task_queues_run_since_last_check_bitmap);
 
   // If anything was run on the queues we care about, then we're not quiescent
   // and we should wait.
   return task_queues_run_since_last_check_bitmap != 0;
 }
 
 void IdleHelper::EnableLongIdlePeriod() {
   TRACE_EVENT0(disabled_by_default_tracing_category_, "EnableLongIdlePeriod");
   helper_->CheckOnValidThread();
+  if (helper_->IsShutdown())
+    return;
 
   // End any previous idle period.
   EndIdlePeriod();
 
   if (ShouldWaitForQuiescence()) {
     helper_->ControlTaskRunner()->PostDelayedTask(
         FROM_HERE, enable_next_long_idle_period_closure_.callback(),
         required_quiescence_duration_before_long_idle_period_);
     delegate_->IsNotQuiescent();
     return;
   }
 
   base::TimeTicks now(helper_->Now());
   base::TimeDelta next_long_idle_period_delay;
   IdlePeriodState new_idle_period_state =
       ComputeNewLongIdlePeriodState(now, &next_long_idle_period_delay);
   if (IsInIdlePeriod(new_idle_period_state)) {
     StartIdlePeriod(new_idle_period_state, now,
-                    now + next_long_idle_period_delay, false);
-  }
-
-  if (helper_->IsQueueEmpty(idle_queue_index_)) {
-    // If there are no current idle tasks then post the call to initiate the
-    // next idle for execution after wakeup (at which point after-wakeup idle
-    // tasks might be eligible to run or more idle tasks posted).
-    helper_->ControlAfterWakeUpTaskRunner()->PostDelayedTask(
-        FROM_HERE,
-        enable_next_long_idle_period_after_wakeup_closure_.callback(),
-        next_long_idle_period_delay);
+                    now + next_long_idle_period_delay);
   } else {
-    // Otherwise post on the normal control task queue.
+    // Otherwise wait for the next long idle period delay before trying again.
     helper_->ControlTaskRunner()->PostDelayedTask(
         FROM_HERE, enable_next_long_idle_period_closure_.callback(),
         next_long_idle_period_delay);
   }
 }
 
-void IdleHelper::EnableLongIdlePeriodAfterWakeup() {
-  TRACE_EVENT0(disabled_by_default_tracing_category_,
-               "EnableLongIdlePeriodAfterWakeup");
-  helper_->CheckOnValidThread();
-
-  if (IsInIdlePeriod(idle_period_state_)) {
-    // Since we were asleep until now, end the async idle period trace event at
-    // the time when it would have ended were we awake.
-    TRACE_EVENT_ASYNC_END_WITH_TIMESTAMP0(
-        tracing_category_, idle_period_tracing_name_, this,
-        std::min(idle_period_deadline_, helper_->Now()).ToInternalValue());
-    idle_period_state_ = IdlePeriodState::ENDING_LONG_IDLE_PERIOD;
-    EndIdlePeriod();
-  }
-
-  // Post a task to initiate the next long idle period rather than calling it
-  // directly to allow all pending PostIdleTaskAfterWakeup tasks to get enqueued
-  // on the idle task queue before the next idle period starts so they are
-  // eligible to be run during the new idle period.
-  helper_->ControlTaskRunner()->PostTask(
-      FROM_HERE, enable_next_long_idle_period_closure_.callback());
-}
-
 void IdleHelper::StartIdlePeriod(IdlePeriodState new_state,
                                  base::TimeTicks now,
-                                 base::TimeTicks idle_period_deadline,
-                                 bool post_end_idle_period) {
+                                 base::TimeTicks idle_period_deadline) {
   DCHECK_GT(idle_period_deadline, now);
-  TRACE_EVENT_ASYNC_BEGIN0(tracing_category_, idle_period_tracing_name_, this);
   helper_->CheckOnValidThread();
   DCHECK(IsInIdlePeriod(new_state));
+  TRACE_EVENT0(disabled_by_default_tracing_category_, "StartIdlePeriod");
 
   helper_->EnableQueue(idle_queue_index_,
                        PrioritizingTaskQueueSelector::BEST_EFFORT_PRIORITY);
   helper_->PumpQueue(idle_queue_index_);
-  idle_period_state_ = new_state;
 
-  idle_period_deadline_ = idle_period_deadline;
-  if (post_end_idle_period) {
-    helper_->ControlTaskRunner()->PostDelayedTask(
-        FROM_HERE, end_idle_period_closure_.callback(),
-        idle_period_deadline_ - now);
-  }
+  SetIdlePeriodState(new_state, idle_period_deadline, now);
 }
 
 void IdleHelper::EndIdlePeriod() {
   helper_->CheckOnValidThread();
+  TRACE_EVENT0(disabled_by_default_tracing_category_, "EndIdlePeriod");
 
-  end_idle_period_closure_.Cancel();
   enable_next_long_idle_period_closure_.Cancel();
-  enable_next_long_idle_period_after_wakeup_closure_.Cancel();
 
   // If we weren't already within an idle period then early-out.
   if (!IsInIdlePeriod(idle_period_state_))
     return;
 
-  // If we are in the ENDING_LONG_IDLE_PERIOD state we have already logged the
-  // trace event.
-  if (idle_period_state_ != IdlePeriodState::ENDING_LONG_IDLE_PERIOD) {
-    bool is_tracing;
-    TRACE_EVENT_CATEGORY_GROUP_ENABLED(tracing_category_, &is_tracing);
-    if (is_tracing && !idle_period_deadline_.is_null() &&
-        helper_->Now() > idle_period_deadline_) {
-      TRACE_EVENT_ASYNC_STEP_INTO_WITH_TIMESTAMP0(
-          tracing_category_, idle_period_tracing_name_, this, "DeadlineOverrun",
-          idle_period_deadline_.ToInternalValue());
-    }
-    TRACE_EVENT_ASYNC_END0(tracing_category_, idle_period_tracing_name_, this);
-  }
-
   helper_->DisableQueue(idle_queue_index_);
-  idle_period_state_ = IdlePeriodState::NOT_IN_IDLE_PERIOD;
+  SetIdlePeriodState(IdlePeriodState::NOT_IN_IDLE_PERIOD,
+      base::TimeTicks(), base::TimeTicks());
   idle_period_deadline_ = base::TimeTicks();
 }
 
+void IdleHelper::WillProcessTask(const base::PendingTask& pending_task) {
+}
+
+void IdleHelper::DidProcessTask(const base::PendingTask& pending_task) {
+  helper_->CheckOnValidThread();
+  TRACE_EVENT0(disabled_by_default_tracing_category_, "DidProcessTask");
+  if (IsInIdlePeriod(idle_period_state_) &&
+      idle_period_state_ != IdlePeriodState::IN_LONG_IDLE_PERIOD_PAUSED &&
+      helper_->Now() >= idle_period_deadline_) {
+    // If the idle period has now been reached, either end the idle period or

[Sami, 2015/05/26 13:35:41]

"idle period deadline"?

[rmcilroy, 2015/05/27 11:58:36]

Done.

+    // trigger a new long-idle period.
+    if (IsInLongIdlePeriod(idle_period_state_)) {
+      EnableLongIdlePeriod();
+    } else {
+      DCHECK(IdlePeriodState::IN_SHORT_IDLE_PERIOD == idle_period_state_);
+      EndIdlePeriod();
+    }
+  }
+}
+
+void IdleHelper::CheckLongIdlePeriodSentinel() {
+  helper_->CheckOnValidThread();
+  DCHECK(IsInLongIdlePeriod(idle_period_state_));
+  TRACE_EVENT0(disabled_by_default_tracing_category_,
+               "CheckLongIdlePeriodSentinel");
+
+  if (helper_->IsQueueEmpty(idle_queue_index_)) {

[Sami, 2015/05/26 13:35:41]

Optimization-ocd-nit: we could combine IsQueueEmpty and QueueNeedsPumped to a
single method that returns a tri-state. Probably not a very big deal either way
can could definitely be done later.

[rmcilroy, 2015/05/27 11:58:36]

Ack. I'll make this change on the preceeding CL and rebase into this CL.

[rmcilroy, 2015/05/27 19:17:05]

Done in latest patchset.

+    // If there are no more idle tasks then pause long idle period ticks until a
+    // new idle task is posted.
+    SetIdlePeriodState(IdlePeriodState::IN_LONG_IDLE_PERIOD_PAUSED,
+                       idle_period_deadline_,
+                       base::TimeTicks());
+  } else if (helper_->QueueNeedsPumped(idle_queue_index_)) {
+    // If there is still idle work to do then just start the next idle period.
+    base::TimeDelta next_long_idle_period_delay;
+    if (idle_period_state_ ==
+        IdlePeriodState::IN_LONG_IDLE_PERIOD_WITH_MAX_DEADLINE) {
+      // If we are in a max deadline long idle period then start the next
+      // idle period immediately.
+      next_long_idle_period_delay = base::TimeDelta();
+    } else {
+      // Otherwise ensure that we kick the scheduler at the right time to
+      // initiate the next idle period.
+      next_long_idle_period_delay = idle_period_deadline_ - helper_->Now();

[Sami, 2015/05/26 13:35:41]

Should we clamp this to zero to avoid random DCHECKs when the deadline is in the
past?

[rmcilroy, 2015/05/27 11:58:36]

Good point! Done.

+    }
+    helper_->ControlTaskRunner()->PostDelayedTask(FROM_HERE,
+        enable_next_long_idle_period_closure_.callback(),
+        next_long_idle_period_delay);
+  }
+}
+
+void IdleHelper::CurrentIdleTaskDeadlineCallback(
+    base::TimeTicks* deadline_out) const {
+  helper_->CheckOnValidThread();
+  *deadline_out = idle_period_deadline_;
+}
+
+
+void IdleHelper::OnIdleTaskPosted() {
+  helper_->CheckOnValidThread();

[Sami, 2015/05/26 13:35:40]

This can be running on any thread, right?

[rmcilroy, 2015/05/27 11:58:36]

Yes, thanks. Done.

[Sami, 2015/05/27 12:11:56]

Did you mean to add some locking/posting here?-)

[rmcilroy, 2015/05/27 19:17:05]

Opps, added a comment about this then forgot about the rest. Done now.

+  if (idle_period_state_ == IdlePeriodState::IN_LONG_IDLE_PERIOD_PAUSED) {
+    // Restart long idle period ticks.
+    enable_next_long_idle_period_closure_.Cancel();
+    helper_->ControlTaskRunner()->PostTask(FROM_HERE,
+        enable_next_long_idle_period_closure_.callback());
+  }
+}
+
+void IdleHelper::OnWillRunIdleTask(base::TimeTicks* deadline_out) const {
+  helper_->CheckOnValidThread();
+  //DCHECK(IsInIdlePeriod(idle_period_state_));

[Sami, 2015/05/26 13:35:41]

Uncomment/remove?

[rmcilroy, 2015/05/27 11:58:36]

Uncommented

+  bool is_tracing;
+  TRACE_EVENT_CATEGORY_GROUP_ENABLED(tracing_category_, &is_tracing);
+  if (is_tracing && nestable_events_started_) {
+    last_traced_start_running_idle_task_ = helper_->Now();

[Sami, 2015/05/26 13:35:40]

I believe we should use NowFromSystemTraceTime() to make sure everything lines
up on platforms where Now() != NowFromSystemTraceTime() (CrOS). We could
probably just call that directly without going throught the helper. Just make
sure the time stamps are never mixed :)

[rmcilroy, 2015/05/27 11:58:36]

Done, although we later pass "std::max(idle_period_deadline_,
last_traced_start_running_idle_task_)" to a trace event and
idle_period_deadline_ is not using NowFromSystemTraceTime(). Should we keep a
separate idle_period_deadline_ initialized via NowFromSystemTraceTime just for
this?

[Sami, 2015/05/27 12:11:56]

I think we should. The two timebases aren't compatible and I believe they will
soon be split into two different time types.

[rmcilroy, 2015/05/27 19:17:05]

Ok, good to know. Done.

+    TRACE_EVENT_NESTABLE_ASYNC_BEGIN_WITH_TIMESTAMP0(
+        tracing_category_, "RunningIdleTask", this,
+        last_traced_start_running_idle_task_.ToInternalValue());
+  }
+  CurrentIdleTaskDeadlineCallback(deadline_out);

[Sami, 2015/05/26 13:35:41]

Could we just replace this with a simple assigment now? In any case the function
shouldn't be called a "callback" anymore.

[rmcilroy, 2015/05/27 11:58:36]

I kept the method for tests. Removed "Callback".

+}
+
+void IdleHelper::OnDidRunIdleTask() {
+  helper_->CheckOnValidThread();
+  DCHECK(IsInIdlePeriod(idle_period_state_));
+  bool is_tracing;
+  TRACE_EVENT_CATEGORY_GROUP_ENABLED(tracing_category_, &is_tracing);
+  if (is_tracing && nestable_events_started_) {
+      if (!idle_period_deadline_.is_null() &&
+          helper_->Now() > idle_period_deadline_) {
+      TRACE_EVENT_NESTABLE_ASYNC_BEGIN_WITH_TIMESTAMP0(
+          tracing_category_,"DeadlineOverrun", this,
+          std::max(idle_period_deadline_, last_traced_start_running_idle_task_)
+              .ToInternalValue());
+      TRACE_EVENT_NESTABLE_ASYNC_END0(
+          tracing_category_,"DeadlineOverrun", this);
+    }
+    TRACE_EVENT_NESTABLE_ASYNC_END0(tracing_category_, "RunningIdleTask", this);
+  }
+
+  if (IsInLongIdlePeriod(idle_period_state_)) {
+    CheckLongIdlePeriodSentinel();

[Sami, 2015/05/26 13:35:40]

nit: It's not clear what "sentinel" refers to here. Is this essentially
something like UpdateLongIdlePeriodState{AfterIdleTask}()?

[rmcilroy, 2015/05/27 11:58:36]

Yeah, this was originally a sentinal task posted on the idle queue and I never
came up with a better name :). 

+  }
+}
+
 // static
 bool IdleHelper::IsInIdlePeriod(IdlePeriodState state) {
   return state != IdlePeriodState::NOT_IN_IDLE_PERIOD;
 }
 
+// static
+bool IdleHelper::IsInLongIdlePeriod(IdlePeriodState state) {
+  return state == IdlePeriodState::IN_LONG_IDLE_PERIOD ||
+         state == IdlePeriodState::IN_LONG_IDLE_PERIOD_WITH_MAX_DEADLINE ||
+         state == IdlePeriodState::IN_LONG_IDLE_PERIOD_PAUSED;
+}
+
+void IdleHelper::SetIdlePeriodState(IdlePeriodState new_state,
+                                    base::TimeTicks new_deadline,
+                                    base::TimeTicks optional_now) {
+  helper_->CheckOnValidThread();
+  if (new_state == idle_period_state_) return;

[Sami, 2015/05/26 13:35:40]

Should we DCHECK that the deadline didn't change?

[rmcilroy, 2015/05/27 11:58:36]

Done.

+
+  bool is_tracing;
+  TRACE_EVENT_CATEGORY_GROUP_ENABLED(tracing_category_, &is_tracing);
+  if (is_tracing) {
+    TraceEventIdlePeriodStateChange(new_state, new_deadline, optional_now);
+  }
+
+  idle_period_state_ = new_state;
+  idle_period_deadline_ = new_deadline;
+}
+
 bool IdleHelper::CanExceedIdleDeadlineIfRequired() const {
   TRACE_EVENT0(tracing_category_, "CanExceedIdleDeadlineIfRequired");
   helper_->CheckOnValidThread();
   return idle_period_state_ ==
          IdlePeriodState::IN_LONG_IDLE_PERIOD_WITH_MAX_DEADLINE;
 }
 
 IdleHelper::IdlePeriodState IdleHelper::SchedulerIdlePeriodState() const {
   return idle_period_state_;
 }
 
+void IdleHelper::TraceEventIdlePeriodStateChange(
+    IdlePeriodState new_state,
+    base::TimeTicks new_deadline,
+    base::TimeTicks optional_now) const {
+  TRACE_EVENT2(disabled_by_default_tracing_category_, "SetIdlePeriodState",
+      "old_state", IdleHelper::IdlePeriodStateToString(idle_period_state_),
+      "new_state", IdleHelper::IdlePeriodStateToString(new_state));
+  if (nestable_events_started_) {
+    // End async tracing events for the state we are leaving.
+    if (idle_period_state_ == IdlePeriodState::IN_LONG_IDLE_PERIOD_PAUSED) {
+      TRACE_EVENT_NESTABLE_ASYNC_END0(tracing_category_,

[Sami, 2015/05/26 13:35:40]

Would this work better using the non-nestable STEP_INTO variants? Or do we
actually need nesting in some cases? Maybe I just need to see a trace :)

[rmcilroy, 2015/05/27 11:58:36]

Apparently the non-nestable STEP_INTO variants are deprecated and NESTABLE is
the new hotness. It works quite well as long as you keep the nesting consistent
(hence some of the extra bookkeeping requirements. I'll show you a trace.

[Sami, 2015/05/27 12:11:56]

Yeah thanks I didn't realize they were deprecated.

+                                      "LongIdlePeriodPaused",
+                                      this);
+    }
+    if (IsInLongIdlePeriod(idle_period_state_) &&
+        !IsInLongIdlePeriod(new_state)) {
+      TRACE_EVENT_NESTABLE_ASYNC_END0(tracing_category_,
+                                      "LongIdlePeriod",
+                                      this);
+    }
+    if (idle_period_state_ == IdlePeriodState::IN_SHORT_IDLE_PERIOD) {
+      TRACE_EVENT_NESTABLE_ASYNC_END0(tracing_category_,
+                                      "ShortIdlePeriod",
+                                      this);
+    }
+    if (IsInIdlePeriod(idle_period_state_) && !IsInLongIdlePeriod(new_state)) {
+      TRACE_EVENT_NESTABLE_ASYNC_END0(tracing_category_,
+                                      idle_period_tracing_name_,
+                                      this);
+      nestable_events_started_ = false;
+    }
+  }
+
+  // Start async tracing events for the state we are entering.
+  if (IsInIdlePeriod(new_state) && !IsInIdlePeriod(idle_period_state_)) {
+    if (optional_now.is_null())
+      optional_now = helper_->Now();
+    nestable_events_started_ =

[Sami, 2015/05/26 13:35:40]

Weird newline here.

[rmcilroy, 2015/05/27 11:58:36]

Done.

+    true;
+    TRACE_EVENT_NESTABLE_ASYNC_BEGIN1(tracing_category_,
+        idle_period_tracing_name_,
+        this,
+        "idle_period_length_ms",
+        (new_deadline - optional_now).ToInternalValue());
+  }
+  if (new_state == IdlePeriodState::IN_SHORT_IDLE_PERIOD) {
+    TRACE_EVENT_NESTABLE_ASYNC_END0(tracing_category_,
+                                    "ShortIdlePeriod",
+                                    this);
+  }
+  if (IsInLongIdlePeriod(new_state) && !IsInIdlePeriod(idle_period_state_)) {
+    TRACE_EVENT_NESTABLE_ASYNC_BEGIN0(tracing_category_,
+                                      "LongIdlePeriod",
+                                      this);
+  }
+  if (new_state == IdlePeriodState::IN_LONG_IDLE_PERIOD_PAUSED) {
+    TRACE_EVENT_NESTABLE_ASYNC_BEGIN0(tracing_category_,
+                                      "LongIdlePeriodPaused",
+                                      this);
+  }
+}
+
 // static
 const char* IdleHelper::IdlePeriodStateToString(
     IdlePeriodState idle_period_state) {
   switch (idle_period_state) {
     case IdlePeriodState::NOT_IN_IDLE_PERIOD:
       return "not_in_idle_period";
     case IdlePeriodState::IN_SHORT_IDLE_PERIOD:
       return "in_short_idle_period";
     case IdlePeriodState::IN_LONG_IDLE_PERIOD:
       return "in_long_idle_period";
     case IdlePeriodState::IN_LONG_IDLE_PERIOD_WITH_MAX_DEADLINE:
       return "in_long_idle_period_with_max_deadline";
-    case IdlePeriodState::ENDING_LONG_IDLE_PERIOD:
-      return "ending_long_idle_period";
+    case IdlePeriodState::IN_LONG_IDLE_PERIOD_PAUSED:
+      return "in_long_idle_period_paused";
     default:
       NOTREACHED();
       return nullptr;
   }
 }
 
 }  // namespace scheduler