This is a second attempt at submitting this changelist. The original one was

http://codereview.chromium.org/196053 It turns out, since none of our tests
abstract time correctly, unittests are very sensitive to subtle changes in
timing. This made some of the valgrind tests on Linux fail, and unfortunately,
neither my desktop nor the trybots could reproduce the problem reliably.

As far as I can tell, all the (design) bugs are in the unittests. The browser
is actually fine.

Tweaked the code a little more. Will resubmit and carefully monitor the
buildbots.


Original change description follows:

When converting between units of time or data types of different precision, 
we have to be careful to consistently round in the same direction. 

Timeout checks usually check if Now() is less or equal to a deadline in order 
to determine if a timeout has occurred. This correctly handles the case where 
actual sleep times are equal or longer than requested sleep times. 

But if we round down when setting the sleep delay, this can result in 
unnecessary and expensive looping. Make sure, we always round up when converting 
to a format with less precision. 

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

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

3 files changed, 68 insertions, 13 deletions

diff --git a/net/socket/client_socket_pool_base_unittest.cc b/net/socket/client_socket_pool_base_unittest.cc
index 5741b91..be502af 100644
--- a/net/socket/client_socket_pool_base_unittest.cc
+++ b/net/socket/client_socket_pool_base_unittest.cc
@@ -143,31 +143,46 @@ class TestConnectJob : public ConnectJob {
         return DoConnect(false /* error */, false /* sync */);
       case kMockPendingJob:
         set_load_state(LOAD_STATE_CONNECTING);
-        MessageLoop::current()->PostTask(
+
+        // Depending on execution timings, posting a delayed task can result
+        // in the task getting executed the at the earliest possible
+        // opportunity or only after returning once from the message loop and
+        // then a second call into the message loop. In order to make behavior
+        // more deterministic, we change the default delay to 2ms. This should
+        // always require us to wait for the second call into the message loop.
+        //
+        // N.B. The correct fix for this and similar timing problems is to
+        // abstract time for the purpose of unittests. Unfortunately, we have
+        // a lot of third-party components that directly call the various
+        // time functions, so this change would be rather invasive.
+        MessageLoop::current()->PostDelayedTask(
             FROM_HERE,
             method_factory_.NewRunnableMethod(
-               &TestConnectJob::DoConnect,
-               true /* successful */,
-               true /* async */));
+                &TestConnectJob::DoConnect,
+                true /* successful */,
+                true /* async */),
+            2);
         return ERR_IO_PENDING;
       case kMockPendingFailingJob:
         set_load_state(LOAD_STATE_CONNECTING);
-        MessageLoop::current()->PostTask(
+        MessageLoop::current()->PostDelayedTask(
             FROM_HERE,
             method_factory_.NewRunnableMethod(
-               &TestConnectJob::DoConnect,
-               false /* error */,
-               true  /* async */));
+                &TestConnectJob::DoConnect,
+                false /* error */,
+                true  /* async */),
+            2);
         return ERR_IO_PENDING;
       case kMockWaitingJob:
         client_socket_factory_->WaitForSignal(this);
         waiting_success_ = true;
         return ERR_IO_PENDING;
       case kMockAdvancingLoadStateJob:
-        MessageLoop::current()->PostTask(
+        MessageLoop::current()->PostDelayedTask(
             FROM_HERE,
             method_factory_.NewRunnableMethod(
-                &TestConnectJob::AdvanceLoadState, load_state_));
+                &TestConnectJob::AdvanceLoadState, load_state_),
+            2);
         return ERR_IO_PENDING;
       default:
         NOTREACHED();
@@ -396,6 +411,13 @@ class ClientSocketPoolBaseTest : public ClientSocketPoolTest {
   }
 
   virtual void TearDown() {
+    // We post all of our delayed tasks with a 2ms delay. I.e. they don't
+    // actually become pending until 2ms after they have been created. In order
+    // to flush all tasks, we need to wait so that we know there are no
+    // soon-to-be-pending tasks waiting.
+    PlatformThread::Sleep(10);
+    MessageLoop::current()->RunAllPending();
+
     // Need to delete |pool_| before we turn late binding back off. We also need
     // to delete |requests_| because the pool is reference counted and requests
     // keep reference to it.
@@ -715,6 +737,13 @@ TEST_F(ClientSocketPoolBaseTest, TotalLimitCountsConnectingSockets) {
   connect_job_factory_->set_job_type(TestConnectJob::kMockPendingJob);
   EXPECT_EQ(ERR_IO_PENDING, StartRequest("d", kDefaultPriority));
 
+  // We post all of our delayed tasks with a 2ms delay. I.e. they don't
+  // actually become pending until 2ms after they have been created. In order
+  // to flush all tasks, we need to wait so that we know there are no
+  // soon-to-be-pending tasks waiting.
+  PlatformThread::Sleep(10);
+  MessageLoop::current()->RunAllPending();
+
   // The next synchronous request should wait for its turn.
   connect_job_factory_->set_job_type(TestConnectJob::kMockJob);
   EXPECT_EQ(ERR_IO_PENDING, StartRequest("e", kDefaultPriority));
@@ -950,14 +979,26 @@ class RequestSocketCallback : public CallbackRunner< Tuple1<int> > {
       test_connect_job_factory_->set_job_type(next_job_type_);
       handle_->Reset();
       within_callback_ = true;
+      TestCompletionCallback next_job_callback;
       int rv = InitHandle(
-          handle_, "a", kDefaultPriority, this, pool_.get(), NULL);
+          handle_, "a", kDefaultPriority, &next_job_callback, pool_.get(),
+          NULL);
       switch (next_job_type_) {
         case TestConnectJob::kMockJob:
           EXPECT_EQ(OK, rv);
           break;
         case TestConnectJob::kMockPendingJob:
           EXPECT_EQ(ERR_IO_PENDING, rv);
+
+          // For pending jobs, wait for new socket to be created. This makes
+          // sure there are no more pending operations nor any unclosed sockets
+          // when the test finishes.
+          // We need to give it a little bit of time to run, so that all the
+          // operations that happen on timers (e.g. cleanup of idle
+          // connections) can execute.
+          MessageLoop::current()->SetNestableTasksAllowed(true);
+          PlatformThread::Sleep(10);
+          EXPECT_EQ(OK, next_job_callback.WaitForResult());
           break;
         default:
           FAIL() << "Unexpected job type: " << next_job_type_;
@@ -1812,6 +1853,12 @@ TEST_F(ClientSocketPoolBaseTest_LateBinding, CleanupTimedOutIdleSockets) {
   req.handle()->Reset();
   EXPECT_EQ(OK, req2.WaitForResult());
   req2.handle()->Reset();
+
+  // We post all of our delayed tasks with a 2ms delay. I.e. they don't
+  // actually become pending until 2ms after they have been created. In order
+  // to flush all tasks, we need to wait so that we know there are no
+  // soon-to-be-pending tasks waiting.
+  PlatformThread::Sleep(10);
   MessageLoop::current()->RunAllPending();
 
   ASSERT_EQ(2, pool_->IdleSocketCount());
diff --git a/net/socket/socket_test_util.cc b/net/socket/socket_test_util.cc
index e053f6c..60ef70c 100644
--- a/net/socket/socket_test_util.cc
+++ b/net/socket/socket_test_util.cc
@@ -334,6 +334,15 @@ void ClientSocketPoolTest::SetUp() {
 void ClientSocketPoolTest::TearDown() {
   // The tests often call Reset() on handles at the end which may post
   // DoReleaseSocket() tasks.
+  // Pending tasks created by client_socket_pool_base_unittest.cc are
+  // posted two milliseconds into the future and thus won't become
+  // scheduled until that time.
+  // We wait a few milliseconds to make sure that all such future tasks
+  // are ready to run, before calling RunAllPending(). This will work
+  // correctly even if Sleep() finishes late (and it should never finish
+  // early), as all we have to ensure is that actual wall-time has progressed
+  // past the scheduled starting time of the pending task.
+  PlatformThread::Sleep(10);
   MessageLoop::current()->RunAllPending();
 }
 
diff --git a/net/socket/tcp_client_socket_pool_unittest.cc b/net/socket/tcp_client_socket_pool_unittest.cc
index f66fdb7..5e1b0eeb1 100644
--- a/net/socket/tcp_client_socket_pool_unittest.cc
+++ b/net/socket/tcp_client_socket_pool_unittest.cc
@@ -364,13 +364,12 @@ TEST_F(TCPClientSocketPoolTest, CancelRequestClearGroup) {
                 "a", info, kDefaultPriority, &req, pool_.get(), NULL));
   req.handle()->Reset();
 
-  PlatformThread::Sleep(100);
-
   // There is a race condition here.  If the worker pool doesn't post the task
   // before we get here, then this might not run ConnectingSocket::OnIOComplete
   // and therefore leak the canceled ConnectingSocket.  However, other tests
   // after this will call MessageLoop::RunAllPending() which should prevent a
   // leak, unless the worker thread takes longer than all of them.
+  PlatformThread::Sleep(10);
   MessageLoop::current()->RunAllPending();
 }