[Issue #1] Added test timers

Makefile.am

@@ -45,4 +45,5 @@ libcriterion_la_SOURCES = \
 	src/stats.h \
 	src/logging.c \
 	src/options.c \
+	src/timer.c \
 	src/main.c

include/criterion/stats.h

@@ -46,6 +46,7 @@ struct criterion_test_stats {
     int passed_asserts;
     int failed_asserts;
     int signal;
+    float elapsed_time;
     unsigned progress;
     const char *file;
 

src/event.c

@@ -40,15 +40,25 @@ struct event *read_event(int fd) {
     if (read(fd, &kind, sizeof (unsigned)) < (ssize_t) sizeof (unsigned))
         return NULL;
 
-    if (kind != ASSERT)
-        return unique_ptr(struct event, ({ .kind = kind, .data = NULL }));
+    switch (kind) {
+        case ASSERT: {
+            const size_t assert_size = sizeof (struct criterion_assert_stats);
+            unsigned char *buf = malloc(assert_size);
+            if (read(fd, buf, assert_size) < (ssize_t) assert_size)
+                return NULL;
 
-    const size_t assert_size = sizeof (struct criterion_assert_stats);
-    unsigned char *buf = malloc(assert_size);
-    if (read(fd, buf, assert_size) < (ssize_t) assert_size)
-        return NULL;
+            return unique_ptr(struct event, ({ .kind = kind, .data = buf }), destroy_event);
+        }
+        case POST_TEST: {
+            double *elapsed_time = malloc(sizeof (double));
+            if (read(fd, elapsed_time, sizeof (double)) < (ssize_t) sizeof (double))
+                return NULL;
 
-    return unique_ptr(struct event, ({ .kind = kind, .data = buf }), destroy_event);
+            return unique_ptr(struct event, ({ .kind = kind, .data = elapsed_time }), destroy_event);
+        }
+        default:
+            return unique_ptr(struct event, ({ .kind = kind, .data = NULL }));
+    }
 }
 
 void send_event(int kind, void *data, size_t size) {

src/report.c

@@ -27,6 +27,7 @@
 #include "criterion/logging.h"
 #include "criterion/options.h"
 #include "report.h"
+#include "timer.h"
 
 #define IMPL_CALL_REPORT_HOOKS(Kind)                        \
     IMPL_SECTION_LIMITS(f_report_hook, crit_ ## Kind);       \
@@ -57,11 +58,14 @@ ReportHook(PRE_INIT)(struct criterion_test *test) {
 
 ReportHook(POST_TEST)(struct criterion_test_stats *stats) {
     if (criterion_options.enable_tap_format) {
-        criterion_important("%s " SIZE_T_FORMAT " - %s::%s\n",
+        const char *format = can_measure_time() ? "%s " SIZE_T_FORMAT " - %s::%s (%3.2fs)\n"
+                                                : "%s " SIZE_T_FORMAT " - %s::%s\n";
+        criterion_important(format,
                 stats->failed ? "not ok" : "ok",
                 tap_test_index++,
                 stats->test->category,
-                stats->test->name);
+                stats->test->name,
+                stats->elapsed_time);
         for (struct criterion_assert_stats *asrt = stats->asserts; asrt; asrt = asrt->next) {
             if (!asrt->passed) {
                 char *dup = strdup(*asrt->message ? asrt->message : asrt->condition), *saveptr = NULL;
@@ -76,11 +80,13 @@ ReportHook(POST_TEST)(struct criterion_test_stats *stats) {
             }
         }
     } else {
+        const char *format = can_measure_time() ? "%s::%s: %s (%3.2fs)\n" : "%s::%s: %s\n";
         criterion_log(stats->failed ? CRITERION_IMPORTANT : CRITERION_INFO,
-                "%s::%s: %s\n",
+                format,
                 stats->test->category,
                 stats->test->name,
-                stats->failed ? "FAILURE" : "SUCCESS");
+                stats->failed ? "FAILURE" : "SUCCESS",
+                stats->elapsed_time);
     }
 }
 

src/runner.c

@@ -31,6 +31,7 @@
 #include "report.h"
 #include "event.h"
 #include "process.h"
+#include "timer.h"
 
 IMPL_SECTION_LIMITS(struct criterion_test, criterion_tests);
 
@@ -87,8 +88,15 @@ static void run_test_child(struct criterion_test *test) {
     send_event(PRE_INIT, NULL, 0);
     (test->data->init ?: nothing)();
     send_event(PRE_TEST, NULL, 0);
+
+    struct timespec_compat ts;
+    timer_start(&ts);
     (test->test       ?: nothing)();
-    send_event(POST_TEST, NULL, 0);
+    double elapsed_time;
+    if (!timer_end(&elapsed_time, &ts))
+        elapsed_time = -1;
+
+    send_event(POST_TEST, &elapsed_time, sizeof (double));
     (test->data->fini ?: nothing)();
     send_event(POST_FINI, NULL, 0);
 }
@@ -124,11 +132,12 @@ static void run_test(struct criterion_global_stats *stats, struct criterion_test
             stat_push_event(stats, test_stats, &ev);
             report(TEST_CRASH, test_stats);
         } else {
-            struct event ev = { .kind = POST_TEST };
+            double elapsed_time = 0;
+            struct event ev = { .kind = POST_TEST, .data = &elapsed_time };
             stat_push_event(stats, test_stats, &ev);
             report(POST_TEST, test_stats);
 
-            ev.kind = POST_FINI;
+            ev = (struct event) { .kind = POST_FINI, .data = NULL };
             stat_push_event(stats, test_stats, &ev);
             report(POST_FINI, test_stats);
         }

src/stats.c

@@ -114,7 +114,8 @@ static void push_assert(s_glob_stats *stats,
 
 static void push_post_test(s_glob_stats *stats,
                            s_test_stats *test,
-                           UNUSED void *ptr) {
+                           double *ptr) {
+    test->elapsed_time = *ptr;
     if (test->failed_asserts > 0 || test->signal != test->test->data->signal) {
         test->failed = 1;
         ++stats->tests_failed;

src/timer.c

@@ -0,0 +1,83 @@
+#include <errno.h>
+#include <inttypes.h>
+#include "timer.h"
+
+#define GIGA 1000000000
+
+#if defined(__unix__) && !defined(__CYGWIN__)
+
+# ifdef CLOCK_MONOTONIC_RAW
+#  define CLOCK CLOCK_MONOTONIC_RAW
+# else
+#  define CLOCK CLOCK_MONOTONIC
+# endif
+
+extern __attribute__ ((weak)) int clock_gettime(clockid_t, struct timespec *);
+
+#elif defined(__APPLE__)
+# include <mach/clock.h>
+# include <mach/mach.h>
+#elif defined(_WIN32) || defined(__CYGWIN__)
+# define VC_EXTRALEAN
+# define WIN32_LEAN_AND_MEAN
+# include <Windows.h>
+#endif
+
+bool can_measure_time(void) {
+#if defined(__unix__) && !defined(__CYGWIN__)
+    return clock_gettime != NULL;
+#else
+    return true;
+#endif
+}
+
+int gettime_compat(struct timespec_compat *ts) {
+#if defined(__APPLE__)
+    clock_serv_t cclock;
+    mach_timespec_t mts;
+
+    host_get_clock_service(mach_host_self(), SYSTEM_CLOCK, &cclock);
+    int res = clock_get_time(cclock, &mts);
+    mach_port_deallocate(mach_task_self(), cclock);
+
+    *ts = (struct timespec_compat) { mts.tv_sec, mts.tv_nsec };
+    return res > 0 ? -1 : 0;
+#elif defined(_WIN32) || defined(__CYGWIN__)
+    LARGE_INTEGER freq, count;
+    if (!QueryPerformanceFrequency(&freq)
+        || !QueryPerformanceCounter(&count))
+        return -1;
+
+    int64_t sec  = count.QuadPart / freq.QuadPart;
+    int64_t nano = (int64_t) ((double) count.QuadPart * GIGA / (double) freq.QuadPart) % GIGA;
+
+    *ts = (struct timespec_compat) { sec, nano };
+    return 0;
+#elif defined(__unix__)
+    if (!can_measure_time()) {
+        errno = ENOTSUP;
+        return -1;
+    }
+
+    struct timespec ts_;
+    int res = clock_gettime(CLOCK, &ts_);
+
+    *ts = (struct timespec_compat) { ts_.tv_sec, ts_.tv_nsec };
+    return res;
+#else
+    return -1;
+#endif
+}
+
+int timer_start(struct timespec_compat *state) {
+    return gettime_compat(state) == -1 ? 0 : 1;
+}
+
+int timer_end(double *time, struct timespec_compat *state) {
+    struct timespec_compat last;
+    if (gettime_compat(&last) == -1)
+        return 0;
+
+    *time = (last.tv_sec - state->tv_sec) + (last.tv_nsec - state->tv_nsec) / (double) GIGA;
+    return 1;
+}

src/timer.h

@@ -0,0 +1,17 @@
+#ifndef TIMER_H_
+# define TIMER_H_
+
+# include <time.h>
+# include <inttypes.h>
+# include <stdbool.h>
+
+struct timespec_compat {
+    int64_t tv_sec;
+    int64_t tv_nsec;
+};
+
+bool can_measure_time(void);
+int timer_start(struct timespec_compat *state);
+int timer_end(double *time, struct timespec_compat *state);
+
+#endif /* !TIMER_H_ */