Add four histograms to measure duration of individual TCP connect attempts.

(1) Net.TcpConnectAttempt.Latency.Error:
  Number of milliseconds a TCP connect took to fail.

(2) Net.TcpConnectAttempt.Latency.Success
  Number of milliseconds a TCP connect took to succeed.

(3) Net.TcpConnectAttempt.LatencyPercentRTT.Error
  How long a TCP connect took to fail, as a percentage of the estimated RTT

(4) Net.TcpConnectAttempt.LatencyPercentRTT.Success
  How long a TCP connect took to succeed, as a percentage of the estimated RTT

Bug: 1123197
Change-Id: I5b05956ff60e415d707ad14f95bbb44a2d5f0377
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/2401335
Commit-Queue: Eric Roman <eroman@chromium.org>
Reviewed-by: Tarun Bansal <tbansal@chromium.org>
Cr-Commit-Position: refs/heads/master@{#810894}

net/socket/tcp_client_socket.cc

@@ -16,6 +16,7 @@
 #include "net/base/io_buffer.h"
 #include "net/base/ip_endpoint.h"
 #include "net/base/net_errors.h"
+#include "net/nqe/network_quality_estimator.h"
 #include "net/socket/socket_performance_watcher.h"
 #include "net/traffic_annotation/network_traffic_annotation.h"
 
@@ -151,7 +152,8 @@ TCPClientSocket::TCPClientSocket(
       previously_disconnected_(false),
       total_received_bytes_(0),
       was_ever_used_(false),
-      was_disconnected_on_suspend_(false) {
+      was_disconnected_on_suspend_(false),
+      network_quality_estimator_(network_quality_estimator) {
   DCHECK(socket_);
   if (socket_->IsValid())
     socket_->SetDefaultOptionsForClient();
@@ -256,10 +258,16 @@ int TCPClientSocket::DoConnect() {
   if (socket_->socket_performance_watcher() && current_address_index_ != 0)
     socket_->socket_performance_watcher()->OnConnectionChanged();
 
+  start_connect_attempt_ = base::TimeTicks::Now();
   return ConnectInternal(endpoint);
 }
 
 int TCPClientSocket::DoConnectComplete(int result) {
+  if (start_connect_attempt_) {
+    EmitConnectAttemptHistograms(result);
+    start_connect_attempt_ = base::nullopt;
+  }
+
   if (result == OK)
     return OK;  // Done!
 
@@ -307,6 +315,11 @@ void TCPClientSocket::Disconnect() {
 }
 
 void TCPClientSocket::DoDisconnect() {
+  if (start_connect_attempt_) {
+    EmitConnectAttemptHistograms(ERR_ABORTED);
+    start_connect_attempt_ = base::nullopt;
+  }
+
   total_received_bytes_ = 0;
   EmitTCPMetricsHistogramsOnDisconnect();
 
@@ -540,4 +553,53 @@ void TCPClientSocket::EmitTCPMetricsHistogramsOnDisconnect() {
   }
 }
 
+void TCPClientSocket::EmitConnectAttemptHistograms(int result) {
+  // This should only be called in response to completing a connect attempt.
+  DCHECK(start_connect_attempt_);
+
+  base::TimeDelta duration =
+      base::TimeTicks::Now() - start_connect_attempt_.value();
+
+  // Histogram the total time the connect attempt took, grouped by success and
+  // failure. Note that failures also include cases when the connect attempt
+  // was cancelled by the client before the handshake completed.
+  if (result == OK) {
+    UMA_HISTOGRAM_MEDIUM_TIMES("Net.TcpConnectAttempt.Latency.Success",
+                               duration);
+  } else {
+    UMA_HISTOGRAM_MEDIUM_TIMES("Net.TcpConnectAttempt.Latency.Error", duration);
+  }
+
+  base::Optional<base::TimeDelta> transport_rtt = base::nullopt;
+  if (network_quality_estimator_)
+    transport_rtt = network_quality_estimator_->GetTransportRTT();
+
+  // In cases where there is an estimated transport RTT, histogram the attempt
+  // duration as a percentage of the transport RTT. The histogram range can
+  // record fractions up to 1,000x RTT.
+  if (transport_rtt) {
+    int percent_rtt = 0;
+
+    if (transport_rtt.value().InMilliseconds() != 0) {
+      // Convert the percentage to an int, saturating to 100000.
+      float percent_rtt_float =
+          100.f * (duration.InMillisecondsF() /
+                   transport_rtt.value().InMillisecondsF());
+      if (percent_rtt_float > 100000) {
+        percent_rtt = 100000;
+      } else if (percent_rtt_float > 0) {
+        percent_rtt = static_cast<int>(percent_rtt_float);
+      }
+    }
+
+    if (result == OK) {
+      UMA_HISTOGRAM_COUNTS_100000(
+          "Net.TcpConnectAttempt.LatencyPercentRTT.Success", percent_rtt);
+    } else {
+      UMA_HISTOGRAM_COUNTS_100000(
+          "Net.TcpConnectAttempt.LatencyPercentRTT.Error", percent_rtt);
+    }
+  }
+}
+
 }  // namespace net

net/socket/tcp_client_socket.h

@@ -172,6 +172,10 @@ class NET_EXPORT TCPClientSocket : public TransportClientSocket,
   // disconnected.
   void EmitTCPMetricsHistogramsOnDisconnect();
 
+  // Emits histograms for the TCP connect attempt that just completed with
+  // |result|.
+  void EmitConnectAttemptHistograms(int result);
+
   std::unique_ptr<TCPSocket> socket_;
 
   // Local IP address and port we are bound to. Set to NULL if Bind()
@@ -211,6 +215,13 @@ class NET_EXPORT TCPClientSocket : public TransportClientSocket,
   // Connect() or Disconnect() is called.
   bool was_disconnected_on_suspend_;
 
+  // The time when the latest connect attempt was started.
+  base::Optional<base::TimeTicks> start_connect_attempt_;
+
+  // The NetworkQualityEstimator for the context this socket is associated with.
+  // Can be nullptr.
+  NetworkQualityEstimator* network_quality_estimator_;
+
   base::WeakPtrFactory<TCPClientSocket> weak_ptr_factory_{this};
 
   DISALLOW_COPY_AND_ASSIGN(TCPClientSocket);

tools/metrics/histograms/histograms.xml

@@ -103900,6 +103900,52 @@ reviews. Googlers can read more about this at go/gwsq-gerrit.
   </summary>
 </histogram>
 
+<histogram name="Net.TcpConnectAttempt.Latency.Error" units="ms"
+    expires_after="M90">
+  <owner>eroman@chromium.org</owner>
+  <owner>src/net/OWNERS</owner>
+  <summary>
+    Time taken when failed to establish a TCP connection to an individual
+    endpoint. This includes the case when the attempt was aborted by a higher
+    layer (likely because it took too long).
+  </summary>
+</histogram>
+
+<histogram name="Net.TcpConnectAttempt.Latency.Success" units="ms"
+    expires_after="M90">
+  <owner>eroman@chromium.org</owner>
+  <owner>src/net/OWNERS</owner>
+  <summary>
+    Time taken to successfully establish a TCP connection to an individual
+    endpoint.
+  </summary>
+</histogram>
+
+<histogram name="Net.TcpConnectAttempt.LatencyPercentRTT.Error" units="%"
+    expires_after="M90">
+  <owner>eroman@chromium.org</owner>
+  <owner>src/net/OWNERS</owner>
+  <summary>
+    Time taken when failed to establish a TCP connection to an individual
+    endpoint, expressed as a multiple of the transport RTT. This includes the
+    case when the attempt was aborted by a higher layer (likely because it took
+    too long). This may have fewer samples than Net.TcpConnectAttempt.Latency.*
+    in cases where the network quality estimation was unknown.
+  </summary>
+</histogram>
+
+<histogram name="Net.TcpConnectAttempt.LatencyPercentRTT.Success" units="%"
+    expires_after="M90">
+  <owner>eroman@chromium.org</owner>
+  <owner>src/net/OWNERS</owner>
+  <summary>
+    Time taken to successfully establish a TCP connection to an individual
+    endpoint, expressed as a multiple of the transport RTT. This may have fewer
+    samples than Net.TcpConnectAttempt.Latency.* in cases where the network
+    quality estimation was unknown.
+  </summary>
+</histogram>
+
 <histogram name="Net.TcpFastOpenSocketConnection" enum="TcpSocketStatus"
     expires_after="2019-02-13">
   <obsolete>