From c28cff39b8ad99d21761f4dc5b7ff99d4ef7642b Mon Sep 17 00:00:00 2001 From: Snaipe Date: Sat, 7 Feb 2015 14:22:08 +0100 Subject: [PATCH 1/4] [Issue #1] Added time measurements --- include/criterion/stats.h | 1 + src/event.c | 24 +++++++++++++++++------- src/runner.c | 11 +++++++++-- src/stats.c | 3 ++- 4 files changed, 29 insertions(+), 10 deletions(-) diff --git a/include/criterion/stats.h b/include/criterion/stats.h index 03600db..2225896 100644 --- a/include/criterion/stats.h +++ b/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; diff --git a/src/event.c b/src/event.c index 19ca42d..d77709a 100644 --- a/src/event.c +++ b/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: { + float *elapsed_time = malloc(sizeof (float)); + if (read(fd, elapsed_time, sizeof (float)) < (ssize_t) sizeof (float)) + 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) { diff --git a/src/runner.c b/src/runner.c index 2fd63f8..2f51512 100644 --- a/src/runner.c +++ b/src/runner.c @@ -24,6 +24,7 @@ #include #include #include +#include #include #include "criterion/options.h" #include "stats.h" @@ -87,8 +88,13 @@ 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); + + clock_t before = clock(); (test->test ?: nothing)(); - send_event(POST_TEST, NULL, 0); + clock_t after = clock(); + + double elapsed_time = (double) (after - before) / CLOCKS_PER_SEC; + send_event(POST_TEST, &elapsed_time, sizeof (double)); (test->data->fini ?: nothing)(); send_event(POST_FINI, NULL, 0); } @@ -124,7 +130,8 @@ 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); diff --git a/src/stats.c b/src/stats.c index e12db58..ba5a2ed 100644 --- a/src/stats.c +++ b/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) { + float *ptr) { + test->elapsed_time = *ptr; if (test->failed_asserts > 0 || test->signal != test->test->data->signal) { test->failed = 1; ++stats->tests_failed; From 4a5c19a08c2fb393d0ccb992ef26f8f6f4784700 Mon Sep 17 00:00:00 2001 From: Snaipe Date: Mon, 16 Mar 2015 23:32:03 +0100 Subject: [PATCH 2/4] Added monotonic cross-platform timer --- Makefile.am | 1 + src/event.c | 4 +-- src/report.c | 14 +++++++--- src/runner.c | 12 ++++---- src/stats.c | 2 +- src/timer.c | 79 ++++++++++++++++++++++++++++++++++++++++++++++++++++ src/timer.h | 17 +++++++++++ 7 files changed, 117 insertions(+), 12 deletions(-) create mode 100644 src/timer.c create mode 100644 src/timer.h diff --git a/Makefile.am b/Makefile.am index f373ec2..9e4c7bd 100644 --- a/Makefile.am +++ b/Makefile.am @@ -45,4 +45,5 @@ libcriterion_la_SOURCES = \ src/stats.h \ src/logging.c \ src/options.c \ + src/timer.c \ src/main.c diff --git a/src/event.c b/src/event.c index d77709a..e5df964 100644 --- a/src/event.c +++ b/src/event.c @@ -50,8 +50,8 @@ struct event *read_event(int fd) { return unique_ptr(struct event, ({ .kind = kind, .data = buf }), destroy_event); } case POST_TEST: { - float *elapsed_time = malloc(sizeof (float)); - if (read(fd, elapsed_time, sizeof (float)) < (ssize_t) sizeof (float)) + 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 = elapsed_time }), destroy_event); diff --git a/src/report.c b/src/report.c index fc07f03..e135732 100644 --- a/src/report.c +++ b/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); } } diff --git a/src/runner.c b/src/runner.c index 2f51512..0572c6c 100644 --- a/src/runner.c +++ b/src/runner.c @@ -24,7 +24,6 @@ #include #include #include -#include #include #include "criterion/options.h" #include "stats.h" @@ -32,6 +31,7 @@ #include "report.h" #include "event.h" #include "process.h" +#include "timer.h" IMPL_SECTION_LIMITS(struct criterion_test, criterion_tests); @@ -89,11 +89,13 @@ static void run_test_child(struct criterion_test *test) { (test->data->init ?: nothing)(); send_event(PRE_TEST, NULL, 0); - clock_t before = clock(); + struct timespec_compat ts; + timer_start(&ts); (test->test ?: nothing)(); - clock_t after = clock(); + double elapsed_time; + if (!timer_end(&elapsed_time, &ts)) + elapsed_time = -1; - double elapsed_time = (double) (after - before) / CLOCKS_PER_SEC; send_event(POST_TEST, &elapsed_time, sizeof (double)); (test->data->fini ?: nothing)(); send_event(POST_FINI, NULL, 0); @@ -135,7 +137,7 @@ static void run_test(struct criterion_global_stats *stats, struct criterion_test 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); } diff --git a/src/stats.c b/src/stats.c index ba5a2ed..4c33793 100644 --- a/src/stats.c +++ b/src/stats.c @@ -114,7 +114,7 @@ static void push_assert(s_glob_stats *stats, static void push_post_test(s_glob_stats *stats, s_test_stats *test, - float *ptr) { + double *ptr) { test->elapsed_time = *ptr; if (test->failed_asserts > 0 || test->signal != test->test->data->signal) { test->failed = 1; diff --git a/src/timer.c b/src/timer.c new file mode 100644 index 0000000..67939ad --- /dev/null +++ b/src/timer.c @@ -0,0 +1,79 @@ +#include +#include "timer.h" + +#define GIGA 1e9 + +#if defined(__unix__) + +# 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 +# include +#elif defined(_WIN32) +# define VC_EXTRALEAN +# define WIN32_LEAN_AND_MEAN +# include +#endif + +bool can_measure_time(void) { +#ifdef __unix__ + 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) + LARGE_INTEGER freq, count; + if (!QueryPerformanceFrequency(&freq) + || !QueryPerformanceCounter(&count)) + return -1; + + *ts = (struct timespec_compat) { count / freq, count * (GIGA - 1) / freq }; + 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) / GIGA; + return 1; +} diff --git a/src/timer.h b/src/timer.h new file mode 100644 index 0000000..2d334cb --- /dev/null +++ b/src/timer.h @@ -0,0 +1,17 @@ +#ifndef TIMER_H_ +# define TIMER_H_ + +# include +# include +# include + +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_ */ From 098eabb7e75d746c7ef87566f6bede341d507926 Mon Sep 17 00:00:00 2001 From: Snaipe Date: Tue, 17 Mar 2015 23:16:30 +0100 Subject: [PATCH 3/4] Fixed test timing on windows --- src/timer.c | 18 +++++++++++------- 1 file changed, 11 insertions(+), 7 deletions(-) diff --git a/src/timer.c b/src/timer.c index 67939ad..8e41f14 100644 --- a/src/timer.c +++ b/src/timer.c @@ -1,9 +1,10 @@ #include +#include #include "timer.h" -#define GIGA 1e9 +#define GIGA 1000000000 -#if defined(__unix__) +#if defined(__unix__) && !defined(__CYGWIN__) # ifdef CLOCK_MONOTONIC_RAW # define CLOCK CLOCK_MONOTONIC_RAW @@ -16,14 +17,14 @@ extern __attribute__ ((weak)) int clock_gettime(clockid_t, struct timespec *); #elif defined(__APPLE__) # include # include -#elif defined(_WIN32) +#elif defined(_WIN32) || defined(__CYGWIN__) # define VC_EXTRALEAN # define WIN32_LEAN_AND_MEAN # include #endif bool can_measure_time(void) { -#ifdef __unix__ +#if defined(__unix__) && !defined(__CYGWIN__) return clock_gettime != NULL; #else return true; @@ -41,13 +42,16 @@ int gettime_compat(struct timespec_compat *ts) { *ts = (struct timespec_compat) { mts->tv_sec, mts->tv_nsec }; return res > 0 ? -1 : 0; -#elif defined(_WIN32) +#elif defined(_WIN32) || defined(__CYGWIN__) LARGE_INTEGER freq, count; if (!QueryPerformanceFrequency(&freq) || !QueryPerformanceCounter(&count)) return -1; - *ts = (struct timespec_compat) { count / freq, count * (GIGA - 1) / freq }; + 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()) { @@ -74,6 +78,6 @@ int timer_end(double *time, struct timespec_compat *state) { if (gettime_compat(&last) == -1) return 0; - *time = (last.tv_sec - state->tv_sec) + (last.tv_nsec - state->tv_nsec) / GIGA; + *time = (last.tv_sec - state->tv_sec) + (last.tv_nsec - state->tv_nsec) / (double) GIGA; return 1; } From 73eae59b056a829670838877960b441d13212777 Mon Sep 17 00:00:00 2001 From: Snaipe Date: Tue, 17 Mar 2015 17:50:01 +0100 Subject: [PATCH 4/4] Fixed compile error on OS X timers --- src/timer.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/timer.c b/src/timer.c index 8e41f14..edb181e 100644 --- a/src/timer.c +++ b/src/timer.c @@ -40,7 +40,7 @@ int gettime_compat(struct timespec_compat *ts) { int res = clock_get_time(cclock, &mts); mach_port_deallocate(mach_task_self(), cclock); - *ts = (struct timespec_compat) { mts->tv_sec, mts->tv_nsec }; + *ts = (struct timespec_compat) { mts.tv_sec, mts.tv_nsec }; return res > 0 ? -1 : 0; #elif defined(_WIN32) || defined(__CYGWIN__) LARGE_INTEGER freq, count;