Temporarily adding timers to one WebRTC browsertest.

content/browser/media/webrtc_getusermedia_browsertest.cc

Index: content/browser/media/webrtc_getusermedia_browsertest.cc
diff --git a/content/browser/media/webrtc_getusermedia_browsertest.cc b/content/browser/media/webrtc_getusermedia_browsertest.cc
index 8821d64f458ac2e53e5f538e02e86b63b89a544a..e096bbb359fd39c6f1e4df386b0b6da1d45f3384 100644
--- a/content/browser/media/webrtc_getusermedia_browsertest.cc
+++ b/content/browser/media/webrtc_getusermedia_browsertest.cc
@@ -7,6 +7,7 @@
 #include "base/json/json_reader.h"
 #include "base/strings/stringprintf.h"
 #include "base/test/trace_event_analyzer.h"
+#include "base/timer/elapsed_timer.h"
 #include "base/values.h"
 #include "content/browser/media/webrtc_internals.h"
 #include "content/browser/web_contents/web_contents_impl.h"
@@ -81,6 +82,14 @@ class WebRtcGetUserMediaBrowserTest: public WebRtcContentBrowserTest,
   WebRtcGetUserMediaBrowserTest() : trace_log_(NULL) {}
   virtual ~WebRtcGetUserMediaBrowserTest() {}
 
+  virtual void TearDown() OVERRIDE {
+    LOG(INFO) << "Entering teardown; " << timer_.Elapsed().InSeconds()

[tommi (sloooow) - chröme, 2014/07/07 09:35:06]

We don't use LOG(INFO) anymore.  VLOG(1)?

[phoglund_chromium, 2014/07/07 09:48:40]

VLOG(1) logs don't seem to be visible by default in the bot logs unfortunately,
and they need to be to be useful (since the issue I'm analyzing only repros on
the bots)

+              << " seconds elapsed.";
+    WebRtcContentBrowserTest::TearDown();
+    LOG(INFO) << "Exiting teardown; " << timer_.Elapsed().InSeconds()
+              << " seconds elapsed.";
+  }
+
   virtual void SetUpCommandLine(CommandLine* command_line) OVERRIDE {
     WebRtcContentBrowserTest::SetUpCommandLine(command_line);
 
@@ -236,10 +245,14 @@ class WebRtcGetUserMediaBrowserTest: public WebRtcContentBrowserTest,
     ASSERT_FALSE(video_ids->empty());
   }
 
+  // TODO(phoglund): Remove when done debugging https://crbug.com/387895.
+  base::ElapsedTimer timer_;

[tommi (sloooow) - chröme, 2014/07/07 09:35:06]

protected?

[phoglund_chromium, 2014/07/07 09:48:40]

Done.

+
  private:
   base::debug::TraceLog* trace_log_;
   scoped_refptr<base::RefCountedString> recorded_trace_data_;
   scoped_refptr<MessageLoopRunner> message_loop_runner_;
+

[tommi (sloooow) - chröme, 2014/07/07 09:35:06]

remove

[phoglund_chromium, 2014/07/07 09:48:40]

Done.

 };
 
 static const bool kRunTestsWithFlag[] = { false, true };
@@ -353,6 +366,9 @@ IN_PROC_BROWSER_TEST_P(WebRtcGetUserMediaBrowserTest,
                        GetUserMediaWithMandatorySourceID) {
   ASSERT_TRUE(embedded_test_server()->InitializeAndWaitUntilReady());
 
+  LOG(INFO) << "HTTP server ready; " << timer_.Elapsed().InSeconds()
+            << " seconds elapsed.";
+
   std::vector<std::string> audio_ids;
   std::vector<std::string> video_ids;
   GetInputDevices(&audio_ids, &video_ids);
@@ -371,7 +387,12 @@ IN_PROC_BROWSER_TEST_P(WebRtcGetUserMediaBrowserTest,
               *audio_it,
               *video_it)));
     }
+    LOG(INFO) << "Tested one combination; " << timer_.Elapsed().InSeconds()
+              << " seconds elapsed.";
   }
+
+  LOG(INFO) << "End test body; " << timer_.Elapsed().InSeconds()
+            << " seconds elapsed.";
 }
 
 IN_PROC_BROWSER_TEST_P(WebRtcGetUserMediaBrowserTest,