]> granicus.if.org Git - libevent/commitdiff
Make regression tests run over 3x faster.
authorNick Mathewson <nickm@torproject.org>
Tue, 24 Jan 2012 19:33:10 +0000 (14:33 -0500)
committerNick Mathewson <nickm@torproject.org>
Tue, 24 Jan 2012 19:48:04 +0000 (14:48 -0500)
This was mainly a matter of reducing timeouts and delays, paying
special attention to every test that took longer than a second to
finish.

We could do better here; IMO anything over .7 sec is probably too
long, but it's a big win as it is.

Remember, interactive computing is a big win over batch processing:
anything that makes you get up and walk away from the terminal might
as well be making you carry your punch cards over to the mainframe.

test/regress.c
test/regress_bufferevent.c
test/regress_dns.c
test/regress_http.c
test/regress_rpc.c
test/regress_thread.c

index 0fdfeb35b490a37887437808a2b91bc6794338d3..f7686d4d96120f8f63f03bade4b683146bfa8d52 100644 (file)
@@ -87,7 +87,6 @@ static struct timeval tcalled;
 
 
 #define TEST1  "this is a test"
-#define SECONDS        1
 
 #ifndef SHUT_WR
 #define SHUT_WR 1
@@ -233,21 +232,7 @@ multiple_read_cb(evutil_socket_t fd, short event, void *arg)
 static void
 timeout_cb(evutil_socket_t fd, short event, void *arg)
 {
-       struct timeval tv;
-       int diff;
-
        evutil_gettimeofday(&tcalled, NULL);
-       if (evutil_timercmp(&tcalled, &tset, >))
-               evutil_timersub(&tcalled, &tset, &tv);
-       else
-               evutil_timersub(&tset, &tcalled, &tv);
-
-       diff = tv.tv_sec*1000 + tv.tv_usec/1000 - SECONDS * 1000;
-       if (diff < 0)
-               diff = -diff;
-
-       if (diff < 100)
-               test_ok = 1;
 }
 
 struct both {
@@ -578,19 +563,26 @@ end:
 static void
 test_simpletimeout(void)
 {
-       struct timeval tv;
+       struct timeval tv, elapsed;
        struct event ev;
 
        setup_test("Simple timeout: ");
 
-       tv.tv_usec = 0;
-       tv.tv_sec = SECONDS;
+       tv.tv_usec = 200*1000;
+       tv.tv_sec = 0;
+       evutil_timerclear(&tcalled);
        evtimer_set(&ev, timeout_cb, NULL);
        evtimer_add(&ev, &tv);
 
        evutil_gettimeofday(&tset, NULL);
        event_dispatch();
+       evutil_timersub(&tcalled, &tset, &elapsed);
+       tt_int_op(0, ==, elapsed.tv_sec);
+       tt_int_op(elapsed.tv_usec, >, 150000);
+       tt_int_op(elapsed.tv_usec, <, 300000);
 
+       test_ok = 1;
+end:
        cleanup_test();
 }
 
@@ -707,7 +699,7 @@ common_timeout_cb(evutil_socket_t fd, short event, void *arg)
        struct common_timeout_info *ti = arg;
        ++ti->count;
        evutil_gettimeofday(&ti->called_at, NULL);
-       if (ti->count >= 6)
+       if (ti->count >= 4)
                event_del(&ti->ev);
 }
 
@@ -720,7 +712,7 @@ test_common_timeout(void *ptr)
        int i;
        struct common_timeout_info info[100];
 
-       struct timeval now;
+       struct timeval start;
        struct timeval tmp_100_ms = { 0, 100*1000 };
        struct timeval tmp_200_ms = { 0, 200*1000 };
 
@@ -751,23 +743,23 @@ test_common_timeout(void *ptr)
        }
 
        event_base_assert_ok(base);
+       evutil_gettimeofday(&start, NULL);
        event_base_dispatch(base);
 
-       evutil_gettimeofday(&now, NULL);
        event_base_assert_ok(base);
 
        for (i=0; i<10; ++i) {
                struct timeval tmp;
-               int ms_diff;
-               tt_int_op(info[i].count, ==, 6);
-               evutil_timersub(&now, &info[i].called_at, &tmp);
-               ms_diff = tmp.tv_usec/1000 + tmp.tv_sec*1000;
+               int ms_elapsed;
+               tt_int_op(info[i].count, ==, 4);
+               evutil_timersub(&info[i].called_at, &start, &tmp);
+               ms_elapsed = tmp.tv_usec/1000 + tmp.tv_sec*1000;
                if (i % 2) {
-                       tt_int_op(ms_diff, >, 500);
-                       tt_int_op(ms_diff, <, 700);
+                       tt_int_op(ms_elapsed, >, 300);
+                       tt_int_op(ms_elapsed, <, 500);
                } else {
-                       tt_int_op(ms_diff, >, -100);
-                       tt_int_op(ms_diff, <, 100);
+                       tt_int_op(ms_elapsed, >, 700);
+                       tt_int_op(ms_elapsed, <, 900);
                }
        }
 
@@ -927,7 +919,8 @@ test_simplesignal(void)
        evsignal_add(&ev, NULL);
 
        memset(&itv, 0, sizeof(itv));
-       itv.it_value.tv_sec = 1;
+       itv.it_value.tv_sec = 0;
+       itv.it_value.tv_usec = 100000;
        if (setitimer(ITIMER_REAL, &itv, NULL) == -1)
                goto skip_simplesignal;
 
@@ -954,7 +947,8 @@ test_multiplesignal(void)
        evsignal_add(&ev_two, NULL);
 
        memset(&itv, 0, sizeof(itv));
-       itv.it_value.tv_sec = 1;
+       itv.it_value.tv_sec = 0;
+       itv.it_value.tv_usec = 100000;
        if (setitimer(ITIMER_REAL, &itv, NULL) == -1)
                goto skip_simplesignal;
 
@@ -1343,23 +1337,22 @@ test_loopexit(void)
        evtimer_set(&ev, timeout_cb, NULL);
        evtimer_add(&ev, &tv);
 
-       tv.tv_usec = 0;
-       tv.tv_sec = 1;
+       tv.tv_usec = 300*1000;
+       tv.tv_sec = 0;
        event_loopexit(&tv);
 
        evutil_gettimeofday(&tv_start, NULL);
        event_dispatch();
        evutil_gettimeofday(&tv_end, NULL);
-       evutil_timersub(&tv_end, &tv_start, &tv_end);
 
        evtimer_del(&ev);
 
        tt_assert(event_base_got_exit(global_base));
        tt_assert(!event_base_got_break(global_base));
 
-       if (tv.tv_sec < 2)
-               test_ok = 1;
+       test_timeval_diff_eq(&tv_start, &tv_end, 300);
 
+       test_ok = 1;
 end:
        cleanup_test();
 }
@@ -1367,28 +1360,32 @@ end:
 static void
 test_loopexit_multiple(void)
 {
-       struct timeval tv;
+       struct timeval tv, tv_start, tv_end;
        struct event_base *base;
 
        setup_test("Loop Multiple exit: ");
 
        base = event_base_new();
 
-       tv.tv_usec = 0;
-       tv.tv_sec = 1;
+       tv.tv_usec = 200*1000;
+       tv.tv_sec = 0;
        event_base_loopexit(base, &tv);
 
        tv.tv_usec = 0;
-       tv.tv_sec = 2;
+       tv.tv_sec = 3;
        event_base_loopexit(base, &tv);
 
+       evutil_gettimeofday(&tv_start, NULL);
        event_base_dispatch(base);
+       evutil_gettimeofday(&tv_end, NULL);
 
        tt_assert(event_base_got_exit(base));
        tt_assert(!event_base_got_break(base));
 
        event_base_free(base);
 
+       test_timeval_diff_eq(&tv_start, &tv_end, 200);
+
        test_ok = 1;
 
 end:
@@ -1662,7 +1659,7 @@ test_want_only_once(void)
 
        /* Setup the loop termination */
        evutil_timerclear(&tv);
-       tv.tv_sec = 1;
+       tv.tv_usec = 300*1000;
        event_loopexit(&tv);
 
        event_set(&ev, pair[1], EV_READ, read_once_cb, &ev);
index 26273f6c7af9a2bffba5e0088306a4ccfc49cac3..82d582cd2620b3f79d5e9c20c393943645f125c7 100644 (file)
@@ -746,8 +746,8 @@ test_bufferevent_timeouts(void *arg)
        bufferevent_set_timeouts(bev2, &tv_r, &tv_w);
        bufferevent_enable(bev2, EV_WRITE);
 
-       tv_r.tv_sec = 1;
-       tv_r.tv_usec = 0;
+       tv_r.tv_sec = 0;
+       tv_r.tv_usec = 350000;
 
        event_base_loopexit(data->base, &tv_r);
        event_base_dispatch(data->base);
index be3e7220be946bb55cb03fe85ba28de0159f77bd..9c24061c5054ee7190c5387c75fab5cdddab90cb 100644 (file)
@@ -684,9 +684,9 @@ dns_retry_test(void *arg)
 
        dns = evdns_base_new(base, 0);
        tt_assert(!evdns_base_nameserver_ip_add(dns, buf));
-       tt_assert(! evdns_base_set_option(dns, "timeout", "0.3"));
+       tt_assert(! evdns_base_set_option(dns, "timeout", "0.2"));
        tt_assert(! evdns_base_set_option(dns, "max-timeouts:", "10"));
-       tt_assert(! evdns_base_set_option(dns, "initial-probe-timeout", "0.5"));
+       tt_assert(! evdns_base_set_option(dns, "initial-probe-timeout", "0.1"));
 
        evdns_base_resolve_ipv4(dns, "host.example.com", 0,
            generic_dns_callback, &r1);
@@ -705,8 +705,8 @@ dns_retry_test(void *arg)
        /* Now try again, but this time have the server get treated as
         * failed, so we can send it a test probe. */
        drop_count = 4;
-       tt_assert(! evdns_base_set_option(dns, "max-timeouts:", "3"));
-       tt_assert(! evdns_base_set_option(dns, "attempts:", "4"));
+       tt_assert(! evdns_base_set_option(dns, "max-timeouts:", "2"));
+       tt_assert(! evdns_base_set_option(dns, "attempts:", "3"));
        memset(&r1, 0, sizeof(r1));
 
        evdns_base_resolve_ipv4(dns, "host.example.com", 0,
@@ -883,6 +883,8 @@ be_getaddrinfo_server_cb(struct evdns_server_request *req, void *data)
                struct in6_addr ans6;
                memset(&ans6, 0, sizeof(ans6));
 
+               TT_BLATHER(("Got question about %s, type=%d", qname, qtype));
+
                if (qtype == EVDNS_TYPE_A &&
                    qclass == EVDNS_CLASS_INET &&
                    !evutil_ascii_strcasecmp(qname, "nobodaddy.example.com")) {
@@ -983,10 +985,13 @@ be_getaddrinfo_server_cb(struct evdns_server_request *req, void *data)
                        TT_GRIPE(("Got weird request for %s",qname));
                }
        }
-       if (added_any)
+       if (added_any) {
+               TT_BLATHER(("answering"));
                evdns_server_request_respond(req, 0);
-       else
+       } else {
+               TT_BLATHER(("saying nexist."));
                evdns_server_request_respond(req, 3);
+       }
 }
 
 /* Implements a listener for connect_hostname test. */
@@ -1215,6 +1220,9 @@ test_getaddrinfo_async(void *arg)
        /* for localhost */
        evdns_base_load_hosts(dns_base, NULL);
 
+       tt_assert(! evdns_base_set_option(dns_base, "timeout", "0.3"));
+       tt_assert(! evdns_base_set_option(dns_base, "getaddrinfo-allow-skew", "0.2"));
+
        memset(a_out, 0, sizeof(a_out));
 
        n_gai_results_pending = 10000; /* don't think about exiting yet. */
index 81632b93aaf77588cfa073a9aa5a1deec034037f..31eef55ba1030583236aed7917cae5e425484df8 100644 (file)
@@ -628,7 +628,7 @@ http_large_delay_cb(struct evhttp_request *req, void *arg)
 {
        struct timeval tv;
        evutil_timerclear(&tv);
-       tv.tv_sec = 3;
+       tv.tv_usec = 500000;
 
        event_base_once(arg, -1, EV_TIMEOUT, http_delay_reply, req, &tv);
        evhttp_connection_fail(delayed_client, EVCON_HTTP_EOF);
@@ -1769,7 +1769,7 @@ close_detect_done(struct evhttp_request *req, void *arg)
 
  end:
        evutil_timerclear(&tv);
-       tv.tv_sec = 3;
+       tv.tv_usec = 150000;
        event_base_loopexit(arg, &tv);
 }
 
@@ -1803,9 +1803,10 @@ close_detect_cb(struct evhttp_request *req, void *arg)
        }
 
        evutil_timerclear(&tv);
-       tv.tv_sec = 3;   /* longer than the http time out */
+       tv.tv_sec = 0;   /* longer than the http time out */
+       tv.tv_usec = 600000;   /* longer than the http time out */
 
-       /* launch a new request on the persistent connection in 3 seconds */
+       /* launch a new request on the persistent connection in .3 seconds */
        event_base_once(base, -1, EV_TIMEOUT, close_detect_launch, evcon, &tv);
  end:
        ;
@@ -1818,15 +1819,19 @@ _http_close_detection(struct basic_test_data *data, int with_delay)
        ev_uint16_t port = 0;
        struct evhttp_connection *evcon = NULL;
        struct evhttp_request *req = NULL;
+       const struct timeval sec_tenth = { 0, 100000 };
 
        test_ok = 0;
        http = http_setup(&port, data->base);
 
-       /* 2 second timeout */
-       evhttp_set_timeout(http, 1);
+       /* .1 second timeout */
+       evhttp_set_timeout_tv(http, &sec_tenth);
 
        evcon = evhttp_connection_base_new(data->base, NULL,
            "127.0.0.1", port);
+       evhttp_connection_set_timeout_tv(evcon, &sec_tenth);
+
+
        tt_assert(evcon);
        delayed_client = evcon;
 
@@ -3143,7 +3148,12 @@ http_connection_retry_test(void *arg)
         */
        test_ok = 0;
 
-       evhttp_connection_set_timeout(evcon, 1);
+       {
+               const struct timeval tv_timeout = { 0, 300000 };
+               const struct timeval tv_retry = { 0, 200000 };
+               evhttp_connection_set_timeout_tv(evcon, &tv_timeout);
+               evhttp_connection_set_initial_retry_tv(evcon, &tv_retry);
+       }
        evhttp_connection_set_retries(evcon, 1);
 
        req = evhttp_request_new(http_connection_retry_done, data->base);
@@ -3160,9 +3170,9 @@ http_connection_retry_test(void *arg)
        evutil_gettimeofday(&tv_start, NULL);
        event_base_dispatch(data->base);
        evutil_gettimeofday(&tv_end, NULL);
-       evutil_timersub(&tv_end, &tv_start, &tv_end);
-       tt_int_op(tv_end.tv_sec, >, 1);
-       tt_int_op(tv_end.tv_sec, <, 6);
+
+       /* fails fast, .2 sec to wait to retry, fails fast again. */
+       test_timeval_diff_eq(&tv_start, &tv_end, 200);
 
        tt_assert(test_ok == 1);
 
@@ -3186,22 +3196,19 @@ http_connection_retry_test(void *arg)
                tt_abort_msg("Couldn't make request");
        }
 
-       /* start up a web server one second after the connection tried
+       /* start up a web server .2 seconds after the connection tried
         * to send a request
         */
        evutil_timerclear(&tv);
-       tv.tv_sec = 1;
+       tv.tv_usec = 200000;
        http_make_web_server_base = data->base;
        event_base_once(data->base, -1, EV_TIMEOUT, http_make_web_server, &port, &tv);
 
        evutil_gettimeofday(&tv_start, NULL);
        event_base_dispatch(data->base);
        evutil_gettimeofday(&tv_end, NULL);
-
-       evutil_timersub(&tv_end, &tv_start, &tv_end);
-
-       tt_int_op(tv_end.tv_sec, >, 1);
-       tt_int_op(tv_end.tv_sec, <, 6);
+       /* We'll wait twice as long as we did last time. */
+       test_timeval_diff_eq(&tv_start, &tv_end, 400);
 
        tt_int_op(test_ok, ==, 1);
 
index c698ed359d6cfebeee972d1a19dd1dbeeae79c1b..e22da92cf44563cbbd9cc5cdc55747f787888175 100644 (file)
@@ -687,8 +687,8 @@ rpc_client_timeout(void)
 
        pool = rpc_pool_with_connection(port);
 
-       /* set the timeout to 5 seconds */
-       evrpc_pool_set_timeout(pool, 5);
+       /* set the timeout to 1 second. */
+       evrpc_pool_set_timeout(pool, 1);
 
        /* set up the basic message */
        msg = msg_new();
index da43b2e7eab94fc53dc666b6469365d9c019624d..a652083674845f6cad186fcddf99b7d94d96a0ae 100644 (file)
@@ -60,6 +60,7 @@
 #include "evthread-internal.h"
 #include "event-internal.h"
 #include "defer-internal.h"
+#include "util-internal.h"
 #include "regress.h"
 #include "tinytest_macros.h"
 
@@ -403,19 +404,22 @@ end:
 #define CB_COUNT 128
 #define QUEUE_THREAD_COUNT 8
 
-#ifdef _WIN32
-#define SLEEP_MS(ms) Sleep(ms)
-#else
-#define SLEEP_MS(ms) usleep((ms) * 1000)
-#endif
+static void
+SLEEP_MS(int ms)
+{
+       struct timeval tv;
+       tv.tv_sec = ms/1000;
+       tv.tv_usec = (ms%1000)*1000;
+       evutil_usleep(&tv);
+}
 
 struct deferred_test_data {
        struct deferred_cb cbs[CB_COUNT];
        struct deferred_cb_queue *queue;
 };
 
-static time_t timer_start = 0;
-static time_t timer_end = 0;
+static struct timeval timer_start = {0,0};
+static struct timeval timer_end = {0,0};
 static unsigned callback_count = 0;
 static THREAD_T load_threads[QUEUE_THREAD_COUNT];
 static struct deferred_test_data deferred_data[QUEUE_THREAD_COUNT];
@@ -445,7 +449,7 @@ load_deferred_queue(void *arg)
 static void
 timer_callback(evutil_socket_t fd, short what, void *arg)
 {
-       timer_end = time(NULL);
+       evutil_gettimeofday(&timer_end, NULL);
 }
 
 static void
@@ -463,9 +467,10 @@ static void
 thread_deferred_cb_skew(void *arg)
 {
        struct basic_test_data *data = arg;
-       struct timeval tv_timer = {4, 0};
+       struct timeval tv_timer = {1, 0};
        struct deferred_cb_queue *queue;
-       time_t elapsed;
+       struct timeval elapsed;
+       int elapsed_usec;
        int i;
 
        queue = event_base_get_deferred_cb_queue(data->base);
@@ -474,19 +479,23 @@ thread_deferred_cb_skew(void *arg)
        for (i = 0; i < QUEUE_THREAD_COUNT; ++i)
                deferred_data[i].queue = queue;
 
-       timer_start = time(NULL);
+       evutil_gettimeofday(&timer_start, NULL);
        event_base_once(data->base, -1, EV_TIMEOUT, timer_callback, NULL,
                        &tv_timer);
        event_base_once(data->base, -1, EV_TIMEOUT, start_threads_callback,
                        NULL, NULL);
        event_base_dispatch(data->base);
 
-       elapsed = timer_end - timer_start;
+       evutil_timersub(&timer_end, &timer_start, &elapsed);
        TT_BLATHER(("callback count, %u", callback_count));
-       TT_BLATHER(("elapsed time, %u", (unsigned)elapsed));
+       elapsed_usec =
+           (unsigned)(elapsed.tv_sec*1000000 + elapsed.tv_usec);
+       TT_BLATHER(("elapsed time, %u usec", elapsed_usec));
+
        /* XXX be more intelligent here.  just make sure skew is
-        * within 2 seconds for now. */
-       tt_assert(elapsed >= 4 && elapsed <= 6);
+        * within .3 seconds for now. */
+
+       tt_assert(elapsed_usec >= 700000 && elapsed_usec <= 1200000);
 
 end:
        for (i = 0; i < QUEUE_THREAD_COUNT; ++i)