Cast: Make castv2 mirroring performance test run again

chrome/browser/extensions/api/cast_streaming/performance_test.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 <map>
 #include <vector>
 
 #include "base/basictypes.h"
 #include "base/command_line.h"
 #if defined(OS_MACOSX)
 #include "base/mac/mac_util.h"
 #endif
 #include "base/strings/stringprintf.h"
 #include "base/test/trace_event_analyzer.h"
+#include "base/time/default_tick_clock.h"
 #include "base/win/windows_version.h"
 #include "chrome/browser/extensions/extension_apitest.h"
 #include "chrome/browser/extensions/extension_service.h"
 #include "chrome/browser/extensions/extension_test_message_listener.h"
 #include "chrome/browser/extensions/tab_helper.h"
 #include "chrome/browser/profiles/profile.h"
 #include "chrome/browser/ui/fullscreen/fullscreen_controller.h"
 #include "chrome/common/chrome_switches.h"
 #include "chrome/common/chrome_version_info.h"
 #include "chrome/test/base/test_launcher_utils.h"
@@ skipping 40 matching lines @@
                                  // on the command line.  This is required for
                                  // tests that run on GPU.
   kDisableVsync        = 1 << 1, // Do not limit framerate to vertical refresh.
                                  // when on GPU, nor to 60hz when not on GPU.
   kSmallWindow         = 1 << 2, // 1 = 800x600, 0 = 2000x1000
   k24fps               = 1 << 3, // use 24 fps video
   k30fps               = 1 << 4, // use 30 fps video
   k60fps               = 1 << 5, // use 60 fps video
   kProxyWifi           = 1 << 6, // Run UDP through UDPProxy wifi profile
   kProxyEvil           = 1 << 7, // Run UDP through UDPProxy evil profile
+  kSlowClock           = 1 << 8, // Receiver clock is 10 seconds slow
+  kFastClock           = 1 << 9, // Receiver clock is 10 seconds fast
+};
+
+class SkewedTickClock : public base::DefaultTickClock {
+ public:
+  explicit SkewedTickClock(const base::TimeDelta& delta) : delta_(delta) {
+  }
+  virtual base::TimeTicks NowTicks() OVERRIDE {
+    return DefaultTickClock::NowTicks() + delta_;
+  }
+ private:
+  base::TimeDelta delta_;
 };
 
 // We log one of these for each call to OnAudioFrame/OnVideoFrame.
 struct TimeData {
   TimeData(uint16 frame_no_, base::TimeTicks render_time_) :
       frame_no(frame_no_),
       render_time(render_time_) {
   }
   // The unit here is video frames, for audio data there can be duplicates.
   // This was decoded from the actual audio/video data.
@@ skipping 30 matching lines @@
              const std::string& unit) {
     if (num_values >= 20) {
       perf_test::PrintResultMeanAndError(measurement,
                                          modifier,
                                          trace,
                                          AsString(),
                                          unit,
                                          true);
     } else {
       LOG(ERROR) << "Not enough events for "
-                 << measurement << " " << modifier << " " << trace;
+                 << measurement << modifier << " " << trace;
     }
   }
 
   size_t num_values;
   double mean;
   double std_dev;
 };
 
 // This function checks how smooth the data in |data| is.
 // It computes the average error of deltas and the average delta.
@@ skipping 148 matching lines @@
     if (HasFlag(k24fps))
       suffix += "_24fps";
     if (HasFlag(k30fps))
       suffix += "_30fps";
     if (HasFlag(k60fps))
       suffix += "_60fps";
     if (HasFlag(kProxyWifi))
       suffix += "_wifi";
     if (HasFlag(kProxyEvil))
       suffix += "_evil";
+    if (HasFlag(kSlowClock))
+      suffix += "_slow";
+    if (HasFlag(kFastClock))
+      suffix += "_fast";
     return suffix;
   }
 
   int getfps() {
     if (HasFlag(k24fps))
       return 24;
     if (HasFlag(k30fps))
       return 30;
     if (HasFlag(k60fps))
       return 60;
@@ skipping 56 matching lines @@
   }
 
   void GetTraceEvents(trace_analyzer::TraceAnalyzer* analyzer,
                       const std::string& event_name,
                       trace_analyzer::TraceEventVector* events) {
     trace_analyzer::Query query =
         trace_analyzer::Query::EventNameIs(event_name) &&
         (trace_analyzer::Query::EventPhaseIs(TRACE_EVENT_PHASE_BEGIN) ||
          trace_analyzer::Query::EventPhaseIs(TRACE_EVENT_PHASE_ASYNC_BEGIN) ||
          trace_analyzer::Query::EventPhaseIs(TRACE_EVENT_PHASE_FLOW_BEGIN) ||
-         trace_analyzer::Query::EventPhaseIs(TRACE_EVENT_PHASE_INSTANT));
+         trace_analyzer::Query::EventPhaseIs(TRACE_EVENT_PHASE_INSTANT) ||
+         trace_analyzer::Query::EventPhaseIs(TRACE_EVENT_PHASE_COMPLETE));
     analyzer->FindEvents(query, events);
   }
 
   // The key contains the name of the argument and the argument.
   typedef std::pair<std::string, double> EventMapKey;
   typedef std::map<EventMapKey, const trace_analyzer::TraceEvent*> EventMap;
 
   // Make events findable by their arguments, for instance, if an
   // event has a "timestamp": 238724 argument, the map will contain
   // pair<"timestamp", 238724> -> &event.  All arguments are indexed.
@@ skipping 166 matching lines @@
 
     ASSERT_EQ(1,
               (HasFlag(k24fps) ? 1 : 0) +
               (HasFlag(k30fps) ? 1 : 0) +
               (HasFlag(k60fps) ? 1 : 0));
 
     net::IPEndPoint receiver_end_point = GetFreeLocalPort();
 
     // Start the in-process receiver that examines audio/video for the expected
     // test patterns.
+    base::TimeDelta delta = base::TimeDelta::FromSeconds(0);
+    if (HasFlag(kFastClock)) {
+      delta = base::TimeDelta::FromSeconds(10);
+    }
+    if (HasFlag(kSlowClock)) {
+      delta = base::TimeDelta::FromSeconds(-10);
+    }
     scoped_refptr<media::cast::StandaloneCastEnvironment> cast_environment(
-        new media::cast::StandaloneCastEnvironment);
+        new media::cast::StandaloneCastEnvironment(
+            make_scoped_ptr<base::TickClock>(new SkewedTickClock(delta))));
     TestPatternReceiver* const receiver =
         new TestPatternReceiver(cast_environment, receiver_end_point);
     receiver->Start();
 
     scoped_ptr<media::cast::test::UDPProxy> udp_proxy;
     if (HasFlag(kProxyWifi) || HasFlag(kProxyEvil)) {
       net::IPEndPoint proxy_end_point = GetFreeLocalPort();
       if (HasFlag(kProxyWifi)) {
         udp_proxy = media::cast::test::UDPProxy::Create(
             proxy_end_point,
             receiver_end_point,
             media::cast::test::WifiNetwork().Pass(),
             media::cast::test::WifiNetwork().Pass(),
             NULL);
       } else if (HasFlag(kProxyEvil)) {
         udp_proxy = media::cast::test::UDPProxy::Create(
             proxy_end_point,
             receiver_end_point,
             media::cast::test::EvilNetwork().Pass(),
             media::cast::test::EvilNetwork().Pass(),
             NULL);
       }
       receiver_end_point = proxy_end_point;
     }
 
     std::string json_events;
-    ASSERT_TRUE(tracing::BeginTracing("test_fps,mirroring,cast_perf_test"));
+    ASSERT_TRUE(tracing::BeginTracing(
+        "renderer_host,mirroring,cast_perf_test"));
     const std::string page_url = base::StringPrintf(
         "performance%d.html?port=%d",
         getfps(),
         receiver_end_point.port());
     ASSERT_TRUE(RunExtensionSubtest("cast_streaming", page_url)) << message_;
     ASSERT_TRUE(tracing::EndTracing(&json_events));
     receiver->Stop();
 
     // Stop all threads, removes the need for synchronization when analyzing
     // the data.
     cast_environment->Shutdown();
     scoped_ptr<trace_analyzer::TraceAnalyzer> analyzer;
     analyzer.reset(trace_analyzer::TraceAnalyzer::Create(json_events));
     analyzer->AssociateAsyncBeginEndEvents();
 
     // Only one of these PrintResults should actually print something.
     // The printed result will be the average time between frames in the
     // browser window.
-    MeanAndError sw_frame_data = AnalyzeTraceDistance(analyzer.get(),
-                                                      "TestFrameTickSW");
-    MeanAndError frame_data = AnalyzeTraceDistance(analyzer.get(),
-                                                   "TestFrameTickGPU");
-    if (frame_data.num_values == 0) {
-      frame_data = sw_frame_data;
-    }
+    MeanAndError frame_data = AnalyzeTraceDistance(
+        analyzer.get(),
+#ifdef OS_MACOSX
+        "RenderWidgetHostImpl::OnCompositorSurfaceBuffersSwapped"
+#else
+        "RenderWidgetHostImpl::OnSwapCompositorFrame"
+#endif

[piman, 2014/04/08 22:46:03]

This hardcodes the knowledge that "on mac we don't use delegated rendering" in
the test, which is unfortunate (it won't be true forever).
Maybe we can have both methods generate the same event "got a frame from the
renderer", so that we don't need to hardcode this here?

[hubbe, 2014/04/08 22:58:29]

Now uses a special trace event which is normally OFF.

+        );
     EXPECT_GT(frame_data.num_values, 0UL);
     // Lower is better.
     frame_data.Print(test_name,
                      GetSuffixForTestFlags(),
                      "time_between_frames",
                      "ms");
 
     // This prints out the average time between capture events.
     // As the capture frame rate is capped at 30fps, this score
     // cannot get any better than (lower) 33.33 ms.
@@ skipping 20 matching lines @@
 // (it's a prefix for the generated test cases)
 INSTANTIATE_TEST_CASE_P(
     ,
     CastV2PerformanceTest,
     testing::Values(
         kUseGpu | k24fps,
         kUseGpu | k30fps,
         kUseGpu | k60fps,
         kUseGpu | k24fps | kDisableVsync,
         kUseGpu | k30fps | kProxyWifi,
-        kUseGpu | k30fps | kProxyEvil));
+        kUseGpu | k30fps | kProxyEvil,
+        kUseGpu | k30fps | kSlowClock,
+        kUseGpu | k30fps | kFastClock));