Add GetLoadTimingInfo to net::BidirectionalStream

net/http/bidirectional_stream.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/bidirectional_stream.h"
 
 #include <memory>
 #include <string>
 
 #include "base/bind.h"
@@ skipping 74 matching lines @@
                                       NetLogSourceType::BIDIRECTIONAL_STREAM)),
       session_(session),
       send_request_headers_automatically_(send_request_headers_automatically),
       request_headers_sent_(false),
       delegate_(delegate),
       timer_(std::move(timer)),
       weak_factory_(this) {
   DCHECK(delegate_);
   DCHECK(request_info_);
 
+  // Start time should be measured before connect.
+  load_timing_info_.request_start_time = base::Time::Now();
+  load_timing_info_.request_start = base::TimeTicks::Now();
+
   if (net_log_.IsCapturing()) {
     net_log_.BeginEvent(
         NetLogEventType::BIDIRECTIONAL_STREAM_ALIVE,
         base::Bind(&NetLogCallback, &request_info_->url, &request_info_->method,
                    base::Unretained(&request_info_->extra_headers)));
   }
 
   SSLConfig server_ssl_config;
   session->ssl_config_service()->GetSSLConfig(&server_ssl_config);
   session->GetAlpnProtos(&server_ssl_config.alpn_protos);
@@ skipping 104 matching lines @@
   return stream_impl_->GetTotalReceivedBytes();
 }
 
 int64_t BidirectionalStream::GetTotalSentBytes() const {
   if (!stream_impl_)
     return 0;
 
   return stream_impl_->GetTotalSentBytes();
 }
 
+void BidirectionalStream::GetLoadTimingInfo(
+    LoadTimingInfo* load_timing_info) const {
+  *load_timing_info = load_timing_info_;
+}
+
 void BidirectionalStream::OnStreamReady(bool request_headers_sent) {
   request_headers_sent_ = request_headers_sent;
   if (net_log_.IsCapturing()) {
     net_log_.AddEvent(
         NetLogEventType::BIDIRECTIONAL_STREAM_READY,
         NetLog::BoolCallback("request_headers_sent", request_headers_sent));
   }
-  send_start_time_ = base::TimeTicks::Now();
-  send_end_time_ = send_start_time_;
+  load_timing_info_.send_start = base::TimeTicks::Now();
+  load_timing_info_.send_end = load_timing_info_.send_start;
   delegate_->OnStreamReady(request_headers_sent);
 }
 
 void BidirectionalStream::OnHeadersReceived(
     const SpdyHeaderBlock& response_headers) {
   HttpResponseInfo response_info;
   if (!SpdyHeadersToHttpResponse(response_headers, &response_info)) {
     DLOG(WARNING) << "Invalid headers";
     NotifyFailed(ERR_FAILED);
     return;
   }
   if (net_log_.IsCapturing()) {
     net_log_.AddEvent(NetLogEventType::BIDIRECTIONAL_STREAM_RECV_HEADERS,
                       base::Bind(&NetLogHeadersCallback, &response_headers));
   }
-  read_start_time_ = base::TimeTicks::Now();
-  read_end_time_ = read_start_time_;
+  // Impl should only provide |connect_timing| and |socket_reused| info,
+  // so use a copy to get these information only.
+  LoadTimingInfo impl_load_timing_info;
+  bool has_load_timing =
+      stream_impl_->GetLoadTimingInfo(&impl_load_timing_info);
+  if (has_load_timing) {
+    load_timing_info_.connect_timing = impl_load_timing_info.connect_timing;
+    load_timing_info_.socket_reused = impl_load_timing_info.socket_reused;
+  }
+  load_timing_info_.receive_headers_end = base::TimeTicks::Now();
+  read_end_time_ = load_timing_info_.receive_headers_end;
   session_->http_stream_factory()->ProcessAlternativeServices(
       session_, response_info.headers.get(),
       url::SchemeHostPort(request_info_->url));
   delegate_->OnHeadersReceived(response_headers);
 }
 
 void BidirectionalStream::OnDataRead(int bytes_read) {
   DCHECK(read_buffer_);
 
   if (net_log_.IsCapturing()) {
@@ skipping 20 matching lines @@
     for (size_t i = 0; i < write_buffer_list_.size(); ++i) {
       net_log_.AddByteTransferEvent(
           NetLogEventType::BIDIRECTIONAL_STREAM_BYTES_SENT,
           write_buffer_len_list_[i], write_buffer_list_[i]->data());
     }
     if (write_buffer_list_.size() > 1) {
       net_log_.EndEvent(
           NetLogEventType::BIDIRECTIONAL_STREAM_BYTES_SENT_COALESCED);
     }
   }
-  send_end_time_ = base::TimeTicks::Now();
+  load_timing_info_.send_end = base::TimeTicks::Now();
   write_buffer_list_.clear();
   write_buffer_len_list_.clear();
   delegate_->OnDataSent();
 }
 
 void BidirectionalStream::OnTrailersReceived(const SpdyHeaderBlock& trailers) {
   if (net_log_.IsCapturing()) {
     net_log_.AddEvent(NetLogEventType::BIDIRECTIONAL_STREAM_RECV_TRAILERS,
                       base::Bind(&NetLogHeadersCallback, &trailers));
   }
@@ skipping 14 matching lines @@
                                         HttpStream* stream) {
   NOTREACHED();
 }
 
 void BidirectionalStream::OnBidirectionalStreamImplReady(
     const SSLConfig& used_ssl_config,
     const ProxyInfo& used_proxy_info,
     BidirectionalStreamImpl* stream) {
   DCHECK(!stream_impl_);
 
-  start_time_ = base::TimeTicks::Now();
   stream_request_.reset();
   stream_impl_.reset(stream);
   stream_impl_->Start(request_info_.get(), net_log_,
                       send_request_headers_automatically_, this,
                       std::move(timer_));
 }
 
 void BidirectionalStream::OnWebSocketHandshakeStreamReady(
     const SSLConfig& used_ssl_config,
     const ProxyInfo& used_proxy_info,
@@ skipping 49 matching lines @@
 
 void BidirectionalStream::OnQuicBroken() {}
 
 void BidirectionalStream::NotifyFailed(int error) {
   delegate_->OnFailed(error);
 }
 
 void BidirectionalStream::UpdateHistograms() {
   // If the request failed before response is started, treat the metrics as
   // bogus and skip logging.
-  if (start_time_.is_null() || read_start_time_.is_null() ||
-      read_end_time_.is_null() || send_start_time_.is_null() ||
-      send_end_time_.is_null()) {
+  if (load_timing_info_.request_start.is_null() ||
+      load_timing_info_.receive_headers_end.is_null() ||
+      read_end_time_.is_null() || load_timing_info_.send_start.is_null() ||
+      load_timing_info_.send_end.is_null()) {
     return;
   }
   if (GetProtocol() == kProtoHTTP2) {
     UMA_HISTOGRAM_TIMES("Net.BidirectionalStream.TimeToReadStart.HTTP2",
-                        read_start_time_ - start_time_);
+                        load_timing_info_.receive_headers_end -
+                            load_timing_info_.request_start);
     UMA_HISTOGRAM_TIMES("Net.BidirectionalStream.TimeToReadEnd.HTTP2",
-                        read_end_time_ - start_time_);
-    UMA_HISTOGRAM_TIMES("Net.BidirectionalStream.TimeToSendStart.HTTP2",
-                        send_start_time_ - start_time_);
-    UMA_HISTOGRAM_TIMES("Net.BidirectionalStream.TimeToSendEnd.HTTP2",
-                        send_end_time_ - start_time_);
+                        read_end_time_ - load_timing_info_.request_start);
+    UMA_HISTOGRAM_TIMES(
+        "Net.BidirectionalStream.TimeToSendStart.HTTP2",
+        load_timing_info_.send_start - load_timing_info_.request_start);
+    UMA_HISTOGRAM_TIMES(
+        "Net.BidirectionalStream.TimeToSendEnd.HTTP2",
+        load_timing_info_.send_end - load_timing_info_.request_start);
     UMA_HISTOGRAM_COUNTS("Net.BidirectionalStream.ReceivedBytes.HTTP2",
                          stream_impl_->GetTotalReceivedBytes());
     UMA_HISTOGRAM_COUNTS("Net.BidirectionalStream.SentBytes.HTTP2",
                          stream_impl_->GetTotalSentBytes());
   } else if (GetProtocol() == kProtoQUIC1SPDY3) {
     UMA_HISTOGRAM_TIMES("Net.BidirectionalStream.TimeToReadStart.QUIC",
-                        read_start_time_ - start_time_);
+                        load_timing_info_.receive_headers_end -
+                            load_timing_info_.request_start);
     UMA_HISTOGRAM_TIMES("Net.BidirectionalStream.TimeToReadEnd.QUIC",
-                        read_end_time_ - start_time_);
-    UMA_HISTOGRAM_TIMES("Net.BidirectionalStream.TimeToSendStart.QUIC",
-                        send_start_time_ - start_time_);
-    UMA_HISTOGRAM_TIMES("Net.BidirectionalStream.TimeToSendEnd.QUIC",
-                        send_end_time_ - start_time_);
+                        read_end_time_ - load_timing_info_.request_start);
+    UMA_HISTOGRAM_TIMES(
+        "Net.BidirectionalStream.TimeToSendStart.QUIC",
+        load_timing_info_.send_start - load_timing_info_.request_start);
+    UMA_HISTOGRAM_TIMES(
+        "Net.BidirectionalStream.TimeToSendEnd.QUIC",
+        load_timing_info_.send_end - load_timing_info_.request_start);
     UMA_HISTOGRAM_COUNTS("Net.BidirectionalStream.ReceivedBytes.QUIC",
                          stream_impl_->GetTotalReceivedBytes());
     UMA_HISTOGRAM_COUNTS("Net.BidirectionalStream.SentBytes.QUIC",
                          stream_impl_->GetTotalSentBytes());
   }
 }
 
 }  // namespace net