Add Net.ProxyScriptFetchSuccessDuration UMA to record how long PAC script fetches take.

net/proxy/proxy_script_fetcher_impl.cc

 // Copyright (c) 2012 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 "net/proxy/proxy_script_fetcher_impl.h"
 
 #include "base/compiler_specific.h"
 #include "base/location.h"
 #include "base/logging.h"
+#include "base/metrics/histogram.h"
 #include "base/single_thread_task_runner.h"
 #include "base/strings/string_util.h"
 #include "base/thread_task_runner_handle.h"
 #include "net/base/data_url.h"
 #include "net/base/io_buffer.h"
 #include "net/base/load_flags.h"
 #include "net/base/net_errors.h"
 #include "net/base/net_string_util.h"
 #include "net/base/request_priority.h"
 #include "net/cert/cert_status_flags.h"
@@ skipping 106 matching lines @@
     std::string mime_type;
     std::string charset;
     std::string data;
     if (!DataURL::Parse(url, &mime_type, &charset, &data))
       return ERR_FAILED;
 
     ConvertResponseToUTF16(charset, data, text);
     return OK;
   }
 
+  DCHECK(fetch_start_time_.is_null());
+  fetch_start_time_ = base::Time::Now();

[eroman, 2015/07/13 21:39:04]

I suggest using base::TimeTicks over base::Time for measuring elapsed times.

base::Time is influenced from changing the system clock, so it is more likely to
measure walltime deltas incorrectly.

While base::TimeTicks is better in this regard, it has inconsistencies with how
time lapses measured across system sleep/suspend work, because unfortunately
last I looked we didn't use a consistent monotonic clock across platforms (ticks
will stand still on some platforms, but increase on others while sleeping).

... Even so, that is not likely to impact this histogram since fetches
interrupted by a suspend/sleep will almost surely fail (either aborted or
network error).

+
   cur_request_ =
       url_request_context_->CreateRequest(url, DEFAULT_PRIORITY, this);
   cur_request_->set_method("GET");
 
   // Make sure that the PAC script is downloaded using a direct connection,
   // to avoid circular dependencies (fetching is a part of proxy resolution).
   // Also disable the use of the disk cache. The cache is disabled so that if
   // the user switches networks we don't potentially use the cached response
   // from old network when we should in fact be re-fetching on the new network.
   // If the PAC script is hosted on an HTTPS server we bypass revocation
@@ skipping 129 matching lines @@
     request->Cancel();
     return false;
   }
 
   bytes_read_so_far_.append(buf_->data(), num_bytes);
   return true;
 }
 
 void ProxyScriptFetcherImpl::FetchCompleted() {
   if (result_code_ == OK) {
+    // Calculate duration of time for proxy script fetch to complete.
+    DCHECK(!fetch_start_time_.is_null());
+    UMA_HISTOGRAM_TIMES("Net.ProxyScriptFetcher.SuccessDuration",

[eroman, 2015/07/13 21:39:04]

I see you considered putting it in ProxyScriptDecider. This should be fine to
start getting some data.

Note that an advantage of ProxyScriptDecider is we might be rejecting slow
successful fetches in ProxyScriptDecider::DoVerifyPacScript().

For instance a hypothetical situation would be a captive portal that makes the
proxy script fetch really slow, however it still completes with an HTTP 200
code. The page served up however is an HTML page rather than a PAC script, so
DoVerifyPacScript() subsequently fails and we fallback to not using the script.

+                        base::Time::Now() - fetch_start_time_);
+
     // The caller expects the response to be encoded as UTF16.
     std::string charset;
     cur_request_->GetCharset(&charset);
     ConvertResponseToUTF16(charset, bytes_read_so_far_, result_text_);
   } else {
     // On error, the caller expects empty string for bytes.
     result_text_->clear();
   }
 
   int result_code = result_code_;
   CompletionCallback callback = callback_;
 
   ResetCurRequestState();
 
   callback.Run(result_code);
 }
 
 void ProxyScriptFetcherImpl::ResetCurRequestState() {
   cur_request_.reset();
   cur_request_id_ = 0;
   callback_.Reset();
   result_code_ = OK;
   result_text_ = NULL;
+  fetch_start_time_ = base::Time();
 }
 
 void ProxyScriptFetcherImpl::OnTimeout(int id) {
   // Timeout tasks may outlive the URLRequest they reference. Make sure it
   // is still applicable.
   if (cur_request_id_ != id)
     return;
 
   DCHECK(cur_request_.get());
   result_code_ = ERR_TIMED_OUT;
   cur_request_->Cancel();
 }
 
 }  // namespace net