Temporarily adding timers to one WebRTC browsertest.

content/browser/media/webrtc_getusermedia_browsertest.cc

 // Copyright 2014 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 "base/command_line.h"
 #include "base/debug/trace_event_impl.h"
 #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"
 #include "content/public/common/content_switches.h"
 #include "content/public/test/browser_test_utils.h"
 #include "content/public/test/content_browser_test_utils.h"
 #include "content/public/test/test_utils.h"
 #include "content/shell/browser/shell.h"
 #include "content/test/webrtc_content_browsertest_base.h"
 #include "net/test/embedded_test_server/embedded_test_server.h"
@@ skipping 54 matching lines @@
 }  // namespace
 
 namespace content {
 
 class WebRtcGetUserMediaBrowserTest: public WebRtcContentBrowserTest,
                                      public testing::WithParamInterface<bool> {
  public:
   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);
 
     bool enable_audio_track_processing = GetParam();
     if (!enable_audio_track_processing)
       command_line->AppendSwitch(switches::kDisableAudioTrackProcessing);
   }
 
   void StartTracing() {
     CHECK(trace_log_ == NULL) << "Can only can start tracing once";
@@ skipping 135 matching lines @@
       if (kind == "audio") {
         audio_ids->push_back(device_id);
       } else if (kind == "video") {
         video_ids->push_back(device_id);
       }
     }
     ASSERT_FALSE(audio_ids->empty());
     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 };
 INSTANTIATE_TEST_CASE_P(WebRtcGetUserMediaBrowserTests,
                         WebRtcGetUserMediaBrowserTest,
                         testing::ValuesIn(kRunTestsWithFlag));
 
 // These tests will all make a getUserMedia call with different constraints and
 // see that the success callback is called. If the error callback is called or
 // none of the callbacks are called the tests will simply time out and fail.
@@ skipping 93 matching lines @@
 
   ExecuteJavascriptAndWaitForOk("getUserMediaAndRenderInSeveralVideoTags();");
 }
 
 
 
 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);
 
   GURL url(embedded_test_server()->GetURL("/media/getusermedia.html"));
 
   // Test all combinations of mandatory sourceID;
   for (std::vector<std::string>::const_iterator video_it = video_ids.begin();
        video_it != video_ids.end(); ++video_it) {
     for (std::vector<std::string>::const_iterator audio_it = audio_ids.begin();
          audio_it != audio_ids.end(); ++audio_it) {
       NavigateToURL(shell(), url);
       EXPECT_EQ(kOK, ExecuteJavascriptAndReturnResult(
           GenerateGetUserMediaWithMandatorySourceID(
               kGetUserMediaAndStop,
               *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,
                        GetUserMediaWithInvalidMandatorySourceID) {
   ASSERT_TRUE(embedded_test_server()->InitializeAndWaitUntilReady());
 
   std::vector<std::string> audio_ids;
   std::vector<std::string> video_ids;
   GetInputDevices(&audio_ids, &video_ids);
 
@@ skipping 240 matching lines @@
     {640, 640, 360, 360, 10, 30},
     {640, 640, 480, 480, 10, 30},
     {960, 960, 720, 720, 10, 30},
     {1280, 1280, 720, 720, 10, 30}};
 
 INSTANTIATE_TEST_CASE_P(UserMedia,
                         WebRtcConstraintsBrowserTest,
                         testing::ValuesIn(kAllUserMediaSizes));
 
 }  // namespace content