Record the time duration for establishing proxy connection

net/http/http_proxy_client_socket_wrapper.cc

Index: net/http/http_proxy_client_socket_wrapper.cc
diff --git a/net/http/http_proxy_client_socket_wrapper.cc b/net/http/http_proxy_client_socket_wrapper.cc
index b209a5af46710d743f896bf013eb89e474ea56ae..de4e7d7a63e6f9e8708f6e00b8d7cfb5bbb774fc 100644
--- a/net/http/http_proxy_client_socket_wrapper.cc
+++ b/net/http/http_proxy_client_socket_wrapper.cc
@@ -10,6 +10,7 @@
 #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"
@@ -387,6 +388,7 @@ int HttpProxyClientSocketWrapper::DoLoop(int result) {
 }
 
 int HttpProxyClientSocketWrapper::DoBeginConnect() {
+  connect_start_time_ = base::TimeTicks::Now();
   SetConnectTimer(connect_timeout_duration_);
   if (transport_params_) {
     next_state_ = STATE_TCP_CONNECT;
@@ -501,6 +503,14 @@ int HttpProxyClientSocketWrapper::DoSSLConnectComplete(int 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_,
@@ -618,6 +628,17 @@ void HttpProxyClientSocketWrapper::ConnectTimeout() {
   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_;