Rework the logging for sockets/connectjobs....

net/socket/client_socket_pool_base_unittest.cc

 // Copyright (c) 2010 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/socket/client_socket_pool_base.h"
 
 #include "base/callback.h"
 #include "base/compiler_specific.h"
 #include "base/message_loop.h"
 #include "base/platform_thread.h"
@@ skipping 28 matching lines @@
   // Socket methods:
   virtual int Read(
       IOBuffer* /* buf */, int /* len */, CompletionCallback* /* callback */) {
     return ERR_UNEXPECTED;
   }
 
   virtual int Write(
       IOBuffer* /* buf */, int /* len */, CompletionCallback* /* callback */) {
     return ERR_UNEXPECTED;
   }
-  virtual bool SetReceiveBufferSize(int32 size) { return true; };
-  virtual bool SetSendBufferSize(int32 size) { return true; };
+  virtual bool SetReceiveBufferSize(int32 size) { return true; }
+  virtual bool SetSendBufferSize(int32 size) { return true; }
 
   // ClientSocket methods:
 
   virtual int Connect(CompletionCallback* callback) {
     connected_ = true;
     return OK;
   }
 
   virtual void Disconnect() { connected_ = false; }
   virtual bool IsConnected() const { return connected_; }
@@ skipping 54 matching lines @@
     kMockWaitingJob,
     kMockAdvancingLoadStateJob,
   };
 
   TestConnectJob(JobType job_type,
                  const std::string& group_name,
                  const TestClientSocketPoolBase::Request& request,
                  base::TimeDelta timeout_duration,
                  ConnectJob::Delegate* delegate,
                  MockClientSocketFactory* client_socket_factory,
-                 const BoundNetLog& net_log)
-      : ConnectJob(group_name, timeout_duration, delegate, net_log),
+                 NetLog* net_log)
+      : ConnectJob(group_name, timeout_duration, delegate,
+                   BoundNetLog::Make(net_log, NetLog::SOURCE_CONNECT_JOB)),
         job_type_(job_type),
         client_socket_factory_(client_socket_factory),
         method_factory_(ALLOW_THIS_IN_INITIALIZER_LIST(this)),
         load_state_(LOAD_STATE_IDLE) {}
 
   void Signal() {
     DoConnect(waiting_success_, true /* async */);
   }
 
   virtual LoadState GetLoadState() const { return load_state_; }
@@ skipping 111 matching lines @@
 
   void set_timeout_duration(base::TimeDelta timeout_duration) {
     timeout_duration_ = timeout_duration;
   }
 
   // ConnectJobFactory methods:
 
   virtual ConnectJob* NewConnectJob(
       const std::string& group_name,
       const TestClientSocketPoolBase::Request& request,
-      ConnectJob::Delegate* delegate,
-      const BoundNetLog& net_log) const {
+      ConnectJob::Delegate* delegate) const {
     return new TestConnectJob(job_type_,
                               group_name,
                               request,
                               timeout_duration_,
                               delegate,
                               client_socket_factory_,
-                              net_log);
+                              NULL);
   }
 
   virtual base::TimeDelta ConnectionTimeout() const {
     return timeout_duration_;
   }
 
  private:
   TestConnectJob::JobType job_type_;
   base::TimeDelta timeout_duration_;
   MockClientSocketFactory* const client_socket_factory_;
@@ skipping 200 matching lines @@
   ClientSocketHandle ignored;
   TestClientSocketPoolBase::Request request(
       &ignored, NULL, kDefaultPriority, NULL, BoundNetLog());
   scoped_ptr<TestConnectJob> job(
       new TestConnectJob(TestConnectJob::kMockJob,
                          "a",
                          request,
                          base::TimeDelta::FromMicroseconds(1),
                          &delegate,
                          &client_socket_factory_,
-                         BoundNetLog()));
+                         NULL));
   EXPECT_EQ(OK, job->Connect());
 }
 
 TEST_F(ClientSocketPoolBaseTest, ConnectJob_TimedOut) {
   TestConnectJobDelegate delegate;
   ClientSocketHandle ignored;
-  CapturingBoundNetLog log(CapturingNetLog::kUnbounded);
+  CapturingNetLog log(CapturingNetLog::kUnbounded);
 
   TestClientSocketPoolBase::Request request(
       &ignored, NULL, kDefaultPriority, NULL, BoundNetLog());
   // Deleted by TestConnectJobDelegate.
   TestConnectJob* job =
       new TestConnectJob(TestConnectJob::kMockPendingJob,
                          "a",
                          request,
                          base::TimeDelta::FromMicroseconds(1),
                          &delegate,
                          &client_socket_factory_,
-                         log.bound());
+                         &log);
   ASSERT_EQ(ERR_IO_PENDING, job->Connect());
   PlatformThread::Sleep(1);
   EXPECT_EQ(ERR_TIMED_OUT, delegate.WaitForResult());
 
-  EXPECT_EQ(3u, log.entries().size());
+  EXPECT_EQ(6u, log.entries().size());
   EXPECT_TRUE(LogContainsBeginEvent(
       log.entries(), 0, NetLog::TYPE_SOCKET_POOL_CONNECT_JOB));
+  EXPECT_TRUE(LogContainsBeginEvent(
+      log.entries(), 1, NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_CONNECT));
   EXPECT_TRUE(LogContainsEvent(
-      log.entries(), 1, NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_TIMED_OUT,
+      log.entries(), 2, NetLog::TYPE_CONNECT_JOB_SET_SOCKET,
+      NetLog::PHASE_NONE));
+  EXPECT_TRUE(LogContainsEvent(
+      log.entries(), 3, NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_TIMED_OUT,
       NetLog::PHASE_NONE));
   EXPECT_TRUE(LogContainsEndEvent(
-      log.entries(), 2, NetLog::TYPE_SOCKET_POOL_CONNECT_JOB));
+      log.entries(), 4, NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_CONNECT));
+  EXPECT_TRUE(LogContainsEndEvent(
+      log.entries(), 5, NetLog::TYPE_SOCKET_POOL_CONNECT_JOB));
 }
 
 TEST_F(ClientSocketPoolBaseTest, BasicSynchronous) {
   CreatePool(kDefaultMaxSockets, kDefaultMaxSocketsPerGroup);
 
   TestCompletionCallback callback;
   ClientSocketHandle handle;
   CapturingBoundNetLog log(CapturingNetLog::kUnbounded);
 
   EXPECT_EQ(OK, InitHandle(&handle, "a", kDefaultPriority, &callback, pool_,
                            log.bound()));
   EXPECT_TRUE(handle.is_initialized());
   EXPECT_TRUE(handle.socket());
   handle.Reset();
 
-  EXPECT_EQ(7u, log.entries().size());
+  EXPECT_EQ(4u, log.entries().size());
   EXPECT_TRUE(LogContainsBeginEvent(
       log.entries(), 0, NetLog::TYPE_SOCKET_POOL));
-  EXPECT_TRUE(LogContainsBeginEvent(
-      log.entries(), 1, NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID));
-  EXPECT_TRUE(LogContainsBeginEvent(
-      log.entries(), 2, NetLog::TYPE_SOCKET_POOL_CONNECT_JOB));
-  EXPECT_TRUE(LogContainsEndEvent(
-      log.entries(), 3, NetLog::TYPE_SOCKET_POOL_CONNECT_JOB));
-  EXPECT_TRUE(LogContainsEndEvent(
-      log.entries(), 4, NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID));
   EXPECT_TRUE(LogContainsEvent(
-      log.entries(), 5, NetLog::TYPE_SOCKET_POOL_SOCKET_ID,
+      log.entries(), 1, NetLog::TYPE_SOCKET_POOL_BOUND_TO_CONNECT_JOB,
+      NetLog::PHASE_NONE));
+  EXPECT_TRUE(LogContainsEvent(
+      log.entries(), 2, NetLog::TYPE_SOCKET_POOL_BOUND_TO_SOCKET,
       NetLog::PHASE_NONE));
   EXPECT_TRUE(LogContainsEndEvent(
-      log.entries(), 6, NetLog::TYPE_SOCKET_POOL));
+      log.entries(), 3, NetLog::TYPE_SOCKET_POOL));
 }
 
 TEST_F(ClientSocketPoolBaseTest, InitConnectionFailure) {
   CreatePool(kDefaultMaxSockets, kDefaultMaxSocketsPerGroup);
 
   connect_job_factory_->set_job_type(TestConnectJob::kMockFailingJob);
   CapturingBoundNetLog log(CapturingNetLog::kUnbounded);
 
   TestSocketRequest req(&request_order_, &completion_count_);
   EXPECT_EQ(ERR_CONNECTION_FAILED,
             InitHandle(req.handle(), "a", kDefaultPriority, &req, pool_,
                        log.bound()));
 
-  EXPECT_EQ(6u, log.entries().size());
+  EXPECT_EQ(3u, log.entries().size());
   EXPECT_TRUE(LogContainsBeginEvent(
       log.entries(), 0, NetLog::TYPE_SOCKET_POOL));
-  EXPECT_TRUE(LogContainsBeginEvent(
-      log.entries(), 2, NetLog::TYPE_SOCKET_POOL_CONNECT_JOB));
+  EXPECT_TRUE(LogContainsEvent(
+      log.entries(), 1, NetLog::TYPE_SOCKET_POOL_BOUND_TO_CONNECT_JOB,
+      NetLog::PHASE_NONE));
   EXPECT_TRUE(LogContainsEndEvent(
-      log.entries(), 3, NetLog::TYPE_SOCKET_POOL_CONNECT_JOB));
-  EXPECT_TRUE(LogContainsEndEvent(log.entries(), 5, NetLog::TYPE_SOCKET_POOL));
+      log.entries(), 2, NetLog::TYPE_SOCKET_POOL));
 }
 
 TEST_F(ClientSocketPoolBaseTest, TotalLimit) {
   CreatePool(kDefaultMaxSockets, kDefaultMaxSocketsPerGroup);
 
   // TODO(eroman): Check that the NetLog contains this event.
 
   EXPECT_EQ(OK, StartRequest("a", kDefaultPriority));
   EXPECT_EQ(OK, StartRequest("b", kDefaultPriority));
   EXPECT_EQ(OK, StartRequest("c", kDefaultPriority));
@@ skipping 617 matching lines @@
   TestSocketRequest req(&request_order_, &completion_count_);
   CapturingBoundNetLog log(CapturingNetLog::kUnbounded);
   int rv = InitHandle(req.handle(), "a", LOWEST, &req, pool_, log.bound());
   EXPECT_EQ(ERR_IO_PENDING, rv);
   EXPECT_EQ(LOAD_STATE_CONNECTING, pool_->GetLoadState("a", req.handle()));
   EXPECT_EQ(OK, req.WaitForResult());
   EXPECT_TRUE(req.handle()->is_initialized());
   EXPECT_TRUE(req.handle()->socket());
   req.handle()->Reset();
 
-  EXPECT_EQ(7u, log.entries().size());
+  EXPECT_EQ(4u, log.entries().size());
   EXPECT_TRUE(LogContainsBeginEvent(
       log.entries(), 0, NetLog::TYPE_SOCKET_POOL));
-  EXPECT_TRUE(LogContainsBeginEvent(
-      log.entries(), 2, NetLog::TYPE_SOCKET_POOL_CONNECT_JOB));
+  EXPECT_TRUE(LogContainsEvent(
+      log.entries(), 1, NetLog::TYPE_SOCKET_POOL_BOUND_TO_CONNECT_JOB,
+      NetLog::PHASE_NONE));
+  EXPECT_TRUE(LogContainsEvent(
+      log.entries(), 2, NetLog::TYPE_SOCKET_POOL_BOUND_TO_SOCKET,
+      NetLog::PHASE_NONE));
   EXPECT_TRUE(LogContainsEndEvent(
-      log.entries(), 3, NetLog::TYPE_SOCKET_POOL_CONNECT_JOB));
-  EXPECT_TRUE(LogContainsEndEvent(
-      log.entries(), 5, NetLog::TYPE_SOCKET_POOL));
+      log.entries(), 3, NetLog::TYPE_SOCKET_POOL));
 }
 
 TEST_F(ClientSocketPoolBaseTest,
        InitConnectionAsynchronousFailure) {
   CreatePool(kDefaultMaxSockets, kDefaultMaxSocketsPerGroup);
 
   connect_job_factory_->set_job_type(TestConnectJob::kMockPendingFailingJob);
   TestSocketRequest req(&request_order_, &completion_count_);
   CapturingBoundNetLog log(CapturingNetLog::kUnbounded);
   EXPECT_EQ(ERR_IO_PENDING,
             InitHandle(req.handle(), "a", kDefaultPriority, &req, pool_,
                        log.bound()));
   EXPECT_EQ(LOAD_STATE_CONNECTING, pool_->GetLoadState("a", req.handle()));
   EXPECT_EQ(ERR_CONNECTION_FAILED, req.WaitForResult());
 
-  EXPECT_EQ(6u, log.entries().size());
+  EXPECT_EQ(3u, log.entries().size());
   EXPECT_TRUE(LogContainsBeginEvent(
       log.entries(), 0, NetLog::TYPE_SOCKET_POOL));
-  EXPECT_TRUE(LogContainsBeginEvent(
-      log.entries(), 2, NetLog::TYPE_SOCKET_POOL_CONNECT_JOB));
+  EXPECT_TRUE(LogContainsEvent(
+      log.entries(), 1, NetLog::TYPE_SOCKET_POOL_BOUND_TO_CONNECT_JOB,
+      NetLog::PHASE_NONE));
   EXPECT_TRUE(LogContainsEndEvent(
-      log.entries(), 3, NetLog::TYPE_SOCKET_POOL_CONNECT_JOB));
-  EXPECT_TRUE(LogContainsEndEvent(
-      log.entries(), 5, NetLog::TYPE_SOCKET_POOL));
+      log.entries(), 2, NetLog::TYPE_SOCKET_POOL));
 }
 
 TEST_F(ClientSocketPoolBaseTest, TwoRequestsCancelOne) {
   // TODO(eroman): Add back the log expectations! Removed them because the
   //               ordering is difficult, and some may fire during destructor.
   CreatePool(kDefaultMaxSockets, kDefaultMaxSocketsPerGroup);
 
   connect_job_factory_->set_job_type(TestConnectJob::kMockPendingJob);
   TestSocketRequest req(&request_order_, &completion_count_);
   TestSocketRequest req2(&request_order_, &completion_count_);
@@ skipping 377 matching lines @@
   TestReleasingSocketRequest request(pool_.get());
   EXPECT_EQ(ERR_IO_PENDING, InitHandle(request.handle(), "a", kDefaultPriority,
                                        &request, pool_, BoundNetLog()));
 
   EXPECT_EQ(OK, request.WaitForResult());
 }
 
 }  // namespace
 
 }  // namespace net