Fix flaky IncognitoSplitMode.

Stop processing incoming messages in BrowserRenderProcessHost when it is about
to be deleted. See comment 20 on the bug for details.

BUG=53991
TEST=handled by existing test

Review URL: http://codereview.chromium.org/3656005

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@62432 0039d316-1c4b-4281-b951-d872f2087c98

6 files changed, 55 insertions, 38 deletions

diff --git a/chrome/browser/browser.cc b/chrome/browser/browser.cc
index 3fe5245..d450835 100644
--- a/chrome/browser/browser.cc
+++ b/chrome/browser/browser.cc
@@ -187,6 +187,8 @@ bool CompareURLsIgnoreRef(const GURL& url, const GURL& other) {
 
 }  // namespace
 
+extern bool g_log_bug53991;
+
 ///////////////////////////////////////////////////////////////////////////////
 // Browser, Constructors, Creation, Showing:
 
@@ -265,6 +267,10 @@ Browser::Browser(Type type, Profile* profile)
 }
 
 Browser::~Browser() {
+  LOG_IF(INFO, g_log_bug53991) <<
+      "~Browser: " << profile_->IsOffTheRecord() <<
+      "; stillActive=" << BrowserList::IsOffTheRecordSessionActive();
+
   if (profile_->GetProfileSyncService())
     profile_->GetProfileSyncService()->RemoveObserver(this);
 
diff --git a/chrome/browser/extensions/extension_apitest.cc b/chrome/browser/extensions/extension_apitest.cc
index 28ecc68..da9e01c 100644
--- a/chrome/browser/extensions/extension_apitest.cc
+++ b/chrome/browser/extensions/extension_apitest.cc
@@ -43,7 +43,6 @@ bool ExtensionApiTest::ResultCatcher::GetNextResult() {
     return ret;
   }
 
-  LOG(INFO) << "DEBUG: results aren't empty";
   NOTREACHED();
   return false;
 }
@@ -58,7 +57,7 @@ void ExtensionApiTest::ResultCatcher::Observe(
 
   switch (type.value) {
     case NotificationType::EXTENSION_TEST_PASSED:
-      LOG(INFO) << "Got EXTENSION_TEST_PASSED notification (" << this << ").";
+      LOG(INFO) << "Got EXTENSION_TEST_PASSED notification.";
       results_.push_back(true);
       messages_.push_back("");
       if (waiting_)
@@ -66,7 +65,7 @@ void ExtensionApiTest::ResultCatcher::Observe(
       break;
 
     case NotificationType::EXTENSION_TEST_FAILED:
-      LOG(INFO) << "Got EXTENSION_TEST_FAILED notification (" << this << ").";
+      LOG(INFO) << "Got EXTENSION_TEST_FAILED notification.";
       results_.push_back(false);
       messages_.push_back(*(Details<std::string>(details).ptr()));
       if (waiting_)
diff --git a/chrome/browser/extensions/extension_incognito_apitest.cc b/chrome/browser/extensions/extension_incognito_apitest.cc
index abe5267..640fa14 100644
--- a/chrome/browser/extensions/extension_incognito_apitest.cc
+++ b/chrome/browser/extensions/extension_incognito_apitest.cc
@@ -108,45 +108,37 @@ IN_PROC_BROWSER_TEST_F(ExtensionApiTest, Incognito) {
 // Tests that the APIs in an incognito-enabled split-mode extension work
 // properly.
 // TODO(mpcomplete): Crashes flakily. http://crbug.com/53991
+extern bool g_log_bug53991;
 IN_PROC_BROWSER_TEST_F(ExtensionApiTest, FLAKY_IncognitoSplitMode) {
+  g_log_bug53991 = true;
   host_resolver()->AddRule("*", "127.0.0.1");
   ASSERT_TRUE(test_server()->Start());
 
-  {
-    // We need 2 ResultCatchers because we'll be running the same test in both
-    // regular and incognito mode.
-    ResultCatcher catcher;
-    catcher.RestrictToProfile(browser()->profile());
-    ResultCatcher catcher_incognito;
-    catcher_incognito.RestrictToProfile(
-        browser()->profile()->GetOffTheRecordProfile());
-
-    // Open incognito window and navigate to test page.
-    ui_test_utils::OpenURLOffTheRecord(browser()->profile(),
-        GURL("http://www.example.com:1337/files/extensions/test_file.html"));
-
-    LOG(INFO) << "DEBUG: Loading extension";
-
-    ASSERT_TRUE(LoadExtensionIncognito(test_data_dir_.
-        AppendASCII("incognito").AppendASCII("split")));
-
-    LOG(INFO) << "DEBUG: waiting for message";
-
-    // Wait for both extensions to be ready before telling them to proceed.
-    ExtensionTestMessageListener listener("waiting", true);
-    EXPECT_TRUE(listener.WaitUntilSatisfied());
-    ExtensionTestMessageListener listener_incognito("waiting", true);
-    EXPECT_TRUE(listener_incognito.WaitUntilSatisfied());
-    listener.Reply("go");
-    listener_incognito.Reply("go");
-
-    LOG(INFO) << "DEBUG: Get result for normal";
-    EXPECT_TRUE(catcher.GetNextResult()) << catcher.message();
-    LOG(INFO) << "DEBUG: Get result for incognito";
-    EXPECT_TRUE(catcher_incognito.GetNextResult()) << catcher.message();
-    LOG(INFO) << "DEBUG: Got results";
-  }
-  LOG(INFO) << "DEBUG: ResultCatcher destroyed.";
+  // We need 2 ResultCatchers because we'll be running the same test in both
+  // regular and incognito mode.
+  ResultCatcher catcher;
+  catcher.RestrictToProfile(browser()->profile());
+  ResultCatcher catcher_incognito;
+  catcher_incognito.RestrictToProfile(
+      browser()->profile()->GetOffTheRecordProfile());
+
+  // Open incognito window and navigate to test page.
+  ui_test_utils::OpenURLOffTheRecord(browser()->profile(),
+      GURL("http://www.example.com:1337/files/extensions/test_file.html"));
+
+  ASSERT_TRUE(LoadExtensionIncognito(test_data_dir_
+      .AppendASCII("incognito").AppendASCII("split")));
+
+  // Wait for both extensions to be ready before telling them to proceed.
+  ExtensionTestMessageListener listener("waiting", true);
+  EXPECT_TRUE(listener.WaitUntilSatisfied());
+  ExtensionTestMessageListener listener_incognito("waiting", true);
+  EXPECT_TRUE(listener_incognito.WaitUntilSatisfied());
+  listener.Reply("go");
+  listener_incognito.Reply("go");
+
+  EXPECT_TRUE(catcher.GetNextResult()) << catcher.message();
+  EXPECT_TRUE(catcher_incognito.GetNextResult()) << catcher.message();
 }
 
 // Tests that the APIs in an incognito-disabled extension don't see incognito
diff --git a/chrome/browser/extensions/extension_process_manager.cc b/chrome/browser/extensions/extension_process_manager.cc
index 954f92d..5a28617 100644
--- a/chrome/browser/extensions/extension_process_manager.cc
+++ b/chrome/browser/extensions/extension_process_manager.cc
@@ -73,6 +73,8 @@ static void CreateBackgroundHosts(
 
 }  // namespace
 
+extern bool g_log_bug53991;
+
 //
 // ExtensionProcessManager
 //
@@ -103,6 +105,7 @@ ExtensionProcessManager::ExtensionProcessManager(Profile* profile)
 }
 
 ExtensionProcessManager::~ExtensionProcessManager() {
+  LOG_IF(INFO, g_log_bug53991) << "~ExtensionProcessManager: " << this;
   CloseBackgroundHosts();
   DCHECK(background_hosts_.empty());
 }
@@ -347,6 +350,7 @@ void ExtensionProcessManager::OnExtensionHostCreated(ExtensionHost* host,
 }
 
 void ExtensionProcessManager::CloseBackgroundHosts() {
+  LOG_IF(INFO, g_log_bug53991) << "CloseBackgroundHosts: " << this;
   for (ExtensionHostSet::iterator iter = background_hosts_.begin();
        iter != background_hosts_.end(); ) {
     ExtensionHostSet::iterator current = iter++;
diff --git a/chrome/browser/renderer_host/browser_render_process_host.cc b/chrome/browser/renderer_host/browser_render_process_host.cc
index 718120f..7b54d35 100644
--- a/chrome/browser/renderer_host/browser_render_process_host.cc
+++ b/chrome/browser/renderer_host/browser_render_process_host.cc
@@ -77,6 +77,10 @@ using WebKit::WebCache;
 
 #include "third_party/skia/include/core/SkBitmap.h"
 
+// TODO(mpcomplete): Remove this after fixing
+// http://code.google.com/p/chromium/issues/detail?id=53991
+bool g_log_bug53991 = false;
+
 // This class creates the IO thread for the renderer when running in
 // single-process mode.  It's not used in multi-process mode.
 class RendererMainThread : public base::Thread {
@@ -250,6 +254,8 @@ BrowserRenderProcessHost::BrowserRenderProcessHost(Profile* profile)
 }
 
 BrowserRenderProcessHost::~BrowserRenderProcessHost() {
+  LOG_IF(INFO, g_log_bug53991) << "~BrowserRenderProcessHost: " << this;
+
   WebCacheManager::GetInstance()->Remove(id());
   ChildProcessSecurityPolicy::GetInstance()->Remove(id());
 
@@ -836,6 +842,10 @@ bool BrowserRenderProcessHost::Send(IPC::Message* msg) {
 }
 
 void BrowserRenderProcessHost::OnMessageReceived(const IPC::Message& msg) {
+  LOG_IF(INFO, g_log_bug53991) <<
+      "OnMessageReceived: " << this <<
+      "; type=" << msg.type() <<
+      "; routing=" << msg.routing_id();
   mark_child_process_activity_time();
   if (msg.routing_id() == MSG_ROUTING_CONTROL) {
     // Dispatch control messages.
diff --git a/chrome/browser/renderer_host/render_process_host.cc b/chrome/browser/renderer_host/render_process_host.cc
index 959252e..3bba7b5 100644
--- a/chrome/browser/renderer_host/render_process_host.cc
+++ b/chrome/browser/renderer_host/render_process_host.cc
@@ -79,6 +79,8 @@ IDMap<RenderProcessHost> all_hosts;
 
 }  // namespace
 
+extern bool g_log_bug53991;
+
 // static
 bool RenderProcessHost::run_renderer_in_process_ = false;
 
@@ -108,10 +110,14 @@ RenderProcessHost::~RenderProcessHost() {
 
 void RenderProcessHost::Attach(IPC::Channel::Listener* listener,
                                int routing_id) {
+  LOG_IF(INFO, g_log_bug53991) <<
+      "AddListener: (" << this << "): " << routing_id;
   listeners_.AddWithID(listener, routing_id);
 }
 
 void RenderProcessHost::Release(int listener_id) {
+  LOG_IF(INFO, g_log_bug53991) <<
+      "RemListener: (" << this << "): " << listener_id;
   DCHECK(listeners_.Lookup(listener_id) != NULL);
   listeners_.Remove(listener_id);