[Cronet] Basic performance testing.

This adds some very basic performance testing to the Cronet test suite.

Bug: 706515
Cq-Include-Trybots: master.tryserver.chromium.android:android_cronet_tester;master.tryserver.chromium.mac:ios-simulator-cronet
Change-Id: I64f4a24baf8fe92d2d9d865752cbff4bcb2df12c
Reviewed-on: https://chromium-review.googlesource.com/649991Reviewed-by: Misha Efimov <mef@chromium.org>
Reviewed-by: Andrei Kapishnikov <kapishnikov@chromium.org>
Commit-Queue: Andrei Kapishnikov <kapishnikov@chromium.org>
Cr-Commit-Position: refs/heads/master@{#512830}

components/cronet/ios/test/BUILD.gn

@@ -11,6 +11,7 @@ test("cronet_test") {
     "cronet_acceptlang_test.mm",
     "cronet_http_test.mm",
     "cronet_netlog_test.mm",
+    "cronet_performance_test.mm",
     "cronet_pkp_test.mm",
     "cronet_prefs_test.mm",
     "cronet_quic_test.mm",

components/cronet/ios/test/cronet_http_test.mm

@@ -105,38 +105,6 @@ TEST_F(HttpTest, NSURLSessionReceivesData) {
                base::SysNSStringToUTF8([delegate_ responseBody]).c_str());
 }
 
-TEST_F(HttpTest, NSURLSessionReceivesBigHttpDataLoop) {
-  int iterations = 50;
-  long size = 10 * 1024 * 1024;
-  LOG(INFO) << "Downloading " << size << " bytes " << iterations << " times.";
-  NSTimeInterval elapsed_avg = 0;
-  NSTimeInterval elapsed_max = 0;
-  NSURL* url = net::NSURLWithGURL(GURL(TestServer::PrepareBigDataURL(size)));
-  for (int i = 0; i < iterations; ++i) {
-    [delegate_ reset];
-    __block BOOL block_used = NO;
-    NSURLSessionDataTask* task = [session_ dataTaskWithURL:url];
-    [Cronet setRequestFilterBlock:^(NSURLRequest* request) {
-      block_used = YES;
-      EXPECT_EQ([request URL], url);
-      return YES;
-    }];
-    NSDate* start = [NSDate date];
-    StartDataTaskAndWaitForCompletion(task);
-    NSTimeInterval elapsed = -[start timeIntervalSinceNow];
-    elapsed_avg += elapsed;
-    if (elapsed > elapsed_max)
-      elapsed_max = elapsed;
-    EXPECT_TRUE(block_used);
-    EXPECT_EQ(nil, [delegate_ error]);
-    EXPECT_EQ(size, [delegate_ totalBytesReceived]);
-  }
-  // Release the response buffer.
-  TestServer::ReleaseBigDataURL();
-  LOG(INFO) << "Elapsed Average:" << elapsed_avg * 1000 / iterations
-            << "ms Max:" << elapsed_max * 1000 << "ms";
-}
-
 TEST_F(HttpTest, GetGlobalMetricsDeltas) {
   NSData* delta1 = [Cronet getGlobalMetricsDeltas];
 

components/cronet/ios/test/cronet_performance_test.mm

+// Copyright 2017 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.
+
+#import <Cronet/Cronet.h>
+#import <Foundation/Foundation.h>
+
+#include <stdint.h>
+
+#include "base/logging.h"
+#include "base/mac/scoped_nsobject.h"
+#include "base/strings/stringprintf.h"
+#include "base/strings/sys_string_conversions.h"
+#include "components/cronet/ios/test/cronet_test_base.h"
+#include "components/cronet/ios/test/test_server.h"
+#include "components/grpc_support/test/quic_test_server.h"
+#include "net/base/mac/url_conversions.h"
+#include "net/base/net_errors.h"
+#include "net/cert/mock_cert_verifier.h"
+#include "testing/gtest/include/gtest/gtest.h"
+#include "testing/gtest_mac.h"
+#include "url/gurl.h"
+
+namespace {
+
+const int kTestIterations = 10;
+const BOOL kUseExternalUrl = NO;
+const int kDownloadSize = 19307439;  // used for internal server only
+const char* kExternalUrl = "https://www.gstatic.com/chat/hangouts/bg/davec.jpg";
+
+struct PerfResult {
+  NSTimeInterval total;
+  NSTimeInterval mean;
+  NSTimeInterval max;
+  int total_bytes_downloaded;
+  int failed_requests;
+  int total_requests;
+};
+
+struct TestConfig {
+  BOOL quic;
+  BOOL http2;
+  BOOL akd4;
+  BOOL cronet;
+};
+
+bool operator<(TestConfig a, TestConfig b) {
+  return std::tie(a.quic, a.http2, a.akd4, a.cronet) <
+         std::tie(b.quic, b.http2, b.akd4, b.cronet);
+}
+
+const TestConfig test_combinations[] = {
+    //  QUIC   HTTP2  AKD4   Cronet
+    { false, false, false, false, },
+    { false, false, false, true, },
+    { false, true, false, true, },
+    { true, false, false, true, },
+    { true, false, true, true, },
+};
+
+}  // namespace
+
+namespace cronet {
+
+class PerfTest : public CronetTestBase,
+                 public ::testing::WithParamInterface<TestConfig> {
+ public:
+  static void TearDownTestCase() {
+    NSMutableString* perf_data_acc = [NSMutableString stringWithCapacity:0];
+
+    LOG(INFO) << "Performance Data:";
+    for (auto const& entry : perf_test_results) {
+      NSString* formatted_entry = [NSString
+          stringWithFormat:
+              @"Quic %i\tHttp2 %i\tAKD4 %i\tCronet %i: Mean: %fs "
+              @"(%fmbps)\tMax: "
+              @"%fs with %i fails out of %i total requests.",
+              entry.first.quic, entry.first.http2, entry.first.akd4,
+              entry.first.cronet, entry.second.mean,
+              entry.second.total ? 8 * entry.second.total_bytes_downloaded /
+                                       entry.second.total / 10e6
+                                 : 0,
+              entry.second.max, entry.second.failed_requests,
+              entry.second.total_requests];
+
+      [perf_data_acc appendFormat:@"%@\n", formatted_entry];
+
+      LOG(INFO) << base::SysNSStringToUTF8(formatted_entry);
+    }
+
+    NSString* filename = [NSString
+        stringWithFormat:@"performance_metrics-%@.txt",
+                         [[NSDate date]
+                             descriptionWithLocale:[NSLocale currentLocale]]];
+    NSString* path =
+        [[[[[NSFileManager defaultManager] URLsForDirectory:NSDocumentDirectory
+                                                  inDomains:NSUserDomainMask]
+            lastObject] URLByAppendingPathComponent:filename] path];
+
+    NSData* filedata = [perf_data_acc dataUsingEncoding:NSUTF8StringEncoding];
+    [[NSFileManager defaultManager] createFileAtPath:path
+                                            contents:filedata
+                                          attributes:nil];
+  }
+
+ protected:
+  static std::map<TestConfig, PerfResult> perf_test_results;
+
+  PerfTest() {}
+  ~PerfTest() override {}
+
+  void SetUp() override {
+    CronetTestBase::SetUp();
+    TestServer::Start();
+
+    // These are normally called by StartCronet(), but because of the test
+    // parameterization we need to call them inline, and not use StartCronet()
+    [Cronet setUserAgent:@"CronetTest/1.0.0.0" partial:NO];
+    [Cronet setQuicEnabled:GetParam().quic];
+    [Cronet setHttp2Enabled:GetParam().http2];
+    [Cronet setAcceptLanguages:@"en-US,en"];
+    if (kUseExternalUrl) {
+      NSString* external_host = [[NSURL
+          URLWithString:[NSString stringWithUTF8String:kExternalUrl]] host];
+      [Cronet addQuicHint:external_host port:443 altPort:443];
+    } else {
+      [Cronet addQuicHint:@"test.example.com" port:443 altPort:443];
+    }
+    [Cronet enableTestCertVerifierForTesting];
+    [Cronet setHttpCacheType:CRNHttpCacheTypeDisabled];
+    if (GetParam().akd4) {
+      [Cronet setExperimentalOptions:
+                  @"{\"QUIC\":{\"connection_options\":\"AKD4\"}}"];
+    }
+
+    [Cronet start];
+
+    NSString* rules = base::SysUTF8ToNSString(
+        base::StringPrintf("MAP test.example.com 127.0.0.1:%d,"
+                           "MAP notfound.example.com ~NOTFOUND",
+                           grpc_support::GetQuicTestServerPort()));
+    [Cronet setHostResolverRulesForTesting:rules];
+    // This is the end of the behavior normally performed by StartCronet()
+
+    NSURLSessionConfiguration* config =
+        [NSURLSessionConfiguration ephemeralSessionConfiguration];
+    config.requestCachePolicy = NSURLRequestReloadIgnoringLocalCacheData;
+    if (GetParam().cronet) {
+      [Cronet registerHttpProtocolHandler];
+      [Cronet installIntoSessionConfiguration:config];
+    } else {
+      [Cronet unregisterHttpProtocolHandler];
+    }
+    session_ = [NSURLSession sessionWithConfiguration:config
+                                             delegate:delegate_
+                                        delegateQueue:nil];
+  }
+
+  void TearDown() override {
+    TestServer::Shutdown();
+
+    [Cronet shutdownForTesting];
+    CronetTestBase::TearDown();
+  }
+
+  NSURLSession* session_;
+};
+
+// static
+std::map<TestConfig, PerfResult> PerfTest::perf_test_results;
+
+TEST_P(PerfTest, NSURLSessionReceivesImageLoop) {
+  int iterations = kTestIterations;
+  int failed_iterations = 0;
+  int total_bytes_received = 0;
+  NSTimeInterval elapsed_total = 0;
+  NSTimeInterval elapsed_max = 0;
+
+  int first_log = false;
+
+  LOG(INFO) << "Running with parameters: "
+            << "QUIC: " << GetParam().quic << "\t"
+            << "HTTP2: " << GetParam().http2 << "\t"
+            << "AKD4: " << GetParam().akd4 << "\t"
+            << "Cronet: " << GetParam().cronet << "\t";
+
+  NSURL* url;
+  if (kUseExternalUrl) {
+    url = net::NSURLWithGURL(GURL(kExternalUrl));
+  } else {
+    LOG(INFO) << "Downloading " << kDownloadSize << " bytes per iteration";
+    url =
+        net::NSURLWithGURL(GURL(TestServer::PrepareBigDataURL(kDownloadSize)));
+  }
+
+  for (int i = 0; i < iterations; ++i) {
+    __block BOOL block_used = NO;
+    NSURLSessionDataTask* task = [session_ dataTaskWithURL:url];
+    [Cronet setRequestFilterBlock:^(NSURLRequest* request) {
+      block_used = YES;
+      EXPECT_EQ([request URL], url);
+      return YES;
+    }];
+
+    NSDate* start = [NSDate date];
+    BOOL success = StartDataTaskAndWaitForCompletion(task);
+
+    if (!success) {
+      [task cancel];
+    }
+
+    NSTimeInterval elapsed = -[start timeIntervalSinceNow];
+
+    // Do not tolerate failures on internal server.
+    if (!kUseExternalUrl) {
+      CHECK(success && ![delegate_ errorPerTask][task]);
+    }
+
+    if (kUseExternalUrl && success && !first_log) {
+      LOG(INFO) << "Downloaded " << [delegate_ totalBytesReceivedPerTask][task]
+                << " bytes on first iteration.";
+      first_log = true;
+    }
+
+    if (!success) {
+      if ([delegate_ errorPerTask][task]) {
+        LOG(WARNING) << "Request failed during performance testing: "
+                     << base::SysNSStringToUTF8([[delegate_ errorPerTask][task]
+                            localizedDescription]);
+      } else {
+        LOG(WARNING) << "Request timed out during performance testing.";
+      }
+      ++failed_iterations;
+    } else {
+      // Checking that the correct amount of data was downloaded only makes
+      // sense if the request succeeded.
+      EXPECT_EQ([[delegate_ expectedContentLengthPerTask][task] intValue],
+                [[delegate_ totalBytesReceivedPerTask][task] intValue]);
+
+      elapsed_total += elapsed;
+      elapsed_max = MAX(elapsed, elapsed_max);
+
+      total_bytes_received +=
+          [[delegate_ totalBytesReceivedPerTask][task] intValue];
+    }
+
+    EXPECT_EQ(block_used, GetParam().cronet);
+  }
+
+  LOG(INFO) << "Elapsed Total:" << elapsed_total * 1000 << "ms";
+
+  // Reject performance data from too many failures.
+  if (kUseExternalUrl) {
+    CHECK(failed_iterations < iterations / 2);
+  }
+
+  perf_test_results[GetParam()] = {
+      elapsed_total,        elapsed_total / iterations, elapsed_max,
+      total_bytes_received, failed_iterations,          iterations};
+
+  if (!kUseExternalUrl) {
+    TestServer::ReleaseBigDataURL();
+  }
+}
+
+INSTANTIATE_TEST_CASE_P(Loops,
+                        PerfTest,
+                        ::testing::ValuesIn(test_combinations));
+}  // namespace cronet

components/cronet/ios/test/cronet_test_base.h

@@ -31,21 +31,33 @@ class Thread;
 @interface TestDelegate : NSObject<NSURLSessionDataDelegate>
 
 // Error the request this delegate is attached to failed with, if any.
-@property(retain, atomic) NSError* error;
+@property(retain, atomic)
+    NSMutableDictionary<NSURLSessionTask*, NSError*>* errorPerTask;
 
 // Contains total amount of received data.
-@property(readonly) long totalBytesReceived;
+@property(readonly) NSMutableDictionary<NSURLSessionDataTask*, NSNumber*>*
+    totalBytesReceivedPerTask;
+
+@property(readonly) NSMutableDictionary<NSURLSessionDataTask*, NSNumber*>*
+    expectedContentLengthPerTask;
 
 // Resets the delegate, so it can be used again for another request.
 - (void)reset;
 
 // Contains the response body.
-- (NSString*)responseBody;
+- (NSString*)responseBody:(NSURLSessionDataTask*)task;
 
-/// Waits for request to complete.
+/// Waits for a single request to complete.
 
 /// @return  |NO| if the request didn't complete and the method timed-out.
-- (BOOL)waitForDone;
+- (BOOL)waitForDone:(NSURLSessionDataTask*)task
+        withTimeout:(int64_t)deadline_ns;
+
+// Convenience functions for single-task delegates
+- (NSError*)error;
+- (long)totalBytesReceived;
+- (long)expectedContentLength;
+- (NSString*)responseBody;
 
 @end
 
@@ -65,7 +77,9 @@ class CronetTestBase : public ::testing::Test {
 
   void SetUp() override;
   void TearDown() override;
-  void StartDataTaskAndWaitForCompletion(NSURLSessionDataTask* task);
+  bool StartDataTaskAndWaitForCompletion(NSURLSessionDataTask* task,
+                                         int64_t deadline_ns = 20 *
+                                                               NSEC_PER_SEC);
   std::unique_ptr<net::MockCertVerifier> CreateMockCertVerifier(
       const std::vector<std::string>& certs,
       bool known_root);

components/cronet/ios/test/cronet_test_base.mm

@@ -15,48 +15,98 @@
 #pragma mark
 
 @implementation TestDelegate {
-  // Completion semaphore for this TestDelegate. When the request this delegate
-  // is attached to finishes (either successfully or with an error), this
-  // delegate signals this semaphore.
-  dispatch_semaphore_t _semaphore;
-}
+  // Dictionary which maps tasks to completion semaphores for this TestDelegate.
+  // When a request this delegate is attached to finishes (either successfully
+  // or with an error), this delegate signals that task's semaphore.
+  NSMutableDictionary<NSURLSessionTask*, dispatch_semaphore_t>* _semaphores;
 
-@synthesize error = _error;
-@synthesize totalBytesReceived = _totalBytesReceived;
+  NSMutableDictionary<NSURLSessionDataTask*, NSMutableArray<NSData*>*>*
+      _responseDataPerTask;
+}
 
-NSMutableArray<NSData*>* _responseData;
+@synthesize errorPerTask = _errorPerTask;
+@synthesize totalBytesReceivedPerTask = _totalBytesReceivedPerTask;
+@synthesize expectedContentLengthPerTask = _expectedContentLengthPerTask;
 
 - (id)init {
   if (self = [super init]) {
-    _semaphore = dispatch_semaphore_create(0);
+    _semaphores = [NSMutableDictionary dictionaryWithCapacity:0];
   }
   return self;
 }
 
 - (void)reset {
-  _responseData = nil;
-  _error = nil;
-  _totalBytesReceived = 0;
+  _responseDataPerTask = [NSMutableDictionary dictionaryWithCapacity:0];
+  _errorPerTask = [NSMutableDictionary dictionaryWithCapacity:0];
+  _totalBytesReceivedPerTask = [NSMutableDictionary dictionaryWithCapacity:0];
+  _expectedContentLengthPerTask =
+      [NSMutableDictionary dictionaryWithCapacity:0];
+}
+
+- (NSError*)error {
+  if ([_errorPerTask count] == 0)
+    return nil;
+
+  DCHECK([_errorPerTask count] == 1);
+  return [[_errorPerTask objectEnumerator] nextObject];
+}
+
+- (long)totalBytesReceived {
+  DCHECK([_totalBytesReceivedPerTask count] == 1);
+  return [[[_totalBytesReceivedPerTask objectEnumerator] nextObject] intValue];
+}
+
+- (long)expectedContentLength {
+  DCHECK([_expectedContentLengthPerTask count] == 1);
+  return
+      [[[_expectedContentLengthPerTask objectEnumerator] nextObject] intValue];
 }
 
 - (NSString*)responseBody {
-  if (_responseData == nil) {
+  if ([_responseDataPerTask count] == 0)
+    return nil;
+
+  DCHECK([_responseDataPerTask count] == 1);
+  NSURLSessionDataTask* task =
+      [[_responseDataPerTask keyEnumerator] nextObject];
+
+  return [self responseBody:task];
+}
+
+- (NSString*)responseBody:(NSURLSessionDataTask*)task {
+  if (_responseDataPerTask[task] == nil) {
     return nil;
   }
   NSMutableString* body = [NSMutableString string];
-  for (NSData* data in _responseData) {
+  for (NSData* data in _responseDataPerTask[task]) {
     [body appendString:[[NSString alloc] initWithData:data
                                              encoding:NSUTF8StringEncoding]];
   }
   VLOG(3) << "responseBody size:" << [body length]
-          << " chunks:" << [_responseData count];
+          << " chunks:" << [_responseDataPerTask[task] count];
   return body;
 }
 
-- (BOOL)waitForDone {
-  int64_t deadline_ns = 20 * NSEC_PER_SEC;
-  return dispatch_semaphore_wait(
-             _semaphore, dispatch_time(DISPATCH_TIME_NOW, deadline_ns)) == 0;
+- (dispatch_semaphore_t)getSemaphoreForTask:(NSURLSessionTask*)task {
+  @synchronized(_semaphores) {
+    if (!_semaphores[task]) {
+      _semaphores[task] = dispatch_semaphore_create(0);
+    }
+    return _semaphores[task];
+  }
+}
+
+// |timeout_ns|, if positive, specifies how long to wait before timing out in
+// nanoseconds, a value of 0 or less means do not ever time out.
+- (BOOL)waitForDone:(NSURLSessionDataTask*)task
+        withTimeout:(int64_t)timeout_ns {
+  dispatch_semaphore_t _semaphore = [self getSemaphoreForTask:task];
+  if (timeout_ns > 0) {
+    return dispatch_semaphore_wait(
+               _semaphore, dispatch_time(DISPATCH_TIME_NOW, timeout_ns)) == 0;
+  } else {
+    return dispatch_semaphore_wait(_semaphore, DISPATCH_TIME_FOREVER) == 0;
+  }
 }
 
 - (void)URLSession:(NSURLSession*)session
@@ -66,7 +116,10 @@ NSMutableArray<NSData*>* _responseData;
 - (void)URLSession:(NSURLSession*)session
                     task:(NSURLSessionTask*)task
     didCompleteWithError:(NSError*)error {
-  [self setError:error];
+  if (error)
+    _errorPerTask[task] = error;
+
+  dispatch_semaphore_t _semaphore = [self getSemaphoreForTask:task];
   dispatch_semaphore_signal(_semaphore);
 }
 
@@ -84,17 +137,27 @@ NSMutableArray<NSData*>* _responseData;
     didReceiveResponse:(NSURLResponse*)response
      completionHandler:(void (^)(NSURLSessionResponseDisposition disposition))
                            completionHandler {
+  _expectedContentLengthPerTask[dataTask] =
+      [NSNumber numberWithInt:[response expectedContentLength]];
   completionHandler(NSURLSessionResponseAllow);
 }
 
 - (void)URLSession:(NSURLSession*)session
           dataTask:(NSURLSessionDataTask*)dataTask
     didReceiveData:(NSData*)data {
-  _totalBytesReceived += [data length];
-  if (_responseData == nil) {
-    _responseData = [[NSMutableArray alloc] init];
+  if (_totalBytesReceivedPerTask[dataTask]) {
+    _totalBytesReceivedPerTask[dataTask] = [NSNumber
+        numberWithInt:[_totalBytesReceivedPerTask[dataTask] intValue] +
+                      [data length]];
+  } else {
+    _totalBytesReceivedPerTask[dataTask] =
+        [NSNumber numberWithInt:[data length]];
+  }
+
+  if (_responseDataPerTask[dataTask] == nil) {
+    _responseDataPerTask[dataTask] = [[NSMutableArray alloc] init];
   }
-  [_responseData addObject:data];
+  [_responseDataPerTask[dataTask] addObject:data];
 }
 
 - (void)URLSession:(NSURLSession*)session
@@ -120,13 +183,15 @@ void CronetTestBase::TearDown() {
   ::testing::Test::TearDown();
 }
 
-// Launches the supplied |task| and blocks until it completes, with a timeout
-// of 1 second.
-void CronetTestBase::StartDataTaskAndWaitForCompletion(
-    NSURLSessionDataTask* task) {
+// Launches the supplied |task| and blocks until it completes, with a default
+// timeout of 20 seconds.  |deadline_ns|, if specified, is in nanoseconds.
+// If |deadline_ns| is 0 or negative, the request will not time out.
+bool CronetTestBase::StartDataTaskAndWaitForCompletion(
+    NSURLSessionDataTask* task,
+    int64_t deadline_ns) {
   [delegate_ reset];
   [task resume];
-  CHECK([delegate_ waitForDone]);
+  return [delegate_ waitForDone:task withTimeout:deadline_ns];
 }
 
 ::testing::AssertionResult CronetTestBase::IsResponseSuccessful() {