diff options
author | mmenke@chromium.org <mmenke@chromium.org@0039d316-1c4b-4281-b951-d872f2087c98> | 2013-01-12 07:11:59 +0000 |
---|---|---|
committer | mmenke@chromium.org <mmenke@chromium.org@0039d316-1c4b-4281-b951-d872f2087c98> | 2013-01-12 07:11:59 +0000 |
commit | b258e079af6287b7a32cdc66b56e47bd249d3ace (patch) | |
tree | b34a7d2a660deb89e208b4575c0f2d7fc10a6e2b /net | |
parent | 9dfa874dead3db8aef47078725578bf1fc845c04 (diff) | |
download | chromium_src-b258e079af6287b7a32cdc66b56e47bd249d3ace.zip chromium_src-b258e079af6287b7a32cdc66b56e47bd249d3ace.tar.gz chromium_src-b258e079af6287b7a32cdc66b56e47bd249d3ace.tar.bz2 |
LoadTiming implementation in net, part 2.
Add LoadTiming interface to HttpStream.
BUG=77446
Review URL: https://codereview.chromium.org/11622007
git-svn-id: svn://svn.chromium.org/chrome/trunk/src@176513 0039d316-1c4b-4281-b951-d872f2087c98
Diffstat (limited to 'net')
24 files changed, 650 insertions, 190 deletions
diff --git a/net/base/load_timing_info_test_util.cc b/net/base/load_timing_info_test_util.cc new file mode 100644 index 0000000..a34a583 --- /dev/null +++ b/net/base/load_timing_info_test_util.cc @@ -0,0 +1,59 @@ +// Copyright (c) 2013 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/base/load_timing_info_test_util.h" + +#include "net/base/load_timing_info.h" +#include "testing/gtest/include/gtest/gtest.h" + +namespace net { + +void ExpectConnectTimingHasNoTimes( + const LoadTimingInfo::ConnectTiming& connect_timing) { + EXPECT_TRUE(connect_timing.dns_start.is_null()); + EXPECT_TRUE(connect_timing.dns_end.is_null()); + EXPECT_TRUE(connect_timing.connect_start.is_null()); + EXPECT_TRUE(connect_timing.connect_end.is_null()); + EXPECT_TRUE(connect_timing.ssl_start.is_null()); + EXPECT_TRUE(connect_timing.ssl_end.is_null()); +} + +void ExpectConnectTimingHasTimes( + const LoadTimingInfo::ConnectTiming& connect_timing, + int connect_timing_flags) { + EXPECT_FALSE(connect_timing.connect_start.is_null()); + EXPECT_LE(connect_timing.connect_start, connect_timing.connect_end); + + if (!(connect_timing_flags & CONNECT_TIMING_HAS_DNS_TIMES)) { + EXPECT_TRUE(connect_timing.dns_start.is_null()); + EXPECT_TRUE(connect_timing.dns_end.is_null()); + } else { + EXPECT_FALSE(connect_timing.dns_start.is_null()); + EXPECT_LE(connect_timing.dns_start, connect_timing.dns_end); + EXPECT_LE(connect_timing.dns_end, connect_timing.connect_start); + } + + if (!(connect_timing_flags & CONNECT_TIMING_HAS_SSL_TIMES)) { + EXPECT_TRUE(connect_timing.ssl_start.is_null()); + EXPECT_TRUE(connect_timing.ssl_start.is_null()); + } else { + EXPECT_FALSE(connect_timing.ssl_start.is_null()); + EXPECT_LE(connect_timing.connect_start, connect_timing.ssl_start); + EXPECT_LE(connect_timing.ssl_start, connect_timing.ssl_end); + EXPECT_LE(connect_timing.ssl_end, connect_timing.connect_end); + } +} + +void ExpectLoadTimingHasOnlyConnectionTimes( + const LoadTimingInfo& load_timing_info) { + EXPECT_TRUE(load_timing_info.request_start_time.is_null()); + EXPECT_TRUE(load_timing_info.request_start.is_null()); + EXPECT_TRUE(load_timing_info.proxy_resolve_start.is_null()); + EXPECT_TRUE(load_timing_info.proxy_resolve_end.is_null()); + EXPECT_TRUE(load_timing_info.send_start.is_null()); + EXPECT_TRUE(load_timing_info.send_end.is_null()); + EXPECT_TRUE(load_timing_info.receive_headers_end.is_null()); +} + +} // namespace net diff --git a/net/base/load_timing_info_test_util.h b/net/base/load_timing_info_test_util.h new file mode 100644 index 0000000..5c2fd17 --- /dev/null +++ b/net/base/load_timing_info_test_util.h @@ -0,0 +1,39 @@ +// Copyright (c) 2013 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. + +#ifndef NET_BASE_LOAD_TIMING_INFO_TEST_UTIL_H_ +#define NET_BASE_LOAD_TIMING_INFO_TEST_UTIL_H_ + +#include "net/base/load_timing_info.h" + +namespace net { + +// Flags indicating which times in a LoadTimingInfo::ConnectTiming struct should +// be non-null. +enum ConnectTimeFlags { + CONNECT_TIMING_HAS_CONNECT_TIMES_ONLY = 0, + CONNECT_TIMING_HAS_DNS_TIMES = 1 << 0, + CONNECT_TIMING_HAS_SSL_TIMES = 1 << 1, +}; + +// Checks that all times in |connect_timing| are null. +void ExpectConnectTimingHasNoTimes( + const LoadTimingInfo::ConnectTiming& connect_timing); + +// Checks that |connect_timing|'s times are in the correct order. +// |connect_start| and |connect_end| must be non-null. Checks null state and +// order of DNS times and SSL times based on |flags|, which must be a +// combination of ConnectTimeFlags. +void ExpectConnectTimingHasTimes( + const LoadTimingInfo::ConnectTiming& connect_timing, + int connect_timing_flags); + +// Tests that all non-connection establishment times in |load_timing_info| are +// null. Its |connect_timing| field is ignored. +void ExpectLoadTimingHasOnlyConnectionTimes( + const LoadTimingInfo& load_timing_info); + +} // namespace net + +#endif // NET_BASE_LOAD_TIMING_INFO_TEST_UTIL_H_ diff --git a/net/http/http_basic_stream.cc b/net/http/http_basic_stream.cc index b39a4cd..b8300df 100644 --- a/net/http/http_basic_stream.cc +++ b/net/http/http_basic_stream.cc @@ -112,6 +112,11 @@ bool HttpBasicStream::IsConnectionReusable() const { return parser_->IsConnectionReusable(); } +bool HttpBasicStream::GetLoadTimingInfo( + LoadTimingInfo* load_timing_info) const { + return connection_->GetLoadTimingInfo(IsConnectionReused(), load_timing_info); +} + void HttpBasicStream::GetSSLInfo(SSLInfo* ssl_info) { parser_->GetSSLInfo(ssl_info); } diff --git a/net/http/http_basic_stream.h b/net/http/http_basic_stream.h index a65fc5b..f0545e2 100644 --- a/net/http/http_basic_stream.h +++ b/net/http/http_basic_stream.h @@ -70,6 +70,9 @@ class HttpBasicStream : public HttpStream { virtual bool IsConnectionReusable() const OVERRIDE; + virtual bool GetLoadTimingInfo( + LoadTimingInfo* load_timing_info) const OVERRIDE; + virtual void GetSSLInfo(SSLInfo* ssl_info) OVERRIDE; virtual void GetSSLCertRequestInfo( diff --git a/net/http/http_pipelined_connection_impl.cc b/net/http/http_pipelined_connection_impl.cc index c8bc02a..d45f69c 100644 --- a/net/http/http_pipelined_connection_impl.cc +++ b/net/http/http_pipelined_connection_impl.cc @@ -661,6 +661,12 @@ void HttpPipelinedConnectionImpl::SetConnectionReused(int pipeline_id) { connection_->set_is_reused(true); } +bool HttpPipelinedConnectionImpl::GetLoadTimingInfo( + int pipeline_id, LoadTimingInfo* load_timing_info) const { + return connection_->GetLoadTimingInfo(IsConnectionReused(pipeline_id), + load_timing_info); +} + void HttpPipelinedConnectionImpl::GetSSLInfo(int pipeline_id, SSLInfo* ssl_info) { CHECK(ContainsKey(stream_info_map_, pipeline_id)); diff --git a/net/http/http_pipelined_connection_impl.h b/net/http/http_pipelined_connection_impl.h index f358c05..eb8dbcd 100644 --- a/net/http/http_pipelined_connection_impl.h +++ b/net/http/http_pipelined_connection_impl.h @@ -31,6 +31,7 @@ class HttpNetworkSession; class HttpRequestHeaders; class HttpResponseInfo; class IOBuffer; +struct LoadTimingInfo; class SSLCertRequestInfo; class SSLInfo; @@ -126,8 +127,10 @@ class NET_EXPORT_PRIVATE HttpPipelinedConnectionImpl void SetConnectionReused(int pipeline_id); - void GetSSLInfo(int pipeline_id, - SSLInfo* ssl_info); + bool GetLoadTimingInfo(int pipeline_id, + LoadTimingInfo* load_timing_info) const; + + void GetSSLInfo(int pipeline_id, SSLInfo* ssl_info); void GetSSLCertRequestInfo(int pipeline_id, SSLCertRequestInfo* cert_request_info); diff --git a/net/http/http_pipelined_connection_impl_unittest.cc b/net/http/http_pipelined_connection_impl_unittest.cc index bbb6001..801e618 100644 --- a/net/http/http_pipelined_connection_impl_unittest.cc +++ b/net/http/http_pipelined_connection_impl_unittest.cc @@ -9,7 +9,10 @@ #include "base/memory/ref_counted.h" #include "base/memory/scoped_ptr.h" #include "base/memory/scoped_vector.h" +#include "net/base/capturing_net_log.h" #include "net/base/io_buffer.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/base/request_priority.h" #include "net/http/http_pipelined_stream.h" @@ -36,6 +39,33 @@ REGISTER_SOCKET_PARAMS_FOR_POOL(MockTransportClientSocketPool, namespace { +// Tests the load timing of a stream that's connected and is not the first +// request sent on a connection. +void TestLoadTimingReused(const HttpStream& stream) { + LoadTimingInfo load_timing_info; + EXPECT_TRUE(stream.GetLoadTimingInfo(&load_timing_info)); + + EXPECT_TRUE(load_timing_info.socket_reused); + EXPECT_NE(NetLog::Source::kInvalidId, load_timing_info.socket_log_id); + + ExpectConnectTimingHasNoTimes(load_timing_info.connect_timing); + ExpectLoadTimingHasOnlyConnectionTimes(load_timing_info); +} + +// Tests the load timing of a stream that's connected and using a fresh +// connection. +void TestLoadTimingNotReused(const HttpStream& stream) { + LoadTimingInfo load_timing_info; + EXPECT_TRUE(stream.GetLoadTimingInfo(&load_timing_info)); + + EXPECT_FALSE(load_timing_info.socket_reused); + EXPECT_NE(NetLog::Source::kInvalidId, load_timing_info.socket_log_id); + + ExpectConnectTimingHasTimes(load_timing_info.connect_timing, + CONNECT_TIMING_HAS_DNS_TIMES); + ExpectLoadTimingHasOnlyConnectionTimes(load_timing_info); +} + class MockPipelineDelegate : public HttpPipelinedConnection::Delegate { public: MOCK_METHOD1(OnPipelineHasCapacity, void(HttpPipelinedConnection* pipeline)); @@ -90,8 +120,12 @@ class HttpPipelinedConnectionImplTest : public testing::Test { factory_.AddSocketDataProvider(data_.get()); scoped_refptr<DummySocketParams> params; ClientSocketHandle* connection = new ClientSocketHandle; + // Only give the connection a real NetLog to make sure that LoadTiming uses + // the connection's ID, rather than the pipeline's. Since pipelines are + // destroyed when they've responded to all requests, but the connection + // lives on, this is an important behavior. connection->Init("a", params, MEDIUM, CompletionCallback(), &pool_, - BoundNetLog()); + net_log_.bound()); pipeline_.reset(new HttpPipelinedConnectionImpl( connection, &delegate_, origin_, ssl_config_, proxy_info_, BoundNetLog(), false, kProtoUnknown)); @@ -145,6 +179,7 @@ class HttpPipelinedConnectionImplTest : public testing::Test { stream->Close(false); } + CapturingBoundNetLog net_log_; DeterministicMockClientSocketFactory factory_; ClientSocketPoolHistograms histograms_; MockTransportClientSocketPool pool_; @@ -176,7 +211,9 @@ TEST_F(HttpPipelinedConnectionImplTest, StreamBoundButNotUsed) { scoped_ptr<HttpStream> stream(NewTestStream("ok.html")); + TestLoadTimingNotReused(*stream); stream->Close(false); + TestLoadTimingNotReused(*stream); } TEST_F(HttpPipelinedConnectionImplTest, SyncSingleRequest) { @@ -191,7 +228,9 @@ TEST_F(HttpPipelinedConnectionImplTest, SyncSingleRequest) { Initialize(reads, arraysize(reads), writes, arraysize(writes)); scoped_ptr<HttpStream> stream(NewTestStream("ok.html")); + TestLoadTimingNotReused(*stream); TestSyncRequest(stream, "ok.html"); + TestLoadTimingNotReused(*stream); } TEST_F(HttpPipelinedConnectionImplTest, AsyncSingleRequest) { @@ -213,12 +252,15 @@ TEST_F(HttpPipelinedConnectionImplTest, AsyncSingleRequest) { callback_.callback())); data_->RunFor(1); EXPECT_LE(OK, callback_.WaitForResult()); + TestLoadTimingNotReused(*stream); EXPECT_EQ(ERR_IO_PENDING, stream->ReadResponseHeaders(callback_.callback())); data_->RunFor(2); EXPECT_LE(OK, callback_.WaitForResult()); + TestLoadTimingNotReused(*stream); ExpectResponse("ok.html", stream, true); + TestLoadTimingNotReused(*stream); stream->Close(false); } @@ -245,11 +287,13 @@ TEST_F(HttpPipelinedConnectionImplTest, LockStepAsyncRequests) { HttpResponseInfo response1; EXPECT_EQ(ERR_IO_PENDING, stream1->SendRequest(headers1, &response1, callback_.callback())); + TestLoadTimingNotReused(*stream1); HttpRequestHeaders headers2; HttpResponseInfo response2; EXPECT_EQ(ERR_IO_PENDING, stream2->SendRequest(headers2, &response2, callback_.callback())); + TestLoadTimingReused(*stream2); data_->RunFor(1); EXPECT_LE(OK, callback_.WaitForResult()); @@ -264,6 +308,9 @@ TEST_F(HttpPipelinedConnectionImplTest, LockStepAsyncRequests) { ExpectResponse("ok.html", stream1, true); + TestLoadTimingNotReused(*stream1); + LoadTimingInfo load_timing_info1; + EXPECT_TRUE(stream1->GetLoadTimingInfo(&load_timing_info1)); stream1->Close(false); data_->RunFor(2); @@ -271,6 +318,11 @@ TEST_F(HttpPipelinedConnectionImplTest, LockStepAsyncRequests) { ExpectResponse("ko.html", stream2, true); + TestLoadTimingReused(*stream2); + LoadTimingInfo load_timing_info2; + EXPECT_TRUE(stream2->GetLoadTimingInfo(&load_timing_info2)); + EXPECT_EQ(load_timing_info1.socket_log_id, + load_timing_info2.socket_log_id); stream2->Close(false); } @@ -331,6 +383,8 @@ TEST_F(HttpPipelinedConnectionImplTest, SendOrderSwapped) { TestSyncRequest(stream2, "ko.html"); TestSyncRequest(stream1, "ok.html"); + TestLoadTimingNotReused(*stream1); + TestLoadTimingReused(*stream2); } TEST_F(HttpPipelinedConnectionImplTest, ReadOrderSwapped) { diff --git a/net/http/http_pipelined_stream.cc b/net/http/http_pipelined_stream.cc index 236d475..6b588a8 100644 --- a/net/http/http_pipelined_stream.cc +++ b/net/http/http_pipelined_stream.cc @@ -102,6 +102,11 @@ bool HttpPipelinedStream::IsConnectionReusable() const { return pipeline_->usable(); } +bool HttpPipelinedStream::GetLoadTimingInfo( + LoadTimingInfo* load_timing_info) const { + return pipeline_->GetLoadTimingInfo(pipeline_id_, load_timing_info); +} + void HttpPipelinedStream::GetSSLInfo(SSLInfo* ssl_info) { pipeline_->GetSSLInfo(pipeline_id_, ssl_info); } diff --git a/net/http/http_pipelined_stream.h b/net/http/http_pipelined_stream.h index 6379d7c..a1319e9 100644 --- a/net/http/http_pipelined_stream.h +++ b/net/http/http_pipelined_stream.h @@ -70,6 +70,9 @@ class HttpPipelinedStream : public HttpStream { virtual bool IsConnectionReusable() const OVERRIDE; + virtual bool GetLoadTimingInfo( + LoadTimingInfo* load_timing_info) const OVERRIDE; + virtual void GetSSLInfo(SSLInfo* ssl_info) OVERRIDE; virtual void GetSSLCertRequestInfo( diff --git a/net/http/http_response_body_drainer_unittest.cc b/net/http/http_response_body_drainer_unittest.cc index a052cd6..6294a3e 100644 --- a/net/http/http_response_body_drainer_unittest.cc +++ b/net/http/http_response_body_drainer_unittest.cc @@ -124,6 +124,9 @@ class MockHttpStream : public HttpStream { virtual void LogNumRttVsBytesMetrics() const OVERRIDE {} + virtual bool GetLoadTimingInfo( + LoadTimingInfo* load_timing_info) const OVERRIDE { return false; } + virtual void Drain(HttpNetworkSession*) OVERRIDE {} // Methods to tweak/observer mock behavior: diff --git a/net/http/http_stream_base.h b/net/http/http_stream_base.h index 0a37f27..06d0291 100644 --- a/net/http/http_stream_base.h +++ b/net/http/http_stream_base.h @@ -26,6 +26,7 @@ class HttpRequestHeaders; struct HttpRequestInfo; class HttpResponseInfo; class IOBuffer; +struct LoadTimingInfo; class SSLCertRequestInfo; class SSLInfo; @@ -107,6 +108,17 @@ class NET_EXPORT_PRIVATE HttpStreamBase { // allows it to be reused. virtual bool IsConnectionReusable() const = 0; + // Populates the connection establishment part of |load_timing_info|, and + // socket ID. |load_timing_info| must have all null times when called. + // Returns false and does nothing if there is no underlying connection, either + // because one has yet to be assigned to the stream, or because the underlying + // socket has been closed. + // + // In practice, this means that this function will always succeed any time + // between when the full headers have been received and the stream has been + // closed. + virtual bool GetLoadTimingInfo(LoadTimingInfo* load_timing_info) const = 0; + // Get the SSLInfo associated with this stream's connection. This should // only be called for streams over SSL sockets, otherwise the behavior is // undefined. diff --git a/net/net.gyp b/net/net.gyp index b14331e..408a330 100644 --- a/net/net.gyp +++ b/net/net.gyp @@ -1855,6 +1855,8 @@ 'base/capturing_net_log.h', 'base/cert_test_util.cc', 'base/cert_test_util.h', + 'base/load_timing_info_test_util.cc', + 'base/load_timing_info_test_util.h', 'base/mock_cert_verifier.cc', 'base/mock_cert_verifier.h', 'base/mock_file_stream.cc', diff --git a/net/quic/quic_http_stream.cc b/net/quic/quic_http_stream.cc index 7354bc4..bd3073a 100644 --- a/net/quic/quic_http_stream.cc +++ b/net/quic/quic_http_stream.cc @@ -201,6 +201,11 @@ bool QuicHttpStream::IsConnectionReusable() const { return false; } +bool QuicHttpStream::GetLoadTimingInfo(LoadTimingInfo* load_timing_info) const { + // TODO(mmenke): Figure out what to do here. + return true; +} + void QuicHttpStream::GetSSLInfo(SSLInfo* ssl_info) { DCHECK(stream_); NOTIMPLEMENTED(); diff --git a/net/quic/quic_http_stream.h b/net/quic/quic_http_stream.h index 3803a7b..0ca1f81 100644 --- a/net/quic/quic_http_stream.h +++ b/net/quic/quic_http_stream.h @@ -46,6 +46,8 @@ class NET_EXPORT_PRIVATE QuicHttpStream : virtual bool IsConnectionReused() const OVERRIDE; virtual void SetConnectionReused() OVERRIDE; virtual bool IsConnectionReusable() const OVERRIDE; + virtual bool GetLoadTimingInfo( + LoadTimingInfo* load_timing_info) const OVERRIDE; virtual void GetSSLInfo(SSLInfo* ssl_info) OVERRIDE; virtual void GetSSLCertRequestInfo( SSLCertRequestInfo* cert_request_info) OVERRIDE; diff --git a/net/socket/client_socket_pool_base_unittest.cc b/net/socket/client_socket_pool_base_unittest.cc index d966e3e..ca19b6f 100644 --- a/net/socket/client_socket_pool_base_unittest.cc +++ b/net/socket/client_socket_pool_base_unittest.cc @@ -20,6 +20,7 @@ #include "base/threading/platform_thread.h" #include "base/values.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/base/net_log.h" #include "net/base/net_log_unittest.h" @@ -56,17 +57,8 @@ void TestLoadTimingInfoConnectedReused(const ClientSocketHandle& handle) { EXPECT_EQ(true, load_timing_info.socket_reused); EXPECT_NE(NetLog::Source::kInvalidId, load_timing_info.socket_log_id); - EXPECT_TRUE(load_timing_info.connect_timing.connect_start.is_null()); - EXPECT_TRUE(load_timing_info.connect_timing.connect_end.is_null()); - EXPECT_TRUE(load_timing_info.connect_timing.dns_start.is_null()); - EXPECT_TRUE(load_timing_info.connect_timing.dns_end.is_null()); - EXPECT_TRUE(load_timing_info.connect_timing.ssl_start.is_null()); - EXPECT_TRUE(load_timing_info.connect_timing.ssl_end.is_null()); - EXPECT_TRUE(load_timing_info.proxy_resolve_start.is_null()); - EXPECT_TRUE(load_timing_info.proxy_resolve_end.is_null()); - EXPECT_TRUE(load_timing_info.send_start.is_null()); - EXPECT_TRUE(load_timing_info.send_end.is_null()); - EXPECT_TRUE(load_timing_info.receive_headers_end.is_null()); + ExpectConnectTimingHasNoTimes(load_timing_info.connect_timing); + ExpectLoadTimingHasOnlyConnectionTimes(load_timing_info); } // Make sure |handle| sets load times correctly when it has been assigned a @@ -82,18 +74,9 @@ void TestLoadTimingInfoConnectedNotReused(const ClientSocketHandle& handle) { EXPECT_FALSE(load_timing_info.socket_reused); EXPECT_NE(NetLog::Source::kInvalidId, load_timing_info.socket_log_id); - EXPECT_FALSE(load_timing_info.connect_timing.connect_start.is_null()); - EXPECT_LE(load_timing_info.connect_timing.connect_start, - load_timing_info.connect_timing.connect_end); - EXPECT_TRUE(load_timing_info.connect_timing.dns_start.is_null()); - EXPECT_TRUE(load_timing_info.connect_timing.dns_end.is_null()); - EXPECT_TRUE(load_timing_info.connect_timing.ssl_start.is_null()); - EXPECT_TRUE(load_timing_info.connect_timing.ssl_end.is_null()); - EXPECT_TRUE(load_timing_info.proxy_resolve_start.is_null()); - EXPECT_TRUE(load_timing_info.proxy_resolve_end.is_null()); - EXPECT_TRUE(load_timing_info.send_start.is_null()); - EXPECT_TRUE(load_timing_info.send_end.is_null()); - EXPECT_TRUE(load_timing_info.receive_headers_end.is_null()); + ExpectConnectTimingHasTimes(load_timing_info.connect_timing, + CONNECT_TIMING_HAS_CONNECT_TIMES_ONLY); + ExpectLoadTimingHasOnlyConnectionTimes(load_timing_info); TestLoadTimingInfoConnectedReused(handle); } @@ -110,17 +93,8 @@ void TestLoadTimingInfoNotConnected(const ClientSocketHandle& handle) { EXPECT_FALSE(load_timing_info.socket_reused); EXPECT_EQ(NetLog::Source::kInvalidId, load_timing_info.socket_log_id); - EXPECT_TRUE(load_timing_info.connect_timing.connect_start.is_null()); - EXPECT_TRUE(load_timing_info.connect_timing.connect_end.is_null()); - EXPECT_TRUE(load_timing_info.connect_timing.dns_start.is_null()); - EXPECT_TRUE(load_timing_info.connect_timing.dns_end.is_null()); - EXPECT_TRUE(load_timing_info.connect_timing.ssl_start.is_null()); - EXPECT_TRUE(load_timing_info.connect_timing.ssl_end.is_null()); - EXPECT_TRUE(load_timing_info.proxy_resolve_start.is_null()); - EXPECT_TRUE(load_timing_info.proxy_resolve_end.is_null()); - EXPECT_TRUE(load_timing_info.send_start.is_null()); - EXPECT_TRUE(load_timing_info.send_end.is_null()); - EXPECT_TRUE(load_timing_info.receive_headers_end.is_null()); + ExpectConnectTimingHasNoTimes(load_timing_info.connect_timing); + ExpectLoadTimingHasOnlyConnectionTimes(load_timing_info); } class TestSocketParams : public base::RefCounted<TestSocketParams> { diff --git a/net/socket/socks_client_socket_pool_unittest.cc b/net/socket/socks_client_socket_pool_unittest.cc index e69a297..ab559ca 100644 --- a/net/socket/socks_client_socket_pool_unittest.cc +++ b/net/socket/socks_client_socket_pool_unittest.cc @@ -8,6 +8,7 @@ #include "base/compiler_specific.h" #include "base/time.h" #include "net/base/load_timing_info.h" +#include "net/base/load_timing_info_test_util.h" #include "net/base/mock_host_resolver.h" #include "net/base/net_errors.h" #include "net/base/test_completion_callback.h" @@ -35,20 +36,9 @@ void TestLoadTimingInfo(const ClientSocketHandle& handle) { EXPECT_FALSE(load_timing_info.socket_reused); - EXPECT_FALSE(load_timing_info.connect_timing.connect_start.is_null()); - EXPECT_LE(load_timing_info.connect_timing.connect_start, - load_timing_info.connect_timing.connect_end); - - // None of these should be set by the socket handle. - EXPECT_TRUE(load_timing_info.proxy_resolve_start.is_null()); - EXPECT_TRUE(load_timing_info.proxy_resolve_end.is_null()); - EXPECT_TRUE(load_timing_info.connect_timing.dns_start.is_null()); - EXPECT_TRUE(load_timing_info.connect_timing.dns_end.is_null()); - EXPECT_TRUE(load_timing_info.connect_timing.ssl_start.is_null()); - EXPECT_TRUE(load_timing_info.connect_timing.ssl_end.is_null()); - EXPECT_TRUE(load_timing_info.send_start.is_null()); - EXPECT_TRUE(load_timing_info.send_end.is_null()); - EXPECT_TRUE(load_timing_info.receive_headers_end.is_null()); + ExpectConnectTimingHasTimes(load_timing_info.connect_timing, + CONNECT_TIMING_HAS_CONNECT_TIMES_ONLY); + ExpectLoadTimingHasOnlyConnectionTimes(load_timing_info); } class SOCKSClientSocketPoolTest : public testing::Test { diff --git a/net/socket/ssl_client_socket_pool_unittest.cc b/net/socket/ssl_client_socket_pool_unittest.cc index 0a8b87a..22b6ffa 100644 --- a/net/socket/ssl_client_socket_pool_unittest.cc +++ b/net/socket/ssl_client_socket_pool_unittest.cc @@ -12,6 +12,7 @@ #include "net/base/auth.h" #include "net/base/cert_verifier.h" #include "net/base/load_timing_info.h" +#include "net/base/load_timing_info_test_util.h" #include "net/base/mock_host_resolver.h" #include "net/base/net_errors.h" #include "net/base/ssl_config_service_defaults.h" @@ -51,24 +52,10 @@ void TestLoadTimingInfo(const ClientSocketHandle& handle) { // None of these tests use a NetLog. EXPECT_EQ(NetLog::Source::kInvalidId, load_timing_info.socket_log_id); - EXPECT_FALSE(load_timing_info.connect_timing.dns_start.is_null()); - EXPECT_LE(load_timing_info.connect_timing.dns_start, - load_timing_info.connect_timing.dns_end); - EXPECT_LE(load_timing_info.connect_timing.dns_end, - load_timing_info.connect_timing.connect_start); - EXPECT_LE(load_timing_info.connect_timing.connect_start, - load_timing_info.connect_timing.ssl_start); - EXPECT_LE(load_timing_info.connect_timing.ssl_start, - load_timing_info.connect_timing.ssl_end); - EXPECT_LE(load_timing_info.connect_timing.ssl_end, - load_timing_info.connect_timing.connect_end); - - // None of these should be set by the socket handle. - EXPECT_TRUE(load_timing_info.proxy_resolve_start.is_null()); - EXPECT_TRUE(load_timing_info.proxy_resolve_end.is_null()); - EXPECT_TRUE(load_timing_info.send_start.is_null()); - EXPECT_TRUE(load_timing_info.send_end.is_null()); - EXPECT_TRUE(load_timing_info.receive_headers_end.is_null()); + ExpectConnectTimingHasTimes( + load_timing_info.connect_timing, + CONNECT_TIMING_HAS_SSL_TIMES | CONNECT_TIMING_HAS_DNS_TIMES); + ExpectLoadTimingHasOnlyConnectionTimes(load_timing_info); } // Just like TestLoadTimingInfo, except DNS times are expected to be null, for @@ -82,22 +69,9 @@ void TestLoadTimingInfoNoDns(const ClientSocketHandle& handle) { EXPECT_FALSE(load_timing_info.socket_reused); - EXPECT_TRUE(load_timing_info.connect_timing.dns_start.is_null()); - EXPECT_TRUE(load_timing_info.connect_timing.dns_end.is_null()); - EXPECT_FALSE(load_timing_info.connect_timing.connect_start.is_null()); - EXPECT_LE(load_timing_info.connect_timing.connect_start, - load_timing_info.connect_timing.ssl_start); - EXPECT_LE(load_timing_info.connect_timing.ssl_start, - load_timing_info.connect_timing.ssl_end); - EXPECT_LE(load_timing_info.connect_timing.ssl_end, - load_timing_info.connect_timing.connect_end); - - // None of these should be set by the socket handle. - EXPECT_TRUE(load_timing_info.proxy_resolve_start.is_null()); - EXPECT_TRUE(load_timing_info.proxy_resolve_end.is_null()); - EXPECT_TRUE(load_timing_info.send_start.is_null()); - EXPECT_TRUE(load_timing_info.send_end.is_null()); - EXPECT_TRUE(load_timing_info.receive_headers_end.is_null()); + ExpectConnectTimingHasTimes(load_timing_info.connect_timing, + CONNECT_TIMING_HAS_SSL_TIMES); + ExpectLoadTimingHasOnlyConnectionTimes(load_timing_info); } class SSLClientSocketPoolTest : public testing::Test { diff --git a/net/socket/transport_client_socket_pool_unittest.cc b/net/socket/transport_client_socket_pool_unittest.cc index 61a10e1..6a3d896 100644 --- a/net/socket/transport_client_socket_pool_unittest.cc +++ b/net/socket/transport_client_socket_pool_unittest.cc @@ -14,6 +14,7 @@ #include "net/base/capturing_net_log.h" #include "net/base/ip_endpoint.h" #include "net/base/load_timing_info.h" +#include "net/base/load_timing_info_test_util.h" #include "net/base/mock_host_resolver.h" #include "net/base/net_errors.h" #include "net/base/net_util.h" @@ -46,17 +47,8 @@ void TestLoadTimingInfoConnectedReused(const ClientSocketHandle& handle) { EXPECT_TRUE(load_timing_info.socket_reused); EXPECT_NE(NetLog::Source::kInvalidId, load_timing_info.socket_log_id); - EXPECT_TRUE(load_timing_info.connect_timing.connect_start.is_null()); - EXPECT_TRUE(load_timing_info.connect_timing.connect_end.is_null()); - EXPECT_TRUE(load_timing_info.connect_timing.dns_start.is_null()); - EXPECT_TRUE(load_timing_info.connect_timing.dns_end.is_null()); - EXPECT_TRUE(load_timing_info.connect_timing.ssl_start.is_null()); - EXPECT_TRUE(load_timing_info.connect_timing.ssl_end.is_null()); - EXPECT_TRUE(load_timing_info.proxy_resolve_start.is_null()); - EXPECT_TRUE(load_timing_info.proxy_resolve_end.is_null()); - EXPECT_TRUE(load_timing_info.send_start.is_null()); - EXPECT_TRUE(load_timing_info.send_end.is_null()); - EXPECT_TRUE(load_timing_info.receive_headers_end.is_null()); + ExpectConnectTimingHasNoTimes(load_timing_info.connect_timing); + ExpectLoadTimingHasOnlyConnectionTimes(load_timing_info); } // Make sure |handle| sets load times correctly when it has been assigned a @@ -72,21 +64,9 @@ void TestLoadTimingInfoConnectedNotReused(const ClientSocketHandle& handle) { EXPECT_FALSE(load_timing_info.socket_reused); EXPECT_NE(NetLog::Source::kInvalidId, load_timing_info.socket_log_id); - EXPECT_FALSE(load_timing_info.connect_timing.dns_start.is_null()); - EXPECT_LE(load_timing_info.connect_timing.dns_start, - load_timing_info.connect_timing.dns_end); - EXPECT_LE(load_timing_info.connect_timing.dns_end, - load_timing_info.connect_timing.connect_start); - EXPECT_LE(load_timing_info.connect_timing.connect_start, - load_timing_info.connect_timing.connect_end); - - EXPECT_TRUE(load_timing_info.connect_timing.ssl_start.is_null()); - EXPECT_TRUE(load_timing_info.connect_timing.ssl_end.is_null()); - EXPECT_TRUE(load_timing_info.proxy_resolve_start.is_null()); - EXPECT_TRUE(load_timing_info.proxy_resolve_end.is_null()); - EXPECT_TRUE(load_timing_info.send_start.is_null()); - EXPECT_TRUE(load_timing_info.send_end.is_null()); - EXPECT_TRUE(load_timing_info.receive_headers_end.is_null()); + ExpectConnectTimingHasTimes(load_timing_info.connect_timing, + CONNECT_TIMING_HAS_DNS_TIMES); + ExpectLoadTimingHasOnlyConnectionTimes(load_timing_info); TestLoadTimingInfoConnectedReused(handle); } diff --git a/net/spdy/spdy_http_stream.cc b/net/spdy/spdy_http_stream.cc index ab1b32f..b49b9f7 100644 --- a/net/spdy/spdy_http_stream.cc +++ b/net/spdy/spdy_http_stream.cc @@ -185,6 +185,17 @@ bool SpdyHttpStream::IsConnectionReusable() const { return false; } +bool SpdyHttpStream::GetLoadTimingInfo(LoadTimingInfo* load_timing_info) const { + // If |stream_| has yet to be created, or does not yet have an ID, fail. + // The reused flag can only be correctly set once a stream has an ID. Streams + // get their IDs once the request has been successfully sent, so this does not + // behave that differently from other stream types. + if (!stream_ || stream_->stream_id() == 0) + return false; + return spdy_session_->GetLoadTimingInfo(stream_->stream_id(), + load_timing_info); +} + int SpdyHttpStream::SendRequest(const HttpRequestHeaders& request_headers, HttpResponseInfo* response, const CompletionCallback& callback) { diff --git a/net/spdy/spdy_http_stream.h b/net/spdy/spdy_http_stream.h index ddd2ccb..5e2e55e 100644 --- a/net/spdy/spdy_http_stream.h +++ b/net/spdy/spdy_http_stream.h @@ -60,6 +60,8 @@ class NET_EXPORT_PRIVATE SpdyHttpStream : public SpdyStream::Delegate, virtual bool IsConnectionReused() const OVERRIDE; virtual void SetConnectionReused() OVERRIDE; virtual bool IsConnectionReusable() const OVERRIDE; + virtual bool GetLoadTimingInfo( + LoadTimingInfo* load_timing_info) const OVERRIDE; virtual void GetSSLInfo(SSLInfo* ssl_info) OVERRIDE; virtual void GetSSLCertRequestInfo( SSLCertRequestInfo* cert_request_info) OVERRIDE; diff --git a/net/spdy/spdy_http_stream_spdy2_unittest.cc b/net/spdy/spdy_http_stream_spdy2_unittest.cc index 88e2fa9..4ecd840 100644 --- a/net/spdy/spdy_http_stream_spdy2_unittest.cc +++ b/net/spdy/spdy_http_stream_spdy2_unittest.cc @@ -8,7 +8,10 @@ #include "crypto/ec_signature_creator.h" #include "crypto/signature_creator.h" #include "net/base/asn1_util.h" +#include "net/base/capturing_net_log.h" #include "net/base/default_server_bound_cert_store.h" +#include "net/base/load_timing_info.h" +#include "net/base/load_timing_info_test_util.h" #include "net/base/upload_data_stream.h" #include "net/base/upload_element_reader.h" #include "net/http/http_request_info.h" @@ -22,12 +25,50 @@ using namespace net::test_spdy2; namespace net { +namespace { + +// Tests the load timing of a stream that's connected and is not the first +// request sent on a connection. +void TestLoadTimingReused(const HttpStream& stream) { + LoadTimingInfo load_timing_info; + EXPECT_TRUE(stream.GetLoadTimingInfo(&load_timing_info)); + + EXPECT_TRUE(load_timing_info.socket_reused); + EXPECT_NE(NetLog::Source::kInvalidId, load_timing_info.socket_log_id); + + ExpectConnectTimingHasNoTimes(load_timing_info.connect_timing); + ExpectLoadTimingHasOnlyConnectionTimes(load_timing_info); +} + +// Tests the load timing of a stream that's connected and using a fresh +// connection. +void TestLoadTimingNotReused(const HttpStream& stream) { + LoadTimingInfo load_timing_info; + EXPECT_TRUE(stream.GetLoadTimingInfo(&load_timing_info)); + + EXPECT_FALSE(load_timing_info.socket_reused); + EXPECT_NE(NetLog::Source::kInvalidId, load_timing_info.socket_log_id); + + ExpectConnectTimingHasTimes(load_timing_info.connect_timing, + CONNECT_TIMING_HAS_DNS_TIMES); + ExpectLoadTimingHasOnlyConnectionTimes(load_timing_info); +} + +} // namespace + class SpdyHttpStreamSpdy2Test : public testing::Test { public: + SpdyHttpStreamSpdy2Test() { + session_deps_.net_log = &net_log_; + } + + DeterministicSocketData* deterministic_data() { + return deterministic_data_.get(); + } + OrderedSocketData* data() { return data_.get(); } - protected: - SpdyHttpStreamSpdy2Test() {} + protected: virtual void TearDown() { crypto::ECSignatureCreator::SetFactoryForTesting(NULL); UploadDataStream::ResetMergeChunks(); @@ -38,6 +79,38 @@ class SpdyHttpStreamSpdy2Test : public testing::Test { UploadDataStream::set_merge_chunks(merge); } + // Initializes the session using DeterministicSocketData. It's advisable + // to use this function rather than the OrderedSocketData, since the + // DeterministicSocketData behaves in a reasonable manner. + int InitSessionDeterministic(MockRead* reads, size_t reads_count, + MockWrite* writes, size_t writes_count, + HostPortPair& host_port_pair) { + HostPortProxyPair pair(host_port_pair, ProxyServer::Direct()); + deterministic_data_.reset( + new DeterministicSocketData(reads, reads_count, writes, writes_count)); + session_deps_.deterministic_socket_factory->AddSocketDataProvider( + deterministic_data_.get()); + http_session_ = + SpdySessionDependencies::SpdyCreateSessionDeterministic(&session_deps_); + session_ = http_session_->spdy_session_pool()->Get(pair, BoundNetLog()); + transport_params_ = new TransportSocketParams(host_port_pair, + MEDIUM, false, false, + OnHostResolutionCallback()); + TestCompletionCallback callback; + scoped_ptr<ClientSocketHandle> connection(new ClientSocketHandle); + EXPECT_EQ(ERR_IO_PENDING, + connection->Init(host_port_pair.ToString(), + transport_params_, + MEDIUM, + callback.callback(), + http_session_->GetTransportSocketPool( + HttpNetworkSession::NORMAL_SOCKET_POOL), + BoundNetLog())); + EXPECT_EQ(OK, callback.WaitForResult()); + return session_->InitializeWithSocket(connection.release(), false, OK); + } + + // Initializes the session using the finicky OrderedSocketData class. int InitSession(MockRead* reads, size_t reads_count, MockWrite* writes, size_t writes_count, HostPortPair& host_port_pair) { @@ -64,8 +137,10 @@ class SpdyHttpStreamSpdy2Test : public testing::Test { return session_->InitializeWithSocket(connection.release(), false, OK); } + CapturingNetLog net_log_; SpdySessionDependencies session_deps_; scoped_ptr<OrderedSocketData> data_; + scoped_ptr<DeterministicSocketData> deterministic_data_; scoped_refptr<HttpNetworkSession> http_session_; scoped_refptr<SpdySession> session_; scoped_refptr<TransportSocketParams> transport_params_; @@ -96,17 +171,26 @@ TEST_F(SpdyHttpStreamSpdy2Test, SendRequest) { BoundNetLog net_log; scoped_ptr<SpdyHttpStream> http_stream( new SpdyHttpStream(session_.get(), true)); + // Make sure getting load timing information the stream early does not crash. + LoadTimingInfo load_timing_info; + EXPECT_FALSE(http_stream->GetLoadTimingInfo(&load_timing_info)); + ASSERT_EQ( OK, http_stream->InitializeStream(&request, net_log, CompletionCallback())); + EXPECT_FALSE(http_stream->GetLoadTimingInfo(&load_timing_info)); EXPECT_EQ(ERR_IO_PENDING, http_stream->SendRequest(headers, &response, callback.callback())); EXPECT_TRUE(http_session_->spdy_session_pool()->HasSession(pair)); + EXPECT_FALSE(http_stream->GetLoadTimingInfo(&load_timing_info)); // This triggers the MockWrite and read 2 callback.WaitForResult(); + // Can get timing information once the stream connects. + TestLoadTimingNotReused(*http_stream); + // This triggers read 3. The empty read causes the session to shut down. data()->CompleteRead(); @@ -115,6 +199,100 @@ TEST_F(SpdyHttpStreamSpdy2Test, SendRequest) { EXPECT_FALSE(http_session_->spdy_session_pool()->HasSession(pair)); EXPECT_TRUE(data()->at_read_eof()); EXPECT_TRUE(data()->at_write_eof()); + + TestLoadTimingNotReused(*http_stream); + http_stream->Close(true); + // Test that there's no crash when trying to get the load timing after the + // stream has been closed. + TestLoadTimingNotReused(*http_stream); +} + +TEST_F(SpdyHttpStreamSpdy2Test, LoadTimingTwoRequests) { + scoped_ptr<SpdyFrame> req1(ConstructSpdyGet(NULL, 0, false, 1, LOWEST)); + scoped_ptr<SpdyFrame> req2(ConstructSpdyGet(NULL, 0, false, 3, LOWEST)); + MockWrite writes[] = { + CreateMockWrite(*req1, 0), + CreateMockWrite(*req2, 1), + }; + scoped_ptr<SpdyFrame> resp1(ConstructSpdyGetSynReply(NULL, 0, 1)); + scoped_ptr<SpdyFrame> body1(ConstructSpdyBodyFrame(1, "", 0, true)); + scoped_ptr<SpdyFrame> resp2(ConstructSpdyGetSynReply(NULL, 0, 3)); + scoped_ptr<SpdyFrame> body2(ConstructSpdyBodyFrame(3, "", 0, true)); + MockRead reads[] = { + CreateMockRead(*resp1, 2), + CreateMockRead(*body1, 3), + CreateMockRead(*resp2, 4), + CreateMockRead(*body2, 5), + MockRead(ASYNC, 0, 6) // EOF + }; + + HostPortPair host_port_pair("www.google.com", 80); + HostPortProxyPair pair(host_port_pair, ProxyServer::Direct()); + ASSERT_EQ(OK, InitSessionDeterministic(reads, arraysize(reads), + writes, arraysize(writes), + host_port_pair)); + + HttpRequestInfo request1; + request1.method = "GET"; + request1.url = GURL("http://www.google.com/"); + TestCompletionCallback callback1; + HttpResponseInfo response1; + HttpRequestHeaders headers1; + scoped_ptr<SpdyHttpStream> http_stream1( + new SpdyHttpStream(session_.get(), true)); + + ASSERT_EQ(OK, + http_stream1->InitializeStream(&request1, BoundNetLog(), + CompletionCallback())); + EXPECT_EQ(ERR_IO_PENDING, http_stream1->SendRequest(headers1, &response1, + callback1.callback())); + EXPECT_TRUE(http_session_->spdy_session_pool()->HasSession(pair)); + + HttpRequestInfo request2; + request2.method = "GET"; + request2.url = GURL("http://www.google.com/"); + TestCompletionCallback callback2; + HttpResponseInfo response2; + HttpRequestHeaders headers2; + scoped_ptr<SpdyHttpStream> http_stream2( + new SpdyHttpStream(session_.get(), true)); + + ASSERT_EQ(OK, + http_stream2->InitializeStream(&request2, BoundNetLog(), + CompletionCallback())); + EXPECT_EQ(ERR_IO_PENDING, http_stream2->SendRequest(headers2, &response2, + callback2.callback())); + EXPECT_TRUE(http_session_->spdy_session_pool()->HasSession(pair)); + + // First write. + deterministic_data()->RunFor(1); + EXPECT_LE(0, callback1.WaitForResult()); + + TestLoadTimingNotReused(*http_stream1); + LoadTimingInfo load_timing_info1; + LoadTimingInfo load_timing_info2; + EXPECT_TRUE(http_stream1->GetLoadTimingInfo(&load_timing_info1)); + EXPECT_FALSE(http_stream2->GetLoadTimingInfo(&load_timing_info2)); + + // Second write. + deterministic_data()->RunFor(1); + EXPECT_LE(0, callback2.WaitForResult()); + TestLoadTimingReused(*http_stream2); + EXPECT_TRUE(http_stream2->GetLoadTimingInfo(&load_timing_info2)); + EXPECT_EQ(load_timing_info1.socket_log_id, load_timing_info2.socket_log_id); + + // All the reads. + deterministic_data()->RunFor(6); + + // Read stream 1 to completion, before making sure we can still read load + // timing from both streams. + scoped_refptr<IOBuffer> buf1(new IOBuffer(1)); + ASSERT_EQ(0, http_stream1->ReadResponseBody(buf1, 1, callback1.callback())); + + // Stream 1 has been read to completion. + TestLoadTimingNotReused(*http_stream1); + // Stream 2 still has queued body data. + TestLoadTimingReused(*http_stream2); } TEST_F(SpdyHttpStreamSpdy2Test, SendChunkedPost) { @@ -209,35 +387,9 @@ TEST_F(SpdyHttpStreamSpdy2Test, DelayedSendChunkedPost) { HostPortPair host_port_pair("www.google.com", 80); HostPortProxyPair pair(host_port_pair, ProxyServer::Direct()); - DeterministicSocketData data(reads, arraysize(reads), - writes, arraysize(writes)); - - DeterministicMockClientSocketFactory* socket_factory = - session_deps_.deterministic_socket_factory.get(); - socket_factory->AddSocketDataProvider(&data); - - http_session_ = SpdySessionDependencies::SpdyCreateSessionDeterministic( - &session_deps_); - session_ = http_session_->spdy_session_pool()->Get(pair, BoundNetLog()); - transport_params_ = new TransportSocketParams(host_port_pair, - MEDIUM, false, false, - OnHostResolutionCallback()); - - TestCompletionCallback callback; - scoped_ptr<ClientSocketHandle> connection(new ClientSocketHandle); - - EXPECT_EQ(ERR_IO_PENDING, - connection->Init(host_port_pair.ToString(), - transport_params_, - MEDIUM, - callback.callback(), - http_session_->GetTransportSocketPool( - HttpNetworkSession::NORMAL_SOCKET_POOL), - BoundNetLog())); - - callback.WaitForResult(); - EXPECT_EQ(OK, - session_->InitializeWithSocket(connection.release(), false, OK)); + ASSERT_EQ(OK, InitSessionDeterministic(reads, arraysize(reads), + writes, arraysize(writes), + host_port_pair)); UploadDataStream upload_stream(UploadDataStream::CHUNKED, 0); @@ -258,6 +410,7 @@ TEST_F(SpdyHttpStreamSpdy2Test, DelayedSendChunkedPost) { HttpRequestHeaders headers; HttpResponseInfo response; + TestCompletionCallback callback; // This will attempt to Write() the initial request and headers, which will // complete asynchronously. EXPECT_EQ(ERR_IO_PENDING, http_stream->SendRequest(headers, &response, @@ -265,7 +418,7 @@ TEST_F(SpdyHttpStreamSpdy2Test, DelayedSendChunkedPost) { EXPECT_TRUE(http_session_->spdy_session_pool()->HasSession(pair)); // Complete the initial request write and the first chunk. - data.RunFor(2); + deterministic_data()->RunFor(2); ASSERT_TRUE(callback.have_result()); EXPECT_GT(callback.WaitForResult(), 0); @@ -274,14 +427,14 @@ TEST_F(SpdyHttpStreamSpdy2Test, DelayedSendChunkedPost) { upload_stream.AppendChunk(kUploadData, kUploadDataSize, true); // Finish writing all the chunks. - data.RunFor(2); + deterministic_data()->RunFor(2); // Read response headers. - data.RunFor(1); + deterministic_data()->RunFor(1); ASSERT_EQ(OK, http_stream->ReadResponseHeaders(callback.callback())); // Read and check |chunk1| response. - data.RunFor(1); + deterministic_data()->RunFor(1); scoped_refptr<IOBuffer> buf1(new IOBuffer(kUploadDataSize)); ASSERT_EQ(kUploadDataSize, http_stream->ReadResponseBody(buf1, @@ -290,7 +443,7 @@ TEST_F(SpdyHttpStreamSpdy2Test, DelayedSendChunkedPost) { EXPECT_EQ(kUploadData, std::string(buf1->data(), kUploadDataSize)); // Read and check |chunk2| response. - data.RunFor(1); + deterministic_data()->RunFor(1); scoped_refptr<IOBuffer> buf2(new IOBuffer(kUploadData1Size)); ASSERT_EQ(kUploadData1Size, http_stream->ReadResponseBody(buf2, @@ -299,7 +452,7 @@ TEST_F(SpdyHttpStreamSpdy2Test, DelayedSendChunkedPost) { EXPECT_EQ(kUploadData1, std::string(buf2->data(), kUploadData1Size)); // Read and check |chunk3| response. - data.RunFor(1); + deterministic_data()->RunFor(1); scoped_refptr<IOBuffer> buf3(new IOBuffer(kUploadDataSize)); ASSERT_EQ(kUploadDataSize, http_stream->ReadResponseBody(buf3, @@ -308,11 +461,11 @@ TEST_F(SpdyHttpStreamSpdy2Test, DelayedSendChunkedPost) { EXPECT_EQ(kUploadData, std::string(buf3->data(), kUploadDataSize)); // Finish reading the |EOF|. - data.RunFor(1); + deterministic_data()->RunFor(1); ASSERT_TRUE(response.headers.get()); ASSERT_EQ(200, response.headers->response_code()); - EXPECT_TRUE(data.at_read_eof()); - EXPECT_TRUE(data.at_write_eof()); + EXPECT_TRUE(deterministic_data()->at_read_eof()); + EXPECT_TRUE(deterministic_data()->at_write_eof()); } // Test case for bug: http://code.google.com/p/chromium/issues/detail?id=50058 diff --git a/net/spdy/spdy_http_stream_spdy3_unittest.cc b/net/spdy/spdy_http_stream_spdy3_unittest.cc index 1b7760b..4c31247 100644 --- a/net/spdy/spdy_http_stream_spdy3_unittest.cc +++ b/net/spdy/spdy_http_stream_spdy3_unittest.cc @@ -10,7 +10,10 @@ #include "crypto/ec_signature_creator.h" #include "crypto/signature_creator.h" #include "net/base/asn1_util.h" +#include "net/base/capturing_net_log.h" #include "net/base/default_server_bound_cert_store.h" +#include "net/base/load_timing_info.h" +#include "net/base/load_timing_info_test_util.h" #include "net/base/upload_data_stream.h" #include "net/base/upload_element_reader.h" #include "net/http/http_request_info.h" @@ -26,8 +29,47 @@ using namespace net::test_spdy3; namespace net { +namespace { + +// Tests the load timing of a stream that's connected and is not the first +// request sent on a connection. +void TestLoadTimingReused(const HttpStream& stream) { + LoadTimingInfo load_timing_info; + EXPECT_TRUE(stream.GetLoadTimingInfo(&load_timing_info)); + + EXPECT_TRUE(load_timing_info.socket_reused); + EXPECT_NE(NetLog::Source::kInvalidId, load_timing_info.socket_log_id); + + ExpectConnectTimingHasNoTimes(load_timing_info.connect_timing); + ExpectLoadTimingHasOnlyConnectionTimes(load_timing_info); +} + +// Tests the load timing of a stream that's connected and using a fresh +// connection. +void TestLoadTimingNotReused(const HttpStream& stream) { + LoadTimingInfo load_timing_info; + EXPECT_TRUE(stream.GetLoadTimingInfo(&load_timing_info)); + + EXPECT_FALSE(load_timing_info.socket_reused); + EXPECT_NE(NetLog::Source::kInvalidId, load_timing_info.socket_log_id); + + ExpectConnectTimingHasTimes(load_timing_info.connect_timing, + CONNECT_TIMING_HAS_DNS_TIMES); + ExpectLoadTimingHasOnlyConnectionTimes(load_timing_info); +} + +} // namespace + class SpdyHttpStreamSpdy3Test : public testing::Test { public: + SpdyHttpStreamSpdy3Test() { + session_deps_.net_log = &net_log_; + } + + DeterministicSocketData* deterministic_data() { + return deterministic_data_.get(); + } + OrderedSocketData* data() { return data_.get(); } protected: @@ -40,6 +82,38 @@ class SpdyHttpStreamSpdy3Test : public testing::Test { UploadDataStream::set_merge_chunks(merge); } + // Initializes the session using DeterministicSocketData. It's advisable + // to use this function rather than the OrderedSocketData, since the + // DeterministicSocketData behaves in a reasonable manner. + int InitSessionDeterministic(MockRead* reads, size_t reads_count, + MockWrite* writes, size_t writes_count, + HostPortPair& host_port_pair) { + HostPortProxyPair pair(host_port_pair, ProxyServer::Direct()); + deterministic_data_.reset( + new DeterministicSocketData(reads, reads_count, writes, writes_count)); + session_deps_.deterministic_socket_factory->AddSocketDataProvider( + deterministic_data_.get()); + http_session_ = + SpdySessionDependencies::SpdyCreateSessionDeterministic(&session_deps_); + session_ = http_session_->spdy_session_pool()->Get(pair, BoundNetLog()); + transport_params_ = new TransportSocketParams(host_port_pair, + MEDIUM, false, false, + OnHostResolutionCallback()); + TestCompletionCallback callback; + scoped_ptr<ClientSocketHandle> connection(new ClientSocketHandle); + EXPECT_EQ(ERR_IO_PENDING, + connection->Init(host_port_pair.ToString(), + transport_params_, + MEDIUM, + callback.callback(), + http_session_->GetTransportSocketPool( + HttpNetworkSession::NORMAL_SOCKET_POOL), + BoundNetLog())); + EXPECT_EQ(OK, callback.WaitForResult()); + return session_->InitializeWithSocket(connection.release(), false, OK); + } + + // Initializes the session using the finicky OrderedSocketData class. int InitSession(MockRead* reads, size_t reads_count, MockWrite* writes, size_t writes_count, HostPortPair& host_port_pair) { @@ -71,8 +145,10 @@ class SpdyHttpStreamSpdy3Test : public testing::Test { const std::string& cert, const std::string& proof); + CapturingNetLog net_log_; SpdySessionDependencies session_deps_; scoped_ptr<OrderedSocketData> data_; + scoped_ptr<DeterministicSocketData> deterministic_data_; scoped_refptr<HttpNetworkSession> http_session_; scoped_refptr<SpdySession> session_; scoped_refptr<TransportSocketParams> transport_params_; @@ -106,17 +182,26 @@ TEST_F(SpdyHttpStreamSpdy3Test, SendRequest) { BoundNetLog net_log; scoped_ptr<SpdyHttpStream> http_stream( new SpdyHttpStream(session_.get(), true)); + // Make sure getting load timing information the stream early does not crash. + LoadTimingInfo load_timing_info; + EXPECT_FALSE(http_stream->GetLoadTimingInfo(&load_timing_info)); + ASSERT_EQ( OK, http_stream->InitializeStream(&request, net_log, CompletionCallback())); + EXPECT_FALSE(http_stream->GetLoadTimingInfo(&load_timing_info)); EXPECT_EQ(ERR_IO_PENDING, http_stream->SendRequest(headers, &response, callback.callback())); EXPECT_TRUE(http_session_->spdy_session_pool()->HasSession(pair)); + EXPECT_FALSE(http_stream->GetLoadTimingInfo(&load_timing_info)); // This triggers the MockWrite and read 2 callback.WaitForResult(); + // Can get timing information once the stream connects. + TestLoadTimingNotReused(*http_stream); + // This triggers read 3. The empty read causes the session to shut down. data()->CompleteRead(); @@ -125,6 +210,100 @@ TEST_F(SpdyHttpStreamSpdy3Test, SendRequest) { EXPECT_FALSE(http_session_->spdy_session_pool()->HasSession(pair)); EXPECT_TRUE(data()->at_read_eof()); EXPECT_TRUE(data()->at_write_eof()); + + TestLoadTimingNotReused(*http_stream); + http_stream->Close(true); + // Test that there's no crash when trying to get the load timing after the + // stream has been closed. + TestLoadTimingNotReused(*http_stream); +} + +TEST_F(SpdyHttpStreamSpdy3Test, LoadTimingTwoRequests) { + scoped_ptr<SpdyFrame> req1(ConstructSpdyGet(NULL, 0, false, 1, LOWEST)); + scoped_ptr<SpdyFrame> req2(ConstructSpdyGet(NULL, 0, false, 3, LOWEST)); + MockWrite writes[] = { + CreateMockWrite(*req1, 0), + CreateMockWrite(*req2, 1), + }; + scoped_ptr<SpdyFrame> resp1(ConstructSpdyGetSynReply(NULL, 0, 1)); + scoped_ptr<SpdyFrame> body1(ConstructSpdyBodyFrame(1, "", 0, true)); + scoped_ptr<SpdyFrame> resp2(ConstructSpdyGetSynReply(NULL, 0, 3)); + scoped_ptr<SpdyFrame> body2(ConstructSpdyBodyFrame(3, "", 0, true)); + MockRead reads[] = { + CreateMockRead(*resp1, 2), + CreateMockRead(*body1, 3), + CreateMockRead(*resp2, 4), + CreateMockRead(*body2, 5), + MockRead(ASYNC, 0, 6) // EOF + }; + + HostPortPair host_port_pair("www.google.com", 80); + HostPortProxyPair pair(host_port_pair, ProxyServer::Direct()); + ASSERT_EQ(OK, InitSessionDeterministic(reads, arraysize(reads), + writes, arraysize(writes), + host_port_pair)); + + HttpRequestInfo request1; + request1.method = "GET"; + request1.url = GURL("http://www.google.com/"); + TestCompletionCallback callback1; + HttpResponseInfo response1; + HttpRequestHeaders headers1; + scoped_ptr<SpdyHttpStream> http_stream1( + new SpdyHttpStream(session_.get(), true)); + + ASSERT_EQ(OK, + http_stream1->InitializeStream(&request1, BoundNetLog(), + CompletionCallback())); + EXPECT_EQ(ERR_IO_PENDING, http_stream1->SendRequest(headers1, &response1, + callback1.callback())); + EXPECT_TRUE(http_session_->spdy_session_pool()->HasSession(pair)); + + HttpRequestInfo request2; + request2.method = "GET"; + request2.url = GURL("http://www.google.com/"); + TestCompletionCallback callback2; + HttpResponseInfo response2; + HttpRequestHeaders headers2; + scoped_ptr<SpdyHttpStream> http_stream2( + new SpdyHttpStream(session_.get(), true)); + + ASSERT_EQ(OK, + http_stream2->InitializeStream(&request2, BoundNetLog(), + CompletionCallback())); + EXPECT_EQ(ERR_IO_PENDING, http_stream2->SendRequest(headers2, &response2, + callback2.callback())); + EXPECT_TRUE(http_session_->spdy_session_pool()->HasSession(pair)); + + // First write. + deterministic_data()->RunFor(1); + EXPECT_LE(0, callback1.WaitForResult()); + + TestLoadTimingNotReused(*http_stream1); + LoadTimingInfo load_timing_info1; + LoadTimingInfo load_timing_info2; + EXPECT_TRUE(http_stream1->GetLoadTimingInfo(&load_timing_info1)); + EXPECT_FALSE(http_stream2->GetLoadTimingInfo(&load_timing_info2)); + + // Second write. + deterministic_data()->RunFor(1); + EXPECT_LE(0, callback2.WaitForResult()); + TestLoadTimingReused(*http_stream2); + EXPECT_TRUE(http_stream2->GetLoadTimingInfo(&load_timing_info2)); + EXPECT_EQ(load_timing_info1.socket_log_id, load_timing_info2.socket_log_id); + + // All the reads. + deterministic_data()->RunFor(6); + + // Read stream 1 to completion, before making sure we can still read load + // timing from both streams. + scoped_refptr<IOBuffer> buf1(new IOBuffer(1)); + ASSERT_EQ(0, http_stream1->ReadResponseBody(buf1, 1, callback1.callback())); + + // Stream 1 has been read to completion. + TestLoadTimingNotReused(*http_stream1); + // Stream 2 still has queued body data. + TestLoadTimingReused(*http_stream2); } TEST_F(SpdyHttpStreamSpdy3Test, SendChunkedPost) { @@ -219,35 +398,9 @@ TEST_F(SpdyHttpStreamSpdy3Test, DelayedSendChunkedPost) { HostPortPair host_port_pair("www.google.com", 80); HostPortProxyPair pair(host_port_pair, ProxyServer::Direct()); - DeterministicSocketData data(reads, arraysize(reads), - writes, arraysize(writes)); - - DeterministicMockClientSocketFactory* socket_factory = - session_deps_.deterministic_socket_factory.get(); - socket_factory->AddSocketDataProvider(&data); - - http_session_ = SpdySessionDependencies::SpdyCreateSessionDeterministic( - &session_deps_); - session_ = http_session_->spdy_session_pool()->Get(pair, BoundNetLog()); - transport_params_ = new TransportSocketParams(host_port_pair, - MEDIUM, false, false, - OnHostResolutionCallback()); - - TestCompletionCallback callback; - scoped_ptr<ClientSocketHandle> connection(new ClientSocketHandle); - - EXPECT_EQ(ERR_IO_PENDING, - connection->Init(host_port_pair.ToString(), - transport_params_, - MEDIUM, - callback.callback(), - http_session_->GetTransportSocketPool( - HttpNetworkSession::NORMAL_SOCKET_POOL), - BoundNetLog())); - - callback.WaitForResult(); - EXPECT_EQ(OK, - session_->InitializeWithSocket(connection.release(), false, OK)); + ASSERT_EQ(OK, InitSessionDeterministic(reads, arraysize(reads), + writes, arraysize(writes), + host_port_pair)); UploadDataStream upload_stream(UploadDataStream::CHUNKED, 0); @@ -266,6 +419,7 @@ TEST_F(SpdyHttpStreamSpdy3Test, DelayedSendChunkedPost) { net_log, CompletionCallback())); + TestCompletionCallback callback; HttpRequestHeaders headers; HttpResponseInfo response; // This will attempt to Write() the initial request and headers, which will @@ -275,7 +429,7 @@ TEST_F(SpdyHttpStreamSpdy3Test, DelayedSendChunkedPost) { EXPECT_TRUE(http_session_->spdy_session_pool()->HasSession(pair)); // Complete the initial request write and the first chunk. - data.RunFor(2); + deterministic_data()->RunFor(2); ASSERT_TRUE(callback.have_result()); EXPECT_GT(callback.WaitForResult(), 0); @@ -284,14 +438,14 @@ TEST_F(SpdyHttpStreamSpdy3Test, DelayedSendChunkedPost) { upload_stream.AppendChunk(kUploadData, kUploadDataSize, true); // Finish writing all the chunks. - data.RunFor(2); + deterministic_data()->RunFor(2); // Read response headers. - data.RunFor(1); + deterministic_data()->RunFor(1); ASSERT_EQ(OK, http_stream->ReadResponseHeaders(callback.callback())); // Read and check |chunk1| response. - data.RunFor(1); + deterministic_data()->RunFor(1); scoped_refptr<IOBuffer> buf1(new IOBuffer(kUploadDataSize)); ASSERT_EQ(kUploadDataSize, http_stream->ReadResponseBody(buf1, @@ -300,7 +454,7 @@ TEST_F(SpdyHttpStreamSpdy3Test, DelayedSendChunkedPost) { EXPECT_EQ(kUploadData, std::string(buf1->data(), kUploadDataSize)); // Read and check |chunk2| response. - data.RunFor(1); + deterministic_data()->RunFor(1); scoped_refptr<IOBuffer> buf2(new IOBuffer(kUploadData1Size)); ASSERT_EQ(kUploadData1Size, http_stream->ReadResponseBody(buf2, @@ -309,7 +463,7 @@ TEST_F(SpdyHttpStreamSpdy3Test, DelayedSendChunkedPost) { EXPECT_EQ(kUploadData1, std::string(buf2->data(), kUploadData1Size)); // Read and check |chunk3| response. - data.RunFor(1); + deterministic_data()->RunFor(1); scoped_refptr<IOBuffer> buf3(new IOBuffer(kUploadDataSize)); ASSERT_EQ(kUploadDataSize, http_stream->ReadResponseBody(buf3, @@ -318,11 +472,11 @@ TEST_F(SpdyHttpStreamSpdy3Test, DelayedSendChunkedPost) { EXPECT_EQ(kUploadData, std::string(buf3->data(), kUploadDataSize)); // Finish reading the |EOF|. - data.RunFor(1); + deterministic_data()->RunFor(1); ASSERT_TRUE(response.headers.get()); ASSERT_EQ(200, response.headers->response_code()); - EXPECT_TRUE(data.at_read_eof()); - EXPECT_TRUE(data.at_write_eof()); + EXPECT_TRUE(deterministic_data()->at_read_eof()); + EXPECT_TRUE(deterministic_data()->at_write_eof()); } // Test the receipt of a WINDOW_UPDATE frame while waiting for a chunk to be diff --git a/net/spdy/spdy_session.cc b/net/spdy/spdy_session.cc index 0284507..4573baf 100644 --- a/net/spdy/spdy_session.cc +++ b/net/spdy/spdy_session.cc @@ -45,6 +45,9 @@ const int kReadBufferSize = 8 * 1024; const int kDefaultConnectionAtRiskOfLossSeconds = 10; const int kHungIntervalSeconds = 10; +// Always start at 1 for the first stream id. +const SpdyStreamId kFirstStreamId = 1; + // Minimum seconds that unclaimed pushed streams will be kept in memory. const int kMinPushedStreamLifetimeSeconds = 300; @@ -231,7 +234,7 @@ SpdySession::SpdySession(const HostPortProxyPair& host_port_proxy_pair, connection_(new ClientSocketHandle), read_buffer_(new IOBuffer(kReadBufferSize)), read_pending_(false), - stream_hi_water_mark_(1), // Always start at 1 for the first stream id. + stream_hi_water_mark_(kFirstStreamId), write_pending_(false), delayed_write_pending_(false), is_secure_(false), @@ -1105,6 +1108,12 @@ bool SpdySession::IsReused() const { return buffered_spdy_framer_->frames_received() > 0; } +bool SpdySession::GetLoadTimingInfo(SpdyStreamId stream_id, + LoadTimingInfo* load_timing_info) const { + return connection_->GetLoadTimingInfo(stream_id != kFirstStreamId, + load_timing_info); +} + int SpdySession::GetPeerAddress(IPEndPoint* address) const { if (!connection_->socket()) return ERR_SOCKET_NOT_CONNECTED; diff --git a/net/spdy/spdy_session.h b/net/spdy/spdy_session.h index a51daae..0475e56 100644 --- a/net/spdy/spdy_session.h +++ b/net/spdy/spdy_session.h @@ -44,6 +44,7 @@ const int kMaxSpdyFrameChunkSize = (2 * kMss) - SpdyFrame::kHeaderSize; const int kMaxConcurrentPushedStreams = 1000; class BoundNetLog; +struct LoadTimingInfo; class SpdyStream; class SSLInfo; @@ -291,6 +292,17 @@ class NET_EXPORT SpdySession : public base::RefCounted<SpdySession>, return connection_->socket()->WasEverUsed(); } + // Returns the load timing information from the perspective of the given + // stream. If it's not the first stream, the connection is considered reused + // for that stream. + // + // This uses a different notion of reuse than IsReused(). This function + // sets |socket_reused| to false only if |stream_id| is the ID of the first + // stream using the session. IsReused(), on the other hand, indicates if the + // session has been used to send/receive data at all. + bool GetLoadTimingInfo(SpdyStreamId stream_id, + LoadTimingInfo* load_timing_info) const; + void set_spdy_session_pool(SpdySessionPool* pool) { spdy_session_pool_ = NULL; } |