From patchwork Mon Jan 12 21:20:57 2015 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Ola Liljedahl X-Patchwork-Id: 42973 Return-Path: X-Original-To: linaro@patches.linaro.org Delivered-To: linaro@patches.linaro.org Received: from mail-wg0-f70.google.com (mail-wg0-f70.google.com [74.125.82.70]) by ip-10-151-82-157.ec2.internal (Postfix) with ESMTPS id B3FF52055F for ; Mon, 12 Jan 2015 21:20:54 +0000 (UTC) Received: by mail-wg0-f70.google.com with SMTP id y19sf3019735wgg.1 for ; Mon, 12 Jan 2015 13:20:54 -0800 (PST) X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20130820; h=x-gm-message-state:delivered-to:from:to:date:message-id:subject :precedence:list-id:list-unsubscribe:list-archive:list-post :list-help:list-subscribe:mime-version:content-type :content-transfer-encoding:errors-to:sender:x-original-sender :x-original-authentication-results:mailing-list; bh=5LEW71W4j+yaTrDOco9lOG7AIM/zAv8VPUGEopwNKeM=; b=LsA2EwP8dFIMkTtjDwOH9EdjXV9RhdI5oQYeZe3gOuPcM9szSUIgDKvnm5GDqELRNw iqLlZgMmSnQAzrP2ip2jUfnj7Bc0n/1AAaf+u6QYzHOwpemtO40XyiSx6Rf+0jmlE4nr 16f+ykwzAnMOCcq+EYn4qWqe3wNhV4xNtjn5m6Vi+nu5KpWnoivTzmifsrYC05dY6LKR fkADyQX+/0KKOzpzj/+H0NrVrEWfbYJlfpNmSgH2o9xTndiP5Ek9WhGOO5EINNvwAnr+ Y00f5gmTXXxTwq/nPRyk6f6WRR3K4yh4ch0JAFaYu5+WFzIBLFeXccvd87+6SstySNZ/ rvwA== X-Gm-Message-State: ALoCoQlKB9D/fdtLXusjqrpdJx9SZs+9035M8Bv/GTN7SxZ/pSFqYrhIp3BkZzMyJ3fyJ9aIIL89 X-Received: by 10.181.13.147 with SMTP id ey19mr2392891wid.2.1421097654064; Mon, 12 Jan 2015 13:20:54 -0800 (PST) X-BeenThere: patchwork-forward@linaro.org Received: by 10.152.42.234 with SMTP id r10ls568775lal.17.gmail; Mon, 12 Jan 2015 13:20:53 -0800 (PST) X-Received: by 10.112.72.197 with SMTP id f5mr38272533lbv.21.1421097653895; Mon, 12 Jan 2015 13:20:53 -0800 (PST) Received: from mail-lb0-f173.google.com (mail-lb0-f173.google.com. [209.85.217.173]) by mx.google.com with ESMTPS id yi9si1092908lab.58.2015.01.12.13.20.53 for (version=TLSv1 cipher=ECDHE-RSA-RC4-SHA bits=128/128); Mon, 12 Jan 2015 13:20:53 -0800 (PST) Received-SPF: pass (google.com: domain of patch+caf_=patchwork-forward=linaro.org@linaro.org designates 209.85.217.173 as permitted sender) client-ip=209.85.217.173; Received: by mail-lb0-f173.google.com with SMTP id z12so19894720lbi.4 for ; Mon, 12 Jan 2015 13:20:53 -0800 (PST) X-Received: by 10.152.43.103 with SMTP id v7mr39087381lal.29.1421097653732; Mon, 12 Jan 2015 13:20:53 -0800 (PST) X-Forwarded-To: patchwork-forward@linaro.org X-Forwarded-For: patch@linaro.org patchwork-forward@linaro.org Delivered-To: patch@linaro.org Received: by 10.112.9.200 with SMTP id c8csp1195951lbb; Mon, 12 Jan 2015 13:20:52 -0800 (PST) X-Received: by 10.224.172.198 with SMTP id m6mr53140734qaz.11.1421097652055; Mon, 12 Jan 2015 13:20:52 -0800 (PST) Received: from ip-10-35-177-41.ec2.internal (lists.linaro.org. [54.225.227.206]) by mx.google.com with ESMTPS id k68si24140394qgf.66.2015.01.12.13.20.51 (version=TLSv1 cipher=RC4-SHA bits=128/128); Mon, 12 Jan 2015 13:20:52 -0800 (PST) Received-SPF: none (google.com: lng-odp-bounces@lists.linaro.org does not designate permitted sender hosts) client-ip=54.225.227.206; Received: from localhost ([127.0.0.1] helo=ip-10-35-177-41.ec2.internal) by ip-10-35-177-41.ec2.internal with esmtp (Exim 4.76) (envelope-from ) id 1YAmPo-0005zy-Ub; Mon, 12 Jan 2015 21:20:48 +0000 Received: from mail-lb0-f176.google.com ([209.85.217.176]) by ip-10-35-177-41.ec2.internal with esmtp (Exim 4.76) (envelope-from ) id 1YAmPi-0005zt-Fj for lng-odp@lists.linaro.org; Mon, 12 Jan 2015 21:20:42 +0000 Received: by mail-lb0-f176.google.com with SMTP id p9so19902542lbv.7 for ; Mon, 12 Jan 2015 13:20:36 -0800 (PST) X-Received: by 10.112.225.166 with SMTP id rl6mr38110037lbc.58.1421097636627; Mon, 12 Jan 2015 13:20:36 -0800 (PST) Received: from macmini.lan (78-82-118-111.tn.glocalnet.net. [78.82.118.111]) by mx.google.com with ESMTPSA id 10sm293336lar.24.2015.01.12.13.20.35 (version=TLSv1.2 cipher=ECDHE-RSA-AES128-SHA bits=128/128); Mon, 12 Jan 2015 13:20:36 -0800 (PST) From: Ola Liljedahl To: lng-odp@lists.linaro.org Date: Mon, 12 Jan 2015 22:20:57 +0100 Message-Id: <1421097657-7433-1-git-send-email-ola.liljedahl@linaro.org> X-Mailer: git-send-email 1.9.1 X-Topics: timers patch Subject: [lng-odp] [PATCH] test: timer: relaxed timing checks X-BeenThere: lng-odp@lists.linaro.org X-Mailman-Version: 2.1.14 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: , List-Help: , List-Subscribe: , MIME-Version: 1.0 Errors-To: lng-odp-bounces@lists.linaro.org Sender: lng-odp-bounces@lists.linaro.org X-Removed-Original-Auth: Dkim didn't pass. X-Original-Sender: ola.liljedahl@linaro.org X-Original-Authentication-Results: mx.google.com; spf=pass (google.com: domain of patch+caf_=patchwork-forward=linaro.org@linaro.org designates 209.85.217.173 as permitted sender) smtp.mail=patch+caf_=patchwork-forward=linaro.org@linaro.org Mailing-list: list patchwork-forward@linaro.org; contact patchwork-forward+owners@linaro.org X-Google-Group-Id: 836684582541 Don't report too late timeouts using CU_FAIL as this interferes with the cunit test framework. Just count and report (using LOG_DBG) the number of late timeouts. Use CU_ASSERT_FATAL instead of plain assert so to work wither with the cunit test framework. Don't dereference pointer after successful check for NULL as this makes Coverity complain. Use LOG_DBG instead of printf. Remove some unnecessary printouts. Use nanosleep instead of the deprecated usleep. Signed-off-by: Ola Liljedahl --- (This document/code contribution attached is provided under the terms of agreement LES-LTM-21309) test/validation/odp_timer.c | 102 +++++++++++++++++++++++++------------------- 1 file changed, 59 insertions(+), 43 deletions(-) diff --git a/test/validation/odp_timer.c b/test/validation/odp_timer.c index 4c93f71..d893646 100644 --- a/test/validation/odp_timer.c +++ b/test/validation/odp_timer.c @@ -8,10 +8,13 @@ * @file */ -#include +/* For rand_r and nanosleep */ +#define _POSIX_C_SOURCE 200112L +#include #include #include #include "odp_cunit_common.h" +#include "test_debug.h" /** @private Timeout range in milliseconds (ms) */ #define RANGE_MS 2000 @@ -28,6 +31,9 @@ static odp_buffer_pool_t tbp; /** @private Timer pool handle used by all threads */ static odp_timer_pool_t tp; +/** @private Count of timeouts delivered too late */ +static odp_atomic_u32_t ndelivtoolate; + /** @private min() function */ static int min(int a, int b) { @@ -47,8 +53,7 @@ struct test_timer { /* @private Handle a received (timeout) buffer */ static void handle_tmo(odp_buffer_t buf, bool stale, uint64_t prev_tick) { - /* Use assert() for internal correctness checks of test program */ - assert(buf != ODP_BUFFER_INVALID); + CU_ASSERT_FATAL(buf != ODP_BUFFER_INVALID); /* Internal error */ if (odp_buffer_type(buf) != ODP_BUFFER_TYPE_TIMEOUT) { /* Not a timeout buffer */ CU_FAIL("Unexpected buffer type received"); @@ -65,38 +70,41 @@ static void handle_tmo(odp_buffer_t buf, bool stale, uint64_t prev_tick) if (ttp == NULL) CU_FAIL("odp_timeout_user_ptr() null user ptr"); - if (ttp->buf2 != buf) + if (ttp != NULL && ttp->buf2 != buf) CU_FAIL("odp_timeout_user_ptr() wrong user ptr"); - if (ttp->tim != tim) + if (ttp != NULL && ttp->tim != tim) CU_FAIL("odp_timeout_timer() wrong timer"); if (stale) { if (odp_timeout_fresh(tmo)) CU_FAIL("Wrong status (fresh) for stale timeout"); /* Stale timeout => local timer must have invalid tick */ - if (ttp->tick != TICK_INVALID) + if (ttp != NULL && ttp->tick != TICK_INVALID) CU_FAIL("Stale timeout for active timer"); } else { if (!odp_timeout_fresh(tmo)) CU_FAIL("Wrong status (stale) for fresh timeout"); /* Fresh timeout => local timer must have matching tick */ - if (ttp->tick != tick) { - printf("Wrong tick: expected %"PRIu64" actual %"PRIu64"\n", - ttp->tick, tick); + if (ttp != NULL && ttp->tick != tick) { + LOG_DBG("Wrong tick: expected %"PRIu64" actual %"PRIu64"\n", + ttp->tick, tick); CU_FAIL("odp_timeout_tick() wrong tick"); } /* Check that timeout was delivered 'timely' */ if (tick > odp_timer_current_tick(tp)) CU_FAIL("Timeout delivered early"); if (tick < prev_tick) { - printf("Too late tick: %"PRIu64" prev_tick %"PRIu64"\n", - tick, prev_tick); - CU_FAIL("Timeout delivered late"); + LOG_DBG("Too late tick: %"PRIu64" prev_tick %"PRIu64"\n", + tick, prev_tick); + /* We don't report late timeouts using CU_FAIL */ + odp_atomic_inc_u32(&ndelivtoolate); } } - /* Use assert() for correctness check of test program itself */ - assert(ttp->buf == ODP_BUFFER_INVALID); - ttp->buf = buf; + if (ttp != NULL) { + /* Internal error */ + CU_ASSERT_FATAL(ttp->buf == ODP_BUFFER_INVALID); + ttp->buf = buf; + } } /* @private Worker thread entrypoint which performs timer alloc/set/cancel/free @@ -203,8 +211,11 @@ static void *worker_entrypoint(void *arg) /* Save expected expiration tick */ tt[i].tick = cur_tick + tck; } - if (usleep(1000/*1ms*/) < 0) - perror("usleep"), abort(); + struct timespec ts; + ts.tv_sec = 0; + ts.tv_nsec = 1000000; /* 1ms */ + if (nanosleep(&ts, NULL) < 0) + perror("nanosleep"), abort(); } /* Cancel and free all timers */ @@ -220,18 +231,22 @@ static void *worker_entrypoint(void *arg) CU_FAIL("odp_timer_free"); } - printf("Thread %u: %u timers set\n", thr, nset); - printf("Thread %u: %u timers reset\n", thr, nreset); - printf("Thread %u: %u timers cancelled\n", thr, ncancel); - printf("Thread %u: %u timers reset/cancelled too late\n", - thr, ntoolate); - printf("Thread %u: %u timeouts received\n", thr, nrcv); - printf("Thread %u: %u stale timeout(s) after odp_timer_free()\n", - thr, nstale); + LOG_DBG("Thread %u: %u timers set\n", thr, nset); + LOG_DBG("Thread %u: %u timers reset\n", thr, nreset); + LOG_DBG("Thread %u: %u timers cancelled\n", thr, ncancel); + LOG_DBG("Thread %u: %u timers reset/cancelled too late\n", + thr, ntoolate); + LOG_DBG("Thread %u: %u timeouts received\n", thr, nrcv); + LOG_DBG("Thread %u: %u stale timeout(s) after odp_timer_free()\n", + thr, nstale); /* Delay some more to ensure timeouts for expired timers can be * received */ - usleep(1000/*1ms*/); + struct timespec ts; + ts.tv_sec = 0; + ts.tv_nsec = 1000000; /* 1ms */ + if (nanosleep(&ts, NULL) < 0) + perror("nanosleep"), abort(); while (nstale != 0) { odp_buffer_t buf = odp_queue_deq(queue); if (buf != ODP_BUFFER_INVALID) { @@ -247,7 +262,7 @@ static void *worker_entrypoint(void *arg) if (buf != ODP_BUFFER_INVALID) CU_FAIL("Unexpected buffer received"); - printf("Thread %u: exiting\n", thr); + LOG_DBG("Thread %u: exiting\n", thr); return NULL; } @@ -256,9 +271,13 @@ static void test_odp_timer_all(void) { odp_buffer_pool_param_t params; odp_timer_pool_param_t tparam; - /* This is a stressfull test - need to reserve some cpu cycles - * @TODO move to test/performance */ - int num_workers = min(odp_sys_cpu_count()-1, MAX_WORKERS); + /* Reserve at least one core for running other processes so the timer + * test hopefully can run undisturbed and thus get better timing + * results. */ + int num_workers = min(odp_sys_cpu_count() - 1, MAX_WORKERS); + /* On a single-CPU machine run at least one thread */ + if (num_workers < 1) + num_workers = 1; /* Create timeout buffer pools */ params.buf_size = 0; @@ -294,19 +313,11 @@ static void test_odp_timer_all(void) CU_ASSERT(tpinfo.param.res_ns == RES); CU_ASSERT(tpinfo.param.min_tmo == MIN); CU_ASSERT(tpinfo.param.max_tmo == MAX); - printf("Timer pool\n"); - printf("----------\n"); - printf(" name: %s\n", tpinfo.name); - printf(" resolution: %"PRIu64" ns (%"PRIu64" us)\n", - tpinfo.param.res_ns, tpinfo.param.res_ns / 1000); - printf(" min tmo: %"PRIu64" ns\n", tpinfo.param.min_tmo); - printf(" max tmo: %"PRIu64" ns\n", tpinfo.param.max_tmo); - printf("\n"); - - printf("#timers..: %u\n", NTIMERS); - printf("Tmo range: %u ms (%"PRIu64" ticks)\n", RANGE_MS, - odp_timer_ns_to_tick(tp, 1000000ULL * RANGE_MS)); - printf("\n"); + CU_ASSERT(strcmp(tpinfo.name, NAME) == 0); + + LOG_DBG("#timers..: %u\n", NTIMERS); + LOG_DBG("Tmo range: %u ms (%"PRIu64" ticks)\n", RANGE_MS, + odp_timer_ns_to_tick(tp, 1000000ULL * RANGE_MS)); uint64_t tick; for (tick = 0; tick < 1000000000000ULL; tick += 1000000ULL) { @@ -319,6 +330,9 @@ static void test_odp_timer_all(void) /* Initialize barrier used by worker threads for synchronization */ odp_barrier_init(&test_barrier, num_workers); + /* Initialize the shared timeout counter */ + odp_atomic_init_u32(&ndelivtoolate, 0); + /* Create and start worker threads */ pthrd_arg thrdarg; thrdarg.testcase = 0; @@ -327,6 +341,8 @@ static void test_odp_timer_all(void) /* Wait for worker threads to exit */ odp_cunit_thread_exit(&thrdarg); + LOG_DBG("Number of timeouts delivered/received too late: %u\n", + odp_atomic_load_u32(&ndelivtoolate)); /* Check some statistics after the test */ if (odp_timer_pool_info(tp, &tpinfo) != 0)