Record the time duration for establishing proxy connection

net/http/http_proxy_client_socket_wrapper.cc

 // Copyright 2015 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/http/http_proxy_client_socket_wrapper.h"
 
 #include <utility>
 
 #include "base/bind.h"
 #include "base/bind_helpers.h"
 #include "base/callback_helpers.h"
 #include "base/memory/weak_ptr.h"
+#include "base/metrics/histogram_macros.h"
 #include "base/profiler/scoped_tracker.h"
 #include "base/values.h"
 #include "net/base/proxy_delegate.h"
 #include "net/http/http_proxy_client_socket.h"
 #include "net/http/http_response_info.h"
 #include "net/log/net_log_event_type.h"
 #include "net/log/net_log_source.h"
 #include "net/log/net_log_source_type.h"
 #include "net/socket/client_socket_handle.h"
 #include "net/spdy/spdy_proxy_client_socket.h"
@@ skipping 357 matching lines @@
         NOTREACHED() << "bad state";
         rv = ERR_FAILED;
         break;
     }
   } while (rv != ERR_IO_PENDING && next_state_ != STATE_NONE);
 
   return rv;
 }
 
 int HttpProxyClientSocketWrapper::DoBeginConnect() {
+  connect_start_time_ = base::TimeTicks::Now();
   SetConnectTimer(connect_timeout_duration_);
   if (transport_params_) {
     next_state_ = STATE_TCP_CONNECT;
   } else {
     next_state_ = STATE_SSL_CONNECT;
   }
 
   return OK;
 }
 
@@ skipping 94 matching lines @@
     next_state_ = STATE_SPDY_PROXY_CREATE_STREAM;
   } else {
     next_state_ = STATE_HTTP_PROXY_CONNECT;
   }
   return result;
 }
 
 int HttpProxyClientSocketWrapper::DoHttpProxyConnect() {
   next_state_ = STATE_HTTP_PROXY_CONNECT_COMPLETE;
 
+  if (transport_params_) {
+    UMA_HISTOGRAM_MEDIUM_TIMES("Net.Proxy.ConnectLatency.Insecure.Success",
+                               base::TimeTicks::Now() - connect_start_time_);
+  } else {
+    UMA_HISTOGRAM_MEDIUM_TIMES("Net.Proxy.ConnectLatency.Secure.Success",
+                               base::TimeTicks::Now() - connect_start_time_);

[mmenke, 2017/03/27 16:36:33]

These names should make it clear that they're only for Http proxies.

[tbansal1, 2017/03/27 18:29:30]

Done.

+  }
+
   // Add a HttpProxy connection on top of the tcp socket.
   transport_socket_.reset(new HttpProxyClientSocket(
       transport_socket_handle_.release(), user_agent_, endpoint_,
       GetDestination().host_port_pair(), http_auth_controller_.get(), tunnel_,
       using_spdy_, negotiated_protocol_, proxy_delegate_,
       ssl_params_.get() != nullptr));
   return transport_socket_->Connect(base::Bind(
       &HttpProxyClientSocketWrapper::OnIOComplete, base::Unretained(this)));
 }
 
@@ skipping 97 matching lines @@
   connect_timer_.Stop();
   connect_timer_.Start(FROM_HERE, delay, this,
                        &HttpProxyClientSocketWrapper::ConnectTimeout);
 }
 
 void HttpProxyClientSocketWrapper::ConnectTimeout() {
   // Timer shouldn't be running if next_state_ is STATE_NONE.
   DCHECK_NE(STATE_NONE, next_state_);
   DCHECK(!connect_callback_.is_null());
 
+  if (next_state_ == STATE_TCP_CONNECT_COMPLETE ||
+      next_state_ == STATE_SSL_CONNECT_COMPLETE) {

[mmenke, 2017/03/27 16:39:11]

One other question:  What about other errors?  Looks like we're currently
ignoring them.  HTTPS auth case looks kinda funky, too (Not sure about HTTP
auth, didn't think about it).

[tbansal1, 2017/03/27 18:29:30]

Yes, this histogram records time until only the timeout error. Right now, it is
not probably very meaningful since all values are going to be 10 seconds (or 30
seconds). Once I start the dynamic timeout experiment, it will be useful.

I have also added histogram for other errors.

+    if (transport_params_) {
+      UMA_HISTOGRAM_MEDIUM_TIMES("Net.Proxy.ConnectLatency.Insecure.TimedOut",
+                                 base::TimeTicks::Now() - connect_start_time_);
+    } else {
+      UMA_HISTOGRAM_MEDIUM_TIMES("Net.Proxy.ConnectLatency.Secure.TimedOut",
+                                 base::TimeTicks::Now() - connect_start_time_);
+    }
+  }
+
   NotifyProxyDelegateOfCompletion(ERR_CONNECTION_TIMED_OUT);
 
   CompletionCallback callback = connect_callback_;
   Disconnect();
   callback.Run(ERR_CONNECTION_TIMED_OUT);
 }
 
 const HostResolver::RequestInfo&
 HttpProxyClientSocketWrapper::GetDestination() {
   if (transport_params_) {
     return transport_params_->destination();
   } else {
     return ssl_params_->GetDirectConnectionParams()->destination();
   }
 }
 
 }  // namespace net