| Message ID | 1463052176-16065-1-git-send-email-maxim.uvarov@linaro.org |
|---|---|
| State | Accepted |
| Commit | acb74de4a59522289d7cf3c1735a84864451d181 |
| Headers | show |
On Thu, May 12, 2016 at 6:22 AM, Maxim Uvarov <maxim.uvarov@linaro.org> wrote: > Having system call inside loop couse unpredictable delay > as the result wrong time diff calculation. Just removing > print make hole test execution shorter on 0.1 seconds > according to cunit stats. Also make verbose errors in > places where we out of limit in cunit. This should be > very helpful to understand DELAY_TOLERANCE value suitable > for all platforms. > > Signed-off-by: Maxim Uvarov <maxim.uvarov@linaro.org> > Reviewed-by: Bill Fischofer <bill.fischofer@linaro.org> > --- > test/validation/time/time.c | 35 +++++++++++++++++++++++++++-------- > 1 file changed, 27 insertions(+), 8 deletions(-) > > diff --git a/test/validation/time/time.c b/test/validation/time/time.c > index da456ea..f7f3d14 100644 > --- a/test/validation/time/time.c > +++ b/test/validation/time/time.c > @@ -331,7 +331,6 @@ static void time_test_wait_until(time_cb time, > time_from_ns_cb time_from_ns) > for (i = 0; i < WAIT_SECONDS; i++) { > wait = odp_time_sum(wait, second); > odp_time_wait_until(wait); > - printf("%d..", i + 1); > } > end_time = time(); > > @@ -341,8 +340,19 @@ static void time_test_wait_until(time_cb time, > time_from_ns_cb time_from_ns) > upper_limit = time_from_ns(WAIT_SECONDS * ODP_TIME_SEC_IN_NS + > DELAY_TOLERANCE); > > - CU_ASSERT(odp_time_cmp(wait, lower_limit) >= 0); > - CU_ASSERT(odp_time_cmp(wait, upper_limit) <= 0); > + if (odp_time_cmp(wait, lower_limit) < 0) { > + fprintf(stderr, "Exceed lower limit: " > + "wait is %" PRIu64 ", lower_limit %" PRIu64 "\n", > + odp_time_to_ns(wait), odp_time_to_ns(lower_limit)); > + CU_FAIL("Exceed lower limit\n"); > + } > + > + if (odp_time_cmp(wait, upper_limit) > 0) { > + fprintf(stderr, "Exceed upper limit: " > + "wait is %" PRIu64 ", upper_limit %" PRIu64 "\n", > + odp_time_to_ns(wait), odp_time_to_ns(lower_limit)); > + CU_FAIL("Exceed upper limit\n"); > + } > } > > void time_test_local_wait_until(void) > @@ -362,10 +372,8 @@ void time_test_wait_ns(void) > odp_time_t start_time, end_time, diff; > > start_time = odp_time_local(); > - for (i = 0; i < WAIT_SECONDS; i++) { > + for (i = 0; i < WAIT_SECONDS; i++) > odp_time_wait_ns(ODP_TIME_SEC_IN_NS); > - printf("%d..", i + 1); > - } > end_time = odp_time_local(); > > diff = odp_time_diff(end_time, start_time); > @@ -375,8 +383,19 @@ void time_test_wait_ns(void) > upper_limit = odp_time_local_from_ns(WAIT_SECONDS * > ODP_TIME_SEC_IN_NS + > DELAY_TOLERANCE); > > - CU_ASSERT(odp_time_cmp(diff, lower_limit) >= 0); > - CU_ASSERT(odp_time_cmp(diff, upper_limit) <= 0); > + if (odp_time_cmp(diff, lower_limit) < 0) { > + fprintf(stderr, "Exceed lower limit: " > + "diff is %" PRIu64 ", lower_limit %" PRIu64 "\n", > + odp_time_to_ns(diff), odp_time_to_ns(lower_limit)); > + CU_FAIL("Exceed lower limit\n"); > + } > + > + if (odp_time_cmp(diff, upper_limit) > 0) { > + fprintf(stderr, "Exceed upper limit: " > + "diff is %" PRIu64 ", upper_limit %" PRIu64 "\n", > + odp_time_to_ns(diff), odp_time_to_ns(lower_limit)); > + CU_FAIL("Exceed upper limit\n"); > + } > } > > static void time_test_to_u64(time_cb time) > -- > 2.7.1.250.gff4ea60 > > _______________________________________________ > lng-odp mailing list > lng-odp@lists.linaro.org > https://lists.linaro.org/mailman/listinfo/lng-odp >
Merged, Maxim. On 05/12/16 22:05, Bill Fischofer wrote: > > > On Thu, May 12, 2016 at 6:22 AM, Maxim Uvarov <maxim.uvarov@linaro.org > <mailto:maxim.uvarov@linaro.org>> wrote: > > Having system call inside loop couse unpredictable delay > as the result wrong time diff calculation. Just removing > print make hole test execution shorter on 0.1 seconds > according to cunit stats. Also make verbose errors in > places where we out of limit in cunit. This should be > very helpful to understand DELAY_TOLERANCE value suitable > for all platforms. > > Signed-off-by: Maxim Uvarov <maxim.uvarov@linaro.org > <mailto:maxim.uvarov@linaro.org>> > > > Reviewed-by: Bill Fischofer <bill.fischofer@linaro.org > <mailto:bill.fischofer@linaro.org>> > > --- > test/validation/time/time.c | 35 +++++++++++++++++++++++++++-------- > 1 file changed, 27 insertions(+), 8 deletions(-) > > diff --git a/test/validation/time/time.c b/test/validation/time/time.c > index da456ea..f7f3d14 100644 > --- a/test/validation/time/time.c > +++ b/test/validation/time/time.c > @@ -331,7 +331,6 @@ static void time_test_wait_until(time_cb time, > time_from_ns_cb time_from_ns) > for (i = 0; i < WAIT_SECONDS; i++) { > wait = odp_time_sum(wait, second); > odp_time_wait_until(wait); > - printf("%d..", i + 1); > } > end_time = time(); > > @@ -341,8 +340,19 @@ static void time_test_wait_until(time_cb > time, time_from_ns_cb time_from_ns) > upper_limit = time_from_ns(WAIT_SECONDS * ODP_TIME_SEC_IN_NS + > DELAY_TOLERANCE); > > - CU_ASSERT(odp_time_cmp(wait, lower_limit) >= 0); > - CU_ASSERT(odp_time_cmp(wait, upper_limit) <= 0); > + if (odp_time_cmp(wait, lower_limit) < 0) { > + fprintf(stderr, "Exceed lower limit: " > + "wait is %" PRIu64 ", lower_limit %" > PRIu64 "\n", > + odp_time_to_ns(wait), > odp_time_to_ns(lower_limit)); > + CU_FAIL("Exceed lower limit\n"); > + } > + > + if (odp_time_cmp(wait, upper_limit) > 0) { > + fprintf(stderr, "Exceed upper limit: " > + "wait is %" PRIu64 ", upper_limit %" > PRIu64 "\n", > + odp_time_to_ns(wait), > odp_time_to_ns(lower_limit)); > + CU_FAIL("Exceed upper limit\n"); > + } > } > > void time_test_local_wait_until(void) > @@ -362,10 +372,8 @@ void time_test_wait_ns(void) > odp_time_t start_time, end_time, diff; > > start_time = odp_time_local(); > - for (i = 0; i < WAIT_SECONDS; i++) { > + for (i = 0; i < WAIT_SECONDS; i++) > odp_time_wait_ns(ODP_TIME_SEC_IN_NS); > - printf("%d..", i + 1); > - } > end_time = odp_time_local(); > > diff = odp_time_diff(end_time, start_time); > @@ -375,8 +383,19 @@ void time_test_wait_ns(void) > upper_limit = odp_time_local_from_ns(WAIT_SECONDS * > ODP_TIME_SEC_IN_NS + > DELAY_TOLERANCE); > > - CU_ASSERT(odp_time_cmp(diff, lower_limit) >= 0); > - CU_ASSERT(odp_time_cmp(diff, upper_limit) <= 0); > + if (odp_time_cmp(diff, lower_limit) < 0) { > + fprintf(stderr, "Exceed lower limit: " > + "diff is %" PRIu64 ", lower_limit %" > PRIu64 "\n", > + odp_time_to_ns(diff), > odp_time_to_ns(lower_limit)); > + CU_FAIL("Exceed lower limit\n"); > + } > + > + if (odp_time_cmp(diff, upper_limit) > 0) { > + fprintf(stderr, "Exceed upper limit: " > + "diff is %" PRIu64 ", upper_limit %" > PRIu64 "\n", > + odp_time_to_ns(diff), > odp_time_to_ns(lower_limit)); > + CU_FAIL("Exceed upper limit\n"); > + } > } > > static void time_test_to_u64(time_cb time) > -- > 2.7.1.250.gff4ea60 > > _______________________________________________ > lng-odp mailing list > lng-odp@lists.linaro.org <mailto:lng-odp@lists.linaro.org> > https://lists.linaro.org/mailman/listinfo/lng-odp > >
Hi Maxim, I know it's a little late, but printf was here not for testing wait until. It was here to expose visually time for a second. As ODP doesn't have other accurate enough time source the printf was added to visually demonstrate 1 second. It allows to see if at least frequency of counter was chosen correctly, as it's most frequent error while time API implementation. It can be easily broken even later while simple setting of some clock divider to wrong value, usually in two times more or less. That's enough to see with human eye. I think this ability is more needed then saving of some 0.1 second. On 12.05.16 14:22, Maxim Uvarov wrote: > Having system call inside loop couse unpredictable delay > as the result wrong time diff calculation. Just removing > print make hole test execution shorter on 0.1 seconds > according to cunit stats. Also make verbose errors in > places where we out of limit in cunit. This should be > very helpful to understand DELAY_TOLERANCE value suitable > for all platforms. > > Signed-off-by: Maxim Uvarov <maxim.uvarov@linaro.org> > --- > test/validation/time/time.c | 35 +++++++++++++++++++++++++++-------- > 1 file changed, 27 insertions(+), 8 deletions(-) > > diff --git a/test/validation/time/time.c b/test/validation/time/time.c > index da456ea..f7f3d14 100644 > --- a/test/validation/time/time.c > +++ b/test/validation/time/time.c > @@ -331,7 +331,6 @@ static void time_test_wait_until(time_cb time, time_from_ns_cb time_from_ns) > for (i = 0; i < WAIT_SECONDS; i++) { > wait = odp_time_sum(wait, second); > odp_time_wait_until(wait); > - printf("%d..", i + 1); > } > end_time = time(); > > @@ -341,8 +340,19 @@ static void time_test_wait_until(time_cb time, time_from_ns_cb time_from_ns) > upper_limit = time_from_ns(WAIT_SECONDS * ODP_TIME_SEC_IN_NS + > DELAY_TOLERANCE); > > - CU_ASSERT(odp_time_cmp(wait, lower_limit) >= 0); > - CU_ASSERT(odp_time_cmp(wait, upper_limit) <= 0); > + if (odp_time_cmp(wait, lower_limit) < 0) { > + fprintf(stderr, "Exceed lower limit: " > + "wait is %" PRIu64 ", lower_limit %" PRIu64 "\n", > + odp_time_to_ns(wait), odp_time_to_ns(lower_limit)); > + CU_FAIL("Exceed lower limit\n"); > + } > + > + if (odp_time_cmp(wait, upper_limit) > 0) { > + fprintf(stderr, "Exceed upper limit: " > + "wait is %" PRIu64 ", upper_limit %" PRIu64 "\n", > + odp_time_to_ns(wait), odp_time_to_ns(lower_limit)); > + CU_FAIL("Exceed upper limit\n"); > + } > } > > void time_test_local_wait_until(void) > @@ -362,10 +372,8 @@ void time_test_wait_ns(void) > odp_time_t start_time, end_time, diff; > > start_time = odp_time_local(); > - for (i = 0; i < WAIT_SECONDS; i++) { > + for (i = 0; i < WAIT_SECONDS; i++) > odp_time_wait_ns(ODP_TIME_SEC_IN_NS); > - printf("%d..", i + 1); > - } > end_time = odp_time_local(); > > diff = odp_time_diff(end_time, start_time); > @@ -375,8 +383,19 @@ void time_test_wait_ns(void) > upper_limit = odp_time_local_from_ns(WAIT_SECONDS * ODP_TIME_SEC_IN_NS + > DELAY_TOLERANCE); > > - CU_ASSERT(odp_time_cmp(diff, lower_limit) >= 0); > - CU_ASSERT(odp_time_cmp(diff, upper_limit) <= 0); > + if (odp_time_cmp(diff, lower_limit) < 0) { > + fprintf(stderr, "Exceed lower limit: " > + "diff is %" PRIu64 ", lower_limit %" PRIu64 "\n", > + odp_time_to_ns(diff), odp_time_to_ns(lower_limit)); > + CU_FAIL("Exceed lower limit\n"); > + } > + > + if (odp_time_cmp(diff, upper_limit) > 0) { > + fprintf(stderr, "Exceed upper limit: " > + "diff is %" PRIu64 ", upper_limit %" PRIu64 "\n", > + odp_time_to_ns(diff), odp_time_to_ns(lower_limit)); > + CU_FAIL("Exceed upper limit\n"); > + } > } > > static void time_test_to_u64(time_cb time) >
On 05/16/16 17:00, Ivan Khoronzhuk wrote: > Hi Maxim, > > I know it's a little late, but printf was here not for testing wait > until. > It was here to expose visually time for a second. As ODP doesn't have > other accurate enough time source the printf was added to visually > demonstrate > 1 second. It allows to see if at least frequency of counter was chosen > correctly, > as it's most frequent error while time API implementation. It can be > easily broken > even later while simple setting of some clock divider to wrong value, > usually in > two times more or less. That's enough to see with human eye. I think > this ability > is more needed then saving of some 0.1 second. > In my understanding it saves time between start() and end() measurements which can be result of not passing border check. I think that if test hangs for some long time you anyway need to add some debug prints or stop it with gdb and see where exactly it was stopped. Maybe do add separate test which prints/verify odp_time and linux system time? Maxim. > On 12.05.16 14:22, Maxim Uvarov wrote: >> Having system call inside loop couse unpredictable delay >> as the result wrong time diff calculation. Just removing >> print make hole test execution shorter on 0.1 seconds >> according to cunit stats. Also make verbose errors in >> places where we out of limit in cunit. This should be >> very helpful to understand DELAY_TOLERANCE value suitable >> for all platforms. >> >> Signed-off-by: Maxim Uvarov <maxim.uvarov@linaro.org> >> --- >> test/validation/time/time.c | 35 +++++++++++++++++++++++++++-------- >> 1 file changed, 27 insertions(+), 8 deletions(-) >> >> diff --git a/test/validation/time/time.c b/test/validation/time/time.c >> index da456ea..f7f3d14 100644 >> --- a/test/validation/time/time.c >> +++ b/test/validation/time/time.c >> @@ -331,7 +331,6 @@ static void time_test_wait_until(time_cb time, >> time_from_ns_cb time_from_ns) >> for (i = 0; i < WAIT_SECONDS; i++) { >> wait = odp_time_sum(wait, second); >> odp_time_wait_until(wait); >> - printf("%d..", i + 1); >> } >> end_time = time(); >> >> @@ -341,8 +340,19 @@ static void time_test_wait_until(time_cb time, >> time_from_ns_cb time_from_ns) >> upper_limit = time_from_ns(WAIT_SECONDS * ODP_TIME_SEC_IN_NS + >> DELAY_TOLERANCE); >> >> - CU_ASSERT(odp_time_cmp(wait, lower_limit) >= 0); >> - CU_ASSERT(odp_time_cmp(wait, upper_limit) <= 0); >> + if (odp_time_cmp(wait, lower_limit) < 0) { >> + fprintf(stderr, "Exceed lower limit: " >> + "wait is %" PRIu64 ", lower_limit %" PRIu64 "\n", >> + odp_time_to_ns(wait), odp_time_to_ns(lower_limit)); >> + CU_FAIL("Exceed lower limit\n"); >> + } >> + >> + if (odp_time_cmp(wait, upper_limit) > 0) { >> + fprintf(stderr, "Exceed upper limit: " >> + "wait is %" PRIu64 ", upper_limit %" PRIu64 "\n", >> + odp_time_to_ns(wait), odp_time_to_ns(lower_limit)); >> + CU_FAIL("Exceed upper limit\n"); >> + } >> } >> >> void time_test_local_wait_until(void) >> @@ -362,10 +372,8 @@ void time_test_wait_ns(void) >> odp_time_t start_time, end_time, diff; >> >> start_time = odp_time_local(); >> - for (i = 0; i < WAIT_SECONDS; i++) { >> + for (i = 0; i < WAIT_SECONDS; i++) >> odp_time_wait_ns(ODP_TIME_SEC_IN_NS); >> - printf("%d..", i + 1); >> - } >> end_time = odp_time_local(); >> >> diff = odp_time_diff(end_time, start_time); >> @@ -375,8 +383,19 @@ void time_test_wait_ns(void) >> upper_limit = odp_time_local_from_ns(WAIT_SECONDS * >> ODP_TIME_SEC_IN_NS + >> DELAY_TOLERANCE); >> >> - CU_ASSERT(odp_time_cmp(diff, lower_limit) >= 0); >> - CU_ASSERT(odp_time_cmp(diff, upper_limit) <= 0); >> + if (odp_time_cmp(diff, lower_limit) < 0) { >> + fprintf(stderr, "Exceed lower limit: " >> + "diff is %" PRIu64 ", lower_limit %" PRIu64 "\n", >> + odp_time_to_ns(diff), odp_time_to_ns(lower_limit)); >> + CU_FAIL("Exceed lower limit\n"); >> + } >> + >> + if (odp_time_cmp(diff, upper_limit) > 0) { >> + fprintf(stderr, "Exceed upper limit: " >> + "diff is %" PRIu64 ", upper_limit %" PRIu64 "\n", >> + odp_time_to_ns(diff), odp_time_to_ns(lower_limit)); >> + CU_FAIL("Exceed upper limit\n"); >> + } >> } >> >> static void time_test_to_u64(time_cb time) >> >
On 16.05.16 17:18, Maxim Uvarov wrote: > On 05/16/16 17:00, Ivan Khoronzhuk wrote: >> Hi Maxim, >> >> I know it's a little late, but printf was here not for testing wait until. >> It was here to expose visually time for a second. As ODP doesn't have >> other accurate enough time source the printf was added to visually demonstrate >> 1 second. It allows to see if at least frequency of counter was chosen correctly, >> as it's most frequent error while time API implementation. It can be easily broken >> even later while simple setting of some clock divider to wrong value, usually in >> two times more or less. That's enough to see with human eye. I think this ability >> is more needed then saving of some 0.1 second. >> > > In my understanding it saves time between start() and end() measurements which > can be result of not passing border check. The border check is was done with CU_ASSERT. Was it not enough? I think that if test hangs for some long > time you anyway need to add some debug prints or stop it with gdb and see where > exactly it was stopped. The idea not simply print every second...that's indicator that test is running also, but also to demonstrate sens of 1 second. The *_until APIs are verified with odp_time APIs checked previously, that is, one part of time API is checked with another part of time API ))... and print real second while doing this....in case of error in both parts, you will never catch an error with validation test w/o sense of time or another source. Another source is absent, so only way - print it....at least it allows to see some part of possible errors. Maybe do add separate test which prints/verify odp_time and > linux system time? not sure, ODP can run w/o linux, so validation test should be independent. And adding new test only increases time of testing, so better to do it in same cycle. > > Maxim. > >> On 12.05.16 14:22, Maxim Uvarov wrote: >>> Having system call inside loop couse unpredictable delay >>> as the result wrong time diff calculation. Just removing >>> print make hole test execution shorter on 0.1 seconds >>> according to cunit stats. Also make verbose errors in >>> places where we out of limit in cunit. This should be >>> very helpful to understand DELAY_TOLERANCE value suitable >>> for all platforms. >>> >>> Signed-off-by: Maxim Uvarov <maxim.uvarov@linaro.org> >>> --- >>> test/validation/time/time.c | 35 +++++++++++++++++++++++++++-------- >>> 1 file changed, 27 insertions(+), 8 deletions(-) >>> >>> diff --git a/test/validation/time/time.c b/test/validation/time/time.c >>> index da456ea..f7f3d14 100644 >>> --- a/test/validation/time/time.c >>> +++ b/test/validation/time/time.c >>> @@ -331,7 +331,6 @@ static void time_test_wait_until(time_cb time, time_from_ns_cb time_from_ns) >>> for (i = 0; i < WAIT_SECONDS; i++) { >>> wait = odp_time_sum(wait, second); >>> odp_time_wait_until(wait); >>> - printf("%d..", i + 1); >>> } >>> end_time = time(); >>> >>> @@ -341,8 +340,19 @@ static void time_test_wait_until(time_cb time, time_from_ns_cb time_from_ns) >>> upper_limit = time_from_ns(WAIT_SECONDS * ODP_TIME_SEC_IN_NS + >>> DELAY_TOLERANCE); >>> >>> - CU_ASSERT(odp_time_cmp(wait, lower_limit) >= 0); >>> - CU_ASSERT(odp_time_cmp(wait, upper_limit) <= 0); >>> + if (odp_time_cmp(wait, lower_limit) < 0) { >>> + fprintf(stderr, "Exceed lower limit: " >>> + "wait is %" PRIu64 ", lower_limit %" PRIu64 "\n", >>> + odp_time_to_ns(wait), odp_time_to_ns(lower_limit)); >>> + CU_FAIL("Exceed lower limit\n"); >>> + } >>> + >>> + if (odp_time_cmp(wait, upper_limit) > 0) { >>> + fprintf(stderr, "Exceed upper limit: " >>> + "wait is %" PRIu64 ", upper_limit %" PRIu64 "\n", >>> + odp_time_to_ns(wait), odp_time_to_ns(lower_limit)); >>> + CU_FAIL("Exceed upper limit\n"); >>> + } >>> } >>> >>> void time_test_local_wait_until(void) >>> @@ -362,10 +372,8 @@ void time_test_wait_ns(void) >>> odp_time_t start_time, end_time, diff; >>> >>> start_time = odp_time_local(); >>> - for (i = 0; i < WAIT_SECONDS; i++) { >>> + for (i = 0; i < WAIT_SECONDS; i++) >>> odp_time_wait_ns(ODP_TIME_SEC_IN_NS); >>> - printf("%d..", i + 1); >>> - } >>> end_time = odp_time_local(); >>> >>> diff = odp_time_diff(end_time, start_time); >>> @@ -375,8 +383,19 @@ void time_test_wait_ns(void) >>> upper_limit = odp_time_local_from_ns(WAIT_SECONDS * ODP_TIME_SEC_IN_NS + >>> DELAY_TOLERANCE); >>> >>> - CU_ASSERT(odp_time_cmp(diff, lower_limit) >= 0); >>> - CU_ASSERT(odp_time_cmp(diff, upper_limit) <= 0); >>> + if (odp_time_cmp(diff, lower_limit) < 0) { >>> + fprintf(stderr, "Exceed lower limit: " >>> + "diff is %" PRIu64 ", lower_limit %" PRIu64 "\n", >>> + odp_time_to_ns(diff), odp_time_to_ns(lower_limit)); >>> + CU_FAIL("Exceed lower limit\n"); >>> + } >>> + >>> + if (odp_time_cmp(diff, upper_limit) > 0) { >>> + fprintf(stderr, "Exceed upper limit: " >>> + "diff is %" PRIu64 ", upper_limit %" PRIu64 "\n", >>> + odp_time_to_ns(diff), odp_time_to_ns(lower_limit)); >>> + CU_FAIL("Exceed upper limit\n"); >>> + } >>> } >>> >>> static void time_test_to_u64(time_cb time) >>> >> >
diff --git a/test/validation/time/time.c b/test/validation/time/time.c index da456ea..f7f3d14 100644 --- a/test/validation/time/time.c +++ b/test/validation/time/time.c @@ -331,7 +331,6 @@ static void time_test_wait_until(time_cb time, time_from_ns_cb time_from_ns) for (i = 0; i < WAIT_SECONDS; i++) { wait = odp_time_sum(wait, second); odp_time_wait_until(wait); - printf("%d..", i + 1); } end_time = time(); @@ -341,8 +340,19 @@ static void time_test_wait_until(time_cb time, time_from_ns_cb time_from_ns) upper_limit = time_from_ns(WAIT_SECONDS * ODP_TIME_SEC_IN_NS + DELAY_TOLERANCE); - CU_ASSERT(odp_time_cmp(wait, lower_limit) >= 0); - CU_ASSERT(odp_time_cmp(wait, upper_limit) <= 0); + if (odp_time_cmp(wait, lower_limit) < 0) { + fprintf(stderr, "Exceed lower limit: " + "wait is %" PRIu64 ", lower_limit %" PRIu64 "\n", + odp_time_to_ns(wait), odp_time_to_ns(lower_limit)); + CU_FAIL("Exceed lower limit\n"); + } + + if (odp_time_cmp(wait, upper_limit) > 0) { + fprintf(stderr, "Exceed upper limit: " + "wait is %" PRIu64 ", upper_limit %" PRIu64 "\n", + odp_time_to_ns(wait), odp_time_to_ns(lower_limit)); + CU_FAIL("Exceed upper limit\n"); + } } void time_test_local_wait_until(void) @@ -362,10 +372,8 @@ void time_test_wait_ns(void) odp_time_t start_time, end_time, diff; start_time = odp_time_local(); - for (i = 0; i < WAIT_SECONDS; i++) { + for (i = 0; i < WAIT_SECONDS; i++) odp_time_wait_ns(ODP_TIME_SEC_IN_NS); - printf("%d..", i + 1); - } end_time = odp_time_local(); diff = odp_time_diff(end_time, start_time); @@ -375,8 +383,19 @@ void time_test_wait_ns(void) upper_limit = odp_time_local_from_ns(WAIT_SECONDS * ODP_TIME_SEC_IN_NS + DELAY_TOLERANCE); - CU_ASSERT(odp_time_cmp(diff, lower_limit) >= 0); - CU_ASSERT(odp_time_cmp(diff, upper_limit) <= 0); + if (odp_time_cmp(diff, lower_limit) < 0) { + fprintf(stderr, "Exceed lower limit: " + "diff is %" PRIu64 ", lower_limit %" PRIu64 "\n", + odp_time_to_ns(diff), odp_time_to_ns(lower_limit)); + CU_FAIL("Exceed lower limit\n"); + } + + if (odp_time_cmp(diff, upper_limit) > 0) { + fprintf(stderr, "Exceed upper limit: " + "diff is %" PRIu64 ", upper_limit %" PRIu64 "\n", + odp_time_to_ns(diff), odp_time_to_ns(lower_limit)); + CU_FAIL("Exceed upper limit\n"); + } } static void time_test_to_u64(time_cb time)
Having system call inside loop couse unpredictable delay as the result wrong time diff calculation. Just removing print make hole test execution shorter on 0.1 seconds according to cunit stats. Also make verbose errors in places where we out of limit in cunit. This should be very helpful to understand DELAY_TOLERANCE value suitable for all platforms. Signed-off-by: Maxim Uvarov <maxim.uvarov@linaro.org> --- test/validation/time/time.c | 35 +++++++++++++++++++++++++++-------- 1 file changed, 27 insertions(+), 8 deletions(-)