thread.c 13 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538
  1. /*******************************************************************************
  2. * Copyright (c) 2009, 2020 IBM Corp.
  3. *
  4. * All rights reserved. This program and the accompanying materials
  5. * are made available under the terms of the Eclipse Public License v2.0
  6. * and Eclipse Distribution License v1.0 which accompany this distribution.
  7. *
  8. * The Eclipse Public License is available at
  9. * https://www.eclipse.org/legal/epl-2.0/
  10. * and the Eclipse Distribution License is available at
  11. * http://www.eclipse.org/org/documents/edl-v10.php.
  12. *
  13. * Contributors:
  14. * Ian Craggs - initial API and implementation and/or initial documentation
  15. *******************************************************************************/
  16. /**
  17. * @file
  18. * Unit tests for threading
  19. */
  20. #include "Thread.h"
  21. #include <string.h>
  22. #include <stdlib.h>
  23. #if !defined(_WINDOWS)
  24. #include <sys/time.h>
  25. #include <sys/socket.h>
  26. #include <unistd.h>
  27. #include <errno.h>
  28. #define WINAPI
  29. #else
  30. #include <windows.h>
  31. #endif
  32. #define ARRAY_SIZE(a) (sizeof(a) / sizeof(a[0]))
  33. void usage(void)
  34. {
  35. printf("help!!\n");
  36. exit(EXIT_FAILURE);
  37. }
  38. struct Options
  39. {
  40. int verbose;
  41. int test_no;
  42. int iterations;
  43. } options =
  44. {
  45. 0,
  46. -1,
  47. 1,
  48. };
  49. void getopts(int argc, char** argv)
  50. {
  51. int count = 1;
  52. while (count < argc)
  53. {
  54. if (strcmp(argv[count], "--test_no") == 0)
  55. {
  56. if (++count < argc)
  57. options.test_no = atoi(argv[count]);
  58. else
  59. usage();
  60. }
  61. else if (strcmp(argv[count], "--iterations") == 0)
  62. {
  63. if (++count < argc)
  64. options.iterations = atoi(argv[count]);
  65. else
  66. usage();
  67. }
  68. else if (strcmp(argv[count], "--verbose") == 0)
  69. options.verbose = 1;
  70. count++;
  71. }
  72. }
  73. #define LOGA_DEBUG 0
  74. #define LOGA_INFO 1
  75. #include <stdarg.h>
  76. #include <time.h>
  77. #include <sys/timeb.h>
  78. void MyLog(int LOGA_level, char* format, ...)
  79. {
  80. static char msg_buf[256];
  81. va_list args;
  82. #if defined(_WIN32) || defined(_WINDOWS)
  83. struct timeb ts;
  84. #else
  85. struct timeval ts;
  86. #endif
  87. struct tm *timeinfo;
  88. if (LOGA_level == LOGA_DEBUG && options.verbose == 0)
  89. return;
  90. #if defined(_WIN32) || defined(_WINDOWS)
  91. ftime(&ts);
  92. timeinfo = localtime(&ts.time);
  93. #else
  94. gettimeofday(&ts, NULL);
  95. timeinfo = localtime(&ts.tv_sec);
  96. #endif
  97. strftime(msg_buf, 80, "%Y%m%d %H%M%S", timeinfo);
  98. #if defined(_WIN32) || defined(_WINDOWS)
  99. sprintf(&msg_buf[strlen(msg_buf)], ".%.3hu ", ts.millitm);
  100. #else
  101. sprintf(&msg_buf[strlen(msg_buf)], ".%.3lu ", ts.tv_usec / 1000L);
  102. #endif
  103. va_start(args, format);
  104. vsnprintf(&msg_buf[strlen(msg_buf)], sizeof(msg_buf) - strlen(msg_buf), format, args);
  105. va_end(args);
  106. printf("%s\n", msg_buf);
  107. fflush(stdout);
  108. }
  109. #if defined(_WIN32) || defined(_WINDOWS)
  110. #define mysleep(A) Sleep(1000*A)
  111. #define START_TIME_TYPE DWORD
  112. static DWORD start_time = 0;
  113. START_TIME_TYPE start_clock(void)
  114. {
  115. return GetTickCount();
  116. }
  117. #elif defined(AIX)
  118. #define mysleep sleep
  119. #define START_TIME_TYPE struct timespec
  120. START_TIME_TYPE start_clock(void)
  121. {
  122. static struct timespec start;
  123. clock_gettime(CLOCK_REALTIME, &start);
  124. return start;
  125. }
  126. #else
  127. #define mysleep sleep
  128. #define START_TIME_TYPE struct timeval
  129. /* TODO - unused - remove? static struct timeval start_time; */
  130. START_TIME_TYPE start_clock(void)
  131. {
  132. struct timeval start_time;
  133. gettimeofday(&start_time, NULL);
  134. return start_time;
  135. }
  136. #endif
  137. #if defined(_WIN32)
  138. long elapsed(START_TIME_TYPE start_time)
  139. {
  140. return GetTickCount() - start_time;
  141. }
  142. #elif defined(AIX)
  143. #define assert(a)
  144. long elapsed(struct timespec start)
  145. {
  146. struct timespec now, res;
  147. clock_gettime(CLOCK_REALTIME, &now);
  148. ntimersub(now, start, res);
  149. return (res.tv_sec)*1000L + (res.tv_nsec)/1000000L;
  150. }
  151. #else
  152. long elapsed(START_TIME_TYPE start_time)
  153. {
  154. struct timeval now, res;
  155. gettimeofday(&now, NULL);
  156. timersub(&now, &start_time, &res);
  157. return (res.tv_sec)*1000 + (res.tv_usec)/1000;
  158. }
  159. #endif
  160. #define assert(a, b, c, d) myassert(__FILE__, __LINE__, a, b, c, d)
  161. #define assert1(a, b, c, d, e) myassert(__FILE__, __LINE__, a, b, c, d, e)
  162. int tests = 0;
  163. int failures = 0;
  164. FILE* xml;
  165. START_TIME_TYPE global_start_time;
  166. char output[3000];
  167. char* cur_output = output;
  168. void write_test_result(void)
  169. {
  170. long duration = elapsed(global_start_time);
  171. fprintf(xml, " time=\"%ld.%.3ld\" >\n", duration / 1000, duration % 1000);
  172. if (cur_output != output)
  173. {
  174. fprintf(xml, "%s", output);
  175. cur_output = output;
  176. }
  177. fprintf(xml, "</testcase>\n");
  178. }
  179. void myassert(char* filename, int lineno, char* description, int value, char* format, ...)
  180. {
  181. ++tests;
  182. if (!value)
  183. {
  184. va_list args;
  185. ++failures;
  186. printf("Assertion failed, file %s, line %d, description: %s, ", filename, lineno, description);
  187. va_start(args, format);
  188. vprintf(format, args);
  189. va_end(args);
  190. printf("\n");
  191. cur_output += sprintf(cur_output, "<failure type=\"%s\">file %s, line %d </failure>\n",
  192. description, filename, lineno);
  193. }
  194. else
  195. MyLog(LOGA_DEBUG, "Assertion succeeded, file %s, line %d, description: %s", filename, lineno, description);
  196. }
  197. static thread_return_type WINAPI sem_secondary(void* n)
  198. {
  199. int rc = 0;
  200. sem_type sem = n;
  201. START_TIME_TYPE start;
  202. long duration;
  203. MyLog(LOGA_DEBUG, "Secondary semaphore pointer %p", sem);
  204. rc = Thread_check_sem(sem);
  205. assert("rc 0 from check_sem", rc == 0, "rc was %d", rc);
  206. MyLog(LOGA_DEBUG, "Secondary thread about to wait");
  207. start = start_clock();
  208. rc = Thread_wait_sem(sem, 99999);
  209. duration = elapsed(start);
  210. assert("rc 0 from lock mutex", rc == 0, "rc was %d", rc);
  211. MyLog(LOGA_INFO, "Lock duration was %ld", duration);
  212. assert("duration is 2s", duration >= 2000L, "duration was %ld", duration);
  213. MyLog(LOGA_DEBUG, "Secondary thread ending");
  214. return 0;
  215. }
  216. int test_sem(struct Options options)
  217. {
  218. char* testname = "test_sem";
  219. int rc = 0, i = 0;
  220. START_TIME_TYPE start;
  221. long duration;
  222. sem_type sem = Thread_create_sem(&rc);
  223. MyLog(LOGA_INFO, "Starting semaphore test");
  224. fprintf(xml, "<testcase classname=\"test\" name=\"%s\"", testname);
  225. global_start_time = start_clock();
  226. MyLog(LOGA_DEBUG, "Primary semaphore pointer %p\n", sem);
  227. /* The semaphore should be created non-signaled */
  228. rc = Thread_check_sem(sem);
  229. assert("rc 0 from check_sem", rc == 0, "rc was %d\n", rc);
  230. MyLog(LOGA_DEBUG, "Post semaphore so then check should be 1\n");
  231. rc = Thread_post_sem(sem);
  232. assert("rc 0 from post_sem", rc == 0, "rc was %d\n", rc);
  233. /* should be 1, and then reset to 0 */
  234. rc = Thread_check_sem(sem);
  235. assert("rc 1 from check_sem", rc == 1, "rc was %d", rc);
  236. /* so now it'll be 0 */
  237. rc = Thread_check_sem(sem);
  238. assert("rc 0 from check_sem", rc == 0, "rc was %d", rc);
  239. /* multiple posts */
  240. for (i = 0; i < 10; ++i)
  241. {
  242. rc = Thread_post_sem(sem);
  243. assert("rc 0 from post_sem", rc == 0, "rc was %d\n", rc);
  244. }
  245. for (i = 0; i < 10; ++i)
  246. {
  247. rc = Thread_check_sem(sem);
  248. assert("rc 1 from check_sem", rc == 1, "rc was %d", rc);
  249. }
  250. rc = Thread_check_sem(sem);
  251. assert("rc 0 from check_sem", rc == 0, "rc was %d", rc);
  252. MyLog(LOGA_DEBUG, "Check timeout");
  253. start = start_clock();
  254. rc = Thread_wait_sem(sem, 1500);
  255. duration = elapsed(start);
  256. assert("rc ETIMEDOUT from lock mutex", rc == ETIMEDOUT, "rc was %d", rc);
  257. MyLog(LOGA_INFO, "Lock duration was %ld", duration);
  258. assert("duration is 2s", duration >= 1500L, "duration was %ld", duration);
  259. MyLog(LOGA_DEBUG, "Starting secondary thread");
  260. Thread_start(sem_secondary, (void*)sem);
  261. mysleep(2);
  262. MyLog(LOGA_DEBUG, "post secondary");
  263. rc = Thread_post_sem(sem);
  264. assert("rc 1 from post_sem", rc == 1, "rc was %d", rc);
  265. mysleep(1);
  266. MyLog(LOGA_DEBUG, "Main thread ending");
  267. /*exit: */ MyLog(LOGA_INFO, "%s: test %s. %d tests run, %d failures.",
  268. (failures == 0) ? "passed" : "failed", testname, tests, failures);
  269. write_test_result();
  270. return failures;
  271. }
  272. #if !defined(_WIN32) && !defined(_WIN64)
  273. thread_return_type cond_secondary(void* n)
  274. {
  275. int rc = 0;
  276. cond_type cond = n;
  277. START_TIME_TYPE start;
  278. long duration;
  279. MyLog(LOGA_DEBUG, "This will time out");
  280. start = start_clock();
  281. rc = Thread_wait_cond(cond, 1);
  282. duration = elapsed(start);
  283. MyLog(LOGA_INFO, "Lock duration was %ld", duration);
  284. assert("duration is about 1s", duration >= 1000L && duration <= 1050L, "duration was %ld", duration);
  285. assert("rc non 0 from wait_cond", rc == ETIMEDOUT, "rc was %d", rc);
  286. MyLog(LOGA_DEBUG, "This should hang around a few seconds");
  287. start = start_clock();
  288. rc = Thread_wait_cond(cond, 99999);
  289. duration = elapsed(start);
  290. MyLog(LOGA_INFO, "Lock duration was %ld", duration);
  291. assert("duration is around 1s", duration >= 990L && duration <= 1010L, "duration was %ld", duration);
  292. assert("rc 9 from wait_cond", rc == 0, "rc was %d", rc);
  293. MyLog(LOGA_DEBUG, "Secondary cond thread ending");
  294. return 0;
  295. }
  296. int test_cond(struct Options options)
  297. {
  298. char* testname = "test_cond";
  299. int rc = 0, i = 0;
  300. START_TIME_TYPE start;
  301. long duration;
  302. cond_type cond = Thread_create_cond(&rc);
  303. MyLog(LOGA_INFO, "Starting condition variable test");
  304. fprintf(xml, "<testcase classname=\"cond\" name=\"%s\"", testname);
  305. global_start_time = start_clock();
  306. /* The semaphore should be created non-signaled */
  307. rc = Thread_wait_cond(cond, 0);
  308. assert("rc 0 from wait_cond", rc == ETIMEDOUT, "rc was %d", rc);
  309. MyLog(LOGA_DEBUG, "Check timeout");
  310. start = start_clock();
  311. rc = Thread_wait_cond(cond, 2);
  312. duration = elapsed(start);
  313. assert("rc ETIMEDOUT from lock mutex", rc == ETIMEDOUT, "rc was %d", rc);
  314. MyLog(LOGA_INFO, "Lock duration was %ld", duration);
  315. assert("duration is 2s", duration >= 2000L, "duration was %ld", duration);
  316. /* multiple posts */
  317. for (i = 0; i < 10; ++i)
  318. {
  319. rc = Thread_signal_cond(cond);
  320. assert("rc 0 from signal cond", rc == 0, "rc was %d\n", rc);
  321. }
  322. /* the signals are not stored */
  323. for (i = 0; i < 10; ++i)
  324. {
  325. rc = Thread_wait_cond(cond, 0);
  326. assert("rc non-zero from wait_cond", rc == ETIMEDOUT, "rc was %d", rc);
  327. }
  328. rc = Thread_wait_cond(cond, 0);
  329. assert("rc non-zero from wait_cond", rc == ETIMEDOUT, "rc was %d", rc);
  330. MyLog(LOGA_DEBUG, "Post secondary but it will time out");
  331. rc = Thread_signal_cond(cond);
  332. assert("rc 0 from signal cond", rc == 0, "rc was %d", rc);
  333. MyLog(LOGA_DEBUG, "Starting secondary thread");
  334. Thread_start(cond_secondary, (void*)cond);
  335. MyLog(LOGA_DEBUG, "wait for secondary thread to enter second wait");
  336. mysleep(2);
  337. MyLog(LOGA_DEBUG, "post secondary");
  338. rc = Thread_signal_cond(cond);
  339. assert("rc 0 from signal cond", rc == 0, "rc was %d", rc);
  340. mysleep(1);
  341. MyLog(LOGA_DEBUG, "Main thread ending");
  342. exit: MyLog(LOGA_INFO, "%s: test %s. %d tests run, %d failures.",
  343. (failures == 0) ? "passed" : "failed", testname, tests, failures);
  344. write_test_result();
  345. return failures;
  346. }
  347. #endif
  348. static thread_return_type WINAPI mutex_secondary(void* n)
  349. {
  350. int rc = 0;
  351. mutex_type mutex = n;
  352. START_TIME_TYPE start;
  353. long duration;
  354. /* this should take 2s, as there is another lock held */
  355. start = start_clock();
  356. rc = Thread_lock_mutex(mutex);
  357. duration = elapsed(start);
  358. assert("rc 0 from lock mutex", rc == 0, "rc was %d", rc);
  359. MyLog(LOGA_INFO, "Lock duration was %ld", duration);
  360. assert("duration is 2s", duration >= 1000L, "duration was %ld", duration);
  361. rc = Thread_unlock_mutex(mutex);
  362. assert("rc 0 from unlock mutex", rc == 0, "rc was %d", rc);
  363. MyLog(LOGA_DEBUG, "Secondary thread ending");
  364. return 0;
  365. }
  366. int test_mutex(struct Options options)
  367. {
  368. char* testname = "test_mutex";
  369. int rc = 0;
  370. mutex_type mutex = Thread_create_mutex(&rc);
  371. START_TIME_TYPE start;
  372. long duration;
  373. MyLog(LOGA_INFO, "Starting mutex test");
  374. fprintf(xml, "<testcase classname=\"test\" name=\"%s\"", testname);
  375. global_start_time = start_clock();
  376. /* this should happen immediately, as there is no other lock held */
  377. start = start_clock();
  378. rc = Thread_lock_mutex(mutex);
  379. duration = elapsed(start);
  380. assert("rc 0 from lock mutex", rc == 0, "rc was %d", rc);
  381. MyLog(LOGA_INFO, "Lock duration was %ld", duration);
  382. assert("duration is very low", duration < 5L, "duration was %ld", duration);
  383. MyLog(LOGA_DEBUG, "Starting secondary thread");
  384. Thread_start(mutex_secondary, (void*)mutex);
  385. mysleep(2);
  386. rc = Thread_unlock_mutex(mutex); /* let background thread have it */
  387. assert("rc 0 from unlock mutex", rc == 0, "rc was %d", rc);
  388. start = start_clock();
  389. rc = Thread_lock_mutex(mutex); /* make sure background thread hasn't locked it */
  390. duration = elapsed(start);
  391. assert("rc 0 from lock mutex", rc == 0, "rc was %d", rc);
  392. MyLog(LOGA_INFO, "Lock duration was %ld", duration);
  393. assert("duration is very low", duration < 5L, "duration was %ld", duration);
  394. Thread_destroy_mutex(mutex);
  395. MyLog(LOGA_DEBUG, "Main thread ending");
  396. /*exit:*/ MyLog(LOGA_INFO, "%s: test %s. %d tests run, %d failures.",
  397. (failures == 0) ? "passed" : "failed", testname, tests, failures);
  398. write_test_result();
  399. return failures;
  400. }
  401. int main(int argc, char** argv)
  402. {
  403. int rc = -1;
  404. int (*tests[])() = {NULL,
  405. test_mutex,
  406. test_sem,
  407. #if !defined(_WIN32) && !defined(_WIN64)
  408. test_cond
  409. #endif
  410. }; /* indexed starting from 1 */
  411. int i;
  412. xml = fopen("TEST-thread.xml", "w");
  413. fprintf(xml, "<testsuite name=\"thread\" tests=\"%d\">\n", (int)(ARRAY_SIZE(tests)) - 1);
  414. getopts(argc, argv);
  415. for (i = 0; i < options.iterations; ++i)
  416. {
  417. if (options.test_no == -1)
  418. { /* run all the tests */
  419. for (options.test_no = 1; options.test_no < ARRAY_SIZE(tests); ++options.test_no)
  420. {
  421. failures = rc = 0;
  422. rc += tests[options.test_no](options); /* return number of failures. 0 = test succeeded */
  423. }
  424. }
  425. else
  426. {
  427. if (options.test_no >= ARRAY_SIZE(tests))
  428. MyLog(LOGA_INFO, "No test number %d", options.test_no);
  429. else
  430. {
  431. rc = tests[options.test_no](options); /* run just the selected test */
  432. }
  433. }
  434. }
  435. if (rc == 0)
  436. MyLog(LOGA_INFO, "verdict pass");
  437. else
  438. MyLog(LOGA_INFO, "verdict fail");
  439. fprintf(xml, "</testsuite>\n");
  440. fclose(xml);
  441. return rc;
  442. }