Plumb LoadLog into SocketStream

BUG=none
TEST=none
Review URL: http://codereview.chromium.org/385003

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@31881 0039d316-1c4b-4281-b951-d872f2087c98

3 files changed, 72 insertions, 14 deletions

diff --git a/net/socket_stream/socket_stream.cc b/net/socket_stream/socket_stream.cc
index 8ca8489..6a5285c 100644
--- a/net/socket_stream/socket_stream.cc
+++ b/net/socket_stream/socket_stream.cc
@@ -29,6 +29,7 @@
 #include "net/socket_stream/socket_stream_throttle.h"
 #include "net/url_request/url_request.h"
 
+static const int kMaxNumLoadLogEntries = 50;
 static const int kMaxPendingSendAllowed = 32768;  // 32 kilobytes.
 static const int kReadBufferSize = 4096;
 
@@ -39,7 +40,8 @@ void SocketStream::ResponseHeaders::Realloc(size_t new_size) {
 }
 
 SocketStream::SocketStream(const GURL& url, Delegate* delegate)
-    : url_(url),
+    : load_log_(new net::LoadLog(kMaxNumLoadLogEntries)),
+      url_(url),
       delegate_(delegate),
       max_pending_send_allowed_(kMaxPendingSendAllowed),
       next_state_(STATE_NONE),
@@ -60,7 +62,9 @@ SocketStream::SocketStream(const GURL& url, Delegate* delegate)
       throttle_(
           SocketStreamThrottle::GetSocketStreamThrottleForScheme(
               url.scheme())),
-      metrics_(new SocketStreamMetrics(url)) {
+      metrics_(new SocketStreamMetrics(url)),
+      ALLOW_THIS_IN_INITIALIZER_LIST(
+          request_tracker_node_(this)) {
   DCHECK(MessageLoop::current()) <<
       "The current MessageLoop must exist";
   DCHECK_EQ(MessageLoop::TYPE_IO, MessageLoop::current()->type()) <<
@@ -70,6 +74,7 @@ SocketStream::SocketStream(const GURL& url, Delegate* delegate)
 }
 
 SocketStream::~SocketStream() {
+  set_context(NULL);
   DCHECK(!delegate_);
 }
 
@@ -86,8 +91,20 @@ void SocketStream::SetUserData(const void* key, UserData* data) {
 }
 
 void SocketStream::set_context(URLRequestContext* context) {
+  scoped_refptr<URLRequestContext> prev_context = context_;
+
   context_ = context;
-  host_resolver_ = context_->host_resolver();
+
+  if (prev_context != context) {
+    if (prev_context)
+      prev_context->socket_stream_tracker()->Remove(this);
+    if (context)
+      context->socket_stream_tracker()->Add(this);
+  }
+
+  if (context_)
+    host_resolver_ = context_->host_resolver();
+
 }
 
 void SocketStream::Connect() {
@@ -102,6 +119,7 @@ void SocketStream::Connect() {
   // Open a connection asynchronously, so that delegate won't be called
   // back before returning Connect().
   next_state_ = STATE_RESOLVE_PROXY;
+  LoadLog::BeginEvent(load_log_, LoadLog::TYPE_SOCKET_STREAM_CONNECT);
   MessageLoop::current()->PostTask(
       FROM_HERE,
       NewRunnableMethod(this, &SocketStream::DoLoop, OK));
@@ -187,6 +205,7 @@ void SocketStream::DetachDelegate() {
   if (!delegate_)
     return;
   delegate_ = NULL;
+  LoadLog::AddEvent(load_log_, LoadLog::TYPE_CANCELLED);
   Close();
 }
 
@@ -195,7 +214,9 @@ void SocketStream::Finish(int result) {
       "The current MessageLoop must exist";
   DCHECK_EQ(MessageLoop::TYPE_IO, MessageLoop::current()->type()) <<
       "The current MessageLoop must be TYPE_IO";
-  DCHECK_LT(result, 0);
+  DCHECK_LE(result, OK);
+  if (result == OK)
+    result = ERR_CONNECTION_CLOSED;
   DCHECK_EQ(next_state_, STATE_NONE);
   DLOG(INFO) << "Finish result=" << net::ErrorToString(result);
   if (delegate_)
@@ -234,6 +255,7 @@ int SocketStream::DidEstablishConnection() {
   next_state_ = STATE_READ_WRITE;
   metrics_->OnConnected();
 
+  LoadLog::EndEvent(load_log_, LoadLog::TYPE_SOCKET_STREAM_CONNECT);
   if (delegate_)
     delegate_->OnConnected(this, max_pending_send_allowed_);
 
@@ -243,6 +265,7 @@ int SocketStream::DidEstablishConnection() {
 int SocketStream::DidReceiveData(int result) {
   DCHECK(read_buf_);
   DCHECK_GT(result, 0);
+  LoadLog::AddEvent(load_log_, LoadLog::TYPE_SOCKET_STREAM_RECEIVED);
   int len = result;
   metrics_->OnRead(len);
   result = throttle_->OnRead(this, read_buf_->data(), len, &io_callback_);
@@ -256,6 +279,7 @@ int SocketStream::DidReceiveData(int result) {
 
 int SocketStream::DidSendData(int result) {
   DCHECK_GT(result, 0);
+  LoadLog::AddEvent(load_log_, LoadLog::TYPE_SOCKET_STREAM_SENT);
   int len = result;
   metrics_->OnWrite(len);
   result = throttle_->OnWrite(this, current_write_buf_->data(), len,
@@ -364,8 +388,6 @@ void SocketStream::DoLoop(int result) {
         break;
       case STATE_CLOSE:
         DCHECK_LE(result, OK);
-        if (result == OK)
-          result = ERR_CONNECTION_CLOSED;
         Finish(result);
         return;
       default:
@@ -373,6 +395,12 @@ void SocketStream::DoLoop(int result) {
         Finish(result);
         return;
     }
+    // If the connection is not established yet and had actual errors,
+    // close the connection.
+    if (state != STATE_READ_WRITE && result < ERR_IO_PENDING) {
+      DCHECK_EQ(next_state_, STATE_CLOSE);
+      LoadLog::EndEvent(load_log_, LoadLog::TYPE_SOCKET_STREAM_CONNECT);
+    }
   } while (result != ERR_IO_PENDING);
 }
 
@@ -381,7 +409,7 @@ int SocketStream::DoResolveProxy() {
   next_state_ = STATE_RESOLVE_PROXY_COMPLETE;
 
   return proxy_service()->ResolveProxy(
-      url_, &proxy_info_, &io_callback_, &pac_request_, NULL);
+      url_, &proxy_info_, &io_callback_, &pac_request_, load_log_);
 }
 
 int SocketStream::DoResolveProxyComplete(int result) {
@@ -424,7 +452,8 @@ int SocketStream::DoResolveHost() {
 
   DCHECK(host_resolver_.get());
   resolver_.reset(new SingleRequestHostResolver(host_resolver_.get()));
-  return resolver_->Resolve(resolve_info, &addresses_, &io_callback_, NULL);
+  return resolver_->Resolve(resolve_info, &addresses_, &io_callback_,
+                            load_log_);
 }
 
 int SocketStream::DoResolveHostComplete(int result) {
@@ -444,9 +473,8 @@ int SocketStream::DoTcpConnect() {
   next_state_ = STATE_TCP_CONNECT_COMPLETE;
   DCHECK(factory_);
   socket_.reset(factory_->CreateTCPClientSocket(addresses_));
-  // TODO(willchan): Plumb LoadLog into SocketStream.
   metrics_->OnStartConnection();
-  return socket_->Connect(&io_callback_, NULL);
+  return socket_->Connect(&io_callback_, load_log_);
 }
 
 int SocketStream::DoTcpConnectComplete(int result) {
@@ -654,9 +682,8 @@ int SocketStream::DoSOCKSConnect() {
   else
     s = new SOCKSClientSocket(s, req_info, host_resolver_.get());
   socket_.reset(s);
-  // TODO(willchan): Plumb LoadLog into SocketStream.
   metrics_->OnSOCKSProxy();
-  return socket_->Connect(&io_callback_, NULL);
+  return socket_->Connect(&io_callback_, load_log_);
 }
 
 int SocketStream::DoSOCKSConnectComplete(int result) {
@@ -667,6 +694,8 @@ int SocketStream::DoSOCKSConnectComplete(int result) {
       next_state_ = STATE_SSL_CONNECT;
     else
       result = DidEstablishConnection();
+  } else {
+    next_state_ = STATE_CLOSE;
   }
   return result;
 }
@@ -676,9 +705,8 @@ int SocketStream::DoSSLConnect() {
   socket_.reset(factory_->CreateSSLClientSocket(
       socket_.release(), url_.HostNoBrackets(), ssl_config_));
   next_state_ = STATE_SSL_CONNECT_COMPLETE;
-  // TODO(willchan): Plumb LoadLog into SocketStream.
   metrics_->OnSSLConnection();
-  return socket_->Connect(&io_callback_, NULL);
+  return socket_->Connect(&io_callback_, load_log_);
 }
 
 int SocketStream::DoSSLConnectComplete(int result) {
@@ -848,4 +876,10 @@ ProxyService* SocketStream::proxy_service() const {
   return context_->proxy_service();
 }
 
+void SocketStream::GetInfoForTracker(
+    RequestTracker<SocketStream>::RecentRequestInfo* info) const {
+  info->original_url = url_;
+  info->load_log = load_log_;
+}
+
 }  // namespace net
diff --git a/net/socket_stream/socket_stream.h b/net/socket_stream/socket_stream.h
index ad06be0..1892022 100644
--- a/net/socket_stream/socket_stream.h
+++ b/net/socket_stream/socket_stream.h
@@ -22,6 +22,7 @@
 #include "net/http/http_auth_handler.h"
 #include "net/proxy/proxy_service.h"
 #include "net/socket/tcp_client_socket.h"
+#include "net/url_request/request_tracker.h"
 #include "net/url_request/url_request_context.h"
 
 namespace net {
@@ -29,6 +30,7 @@ namespace net {
 class AuthChallengeInfo;
 class ClientSocketFactory;
 class HostResolver;
+class LoadLog;
 class SSLConfigService;
 class SingleRequestHostResolver;
 class SocketStreamMetrics;
@@ -105,6 +107,8 @@ class SocketStream : public base::RefCountedThreadSafe<SocketStream> {
   URLRequestContext* context() const { return context_.get(); }
   void set_context(URLRequestContext* context);
 
+  LoadLog* load_log() const { return load_log_; }
+
   // Opens the connection on the IO thread.
   // Once the connection is established, calls delegate's OnConnected.
   void Connect();
@@ -195,6 +199,7 @@ class SocketStream : public base::RefCountedThreadSafe<SocketStream> {
   };
 
   typedef std::deque< scoped_refptr<IOBufferWithSize> > PendingDataQueue;
+  friend class RequestTracker<SocketStream>;
   friend class base::RefCountedThreadSafe<SocketStream>;
   ~SocketStream();
 
@@ -246,6 +251,11 @@ class SocketStream : public base::RefCountedThreadSafe<SocketStream> {
   SSLConfigService* ssl_config_service() const;
   ProxyService* proxy_service() const;
 
+  void GetInfoForTracker(
+      RequestTracker<SocketStream>::RecentRequestInfo *info) const;
+
+  scoped_refptr<LoadLog> load_log_;
+
   GURL url_;
   Delegate* delegate_;
   int max_pending_send_allowed_;
@@ -306,6 +316,8 @@ class SocketStream : public base::RefCountedThreadSafe<SocketStream> {
 
   scoped_ptr<SocketStreamMetrics> metrics_;
 
+  RequestTracker<SocketStream>::Node request_tracker_node_;
+
   DISALLOW_COPY_AND_ASSIGN(SocketStream);
 };
 
diff --git a/net/socket_stream/socket_stream_unittest.cc b/net/socket_stream/socket_stream_unittest.cc
index fa44afb..3f0997c 100644
--- a/net/socket_stream/socket_stream_unittest.cc
+++ b/net/socket_stream/socket_stream_unittest.cc
@@ -5,6 +5,8 @@
 #include <string>
 #include <vector>
 
+#include "net/base/load_log.h"
+#include "net/base/load_log_unittest.h"
 #include "net/base/mock_host_resolver.h"
 #include "net/base/test_completion_callback.h"
 #include "net/socket/socket_test_util.h"
@@ -205,6 +207,16 @@ TEST_F(SocketStreamTest, BasicAuthProxy) {
   EXPECT_EQ(SocketStreamEvent::EVENT_AUTH_REQUIRED, events[0].event_type);
   EXPECT_EQ(SocketStreamEvent::EVENT_CONNECTED, events[1].event_type);
   EXPECT_EQ(SocketStreamEvent::EVENT_CLOSE, events[2].event_type);
+
+  // The first and last entries of the LoadLog should be for
+  // SOCKET_STREAM_CONNECT.
+  ExpectLogContains(socket_stream->load_log(), 0,
+                    LoadLog::TYPE_SOCKET_STREAM_CONNECT,
+                    LoadLog::PHASE_BEGIN);
+  ExpectLogContains(socket_stream->load_log(),
+                    socket_stream->load_log()->events().size() - 1,
+                    LoadLog::TYPE_SOCKET_STREAM_CONNECT,
+                    LoadLog::PHASE_END);
 }
 
 }  // namespace net