Fix hung renderer timer code in RenderWidgetHost (task spam bug)

content/browser/renderer_host/render_widget_host.cc

 // Copyright (c) 2011 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 "content/browser/renderer_host/render_widget_host.h"
 
 #include "base/auto_reset.h"
 #include "base/bind.h"
 #include "base/command_line.h"
 #include "base/debug/trace_event.h"
@@ skipping 76 matching lines @@
       is_hidden_(false),
       is_accelerated_compositing_active_(false),
       repaint_ack_pending_(false),
       resize_ack_pending_(false),
       mouse_move_pending_(false),
       mouse_wheel_pending_(false),
       touch_move_pending_(false),
       touch_event_is_queued_(false),
       needs_repainting_on_restore_(false),
       is_unresponsive_(false),
+      is_monitoring_for_hung_renderer_(false),
       in_get_backing_store_(false),
       view_being_painted_(false),
       ignore_input_events_(false),
       text_direction_updated_(false),
       text_direction_(WebKit::WebTextDirectionLeftToRight),
       text_direction_canceled_(false),
       suppress_next_char_events_(false),
       pending_mouse_lock_request_(false),
       ALLOW_THIS_IN_INITIALIZER_LIST(weak_factory_(this)) {
   if (routing_id_ == MSG_ROUTING_NONE)
@@ skipping 392 matching lines @@
     Send(new ViewMsg_Repaint(routing_id_, current_size_));
   }
 }
 
 void RenderWidgetHost::StartHangMonitorTimeout(TimeDelta delay) {
   if (CommandLine::ForCurrentProcess()->HasSwitch(
           switches::kDisableHangMonitor)) {
     return;
   }
 
-  // If we already have a timer that will expire at or before the given delay,
-  // then we have nothing more to do now.  If we have set our end time to null
-  // by calling StopHangMonitorTimeout, though, we will need to restart the
-  // timer.
-  if (hung_renderer_timer_.IsRunning() &&
-      hung_renderer_timer_.GetCurrentDelay() <= delay &&

[jbates, 2011/11/10 01:51:31]

This code seems to assume that GetCurrentDelay is the time remaining until the
task fires, but it's actually just the original delay set for the timer. This
caused the Stop/Start code below to execute every few milliseconds in some cases
(possibly based on mouse inputs and other forwarded communication). This showed
up in about:tracing as null MessageLoop tasks running every few milliseconds.

[Charlie Reis, 2011/11/10 19:35:54]

Thanks for catching this!

-      !time_when_considered_hung_.is_null()) {
-    return;
+  is_monitoring_for_hung_renderer_ = true;
+
+  // Start the timer if it's not already pending.
+  if (!hung_renderer_timer_.IsRunning()) {
+    hung_renderer_timer_.Start(FROM_HERE, delay, this,
+                               &RenderWidgetHost::CheckRendererIsUnresponsive);
   }
-
-  // Either the timer is not yet running, or we need to adjust the timer to
-  // fire sooner.
-  time_when_considered_hung_ = Time::Now() + delay;
-  hung_renderer_timer_.Stop();
-  hung_renderer_timer_.Start(FROM_HERE, delay, this,
-      &RenderWidgetHost::CheckRendererIsUnresponsive);
 }
 
 void RenderWidgetHost::RestartHangMonitorTimeout() {
-  // Setting to null will cause StartHangMonitorTimeout to restart the timer.
-  time_when_considered_hung_ = Time();

[jbates, 2011/11/10 01:51:31]

Instead of overloading the meaning of this time, I added a bool to indicate
whether we are monitoring for hung renderer.

[Charlie Reis, 2011/11/10 19:35:54]

I like it.

+  time_of_last_renderer_response_ = TimeTicks::Now();

[jbates, 2011/11/10 01:51:31]

Storing the time_of_last_renderer_response_ rather than the
time_when_considered_hung_ simplifies the code a bit.

[Charlie Reis, 2011/11/10 19:35:54]

I like simplifying it, but I'm not sure this is correct.  If someone calls
StartHangMonitorTimeout directly, this field doesn't get set.  That means the
timeout reflects the time since the last IPC received from the renderer
(possibly a long time ago), not the time since StartHangMonitorTimeout was
called.

Because of the way CheckRendererIsUnresponsive calls StartHangMonitorTimeout, I
also think it's not as simple as updating time_of_last_renderer_response_ in
StartHangMonitorTimeout.

Is there another way to fix it?  Or should we rename Restart to Start and Start
to Resume?

   StartHangMonitorTimeout(TimeDelta::FromMilliseconds(kHungRendererDelayMs));
 }
 
 void RenderWidgetHost::StopHangMonitorTimeout() {
-  time_when_considered_hung_ = Time();
+  is_monitoring_for_hung_renderer_ = false;
   RendererIsResponsive();
 
   // We do not bother to stop the hung_renderer_timer_ here in case it will be
   // started again shortly, which happens to be the common use case.
 }
 
 void RenderWidgetHost::ForwardMouseEvent(const WebMouseEvent& mouse_event) {
   TRACE_EVENT0("renderer_host", "RenderWidgetHost::ForwardMouseEvent");
   if (ignore_input_events_ || process_->ignore_input_events())
     return;
@@ skipping 307 matching lines @@
   // of other messages on us.  So if you do any other deinitialization here,
   // do it after this call to view_->Destroy().
   if (view_)
     view_->Destroy();
 
   delete this;
 }
 
 void RenderWidgetHost::CheckRendererIsUnresponsive() {
   // If we received a call to StopHangMonitorTimeout.
-  if (time_when_considered_hung_.is_null())
+  if (!is_monitoring_for_hung_renderer_)
     return;
 
   // If we have not waited long enough, then wait some more.
-  Time now = Time::Now();
-  if (now < time_when_considered_hung_) {
-    StartHangMonitorTimeout(time_when_considered_hung_ - now);
+  TimeDelta elapsed_time = TimeTicks::Now() - time_of_last_renderer_response_;
+  TimeDelta hung_delay = TimeDelta::FromMilliseconds(kHungRendererDelayMs);

[Charlie Reis, 2011/11/10 19:35:54]

This isn't correct-- we use different values in different places.  (It's a much
longer delay for interaction response than for closing a tab, for example.  See
kUnloadTimeoutMS.)

+  if (elapsed_time < hung_delay) {
+    StartHangMonitorTimeout(hung_delay - elapsed_time);
     return;
   }
 
   // OK, looks like we have a hung renderer!
   content::NotificationService::current()->Notify(
       content::NOTIFICATION_RENDERER_PROCESS_HANG,
       content::Source<RenderWidgetHost>(this),
       content::NotificationService::NoDetails());
   is_unresponsive_ = true;
   NotifyRendererUnresponsive();
 }
 
 void RenderWidgetHost::RendererIsResponsive() {
+  time_of_last_renderer_response_ = TimeTicks::Now();
   if (is_unresponsive_) {
     is_unresponsive_ = false;
     NotifyRendererResponsive();
   }
 }
 
 void RenderWidgetHost::OnMsgRenderViewReady() {
   WasResized();
 }
 
@@ skipping 570 matching lines @@
     pending_mouse_lock_request_ = false;
     if (!view_ || !view_->HasFocus()|| !view_->LockMouse()) {
       Send(new ViewMsg_LockMouse_ACK(routing_id_, false));
       return false;
     } else {
       Send(new ViewMsg_LockMouse_ACK(routing_id_, true));
       return true;
     }
   }
 }