svn commit: r1005155 - /incubator/thrift/trunk/lib/cpp/test/TFileTransportTest.cpp

[dr...@apache.org]

Author: dreiss
Date: Wed Oct  6 17:10:31 2010
New Revision: 1005155

URL: http://svn.apache.org/viewvc?rev=1005155&view=rev
Log:
THRIFT-926. cpp: TFileTransportTest timing slightly more lenient

Several of the TFileTransportTest tests check wall clock time to make
sure the writer thread processes operations quickly enough, and isn't
hanging.  However, this can easily result in false failures if we don't
get enough processor time.  This commit makes a few changes to reduce
the number of these failures.

- No longer fail if a single destructor call takes more than 500us.
  We only require 90% of the calls to complete in 500us.  No call may
  take more than 100ms, though.  With this change, the test passes most
  of the time now, even while an "fbmake opt" task is running in
  parallel.

- In the flush_max_us tests, make sure the writer thread is started
  before we start recording timing.  Otherwise, creating the thread
  could take long enough to throw off the numbers for the first fsync()
  call.

Also tested with the pthread_cond_signal() in the TFileTransport
destructor commented out, to make sure the test still fails properly
when the destructor takes too long.

Modified:
    incubator/thrift/trunk/lib/cpp/test/TFileTransportTest.cpp

Modified: incubator/thrift/trunk/lib/cpp/test/TFileTransportTest.cpp
URL: http://svn.apache.org/viewvc/incubator/thrift/trunk/lib/cpp/test/TFileTransportTest.cpp?rev=1005155&r1=1005154&r2=1005155&view=diff
==============================================================================
--- incubator/thrift/trunk/lib/cpp/test/TFileTransportTest.cpp (original)
+++ incubator/thrift/trunk/lib/cpp/test/TFileTransportTest.cpp Wed Oct  6 17:10:31 2010
@@ -168,8 +168,8 @@ void test_destructor() {
   TempFile f(tmp_dir, "thrift.TFileTransportTest.");
 
   unsigned int const NUM_ITERATIONS = 1000;
-  int const MAX_DESTRUCTOR_USEC = 500;
 
+  unsigned int num_over_500us = 0;
   for (unsigned int n = 0; n < NUM_ITERATIONS; ++n) {
     ftruncate(f.getFD(), 0);
 
@@ -195,8 +195,22 @@ void test_destructor() {
     gettimeofday(&end, NULL);
 
     int delta = time_diff(&start, &end);
-    BOOST_CHECK_LT(delta, MAX_DESTRUCTOR_USEC);
+
+    // If any attempt takes more than 100ms, treat that as a failure.
+    // Treat this as a fatal failure, so we'll return now instead of
+    // looping over a very slow operation.
+    BOOST_REQUIRE_LT(delta, 100000);
+
+    // Normally, it takes less than 500us on my dev box.
+    // However, if the box is heavily loaded, some of the test runs
+    // take longer, since we're just waiting for our turn on the CPU.
+    if (delta > 500) {
+      ++num_over_500us;
+    }
   }
+
+  // Make sure fewer than 10% of the runs took longer than 500us
+  BOOST_CHECK(num_over_500us < (NUM_ITERATIONS / 10));
 }
 
 /**
@@ -220,9 +234,15 @@ void test_flush_max_us_impl(uint32_t flu
   uint8_t buf[] = "a";
   uint32_t buflen = sizeof(buf);
 
-  // Flush every 500us
+  // Set the flush interval
   transport->setFlushMaxUs(flush_us);
 
+  // Make one call to write, to start the writer thread now.
+  // (If we just let the thread get created during our test loop,
+  // the thread creation sometimes takes long enough to make the first
+  // fsync interval fail the check.)
+  transport->write(buf, buflen);
+
   // Add one entry to the fsync log, just to mark the start time
   log.fsync(-1);