bench: replace wall-clock timer with per-process CPU timer

Makefile.am

@@ -109,23 +109,26 @@ if USE_BENCHMARK
 noinst_PROGRAMS += bench bench_internal bench_ecmult
 bench_SOURCES = src/bench.c
 bench_LDADD = libsecp256k1.la
-bench_CPPFLAGS = $(SECP_CONFIG_DEFINES)
+bench_CPPFLAGS = $(SECP_CONFIG_DEFINES) $(CLOCK_GETTIME_CPPFLAGS)
+bench_LDFLAGS = $(CLOCK_GETTIME_LIBS)
 bench_internal_SOURCES = src/bench_internal.c
 bench_internal_LDADD = $(COMMON_LIB) $(PRECOMPUTED_LIB)
-bench_internal_CPPFLAGS = $(SECP_CONFIG_DEFINES)
+bench_internal_CPPFLAGS = $(bench_CPPFLAGS)
+bench_internal_LDFLAGS = $(bench_LDFLAGS)
 bench_ecmult_SOURCES = src/bench_ecmult.c
 bench_ecmult_LDADD = $(COMMON_LIB) $(PRECOMPUTED_LIB)
-bench_ecmult_CPPFLAGS = $(SECP_CONFIG_DEFINES)
+bench_ecmult_CPPFLAGS = $(bench_CPPFLAGS)
+bench_ecmult_LDFLAGS = $(bench_LDFLAGS)
 endif
 
 TESTS =
 if USE_TESTS
 TESTS += noverify_tests
 noinst_PROGRAMS += noverify_tests
 noverify_tests_SOURCES = src/tests.c
-noverify_tests_CPPFLAGS = $(SECP_CONFIG_DEFINES) $(TEST_DEFINES)
+noverify_tests_CPPFLAGS = $(SECP_CONFIG_DEFINES) $(TEST_DEFINES) $(CLOCK_GETTIME_CPPFLAGS)
 noverify_tests_LDADD = $(COMMON_LIB) $(PRECOMPUTED_LIB)
-noverify_tests_LDFLAGS = -static
+noverify_tests_LDFLAGS = -static $(CLOCK_GETTIME_LIBS)
 if !ENABLE_COVERAGE
 TESTS += tests
 noinst_PROGRAMS += tests

README.md

@@ -157,6 +157,8 @@ Benchmark
 ------------
 If configured with `--enable-benchmark` (which is the default), binaries for benchmarking the libsecp256k1 functions will be present in the root directory after the build.
 
+For reliable benchmarks, it is strongly recommended to pin the process to a single CPU core and to disable CPU frequency scaling.
+
 To print the benchmark result to the command line:
 
     $ ./bench_name

build-aux/m4/bitcoin_secp.m4

@@ -89,3 +89,40 @@ AC_DEFUN([SECP_SET_DEFAULT], [
     $1="$2"
   fi
 ])
+
+m4_define([SECP_CHECK_CLOCK_GETTIME_testbody], [[
+  #include <time.h>
+
+  int main() {
+    struct timespec ts;
+    return clock_gettime(CLOCK_REALTIME, &ts);
+  }
+]])
+
+AC_DEFUN([SECP_CHECK_CLOCK_GETTIME_NEEDS_RT], [
+  AC_MSG_CHECKING([whether clock_gettime can be used without -lrt])
+  AC_LINK_IFELSE([AC_LANG_SOURCE([SECP_CHECK_CLOCK_GETTIME_testbody])], [
+    AC_MSG_RESULT([yes])
+  ],[
+    AC_MSG_RESULT([no])
+    AC_MSG_CHECKING([whether clock_gettime can be used with -lrt])
+    SECP_CHECK_CLOCK_GETTIME_NEEDS_RT_saved_LIBS="$LIBS"
+    CLOCK_GETTIME_LIBS="-lrt"
+    LIBS="$CLOCK_GETTIME_LIBS"
+    AC_LINK_IFELSE([AC_LANG_SOURCE([SECP_CHECK_CLOCK_GETTIME_testbody])], [
+      AC_MSG_RESULT([yes])
+    ],[
+      AC_MSG_RESULT([no])
+      AC_MSG_ERROR([clock_gettime not available])
+    ])
+    LIBS="$SECP_CHECK_CLOCK_GETTIME_NEEDS_RT_saved_LIBS"
+  ])
+])
+
+AC_DEFUN([SECP_CHECK_CLOCK_GETTIME], [
+  SECP_CHECK_CLOCK_GETTIME_saved_CPPFLAGS="$CPPFLAGS"
+  CLOCK_GETTIME_CPPFLAGS="-D_POSIX_C_SOURCE=199309L"
+  CPPFLAGS="$CLOCK_GETTIME_CPPFLAGS"
+  AC_CHECK_DECLS([clock_gettime], [SECP_CHECK_CLOCK_GETTIME_NEEDS_RT], [], [[#include <time.h>]])
+  CPPFLAGS="$SECP_CHECK_CLOCK_GETTIME_saved_CPPFLAGS"
+])

cmake/FindClockGettime.cmake

@@ -0,0 +1,47 @@
+#[=======================================================================[
+FindClockGettime
+----------------
+
+Finds the clock_gettime() POSIX function on the system.
+
+Imported Targets
+^^^^^^^^^^^^^^^^
+
+This module provides the following Imported Targets:
+
+POSIX::clock_gettime
+  Target encapsulating the clock_gettime() usage requirements, available
+  only if clock_gettime() is found.
+
+#]=======================================================================]
+
+include(CheckSymbolExists)
+include(CMakePushCheckState)
+
+cmake_push_check_state(RESET)
+
+set(CMAKE_REQUIRED_DEFINITIONS -D_POSIX_C_SOURCE=199309L)
+check_symbol_exists(clock_gettime "time.h" CLOCK_GETTIME_IS_BUILT_IN)
+set(${CMAKE_FIND_PACKAGE_NAME}_FOUND ${CLOCK_GETTIME_IS_BUILT_IN})
+
+if(NOT ${CMAKE_FIND_PACKAGE_NAME}_FOUND)
+  set(CMAKE_REQUIRED_LIBRARIES rt)
+  check_symbol_exists(clock_gettime "time.h" CLOCK_GETTIME_NEEDS_LINK_TO_LIBRT)
+  set(${CMAKE_FIND_PACKAGE_NAME}_FOUND ${CLOCK_GETTIME_NEEDS_LINK_TO_LIBRT})
+endif()
+
+if(${CMAKE_FIND_PACKAGE_NAME}_FOUND)
+  if(NOT TARGET POSIX::clock_gettime)
+    add_library(POSIX::clock_gettime INTERFACE IMPORTED)
+    set_target_properties(POSIX::clock_gettime PROPERTIES
+      INTERFACE_COMPILE_DEFINITIONS "_POSIX_C_SOURCE=199309L"
+      INTERFACE_LINK_LIBRARIES "${CMAKE_REQUIRED_LIBRARIES}"
+    )
+  endif()
+else()
+  if(${CMAKE_FIND_PACKAGE_NAME}_FIND_REQUIRED)
+    message(FATAL_ERROR "clock_gettime() not available.")
+  endif()
+endif()
+
+cmake_pop_check_state()

configure.ac

@@ -451,6 +451,14 @@ if test "x$enable_tests" != x"no"; then
   AC_SUBST(TEST_DEFINES)
 fi
 
+if test "x$enable_tests" != xno || test "x$enable_benchmark" != xno ; then
+  if test "x$build_windows" != xyes ; then
+    SECP_CHECK_CLOCK_GETTIME()
+    AC_SUBST(CLOCK_GETTIME_CPPFLAGS)
+    AC_SUBST(CLOCK_GETTIME_LIBS)
+  fi
+fi
+
 ###
 ### Generate output
 ###

src/CMakeLists.txt

@@ -124,13 +124,23 @@ elseif(CMAKE_SYSTEM_NAME STREQUAL "Windows")
 endif()
 unset(${PROJECT_NAME}_soversion)
 
+if(SECP256K1_BUILD_BENCHMARK OR SECP256K1_BUILD_TESTS)
+  if(WIN32)
+    add_library(clock_interface INTERFACE)  # It is empty on Windows.
+  else()
+    find_package(ClockGettime REQUIRED)
+    add_library(clock_interface ALIAS POSIX::clock_gettime)
+  endif()
+endif()
+
+
 if(SECP256K1_BUILD_BENCHMARK)
   add_executable(bench bench.c)
-  target_link_libraries(bench secp256k1)
+  target_link_libraries(bench secp256k1 clock_interface)
   add_executable(bench_internal bench_internal.c)
-  target_link_libraries(bench_internal secp256k1_precomputed secp256k1_asm)
+  target_link_libraries(bench_internal secp256k1_precomputed secp256k1_asm clock_interface)
   add_executable(bench_ecmult bench_ecmult.c)
-  target_link_libraries(bench_ecmult secp256k1_precomputed secp256k1_asm)
+  target_link_libraries(bench_ecmult secp256k1_precomputed secp256k1_asm clock_interface)
 endif()
 
 if(SECP256K1_BUILD_TESTS)
@@ -145,13 +155,13 @@ if(SECP256K1_BUILD_TESTS)
   endif()
 
   add_executable(noverify_tests tests.c)
-  target_link_libraries(noverify_tests secp256k1_precomputed secp256k1_asm)
+  target_link_libraries(noverify_tests secp256k1_precomputed secp256k1_asm clock_interface)
   target_compile_definitions(noverify_tests PRIVATE ${TEST_DEFINITIONS})
   add_test(NAME secp256k1_noverify_tests COMMAND noverify_tests)
   if(NOT CMAKE_BUILD_TYPE STREQUAL "Coverage")
     add_executable(tests tests.c)
     target_compile_definitions(tests PRIVATE VERIFY ${TEST_DEFINITIONS})
-    target_link_libraries(tests secp256k1_precomputed secp256k1_asm)
+    target_link_libraries(tests secp256k1_precomputed secp256k1_asm clock_interface)
     add_test(NAME secp256k1_tests COMMAND tests)
   endif()
   unset(TEST_DEFINITIONS)

src/bench.c

@@ -252,6 +252,7 @@ int main(int argc, char** argv) {
     data.pubkeylen = 33;
     CHECK(secp256k1_ec_pubkey_serialize(data.ctx, data.pubkey, &data.pubkeylen, &pubkey, SECP256K1_EC_COMPRESSED) == 1);
 
+    print_clock_info();
     print_output_table_header_row();
     if (d || have_flag(argc, argv, "ecdsa") || have_flag(argc, argv, "verify") || have_flag(argc, argv, "ecdsa_verify")) run_benchmark("ecdsa_verify", bench_verify, NULL, NULL, &data, 10, iters);
 

src/bench.h

@@ -85,9 +85,9 @@ static void run_benchmark(char *name, void (*benchmark)(void*, int), void (*setu
         if (setup != NULL) {
             setup(data);
         }
-        begin = gettime_i64();
+        begin = gettime_us();
         benchmark(data, iter);
-        total = gettime_i64() - begin;
+        total = gettime_us() - begin;
         if (teardown != NULL) {
             teardown(data, iter);
         }
@@ -156,6 +156,14 @@ static int get_iters(int default_iters) {
     }
 }
 
+static void print_clock_info(void) {
+#if defined(CLOCK_PROCESS_CPUTIME_ID)
+    printf("INFO: Using per-process CPU timer\n\n");
+#else
+    printf("WARN: Using global timer instead of per-process CPU timer.\n\n");
+#endif
+}
+
 static void print_output_table_header_row(void) {
     char* bench_str = "Benchmark";     /* left justified */
     char* min_str = "    Min(us)    "; /* center alignment */

src/bench_ecmult.c

@@ -363,6 +363,7 @@ int main(int argc, char **argv) {
     secp256k1_ge_set_all_gej_var(data.pubkeys, data.pubkeys_gej, POINTS);
 
 
+    print_clock_info();
     print_output_table_header_row();
     /* Initialize offset1 and offset2 */
     hash_into_offset(&data, 0);

src/bench_internal.c

@@ -398,6 +398,7 @@ int main(int argc, char **argv) {
         }
     }
 
+    print_clock_info();
     print_output_table_header_row();
 
     if (d || have_flag(argc, argv, "scalar") || have_flag(argc, argv, "half")) run_benchmark("scalar_half", bench_scalar_half, bench_setup, NULL, &data, 10, iters*100);

src/tests_common.h

@@ -17,25 +17,38 @@
 
 #include <stdint.h>
 
-#if (defined(_MSC_VER) && _MSC_VER >= 1900)
-#  include <time.h>
-#else
-#  include <sys/time.h>
+#if defined(_WIN32)
+# include <windows.h>
+#else /* POSIX */
+# include <time.h>
 #endif
 
-static int64_t gettime_i64(void) {
-#if (defined(_MSC_VER) && _MSC_VER >= 1900)
-    /* C11 way to get wallclock time */
-    struct timespec tv;
-    if (!timespec_get(&tv, TIME_UTC)) {
-        fputs("timespec_get failed!", stderr);
-        exit(EXIT_FAILURE);
-    }
-    return (int64_t)tv.tv_nsec / 1000 + (int64_t)tv.tv_sec * 1000000LL;
-#else
-    struct timeval tv;
-    gettimeofday(&tv, NULL);
-    return (int64_t)tv.tv_usec + (int64_t)tv.tv_sec * 1000000LL;
+static int64_t gettime_us(void) {
+#if defined(_WIN32)
+
+    LARGE_INTEGER freq, counter;
+    QueryPerformanceFrequency(&freq);
+    QueryPerformanceCounter(&counter);
+    return (int64_t)(counter.QuadPart * 1000000 / freq.QuadPart);
+
+#else /* POSIX */
+
+# if defined(CLOCK_PROCESS_CPUTIME_ID)
+    /* In theory, CLOCK_PROCESS_CPUTIME_ID is only useful if the process is locked to a core,
+     * see `man clock_gettime` on Linux. In practice, modern CPUs have synchronized TSCs which
+     * address this issue, see https://docs.amd.com/r/en-US/ug1586-onload-user/Timer-TSC-Stability . */
+    const clockid_t clock_type = CLOCK_PROCESS_CPUTIME_ID;
+# elif defined(CLOCK_MONOTONIC)
+    /* fallback to global timer */
+    const clockid_t clock_type = CLOCK_MONOTONIC;
+# else
+    /* fallback to wall-clock timer */
+    const clockid_t clock_type = CLOCK_REALTIME;
+# endif
+
+    struct timespec ts;
+    clock_gettime(clock_type, &ts);
+    return (int64_t)ts.tv_sec * 1000000 + ts.tv_nsec / 1000;
 #endif
 }
 

src/unit_test.c

@@ -260,10 +260,10 @@ static int read_args(int argc, char** argv, int start, struct tf_framework* tf)
 }
 
 static void run_test_log(const struct tf_test_entry* t) {
-    int64_t start_time = gettime_i64();
+    int64_t start_time = gettime_us();
     printf("Running %s..\n", t->name);
     t->func();
-    printf("Test %s PASSED (%.3f sec)\n", t->name, (double)(gettime_i64() - start_time) / 1000000);
+    printf("Test %s PASSED (%.3f sec)\n", t->name, (double)(gettime_us() - start_time) / 1000000);
 }
 
 static void run_test(const struct tf_test_entry* t) { t->func(); }
@@ -416,7 +416,7 @@ static int tf_run(struct tf_framework* tf) {
     /* Loop iterator */
     int it;
     /* Initial test time */
-    int64_t start_time = gettime_i64();
+    int64_t start_time = gettime_us();
     /* Verify 'tf_init' has been called */
     if (!tf->fn_run_test) {
         fprintf(stderr, "Error: No test runner set. You must call 'tf_init' first to initialize the framework "
@@ -472,7 +472,7 @@ static int tf_run(struct tf_framework* tf) {
     }
 
     /* Print accumulated time */
-    printf("Total execution time: %.3f seconds\n", (double)(gettime_i64() - start_time) / 1000000);
+    printf("Total execution time: %.3f seconds\n", (double)(gettime_us() - start_time) / 1000000);
     if (tf->fn_teardown && tf->fn_teardown() != 0) return EXIT_FAILURE;
 
     return status;