CC serialization perftests: more accurate "num runs in 2 seconds".

cc/ipc/cc_serialization_perftest.cc

 // Copyright 2013 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 <utility>
 
 #include "base/test/launcher/unit_test_launcher.h"
 #include "base/test/test_suite.h"
 #include "cc/ipc/cc_param_traits.h"
 #include "cc/ipc/compositor_frame.mojom.h"
@@ skipping 42 matching lines @@
       ReadMessage(&msg, &compositor_frame);
     }
 
     base::TimeTicks start = base::TimeTicks::Now();
     base::TimeTicks end =
         start + base::TimeDelta::FromMilliseconds(kTimeLimitMillis);
     base::TimeDelta min_time;
     size_t count = 0;
     while (start < end) {
       for (int i = 0; i < kTimeCheckInterval; ++i) {
-        ++count;
+        base::TimeTicks now = base::TimeTicks::Now();
+        if (now < end)
+          ++count;
         CompositorFrame compositor_frame;
         ReadMessage(&msg, &compositor_frame);
       }
 
       base::TimeTicks now = base::TimeTicks::Now();
       if (now - start < min_time || min_time.is_zero())
         min_time = now - start;
       start = base::TimeTicks::Now();
     }
 
@@ skipping 12 matching lines @@
       IPC::ParamTraits<CompositorFrame>::Write(&msg, frame);
     }
 
     base::TimeTicks start = base::TimeTicks::Now();
     base::TimeTicks end =
         start + base::TimeDelta::FromMilliseconds(kTimeLimitMillis);
     base::TimeDelta min_time;
     size_t count = 0;
     while (start < end) {
       for (int i = 0; i < kTimeCheckInterval; ++i) {
+        base::TimeTicks now = base::TimeTicks::Now();
+        if (now < end)
+          ++count;
         IPC::Message msg(1, 2, IPC::Message::PRIORITY_NORMAL);
         IPC::ParamTraits<CompositorFrame>::Write(&msg, frame);
-        ++count;
       }
 
       base::TimeTicks now = base::TimeTicks::Now();
       if (now - start < min_time || min_time.is_zero())
         min_time = now - start;
       start = base::TimeTicks::Now();
     }
 
     perf_test::PrintResult(
         "ParamTraits serialization: min_frame_serialization_time", "",
@@ skipping 11 matching lines @@
       CompositorFrame compositor_frame;
       mojom::CompositorFrame::Deserialize(data, &compositor_frame);
     }
 
     base::TimeTicks start = base::TimeTicks::Now();
     base::TimeTicks end =
         start + base::TimeDelta::FromMilliseconds(kTimeLimitMillis);
     base::TimeDelta min_time;
     size_t count = 0;
     while (start < end) {
       for (int i = 0; i < kTimeCheckInterval; ++i) {

[danakj, 2016/07/29 22:04:56]

Just decrease kTimeCheckInterval for those tests and maybe EXPECT that it's
larger than some function of the number the test reports?

[yzshen1, 2016/07/29 22:12:12]

Decreasing the number of kTimeCheckInterval may affect the min_frame_*_time,
because that is an average of kTimeCheckInterval runs.

Is it a concern that we may invoke base::TimeTicks::Now() too many times? I
compared the numbers before/after the change, it seems the difference is
negligible.

WDYT? Thanks!

[danakj, 2016/07/29 22:14:02]

Ah ok.

+        base::TimeTicks now = base::TimeTicks::Now();
+        if (now < end)
+          ++count;

[danakj, 2016/07/29 22:14:02]

Can you do this at the bottom of the loop. And you should be able to reuse this
Now() value below the loop if you scope the variable right.

[yzshen1, 2016/07/31 06:57:17]

Done.

         CompositorFrame compositor_frame;
         mojom::CompositorFrame::Deserialize(data, &compositor_frame);
-        ++count;
       }
 
       base::TimeTicks now = base::TimeTicks::Now();
       if (now - start < min_time || min_time.is_zero())
         min_time = now - start;
       start = base::TimeTicks::Now();
     }
 
     perf_test::PrintResult(
         "StructTraits deserialization min_frame_deserialization_time", "",
@@ skipping 11 matching lines @@
       DCHECK_GT(data.size(), 0u);
     }
 
     base::TimeTicks start = base::TimeTicks::Now();
     base::TimeTicks end =
         start + base::TimeDelta::FromMilliseconds(kTimeLimitMillis);
     base::TimeDelta min_time;
     size_t count = 0;
     while (start < end) {
       for (int i = 0; i < kTimeCheckInterval; ++i) {
+        base::TimeTicks now = base::TimeTicks::Now();
+        if (now < end)
+          ++count;
         mojo::Array<uint8_t> data = mojom::CompositorFrame::Serialize(&frame);
         DCHECK_GT(data.size(), 0u);
-        ++count;
       }
 
       base::TimeTicks now = base::TimeTicks::Now();
       if (now - start < min_time || min_time.is_zero())
         min_time = now - start;
       start = base::TimeTicks::Now();
     }
 
     perf_test::PrintResult(
         "StructTraits serialization min_frame_serialization_time", "",
@@ skipping 68 matching lines @@
                          UseSingleSharedQuadState::NO);
 }
 
 TEST_F(CCSerializationPerfTest, DelegatedFrame_ManyRenderPasses_1000_100) {
   RunCompositorFrameTest("DelegatedFrame_ManyRenderPasses_10000_100", 100, 1000,
                          UseSingleSharedQuadState::NO);
 }
 
 }  // namespace
 }  // namespace cc