[PATCH] Remove timing related checks of time/tst-cpuclock1
Stefan Liebler
stli@linux.ibm.com
Mon Oct 26 09:55:12 GMT 2020
On 10/23/20 3:21 PM, Carlos O'Donell wrote:
> On 10/23/20 9:07 AM, Stefan Liebler via Libc-alpha wrote:
>> Starting with the commit 04deeaa9ea74b0679dfc9d9155a37b6425f19a9f
>> "Fix time/tst-cpuclock1 intermitent failures" (2020-07-11),
>> this test fails quite often on s390x/s390 with one/multiple of those:
>> "before - after" / "nanosleep time" / "dead - after" ourside reasonable range.
>>
>> On a zVM/kvm guest the CPUs are shared between multiple guests.
>> And even on the lpar (kvm host) the CPUs are usually shared between multiple lpars.
>> The defined CPUs for a lpar/zVM-system could also have lower weights compared
>> to other lpars which let the steal time further grow.
>>
>> Usually I build (-j$(nproc)) and test (PARALLELMFLAGS="-j$(nproc)") glibc multiple
>> times, e.g. with different GCCs, on various lpars or zVM guests at the same time.
>> During this time, I've run the test for 13500 times and obvserved the following fails:
>> ~600x "before - after"
>> ~60x "nanosleep time"
>> ~70x "dead - after"
>
> I agree that this is a common failure on s390x at Red Hat also during high load
> times on our lpars.
>
>> I've also observed a lot of "before - after" fails on a intel kvm-guest while
>> building/testing glibc on it.
>>
>> The mentioned commit has tighten the limits of valid tv_nsec ranges:
>
> Correct, because we have no data on how *bad* the timing can be.
>
>> "before - after" (expected: 500000000):
>> - 100000000 ... 600000000
>> + 450000000 ... 550000000
>>
>> "nanosleep time" (expected: 100000000):
>> - 100000000 ... 200000000
>> + 090000000 ... 120000000
>>
>> "dead - after" (expected: 100000000):
>> - ... 200000000
>> + 090000000 ... 120000000
>>
>> The test itself forks a child process which chew_cpu (user- and kernel-space).
>> The parent process sleeps with nanosleep(0.5s) and measures the child_clock time:
>> diff = after - before
>> With much workload on the machine, the child won't make much progess
>> and it can fall much beyond the minimum limit.
>
> Correct.
>
> I don't think this test is giving us any value.
>
>> Afterwards the parent process sleeps with clock_nanosleep (child_clock, 0.1s):
>> diff = afterns - after
>> The test currently also allows 0.9 * 0.1s which would be an error.
>> Depending on the workload, the maximum limit can exceed the 1.2 * 0.1s.
>>
>> For "dead - after", the parent process kills the child process and waits long
>> enough to let the child finish dying. Then it gets the time of the child:
>> diff = dead - after
>> Note that diff also contains the time for the previous clock_nanosleep.
>> Thus you'll often see both fails at the same time.
>
> Agreed.
>
>> After discussion on the mailing list, we've decided to keep the functional
>> checks for the clock* functions and remove the timing related checks as those
>> are prone to false positives.
>
> Agreed.
>
>> ---
>> time/tst-cpuclock1.c | 65 ++++----------------------------------------
>> 1 file changed, 6 insertions(+), 59 deletions(-)
>
> Removes 3 support_timespec_check_in_range() checks, and one clock_gettime
> failure check for the after time (which we on longer care about).
>
> OK for master.
>
> Reviewed-by: Carlos O'Donell <carlos@redhat.com>
>
>>
>> diff --git a/time/tst-cpuclock1.c b/time/tst-cpuclock1.c
>> index 1ac611a92b..f40b590111 100644
>> --- a/time/tst-cpuclock1.c
>> +++ b/time/tst-cpuclock1.c
>> @@ -26,7 +26,6 @@
>> #include <signal.h>
>> #include <stdint.h>
>> #include <sys/wait.h>
>> -#include <support/timespec.h>
>
> OK. Don't need the macros any more.
>
>>
>> /* This function is intended to rack up both user and system time. */
>> static void
>> @@ -125,7 +124,7 @@ do_test (void)
>> child, (unsigned long int) child_clock,
>> (uintmax_t) res.tv_sec, (uintmax_t) res.tv_nsec);
>>
>> - struct timespec before, after;
>> + struct timespec before;
>
> OK.
>
>> if (clock_gettime (child_clock, &before) < 0)
>> {
>> printf ("clock_gettime on live PID %d clock %lx => %s\n",
>> @@ -137,38 +136,7 @@ do_test (void)
>> printf ("live PID %d before sleep => %ju.%.9ju\n",
>> child, (uintmax_t) before.tv_sec, (uintmax_t) before.tv_nsec);
>>
>> - struct timespec sleeptime = { .tv_nsec = 500000000 };
>> - if (nanosleep (&sleeptime, NULL) != 0)
>> - {
>> - perror ("nanosleep");
>> - result = 1;
>> - goto done;
>> - }
>> -
>> - if (clock_gettime (child_clock, &after) < 0)
>> - {
>> - printf ("clock_gettime on live PID %d clock %lx => %s\n",
>> - child, (unsigned long int) child_clock, strerror (errno));
>> - result = 1;
>
> OK. Remove check 1/4. Not needed.
>
>> - goto done;
>> - }
>> - /* Should be close to 0.5. */
>> - printf ("live PID %d after sleep => %ju.%.9ju\n",
>> - child, (uintmax_t) after.tv_sec, (uintmax_t) after.tv_nsec);
>> -
>> - /* The bound values are empirically defined by testing this code over high cpu
>> - usage and different nice values. Of all the values we keep the 90th
>> - percentile of values and use those values for our testing allowed range. */
>> - struct timespec diff = timespec_sub (support_timespec_normalize (after),
>> - support_timespec_normalize (before));
>> - if (!support_timespec_check_in_range (sleeptime, diff, .9, 1.1))
>> - {
>> - printf ("before - after %ju.%.9ju outside reasonable range\n",
>> - (uintmax_t) diff.tv_sec, (uintmax_t) diff.tv_nsec);
>> - result = 1;
>> - }
>
> OK. Remove check 2/4.
>
>> -
>> - sleeptime.tv_nsec = 100000000;
>> + struct timespec sleeptime = { .tv_nsec = 100000000 };
>
> OK.
>
>> e = clock_nanosleep (child_clock, 0, &sleeptime, NULL);
>> if (e == EINVAL || e == ENOTSUP || e == ENOSYS)
>> {
>> @@ -191,18 +159,9 @@ do_test (void)
>> }
>> else
>> {
>> - /* The bound values are empirically defined by testing this code over
>> - high cpu usage and different nice values. Of all the values we keep
>> - the 90th percentile of values and use those values for our testing
>> - allowed range. */
>> - 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) diff.tv_sec, (uintmax_t) diff.tv_nsec);
>> - result = 1;
>
> OK. Remove check 3/4.
>
>> - }
>> + printf ("live PID %d after sleep => %ju.%.9ju\n",
>> + child, (uintmax_t) afterns.tv_sec,
>> + (uintmax_t) afterns.tv_nsec);
>
> OK. Informative.
>
>> }
>> }
>>
>> @@ -231,21 +190,9 @@ do_test (void)
>> result = 1;
>> goto done;
>> }
>> - /* Should be close to 0.6. */
>> + /* Should be close to 0.1. */
>> printf ("dead PID %d => %ju.%.9ju\n",
>> child, (uintmax_t) dead.tv_sec, (uintmax_t) dead.tv_nsec);
>
> OK. Informative.
>
>> - /* The bound values are empirically defined by testing this code over high cpu
>> - usage and different nice values. Of all the values we keep the 90th
>> - percentile of values and use those values for our testing allowed range. */
>> - 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);
>> - result = 1;
>> - }
>
> OK. Remove check 4/4.
>
>>
>> /* Now reap the child and verify that its clock is no longer valid. */
>> {
>>
>
>
Committed.
Thanks,
Stefan
More information about the Libc-alpha
mailing list