Simplify bufferevent timeout tests to reduce CPU usage in between start/compare

Between start (setting "started_at") and comparing the time when
timeouts triggered with the start (test_timeval_diff_eq), there is too
much various things that can introduce extra delays and eventually could
fail the test on machine with shortage of CPU.

And this is exactly what happend on:
- travis-ci
- #262

Here is a simple reproducer that I came up with for this issue:
  docker run --cpus=0.01 -e LD_LIBRARY_PATH=$PWD/lib -e PATH=/usr/bin:/bin:$PWD/bin -v $PWD:$PWD --rm -it debian:testing regress --no-fork --verbose bufferevent/bufferevent_timeout

Under limited CPU (see reproducer) the test almost always has problems
with that "write_timeout_at" exceed default timeval diff tolerance
(test_timeval_diff_eq() has 50 tolerance), i.e.:
  FAIL ../test/regress_bufferevent.c:1040: assert(labs(timeval_msec_diff(((&started_at)), ((&res1.write_timeout_at))) - (100)) <= 50): 101 vs 50

But under some setup write timeout can even not triggered, and the
reason for this is that we write to the bufferevent 1024*1024 bytes, and
hence if evbuffer_write_iovec() will has some delay after writev() and
not send more then one vector at a time [1], it is pretty simple to
trigger, i.e.:
  FAIL ../test/regress_bufferevent.c:1040: assert(labs(timeval_msec_diff(((&started_at)), ((&res1.write_timeout_at))) - (100)) <= 50): 1540155888478 vs 50

  [1]: https://gist.github.com/azat/b72773dfe7549fed865d439e03de05c1

So this patch just send static small payload for all cases (plus a few
more asserts added).

The outcome of this patch is that all regression tests passed on
travis-ci for linux box [2]. While before it fails almost always [3].
Also reproducer with CPU limiting via docker also survive some
iterations (and strictly speaking it should has less CPU then travis-ci
workers I guess).

  [2]: https://travis-ci.org/azat/libevent/builds/444391481
  [3]: https://travis-ci.org/libevent/libevent/builds/444336505

(cherry picked from commit 6ac8e775bb3cba49c276c90e288554635d38b466)

diff --git a/test/regress_bufferevent.c b/test/regress_bufferevent.c
index 6d69655ff16fe7ba11dd920d76dce20f165929b1..faf87a7f8dc11b7a8f0d8a220e82ac804a04da91 100644 (file)
--- a/test/regress_bufferevent.c
+++ b/test/regress_bufferevent.c
@@ -908,18 +908,24 @@ struct timeout_cb_result {
        struct timeval read_timeout_at;
        struct timeval write_timeout_at;
        struct timeval last_wrote_at;
+       struct timeval last_read_at;
        int n_read_timeouts;
        int n_write_timeouts;
        int total_calls;
 };
 
+static void
+bev_timeout_read_cb(struct bufferevent *bev, void *arg)
+{
+       struct timeout_cb_result *res = arg;
+       evutil_gettimeofday(&res->last_read_at, NULL);
+}
 static void
 bev_timeout_write_cb(struct bufferevent *bev, void *arg)
 {
        struct timeout_cb_result *res = arg;
        evutil_gettimeofday(&res->last_wrote_at, NULL);
 }
-
 static void
 bev_timeout_event_cb(struct bufferevent *bev, short what, void *arg)
 {
@@ -947,7 +953,6 @@ test_bufferevent_timeouts(void *arg)
        int use_pair = 0, use_filter = 0;
        struct timeval tv_w, tv_r, started_at;
        struct timeout_cb_result res1, res2;
-       char buf[1024];
 
        memset(&res1, 0, sizeof(res1));
        memset(&res2, 0, sizeof(res2));
@@ -966,7 +971,6 @@ test_bufferevent_timeouts(void *arg)
                bev1 = bufferevent_socket_new(data->base, data->pair[0], 0);
                bev2 = bufferevent_socket_new(data->base, data->pair[1], 0);
        }
-
        tt_assert(bev1);
        tt_assert(bev2);
 
@@ -990,30 +994,14 @@ test_bufferevent_timeouts(void *arg)
        tv_w.tv_sec = tv_r.tv_sec = 0;
        tv_w.tv_usec = 100*1000;
        tv_r.tv_usec = 150*1000;
-       bufferevent_setcb(bev1, NULL, bev_timeout_write_cb,
+       bufferevent_setcb(bev1, bev_timeout_read_cb, bev_timeout_write_cb,
            bev_timeout_event_cb, &res1);
-       bufferevent_setwatermark(bev1, EV_WRITE, 1024*1024+10, 0);
        bufferevent_set_timeouts(bev1, &tv_r, &tv_w);
-       if (use_pair) {
-               /* For a pair, the fact that the other side isn't reading
-                * makes the writer stall */
-               bufferevent_write(bev1, "ABCDEFG", 7);
-       } else {
-               /* For a real socket, the kernel's TCP buffers can eat a
-                * fair number of bytes; make sure that at some point we
-                * have some bytes that will stall. */
-               struct evbuffer *output = bufferevent_get_output(bev1);
-               int i;
-               memset(buf, 0xbb, sizeof(buf));
-               for (i=0;i<1024;++i) {
-                       evbuffer_add_reference(output, buf, sizeof(buf),
-                           NULL, NULL);
-               }
-       }
+       bufferevent_write(bev1, "ABCDEFG", 7);
        bufferevent_enable(bev1, EV_READ|EV_WRITE);
 
        /* bev2 has nothing to say, and isn't listening. */
-       bufferevent_setcb(bev2, NULL,  bev_timeout_write_cb,
+       bufferevent_setcb(bev2, bev_timeout_read_cb, bev_timeout_write_cb,
            bev_timeout_event_cb, &res2);
        tv_w.tv_sec = tv_r.tv_sec = 0;
        tv_w.tv_usec = 200*1000;
@@ -1030,15 +1018,26 @@ test_bufferevent_timeouts(void *arg)
        /* XXXX Test that actually reading or writing a little resets the
         * timeouts. */
 
-       /* Each buf1 timeout happens, and happens only once. */
-       tt_want(res1.n_read_timeouts);
-       tt_want(res1.n_write_timeouts);
+       tt_want(res1.total_calls == 2);
        tt_want(res1.n_read_timeouts == 1);
        tt_want(res1.n_write_timeouts == 1);
+       tt_want(res2.total_calls == !(use_pair && !use_filter));
+       tt_want(res2.n_write_timeouts == !(use_pair && !use_filter));
+       tt_want(!res2.n_read_timeouts);
 
        test_timeval_diff_eq(&started_at, &res1.read_timeout_at, 150);
        test_timeval_diff_eq(&started_at, &res1.write_timeout_at, 100);
 
+#define tt_assert_timeval_empty(tv) do {  \
+       tt_int_op((tv).tv_sec, ==, 0);   \
+       tt_int_op((tv).tv_usec, ==, 0);  \
+} while(0)
+       tt_assert_timeval_empty(res1.last_read_at);
+       tt_assert_timeval_empty(res2.last_read_at);
+       tt_assert_timeval_empty(res2.last_wrote_at);
+       tt_assert_timeval_empty(res2.last_wrote_at);
+#undef tt_assert_timeval_empty
+
 end:
        if (bev1)
                bufferevent_free(bev1);
@@ -1363,7 +1362,7 @@ struct testcase_t bufferevent_testcases[] = {
        { "bufferevent_connect_fail", test_bufferevent_connect_fail,
          TT_FORK|TT_NEED_BASE, &basic_setup, NULL },
        { "bufferevent_timeout", test_bufferevent_timeouts,
-         TT_FORK|TT_NEED_BASE|TT_NEED_SOCKETPAIR, &basic_setup, (void*)"" },
+         TT_FORK|TT_NEED_BASE, &basic_setup, (void*)"" },
        { "bufferevent_timeout_pair", test_bufferevent_timeouts,
          TT_FORK|TT_NEED_BASE, &basic_setup, (void*)"pair" },
        { "bufferevent_timeout_filter", test_bufferevent_timeouts,