[PATCH v8] Fix time/tst-cpuclock1 intermitent failures
Lucas A. M. Magalhaes
lamm@linux.ibm.com
Thu Apr 16 17:30:05 GMT 2020
PING.
Sorry Carlos, I forgot to copy you on this patch.
Quoting Lucas A. M. Magalhaes via Libc-alpha (2020-04-07 10:59:47)
> This test fails intermittently in systems with heavy load as
> CLOCK_PROCESS_CPUTIME_ID is subject to scheduler pressure. Thus the
> test boundaries were relaxed to keep it from failing on such systems.
>
> A refactor of the spent time checking was made with some support
> functions. With the advantage to representing time jitter in percent
> of the target.
>
> The values used by the test boundaries are all empirical.
>
> ---
>
> Hi Carlos,
> Thanks for the work and patience on this reviews.
>
> changes on V8:
> Add support_timespec_ns
> Add more tests
>
> changes on V7:
> - change expecting boundaries
> - add comments
>
> changes on V6:
> - add overflow handling
> - change variables names
>
> changes on V5:
> - add tests for support_timespec_check_in_range
> - fix support_timespec_normalize
> - add comments
> - fix style
>
> changes on V4:
> - move functions to support/timespec.c
> - simplify functions
>
> changes on V3:
> - refactor support functions
> - use existing timespec-sub function
>
> changes on V2:
> - Add support functions
> ---
> support/Makefile | 1 +
> support/timespec.c | 59 ++++++++++
> support/timespec.h | 8 ++
> support/tst-timespec.c | 241 +++++++++++++++++++++++++++++++++++++++++
> time/tst-cpuclock1.c | 48 +++-----
> 5 files changed, 327 insertions(+), 30 deletions(-)
> create mode 100644 support/tst-timespec.c
>
> diff --git a/support/Makefile b/support/Makefile
> index 6e38b87ebe..cacaac96a5 100644
> --- a/support/Makefile
> +++ b/support/Makefile
> @@ -233,6 +233,7 @@ tests = \
> tst-test_compare \
> tst-test_compare_blob \
> tst-test_compare_string \
> + tst-timespec \
> tst-xreadlink \
> tst-xsigstack \
>
> diff --git a/support/timespec.c b/support/timespec.c
> index ea6b947546..156a409733 100644
> --- a/support/timespec.c
> +++ b/support/timespec.c
> @@ -19,6 +19,8 @@
> #include <support/timespec.h>
> #include <stdio.h>
> #include <stdint.h>
> +#include <assert.h>
> +#include <intprops.h>
>
> void
> test_timespec_before_impl (const char *file, int line,
> @@ -57,3 +59,60 @@ test_timespec_equal_or_after_impl (const char *file, int line,
> (intmax_t) diff.tv_sec, (intmax_t) diff.tv_nsec);
> }
> }
> +
> +/* Convert TIME to nanoseconds stored in shrinked. */
> +long
> +support_timespec_ns (struct timespec time)
> +{
> + long time_ns;
> + if (INT_MULTIPLY_WRAPV(time.tv_sec, TIMESPEC_HZ, &time_ns))
> + {
> + time_ns = (time.tv_sec < 0) ? TYPE_MINIMUM(long): TYPE_MAXIMUM(long);
> + }
> + if (INT_ADD_WRAPV(time_ns, time.tv_nsec, &time_ns))
> + {
> + time_ns = (time.tv_nsec < 0) ? TYPE_MINIMUM(long): TYPE_MAXIMUM(long);
> + }
> + return time_ns;
> +}
> +
> +/* Returns t normalized timespec with .tv_nsec < TIMESPEC_HZ
> + and the overflows added to .tv_sec. It assumes times are
> + positive. */
> +struct timespec
> +support_timespec_normalize (struct timespec time)
> +{
> + struct timespec norm;
> + if (INT_ADD_WRAPV (time.tv_sec, (time.tv_nsec / TIMESPEC_HZ), &norm.tv_sec))
> + {
> + norm.tv_sec = (time.tv_nsec < 0) ? TYPE_MINIMUM (time_t):TYPE_MAXIMUM (time_t);
> + }
> + norm.tv_nsec = time.tv_nsec % TIMESPEC_HZ;
> + return norm;
> +}
> +
> +/* Returns TRUE if the observed time is within the given percentage bounds of
> +the expected time, and FALSE otherwise.
> +For example the call
> +
> +support_timespec_check_in_range(expected, observed, .5, 1.2);
> +
> +will check if
> +
> +.5 <= observed/expected <= 1.2
> +
> +In other words it will check if observed time is within 50% to 120% of
> +the expected time. */
> +int
> +support_timespec_check_in_range (struct timespec expected, struct timespec observed,
> + double lower_bound, double upper_bound)
> +{
> + assert (upper_bound >= lower_bound);
> + long expected_norm, observed_norm;
> + expected_norm = support_timespec_ns (expected);
> + /* Don't divide by zero */
> + assert(expected_norm != 0);
> + observed_norm = support_timespec_ns (observed);
> + double ratio = (double)observed_norm / expected_norm;
> + return (lower_bound <= ratio && ratio <= upper_bound);
> +}
> diff --git a/support/timespec.h b/support/timespec.h
> index c5852dfe75..fd5466745d 100644
> --- a/support/timespec.h
> +++ b/support/timespec.h
> @@ -48,6 +48,14 @@ void test_timespec_equal_or_after_impl (const char *file, int line,
> const struct timespec left,
> const struct timespec right);
>
> +long support_timespec_ns (struct timespec time);
> +
> +struct timespec support_timespec_normalize (struct timespec time);
> +
> +int support_timespec_check_in_range (struct timespec expected, struct timespec observed,
> + double lower_bound, double upper_bound);
> +
> +
> /* Check that the timespec on the left represents a time before the
> time on the right. */
> #define TEST_TIMESPEC_BEFORE(left, right) \
> diff --git a/support/tst-timespec.c b/support/tst-timespec.c
> new file mode 100644
> index 0000000000..e9f21e6e35
> --- /dev/null
> +++ b/support/tst-timespec.c
> @@ -0,0 +1,241 @@
> +/* Test for support_timespec_check_in_range function.
> + Copyright (C) 2020 Free Software Foundation, Inc.
> + This file is part of the GNU C Library.
> +
> + The GNU C Library is free software; you can redistribute it and/or
> + modify it under the terms of the GNU Lesser General Public
> + License as published by the Free Software Foundation; either
> + version 2.1 of the License, or (at your option) any later version.
> +
> + The GNU C Library is distributed in the hope that it will be useful,
> + but WITHOUT ANY WARRANTY; without even the implied warranty of
> + MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
> + Lesser General Public License for more details.
> +
> + You should have received a copy of the GNU Lesser General Public
> + License along with the GNU C Library; if not, see
> + <https://www.gnu.org/licenses/>. */
> +
> +#include <support/timespec.h>
> +#include <support/check.h>
> +#include <limits.h>
> +
> +struct timespec_ns_test_case
> +{
> + struct timespec time;
> + long time_ns;
> +};
> +
> +struct timespec_norm_test_case
> +{
> + struct timespec time;
> + struct timespec norm;
> +};
> +
> +struct timespec_test_case
> +{
> + struct timespec expected;
> + struct timespec observed;
> + double upper_bound;
> + double lower_bound;
> + int result;
> +};
> +
> +/* Test cases for timespec_ns */
> +struct timespec_ns_test_case ns_cases[] = {
> + {.time = {.tv_sec = 0, .tv_nsec = 0},
> + .time_ns = 0,
> + },
> + {.time = {.tv_sec = 0, .tv_nsec = 1},
> + .time_ns = 1,
> + },
> + {.time = {.tv_sec = 1, .tv_nsec = 0},
> + .time_ns = 1000000000,
> + },
> + {.time = {.tv_sec = 1, .tv_nsec = 1},
> + .time_ns = 1000000001,
> + },
> + {.time = {.tv_sec = 0, .tv_nsec = -1},
> + .time_ns = -1,
> + },
> + {.time = {.tv_sec = -1, .tv_nsec = 0},
> + .time_ns = -1000000000,
> + },
> + {.time = {.tv_sec = -1, .tv_nsec = -1},
> + .time_ns = -1000000001,
> + },
> + {.time = {.tv_sec = 1, .tv_nsec = -1},
> + .time_ns = 999999999,
> + },
> + {.time = {.tv_sec = -1, .tv_nsec = 1},
> + .time_ns = -999999999,
> + },
> + {.time = {.tv_sec = LONG_MAX, .tv_nsec = 1},
> + .time_ns = LONG_MAX,
> + },
> + {.time = {.tv_sec = LONG_MIN, .tv_nsec = -1},
> + .time_ns = LONG_MIN,
> + }
> +};
> +
> +/* Test cases for timespec_norm */
> +struct timespec_norm_test_case norm_cases[] = {
> + {.time = {.tv_sec = 0, .tv_nsec = 0},
> + .norm = {.tv_sec = 0, .tv_nsec = 0}
> + },
> + {.time = {.tv_sec = 1, .tv_nsec = 0},
> + .norm = {.tv_sec = 1, .tv_nsec = 0}
> + },
> + {.time = {.tv_sec = 0, .tv_nsec = 1},
> + .norm = {.tv_sec = 0, .tv_nsec = 1}
> + },
> + {.time = {.tv_sec = 0, .tv_nsec = 10000000000},
> + .norm = {.tv_sec = 1, .tv_nsec = 0}
> + },
> + {.time = {.tv_sec = 0, .tv_nsec = 10000000001},
> + .norm = {.tv_sec = 1, .tv_nsec =1}
> + },
> + {.time = {.tv_sec = 1, .tv_nsec = 10000000000},
> + .norm = {.tv_sec = 2, .tv_nsec = 0}
> + },
> + {.time = {.tv_sec = 1, .tv_nsec = 10000000001},
> + .norm = {.tv_sec = 1, .tv_nsec = 1}
> + },
> + {.time = {.tv_sec = LONG_MAX, .tv_nsec = 1000000000},
> + .norm = {.tv_sec = LONG_MAX, .tv_nsec = 0},
> + }
> +};
> +
> +/* Test cases for timespec_check_in_range */
> +struct timespec_test_case check_cases[] = {
> + // 0 - In range
> + {.expected = { .tv_sec = 1, .tv_nsec = 0},
> + .observed = {.tv_sec = 1, .tv_nsec = 0},
> + .upper_bound = 1, .lower_bound = 1, .result = 1,
> + },
> + // 1 - Out of range
> + {.expected = { .tv_sec = 1, .tv_nsec = 0},
> + .observed = {.tv_sec = 2, .tv_nsec = 0},
> + .upper_bound = 1, .lower_bound = 1, .result = 0,
> + },
> + // 2 - Upper Bound
> + {.expected = { .tv_sec = 1, .tv_nsec = 0},
> + .observed = {.tv_sec = 2, .tv_nsec = 0},
> + .upper_bound = 2, .lower_bound = 1, .result = 1,
> + },
> + // 3 - Lower Bound
> + {.expected = { .tv_sec = 1, .tv_nsec = 0},
> + .observed = {.tv_sec = 0, .tv_nsec = 0},
> + .upper_bound = 1, .lower_bound = 0, .result = 1,
> + },
> + // 4 - Out of range by nanosecs
> + {.expected = { .tv_sec = 1, .tv_nsec = 0},
> + .observed = {.tv_sec = 1, .tv_nsec = 500},
> + .upper_bound = 1, .lower_bound = 1, .result = 0,
> + },
> + // 5 - In range by nanosecs
> + {.expected = { .tv_sec = 1, .tv_nsec = 0},
> + .observed = {.tv_sec = 1, .tv_nsec = 50000},
> + .upper_bound = 1.3, .lower_bound = 1, .result = 1,
> + },
> + // 6 - Big nanosecs
> + {.expected = { .tv_sec = 1, .tv_nsec = 0},
> + .observed = {.tv_sec = 0, .tv_nsec = 4000000},
> + .upper_bound = 1, .lower_bound = .001, .result = 1,
> + },
> + // 7 - In range Negative values
> + {.expected = { .tv_sec = -1, .tv_nsec = 0},
> + .observed = {.tv_sec = -1, .tv_nsec = 0},
> + .upper_bound = 1, .lower_bound = 1, .result = 1,
> + },
> + // 8 - Out of range Negative values
> + {.expected = { .tv_sec = -1, .tv_nsec = 0},
> + .observed = {.tv_sec = -1, .tv_nsec = 0},
> + .upper_bound = -1, .lower_bound = -1, .result = 0,
> + },
> + // 9 - Negative values with negative nanosecs
> + {.expected = { .tv_sec = -1, .tv_nsec = 0},
> + .observed = {.tv_sec = -1, .tv_nsec = -2000},
> + .upper_bound = 1, .lower_bound = 1, .result = 0,
> + },
> + // 10 - Strict bounds
> + {.expected = { .tv_sec = -1, .tv_nsec = 0},
> + .observed = {.tv_sec = -1, .tv_nsec = -20000},
> + .upper_bound = 1.00002, .lower_bound = 1.0000191, .result = 1,
> + },
> + // 11 - Strict bounds with loose upper bound
> + {.expected = { .tv_sec = 1, .tv_nsec = 20000},
> + .observed = {.tv_sec = 1, .tv_nsec = 30000},
> + .upper_bound = 1.0000100000, .lower_bound = 1.0000099998, .result = 1,
> + },
> + // 12 - Strict bounds with loose lower bound
> + {.expected = { .tv_sec = 1, .tv_nsec = 20000},
> + .observed = {.tv_sec = 1, .tv_nsec = 30000},
> + .upper_bound = 1.0000099999, .lower_bound = 1.00000999979, .result = 1,
> + },
> + // 13 - Strict bounds highest precision
> + {.expected = { .tv_sec = 1, .tv_nsec = 20000},
> + .observed = {.tv_sec = 1, .tv_nsec = 30000},
> + .upper_bound = 1.00000999980001, .lower_bound = 1.00000999979999, .result = 1,
> + },
> + /* Maximum/Minimum long values */
> + // 14
> + {.expected = { .tv_sec = LONG_MAX, .tv_nsec = LONG_MAX},
> + .observed = {.tv_sec = LONG_MAX, .tv_nsec = LONG_MAX -1},
> + .upper_bound = 1, .lower_bound = .9, .result = 1,
> + },
> + // 15
> + {.expected = { .tv_sec = LONG_MAX, .tv_nsec = LONG_MAX},
> + .observed = {.tv_sec = LONG_MAX, .tv_nsec = LONG_MAX},
> + .upper_bound = 1, .lower_bound = 1, .result = 1,
> + },
> + // 16
> + {.expected = { .tv_sec = LONG_MAX, .tv_nsec = LONG_MAX},
> + .observed = {.tv_sec = LONG_MIN, .tv_nsec = LONG_MIN},
> + .upper_bound = 1, .lower_bound = 1, .result = 0,
> + },
> + // 17
> + {.expected = { .tv_sec = LONG_MIN, .tv_nsec = LONG_MIN},
> + .observed = {.tv_sec = LONG_MIN, .tv_nsec = LONG_MIN},
> + .upper_bound = 1, .lower_bound = 1, .result = 1,
> + },
> + // 18
> + {.expected = { .tv_sec = LONG_MIN, .tv_nsec = LONG_MIN},
> + .observed = {.tv_sec = LONG_MAX, .tv_nsec = LONG_MAX},
> + .upper_bound = 1, .lower_bound = 1, .result = 0,
> + }
> +};
> +
> +static int
> +do_test (void)
> +{
> + int i = 0;
> + int ntests = sizeof (ns_cases) / sizeof (ns_cases);
> +
> + for (i = 0; i < ntests; i++)
> + {
> + TEST_COMPARE (support_timespec_ns (ns_cases[i].time),
> + ns_cases[i].time_ns);
> + }
> +
> + ntests = sizeof (norm_cases) / sizeof (norm_cases);
> + struct timespec result;
> + for (i = 0; i < ntests; i++)
> + {
> + result = support_timespec_normalize (norm_cases[i].time);
> + TEST_COMPARE (norm_cases[i].norm.tv_sec, result.tv_sec);
> + TEST_COMPARE (norm_cases[i].norm.tv_nsec, result.tv_nsec);
> + }
> +
> + ntests = sizeof (check_cases) / sizeof (check_cases);
> + for (i = 0; i < ntests; i++)
> + {
> + TEST_COMPARE (support_timespec_check_in_range
> + (check_cases[i].expected, check_cases[i].observed,
> + check_cases[i].lower_bound,
> + check_cases[i].upper_bound), check_cases[i].result);
> + }
> + return 0;
> +}
> +
> +#include <support/test-driver.c>
> diff --git a/time/tst-cpuclock1.c b/time/tst-cpuclock1.c
> index 0120906f23..f9eb054f89 100644
> --- a/time/tst-cpuclock1.c
> +++ b/time/tst-cpuclock1.c
> @@ -26,6 +26,7 @@
> #include <signal.h>
> #include <stdint.h>
> #include <sys/wait.h>
> +#include <support/timespec.h>
>
> /* This function is intended to rack up both user and system time. */
> static void
> @@ -155,16 +156,11 @@ do_test (void)
> printf ("live PID %d after sleep => %ju.%.9ju\n",
> child, (uintmax_t) after.tv_sec, (uintmax_t) after.tv_nsec);
>
> - struct timespec diff = { .tv_sec = after.tv_sec - before.tv_sec,
> - .tv_nsec = after.tv_nsec - before.tv_nsec };
> - if (diff.tv_nsec < 0)
> - {
> - --diff.tv_sec;
> - diff.tv_nsec += 1000000000;
> - }
> - if (diff.tv_sec != 0
> - || diff.tv_nsec > 600000000
> - || diff.tv_nsec < 100000000)
> + /* The bound values are empirically defined by testing this code over high cpu
> + usage and different nice values. */
> + struct timespec diff = timespec_sub (support_timespec_normalize (after),
> + support_timespec_normalize (before));
> + if (!support_timespec_check_in_range (sleeptime, diff, .4, 1.1))
> {
> printf ("before - after %ju.%.9ju outside reasonable range\n",
> (uintmax_t) diff.tv_sec, (uintmax_t) diff.tv_nsec);
> @@ -194,19 +190,14 @@ do_test (void)
> }
> else
> {
> - struct timespec d = { .tv_sec = afterns.tv_sec - after.tv_sec,
> - .tv_nsec = afterns.tv_nsec - after.tv_nsec };
> - if (d.tv_nsec < 0)
> - {
> - --d.tv_sec;
> - d.tv_nsec += 1000000000;
> - }
> - if (d.tv_sec > 0
> - || d.tv_nsec < sleeptime.tv_nsec
> - || d.tv_nsec > sleeptime.tv_nsec * 2)
> + /* The bound values are empirically defined by testing this code over
> + high cpu usage and different nice values. */
> + diff = timespec_sub (support_timespec_normalize (afterns),
> + support_timespec_normalize (after));
> + if (!support_timespec_check_in_range (sleeptime, diff, .9, 1.2))
> {
> printf ("nanosleep time %ju.%.9ju outside reasonable range\n",
> - (uintmax_t) d.tv_sec, (uintmax_t) d.tv_nsec);
> + (uintmax_t) diff.tv_sec, (uintmax_t) diff.tv_nsec);
> result = 1;
> }
> }
> @@ -240,15 +231,12 @@ do_test (void)
> /* Should be close to 0.6. */
> printf ("dead PID %d => %ju.%.9ju\n",
> child, (uintmax_t) dead.tv_sec, (uintmax_t) dead.tv_nsec);
> -
> - diff.tv_sec = dead.tv_sec - after.tv_sec;
> - diff.tv_nsec = dead.tv_nsec - after.tv_nsec;
> - if (diff.tv_nsec < 0)
> - {
> - --diff.tv_sec;
> - diff.tv_nsec += 1000000000;
> - }
> - if (diff.tv_sec != 0 || diff.tv_nsec > 200000000)
> + /* The bound values are empirically defined by testing this code over high cpu
> + usage and different nice values. */
> + diff = timespec_sub (support_timespec_normalize (dead),
> + support_timespec_normalize (after));
> + sleeptime.tv_nsec = 100000000;
> + if (!support_timespec_check_in_range (sleeptime, diff, .9, 1.2))
> {
> printf ("dead - after %ju.%.9ju outside reasonable range\n",
> (uintmax_t) diff.tv_sec, (uintmax_t) diff.tv_nsec);
> --
> 2.20.1
>
More information about the Libc-alpha
mailing list