LoadTiming implementation in net, part 1.

net/socket/ssl_client_socket_pool.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/socket/ssl_client_socket_pool.h"
 
 #include "base/bind.h"
 #include "base/bind_helpers.h"
 #include "base/metrics/field_trial.h"
 #include "base/metrics/histogram.h"
@@ skipping 111 matching lines @@
 }
 
 void SSLConnectJob::GetAdditionalErrorState(ClientSocketHandle* handle) {
   // Headers in |error_response_info_| indicate a proxy tunnel setup
   // problem. See DoTunnelConnectComplete.
   if (error_response_info_.headers) {
     handle->set_pending_http_proxy_connection(
         transport_socket_handle_.release());
   }
   handle->set_ssl_error_response_info(error_response_info_);
-  if (!ssl_connect_start_time_.is_null())
+  if (!connect_timing_.ssl_start.is_null())
     handle->set_is_ssl_error(true);
 }
 
 void SSLConnectJob::OnIOComplete(int result) {
   int rv = DoLoop(result);
   if (rv != ERR_IO_PENDING)
     NotifyDelegateOfCompletion(rv);  // Deletes |this|.
 }
 
 int SSLConnectJob::DoLoop(int result) {
@@ skipping 109 matching lines @@
     return result;
 
   next_state_ = STATE_SSL_CONNECT;
   return result;
 }
 
 int SSLConnectJob::DoSSLConnect() {
   next_state_ = STATE_SSL_CONNECT_COMPLETE;
   // Reset the timeout to just the time allowed for the SSL handshake.
   ResetTimer(base::TimeDelta::FromSeconds(kSSLHandshakeTimeoutInSeconds));
-  ssl_connect_start_time_ = base::TimeTicks::Now();
+
+  // If the handle has a fresh socket, get its connect start and DNS times.
+  // This should always be the case.
+  const LoadTimingInfo::ConnectTiming& socket_connect_timing =
+      transport_socket_handle_->connect_timing();
+  if (!transport_socket_handle_->is_reused() &&
+      !socket_connect_timing.connect_start.is_null()) {
+    // Overwriting |connect_start| serves two purposes - it adjusts timing so
+    // |connect_start| doesn't include dns times, and it adjusts the time so
+    // as not to include time spent waiting for an idle socket.
+    connect_timing_.connect_start = socket_connect_timing.connect_start;
+    connect_timing_.dns_start = socket_connect_timing.dns_start;
+    connect_timing_.dns_end = socket_connect_timing.dns_end;
+  }
+
+  connect_timing_.ssl_start = base::TimeTicks::Now();
 
   ssl_socket_.reset(client_socket_factory_->CreateSSLClientSocket(
       transport_socket_handle_.release(), params_->host_and_port(),
       params_->ssl_config(), context_));
   return ssl_socket_->Connect(callback_);
 }
 
 int SSLConnectJob::DoSSLConnectComplete(int result) {
+  connect_timing_.ssl_end = base::TimeTicks::Now();
+
   SSLClientSocket::NextProtoStatus status =
       SSLClientSocket::kNextProtoUnsupported;
   std::string proto;
   std::string server_protos;
   // GetNextProto will fail and and trigger a NOTREACHED if we pass in a socket
   // that hasn't had SSL_ImportFD called on it. If we get a certificate error
   // here, then we know that we called SSL_ImportFD.
   if (result == OK || IsCertificateError(result))
     status = ssl_socket_->GetNextProto(&proto, &server_protos);
 
@@ skipping 14 matching lines @@
   }
   if (params_->want_spdy_over_npn() && !ssl_socket_->was_spdy_negotiated())
     return ERR_NPN_NEGOTIATION_FAILED;
 
   // Spdy might be turned on by default, or it might be over npn.
   bool using_spdy = params_->force_spdy_over_ssl() ||
       params_->want_spdy_over_npn();
 
   if (result == OK ||
       ssl_socket_->IgnoreCertError(result, params_->load_flags())) {
-    DCHECK(ssl_connect_start_time_ != base::TimeTicks());
+    DCHECK(!connect_timing_.ssl_start.is_null());
     base::TimeDelta connect_duration =
-        base::TimeTicks::Now() - ssl_connect_start_time_;
+        connect_timing_.ssl_end - connect_timing_.ssl_start;
     if (using_spdy) {
       UMA_HISTOGRAM_CUSTOM_TIMES("Net.SpdyConnectionLatency",
                                  connect_duration,
                                  base::TimeDelta::FromMilliseconds(1),
                                  base::TimeDelta::FromMinutes(10),
                                  100);
     }
 
     UMA_HISTOGRAM_CUSTOM_TIMES("Net.SSL_Connection_Latency",
                                connect_duration,
@@ skipping 288 matching lines @@
   FlushWithError(ERR_NETWORK_CHANGED);
 }
 
 bool SSLClientSocketPool::CloseOneIdleConnection() {
   if (base_.CloseOneIdleSocket())
     return true;
   return base_.CloseOneIdleConnectionInLayeredPool();
 }
 
 }  // namespace net