net: measure theoretical delay of waiting for DNS cert information.

This patch adds a histogram to measure what the delay would have been,
had we waited for information from DNS in order to make a certificate
verification decision.

BUG=none
TEST=none

http://codereview.chromium.org/6329001

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@71445 0039d316-1c4b-4281-b951-d872f2087c98

net/socket/ssl_client_socket_nss.cc

@@ -2330,7 +2330,6 @@ int SSLClientSocketNSS::DoVerifyCert(int result) {
 int SSLClientSocketNSS::DoVerifyCertComplete(int result) {
   verifier_.reset();
 
-
   if (!start_cert_verification_time_.is_null()) {
     base::TimeDelta verify_time =
         base::TimeTicks::Now() - start_cert_verification_time_;
@@ -2340,6 +2339,9 @@ int SSLClientSocketNSS::DoVerifyCertComplete(int result) {
         UMA_HISTOGRAM_TIMES("Net.SSLCertVerificationTimeError", verify_time);
   }
 
+  if (ssl_host_info_.get())
+    ssl_host_info_->set_cert_verification_finished_time();
+
   // We used to remember the intermediate CA certs in the NSS database
   // persistently.  However, NSS opens a connection to the SQLite database
   // during NSS initialization and doesn't close the connection until NSS

net/socket/ssl_host_info.cc

@@ -76,6 +76,20 @@ SSLHostInfo::State* SSLHostInfo::mutable_state() {
   return &state_;
 }
 
+void SSLHostInfo::set_cert_verification_finished_time() {
+#if defined(OS_LINUX)
+  if (dnsrr_resolver_ && dns_handle_ == DnsRRResolver::kInvalidHandle) {
+    // We have completed the DNS lookup already. Therefore, waiting for the DNS
+    // lookup would cause no delay.
+    UMA_HISTOGRAM_TIMES("Net.SSLHostInfoDNSLookupDelayMs", base::TimeDelta());
+  } else {
+    // The actual delay will be calculated when the DNS lookup finishes, in
+    // DnsComplete.
+    cert_verification_finished_time_ = base::TimeTicks::Now();
+  }
+#endif
+}
+
 bool SSLHostInfo::Parse(const std::string& data) {
   State* state = mutable_state();
 
@@ -224,10 +238,16 @@ void SSLHostInfo::DnsComplete(int rv) {
   dns_callback_ = NULL;
 
   const base::TimeTicks now = base::TimeTicks::Now();
-  const base::TimeDelta elapsed = now - dns_lookup_start_time_;
+  base::TimeDelta elapsed = now - dns_lookup_start_time_;
   UMA_HISTOGRAM_TIMES("Net.SSLHostInfoDNSLookup", elapsed);
+
+  if (!cert_verification_finished_time_.is_null()) {
+    elapsed = now - cert_verification_finished_time_;
+    UMA_HISTOGRAM_TIMES("Net.SSLHostInfoDNSLookupDelayMs", elapsed);
+  }
 }
 
+
 SSLHostInfoFactory::~SSLHostInfoFactory() {}
 
 }  // namespace net

net/socket/ssl_host_info.h

@@ -106,6 +106,12 @@ class SSLHostInfo {
     return verification_end_time_;
   }
 
+  // set_cert_verification_finished_time allows the SSL socket to tell us when
+  // it finished verifing the certificate. If the DNS request hasn't finished
+  // by this time then we record how long we would have had to have waited for
+  // it.
+  void set_cert_verification_finished_time();
+
  protected:
   // Parse parses an opaque blob of data and fills out the public member fields
   // of this object. It returns true iff the parse was successful. The public
@@ -146,6 +152,7 @@ class SSLHostInfo {
   DnsRRResolver::Handle dns_handle_;
   RRResponse dns_response_;
   base::TimeTicks dns_lookup_start_time_;
+  base::TimeTicks cert_verification_finished_time_;
 };
 
 class SSLHostInfoFactory {