]> git.ipfire.org Git - thirdparty/freeradius-server.git/commitdiff
v4: Initial version of performace tests for fr_pair_list_t operations (#4063)
authorNick Porter <nick@portercomputing.co.uk>
Fri, 16 Apr 2021 19:50:24 +0000 (20:50 +0100)
committerGitHub <noreply@github.com>
Fri, 16 Apr 2021 19:50:24 +0000 (14:50 -0500)
* Update acutest.h to latest

* Amend acutest.h so that messages logged in test processes are passed...

... to the parent and if XML output is enabled are included in the
output using the <system-out /> tag.

TEST_MSG() split into two macros:
  - TEST_MSG_FAIL() which only outputs if a test fails
  - TEST_MSG_ALWAYS() which outputs on both success and failure

TEST_DUMP() split into two macros:
  - TEST_DUMP_FAIL() which only outputs if a test fails
  - TEST_DUMP_ALWAYS() which outputs on both success and failure

* Initial version of pair_list_perf_test utility

For performance checking pair list operations. Uses acutest framework to
manage tests.

If a "-x <filename>" option is used, will output performance results in
an XML file.

src/lib/util/acutest.h
src/lib/util/all.mk
src/lib/util/pair_list_perf_test.c [new file with mode: 0644]
src/lib/util/pair_list_perf_test.mk [new file with mode: 0644]

index 958d3a9ab3d957922194d48c7abc74b2195fed65..9caeab4356289e1a26a5a91121e37e6a6c33b8b6 100644 (file)
@@ -59,7 +59,7 @@
  *
  * Note the list has to be ended with a zeroed record.
  */
-#define TEST_LIST               const struct test_ test_list_[]
+#define TEST_LIST               const struct acutest_test_ acutest_list_[]
 
 
 /* Macros for testing whether an unit test succeeds or fails. These macros
@@ -81,8 +81,8 @@
  *       TEST_CHECK(ptr->member2 > 200);
  *   }
  */
-#define TEST_CHECK_(cond,...)   test_check_((cond), __FILE__, __LINE__, __VA_ARGS__)
-#define TEST_CHECK(cond)        test_check_((cond), __FILE__, __LINE__, "%s", #cond)
+#define TEST_CHECK_(cond,...)   acutest_check_((cond), __FILE__, __LINE__, __VA_ARGS__)
+#define TEST_CHECK(cond)        acutest_check_((cond), __FILE__, __LINE__, "%s", #cond)
 
 
 /* These macros are the same as TEST_CHECK_ and TEST_CHECK except that if the
  */
 #define TEST_ASSERT_(cond,...)                                                 \
     do {                                                                       \
-        if(!test_check_((cond), __FILE__, __LINE__, __VA_ARGS__))              \
-            test_abort_();                                                     \
+        if(!acutest_check_((cond), __FILE__, __LINE__, __VA_ARGS__))           \
+            acutest_abort_();                                                  \
     } while(0)
 #define TEST_ASSERT(cond)                                                      \
     do {                                                                       \
-        if(!test_check_((cond), __FILE__, __LINE__, "%s", #cond))              \
-            test_abort_();                                                     \
+        if(!acutest_check_((cond), __FILE__, __LINE__, "%s", #cond))           \
+            acutest_abort_();                                                  \
     } while(0)
 
 
         } catch(...) {                                                         \
             msg_ = "Unexpected exception thrown.";                             \
         }                                                                      \
-        test_check_(exc_ok_, __FILE__, __LINE__, #code " throws " #exctype);   \
+        acutest_check_(exc_ok_, __FILE__, __LINE__, #code " throws " #exctype);\
         if(msg_ != NULL)                                                       \
-            test_message_("%s", msg_);                                         \
+            acutest_message_(false, "%s", msg_);                                      \
     } while(0)
 #define TEST_EXCEPTION_(code, exctype, ...)                                    \
     do {                                                                       \
         } catch(...) {                                                         \
             msg_ = "Unexpected exception thrown.";                             \
         }                                                                      \
-        test_check_(exc_ok_, __FILE__, __LINE__, __VA_ARGS__);                 \
+        acutest_check_(exc_ok_, __FILE__, __LINE__, __VA_ARGS__);              \
         if(msg_ != NULL)                                                       \
-            test_message_("%s", msg_);                                         \
+            acutest_message_(false, "%s", msg_);                                      \
     } while(0)
 #endif  /* #ifdef __cplusplus */
 
  * implicitly the previous one. To end the test case explicitly (e.g. to end
  * the last test case after exiting the loop), you may use TEST_CASE(NULL).
  */
-#define TEST_CASE_(...)         test_case_(__VA_ARGS__)
-#define TEST_CASE(name)         test_case_("%s", name)
+#define TEST_CASE_(...)         acutest_case_(__VA_ARGS__)
+#define TEST_CASE(name)         acutest_case_("%s", name)
 
 
 /* Maximal output per TEST_CASE call. Longer messages are cut.
     #define TEST_CASE_MAXSIZE    64
 #endif
 
-
 /* printf-like macro for outputting an extra information about a failure.
  *
  * Intended use is to output some computed output versus the expected value,
  * The macro can deal with multi-line output fairly well. It also automatically
  * adds a final new-line if there is none present.
  */
-#define TEST_MSG(...)           test_message_(__VA_ARGS__)
+#define TEST_MSG(...)           TEST_MSG_FAIL(__VA_ARGS__)
+#define TEST_MSG_FAIL(...)      acutest_message_(false, __VA_ARGS__)
+
 
+/* Alternative version of TEST_MSG which outputs regardless of the
+ * failure status of the current test.
+ */
+#define TEST_MSG_ALWAYS(...)    acutest_message_(true, __VA_ARGS__)
 
 /* Maximal output per TEST_MSG call. Longer messages are cut.
  * You may define another limit prior including "acutest.h"
  *   TEST_DUMP("Expected:", addr_expected, size_expected);
  *   TEST_DUMP("Produced:", addr_produced, size_produced);
  */
-#define TEST_DUMP(title, addr, size)    test_dump_(title, addr, size)
+#define TEST_DUMP(title, addr, size)        TEST_DUMP_FAIL(title, addr, size)
+#define TEST_DUMP_FAIL(title, addr, size)   acutest_dump_(false, title, addr, size);
+
+/* Alternative version of TEST_DUMP which outputs regardless of the
+ * failure status of the current test
+ */
+#define TEST_DUMP_ALWAYS(title, addr, size) acutest_dump_(true, title, addr, size);
 
 /* Maximal output per TEST_DUMP call (in bytes to dump). Longer blocks are cut.
  * You may define another limit prior including "acutest.h"
     #define TEST_DUMP_MAXSIZE   1024
 #endif
 
+/* Maximal size of log entries passed between child test processes and parent
+ * process.  This allows for a memory block dump with a title up to TEST_MSG_MAXSIZE
+ * in length, plus ": " separator and NULL terminator.  Longer messages cause an error.
+ */
+#define TEST_LOG_MAXSIZE ((TEST_DUMP_MAXSIZE * 3) + TEST_MSG_MAXSIZE + 3)
 
 /* Common test initialiation/clean-up
  *
 #include <stdlib.h>
 #include <string.h>
 #include <setjmp.h>
+#include <stdbool.h>
 
 #if defined(unix) || defined(__unix__) || defined(__unix) || defined(__APPLE__)
     #define ACUTEST_UNIX_       1
     #endif
 #endif
 
-#if defined(_gnu_linux_)
+#if defined(_gnu_linux_) || defined(__linux__)
     #define ACUTEST_LINUX_      1
     #include <fcntl.h>
     #include <sys/stat.h>
     #include <exception>
 #endif
 
-/* Load valgrind.h, if available. This allows to detect valgrind's presence via RUNNING_ON_VALGRIND. */
 #ifdef __has_include
     #if __has_include(<valgrind.h>)
         #include <valgrind.h>
 
 /* Enable the use of the non-standard keyword __attribute__ to silence warnings under some compilers */
 #if defined(__GNUC__) || defined(__clang__)
-    #define TEST_ATTRIBUTE_(attr)   __attribute__((attr))
+    #define ACUTEST_ATTRIBUTE_(attr)    __attribute__((attr))
 #else
-    #define TEST_ATTRIBUTE_(attr)
+    #define ACUTEST_ATTRIBUTE_(attr)
 #endif
 
 /* Note our global private identifiers end with '_' to mitigate risk of clash
 #endif
 
 
-struct test_ {
+struct acutest_test_ {
     const char* name;
     void (*func)(void);
 };
 
-struct test_detail_ {
+typedef struct acutest_data_log_s_ acutest_data_log_;
+
+struct acutest_data_log_s_ {
+    char* msg;
+    acutest_data_log_* next;
+};
+
+struct acutest_test_data_ {
     unsigned char flags;
     double duration;
+    acutest_data_log_* log_head;
+    acutest_data_log_* log_tail;
 };
 
 enum {
-    TEST_FLAG_RUN_ = 1 << 0,
-    TEST_FLAG_SUCCESS_ = 1 << 1,
-    TEST_FLAG_FAILURE_ = 1 << 2,
+    ACUTEST_FLAG_RUN_ = 1 << 0,
+    ACUTEST_FLAG_SUCCESS_ = 1 << 1,
+    ACUTEST_FLAG_FAILURE_ = 1 << 2,
 };
 
-extern const struct test_ test_list_[];
+extern const struct acutest_test_ acutest_list_[];
 
-int test_check_(int cond, const char* file, int line, const char* fmt, ...);
-void test_case_(const char* fmt, ...);
-void test_message_(const char* fmt, ...);
-void test_dump_(const char* title, const void* addr, size_t size);
-void test_abort_(void) TEST_ATTRIBUTE_(noreturn);
+int acutest_check_(int cond, const char* file, int line, const char* fmt, ...);
+void acutest_case_(const char* fmt, ...);
+void acutest_log_(const char* fmt, ...);
+void acutest_message_(bool always, const char* fmt, ...);
+void acutest_dump_(bool always, const char* title, const void* addr, size_t size);
+void acutest_abort_(void) ACUTEST_ATTRIBUTE_(noreturn);
 
 
 #ifndef TEST_NO_MAIN
 
-static char* test_argv0_ = NULL;
-static size_t test_list_size_ = 0;
-static struct test_detail_ *test_details_ = NULL;
-static size_t test_count_ = 0;
-static int test_no_exec_ = -1;
-static int test_no_summary_ = 0;
-static int test_tap_ = 0;
-static int test_skip_mode_ = 0;
-static int test_worker_ = 0;
-static int test_worker_index_ = 0;
-static int test_cond_failed_ = 0;
-static int test_was_aborted_ = 0;
-static FILE *test_xml_output_ = NULL;
-
-static int test_stat_failed_units_ = 0;
-static int test_stat_run_units_ = 0;
-
-static const struct test_* test_current_unit_ = NULL;
-static int test_current_index_ = 0;
-static char test_case_name_[TEST_CASE_MAXSIZE] = "";
-static int test_current_already_logged_ = 0;
-static int test_case_current_already_logged_ = 0;
-static int test_verbose_level_ = 2;
-static int test_current_failures_ = 0;
-static int test_colorize_ = 0;
-static int test_timer_ = 0;
-
-static int test_abort_has_jmp_buf_ = 0;
-static jmp_buf test_abort_jmp_buf_;
+static char* acutest_argv0_ = NULL;
+static size_t acutest_list_size_ = 0;
+static struct acutest_test_data_* acutest_test_data_ = NULL;
+static size_t acutest_count_ = 0;
+static int acutest_no_exec_ = -1;
+static int acutest_no_summary_ = 0;
+static int acutest_tap_ = 0;
+static int acutest_skip_mode_ = 0;
+static int acutest_worker_ = 0;
+static int acutest_worker_index_ = 0;
+static int acutest_cond_failed_ = 0;
+static int acutest_was_aborted_ = 0;
+static FILE *acutest_xml_output_ = NULL;
+
+static int acutest_stat_failed_units_ = 0;
+static int acutest_stat_run_units_ = 0;
+
+static const struct acutest_test_* acutest_current_test_ = NULL;
+static int acutest_current_index_ = 0;
+static char acutest_case_name_[TEST_CASE_MAXSIZE] = "";
+static int acutest_test_already_logged_ = 0;
+static int acutest_case_already_logged_ = 0;
+static int acutest_verbose_level_ = 2;
+static int acutest_test_failures_ = 0;
+static int acutest_colorize_ = 0;
+static int acutest_timer_ = 0;
+
+static int acutest_abort_has_jmp_buf_ = 0;
+static jmp_buf acutest_abort_jmp_buf_;
 
+#if defined ACUTEST_WIN_
+HANDLE hChildWrite = NULL;
+#endif
 
 static void
-test_cleanup_(void)
+acutest_cleanup_(void)
 {
-    free((void*) test_details_);
+    size_t i;
+    acutest_data_log_* log_entry;
+    acutest_data_log_* next;
+
+    for (i = 0; i < acutest_count_; i++) {
+        log_entry = acutest_test_data_[i].log_head;
+        while (log_entry) {
+            next = log_entry->next;
+#if defined ACUTEST_WIN_
+            if (hChildWrite) {
+                if (!WriteFile(hChildWrite, log_entry->msg, (strlen(log_entry->msg) + 1) * sizeof(char), NULL, NULL))
+                    fprintf(stderr, "Upable to write to pipe");
+            }
+#endif
+            free(log_entry->msg);
+            free(log_entry);
+                log_entry = next;
+        }
+    }
+    free((void*) acutest_test_data_);
 }
 
-static void TEST_ATTRIBUTE_(noreturn)
-test_exit_(int exit_code)
+static void ACUTEST_ATTRIBUTE_(noreturn)
+acutest_exit_(int exit_code)
 {
-    test_cleanup_();
+    acutest_cleanup_();
     exit(exit_code);
 }
 
 #if defined ACUTEST_WIN_
-    typedef LARGE_INTEGER test_timer_type_;
-    static LARGE_INTEGER test_timer_freq_;
-    static test_timer_type_ test_timer_start_;
-    static test_timer_type_ test_timer_end_;
+    typedef LARGE_INTEGER acutest_timer_type_;
+    static LARGE_INTEGER acutest_timer_freq_;
+    static acutest_timer_type_ acutest_timer_start_;
+    static acutest_timer_type_ acutest_timer_end_;
 
     static void
-    test_timer_init_(void)
+    acutest_timer_init_(void)
     {
-        QueryPerformanceFrequency(&test_timer_freq_);
+        QueryPerformanceFrequency(&acutest_timer_freq_);
     }
 
     static void
-    test_timer_get_time_(LARGE_INTEGER* ts)
+    acutest_timer_get_time_(LARGE_INTEGER* ts)
     {
         QueryPerformanceCounter(ts);
     }
 
     static double
-    test_timer_diff_(LARGE_INTEGER start, LARGE_INTEGER end)
+    acutest_timer_diff_(LARGE_INTEGER start, LARGE_INTEGER end)
     {
         double duration = (double)(end.QuadPart - start.QuadPart);
-        duration /= (double)test_timer_freq_.QuadPart;
+        duration /= (double)acutest_timer_freq_.QuadPart;
         return duration;
     }
 
     static void
-    test_timer_print_diff_(void)
+    acutest_timer_print_diff_(void)
     {
-        printf("%.6lf secs", test_timer_diff_(test_timer_start_, test_timer_end_));
+        printf("%.6lf secs", acutest_timer_diff_(acutest_timer_start_, acutest_timer_end_));
     }
 #elif defined ACUTEST_HAS_POSIX_TIMER_
-    static clockid_t test_timer_id_;
-    typedef struct timespec test_timer_type_;
-    static test_timer_type_ test_timer_start_;
-    static test_timer_type_ test_timer_end_;
+    static clockid_t acutest_timer_id_;
+    typedef struct timespec acutest_timer_type_;
+    static acutest_timer_type_ acutest_timer_start_;
+    static acutest_timer_type_ acutest_timer_end_;
 
     static void
-    test_timer_init_(void)
+    acutest_timer_init_(void)
     {
-        if(test_timer_ == 1)
-            test_timer_id_ = CLOCK_MONOTONIC;
-        else if(test_timer_ == 2)
-            test_timer_id_ = CLOCK_PROCESS_CPUTIME_ID;
+        if(acutest_timer_ == 1)
+            acutest_timer_id_ = CLOCK_MONOTONIC;
+        else if(acutest_timer_ == 2)
+            acutest_timer_id_ = CLOCK_PROCESS_CPUTIME_ID;
     }
 
     static void
-    test_timer_get_time_(struct timespec* ts)
+    acutest_timer_get_time_(struct timespec* ts)
     {
-        clock_gettime(test_timer_id_, ts);
+        clock_gettime(acutest_timer_id_, ts);
     }
 
     static double
-    test_timer_diff_(struct timespec start, struct timespec end)
+    acutest_timer_diff_(struct timespec start, struct timespec end)
     {
         double endns;
         double startns;
@@ -481,28 +529,28 @@ test_exit_(int exit_code)
     }
 
     static void
-    test_timer_print_diff_(void)
+    acutest_timer_print_diff_(void)
     {
         printf("%.6lf secs",
-            test_timer_diff_(test_timer_start_, test_timer_end_));
+            acutest_timer_diff_(acutest_timer_start_, acutest_timer_end_));
     }
 #else
-    typedef int test_timer_type_;
-    static test_timer_type_ test_timer_start_;
-    static test_timer_type_ test_timer_end_;
+    typedef int acutest_timer_type_;
+    static acutest_timer_type_ acutest_timer_start_;
+    static acutest_timer_type_ acutest_timer_end_;
 
     void
-    test_timer_init_(void)
+    acutest_timer_init_(void)
     {}
 
     static void
-    test_timer_get_time_(int* ts)
+    acutest_timer_get_time_(int* ts)
     {
         (void) ts;
     }
 
     static double
-    test_timer_diff_(int start, int end)
+    acutest_timer_diff_(int start, int end)
     {
         (void) start;
         (void) end;
@@ -510,19 +558,19 @@ test_exit_(int exit_code)
     }
 
     static void
-    test_timer_print_diff_(void)
+    acutest_timer_print_diff_(void)
     {}
 #endif
 
-#define TEST_COLOR_DEFAULT_             0
-#define TEST_COLOR_GREEN_               1
-#define TEST_COLOR_RED_                 2
-#define TEST_COLOR_DEFAULT_INTENSIVE_   3
-#define TEST_COLOR_GREEN_INTENSIVE_     4
-#define TEST_COLOR_RED_INTENSIVE_       5
+#define ACUTEST_COLOR_DEFAULT_              0
+#define ACUTEST_COLOR_GREEN_                1
+#define ACUTEST_COLOR_RED_                  2
+#define ACUTEST_COLOR_DEFAULT_INTENSIVE_    3
+#define ACUTEST_COLOR_GREEN_INTENSIVE_      4
+#define ACUTEST_COLOR_RED_INTENSIVE_        5
 
-static int TEST_ATTRIBUTE_(format (printf, 2, 3))
-test_print_in_color_(int color, const char* fmt, ...)
+static int ACUTEST_ATTRIBUTE_(format (printf, 2, 3))
+acutest_colored_printf_(int color, const char* fmt, ...)
 {
     va_list args;
     char buffer[256];
@@ -533,7 +581,7 @@ test_print_in_color_(int color, const char* fmt, ...)
     va_end(args);
     buffer[sizeof(buffer)-1] = '\0';
 
-    if(!test_colorize_) {
+    if(!acutest_colorize_) {
         return printf("%s", buffer);
     }
 
@@ -541,12 +589,12 @@ test_print_in_color_(int color, const char* fmt, ...)
     {
         const char* col_str;
         switch(color) {
-            case TEST_COLOR_GREEN_:             col_str = "\033[0;32m"; break;
-            case TEST_COLOR_RED_:               col_str = "\033[0;31m"; break;
-            case TEST_COLOR_GREEN_INTENSIVE_:   col_str = "\033[1;32m"; break;
-            case TEST_COLOR_RED_INTENSIVE_:     col_str = "\033[1;31m"; break;
-            case TEST_COLOR_DEFAULT_INTENSIVE_: col_str = "\033[1m"; break;
-            default:                            col_str = "\033[0m"; break;
+            case ACUTEST_COLOR_GREEN_:              col_str = "\033[0;32m"; break;
+            case ACUTEST_COLOR_RED_:                col_str = "\033[0;31m"; break;
+            case ACUTEST_COLOR_GREEN_INTENSIVE_:    col_str = "\033[1;32m"; break;
+            case ACUTEST_COLOR_RED_INTENSIVE_:      col_str = "\033[1;31m"; break;
+            case ACUTEST_COLOR_DEFAULT_INTENSIVE_:  col_str = "\033[1m"; break;
+            default:                                col_str = "\033[0m"; break;
         }
         printf("%s", col_str);
         n = printf("%s", buffer);
@@ -563,12 +611,12 @@ test_print_in_color_(int color, const char* fmt, ...)
         GetConsoleScreenBufferInfo(h, &info);
 
         switch(color) {
-            case TEST_COLOR_GREEN_:             attr = FOREGROUND_GREEN; break;
-            case TEST_COLOR_RED_:               attr = FOREGROUND_RED; break;
-            case TEST_COLOR_GREEN_INTENSIVE_:   attr = FOREGROUND_GREEN | FOREGROUND_INTENSITY; break;
-            case TEST_COLOR_RED_INTENSIVE_:     attr = FOREGROUND_RED | FOREGROUND_INTENSITY; break;
-            case TEST_COLOR_DEFAULT_INTENSIVE_: attr = FOREGROUND_BLUE | FOREGROUND_GREEN | FOREGROUND_RED | FOREGROUND_INTENSITY; break;
-            default:                            attr = 0; break;
+            case ACUTEST_COLOR_GREEN_:              attr = FOREGROUND_GREEN; break;
+            case ACUTEST_COLOR_RED_:                attr = FOREGROUND_RED; break;
+            case ACUTEST_COLOR_GREEN_INTENSIVE_:    attr = FOREGROUND_GREEN | FOREGROUND_INTENSITY; break;
+            case ACUTEST_COLOR_RED_INTENSIVE_:      attr = FOREGROUND_RED | FOREGROUND_INTENSITY; break;
+            case ACUTEST_COLOR_DEFAULT_INTENSIVE_:  attr = FOREGROUND_BLUE | FOREGROUND_GREEN | FOREGROUND_RED | FOREGROUND_INTENSITY; break;
+            default:                                attr = 0; break;
         }
         if(attr != 0)
             SetConsoleTextAttribute(h, attr);
@@ -583,49 +631,49 @@ test_print_in_color_(int color, const char* fmt, ...)
 }
 
 static void
-test_begin_test_line_(const struct test_* test)
+acutest_begin_test_line_(const struct acutest_test_* test)
 {
-    if(!test_tap_) {
-        if(test_verbose_level_ >= 3) {
-            test_print_in_color_(TEST_COLOR_DEFAULT_INTENSIVE_, "Test %s:\n", test->name);
-            test_current_already_logged_++;
-        } else if(test_verbose_level_ >= 1) {
+    if(!acutest_tap_) {
+        if(acutest_verbose_level_ >= 3) {
+            acutest_colored_printf_(ACUTEST_COLOR_DEFAULT_INTENSIVE_, "Test %s:\n", test->name);
+            acutest_test_already_logged_++;
+        } else if(acutest_verbose_level_ >= 1) {
             int n;
             char spaces[48];
 
-            n = test_print_in_color_(TEST_COLOR_DEFAULT_INTENSIVE_, "Test %s... ", test->name);
+            n = acutest_colored_printf_(ACUTEST_COLOR_DEFAULT_INTENSIVE_, "Test %s... ", test->name);
             memset(spaces, ' ', sizeof(spaces));
             if(n < (int) sizeof(spaces))
                 printf("%.*s", (int) sizeof(spaces) - n, spaces);
         } else {
-            test_current_already_logged_ = 1;
+            acutest_test_already_logged_ = 1;
         }
     }
 }
 
 static void
-test_finish_test_line_(int result)
+acutest_finish_test_line_(int result)
 {
-    if(test_tap_) {
+    if(acutest_tap_) {
         const char* str = (result == 0) ? "ok" : "not ok";
 
-        printf("%s %d - %s\n", str, test_current_index_ + 1, test_current_unit_->name);
+        printf("%s %d - %s\n", str, acutest_current_index_ + 1, acutest_current_test_->name);
 
-        if(result == 0  &&  test_timer_) {
+        if(result == 0  &&  acutest_timer_) {
             printf("# Duration: ");
-            test_timer_print_diff_();
+            acutest_timer_print_diff_();
             printf("\n");
         }
     } else {
-        int color = (result == 0) ? TEST_COLOR_GREEN_INTENSIVE_ : TEST_COLOR_RED_INTENSIVE_;
+        int color = (result == 0) ? ACUTEST_COLOR_GREEN_INTENSIVE_ : ACUTEST_COLOR_RED_INTENSIVE_;
         const char* str = (result == 0) ? "OK" : "FAILED";
         printf("[ ");
-        test_print_in_color_(color, "%s", str);
+        acutest_colored_printf_(color, "%s", str);
         printf(" ]");
 
-        if(result == 0  &&  test_timer_) {
+        if(result == 0  &&  acutest_timer_) {
             printf("  ");
-            test_timer_print_diff_();
+            acutest_timer_print_diff_();
         }
 
         printf("\n");
@@ -633,12 +681,12 @@ test_finish_test_line_(int result)
 }
 
 static void
-test_line_indent_(int level)
+acutest_line_indent_(int level)
 {
     static const char spaces[] = "                ";
     int n = level * 2;
 
-    if(test_tap_  &&  n > 0) {
+    if(acutest_tap_  &&  n > 0) {
         n--;
         printf("#");
     }
@@ -650,8 +698,8 @@ test_line_indent_(int level)
     printf("%.*s", n, spaces);
 }
 
-int TEST_ATTRIBUTE_(format (printf, 4, 5))
-test_check_(int cond, const char* file, int line, const char* fmt, ...)
+int ACUTEST_ATTRIBUTE_(format (printf, 4, 5))
+acutest_check_(int cond, const char* file, int line, const char* fmt, ...)
 {
     const char *result_str;
     int result_color;
@@ -659,30 +707,30 @@ test_check_(int cond, const char* file, int line, const char* fmt, ...)
 
     if(cond) {
         result_str = "ok";
-        result_color = TEST_COLOR_GREEN_;
+        result_color = ACUTEST_COLOR_GREEN_;
         verbose_level = 3;
     } else {
-        if(!test_current_already_logged_  &&  test_current_unit_ != NULL)
-            test_finish_test_line_(-1);
+        if(!acutest_test_already_logged_  &&  acutest_current_test_ != NULL)
+            acutest_finish_test_line_(-1);
 
         result_str = "failed";
-        result_color = TEST_COLOR_RED_;
+        result_color = ACUTEST_COLOR_RED_;
         verbose_level = 2;
-        test_current_failures_++;
-        test_current_already_logged_++;
+        acutest_test_failures_++;
+        acutest_test_already_logged_++;
     }
 
-    if(test_verbose_level_ >= verbose_level) {
+    if(acutest_verbose_level_ >= verbose_level) {
         va_list args;
 
-        if(!test_case_current_already_logged_  &&  test_case_name_[0]) {
-            test_line_indent_(1);
-            test_print_in_color_(TEST_COLOR_DEFAULT_INTENSIVE_, "Case %s:\n", test_case_name_);
-            test_current_already_logged_++;
-            test_case_current_already_logged_++;
+        if(!acutest_case_already_logged_  &&  acutest_case_name_[0]) {
+            acutest_line_indent_(1);
+            acutest_colored_printf_(ACUTEST_COLOR_DEFAULT_INTENSIVE_, "Case %s:\n", acutest_case_name_);
+            acutest_test_already_logged_++;
+            acutest_case_already_logged_++;
         }
 
-        test_line_indent_(test_case_name_[0] ? 2 : 1);
+        acutest_line_indent_(acutest_case_name_[0] ? 2 : 1);
         if(file != NULL) {
 #ifdef ACUTEST_WIN_
             const char* lastsep1 = strrchr(file, '\\');
@@ -705,58 +753,96 @@ test_check_(int cond, const char* file, int line, const char* fmt, ...)
         va_end(args);
 
         printf("... ");
-        test_print_in_color_(result_color, "%s", result_str);
+        acutest_colored_printf_(result_color, "%s", result_str);
         printf("\n");
-        test_current_already_logged_++;
+        acutest_test_already_logged_++;
     }
 
-    test_cond_failed_ = (cond == 0);
-    return !test_cond_failed_;
+    acutest_cond_failed_ = (cond == 0);
+    return !acutest_cond_failed_;
+}
+
+void ACUTEST_ATTRIBUTE_(format (printf, 1, 2))
+acutest_log_(const char* fmt, ...)
+{
+    char buffer[TEST_LOG_MAXSIZE];
+    acutest_data_log_* log_entry;
+    va_list args;
+
+    log_entry = (acutest_data_log_*)calloc(1, sizeof(acutest_data_log_));
+    if (log_entry == NULL) {
+        fprintf(stderr, "Out of memory.\n");
+        acutest_exit_(2);
+    }
+
+    /* This is the first log entry for the current test, set the head */
+    if (!acutest_test_data_[acutest_current_index_].log_head)
+        acutest_test_data_[acutest_current_index_].log_head = log_entry;
+
+    /* There is something already at the tail of the list - append our new entry */
+    if (acutest_test_data_[acutest_current_index_].log_tail)
+        acutest_test_data_[acutest_current_index_].log_tail->next = log_entry;
+
+    /* Set the tail of the list ready for the next append */
+    acutest_test_data_[acutest_current_index_].log_tail = log_entry;
+
+    va_start(args, fmt);
+    vsnprintf(buffer, TEST_LOG_MAXSIZE - 1, fmt, args);
+    va_end(args);
+    buffer[TEST_LOG_MAXSIZE - 1] = '\0';
+
+    log_entry->msg = (char *)calloc(strlen(buffer) + 1, sizeof(char));
+    if (log_entry->msg == NULL) {
+        fprintf(stderr, "Out of memory.\n");
+        acutest_exit_(2);
+
+    }
+    strcpy(log_entry->msg, buffer);
 }
 
-void TEST_ATTRIBUTE_(format (printf, 1, 2))
-test_case_(const char* fmt, ...)
+void ACUTEST_ATTRIBUTE_(format (printf, 1, 2))
+acutest_case_(const char* fmt, ...)
 {
     va_list args;
 
-    if(test_verbose_level_ < 2)
+    if(acutest_verbose_level_ < 2)
         return;
 
-    if(test_case_name_[0]) {
-        test_case_current_already_logged_ = 0;
-        test_case_name_[0] = '\0';
+    if(acutest_case_name_[0]) {
+        acutest_case_already_logged_ = 0;
+        acutest_case_name_[0] = '\0';
     }
 
     if(fmt == NULL)
         return;
 
     va_start(args, fmt);
-    vsnprintf(test_case_name_, sizeof(test_case_name_) - 1, fmt, args);
+    vsnprintf(acutest_case_name_, sizeof(acutest_case_name_) - 1, fmt, args);
     va_end(args);
-    test_case_name_[sizeof(test_case_name_) - 1] = '\0';
+    acutest_case_name_[sizeof(acutest_case_name_) - 1] = '\0';
 
-    if(test_verbose_level_ >= 3) {
-        test_line_indent_(1);
-        test_print_in_color_(TEST_COLOR_DEFAULT_INTENSIVE_, "Case %s:\n", test_case_name_);
-        test_current_already_logged_++;
-        test_case_current_already_logged_++;
+    if(acutest_verbose_level_ >= 3) {
+        acutest_line_indent_(1);
+        acutest_colored_printf_(ACUTEST_COLOR_DEFAULT_INTENSIVE_, "Case %s:\n", acutest_case_name_);
+        acutest_test_already_logged_++;
+        acutest_case_already_logged_++;
     }
 }
 
-void TEST_ATTRIBUTE_(format (printf, 1, 2))
-test_message_(const char* fmt, ...)
+void ACUTEST_ATTRIBUTE_(format (printf, 2, 3))
+acutest_message_(bool always, const char* fmt, ...)
 {
     char buffer[TEST_MSG_MAXSIZE];
     char* line_beg;
     char* line_end;
     va_list args;
 
-    if(test_verbose_level_ < 2)
+    if(acutest_verbose_level_ < 2)
         return;
 
     /* We allow extra message only when something is already wrong in the
-     * current test. */
-    if(test_current_unit_ == NULL  ||  !test_cond_failed_)
+     * current test or always is true. */
+    if((acutest_current_test_ == NULL  ||  !acutest_cond_failed_) && !always)
         return;
 
     va_start(args, fmt);
@@ -764,34 +850,38 @@ test_message_(const char* fmt, ...)
     va_end(args);
     buffer[TEST_MSG_MAXSIZE-1] = '\0';
 
+    acutest_log_("%s", buffer); /* Add the message to the log */
+
     line_beg = buffer;
     while(1) {
         line_end = strchr(line_beg, '\n');
         if(line_end == NULL)
             break;
-        test_line_indent_(test_case_name_[0] ? 3 : 2);
+        acutest_line_indent_(acutest_case_name_[0] ? 3 : 2);
         printf("%.*s\n", (int)(line_end - line_beg), line_beg);
         line_beg = line_end + 1;
     }
     if(line_beg[0] != '\0') {
-        test_line_indent_(test_case_name_[0] ? 3 : 2);
+        acutest_line_indent_(acutest_case_name_[0] ? 3 : 2);
         printf("%s\n", line_beg);
     }
 }
 
 void
-test_dump_(const char* title, const void* addr, size_t size)
+acutest_dump_(bool always, const char* title, const void* addr, size_t size)
 {
     static const size_t BYTES_PER_LINE = 16;
     size_t line_beg;
     size_t truncate = 0;
+    char* buffer;
+    char* p;
 
-    if(test_verbose_level_ < 2)
+    if(acutest_verbose_level_ < 2)
         return;
 
     /* We allow extra message only when something is already wrong in the
-     * current test. */
-    if(test_current_unit_ == NULL  ||  !test_cond_failed_)
+     * current test or always is true. */
+    if((acutest_current_test_ == NULL  ||  !acutest_cond_failed_) && !always)
         return;
 
     if(size > TEST_DUMP_MAXSIZE) {
@@ -799,19 +889,31 @@ test_dump_(const char* title, const void* addr, size_t size)
         size = TEST_DUMP_MAXSIZE;
     }
 
-    test_line_indent_(test_case_name_[0] ? 3 : 2);
+    /* Allocate space for log copy of dump */
+    buffer = (char *)calloc((size * 3) + strlen(title) + 2, sizeof(char));
+
+    acutest_line_indent_(acutest_case_name_[0] ? 3 : 2);
     printf((title[strlen(title)-1] == ':') ? "%s\n" : "%s:\n", title);
 
+    strcpy(buffer, title);
+    p = buffer + strlen(title);
+    if (title[strlen(title) - 1] != ':') {
+        *p = ':';
+        p++;
+    }
+
     for(line_beg = 0; line_beg < size; line_beg += BYTES_PER_LINE) {
         size_t line_end = line_beg + BYTES_PER_LINE;
         size_t off;
 
-        test_line_indent_(test_case_name_[0] ? 4 : 3);
+        acutest_line_indent_(acutest_case_name_[0] ? 4 : 3);
         printf("%08lx: ", (unsigned long)line_beg);
         for(off = line_beg; off < line_end; off++) {
-            if(off < size)
+            if(off < size) {
                 printf(" %02x", ((const unsigned char*)addr)[off]);
-            else
+                sprintf(p, " %02x", ((const unsigned char*)addr)[off]);
+                p += 3;
+            } else
                 printf("   ");
         }
 
@@ -828,14 +930,17 @@ test_dump_(const char* title, const void* addr, size_t size)
     }
 
     if(truncate > 0) {
-        test_line_indent_(test_case_name_[0] ? 4 : 3);
+        acutest_line_indent_(acutest_case_name_[0] ? 4 : 3);
         printf("           ... (and more %u bytes)\n", (unsigned) truncate);
     }
+
+    acutest_log_("%s", buffer);
+    free(buffer);
 }
 
 /* This is called just before each test */
 static void
-test_init_(const char *test_name)
+acutest_init_(const char *test_name)
 {
 #ifdef TEST_INIT
     TEST_INIT
@@ -848,7 +953,7 @@ test_init_(const char *test_name)
 
 /* This is called after each test */
 static void
-test_fini_(const char *test_name)
+acutest_fini_(const char *test_name)
 {
 #ifdef TEST_FINI
     TEST_FINI
@@ -860,51 +965,51 @@ test_fini_(const char *test_name)
 }
 
 void
-test_abort_(void)
+acutest_abort_(void)
 {
-    if(test_abort_has_jmp_buf_) {
-        longjmp(test_abort_jmp_buf_, 1);
+    if(acutest_abort_has_jmp_buf_) {
+        longjmp(acutest_abort_jmp_buf_, 1);
     } else {
-        if(test_current_unit_ != NULL)
-            test_fini_(test_current_unit_->name);
+        if(acutest_current_test_ != NULL)
+            acutest_fini_(acutest_current_test_->name);
         abort();
     }
 }
 
 static void
-test_list_names_(void)
+acutest_list_names_(void)
 {
-    const struct test_* test;
+    const struct acutest_test_* test;
 
     printf("Unit tests:\n");
-    for(test = &test_list_[0]; test->func != NULL; test++)
+    for(test = &acutest_list_[0]; test->func != NULL; test++)
         printf("  %s\n", test->name);
 }
 
 static void
-test_remember_(int i)
+acutest_remember_(int i)
 {
-    if(test_details_[i].flags & TEST_FLAG_RUN_)
+    if(acutest_test_data_[i].flags & ACUTEST_FLAG_RUN_)
         return;
 
-    test_details_[i].flags |= TEST_FLAG_RUN_;
-    test_count_++;
+    acutest_test_data_[i].flags |= ACUTEST_FLAG_RUN_;
+    acutest_count_++;
 }
 
 static void
-test_set_success_(int i, int success)
+acutest_set_success_(int i, int success)
 {
-    test_details_[i].flags |= success ? TEST_FLAG_SUCCESS_ : TEST_FLAG_FAILURE_;
+    acutest_test_data_[i].flags |= success ? ACUTEST_FLAG_SUCCESS_ : ACUTEST_FLAG_FAILURE_;
 }
 
 static void
-test_set_duration_(int i, double duration)
+acutest_set_duration_(int i, double duration)
 {
-    test_details_[i].duration = duration;
+    acutest_test_data_[i].duration = duration;
 }
 
 static int
-test_name_contains_word_(const char* name, const char* pattern)
+acutest_name_contains_word_(const char* name, const char* pattern)
 {
     static const char word_delim[] = " \t-_/.,:;";
     const char* substr;
@@ -927,15 +1032,15 @@ test_name_contains_word_(const char* name, const char* pattern)
 }
 
 static int
-test_lookup_(const char* pattern)
+acutest_lookup_(const char* pattern)
 {
     int i;
     int n = 0;
 
     /* Try exact match. */
-    for(i = 0; i < (int) test_list_size_; i++) {
-        if(strcmp(test_list_[i].name, pattern) == 0) {
-            test_remember_(i);
+    for(i = 0; i < (int) acutest_list_size_; i++) {
+        if(strcmp(acutest_list_[i].name, pattern) == 0) {
+            acutest_remember_(i);
             n++;
             break;
         }
@@ -944,9 +1049,9 @@ test_lookup_(const char* pattern)
         return n;
 
     /* Try word match. */
-    for(i = 0; i < (int) test_list_size_; i++) {
-        if(test_name_contains_word_(test_list_[i].name, pattern)) {
-            test_remember_(i);
+    for(i = 0; i < (int) acutest_list_size_; i++) {
+        if(acutest_name_contains_word_(acutest_list_[i].name, pattern)) {
+            acutest_remember_(i);
             n++;
         }
     }
@@ -954,9 +1059,9 @@ test_lookup_(const char* pattern)
         return n;
 
     /* Try relaxed match. */
-    for(i = 0; i < (int) test_list_size_; i++) {
-        if(strstr(test_list_[i].name, pattern) != NULL) {
-            test_remember_(i);
+    for(i = 0; i < (int) acutest_list_size_; i++) {
+        if(strstr(acutest_list_[i].name, pattern) != NULL) {
+            acutest_remember_(i);
             n++;
         }
     }
@@ -968,167 +1073,191 @@ test_lookup_(const char* pattern)
 /* Called if anything goes bad in Acutest, or if the unit test ends in other
  * way then by normal returning from its function (e.g. exception or some
  * abnormal child process termination). */
-static void TEST_ATTRIBUTE_(format (printf, 1, 2))
-test_error_(const char* fmt, ...)
+static void ACUTEST_ATTRIBUTE_(format (printf, 1, 2))
+acutest_error_(const char* fmt, ...)
 {
-    if(test_verbose_level_ == 0)
+    if(acutest_verbose_level_ == 0)
         return;
 
-    if(test_verbose_level_ >= 2) {
+    if(acutest_verbose_level_ >= 2) {
         va_list args;
 
-        test_line_indent_(1);
-        if(test_verbose_level_ >= 3)
-            test_print_in_color_(TEST_COLOR_RED_INTENSIVE_, "ERROR: ");
+        acutest_line_indent_(1);
+        if(acutest_verbose_level_ >= 3)
+            acutest_colored_printf_(ACUTEST_COLOR_RED_INTENSIVE_, "ERROR: ");
         va_start(args, fmt);
         vprintf(fmt, args);
         va_end(args);
         printf("\n");
     }
 
-    if(test_verbose_level_ >= 3) {
+    if(acutest_verbose_level_ >= 3) {
         printf("\n");
     }
 }
 
 /* Call directly the given test unit function. */
 static int
-test_do_run_(const struct test_* test, int index)
+acutest_do_run_(const struct acutest_test_* test, int index)
 {
     int status = -1;
 
-    test_was_aborted_ = 0;
-    test_current_unit_ = test;
-    test_current_index_ = index;
-    test_current_failures_ = 0;
-    test_current_already_logged_ = 0;
-    test_cond_failed_ = 0;
+    acutest_was_aborted_ = 0;
+    acutest_current_test_ = test;
+    acutest_current_index_ = index;
+    acutest_test_failures_ = 0;
+    acutest_test_already_logged_ = 0;
+    acutest_cond_failed_ = 0;
 
 #ifdef __cplusplus
     try {
 #endif
-        test_init_(test->name);
-        test_begin_test_line_(test);
+        acutest_init_(test->name);
+        acutest_begin_test_line_(test);
 
         /* This is good to do in case the test unit crashes. */
         fflush(stdout);
         fflush(stderr);
 
-        if(!test_worker_) {
-            test_abort_has_jmp_buf_ = 1;
-            if(setjmp(test_abort_jmp_buf_) != 0) {
-                test_was_aborted_ = 1;
+        if(!acutest_worker_) {
+            acutest_abort_has_jmp_buf_ = 1;
+            if(setjmp(acutest_abort_jmp_buf_) != 0) {
+                acutest_was_aborted_ = 1;
                 goto aborted;
             }
         }
 
-        test_timer_get_time_(&test_timer_start_);
+        acutest_timer_get_time_(&acutest_timer_start_);
         test->func();
 aborted:
-        test_abort_has_jmp_buf_ = 0;
-        test_timer_get_time_(&test_timer_end_);
+        acutest_abort_has_jmp_buf_ = 0;
+        acutest_timer_get_time_(&acutest_timer_end_);
 
-        if(test_verbose_level_ >= 3) {
-            test_line_indent_(1);
-            if(test_current_failures_ == 0) {
-                test_print_in_color_(TEST_COLOR_GREEN_INTENSIVE_, "SUCCESS: ");
+        if(acutest_verbose_level_ >= 3) {
+            acutest_line_indent_(1);
+            if(acutest_test_failures_ == 0) {
+                acutest_colored_printf_(ACUTEST_COLOR_GREEN_INTENSIVE_, "SUCCESS: ");
                 printf("All conditions have passed.\n");
 
-                if(test_timer_) {
-                    test_line_indent_(1);
+                if(acutest_timer_) {
+                    acutest_line_indent_(1);
                     printf("Duration: ");
-                    test_timer_print_diff_();
+                    acutest_timer_print_diff_();
                     printf("\n");
                 }
             } else {
-                test_print_in_color_(TEST_COLOR_RED_INTENSIVE_, "FAILED: ");
-                if(!test_was_aborted_) {
+                acutest_colored_printf_(ACUTEST_COLOR_RED_INTENSIVE_, "FAILED: ");
+                if(!acutest_was_aborted_) {
                     printf("%d condition%s %s failed.\n",
-                            test_current_failures_,
-                            (test_current_failures_ == 1) ? "" : "s",
-                            (test_current_failures_ == 1) ? "has" : "have");
+                            acutest_test_failures_,
+                            (acutest_test_failures_ == 1) ? "" : "s",
+                            (acutest_test_failures_ == 1) ? "has" : "have");
                 } else {
                     printf("Aborted.\n");
                 }
             }
             printf("\n");
-        } else if(test_verbose_level_ >= 1 && test_current_failures_ == 0) {
-            test_finish_test_line_(0);
+        } else if(acutest_verbose_level_ >= 1 && acutest_test_failures_ == 0) {
+            acutest_finish_test_line_(0);
         }
 
-        status = (test_current_failures_ == 0) ? 0 : -1;
+        status = (acutest_test_failures_ == 0) ? 0 : -1;
 
 #ifdef __cplusplus
     } catch(std::exception& e) {
         const char* what = e.what();
-        test_check_(0, NULL, 0, "Threw std::exception");
+        acutest_check_(0, NULL, 0, "Threw std::exception");
         if(what != NULL)
-            test_message_("std::exception::what(): %s", what);
+            acutest_message_(false, "std::exception::what(): %s", what);
 
-        if(test_verbose_level_ >= 3) {
-            test_line_indent_(1);
-            test_print_in_color_(TEST_COLOR_RED_INTENSIVE_, "FAILED: ");
+        if(acutest_verbose_level_ >= 3) {
+            acutest_line_indent_(1);
+            acutest_colored_printf_(ACUTEST_COLOR_RED_INTENSIVE_, "FAILED: ");
             printf("C++ exception.\n\n");
         }
     } catch(...) {
-        test_check_(0, NULL, 0, "Threw an exception");
+        acutest_check_(0, NULL, 0, "Threw an exception");
 
-        if(test_verbose_level_ >= 3) {
-            test_line_indent_(1);
-            test_print_in_color_(TEST_COLOR_RED_INTENSIVE_, "FAILED: ");
+        if(acutest_verbose_level_ >= 3) {
+            acutest_line_indent_(1);
+            acutest_colored_printf_(ACUTEST_COLOR_RED_INTENSIVE_, "FAILED: ");
             printf("C++ exception.\n\n");
         }
     }
 #endif
 
-    test_fini_(test->name);
-    test_case_(NULL);
-    test_current_unit_ = NULL;
+    acutest_fini_(test->name);
+    acutest_case_(NULL);
+    acutest_current_test_ = NULL;
 
     return status;
 }
 
 /* Trigger the unit test. If possible (and not suppressed) it starts a child
- * process who calls test_do_run_(), otherwise it calls test_do_run_()
+ * process who calls acutest_do_run_(), otherwise it calls acutest_do_run_()
  * directly. */
 static void
-test_run_(const struct test_* test, int index, int master_index)
+acutest_run_(const struct acutest_test_* test, int index, int master_index)
 {
     int failed = 1;
-    test_timer_type_ start, end;
+    acutest_timer_type_ start, end;
 
-    test_current_unit_ = test;
-    test_current_already_logged_ = 0;
-    test_timer_get_time_(&start);
+    acutest_current_test_ = test;
+    acutest_test_already_logged_ = 0;
+    acutest_timer_get_time_(&start);
 
-    if(!test_no_exec_) {
+    if(!acutest_no_exec_) {
 
 #if defined(ACUTEST_UNIX_)
 
         pid_t pid;
         int exit_code;
+        int fd[2];
+        char msg[TEST_LOG_MAXSIZE];
+        char *p;
+        size_t count;
 
         /* Make sure the child starts with empty I/O buffers. */
         fflush(stdout);
         fflush(stderr);
 
+        if (pipe(fd) == -1) {
+            fprintf(stderr, "Unable to create pipe.\n");
+            acutest_exit_(2);
+        }
+
         pid = fork();
         if(pid == (pid_t)-1) {
-            test_error_("Cannot fork. %s [%d]", strerror(errno), errno);
+            acutest_error_("Cannot fork. %s [%d]", strerror(errno), errno);
             failed = 1;
         } else if(pid == 0) {
             /* Child: Do the test. */
-            test_worker_ = 1;
-            failed = (test_do_run_(test, index) != 0);
-            test_exit_(failed ? 1 : 0);
+            acutest_data_log_* log_entry;
+            close(fd[0]);  /* Child only uses the write pipe, close the read one */
+            acutest_worker_ = 1;
+            failed = (acutest_do_run_(test, index) != 0);
+
+            /* Write any log messages to the pipe.
+             * Send each log entry as a null terminated string */
+            log_entry = acutest_test_data_[index].log_head;
+            while (log_entry) {
+                if (write(fd[1], log_entry->msg, (strlen(log_entry->msg) + 1) * sizeof(char)) == -1) {
+                    fprintf(stderr, "Unable to write to pipe\n");
+                    acutest_exit_(2);
+                }
+                log_entry = log_entry->next;
+            }
+            close(fd[1]);
+            acutest_exit_(failed ? 1 : 0);
         } else {
+            close(fd[1]); /* Parent only uses the read pipe, close the write one */
             /* Parent: Wait until child terminates and analyze its exit code. */
             waitpid(pid, &exit_code, 0);
             if(WIFEXITED(exit_code)) {
                 switch(WEXITSTATUS(exit_code)) {
                     case 0:   failed = 0; break;   /* test has passed. */
                     case 1:   /* noop */ break;    /* "normal" failure. */
-                    default:  test_error_("Unexpected exit code [%d]", WEXITSTATUS(exit_code));
+                    default:  acutest_error_("Unexpected exit code [%d]", WEXITSTATUS(exit_code));
                 }
             } else if(WIFSIGNALED(exit_code)) {
                 char tmp[32];
@@ -1144,10 +1273,31 @@ test_run_(const struct test_* test, int index, int master_index)
                     case SIGTERM: signame = "SIGTERM"; break;
                     default:      sprintf(tmp, "signal %d", WTERMSIG(exit_code)); signame = tmp; break;
                 }
-                test_error_("Test interrupted by %s.", signame);
+                acutest_error_("Test interrupted by %s.", signame);
             } else {
-                test_error_("Test ended in an unexpected way [%d].", exit_code);
+                acutest_error_("Test ended in an unexpected way [%d].", exit_code);
             }
+
+            /* Read log messages from the child, one character at a time to
+             * find the NULLs, then re-create the log entries in the parent */
+            p = msg;
+            count = 0;
+            acutest_current_index_ = index; /* acutest_log_() needs this set to know which entry to populate */
+            while (read(fd[0], p, sizeof(char))) {
+                if (*p == '\0') { /* Found a NULL terminator */
+                    acutest_log_("%s", msg); /* Create parent log entry */
+                    p = msg; /* reset pointer */
+                    count = 0;
+                } else {
+                    p++;
+                    count++;
+                }
+                if (count >= TEST_LOG_MAXSIZE) {
+                    fprintf(stderr, "Log message from child too large");
+                    acutest_exit_(2);
+                }
+            }
+            close(fd[0]);
         }
 
 #elif defined(ACUTEST_WIN_)
@@ -1156,66 +1306,105 @@ test_run_(const struct test_* test, int index, int master_index)
         STARTUPINFOA startupInfo;
         PROCESS_INFORMATION processInfo;
         DWORD exitCode;
+        HANDLE hRead = NULL;
+        HANDLE hWrite = NULL;
+        SECURITY_ATTRIBUTES lpPipeAttribute;
+        lpPipeAttribute.nLength = sizeof(lpPipeAttribute);
+        lpPipeAttribute.lpSecurityDescriptor = NULL;
+        lpPipeAttribute.bInheritHandle = TRUE;
+        char* p;
+        char msg[TEST_LOG_MAXSIZE];
+        size_t count;
+
+        /* Create pipe for receiveing log entries */
+        if (!CreatePipe(&hRead, &hWrite, &lpPipeAttribute, 0)) {
+            fprintf(stderr, "Error creating pipe\n");
+            acutest_exit_(2);
+        }
 
         /* Windows has no fork(). So we propagate all info into the child
          * through a command line arguments. */
         _snprintf(buffer, sizeof(buffer)-1,
-                 "%s --worker=%d %s --no-exec --no-summary %s --verbose=%d --color=%s -- \"%s\"",
-                 test_argv0_, index, test_timer_ ? "--time" : "",
-                 test_tap_ ? "--tap" : "", test_verbose_level_,
-                 test_colorize_ ? "always" : "never",
+                 "%s --worker=%d %s --no-exec --no-summary %s --verbose=%d --color=%s --pipe=%I64d -- \"%s\"",
+                 acutest_argv0_, index, acutest_timer_ ? "--time" : "",
+                 acutest_tap_ ? "--tap" : "", acutest_verbose_level_,
+                 acutest_colorize_ ? "always" : "never", (ULONG64)(ULONG_PTR)hWrite,
                  test->name);
         memset(&startupInfo, 0, sizeof(startupInfo));
         startupInfo.cb = sizeof(STARTUPINFO);
-        if(CreateProcessA(NULL, buffer, NULL, NULL, FALSE, 0, NULL, NULL, &startupInfo, &processInfo)) {
+        if(CreateProcessA(NULL, buffer, NULL, NULL, TRUE, 0, NULL, NULL, &startupInfo, &processInfo)) {
             WaitForSingleObject(processInfo.hProcess, INFINITE);
             GetExitCodeProcess(processInfo.hProcess, &exitCode);
             CloseHandle(processInfo.hThread);
             CloseHandle(processInfo.hProcess);
+
+            /* Read log messages from the child, one character at a time to
+             * find the NULLs, then re-create the log entries in the parent */
+            p = msg;
+            count = 0;
+            acutest_current_index_ = index; /* acutest_log_() needs this set to know which entry to populate */
+            while (ReadFile(hRead, p, sizeof(char), NULL, NULL)) {
+                if (*p == '\0') { /* Found a NULL terminator */
+                    acutest_log_("%s", msg); /* Create parent log entry */
+                    p = msg; /* reset pointer */
+                    count = 0;
+                }
+                else {
+                    p++;
+                    count++;
+                }
+                if (count >= TEST_MSG_MAXSIZE) {
+                    fprintf(stderr, "Log message from child too large");
+                    acutest_exit_(2);
+                }
+            }
+
+            CloseHandle(hRead);
+            CloseHandle(hWrite);
             failed = (exitCode != 0);
             if(exitCode > 1) {
                 switch(exitCode) {
-                    case 3:             test_error_("Aborted."); break;
-                    case 0xC0000005:    test_error_("Access violation."); break;
-                    default:            test_error_("Test ended in an unexpected way [%lu].", exitCode); break;
+                    case 3:             acutest_error_("Aborted."); break;
+                    case 0xC0000005:    acutest_error_("Access violation."); break;
+                    default:            acutest_error_("Test ended in an unexpected way [%lu].", exitCode); break;
                 }
             }
         } else {
-            test_error_("Cannot create unit test subprocess [%ld].", GetLastError());
+            acutest_error_("Cannot create unit test subprocess [%ld].", GetLastError());
             failed = 1;
         }
 
 #else
 
         /* A platform where we don't know how to run child process. */
-        failed = (test_do_run_(test, index) != 0);
+        failed = (acutest_do_run_(test, index) != 0);
 
 #endif
 
     } else {
         /* Child processes suppressed through --no-exec. */
-        failed = (test_do_run_(test, index) != 0);
+        failed = (acutest_do_run_(test, index) != 0);
     }
-    test_timer_get_time_(&end);
+    acutest_timer_get_time_(&end);
 
-    test_current_unit_ = NULL;
+    acutest_current_test_ = NULL;
 
-    test_stat_run_units_++;
+    acutest_stat_run_units_++;
     if(failed)
-        test_stat_failed_units_++;
+        acutest_stat_failed_units_++;
 
-    test_set_success_(master_index, !failed);
-    test_set_duration_(master_index, test_timer_diff_(start, end));
+    acutest_set_success_(master_index, !failed);
+    acutest_set_duration_(master_index, acutest_timer_diff_(start, end));
 }
 
 #if defined(ACUTEST_WIN_)
 /* Callback for SEH events. */
 static LONG CALLBACK
-test_seh_exception_filter_(EXCEPTION_POINTERS *ptrs)
+acutest_seh_exception_filter_(EXCEPTION_POINTERS *ptrs)
 {
-    test_check_(0, NULL, 0, "Unhandled SEH exception");
-    test_message_("Exception code:    0x%08lx", ptrs->ExceptionRecord->ExceptionCode);
-    test_message_("Exception address: 0x%p", ptrs->ExceptionRecord->ExceptionAddress);
+    acutest_check_(0, NULL, 0, "Unhandled SEH exception");
+    acutest_message_(false, "Exception code:    0x%08lx", ptrs->ExceptionRecord->ExceptionCode);
+    acutest_message_(false, "Exception address: 0x%p", ptrs->ExceptionRecord->ExceptionAddress);
 
     fflush(stdout);
     fflush(stderr);
@@ -1225,27 +1414,27 @@ test_seh_exception_filter_(EXCEPTION_POINTERS *ptrs)
 #endif
 
 
-#define TEST_CMDLINE_OPTFLAG_OPTIONALARG_   0x0001
-#define TEST_CMDLINE_OPTFLAG_REQUIREDARG_   0x0002
+#define ACUTEST_CMDLINE_OPTFLAG_OPTIONALARG_    0x0001
+#define ACUTEST_CMDLINE_OPTFLAG_REQUIREDARG_    0x0002
 
-#define TEST_CMDLINE_OPTID_NONE_            0
-#define TEST_CMDLINE_OPTID_UNKNOWN_         (-0x7fffffff + 0)
-#define TEST_CMDLINE_OPTID_MISSINGARG_      (-0x7fffffff + 1)
-#define TEST_CMDLINE_OPTID_BOGUSARG_        (-0x7fffffff + 2)
+#define ACUTEST_CMDLINE_OPTID_NONE_             0
+#define ACUTEST_CMDLINE_OPTID_UNKNOWN_          (-0x7fffffff + 0)
+#define ACUTEST_CMDLINE_OPTID_MISSINGARG_       (-0x7fffffff + 1)
+#define ACUTEST_CMDLINE_OPTID_BOGUSARG_         (-0x7fffffff + 2)
 
-typedef struct TEST_CMDLINE_OPTION_ {
+typedef struct acutest_test_CMDLINE_OPTION_ {
     char shortname;
     const char* longname;
     int id;
     unsigned flags;
-} TEST_CMDLINE_OPTION_;
+} ACUTEST_CMDLINE_OPTION_;
 
 static int
-test_cmdline_handle_short_opt_group_(const TEST_CMDLINE_OPTION_* options,
+acutest_cmdline_handle_short_opt_group_(const ACUTEST_CMDLINE_OPTION_* options,
                     const char* arggroup,
                     int (*callback)(int /*optval*/, const char* /*arg*/))
 {
-    const TEST_CMDLINE_OPTION_* opt;
+    const ACUTEST_CMDLINE_OPTION_* opt;
     int i;
     int ret = 0;
 
@@ -1255,7 +1444,7 @@ test_cmdline_handle_short_opt_group_(const TEST_CMDLINE_OPTION_* options,
                 break;
         }
 
-        if(opt->id != 0  &&  !(opt->flags & TEST_CMDLINE_OPTFLAG_REQUIREDARG_)) {
+        if(opt->id != 0  &&  !(opt->flags & ACUTEST_CMDLINE_OPTFLAG_REQUIREDARG_)) {
             ret = callback(opt->id, NULL);
         } else {
             /* Unknown option. */
@@ -1263,7 +1452,7 @@ test_cmdline_handle_short_opt_group_(const TEST_CMDLINE_OPTION_* options,
             badoptname[0] = '-';
             badoptname[1] = arggroup[i];
             badoptname[2] = '\0';
-            ret = callback((opt->id != 0 ? TEST_CMDLINE_OPTID_MISSINGARG_ : TEST_CMDLINE_OPTID_UNKNOWN_),
+            ret = callback((opt->id != 0 ? ACUTEST_CMDLINE_OPTID_MISSINGARG_ : ACUTEST_CMDLINE_OPTID_UNKNOWN_),
                             badoptname);
         }
 
@@ -1274,31 +1463,31 @@ test_cmdline_handle_short_opt_group_(const TEST_CMDLINE_OPTION_* options,
     return ret;
 }
 
-#define TEST_CMDLINE_AUXBUF_SIZE_  32
+#define ACUTEST_CMDLINE_AUXBUF_SIZE_  32
 
 static int
-test_cmdline_read_(const TEST_CMDLINE_OPTION_* options, int argc, char** argv,
-                    int (*callback)(int /*optval*/, const char* /*arg*/))
+acutest_cmdline_read_(const ACUTEST_CMDLINE_OPTION_* options, int argc, char** argv,
+                      int (*callback)(int /*optval*/, const char* /*arg*/))
 {
 
-    const TEST_CMDLINE_OPTION_* opt;
-    char auxbuf[TEST_CMDLINE_AUXBUF_SIZE_+1];
+    const ACUTEST_CMDLINE_OPTION_* opt;
+    char auxbuf[ACUTEST_CMDLINE_AUXBUF_SIZE_+1];
     int after_doubledash = 0;
     int i = 1;
     int ret = 0;
 
-    auxbuf[TEST_CMDLINE_AUXBUF_SIZE_] = '\0';
+    auxbuf[ACUTEST_CMDLINE_AUXBUF_SIZE_] = '\0';
 
     while(i < argc) {
         if(after_doubledash  ||  strcmp(argv[i], "-") == 0) {
             /* Non-option argument. */
-            ret = callback(TEST_CMDLINE_OPTID_NONE_, argv[i]);
+            ret = callback(ACUTEST_CMDLINE_OPTID_NONE_, argv[i]);
         } else if(strcmp(argv[i], "--") == 0) {
             /* End of options. All the remaining members are non-option arguments. */
             after_doubledash = 1;
         } else if(argv[i][0] != '-') {
             /* Non-option argument. */
-            ret = callback(TEST_CMDLINE_OPTID_NONE_, argv[i]);
+            ret = callback(ACUTEST_CMDLINE_OPTID_NONE_, argv[i]);
         } else {
             for(opt = options; opt->id != 0; opt++) {
                 if(opt->longname != NULL  &&  strncmp(argv[i], "--", 2) == 0) {
@@ -1307,18 +1496,18 @@ test_cmdline_read_(const TEST_CMDLINE_OPTION_* options, int argc, char** argv,
                         /* Regular long option. */
                         if(argv[i][2+len] == '\0') {
                             /* with no argument provided. */
-                            if(!(opt->flags & TEST_CMDLINE_OPTFLAG_REQUIREDARG_))
+                            if(!(opt->flags & ACUTEST_CMDLINE_OPTFLAG_REQUIREDARG_))
                                 ret = callback(opt->id, NULL);
                             else
-                                ret = callback(TEST_CMDLINE_OPTID_MISSINGARG_, argv[i]);
+                                ret = callback(ACUTEST_CMDLINE_OPTID_MISSINGARG_, argv[i]);
                             break;
                         } else if(argv[i][2+len] == '=') {
                             /* with an argument provided. */
-                            if(opt->flags & (TEST_CMDLINE_OPTFLAG_OPTIONALARG_ | TEST_CMDLINE_OPTFLAG_REQUIREDARG_)) {
+                            if(opt->flags & (ACUTEST_CMDLINE_OPTFLAG_OPTIONALARG_ | ACUTEST_CMDLINE_OPTFLAG_REQUIREDARG_)) {
                                 ret = callback(opt->id, argv[i]+2+len+1);
                             } else {
                                 sprintf(auxbuf, "--%s", opt->longname);
-                                ret = callback(TEST_CMDLINE_OPTID_BOGUSARG_, auxbuf);
+                                ret = callback(ACUTEST_CMDLINE_OPTID_BOGUSARG_, auxbuf);
                             }
                             break;
                         } else {
@@ -1328,13 +1517,13 @@ test_cmdline_read_(const TEST_CMDLINE_OPTION_* options, int argc, char** argv,
                 } else if(opt->shortname != '\0'  &&  argv[i][0] == '-') {
                     if(argv[i][1] == opt->shortname) {
                         /* Regular short option. */
-                        if(opt->flags & TEST_CMDLINE_OPTFLAG_REQUIREDARG_) {
+                        if(opt->flags & ACUTEST_CMDLINE_OPTFLAG_REQUIREDARG_) {
                             if(argv[i][2] != '\0')
                                 ret = callback(opt->id, argv[i]+2);
                             else if(i+1 < argc)
                                 ret = callback(opt->id, argv[++i]);
                             else
-                                ret = callback(TEST_CMDLINE_OPTID_MISSINGARG_, argv[i]);
+                                ret = callback(ACUTEST_CMDLINE_OPTID_MISSINGARG_, argv[i]);
                             break;
                         } else {
                             ret = callback(opt->id, NULL);
@@ -1342,7 +1531,7 @@ test_cmdline_read_(const TEST_CMDLINE_OPTION_* options, int argc, char** argv,
                             /* There might be more (argument-less) short options
                              * grouped together. */
                             if(ret == 0  &&  argv[i][2] != '\0')
-                                ret = test_cmdline_handle_short_opt_group_(options, argv[i]+2, callback);
+                                ret = acutest_cmdline_handle_short_opt_group_(options, argv[i]+2, callback);
                             break;
                         }
                     }
@@ -1352,7 +1541,7 @@ test_cmdline_read_(const TEST_CMDLINE_OPTION_* options, int argc, char** argv,
             if(opt->id == 0) {  /* still not handled? */
                 if(argv[i][0] != '-') {
                     /* Non-option argument. */
-                    ret = callback(TEST_CMDLINE_OPTID_NONE_, argv[i]);
+                    ret = callback(ACUTEST_CMDLINE_OPTID_NONE_, argv[i]);
                 } else {
                     /* Unknown option. */
                     char* badoptname = argv[i];
@@ -1362,15 +1551,15 @@ test_cmdline_read_(const TEST_CMDLINE_OPTION_* options, int argc, char** argv,
                         char* assignment = strchr(badoptname, '=');
                         if(assignment != NULL) {
                             size_t len = assignment - badoptname;
-                            if(len > TEST_CMDLINE_AUXBUF_SIZE_)
-                                len = TEST_CMDLINE_AUXBUF_SIZE_;
+                            if(len > ACUTEST_CMDLINE_AUXBUF_SIZE_)
+                                len = ACUTEST_CMDLINE_AUXBUF_SIZE_;
                             strncpy(auxbuf, badoptname, len);
                             auxbuf[len] = '\0';
                             badoptname = auxbuf;
                         }
                     }
 
-                    ret = callback(TEST_CMDLINE_OPTID_UNKNOWN_, badoptname);
+                    ret = callback(ACUTEST_CMDLINE_OPTID_UNKNOWN_, badoptname);
                 }
             }
         }
@@ -1384,9 +1573,9 @@ test_cmdline_read_(const TEST_CMDLINE_OPTION_* options, int argc, char** argv,
 }
 
 static void
-test_help_(void)
+acutest_help_(void)
 {
-    printf("Usage: %s [options] [test...]\n", test_argv0_);
+    printf("Usage: %s [options] [test...]\n", acutest_argv0_);
     printf("\n");
     printf("Run the specified unit tests; or if the option '--skip' is used, run all\n");
     printf("tests in the suite but those listed.  By default, if no tests are specified\n");
@@ -1421,158 +1610,164 @@ test_help_(void)
     printf("      --no-color        Same as --color=never\n");
     printf("  -h, --help            Display this help and exit\n");
 
-    if(test_list_size_ < 16) {
+    if(acutest_list_size_ < 16) {
         printf("\n");
-        test_list_names_();
+        acutest_list_names_();
     }
 }
 
-static const TEST_CMDLINE_OPTION_ test_cmdline_options_[] = {
+static const ACUTEST_CMDLINE_OPTION_ acutest_cmdline_options_[] = {
     { 's',  "skip",         's', 0 },
-    {  0,   "exec",         'e', TEST_CMDLINE_OPTFLAG_OPTIONALARG_ },
+    {  0,   "exec",         'e', ACUTEST_CMDLINE_OPTFLAG_OPTIONALARG_ },
     { 'E',  "no-exec",      'E', 0 },
 #if defined ACUTEST_WIN_
     { 't',  "time",         't', 0 },
     {  0,   "timer",        't', 0 },   /* kept for compatibility */
+    {  0,   "pipe",         'p', ACUTEST_CMDLINE_OPTFLAG_REQUIREDARG_},  /* internal */
 #elif defined ACUTEST_HAS_POSIX_TIMER_
-    { 't',  "time",         't', TEST_CMDLINE_OPTFLAG_OPTIONALARG_ },
-    {  0,   "timer",        't', TEST_CMDLINE_OPTFLAG_OPTIONALARG_ },  /* kept for compatibility */
+    { 't',  "time",         't', ACUTEST_CMDLINE_OPTFLAG_OPTIONALARG_ },
+    {  0,   "timer",        't', ACUTEST_CMDLINE_OPTFLAG_OPTIONALARG_ },  /* kept for compatibility */
 #endif
     {  0,   "no-summary",   'S', 0 },
     {  0,   "tap",          'T', 0 },
     { 'l',  "list",         'l', 0 },
-    { 'v',  "verbose",      'v', TEST_CMDLINE_OPTFLAG_OPTIONALARG_ },
+    { 'v',  "verbose",      'v', ACUTEST_CMDLINE_OPTFLAG_OPTIONALARG_ },
     { 'q',  "quiet",        'q', 0 },
-    {  0,   "color",        'c', TEST_CMDLINE_OPTFLAG_OPTIONALARG_ },
+    {  0,   "color",        'c', ACUTEST_CMDLINE_OPTFLAG_OPTIONALARG_ },
     {  0,   "no-color",     'C', 0 },
     { 'h',  "help",         'h', 0 },
-    {  0,   "worker",       'w', TEST_CMDLINE_OPTFLAG_REQUIREDARG_ },  /* internal */
-    { 'x',  "xml-output",   'x', TEST_CMDLINE_OPTFLAG_REQUIREDARG_ },
+    {  0,   "worker",       'w', ACUTEST_CMDLINE_OPTFLAG_REQUIREDARG_ },  /* internal */
+    { 'x',  "xml-output",   'x', ACUTEST_CMDLINE_OPTFLAG_REQUIREDARG_ },
     {  0,   NULL,            0,  0 }
 };
 
 static int
-test_cmdline_callback_(int id, const char* arg)
+acutest_cmdline_callback_(int id, const char* arg)
 {
     switch(id) {
         case 's':
-            test_skip_mode_ = 1;
+            acutest_skip_mode_ = 1;
             break;
 
         case 'e':
             if(arg == NULL || strcmp(arg, "always") == 0) {
-                test_no_exec_ = 0;
+                acutest_no_exec_ = 0;
             } else if(strcmp(arg, "never") == 0) {
-                test_no_exec_ = 1;
+                acutest_no_exec_ = 1;
             } else if(strcmp(arg, "auto") == 0) {
                 /*noop*/
             } else {
-                fprintf(stderr, "%s: Unrecognized argument '%s' for option --exec.\n", test_argv0_, arg);
-                fprintf(stderr, "Try '%s --help' for more information.\n", test_argv0_);
-                test_exit_(2);
+                fprintf(stderr, "%s: Unrecognized argument '%s' for option --exec.\n", acutest_argv0_, arg);
+                fprintf(stderr, "Try '%s --help' for more information.\n", acutest_argv0_);
+                acutest_exit_(2);
             }
             break;
 
         case 'E':
-            test_no_exec_ = 1;
+            acutest_no_exec_ = 1;
             break;
 
         case 't':
 #if defined ACUTEST_WIN_  ||  defined ACUTEST_HAS_POSIX_TIMER_
             if(arg == NULL || strcmp(arg, "real") == 0) {
-                test_timer_ = 1;
+                acutest_timer_ = 1;
     #ifndef ACUTEST_WIN_
             } else if(strcmp(arg, "cpu") == 0) {
-                test_timer_ = 2;
+                acutest_timer_ = 2;
     #endif
             } else {
-                fprintf(stderr, "%s: Unrecognized argument '%s' for option --time.\n", test_argv0_, arg);
-                fprintf(stderr, "Try '%s --help' for more information.\n", test_argv0_);
-                test_exit_(2);
+                fprintf(stderr, "%s: Unrecognized argument '%s' for option --time.\n", acutest_argv0_, arg);
+                fprintf(stderr, "Try '%s --help' for more information.\n", acutest_argv0_);
+                acutest_exit_(2);
             }
 #endif
             break;
 
         case 'S':
-            test_no_summary_ = 1;
+            acutest_no_summary_ = 1;
             break;
 
         case 'T':
-            test_tap_ = 1;
+            acutest_tap_ = 1;
             break;
 
         case 'l':
-            test_list_names_();
-            test_exit_(0);
+            acutest_list_names_();
+            acutest_exit_(0);
             break;
 
         case 'v':
-            test_verbose_level_ = (arg != NULL ? atoi(arg) : test_verbose_level_+1);
+            acutest_verbose_level_ = (arg != NULL ? atoi(arg) : acutest_verbose_level_+1);
             break;
 
+#if defined ACUTEST_WIN_
+        case 'p':
+            hChildWrite = (HANDLE)(ULONG_PTR)_atoi64(arg);
+            break;
+#endif
         case 'q':
-            test_verbose_level_ = 0;
+            acutest_verbose_level_ = 0;
             break;
 
         case 'c':
             if(arg == NULL || strcmp(arg, "always") == 0) {
-                test_colorize_ = 1;
+                acutest_colorize_ = 1;
             } else if(strcmp(arg, "never") == 0) {
-                test_colorize_ = 0;
+                acutest_colorize_ = 0;
             } else if(strcmp(arg, "auto") == 0) {
                 /*noop*/
             } else {
-                fprintf(stderr, "%s: Unrecognized argument '%s' for option --color.\n", test_argv0_, arg);
-                fprintf(stderr, "Try '%s --help' for more information.\n", test_argv0_);
-                test_exit_(2);
+                fprintf(stderr, "%s: Unrecognized argument '%s' for option --color.\n", acutest_argv0_, arg);
+                fprintf(stderr, "Try '%s --help' for more information.\n", acutest_argv0_);
+                acutest_exit_(2);
             }
             break;
 
         case 'C':
-            test_colorize_ = 0;
+            acutest_colorize_ = 0;
             break;
 
         case 'h':
-            test_help_();
-            test_exit_(0);
+            acutest_help_();
+            acutest_exit_(0);
             break;
 
         case 'w':
-            test_worker_ = 1;
-            test_worker_index_ = atoi(arg);
+            acutest_worker_ = 1;
+            acutest_worker_index_ = atoi(arg);
             break;
         case 'x':
-            test_xml_output_ = fopen(arg, "w");
-            if (!test_xml_output_) {
+            acutest_xml_output_ = fopen(arg, "w");
+            if (!acutest_xml_output_) {
                 fprintf(stderr, "Unable to open '%s': %s\n", arg, strerror(errno));
-                test_exit_(2);
+                acutest_exit_(2);
             }
             break;
 
         case 0:
-            if(test_lookup_(arg) == 0) {
-                fprintf(stderr, "%s: Unrecognized unit test '%s'\n", test_argv0_, arg);
-                fprintf(stderr, "Try '%s --list' for list of unit tests.\n", test_argv0_);
-                test_exit_(2);
+            if(acutest_lookup_(arg) == 0) {
+                fprintf(stderr, "%s: Unrecognized unit test '%s'\n", acutest_argv0_, arg);
+                fprintf(stderr, "Try '%s --list' for list of unit tests.\n", acutest_argv0_);
+                acutest_exit_(2);
             }
             break;
 
-        case TEST_CMDLINE_OPTID_UNKNOWN_:
+        case ACUTEST_CMDLINE_OPTID_UNKNOWN_:
             fprintf(stderr, "Unrecognized command line option '%s'.\n", arg);
-            fprintf(stderr, "Try '%s --help' for more information.\n", test_argv0_);
-            test_exit_(2);
+            fprintf(stderr, "Try '%s --help' for more information.\n", acutest_argv0_);
+            acutest_exit_(2);
             break;
 
-        case TEST_CMDLINE_OPTID_MISSINGARG_:
+        case ACUTEST_CMDLINE_OPTID_MISSINGARG_:
             fprintf(stderr, "The command line option '%s' requires an argument.\n", arg);
-            fprintf(stderr, "Try '%s --help' for more information.\n", test_argv0_);
-            test_exit_(2);
+            fprintf(stderr, "Try '%s --help' for more information.\n", acutest_argv0_);
+            acutest_exit_(2);
             break;
 
-        case TEST_CMDLINE_OPTID_BOGUSARG_:
+        case ACUTEST_CMDLINE_OPTID_BOGUSARG_:
             fprintf(stderr, "The command line option '%s' does not expect an argument.\n", arg);
-            fprintf(stderr, "Try '%s --help' for more information.\n", test_argv0_);
-            test_exit_(2);
+            fprintf(stderr, "Try '%s --help' for more information.\n", acutest_argv0_);
+            acutest_exit_(2);
             break;
     }
 
@@ -1582,7 +1777,7 @@ test_cmdline_callback_(int id, const char* arg)
 
 #ifdef ACUTEST_LINUX_
 static int
-test_is_tracer_present_(void)
+acutest_is_tracer_present_(void)
 {
     /* Must be large enough so the line 'TracerPid: ${PID}' can fit in. */
     static const int OVERLAP = 32;
@@ -1634,122 +1829,123 @@ int
 main(int argc, char** argv)
 {
     int i;
-    test_argv0_ = argv[0];
+
+    acutest_argv0_ = argv[0];
 
 #if defined ACUTEST_UNIX_
-    test_colorize_ = isatty(STDOUT_FILENO);
+    acutest_colorize_ = isatty(STDOUT_FILENO);
 #elif defined ACUTEST_WIN_
  #if defined _BORLANDC_
-    test_colorize_ = isatty(_fileno(stdout));
+    acutest_colorize_ = isatty(_fileno(stdout));
  #else
-    test_colorize_ = _isatty(_fileno(stdout));
+    acutest_colorize_ = _isatty(_fileno(stdout));
  #endif
 #else
-    test_colorize_ = 0;
+    acutest_colorize_ = 0;
 #endif
 
     /* Count all test units */
-    test_list_size_ = 0;
-    for(i = 0; test_list_[i].func != NULL; i++)
-        test_list_size_++;
+    acutest_list_size_ = 0;
+    for(i = 0; acutest_list_[i].func != NULL; i++)
+        acutest_list_size_++;
 
-    test_details_ = (struct test_detail_*)calloc(test_list_size_, sizeof(struct test_detail_));
-    if(test_details_ == NULL) {
+    acutest_test_data_ = (struct acutest_test_data_*)calloc(acutest_list_size_, sizeof(struct acutest_test_data_));
+    if(acutest_test_data_ == NULL) {
         fprintf(stderr, "Out of memory.\n");
-        test_exit_(2);
+        acutest_exit_(2);
     }
 
     /* Parse options */
-    test_cmdline_read_(test_cmdline_options_, argc, argv, test_cmdline_callback_);
+    acutest_cmdline_read_(acutest_cmdline_options_, argc, argv, acutest_cmdline_callback_);
 
     /* Initialize the proper timer. */
-    test_timer_init_();
+    acutest_timer_init_();
 
 #if defined(ACUTEST_WIN_)
-    SetUnhandledExceptionFilter(test_seh_exception_filter_);
+    SetUnhandledExceptionFilter(acutest_seh_exception_filter_);
 #ifdef _MSC_VER
     _set_abort_behavior(0, _WRITE_ABORT_MSG);
 #endif
 #endif
 
     /* By default, we want to run all tests. */
-    if(test_count_ == 0) {
-        for(i = 0; test_list_[i].func != NULL; i++)
-            test_remember_(i);
+    if(acutest_count_ == 0) {
+        for(i = 0; acutest_list_[i].func != NULL; i++)
+            acutest_remember_(i);
     }
 
     /* Guess whether we want to run unit tests as child processes. */
-    if(test_no_exec_ < 0) {
-        test_no_exec_ = 0;
+    if(acutest_no_exec_ < 0) {
+        acutest_no_exec_ = 0;
 
-        if(test_count_ <= 1) {
-            test_no_exec_ = 1;
+        if(acutest_count_ <= 1) {
+            acutest_no_exec_ = 1;
         } else {
 #ifdef ACUTEST_WIN_
             if(IsDebuggerPresent())
-                test_no_exec_ = 1;
+                acutest_no_exec_ = 1;
 #endif
 #ifdef ACUTEST_LINUX_
-            if(test_is_tracer_present_())
-                test_no_exec_ = 1;
+            if(acutest_is_tracer_present_())
+                acutest_no_exec_ = 1;
 #endif
 #ifdef RUNNING_ON_VALGRIND
-            /* RUNNING_ON_VALGRIND is provided by valgrind.h */
+            /* RUNNING_ON_VALGRIND is provided by optionally included <valgrind.h> */
             if(RUNNING_ON_VALGRIND)
-                test_no_exec_ = 1;
+                acutest_no_exec_ = 1;
 #endif
         }
     }
 
-    if(test_tap_) {
+    if(acutest_tap_) {
         /* TAP requires we know test result ("ok", "not ok") before we output
          * anything about the test, and this gets problematic for larger verbose
          * levels. */
-        if(test_verbose_level_ > 2)
-            test_verbose_level_ = 2;
+        if(acutest_verbose_level_ > 2)
+            acutest_verbose_level_ = 2;
 
         /* TAP harness should provide some summary. */
-        test_no_summary_ = 1;
+        acutest_no_summary_ = 1;
 
-        if(!test_worker_)
-            printf("1..%d\n", (int) test_count_);
+        if(!acutest_worker_)
+            printf("1..%d\n", (int) acutest_count_);
     }
 
-    int index = test_worker_index_;
-    for(i = 0; test_list_[i].func != NULL; i++) {
-        int run = (test_details_[i].flags & TEST_FLAG_RUN_);
-        if (test_skip_mode_) /* Run all tests except those listed. */
+    int index = acutest_worker_index_;
+    for(i = 0; acutest_list_[i].func != NULL; i++) {
+        int run = (acutest_test_data_[i].flags & ACUTEST_FLAG_RUN_);
+        if (acutest_skip_mode_) /* Run all tests except those listed. */
             run = !run;
         if(run)
-            test_run_(&test_list_[i], index++, i);
+            acutest_run_(&acutest_list_[i], index++, i);
     }
 
     /* Write a summary */
-    if(!test_no_summary_ && test_verbose_level_ >= 1) {
-        if(test_verbose_level_ >= 3) {
-            test_print_in_color_(TEST_COLOR_DEFAULT_INTENSIVE_, "Summary:\n");
-
-            printf("  Count of all unit tests:     %4d\n", (int) test_list_size_);
-            printf("  Count of run unit tests:     %4d\n", test_stat_run_units_);
-            printf("  Count of failed unit tests:  %4d\n", test_stat_failed_units_);
-            printf("  Count of skipped unit tests: %4d\n", (int) test_list_size_ - test_stat_run_units_);
+    if(!acutest_no_summary_ && acutest_verbose_level_ >= 1) {
+        if(acutest_verbose_level_ >= 3) {
+            acutest_colored_printf_(ACUTEST_COLOR_DEFAULT_INTENSIVE_, "Summary:\n");
+
+            printf("  Count of all unit tests:     %4d\n", (int) acutest_list_size_);
+            printf("  Count of run unit tests:     %4d\n", acutest_stat_run_units_);
+            printf("  Count of failed unit tests:  %4d\n", acutest_stat_failed_units_);
+            printf("  Count of skipped unit tests: %4d\n", (int) acutest_list_size_ - acutest_stat_run_units_);
         }
 
-        if(test_stat_failed_units_ == 0) {
-            test_print_in_color_(TEST_COLOR_GREEN_INTENSIVE_, "SUCCESS:");
+        if(acutest_stat_failed_units_ == 0) {
+            acutest_colored_printf_(ACUTEST_COLOR_GREEN_INTENSIVE_, "SUCCESS:");
             printf(" All unit tests have passed.\n");
         } else {
-            test_print_in_color_(TEST_COLOR_RED_INTENSIVE_, "FAILED:");
+            acutest_colored_printf_(ACUTEST_COLOR_RED_INTENSIVE_, "FAILED:");
             printf(" %d of %d unit tests %s failed.\n",
-                    test_stat_failed_units_, test_stat_run_units_,
-                    (test_stat_failed_units_ == 1) ? "has" : "have");
+                    acutest_stat_failed_units_, acutest_stat_run_units_,
+                    (acutest_stat_failed_units_ == 1) ? "has" : "have");
         }
 
-        if(test_verbose_level_ >= 3)
+        if(acutest_verbose_level_ >= 3)
             printf("\n");
     }
 
-    if (test_xml_output_) {
+    if (acutest_xml_output_) {
 #if defined ACUTEST_UNIX_
         char *suite_name = basename(argv[0]);
 #elif defined ACUTEST_WIN_
@@ -1758,26 +1954,32 @@ main(int argc, char** argv)
 #else
         const char *suite_name = argv[0];
 #endif
-        fprintf(test_xml_output_, "<?xml version=\"1.0\" encoding=\"UTF-8\"?>\n");
-        fprintf(test_xml_output_, "<testsuite name=\"%s\" tests=\"%d\" errors=\"%d\" failures=\"%d\" skip=\"%d\">\n",
-            suite_name, (int)test_list_size_, test_stat_failed_units_, test_stat_failed_units_,
-            (int)test_list_size_ - test_stat_run_units_);
-        for(i = 0; test_list_[i].func != NULL; i++) {
-            struct test_detail_ *details = &test_details_[i];
-            fprintf(test_xml_output_, "  <testcase name=\"%s\" time=\"%.2f\">\n", test_list_[i].name, details->duration);
-            if (details->flags & TEST_FLAG_FAILURE_)
-                fprintf(test_xml_output_, "    <failure />\n");
-            if (!(details->flags & TEST_FLAG_FAILURE_) && !(details->flags & TEST_FLAG_SUCCESS_))
-                fprintf(test_xml_output_, "    <skipped />\n");
-            fprintf(test_xml_output_, "  </testcase>\n");
+        acutest_data_log_* log_entry;
+        fprintf(acutest_xml_output_, "<?xml version=\"1.0\" encoding=\"UTF-8\"?>\n");
+        fprintf(acutest_xml_output_, "<testsuite name=\"%s\" tests=\"%d\" errors=\"%d\" failures=\"%d\" skip=\"%d\">\n",
+            suite_name, (int)acutest_list_size_, acutest_stat_failed_units_, acutest_stat_failed_units_,
+            (int)acutest_list_size_ - acutest_stat_run_units_);
+        for(i = 0; acutest_list_[i].func != NULL; i++) {
+            struct acutest_test_data_ *details = &acutest_test_data_[i];
+            fprintf(acutest_xml_output_, "  <testcase name=\"%s\" time=\"%.2f\">\n", acutest_list_[i].name, details->duration);
+            if (details->flags & ACUTEST_FLAG_FAILURE_)
+                fprintf(acutest_xml_output_, "    <failure />\n");
+            if (!(details->flags & ACUTEST_FLAG_FAILURE_) && !(details->flags & ACUTEST_FLAG_SUCCESS_))
+                fprintf(acutest_xml_output_, "    <skipped />\n");
+            log_entry = details->log_head;
+            while (log_entry) {
+                fprintf(acutest_xml_output_, "    <system-out>%s</system-out>\n", log_entry->msg);
+                log_entry = log_entry->next;
+            }
+            fprintf(acutest_xml_output_, "  </testcase>\n");
         }
-        fprintf(test_xml_output_, "</testsuite>\n");
-        fclose(test_xml_output_);
+        fprintf(acutest_xml_output_, "</testsuite>\n");
+        fclose(acutest_xml_output_);
     }
 
-    test_cleanup_();
+    acutest_cleanup_();
 
-    return (test_stat_failed_units_ == 0) ? 0 : 1;
+    return (acutest_stat_failed_units_ == 0) ? 0 : 1;
 }
 
 
index 9873efe4ce5b07f0790b27a2ebf57cfc76f0b38b..a80f8c0d0e70fd49b08b8bfc983f530c2cf7ab13 100644 (file)
@@ -5,6 +5,7 @@ SUBMAKEFILES := \
        heap_tests.mk \
        libfreeradius-util.mk \
        pair_legacy_tests.mk \
+       pair_list_perf_test.mk \
        pair_tests.mk \
        rb_tests.mk \
        sbuff_tests.mk \
diff --git a/src/lib/util/pair_list_perf_test.c b/src/lib/util/pair_list_perf_test.c
new file mode 100644 (file)
index 0000000..fb6d8ce
--- /dev/null
@@ -0,0 +1,285 @@
+/*
+ *   This program is free software; you can redistribute it and/or modify
+ *   it under the terms of the GNU General Public License as published by
+ *   the Free Software Foundation; either version 2 of the License, or
+ *   (at your option) any later version.
+ *
+ *   This program is distributed in the hope that it will be useful,
+ *   but WITHOUT ANY WARRANTY; without even the implied warranty of
+ *   MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+ *   GNU General Public License for more details.
+ *
+ *   You should have received a copy of the GNU General Public License
+ *   along with this program; if not, write to the Free Software
+ *   Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301, USA
+ */
+
+/** Performance tests for lists of fr_pair_t
+ *
+ * @file src/bin/pair_list_perf_test.c
+ * @author Nick Porter <nick.porter@networkradius.com>
+ *
+ * @copyright 2021 Network RADIUS SARL <legal@networkradius.com>
+ */
+
+/**
+ *     The 'TEST_INIT' macro provided by 'acutest.h' allows registering a function to be called
+ *     before call the unit tests. Therefore, It calls the function ALL THE TIME causing an overhead.
+ *     That is why we are initializing pair_list_perf_init() by "__attribute__((constructor));" reducing the
+ *     test execution by 50% of the time.
+ */
+#define USE_CONSTRUCTOR
+
+/*
+ * It should be declared before including "acutest.h"
+ */
+#ifdef USE_CONSTRUCTOR
+static void fr_pair_list_perf_init(void) __attribute__((constructor));
+#else
+static void fr_pair_list_perf_init(void);
+#define TEST_INIT fr_pair_list_perf_init()
+#endif
+
+#include <freeradius-devel/util/acutest.h>
+
+#ifdef WITH_VERIFY_PTR
+#undef WITH_VERIFY_PTR
+#endif
+
+#include "pair.c"
+#include <freeradius-devel/server/base.h>
+
+#define EXIT_WITH_FAILURE \
+do { \
+       ret = EXIT_FAILURE; \
+       goto cleanup; \
+} while (0)
+
+
+typedef struct {
+        int attr;
+        fr_dict_attr_t const **parent;
+        fr_dict_attr_t const **da;
+        char const *name;
+        fr_type_t type;
+        void *values;
+} fr_dict_adhoc_attr_t;
+
+/*
+ *      Global variables
+ */
+
+static fr_dict_t        *dict;
+static char const       *dict_dir  = "share/dictionary";
+static TALLOC_CTX       *autofree;
+static int              input_count = 0;
+static char const       *test_attrs = "Tmp-String-0 = \"goodbye\",Tmp-String-1 = \"wibble\",Tmp-Integer-0 = 542,Tmp-Integer-1 = 456,Tmp-IP-Address-0 = 192.168.1.1,Tmp-IP-Address-1 = 10.0.0.1,Tmp-Ethernet-0 = 11:22:33:44:55:66,Tmp-Ethernet-1 = ff:ee:dd:cc:bb:aa,Tmp-Date-0 = 959985459,Tmp-Date-1 = \"Jan  1 2020 00:00:00 UTC\",Tmp-Integer64-0 = 156453412,Tmp-Integer64-1 = 46456155,Tmp-Signed-0 = -4573,Tmp-Signed-1 = 45645,Tmp-Float-0 = 45.48,Tmp-Float-0 = 58.64,IP-Pool.Name = \"main\",IP-Pool.Action = Allocate";
+static fr_pair_t        **source_vps;
+
+void fr_pair_list_perf_init(void)
+{
+        fr_pair_list_t  input_vps;
+        fr_pair_t       *vp, *next;
+        int             i;
+
+        fr_pair_list_init(&input_vps);
+        autofree = talloc_autofree_context();
+
+       TEST_ASSERT(fr_dict_global_ctx_init(autofree, dict_dir) != NULL);
+
+       TEST_ASSERT(fr_dict_internal_afrom_file(&dict, FR_DICTIONARY_INTERNAL_DIR, __FILE__) == 0);
+
+        TEST_ASSERT(fr_pair_list_afrom_str(autofree, dict, test_attrs, strlen(test_attrs), &input_vps) != T_INVALID);
+
+        fr_time_start();
+
+        input_count = fr_pair_list_len(&input_vps);
+        fr_pair_list_debug(&input_vps);
+
+        /*
+         *  Move vps to array so we can pick them randomly to populate the test list.
+         */
+        source_vps = talloc_zero_array(autofree, fr_pair_t *, input_count);
+        for (vp = fr_pair_list_head(&input_vps), i = 0; vp; vp = next, i++) {
+                next = fr_pair_list_next(&input_vps, vp);
+                fr_pair_remove(&input_vps, vp);
+                source_vps[i] = vp;
+        }
+}
+
+
+static void do_test_fr_pair_append(uint len, uint reps)
+{
+        fr_pair_list_t  test_vps;
+        uint             i, j;
+        fr_pair_t       *new_vp;
+        fr_time_t       start, end, used = 0;
+
+        fr_pair_list_init(&test_vps);
+
+        /*
+         *  Insert pairs into the test list, choosing randomly from the source list
+         */
+        for (i = 0; i < reps; i++) {
+                for (j = 0; j < len; j++) {
+                        int index = rand() % input_count;
+                        new_vp = fr_pair_copy(autofree, source_vps[index]);
+                        start = fr_time();
+                        fr_pair_append(&test_vps, new_vp);
+                        end = fr_time();
+                        used += (end - start);
+                }
+                TEST_CHECK(fr_pair_list_len(&test_vps) == len);
+                fr_pair_list_free(&test_vps);
+        }
+        TEST_MSG_ALWAYS("repetitions=%d", reps);
+        TEST_MSG_ALWAYS("list_length=%d", len);
+        TEST_MSG_ALWAYS("used=%"PRId64, used);
+        TEST_MSG_ALWAYS("per_sec=%0.0lf", (reps * len)/((double)used / NSEC));
+}
+
+#define test_func(_func, _count) static void test_ ## _func ## _ ## _count(void)\
+{\
+        do_test_ ## _func(_count, 10000);\
+}
+
+#define test_funcs(_func) test_func(_func, 20)\
+test_func(_func, 40)\
+test_func(_func, 60)\
+test_func(_func, 80)\
+test_func(_func, 100)
+
+test_funcs(fr_pair_append)
+
+static void do_test_fr_pair_find_by_da(uint len, uint reps)
+{
+        fr_pair_list_t          test_vps;
+        uint                    i, j;
+        fr_pair_t               *new_vp;
+        fr_time_t               start, end, used = 0;
+        const fr_dict_attr_t    *da;
+
+        fr_pair_list_init(&test_vps);
+
+        /*
+         *  Initialise the test list
+         */
+        for (i = 0; i < len; i++) {
+                int index = rand() % input_count;
+                new_vp = fr_pair_copy(autofree, source_vps[index]);
+                fr_pair_append(&test_vps, new_vp);
+        }
+
+        /*
+         * Find first instance of specific DA
+         */
+        for (i = 0; i < reps; i++) {
+                for (j = 0; j < len; j++) {
+                        int index = rand() % input_count;
+                        da = source_vps[index]->da;
+                        start = fr_time();
+                        (void) fr_pair_find_by_da(&test_vps, da);
+                        end = fr_time();
+                        used += (end - start);
+                }
+
+        }
+        fr_pair_list_free(&test_vps);
+        TEST_MSG_ALWAYS("repetitions=%d", reps);
+        TEST_MSG_ALWAYS("list_length=%d", len);
+        TEST_MSG_ALWAYS("used=%"PRId64, used);
+        TEST_MSG_ALWAYS("per_sec=%0.0lf", (reps * len)/((double)used / NSEC));
+}
+
+test_funcs(fr_pair_find_by_da)
+
+static void do_test_find_nth(uint len, uint reps)
+{
+        fr_pair_list_t          test_vps;
+        uint                     i, j, k, nth_item;
+        fr_pair_t               *new_vp;
+        fr_time_t               start, end, used = 0;
+        const fr_dict_attr_t    *da;
+
+        fr_pair_list_init(&test_vps);
+
+        /*
+         *  Initialise the test list
+         */
+        for (i = 0; i < len; i++) {
+                int index = rand() % input_count;
+                new_vp = fr_pair_copy(autofree, source_vps[index]);
+                fr_pair_append(&test_vps, new_vp);
+        }
+
+        /*
+         * Find nth instance of specific DA
+         */
+        nth_item = (uint)(len / input_count);
+        for (i = 0; i < reps; i++) {
+                for (j = 0; j < len; j++) {
+                        int index = rand() % input_count;
+                        da = source_vps[index]->da;
+                        start = fr_time();
+                        k = 0;
+                        for (new_vp = fr_pair_list_head(&test_vps); new_vp; new_vp = fr_pair_list_next(&test_vps, new_vp)) {
+                                if (new_vp->da == da) {
+                                        k++;
+                                        if (k == nth_item) break;
+                                }
+                        }
+                        end = fr_time();
+                        used += (end - start);
+                }
+        }
+        fr_pair_list_free(&test_vps);
+        TEST_MSG_ALWAYS("repetitions=%d", reps);
+        TEST_MSG_ALWAYS("list_length=%d", len);
+        TEST_MSG_ALWAYS("used=%"PRId64, used);
+        TEST_MSG_ALWAYS("per_sec=%0.0lf", (reps * len)/((double)used / NSEC));
+}
+
+test_funcs(find_nth)
+
+static void do_test_fr_pair_list_free(uint len, uint reps)
+{
+        fr_pair_list_t  test_vps;
+        uint             i, j;
+        fr_pair_t       *new_vp;
+        fr_time_t       start, end, used = 0;
+
+        fr_pair_list_init(&test_vps);
+
+        for (i = 0; i < reps; i++) {
+                for (j = 0; j < len; j++) {
+                        int index = rand() % input_count;
+                        new_vp = fr_pair_copy(autofree, source_vps[index]);
+                        fr_pair_append(&test_vps, new_vp);
+                }
+                start = fr_time();
+                fr_pair_list_free(&test_vps);
+                end = fr_time();
+                used += (end - start);
+        }
+        TEST_MSG_ALWAYS("repetitions=%d", reps);
+        TEST_MSG_ALWAYS("list_length=%d", len);
+        TEST_MSG_ALWAYS("used=%"PRId64, used);
+        TEST_MSG_ALWAYS("per_sec=%0.0lf", (reps * len)/((double)used / NSEC));
+}
+
+test_funcs(fr_pair_list_free)
+
+#define tests(_func) { #_func "_20", test_ ## _func ## _20},\
+        { #_func "_40", test_ ## _func ## _40},\
+        { #_func "_60", test_ ## _func ## _60},\
+        { #_func "_80", test_ ## _func ## _80},\
+        { #_func "_100", test_ ## _func ## _100},\
+
+TEST_LIST = {
+        tests(fr_pair_append)
+        tests(fr_pair_find_by_da)
+        tests(find_nth)
+        tests(fr_pair_list_free)
+
+        { NULL }
+};
\ No newline at end of file
diff --git a/src/lib/util/pair_list_perf_test.mk b/src/lib/util/pair_list_perf_test.mk
new file mode 100644 (file)
index 0000000..29c0476
--- /dev/null
@@ -0,0 +1,6 @@
+TARGET := pair_list_perf_test
+SOURCES := pair_list_perf_test.c
+
+TGT_INSTALLDIR :=
+TGT_LDLIBS     := $(LIBS)
+TGT_PREREQS    := $(LIBFREERADIUS_SERVER) libfreeradius-util.a