Add timing traces to PrepopulateRespectBlank to try to track down

a timeout in the test. 

BUG=62937
TEST=Enabling a test to find where it times out.

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

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

1 files changed, 24 insertions, 2 deletions

diff --git a/chrome/browser/ui/views/find_bar_host_interactive_uitest.cc b/chrome/browser/ui/views/find_bar_host_interactive_uitest.cc
index 70e0f87..2049eb0 100644
--- a/chrome/browser/ui/views/find_bar_host_interactive_uitest.cc
+++ b/chrome/browser/ui/views/find_bar_host_interactive_uitest.cc
@@ -38,6 +38,12 @@ class FindInPageTest : public InProcessBrowserTest {
   }
 };
 
+void Checkpoint(const char* message, const base::TimeTicks& start_time) {
+  LOG(INFO) << message << " : "
+    << (base::TimeTicks::Now() - start_time).InMilliseconds()
+    << " ms" << std::flush;
+}
+
 }  // namespace
 
 IN_PROC_BROWSER_TEST_F(FindInPageTest, CrashEscHandlers) {
@@ -122,56 +128,72 @@ IN_PROC_BROWSER_TEST_F(FindInPageTest, FocusRestore) {
 // This tests that whenever you clear values from the Find box and close it that
 // it respects that and doesn't show you the last search, as reported in bug:
 // http://crbug.com/40121.
-// Disabled, http://crbug.com/62937.
-IN_PROC_BROWSER_TEST_F(FindInPageTest, DISABLED_PrepopulateRespectBlank) {
+IN_PROC_BROWSER_TEST_F(FindInPageTest, PrepopulateRespectBlank) {
 #if defined(OS_MACOSX)
   // FindInPage on Mac doesn't use prepopulated values. Search there is global.
   return;
 #endif
 
+  base::TimeTicks start_time = base::TimeTicks::Now();
+  Checkpoint("Starting test server", start_time);
+
   ASSERT_TRUE(test_server()->Start());
 
   // First we navigate to any page.
+  Checkpoint("Navigating", start_time);
   GURL url = test_server()->GetURL(kSimplePage);
   ui_test_utils::NavigateToURL(browser(), url);
 
   // Show the Find bar.
+  Checkpoint("Showing Find window", start_time);
   browser()->GetFindBarController()->Show();
 
   // Search for "a".
+  Checkpoint("Search for 'a'", start_time);
   ASSERT_TRUE(ui_test_utils::SendKeyPressSync(
       browser(), app::VKEY_A, false, false, false, false));
 
   // We should find "a" here.
+  Checkpoint("GetFindBarText", start_time);
   EXPECT_EQ(ASCIIToUTF16("a"), GetFindBarText());
 
   // Delete "a".
+  Checkpoint("Delete 'a'", start_time);
   ASSERT_TRUE(ui_test_utils::SendKeyPressSync(
       browser(), app::VKEY_BACK, false, false, false, false));
 
   // Validate we have cleared the text.
+  Checkpoint("Validate clear", start_time);
   EXPECT_EQ(string16(), GetFindBarText());
 
   // Close the Find box.
+  Checkpoint("Close find", start_time);
   ASSERT_TRUE(ui_test_utils::SendKeyPressSync(
       browser(), app::VKEY_ESCAPE, false, false, false, false));
 
   // Show the Find bar.
+  Checkpoint("Showing Find window", start_time);
   browser()->GetFindBarController()->Show();
 
   // After the Find box has been reopened, it should not have been prepopulated
   // with "a" again.
+  Checkpoint("GetFindBarText", start_time);
   EXPECT_EQ(string16(), GetFindBarText());
 
   // Close the Find box.
+  Checkpoint("Press Esc", start_time);
   ASSERT_TRUE(ui_test_utils::SendKeyPressSync(
       browser(), app::VKEY_ESCAPE, false, false, false, false));
 
   // Press F3 to trigger FindNext.
+  Checkpoint("Press F3", start_time);
   ASSERT_TRUE(ui_test_utils::SendKeyPressSync(
       browser(), app::VKEY_F3, false, false, false, false));
 
   // After the Find box has been reopened, it should still have no prepopulate
   // value.
+  Checkpoint("GetFindBarText", start_time);
   EXPECT_EQ(string16(), GetFindBarText());
+
+  Checkpoint("Test completed", start_time);
 }