Oops, forgot the test file

test/thread.c

+/*******************************************************************************
+ * Copyright (c) 2009, 2018 IBM Corp.
+ *
+ * All rights reserved. This program and the accompanying materials
+ * are made available under the terms of the Eclipse Public License v1.0
+ * and Eclipse Distribution License v1.0 which accompany this distribution.
+ *
+ * The Eclipse Public License is available at
+ *    http://www.eclipse.org/legal/epl-v10.html
+ * and the Eclipse Distribution License is available at
+ *   http://www.eclipse.org/org/documents/edl-v10.php.
+ *
+ * Contributors:
+ *    Ian Craggs - initial API and implementation and/or initial documentation
+ *******************************************************************************/
+
+
+/**
+ * @file
+ * Unit tests for threading
+ */
+
+
+#include "Thread.h"
+#include <string.h>
+#include <stdlib.h>
+
+#if !defined(_WINDOWS)
+	#include <sys/time.h>
+  #include <sys/socket.h>
+	#include <unistd.h>
+  #include <errno.h>
+#else
+	#include <windows.h>
+#endif
+
+#define ARRAY_SIZE(a) (sizeof(a) / sizeof(a[0]))
+
+void usage(void)
+{
+	printf("help!!\n");
+	exit(EXIT_FAILURE);
+}
+
+struct Options
+{
+	int verbose;
+	int test_no;
+	int iterations;
+} options =
+{
+	0,
+	-1,
+	1,
+};
+
+void getopts(int argc, char** argv)
+{
+	int count = 1;
+
+	while (count < argc)
+	{
+		if (strcmp(argv[count], "--test_no") == 0)
+		{
+			if (++count < argc)
+				options.test_no = atoi(argv[count]);
+			else
+				usage();
+		}
+		else if (strcmp(argv[count], "--iterations") == 0)
+		{
+			if (++count < argc)
+				options.iterations = atoi(argv[count]);
+			else
+				usage();
+		}
+		else if (strcmp(argv[count], "--verbose") == 0)
+			options.verbose = 1;
+		count++;
+	}
+}
+
+#define LOGA_DEBUG 0
+#define LOGA_INFO 1
+#include <stdarg.h>
+#include <time.h>
+#include <sys/timeb.h>
+void MyLog(int LOGA_level, char* format, ...)
+{
+	static char msg_buf[256];
+	va_list args;
+	struct timeb ts;
+
+	struct tm *timeinfo;
+
+	if (LOGA_level == LOGA_DEBUG && options.verbose == 0)
+	  return;
+
+	ftime(&ts);
+	timeinfo = localtime(&ts.time);
+	strftime(msg_buf, 80, "%Y%m%d %H%M%S", timeinfo);
+
+	sprintf(&msg_buf[strlen(msg_buf)], ".%.3hu ", ts.millitm);
+
+	va_start(args, format);
+	vsnprintf(&msg_buf[strlen(msg_buf)], sizeof(msg_buf) - strlen(msg_buf), format, args);
+	va_end(args);
+
+	printf("%s\n", msg_buf);
+	fflush(stdout);
+}
+
+
+#if defined(WIN32) || defined(_WINDOWS)
+#define mysleep(A) Sleep(1000*A)
+#define START_TIME_TYPE DWORD
+static DWORD start_time = 0;
+START_TIME_TYPE start_clock(void)
+{
+	return GetTickCount();
+}
+#elif defined(AIX)
+#define mysleep sleep
+#define START_TIME_TYPE struct timespec
+START_TIME_TYPE start_clock(void)
+{
+	static struct timespec start;
+	clock_gettime(CLOCK_REALTIME, &start);
+	return start;
+}
+#else
+#define mysleep sleep
+#define START_TIME_TYPE struct timeval
+/* TODO - unused - remove? static struct timeval start_time; */
+START_TIME_TYPE start_clock(void)
+{
+	struct timeval start_time;
+	gettimeofday(&start_time, NULL);
+	return start_time;
+}
+#endif
+
+
+#if defined(WIN32)
+long elapsed(START_TIME_TYPE start_time)
+{
+	return GetTickCount() - start_time;
+}
+#elif defined(AIX)
+#define assert(a)
+long elapsed(struct timespec start)
+{
+	struct timespec now, res;
+
+	clock_gettime(CLOCK_REALTIME, &now);
+	ntimersub(now, start, res);
+	return (res.tv_sec)*1000L + (res.tv_nsec)/1000000L;
+}
+#else
+long elapsed(START_TIME_TYPE start_time)
+{
+	struct timeval now, res;
+
+	gettimeofday(&now, NULL);
+	timersub(&now, &start_time, &res);
+	return (res.tv_sec)*1000 + (res.tv_usec)/1000;
+}
+#endif
+
+#define assert(a, b, c, d) myassert(__FILE__, __LINE__, a, b, c, d)
+#define assert1(a, b, c, d, e) myassert(__FILE__, __LINE__, a, b, c, d, e)
+
+int tests = 0;
+int failures = 0;
+FILE* xml;
+START_TIME_TYPE global_start_time;
+char output[3000];
+char* cur_output = output;
+
+void write_test_result(void)
+{
+	long duration = elapsed(global_start_time);
+
+	fprintf(xml, " time=\"%ld.%.3ld\" >\n", duration / 1000, duration % 1000);
+	if (cur_output != output)
+	{
+		fprintf(xml, "%s", output);
+		cur_output = output;
+	}
+	fprintf(xml, "</testcase>\n");
+}
+
+void myassert(char* filename, int lineno, char* description, int value, char* format, ...)
+{
+	++tests;
+	if (!value)
+	{
+		va_list args;
+
+		++failures;
+		printf("Assertion failed, file %s, line %d, description: %s, ", filename, lineno, description);
+
+		va_start(args, format);
+		vprintf(format, args);
+		va_end(args);
+
+		printf("\n");
+
+		cur_output += sprintf(cur_output, "<failure type=\"%s\">file %s, line %d </failure>\n",
+                        description, filename, lineno);
+	}
+    else
+    	MyLog(LOGA_DEBUG, "Assertion succeeded, file %s, line %d, description: %s", filename, lineno, description);
+}
+
+
+thread_return_type sem_secondary(void* n)
+{
+	int rc = 0;
+	sem_type sem = n;
+	START_TIME_TYPE start;
+	long duration;
+
+	MyLog(LOGA_DEBUG, "Secondary semaphore pointer %p", sem);
+
+	rc = Thread_check_sem(sem);
+	assert("rc 0 from check_sem", rc == 0, "rc was %d", rc);
+
+	MyLog(LOGA_DEBUG, "Secondary thread about to wait");
+	start = start_clock();
+	rc = Thread_wait_sem(sem, 99999);
+	duration = elapsed(start);
+	assert("rc 0 from lock mutex", rc == 0, "rc was %d", rc);
+	MyLog(LOGA_INFO, "Lock duration was %ld", duration);
+	assert("duration is 2s", duration >= 2000L, "duration was %ld", duration);
+
+	MyLog(LOGA_DEBUG, "Secondary thread ending");
+	return 0;
+}
+
+
+int test_sem(struct Options options)
+{
+	char* testname = "test_sem";
+	int rc = 0, i = 0;
+	START_TIME_TYPE start;
+	long duration;
+	sem_type sem = Thread_create_sem();
+	thread_type thread;
+
+	MyLog(LOGA_INFO, "Starting semaphore test");
+	fprintf(xml, "<testcase classname=\"test\" name=\"%s\"", testname);
+	global_start_time = start_clock();
+
+	MyLog(LOGA_DEBUG, "Primary semaphore pointer %p\n", sem);
+
+	/* The semaphore should be created non-signaled */
+	rc = Thread_check_sem(sem);
+	assert("rc 0 from check_sem", rc == 0, "rc was %d\n", rc);
+
+	MyLog(LOGA_DEBUG, "Post semaphore so then check should be 1\n");
+	rc = Thread_post_sem(sem);
+	assert("rc 0 from post_sem", rc == 0, "rc was %d\n", rc);
+
+	/* should be 1, and then reset to 0 */
+	rc = Thread_check_sem(sem);
+	assert("rc 1 from check_sem", rc == 1, "rc was %d", rc);
+
+	/* so now it'll be 0 */
+	rc = Thread_check_sem(sem);
+	assert("rc 0 from check_sem", rc == 0, "rc was %d", rc);
+
+	/* multiple posts */
+	for (i = 0; i < 10; ++i)
+	{
+		rc = Thread_post_sem(sem);
+		assert("rc 0 from post_sem", rc == 0, "rc was %d\n", rc);
+	}
+
+	for (i = 0; i < 10; ++i)
+	{
+		rc = Thread_check_sem(sem);
+		assert("rc 1 from check_sem", rc == 1, "rc was %d", rc);
+	}
+	rc = Thread_check_sem(sem);
+	assert("rc 0 from check_sem", rc == 0, "rc was %d", rc);
+
+	MyLog(LOGA_DEBUG, "Check timeout");
+	start = start_clock();
+	rc = Thread_wait_sem(sem, 1500);
+	duration = elapsed(start);
+	assert("rc ETIMEDOUT from lock mutex", rc == ETIMEDOUT, "rc was %d", rc);
+	MyLog(LOGA_INFO, "Lock duration was %ld", duration);
+	assert("duration is 2s", duration >= 1500L, "duration was %ld", duration);
+
+	MyLog(LOGA_DEBUG, "Starting secondary thread");
+	thread = Thread_start(sem_secondary, (void*)sem);
+
+	mysleep(2);
+	MyLog(LOGA_DEBUG, "post secondary");
+	rc = Thread_post_sem(sem);
+	assert("rc 1 from post_sem", rc == 1, "rc was %d", rc);
+
+	mysleep(1);
+
+	MyLog(LOGA_DEBUG, "Main thread ending");
+
+	exit: MyLog(LOGA_INFO, "%s: test %s. %d tests run, %d failures.",
+			(failures == 0) ? "passed" : "failed", testname, tests, failures);
+	write_test_result();
+
+	return failures;
+}
+
+#if !defined(WIN32) && !defined(WIN64)
+thread_return_type cond_secondary(void* n)
+{
+	int rc = 0;
+	cond_type cond = n;
+	START_TIME_TYPE start;
+	long duration;
+
+	MyLog(LOGA_DEBUG, "This will time out");
+	start = start_clock();
+	rc = Thread_wait_cond(cond, 1);
+	duration = elapsed(start);
+	MyLog(LOGA_INFO, "Lock duration was %ld", duration);
+	assert("duration is about 1s", duration >= 1000L && duration <= 1050L, "duration was %ld", duration);
+	assert("rc non 0 from wait_cond", rc == ETIMEDOUT, "rc was %d", rc);
+
+	MyLog(LOGA_DEBUG, "This should hang around a few seconds");
+	start = start_clock();
+	rc = Thread_wait_cond(cond, 99999);
+	duration = elapsed(start);
+	MyLog(LOGA_INFO, "Lock duration was %ld", duration);
+	assert("duration is around 1s", duration >= 990L && duration <= 1010L, "duration was %ld", duration);
+	assert("rc 9 from wait_cond", rc == 0, "rc was %d", rc);
+
+	MyLog(LOGA_DEBUG, "Secondary cond thread ending");
+	return 0;
+}
+
+
+int test_cond(struct Options options)
+{
+	char* testname = "test_cond";
+	int rc = 0, i = 0;
+	START_TIME_TYPE start;
+	long duration;
+	cond_type cond = Thread_create_cond();
+	thread_type thread;
+
+	MyLog(LOGA_INFO, "Starting condition variable test");
+	fprintf(xml, "<testcase classname=\"cond\" name=\"%s\"", testname);
+	global_start_time = start_clock();
+
+	/* The semaphore should be created non-signaled */
+	rc = Thread_wait_cond(cond, 0);
+	assert("rc 0 from wait_cond", rc == ETIMEDOUT, "rc was %d", rc);
+
+	MyLog(LOGA_DEBUG, "Check timeout");
+	start = start_clock();
+	rc = Thread_wait_cond(cond, 2);
+	duration = elapsed(start);
+	assert("rc ETIMEDOUT from lock mutex", rc == ETIMEDOUT, "rc was %d", rc);
+	MyLog(LOGA_INFO, "Lock duration was %ld", duration);
+	assert("duration is 2s", duration >= 2000L, "duration was %ld", duration);
+
+	/* multiple posts */
+	for (i = 0; i < 10; ++i)
+	{
+		rc = Thread_signal_cond(cond);
+		assert("rc 0 from signal cond", rc == 0, "rc was %d\n", rc);
+	}
+
+	/* the signals are not stored */
+	for (i = 0; i < 10; ++i)
+	{
+		rc = Thread_wait_cond(cond, 0);
+		assert("rc non-zero from wait_cond", rc == ETIMEDOUT, "rc was %d", rc);
+	}
+	rc = Thread_wait_cond(cond, 0);
+	assert("rc non-zero from wait_cond", rc == ETIMEDOUT, "rc was %d", rc);
+
+	MyLog(LOGA_DEBUG, "Post secondary but it will time out");
+	rc = Thread_signal_cond(cond);
+	assert("rc 0 from signal cond", rc == 0, "rc was %d", rc);
+
+	MyLog(LOGA_DEBUG, "Starting secondary thread");
+	thread = Thread_start(cond_secondary, (void*)cond);
+
+	MyLog(LOGA_DEBUG, "wait for secondary thread to enter second wait");
+	mysleep(2);
+
+	MyLog(LOGA_DEBUG, "post secondary");
+	rc = Thread_signal_cond(cond);
+	assert("rc 0 from signal cond", rc == 0, "rc was %d", rc);
+
+	mysleep(1);
+
+	MyLog(LOGA_DEBUG, "Main thread ending");
+
+	exit: MyLog(LOGA_INFO, "%s: test %s. %d tests run, %d failures.",
+			(failures == 0) ? "passed" : "failed", testname, tests, failures);
+	write_test_result();
+
+	return failures;
+}
+#endif
+
+
+thread_return_type mutex_secondary(void* n)
+{
+	int rc = 0;
+	mutex_type mutex = n;
+	START_TIME_TYPE start;
+	long duration;
+
+	/* this should take 2s, as there is another lock held */
+	start = start_clock();
+	rc = Thread_lock_mutex(mutex);
+	duration = elapsed(start);
+	assert("rc 0 from lock mutex", rc == 0, "rc was %d", rc);
+	MyLog(LOGA_INFO, "Lock duration was %ld", duration);
+	assert("duration is 2s", duration >= 1000L, "duration was %ld", duration);
+
+	rc = Thread_unlock_mutex(mutex);
+	assert("rc 0 from unlock mutex", rc == 0, "rc was %d", rc);
+	MyLog(LOGA_DEBUG, "Secondary thread ending");
+	return 0;
+}
+
+
+int test_mutex(struct Options options)
+{
+	char* testname = "test_mutex";
+	int rc = 0;
+	mutex_type mutex = Thread_create_mutex();
+	thread_type thread;
+	START_TIME_TYPE start;
+	long duration;
+
+	MyLog(LOGA_INFO, "Starting mutex test");
+	fprintf(xml, "<testcase classname=\"test\" name=\"%s\"", testname);
+	global_start_time = start_clock();
+
+	/* this should happen immediately, as there is no other lock held */
+	start = start_clock();
+	rc = Thread_lock_mutex(mutex);
+	duration = elapsed(start);
+	assert("rc 0 from lock mutex", rc == 0, "rc was %d", rc);
+	MyLog(LOGA_INFO, "Lock duration was %ld", duration);
+	assert("duration is very low", duration < 5L, "duration was %ld", duration);
+
+	MyLog(LOGA_DEBUG, "Starting secondary thread");
+	thread = Thread_start(mutex_secondary, (void*)mutex);
+
+	mysleep(2);
+	rc = Thread_unlock_mutex(mutex); /* let background thread have it */
+	assert("rc 0 from unlock mutex", rc == 0, "rc was %d", rc);
+
+	start = start_clock();
+	rc = Thread_lock_mutex(mutex); /* make sure background thread hasn't locked it */
+	duration = elapsed(start);
+	assert("rc 0 from lock mutex", rc == 0, "rc was %d", rc);
+	MyLog(LOGA_INFO, "Lock duration was %ld", duration);
+	assert("duration is very low", duration < 5L, "duration was %ld", duration);
+
+	Thread_destroy_mutex(mutex);
+
+	MyLog(LOGA_DEBUG, "Main thread ending");
+
+	exit: MyLog(LOGA_INFO, "%s: test %s. %d tests run, %d failures.",
+			(failures == 0) ? "passed" : "failed", testname, tests, failures);
+	write_test_result();
+
+	return failures;
+}
+
+
+
+int main(int argc, char** argv)
+{
+	int rc = -1;
+ 	int (*tests[])() = {NULL,
+ 		test_mutex,
+ 		test_sem,
+#if !defined(WIN32) && !defined(WIN64)
+		test_cond
+#endif
+ 	}; /* indexed starting from 1 */
+	int i;
+
+	xml = fopen("TEST-thread.xml", "w");
+	fprintf(xml, "<testsuite name=\"thread\" tests=\"%d\">\n", (int)(ARRAY_SIZE(tests)) - 1);
+
+	getopts(argc, argv);
+
+	for (i = 0; i < options.iterations; ++i)
+	{
+	 	if (options.test_no == -1)
+		{ /* run all the tests */
+			for (options.test_no = 1; options.test_no < ARRAY_SIZE(tests); ++options.test_no)
+			{
+				failures = rc = 0;
+				rc += tests[options.test_no](options); /* return number of failures.  0 = test succeeded */
+			}
+		}
+		else
+		{
+			if (options.test_no >= ARRAY_SIZE(tests))
+				MyLog(LOGA_INFO, "No test number %d", options.test_no);
+			else
+			{
+				rc = tests[options.test_no](options); /* run just the selected test */
+			}
+		}
+	}
+
+	if (rc == 0)
+		MyLog(LOGA_INFO, "verdict pass");
+	else
+		MyLog(LOGA_INFO, "verdict fail");
+
+	fprintf(xml, "</testsuite>\n");
+	fclose(xml);
+
+	return rc;
+}