Fixed tests for glib mutex and condition variable testing.
authorJon A. Cruz <jonc@osg.samsung.com>
Thu, 23 Apr 2015 07:35:33 +0000 (00:35 -0700)
committerErich Keane <erich.keane@intel.com>
Fri, 24 Apr 2015 16:22:28 +0000 (16:22 +0000)
Re-enabled tests that had previously been disabled due to taking too
long.

Removed sleep() calls from test code and replaced with combinations of
usleep() and volatile bools. Since condition variables are being tested
we did not want to use them in the validation process.

Retained debug printf statements, but added #define to turn them
off by default.

On one test system these changes moved the unit test from taking 24
seconds down to only 1.8 seconds.

Change-Id: I9b654a623f3aab9398b6f3aaa2366ab0fcdeb876
Signed-off-by: Jon A. Cruz <jonc@osg.samsung.com>
Reviewed-on: https://gerrit.iotivity.org/gerrit/818
Tested-by: jenkins-iotivity <jenkins-iotivity@opendaylight.org>
Reviewed-by: Joseph Morrow <joseph.l.morrow@intel.com>
Reviewed-by: Charlie Lenahan <charlie.lenahan@intel.com>
Reviewed-by: Erich Keane <erich.keane@intel.com>
resource/csdk/connectivity/test/camutex_tests.cpp

index 02391af..ef9427e 100644 (file)
 //
 //*********************************************************************
 
+// Defining _POSIX_C_SOURCE macro with 200809L (or greater) as value
+// causes header files to expose definitions
+// corresponding to the POSIX.1-2008 base
+// specification (excluding the XSI extension).
+// For POSIX.1-2008 base specification,
+// Refer http://pubs.opengroup.org/stage7tc1/
+//
+// For this specific file, see use of usleep
+#ifndef _POSIX_C_SOURCE
+#define _POSIX_C_SOURCE 200809L
+#endif // _POSIX_C_SOURCE
+
 #include "gtest/gtest.h"
 
 #include <camutex.h>
 
 #include <time.h>
 #include <sys/time.h>
+#include <unistd.h>
+
+//#define DEBUG_VERBOSE 1
+
+// The debug print lines are left in for now since the output can be
+// helpful for developers trying to debug or extend the tests.
+// However, by default they are #defined out so as not to get in
+// the way of normal test runs.
+#ifdef DEBUG_VERBOSE
+#define DBG_printf(...) printf(__VA_ARGS__)
+#else
+#define DBG_printf(...)
+#endif
 
 static const uint64_t USECS_PER_SEC = 1000000;
 
+static const uint64_t USECS_PER_MSEC = 1000;
+
+static const int MINIMAL_LOOP_SLEEP = 20;
+static const int MINIMAL_EXTRA_SLEEP = 25;
+
 uint64_t getAbsTime()
 {
     uint64_t currentTime=0;
@@ -84,51 +114,71 @@ TEST(MutexTests, TC_02_TRY_LOCK)
 typedef struct _tagFunc1
 {
     ca_mutex mutex;
+    volatile bool thread_up;
+    volatile bool finished;
 } _func1_struct;
 
 void mutexFunc(void *context)
 {
     _func1_struct* pData = (_func1_struct*) context;
 
-    printf("Thread: trying to lock\n");
+    DBG_printf("Thread: trying to lock\n");
+
+    // setting the flag must be done before lock attempt, as the test
+    // thread starts off with the mutex locked
+    pData->thread_up = true;
     ca_mutex_lock(pData->mutex);
-    printf("Thread: got lock\n");
-    sleep(5);
-    printf("Thread:releasing\n");
+
+    DBG_printf("Thread: got lock\n");
+    usleep(MINIMAL_LOOP_SLEEP * USECS_PER_MSEC);
+    DBG_printf("Thread: releasing\n");
+
+    pData->finished = true; // assignment guarded by lock
+
     ca_mutex_unlock(pData->mutex);
 }
 
-TEST(MutexTests, DISABLED_TC_03_THREAD_LOCKING)
+TEST(MutexTests, TC_03_THREAD_LOCKING)
 {
     u_thread_pool_t mythreadpool;
 
     EXPECT_EQ(CA_STATUS_OK, u_thread_pool_init(3, &mythreadpool));
 
-    _func1_struct pData;
+    _func1_struct pData = {};
 
     pData.mutex = ca_mutex_new();
 
     EXPECT_TRUE(pData.mutex != NULL);
     if (pData.mutex != NULL)
     {
-        printf("Holding mutex for 5 seconds\n");
+        DBG_printf("test: Holding mutex in test\n");
         ca_mutex_lock(pData.mutex);
 
-        printf("starting thread\n");
+        DBG_printf("test: starting thread\n");
         //start thread
         EXPECT_EQ(CA_STATUS_OK,
                   u_thread_pool_add_task(mythreadpool, mutexFunc, &pData));
 
-        printf("test: sleeping\n");
+        DBG_printf("test: waiting for thread to be up.\n");
 
-        sleep(5);
+        while (!pData.thread_up)
+        {
+            usleep(MINIMAL_LOOP_SLEEP * USECS_PER_MSEC);
+        }
+        // At this point the thread is running and close to trying to lock.
+        // For test purposes only, use of condition variables is being avoided,
+        // so a minor sleep is used.
+        usleep(MINIMAL_EXTRA_SLEEP * USECS_PER_MSEC);
 
-        printf("test: unlocking\n");
+        DBG_printf("test: unlocking\n");
 
         ca_mutex_unlock(pData.mutex);
 
-        printf("test: waiting for thread to release\n");
-        sleep(1);
+        DBG_printf("test: waiting for thread to release\n");
+        while (!pData.finished)
+        {
+            usleep(MINIMAL_LOOP_SLEEP * USECS_PER_MSEC);
+        }
 
         ca_mutex_lock(pData.mutex);
 
@@ -152,32 +202,40 @@ TEST(ConditionTests, TC_01_CREATE)
     }
 }
 
+// Normally we would use one pair of mutex/cond-var communicating to the
+// worker threads and one pair back to the main thread. However since
+// testing the ca_cond itself is the point, only one pair is used here.
 typedef struct _tagFunc2
 {
     int id;
     ca_mutex mutex;
-    ca_cond condition;bool bFinished;
+    ca_cond condition;
+    volatile bool thread_up;
+    volatile bool finished;
 } _func2_struct;
 
 void condFunc(void *context)
 {
     _func2_struct* pData = (_func2_struct*) context;
 
-    printf("Thread %d: waiting on condition\n", pData->id);
+    DBG_printf("Thread_%d: waiting on condition\n", pData->id);
 
     ca_mutex_lock(pData->mutex);
 
+    pData->thread_up = true;
+
     ca_cond_wait(pData->condition, pData->mutex);
 
-    ca_mutex_unlock(pData->mutex);
+    pData->finished = true; // assignment guarded by lock
 
-    pData->bFinished = true;
+    ca_mutex_unlock(pData->mutex);
 
-    printf("Thread %d: got signaled\n", pData->id);
+    DBG_printf("Thread_%d: completed.\n", pData->id);
 }
 
-TEST(ConditionTests, DISABLED_TC_02_SIGNAL)
+TEST(ConditionTests, TC_02_SIGNAL)
 {
+    const int MAX_WAIT_MS = 2000;
     u_thread_pool_t mythreadpool;
 
     EXPECT_EQ(CA_STATUS_OK, u_thread_pool_init(3, &mythreadpool));
@@ -186,14 +244,14 @@ TEST(ConditionTests, DISABLED_TC_02_SIGNAL)
     ca_cond sharedCond = ca_cond_new();
 
     _func2_struct pData1 =
-    { 1, sharedMutex, sharedCond, false };
+    { 1, sharedMutex, sharedCond, false, false };
     _func2_struct pData2 =
-    { 2, sharedMutex, sharedCond, false };
+    { 2, sharedMutex, sharedCond, false, false };
 
     EXPECT_TRUE(pData1.mutex != NULL);
     if (pData1.mutex != NULL)
     {
-        printf("starting thread\n");
+        DBG_printf("starting thread\n");
         //start thread
         EXPECT_EQ(CA_STATUS_OK,
                   u_thread_pool_add_task(mythreadpool, condFunc, &pData1));
@@ -202,31 +260,67 @@ TEST(ConditionTests, DISABLED_TC_02_SIGNAL)
         EXPECT_EQ(CA_STATUS_OK,
                   u_thread_pool_add_task(mythreadpool, condFunc, &pData2));
 
-        printf("test: sleeping\n");
-
-        sleep(2);
+        DBG_printf("test    : sleeping\n");
 
-        printf("test: signaling first thread\n");
+        while (!pData1.thread_up || !pData2.thread_up)
+        {
+            // For test purposes only, use of condition variables is being
+            // avoided, so a minor sleep is used.
+            usleep(MINIMAL_LOOP_SLEEP * USECS_PER_MSEC);
+        }
+        // At this point the threads are running and both have locked. One
+        // has already started waiting on the condition and the other is at
+        // least close.
 
         ca_mutex_lock(sharedMutex);
+        // once the lock is acquired it means both threads were waiting.
+        DBG_printf("test    : signaling first thread\n");
         ca_cond_signal(sharedCond);
         ca_mutex_unlock(sharedMutex);
 
-        sleep(1);
+        // At this point either of the child threads might lock the mutex in
+        // their cond_wait call, or this test thread might lock it again if
+        // mutex_lock gets executed before the child threads can react to
+        // the signaling. Thus we wait on their flag variables
+        int waitCount = 1; // start with 1 for minumum targetWait value.
+        while (!pData1.finished && !pData2.finished)
+        {
+            usleep(MINIMAL_LOOP_SLEEP * USECS_PER_MSEC);
+            waitCount++;
+        }
+
+        // As a rough hueristic wait twice as long for the second to possibly
+        // finish:
+        int targetWait = waitCount * 2;
+        for (int i = 0;
+             (i < targetWait) && (!pData1.finished && !pData2.finished); i++)
+        {
+            usleep(MINIMAL_LOOP_SLEEP * USECS_PER_MSEC);
+        }
+        usleep(MINIMAL_EXTRA_SLEEP);
 
         // only one should be finished
-        EXPECT_FALSE(pData1.bFinished && pData2.bFinished);
+        ca_mutex_lock(sharedMutex);
+        EXPECT_NE(pData1.finished, pData2.finished);
+        ca_mutex_unlock(sharedMutex);
 
-        printf("test: signaling another thread\n");
+        DBG_printf("test    : signaling another thread\n");
 
         ca_mutex_lock(sharedMutex);
         ca_cond_signal(sharedCond);
         ca_mutex_unlock(sharedMutex);
 
-        sleep(1);
+        waitCount = 0;
+        while ((!pData1.finished || !pData2.finished)
+               && ((waitCount * MINIMAL_EXTRA_SLEEP) < MAX_WAIT_MS))
+        {
+            usleep(MINIMAL_LOOP_SLEEP * USECS_PER_MSEC);
+            waitCount++;
+        }
 
         // both should finally be finished
-        EXPECT_TRUE(pData2.bFinished && pData2.bFinished);
+        EXPECT_TRUE(pData1.finished);
+        EXPECT_TRUE(pData2.finished);
 
         // Cleanup Everything
 
@@ -238,8 +332,9 @@ TEST(ConditionTests, DISABLED_TC_02_SIGNAL)
     u_thread_pool_free(mythreadpool);
 }
 
-TEST(ConditionTests, DISABLED_TC_03_BROADCAST)
+TEST(ConditionTests, TC_03_BROADCAST)
 {
+    const int MAX_WAIT_MS = 2000;
     u_thread_pool_t mythreadpool;
 
     EXPECT_EQ(CA_STATUS_OK, u_thread_pool_init(3, &mythreadpool));
@@ -248,14 +343,14 @@ TEST(ConditionTests, DISABLED_TC_03_BROADCAST)
     ca_cond sharedCond = ca_cond_new();
 
     _func2_struct pData1 =
-    { 1, sharedMutex, sharedCond, false };
+    { 1, sharedMutex, sharedCond, false, false };
     _func2_struct pData2 =
-    { 2, sharedMutex, sharedCond, false };
+    { 2, sharedMutex, sharedCond, false, false };
 
     EXPECT_TRUE(pData1.mutex != NULL);
     if (pData1.mutex != NULL)
     {
-        printf("starting thread\n");
+        DBG_printf("starting thread\n");
         //start thread
         EXPECT_EQ(CA_STATUS_OK,
                   u_thread_pool_add_task(mythreadpool, condFunc, &pData1));
@@ -264,20 +359,36 @@ TEST(ConditionTests, DISABLED_TC_03_BROADCAST)
         EXPECT_EQ(CA_STATUS_OK,
                   u_thread_pool_add_task(mythreadpool, condFunc, &pData2));
 
-        printf("test: sleeping\n");
+        DBG_printf("test    : sleeping\n");
 
-        sleep(2);
+        while (!pData1.thread_up || !pData2.thread_up)
+        {
+            // For test purposes only, use of condition variables is being
+            // avoided, so a minor sleep is used.
+            usleep(MINIMAL_LOOP_SLEEP * USECS_PER_MSEC);
+        }
+        // At this point the threads are running and both have locked. One
+        // has already started waiting on the condition and the other is at
+        // least close.
 
-        printf("test: signaling all threads\n");
+        DBG_printf("test    : signaling all threads\n");
 
         ca_mutex_lock(sharedMutex);
+        // once the lock is acquired it means both threads were waiting.
         ca_cond_broadcast(sharedCond);
         ca_mutex_unlock(sharedMutex);
 
-        sleep(1);
+        int waitCount = 0;
+        while ((!pData1.finished || !pData2.finished)
+               && ((waitCount * MINIMAL_EXTRA_SLEEP) < MAX_WAIT_MS))
+        {
+            usleep(MINIMAL_LOOP_SLEEP * USECS_PER_MSEC);
+            waitCount++;
+        }
 
         // both should finally be finished
-        EXPECT_TRUE(pData1.bFinished && pData2.bFinished);
+        EXPECT_TRUE(pData1.finished);
+        EXPECT_TRUE(pData2.finished);
 
         // Cleanup Everything
 
@@ -297,26 +408,28 @@ TEST(CondTests, TC_04_TIMECHECK)
 
     uint64_t end = getAbsTime();
 
-    EXPECT_LE(begin, end); // should never be the same value
+    EXPECT_LT(begin, end); // should never be the same value
 }
 
 void timedFunc(void *context)
 {
     _func2_struct* pData = (_func2_struct*) context;
 
-    printf("Thread %d: waiting for timeout \n", pData->id);
+    DBG_printf("Thread_%d: waiting for timeout \n", pData->id);
 
     ca_mutex_lock(pData->mutex);
 
     uint64_t abs = getAbsTime();
-    abs += 2 * USECS_PER_SEC; // 2 seconds
+    abs += USECS_PER_SEC / 2; // 1/2 second
 
     // test UTIMEDOUT
     CAWaitResult_t ret = ca_cond_wait_until(pData->condition,
                                             pData->mutex, abs);
     EXPECT_EQ(CA_WAIT_TIMEDOUT, ret);
 
-    printf("Thread %d: waiting for signal \n", pData->id);
+    pData->thread_up = true;
+
+    DBG_printf("Thread_%d: waiting for signal \n", pData->id);
 
     abs = getAbsTime();
     abs += 5 * USECS_PER_SEC; // 5 seconds
@@ -325,15 +438,16 @@ void timedFunc(void *context)
     ret = ca_cond_wait_until(pData->condition, pData->mutex, abs);
     EXPECT_EQ(CA_WAIT_SUCCESS, ret);
 
-    ca_mutex_unlock(pData->mutex);
+    pData->finished = true; // assignment guarded by lock
 
-    pData->bFinished = true;
+    ca_mutex_unlock(pData->mutex);
 
-    printf("Thread %d: stopping\n", pData->id);
+    DBG_printf("Thread_%d: stopping\n", pData->id);
 }
 
-TEST(ConditionTests, DISABLED_TC_05_WAIT)
+TEST(ConditionTests, TC_05_WAIT)
 {
+    const int MAX_WAIT_MS = 5000;
     u_thread_pool_t mythreadpool;
 
     EXPECT_EQ(CA_STATUS_OK, u_thread_pool_init(3, &mythreadpool));
@@ -342,29 +456,41 @@ TEST(ConditionTests, DISABLED_TC_05_WAIT)
     ca_cond sharedCond = ca_cond_new();
 
     _func2_struct pData1 =
-    { 1, sharedMutex, sharedCond, false };
+    { 1, sharedMutex, sharedCond, false, false };
 
     EXPECT_TRUE(sharedMutex != NULL);
     if (sharedMutex != NULL)
     {
-        printf("starting thread\n");
+        DBG_printf("test    : starting thread\n");
         //start thread
         EXPECT_EQ(CA_STATUS_OK,
                   u_thread_pool_add_task(mythreadpool, timedFunc, &pData1));
 
-        printf("test: sleeping for 3\n");
+        DBG_printf("test    : waiting for thread to timeout once.\n");
+
+        while (!pData1.thread_up)
+        {
+            // For test purposes only, use of condition variables is being
+            // avoided, so a minor sleep is used.
+            usleep(MINIMAL_LOOP_SLEEP * USECS_PER_MSEC);
+        }
 
-        sleep(4);
 
-        printf("test: signaling first thread\n");
+        DBG_printf("test    : signaling first thread\n");
 
         ca_mutex_lock(sharedMutex);
         ca_cond_signal(sharedCond);
         ca_mutex_unlock(sharedMutex);
 
-        sleep(1);
+        int waitCount = 0;
+        while (!pData1.finished
+               && ((waitCount * MINIMAL_EXTRA_SLEEP) < MAX_WAIT_MS))
+        {
+            usleep(MINIMAL_LOOP_SLEEP * USECS_PER_MSEC);
+            waitCount++;
+        }
 
-        EXPECT_TRUE(pData1.bFinished); // both should finally be finished
+        EXPECT_TRUE(pData1.finished); // thread should finally be finished
 
         // Cleanup Everything
 
@@ -404,6 +530,7 @@ TEST(ConditionTests, TC_06_INVALIDWAIT)
 
 TEST(ConditionTests, TC_07_WAITDURATION)
 {
+    const double TARGET_WAIT = 1.125;
 
     ca_mutex sharedMutex = ca_mutex_new();
     ca_cond sharedCond = ca_cond_new();
@@ -412,7 +539,7 @@ TEST(ConditionTests, TC_07_WAITDURATION)
 
     uint64_t abs = getAbsTime();
     uint64_t beg = abs;
-    abs += 2 * USECS_PER_SEC;
+    abs += TARGET_WAIT * USECS_PER_SEC;
 
     CAWaitResult_t ret = ca_cond_wait_until(sharedCond, sharedMutex, abs);
     EXPECT_EQ(CA_WAIT_TIMEDOUT,ret);
@@ -421,7 +548,7 @@ TEST(ConditionTests, TC_07_WAITDURATION)
 
     double secondsDiff = (end - beg) / (double) USECS_PER_SEC;
 
-    EXPECT_NEAR(2.0, secondsDiff, 0.05);
+    EXPECT_NEAR(TARGET_WAIT, secondsDiff, 0.05);
 
     ca_mutex_unlock(sharedMutex);