Implements BidirectionalStreamQuicImpl::GetLoadTimingInfo

net/quic/chromium/bidirectional_stream_quic_impl_unittest.cc

 // Copyright 2016 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/quic/chromium/bidirectional_stream_quic_impl.h"
 
 #include <utility>
 
 #include "base/callback_helpers.h"
 #include "base/memory/ptr_util.h"
 #include "base/run_loop.h"
 #include "base/strings/string_number_conversions.h"
+#include "base/time/time.h"
 #include "net/base/ip_address.h"
+#include "net/base/load_timing_info.h"
+#include "net/base/load_timing_info_test_util.h"
 #include "net/base/net_errors.h"
 #include "net/http/bidirectional_stream_request_info.h"
 #include "net/http/transport_security_state.h"
 #include "net/log/net_log_event_type.h"
 #include "net/log/test_net_log.h"
 #include "net/log/test_net_log_util.h"
 #include "net/quic/chromium/quic_chromium_alarm_factory.h"
 #include "net/quic/chromium/quic_chromium_connection_helper.h"
 #include "net/quic/chromium/quic_chromium_packet_reader.h"
 #include "net/quic/chromium/quic_chromium_packet_writer.h"
@@ skipping 42 matching lines @@
   TestDelegateBase(IOBuffer* read_buf,
                    int read_buf_len,
                    std::unique_ptr<base::Timer> timer)
       : read_buf_(read_buf),
         read_buf_len_(read_buf_len),
         timer_(std::move(timer)),
         loop_(nullptr),
         next_proto_(kProtoUnknown),
         received_bytes_(0),
         sent_bytes_(0),
+        has_load_timing_info_(false),
         error_(OK),
         on_data_read_count_(0),
         on_data_sent_count_(0),
         not_expect_callback_(false),
         on_failed_called_(false),
         send_request_headers_automatically_(true),
         is_ready_(false) {
     loop_.reset(new base::RunLoop);
   }
 
@@ skipping 109 matching lines @@
       return stream_->GetTotalReceivedBytes();
     return received_bytes_;
   }
 
   int64_t GetTotalSentBytes() const {
     if (stream_)
       return stream_->GetTotalSentBytes();
     return sent_bytes_;
   }
 
+  bool GetLoadTimingInfo(LoadTimingInfo* load_timing_info) {
+    if (stream_)
+      return stream_->GetLoadTimingInfo(load_timing_info);
+    *load_timing_info = load_timing_info_;
+    return has_load_timing_info_;
+  }
+
   void DoNotSendRequestHeadersAutomatically() {
     send_request_headers_automatically_ = false;
   }
 
   // Deletes |stream_|.
   void DeleteStream() {
     next_proto_ = stream_->GetProtocol();
     received_bytes_ = stream_->GetTotalReceivedBytes();
     sent_bytes_ = stream_->GetTotalSentBytes();
+    has_load_timing_info_ = stream_->GetLoadTimingInfo(&load_timing_info_);
     stream_.reset();
   }
 
   // Const getters for internal states.
   const std::string& data_received() const { return data_received_; }
   int error() const { return error_; }
   const SpdyHeaderBlock& response_headers() const { return response_headers_; }
   const SpdyHeaderBlock& trailers() const { return trailers_; }
   int on_data_read_count() const { return on_data_read_count_; }
   int on_data_sent_count() const { return on_data_sent_count_; }
   bool on_failed_called() const { return on_failed_called_; }
   bool is_ready() const { return is_ready_; }
 
  protected:
   // Quits |loop_|.
   void QuitLoop() { loop_->Quit(); }
 
  private:
   std::unique_ptr<BidirectionalStreamQuicImpl> stream_;
   scoped_refptr<IOBuffer> read_buf_;
   int read_buf_len_;
   std::unique_ptr<base::Timer> timer_;
   std::string data_received_;
   std::unique_ptr<base::RunLoop> loop_;
   SpdyHeaderBlock response_headers_;
   SpdyHeaderBlock trailers_;
   NextProto next_proto_;
   int64_t received_bytes_;
   int64_t sent_bytes_;
+  bool has_load_timing_info_;
+  LoadTimingInfo load_timing_info_;
   int error_;
   int on_data_read_count_;
   int on_data_sent_count_;
   // This is to ensure that delegate callback is not invoked synchronously when
   // calling into |stream_|.
   bool not_expect_callback_;
   bool on_failed_called_;
   CompletionCallback callback_;
   bool send_request_headers_automatically_;
   bool is_ready_;
@@ skipping 138 matching lines @@
         socket_data_.get(), net_log().bound().net_log()));
     socket->Connect(peer_addr_);
     runner_ = new TestTaskRunner(&clock_);
     helper_.reset(
         new QuicChromiumConnectionHelper(&clock_, &random_generator_));
     alarm_factory_.reset(new QuicChromiumAlarmFactory(runner_.get(), &clock_));
     connection_ = new QuicConnection(
         connection_id_, peer_addr_, helper_.get(), alarm_factory_.get(),
         new QuicChromiumPacketWriter(socket.get()), true /* owns_writer */,
         Perspective::IS_CLIENT, SupportedVersions(GetParam()));
+    base::TimeTicks dns_end = base::TimeTicks::Now();
+    base::TimeTicks dns_start = dns_end - base::TimeDelta::FromMilliseconds(1);
 
     session_.reset(new QuicChromiumClientSession(
         connection_, std::move(socket),
         /*stream_factory=*/nullptr, &crypto_client_stream_factory_, &clock_,
         &transport_security_state_,
         base::WrapUnique(static_cast<QuicServerInfo*>(nullptr)),
         QuicServerId(kDefaultServerHostName, kDefaultServerPort,
                      PRIVACY_MODE_DISABLED),
         kQuicYieldAfterPacketsRead,
         QuicTime::Delta::FromMilliseconds(kQuicYieldAfterDurationMilliseconds),
         /*cert_verify_flags=*/0, DefaultQuicConfig(), &crypto_config_,
-        "CONNECTION_UNKNOWN", base::TimeTicks::Now(), base::TimeTicks::Now(),
-        &push_promise_index_, base::ThreadTaskRunnerHandle::Get().get(),
+        "CONNECTION_UNKNOWN", dns_start, dns_end, &push_promise_index_,
+        base::ThreadTaskRunnerHandle::Get().get(),
         /*socket_performance_watcher=*/nullptr, net_log().bound().net_log()));
     session_->Initialize();
-    session_->GetCryptoStream()->CryptoConnect();
+    TestCompletionCallback callback;
+    session_->CryptoConnect(/*require_confirmation=*/false,
+                            callback.callback());
     EXPECT_TRUE(session_->IsEncryptionEstablished());
   }
 
   void ConfirmHandshake() {
     crypto_client_stream_factory_.last_stream()->SendOnCryptoHandshakeEvent(
         QuicSession::HANDSHAKE_CONFIRMED);
   }
 
   void SetRequest(const std::string& method,
                   const std::string& path,
@@ skipping 43 matching lines @@
     DVLOG(2) << "packet(" << packet_number << "): " << std::endl
              << QuicUtils::HexDump(packet->AsStringPiece());
     return packet;
   }
 
   std::unique_ptr<QuicReceivedPacket> ConstructRequestHeadersPacket(
       QuicPacketNumber packet_number,
       bool fin,
       RequestPriority request_priority,
       size_t* spdy_headers_frame_length) {
+    return ConstructRequestHeadersPacketInner(
+        packet_number, stream_id_, fin, request_priority,
+        spdy_headers_frame_length, /*offset=*/nullptr);
+  }
+
+  std::unique_ptr<QuicReceivedPacket> ConstructRequestHeadersPacketInner(
+      QuicPacketNumber packet_number,
+      QuicStreamId stream_id,
+      bool fin,
+      RequestPriority request_priority,
+      size_t* spdy_headers_frame_length,
+      QuicStreamOffset* offset) {
     SpdyPriority priority =
         ConvertRequestPriorityToQuicPriority(request_priority);
-    return client_maker_.MakeRequestHeadersPacket(
-        packet_number, stream_id_, kIncludeVersion, fin, priority,
-        std::move(request_headers_), spdy_headers_frame_length);
+    std::unique_ptr<QuicReceivedPacket> packet(
+        client_maker_.MakeRequestHeadersPacket(
+            packet_number, stream_id, kIncludeVersion, fin, priority,
+            std::move(request_headers_), spdy_headers_frame_length, offset));
+    DVLOG(2) << "packet(" << packet_number << "): " << std::endl
+             << QuicUtils::HexDump(packet->AsStringPiece());
+    return packet;
   }
 
   std::unique_ptr<QuicReceivedPacket>
   ConstructRequestHeadersAndMultipleDataFramesPacket(
       QuicPacketNumber packet_number,
       bool fin,
       RequestPriority request_priority,
       size_t* spdy_headers_frame_length,
       const std::vector<std::string>& data) {
     SpdyPriority priority =
         ConvertRequestPriorityToQuicPriority(request_priority);
     std::unique_ptr<QuicReceivedPacket> packet(
         client_maker_.MakeRequestHeadersAndMultipleDataFramesPacket(
             packet_number, stream_id_, kIncludeVersion, fin, priority,
             std::move(request_headers_), spdy_headers_frame_length, data));
     DVLOG(2) << "packet(" << packet_number << "): " << std::endl
              << QuicUtils::HexDump(packet->AsStringPiece());
     return packet;
   }
 
   std::unique_ptr<QuicReceivedPacket> ConstructResponseHeadersPacket(
       QuicPacketNumber packet_number,
       bool fin,
       SpdyHeaderBlock response_headers,
       size_t* spdy_headers_frame_length,
       QuicStreamOffset* offset) {
+    return ConstructResponseHeadersPacketInner(
+        packet_number, stream_id_, fin, std::move(response_headers),
+        spdy_headers_frame_length, offset);
+  }
+
+  std::unique_ptr<QuicReceivedPacket> ConstructResponseHeadersPacketInner(
+      QuicPacketNumber packet_number,
+      QuicStreamId stream_id,
+      bool fin,
+      SpdyHeaderBlock response_headers,
+      size_t* spdy_headers_frame_length,
+      QuicStreamOffset* offset) {
     return server_maker_.MakeResponseHeadersPacket(
-        packet_number, stream_id_, !kIncludeVersion, fin,
+        packet_number, stream_id, !kIncludeVersion, fin,
         std::move(response_headers), spdy_headers_frame_length, offset);
   }
 
   std::unique_ptr<QuicReceivedPacket> ConstructResponseTrailersPacket(
       QuicPacketNumber packet_number,
       bool fin,
       SpdyHeaderBlock trailers,
       size_t* spdy_headers_frame_length,
       QuicStreamOffset* offset) {
     return server_maker_.MakeResponseHeadersPacket(
@@ skipping 62 matching lines @@
 
   std::unique_ptr<QuicReceivedPacket> ConstructServerAckPacket(
       QuicPacketNumber packet_number,
       QuicPacketNumber largest_received,
       QuicPacketNumber least_unacked) {
     return server_maker_.MakeAckPacket(packet_number, largest_received,
                                        least_unacked,
                                        !kIncludeCongestionFeedback);
   }
 
+  void ExpectLoadTimingValid(const LoadTimingInfo& load_timing_info,
+                             bool session_reused) {
+    EXPECT_EQ(session_reused, load_timing_info.socket_reused);
+
+    if (session_reused) {
+      ExpectConnectTimingHasNoTimes(load_timing_info.connect_timing);
+    } else {
+      ExpectConnectTimingHasTimes(
+          load_timing_info.connect_timing,
+          CONNECT_TIMING_HAS_SSL_TIMES | CONNECT_TIMING_HAS_DNS_TIMES);
+    }
+    ExpectLoadTimingHasOnlyConnectionTimes(load_timing_info);
+  }
+
   const BoundTestNetLog& net_log() const { return net_log_; }
 
   QuicChromiumClientSession* session() const { return session_.get(); }
 
  protected:
   BoundTestNetLog net_log_;
   scoped_refptr<TestTaskRunner> runner_;
   std::unique_ptr<MockWrite[]> mock_writes_;
   MockClock clock_;
   QuicConnection* connection_;
@@ skipping 36 matching lines @@
   request.method = "GET";
   request.url = GURL("http://www.google.com/");
   request.end_stream_on_headers = true;
   request.priority = DEFAULT_PRIORITY;
 
   scoped_refptr<IOBuffer> read_buffer(new IOBuffer(kReadBufferSize));
   std::unique_ptr<TestDelegateBase> delegate(
       new TestDelegateBase(read_buffer.get(), kReadBufferSize));
   delegate->Start(&request, net_log().bound(), session()->GetWeakPtr());
   delegate->WaitUntilNextCallback();  // OnStreamReady
+  ConfirmHandshake();
 
   // Server acks the request.
   ProcessPacket(ConstructServerAckPacket(1, 0, 0));
 
   // Server sends the response headers.
   SpdyHeaderBlock response_headers = ConstructResponseHeaders("200");
 
   size_t spdy_response_headers_frame_length;
   QuicStreamOffset offset = 0;
   ProcessPacket(ConstructResponseHeadersPacket(
       2, !kFin, std::move(response_headers),
       &spdy_response_headers_frame_length, &offset));
 
   delegate->WaitUntilNextCallback();  // OnHeadersReceived
+  LoadTimingInfo load_timing_info;
+  EXPECT_TRUE(delegate->GetLoadTimingInfo(&load_timing_info));
+  ExpectLoadTimingValid(load_timing_info, /*session_reused=*/false);
   TestCompletionCallback cb;
   int rv = delegate->ReadData(cb.callback());
   EXPECT_THAT(rv, IsError(ERR_IO_PENDING));
   EXPECT_EQ("200", delegate->response_headers().find(":status")->second);
   const char kResponseBody[] = "Hello world!";
   // Server sends data.
   ProcessPacket(
       ConstructServerDataPacket(3, !kIncludeVersion, !kFin, 0, kResponseBody));
   EXPECT_EQ(12, cb.WaitForResult());
 
@@ skipping 36 matching lines @@
   pos = ExpectLogContainsSomewhere(
       entries, /*min_offset=*/pos,
       NetLogEventType::QUIC_CHROMIUM_CLIENT_STREAM_SEND_REQUEST_HEADERS,
       NetLogEventPhase::NONE);
   ExpectLogContainsSomewhere(
       entries, /*min_offset=*/pos,
       NetLogEventType::QUIC_CHROMIUM_CLIENT_STREAM_SEND_REQUEST_HEADERS,
       NetLogEventPhase::NONE);
 }
 
+TEST_P(BidirectionalStreamQuicImplTest, LoadTimingTwoRequests) {
+  SetRequest("GET", "/", DEFAULT_PRIORITY);
+  QuicStreamOffset offset = 0;
+  AddWrite(ConstructRequestHeadersPacketInner(
+      1, kClientDataStreamId1, kFin, DEFAULT_PRIORITY, nullptr, &offset));
+  // SetRequest() again for second request as |request_headers_| was moved.
+  SetRequest("GET", "/", DEFAULT_PRIORITY);
+  AddWrite(ConstructRequestHeadersPacketInner(
+      2, kClientDataStreamId2, kFin, DEFAULT_PRIORITY, nullptr, &offset));
+  AddWrite(ConstructClientAckPacket(3, 3, 1));
+  Initialize();
+
+  BidirectionalStreamRequestInfo request;
+  request.method = "GET";
+  request.url = GURL("http://www.google.com/");
+  request.end_stream_on_headers = true;
+  request.priority = DEFAULT_PRIORITY;
+
+  // Start first request.
+  scoped_refptr<IOBuffer> read_buffer(new IOBuffer(kReadBufferSize));
+  std::unique_ptr<TestDelegateBase> delegate(
+      new TestDelegateBase(read_buffer.get(), kReadBufferSize));
+  delegate->Start(&request, net_log().bound(), session()->GetWeakPtr());
+
+  // Start second request.
+  scoped_refptr<IOBuffer> read_buffer2(new IOBuffer(kReadBufferSize));
+  std::unique_ptr<TestDelegateBase> delegate2(
+      new TestDelegateBase(read_buffer2.get(), kReadBufferSize));
+  delegate2->Start(&request, net_log().bound(), session()->GetWeakPtr());
+
+  delegate->WaitUntilNextCallback();   // OnStreamReady
+  delegate2->WaitUntilNextCallback();  // OnStreamReady
+
+  ConfirmHandshake();
+  // Server acks the request.
+  ProcessPacket(ConstructServerAckPacket(1, 0, 0));
+
+  // Server sends the response headers.
+  offset = 0;
+  ProcessPacket(ConstructResponseHeadersPacketInner(
+      2, kClientDataStreamId1, kFin, ConstructResponseHeaders("200"), nullptr,
+      &offset));
+
+  ProcessPacket(ConstructResponseHeadersPacketInner(
+      3, kClientDataStreamId2, kFin, ConstructResponseHeaders("200"), nullptr,
+      &offset));
+
+  delegate->WaitUntilNextCallback();   // OnHeadersReceived
+  delegate2->WaitUntilNextCallback();  // OnHeadersReceived
+
+  LoadTimingInfo load_timing_info;
+  EXPECT_TRUE(delegate->GetLoadTimingInfo(&load_timing_info));
+  LoadTimingInfo load_timing_info2;
+  EXPECT_TRUE(delegate2->GetLoadTimingInfo(&load_timing_info2));
+  ExpectLoadTimingValid(load_timing_info, /*session_reused=*/false);
+  ExpectLoadTimingValid(load_timing_info2, /*session_reused=*/true);
+  EXPECT_EQ("200", delegate->response_headers().find(":status")->second);
+  EXPECT_EQ("200", delegate2->response_headers().find(":status")->second);
+  // No response body. ReadData() should return OK synchronously.
+  TestCompletionCallback dummy_callback;
+  EXPECT_EQ(OK, delegate->ReadData(dummy_callback.callback()));
+  EXPECT_EQ(OK, delegate2->ReadData(dummy_callback.callback()));
+}
+
 // Tests that when request headers are not delayed, only data buffers are
 // coalesced.
 TEST_P(BidirectionalStreamQuicImplTest, CoalesceDataBuffersNotHeadersFrame) {
   SetRequest("POST", "/", DEFAULT_PRIORITY);
   size_t spdy_request_headers_frame_length;
 
   const char kBody1[] = "here are some data";
   const char kBody2[] = "data keep coming";
   std::vector<std::string> two_writes = {kBody1, kBody2};
   AddWrite(ConstructRequestHeadersPacket(1, !kFin, DEFAULT_PRIORITY,
@@ skipping 898 matching lines @@
 
   base::RunLoop().RunUntilIdle();
 
   EXPECT_EQ(1, delegate->on_data_read_count());
   EXPECT_EQ(0, delegate->on_data_sent_count());
 }
 
 }  // namespace test
 
 }  // namespace net