Implement timing metrics for UrlRequest

components/cronet/android/test/javatests/src/org/chromium/net/RequestFinishedInfoTest.java

Index: components/cronet/android/test/javatests/src/org/chromium/net/RequestFinishedInfoTest.java
diff --git a/components/cronet/android/test/javatests/src/org/chromium/net/RequestFinishedInfoTest.java b/components/cronet/android/test/javatests/src/org/chromium/net/RequestFinishedInfoTest.java
index b96cf5d7d46b19a9c2899fa4570792cb7ef0db09..3fc4edf6cf67c31b31c1cb768ea13f704e76d769 100644
--- a/components/cronet/android/test/javatests/src/org/chromium/net/RequestFinishedInfoTest.java
+++ b/components/cronet/android/test/javatests/src/org/chromium/net/RequestFinishedInfoTest.java
@@ -84,8 +84,8 @@ public class RequestFinishedInfoTest extends CronetTestBase {
         }
     }
 
-    private static class TestRequestFinishedListener extends RequestFinishedInfo.Listener {
-        private RequestFinishedInfo mRequestInfo;
+    static class TestRequestFinishedListener extends RequestFinishedInfo.Listener {

[xunjieli, 2016/09/20 21:53:33]

Instead of making these classes packet protected, can we move them to a new
class something like MetricsTestUtil.java? 

[mgersh, 2016/09/30 23:47:14]

Done.

+        RequestFinishedInfo mRequestInfo;
 
         public TestRequestFinishedListener(Executor executor) {
             super(executor);
@@ -97,9 +97,67 @@ public class RequestFinishedInfoTest extends CronetTestBase {
             assertNotNull(requestInfo);
             mRequestInfo = requestInfo;
         }
+
+        public void reset() {
+            mRequestInfo = null;
+        }
+    }
+
+    /**
+     * Check existence of all the timing metrics that apply to most test requests,
+     * except those that come from net::LoadTimingInfo::ConnectTiming.
+     * Also check some timing differences, focusing on things we can't check with asserts in the
+     * CronetMetrics constructor.
+     * Don't check push times here.
+     */
+    static void checkTimingMetrics(
+            RequestFinishedInfo.Metrics metrics, Date startTime, Date endTime) {
+        assertNotNull(metrics.getRequestStart());
+        assertTrue(metrics.getRequestStart().after(startTime));
+        assertNotNull(metrics.getSendingStart());
+        assertTrue(metrics.getSendingStart().after(startTime));
+        assertNotNull(metrics.getSendingEnd());
+        assertTrue(metrics.getSendingEnd().before(endTime));
+        assertNotNull(metrics.getResponseStart());
+        assertTrue(metrics.getResponseStart().after(startTime));
+        assertNotNull(metrics.getResponseEnd());
+        assertTrue(metrics.getResponseEnd().before(endTime));
+        // Entire request should take more than 0 ms
+        assertTrue(metrics.getResponseEnd().getTime() - metrics.getRequestStart().getTime() > 0);
+    }
+
+    static void checkHasConnectTiming(
+            RequestFinishedInfo.Metrics metrics, Date startTime, Date endTime, boolean isSsl) {
+        assertNotNull(metrics.getDnsStart());
+        assertTrue(metrics.getDnsStart().after(startTime));
+        assertNotNull(metrics.getDnsEnd());
+        assertTrue(metrics.getDnsEnd().before(endTime));
+        assertNotNull(metrics.getConnectStart());
+        assertTrue(metrics.getConnectStart().after(startTime));
+        assertNotNull(metrics.getConnectEnd());
+        assertTrue(metrics.getConnectEnd().before(endTime));
+        if (isSsl) {
+            assertNotNull(metrics.getSslStart());
+            assertTrue(metrics.getSslStart().after(startTime));
+            assertNotNull(metrics.getSslEnd());
+            assertTrue(metrics.getSslEnd().before(endTime));
+        } else {
+            assertNull(metrics.getSslStart());
+            assertNull(metrics.getSslEnd());
+        }
+    }
+
+    static void checkNoConnectTiming(RequestFinishedInfo.Metrics metrics) {

[xunjieli, 2016/09/20 21:53:33]

It will be great if you can move these to a standalone Java file, so they can be
reused. It's a bit uncommon to reuse methods from a Test file.

[mgersh, 2016/09/30 23:47:14]

Done.

+        assertNull(metrics.getDnsStart());
+        assertNull(metrics.getDnsEnd());
+        assertNull(metrics.getSslStart());
+        assertNull(metrics.getSslEnd());
+        assertNull(metrics.getConnectStart());
+        assertNull(metrics.getConnectEnd());
     }
 
     @SmallTest
+    @OnlyRunNativeCronet
     @Feature({"Cronet"})
     @SuppressWarnings("deprecation")
     public void testRequestFinishedListener() throws Exception {
@@ -111,11 +169,13 @@ public class RequestFinishedInfoTest extends CronetTestBase {
         TestUrlRequestCallback callback = new TestUrlRequestCallback();
         UrlRequest.Builder urlRequestBuilder = new UrlRequest.Builder(
                 mUrl, callback, callback.getExecutor(), mTestFramework.mCronetEngine);
+        Date startTime = new Date();
         urlRequestBuilder.addRequestAnnotation("request annotation")
                 .addRequestAnnotation(this)
                 .build()
                 .start();
         callback.blockForDone();
+        Date endTime = new Date();
         testExecutor.runAllTasks();
 
         RequestFinishedInfo requestInfo = requestFinishedListener.mRequestInfo;
@@ -126,13 +186,21 @@ public class RequestFinishedInfoTest extends CronetTestBase {
                 new HashSet<Object>(requestInfo.getAnnotations()));
         RequestFinishedInfo.Metrics metrics = requestInfo.getMetrics();
         assertNotNull("RequestFinishedInfo.getMetrics() must not be null", metrics);
+        // Check old (deprecated) timing metrics
         assertTrue(metrics.getTotalTimeMs() > 0);
         assertTrue(metrics.getTotalTimeMs() >= metrics.getTtfbMs());
+        // Check new timing metrics
+        checkTimingMetrics(metrics, startTime, endTime);
+        checkHasConnectTiming(metrics, startTime, endTime, false);
+        assertNull(metrics.getPushStart());
+        assertNull(metrics.getPushEnd());
+        // Check data use metrics
         assertTrue(metrics.getReceivedBytesCount() > 0);
         mTestFramework.mCronetEngine.shutdown();
     }
 
     @SmallTest
+    @OnlyRunNativeCronet
     @Feature({"Cronet"})
     @SuppressWarnings("deprecation")
     public void testRequestFinishedListenerDirectExecutor() throws Exception {
@@ -144,11 +212,13 @@ public class RequestFinishedInfoTest extends CronetTestBase {
         TestUrlRequestCallback callback = new TestUrlRequestCallback();
         UrlRequest.Builder urlRequestBuilder = new UrlRequest.Builder(
                 mUrl, callback, callback.getExecutor(), mTestFramework.mCronetEngine);
+        Date startTime = new Date();
         urlRequestBuilder.addRequestAnnotation("request annotation")
                 .addRequestAnnotation(this)
                 .build()
                 .start();
         callback.blockForDone();
+        Date endTime = new Date();
 
         RequestFinishedInfo requestInfo = requestFinishedListener.mRequestInfo;
         assertNotNull("RequestFinishedInfo.Listener must be called", requestInfo);
@@ -160,11 +230,14 @@ public class RequestFinishedInfoTest extends CronetTestBase {
         assertNotNull("RequestFinishedInfo.getMetrics() must not be null", metrics);
         assertTrue(metrics.getTotalTimeMs() > 0);
         assertTrue(metrics.getTotalTimeMs() >= metrics.getTtfbMs());
+        checkTimingMetrics(metrics, startTime, endTime);
+        checkHasConnectTiming(metrics, startTime, endTime, false);
         assertTrue(metrics.getReceivedBytesCount() > 0);
         mTestFramework.mCronetEngine.shutdown();
     }
 
     @SmallTest
+    @OnlyRunNativeCronet
     @Feature({"Cronet"})
     @SuppressWarnings("deprecation")
     public void testRequestFinishedListenerDifferentThreads() throws Exception {
@@ -177,11 +250,13 @@ public class RequestFinishedInfoTest extends CronetTestBase {
         TestUrlRequestCallback callback = new TestUrlRequestCallback();
         UrlRequest.Builder urlRequestBuilder = new UrlRequest.Builder(
                 mUrl, callback, callback.getExecutor(), mTestFramework.mCronetEngine);
+        Date startTime = new Date();
         urlRequestBuilder.addRequestAnnotation("request annotation")
                 .addRequestAnnotation(this)
                 .build()
                 .start();
         callback.blockForDone();
+        Date endTime = new Date();
         testExecutor.joinAll();
 
         RequestFinishedInfo firstRequestInfo = firstListener.mRequestInfo;
@@ -200,16 +275,21 @@ public class RequestFinishedInfoTest extends CronetTestBase {
         assertNotNull("RequestFinishedInfo.getMetrics() must not be null", firstMetrics);
         assertTrue(firstMetrics.getTotalTimeMs() > 0);
         assertTrue(firstMetrics.getTotalTimeMs() >= firstMetrics.getTtfbMs());
+        checkTimingMetrics(firstMetrics, startTime, endTime);
+        checkHasConnectTiming(firstMetrics, startTime, endTime, false);
         assertTrue(firstMetrics.getReceivedBytesCount() > 0);
         RequestFinishedInfo.Metrics secondMetrics = secondRequestInfo.getMetrics();
         assertNotNull("RequestFinishedInfo.getMetrics() must not be null", secondMetrics);
         assertTrue(secondMetrics.getTotalTimeMs() > 0);
         assertTrue(secondMetrics.getTotalTimeMs() >= secondMetrics.getTtfbMs());
+        checkTimingMetrics(secondMetrics, startTime, endTime);
+        checkHasConnectTiming(secondMetrics, startTime, endTime, false);
         assertTrue(secondMetrics.getReceivedBytesCount() > 0);
         mTestFramework.mCronetEngine.shutdown();
     }
 
     @SmallTest
+    @OnlyRunNativeCronet
     @Feature({"Cronet"})
     @SuppressWarnings("deprecation")
     public void testRequestFinishedListenerFailedRequest() throws Exception {
@@ -222,8 +302,10 @@ public class RequestFinishedInfoTest extends CronetTestBase {
         TestUrlRequestCallback callback = new TestUrlRequestCallback();
         UrlRequest.Builder urlRequestBuilder = new UrlRequest.Builder(connectionRefusedUrl,
                 callback, callback.getExecutor(), mTestFramework.mCronetEngine);
+        Date startTime = new Date();
         urlRequestBuilder.build().start();
         callback.blockForDone();
+        Date endTime = new Date();
         assertTrue(callback.mOnErrorCalled);
         testExecutor.runAllTasks();
 
@@ -236,11 +318,25 @@ public class RequestFinishedInfoTest extends CronetTestBase {
         // The failure is occasionally fast enough that time reported is 0, so just check for null
         assertNotNull(metrics.getTotalTimeMs());
         assertNull(metrics.getTtfbMs());
+
+        // Check the timing metrics
+        assertNotNull(metrics.getRequestStart());
+        assertTrue(metrics.getRequestStart().after(startTime));
+        checkNoConnectTiming(metrics);
+        assertNull(metrics.getSendingStart());
+        assertNull(metrics.getSendingEnd());
+        assertNull(metrics.getResponseStart());
+        assertNotNull(metrics.getResponseEnd());
+        assertTrue(metrics.getResponseEnd().before(endTime));
+        // Entire request should take more than 0 ms
+        assertTrue(metrics.getResponseEnd().getTime() - metrics.getRequestStart().getTime() > 0);
+
         assertTrue(metrics.getReceivedBytesCount() == null || metrics.getReceivedBytesCount() == 0);
         mTestFramework.mCronetEngine.shutdown();
     }
 
     @SmallTest
+    @OnlyRunNativeCronet
     @Feature({"Cronet"})
     @SuppressWarnings("deprecation")
     public void testRequestFinishedListenerRemoved() throws Exception {
@@ -249,11 +345,12 @@ public class RequestFinishedInfoTest extends CronetTestBase {
         TestRequestFinishedListener requestFinishedListener =
                 new TestRequestFinishedListener(testExecutor);
         mTestFramework.mCronetEngine.addRequestFinishedListener(requestFinishedListener);
-        mTestFramework.mCronetEngine.removeRequestFinishedListener(requestFinishedListener);
         TestUrlRequestCallback callback = new TestUrlRequestCallback();
         UrlRequest.Builder urlRequestBuilder = new UrlRequest.Builder(
                 mUrl, callback, callback.getExecutor(), mTestFramework.mCronetEngine);
-        urlRequestBuilder.build().start();
+        UrlRequest request = urlRequestBuilder.build();
+        mTestFramework.mCronetEngine.removeRequestFinishedListener(requestFinishedListener);
+        request.start();
         callback.blockForDone();
         testExecutor.runAllTasks();