commit 118556e4b32c30d91c2d132c5f8d3cb8e551fafc Author: Nick Mathewson nickm@torproject.org Date: Wed Apr 13 15:30:59 2016 -0400
Quick-and-dirty test for timers code. --- .gitignore | 2 + src/common/timers.c | 23 ++++++++++- src/test/include.am | 16 +++++++- src/test/test-timers.c | 101 +++++++++++++++++++++++++++++++++++++++++++++++++ 4 files changed, 139 insertions(+), 3 deletions(-)
diff --git a/.gitignore b/.gitignore index b141e80..7900141 100644 --- a/.gitignore +++ b/.gitignore @@ -180,6 +180,7 @@ uptime-*.json /src/test/test-memwipe /src/test/test-ntor-cl /src/test/test-switch-id +/src/test/test-timers /src/test/test_workqueue /src/test/test.exe /src/test/test-slow.exe @@ -188,6 +189,7 @@ uptime-*.json /src/test/test-ntor-cl.exe /src/test/test-memwipe.exe /src/test/test-switch-id.exe +/src/test/test-timers.exe /src/test/test_workqueue.exe /src/test/test_zero_length_keys.sh /src/test/test_ntor.sh diff --git a/src/common/timers.c b/src/common/timers.c index 5f42cd4..58981b9 100644 --- a/src/common/timers.c +++ b/src/common/timers.c @@ -79,12 +79,23 @@ static struct event *global_timer_event = NULL; /** We need to choose this value carefully. Because we're using timer wheels, * it actually costs us to have extra resolution we don't use. So for now, * I'm going to define our resolution as .1 msec, and hope that's good enough. + * + * Note that two of the most popular libevent backends (epoll without timerfd, + * and windows select), simply can't support sub-millisecond resolution, + * do this is optimistic for a lot of users. */ #define USEC_PER_TICK 100
/** One million microseconds in a second */ #define USEC_PER_SEC 1000000
+/** Check at least once every N seconds. */ +#define MIN_CHECK_SECONDS 3600 + +/** Check at least once every N ticks. */ +#define MIN_CHECK_TICKS \ + (((timeout_t)MIN_CHECK_SECONDS) * (1000000 / USEC_PER_TICK)) + /** * Convert the timeval in <b>tv</b> to a timeout_t, and return it. * @@ -135,8 +146,10 @@ libevent_timer_reschedule(void) tor_gettimeofday_cached_monotonic(&now); timer_advance_to_cur_time(&now);
- const timeout_t delay = timeouts_timeout(global_timeouts); + timeout_t delay = timeouts_timeout(global_timeouts); struct timeval d; + if (delay > MIN_CHECK_TICKS) + delay = MIN_CHECK_TICKS; timeout_to_tv(delay, &d); event_add(global_timer_event, &d); } @@ -153,6 +166,7 @@ libevent_timer_callback(evutil_socket_t fd, short what, void *arg) (void)arg;
struct timeval now; + tor_gettimeofday_cache_clear(); tor_gettimeofday_cached_monotonic(&now); timer_advance_to_cur_time(&now);
@@ -187,6 +201,8 @@ timers_initialize(void) -1, 0, libevent_timer_callback, NULL); tor_assert(timer_event); global_timer_event = timer_event; + + libevent_timer_reschedule(); }
/** @@ -253,12 +269,15 @@ timer_schedule(tor_timer_t *t, const struct timeval *tv) tor_gettimeofday_cached_monotonic(&now); timer_advance_to_cur_time(&now);
+ /* Take the old timeout value. */ + timeout_t to = timeouts_timeout(global_timeouts); + timeouts_add(global_timeouts, t, when);
/* Should we update the libevent timer? */ if (to <= when) { return; /* we're already going to fire before this timer would trigger. */ - + } libevent_timer_reschedule(); }
diff --git a/src/test/include.am b/src/test/include.am index 7d80fdf..174bcda 100644 --- a/src/test/include.am +++ b/src/test/include.am @@ -17,6 +17,7 @@ endif
TESTS += src/test/test src/test/test-slow src/test/test-memwipe \ src/test/test_workqueue src/test/test_keygen.sh \ + src/test/test-timers \ $(TESTSCRIPTS)
# These flavors are run using automake's test-driver and test-network.sh @@ -40,7 +41,8 @@ noinst_PROGRAMS+= \ src/test/test-memwipe \ src/test/test-child \ src/test/test_workqueue \ - src/test/test-switch-id + src/test/test-switch-id \ + src/test/test-timers endif
src_test_AM_CPPFLAGS = -DSHARE_DATADIR=""$(datadir)"" \ @@ -127,6 +129,8 @@ src_test_test_slow_SOURCES = \ src_test_test_memwipe_SOURCES = \ src/test/test-memwipe.c
+src_test_test_timers_SOURCES = \ + src/test/test-timers.c
src_test_test_CFLAGS = $(AM_CFLAGS) $(TEST_CFLAGS)
@@ -190,6 +194,16 @@ src_test_test_workqueue_LDADD = src/or/libtor-testing.a \ @TOR_ZLIB_LIBS@ @TOR_LIB_MATH@ @TOR_LIBEVENT_LIBS@ \ @TOR_OPENSSL_LIBS@ @TOR_LIB_WS32@ @TOR_LIB_GDI@ @CURVE25519_LIBS@
+src_test_test_timers_CPPFLAGS = $(src_test_test_CPPFLAGS) +src_test_test_timers_CFLAGS = $(src_test_test_CFLAGS) +src_test_test_timers_LDADD = \ + src/common/libor-event-testing.a \ + src/common/libor-crypto-testing.a $(LIBKECCAK_TINY) $(LIBDONNA) \ + src/common/libor-testing.a \ + @TOR_ZLIB_LIBS@ @TOR_LIB_MATH@ @TOR_LIBEVENT_LIBS@ \ + @TOR_OPENSSL_LIBS@ @TOR_LIB_WS32@ @TOR_LIB_GDI@ @CURVE25519_LIBS@ +src_test_test_timers_LDFLAGS = $(src_test_test_LDFLAGS) + noinst_HEADERS+= \ src/test/fakechans.h \ src/test/log_test_helpers.h \ diff --git a/src/test/test-timers.c b/src/test/test-timers.c new file mode 100644 index 0000000..83a5e1b --- /dev/null +++ b/src/test/test-timers.c @@ -0,0 +1,101 @@ +/* Copyright 2016, The Tor Project, Inc. */ +/* See LICENSE for licensing information */ + +#include "orconfig.h" + +#include <math.h> +#include <stdio.h> +#include <string.h> + +#ifdef HAVE_EVENT2_EVENT_H +#include <event2/event.h> +#else +#include <event.h> +#endif + +#include "compat.h" +#include "compat_libevent.h" +#include "crypto.h" +#include "timers.h" +#include "util.h" + +#define N_TIMERS 1000 +#define MAX_DURATION 30 + +static struct timeval fire_at[N_TIMERS] = {{0,0}}; +static int fired[N_TIMERS] = {0}; +static struct timeval difference[N_TIMERS] = {{0,0}}; +static tor_timer_t *timers[N_TIMERS] = {NULL}; + +static int n_fired = 0; + +static void +timer_cb(tor_timer_t *t, void *arg, const struct timeval *now) +{ + tor_timer_t **t_ptr = arg; + tor_assert(*t_ptr == t); + int idx = (int) (t_ptr - timers); + ++fired[idx]; + timersub(now, &fire_at[idx], &difference[idx]); + ++n_fired; + // printf("%d / %d\n",n_fired, N_TIMERS); + if (n_fired == N_TIMERS) { + event_base_loopbreak(tor_libevent_get_base()); + } +} + +int +main(int argc, char **argv) +{ + (void)argc; + (void)argv; + tor_libevent_cfg cfg; + memset(&cfg, 0, sizeof(cfg)); + tor_libevent_initialize(&cfg); + timers_initialize(); + + int i; + struct timeval now; + tor_gettimeofday(&now); + for (i = 0; i < N_TIMERS; ++i) { + struct timeval delay; + delay.tv_sec = crypto_rand_int_range(0,MAX_DURATION); + delay.tv_usec = crypto_rand_int_range(0,1000000); + timeradd(&now, &delay, &fire_at[i]); + timers[i] = timer_new(timer_cb, &timers[i], 0); + timer_schedule(timers[i], &delay); + } + + event_base_loop(tor_libevent_get_base(), 0); + + uint64_t total_difference = 0; + uint64_t total_square_difference = 0; + tor_assert(n_fired == N_TIMERS); + for (i = 0; i < N_TIMERS; ++i) { + tor_assert(fired[i] == 1); + uint64_t diff = difference[i].tv_usec + difference[i].tv_sec * 1000000; + total_difference += diff; + total_square_difference += diff*diff; + } + const uint64_t mean_diff = total_difference / N_TIMERS; + printf("mean difference: "U64_FORMAT" usec\n", + U64_PRINTF_ARG(mean_diff)); + + const double mean_sq = ((double)total_square_difference) / N_TIMERS; + const double sq_mean = mean_diff * mean_diff; + const double stddev = sqrt(mean_sq - sq_mean); + printf("standard deviation: %lf usec\n", stddev); + + if (mean_diff > 500*1000 || stddev > 500*1000) { + printf("Either your system is under ridiculous load, or the " + "timer backend is broken.\n"); + return 1; + } else if (mean_diff > 2000 || stddev > 2000) { + printf("Either your system is a bit slow or the " + "timer backend is odd.\n"); + return 0; + } else { + printf("Looks good enough.\n"); + } + return 0; +}