From patchwork Fri Apr 3 19:24:52 2020 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: "Lucas A. M. Magalhaes" X-Patchwork-Id: 38724 Return-Path: X-Original-To: libc-alpha@sourceware.org Delivered-To: libc-alpha@sourceware.org Received: from mx0a-001b2d01.pphosted.com (mx0a-001b2d01.pphosted.com [148.163.156.1]) by sourceware.org (Postfix) with ESMTPS id 53E91388A03D for ; Fri, 3 Apr 2020 19:24:59 +0000 (GMT) DMARC-Filter: OpenDMARC Filter v1.3.2 sourceware.org 53E91388A03D Received: from pps.filterd (m0098393.ppops.net [127.0.0.1]) by mx0a-001b2d01.pphosted.com (8.16.0.42/8.16.0.42) with SMTP id 033J5tls100229 for ; Fri, 3 Apr 2020 15:24:57 -0400 Received: from pps.reinject (localhost [127.0.0.1]) by mx0a-001b2d01.pphosted.com with ESMTP id 301yfk7n5y-1 (version=TLSv1.2 cipher=ECDHE-RSA-AES256-GCM-SHA384 bits=256 verify=NOT) for ; Fri, 03 Apr 2020 15:24:57 -0400 Received: from m0098393.ppops.net (m0098393.ppops.net [127.0.0.1]) by pps.reinject (8.16.0.36/8.16.0.36) with SMTP id 033J9dhg135201 for ; Fri, 3 Apr 2020 15:24:56 -0400 Received: from ppma01dal.us.ibm.com (83.d6.3fa9.ip4.static.sl-reverse.com [169.63.214.131]) by mx0a-001b2d01.pphosted.com with ESMTP id 301yfk7n5s-1 (version=TLSv1.2 cipher=ECDHE-RSA-AES256-GCM-SHA384 bits=256 verify=NOT); Fri, 03 Apr 2020 15:24:56 -0400 Received: from pps.filterd (ppma01dal.us.ibm.com [127.0.0.1]) by ppma01dal.us.ibm.com (8.16.0.27/8.16.0.27) with SMTP id 033JJB4p031617; Fri, 3 Apr 2020 19:24:56 GMT Received: from b03cxnp07028.gho.boulder.ibm.com (b03cxnp07028.gho.boulder.ibm.com [9.17.130.15]) by ppma01dal.us.ibm.com with ESMTP id 301x7887y2-1 (version=TLSv1.2 cipher=ECDHE-RSA-AES256-GCM-SHA384 bits=256 verify=NOT); Fri, 03 Apr 2020 19:24:55 +0000 Received: from b03ledav006.gho.boulder.ibm.com (b03ledav006.gho.boulder.ibm.com [9.17.130.237]) by b03cxnp07028.gho.boulder.ibm.com (8.14.9/8.14.9/NCO v10.0) with ESMTP id 033JOsAQ35848662 (version=TLSv1/SSLv3 cipher=DHE-RSA-AES256-GCM-SHA384 bits=256 verify=OK); Fri, 3 Apr 2020 19:24:54 GMT Received: from b03ledav006.gho.boulder.ibm.com (unknown [127.0.0.1]) by IMSVA (Postfix) with ESMTP id 84E3BC6057; Fri, 3 Apr 2020 19:24:54 +0000 (GMT) Received: from b03ledav006.gho.boulder.ibm.com (unknown [127.0.0.1]) by IMSVA (Postfix) with ESMTP id 1205EC6059; Fri, 3 Apr 2020 19:24:53 +0000 (GMT) Received: from localhost (unknown [9.85.169.41]) by b03ledav006.gho.boulder.ibm.com (Postfix) with ESMTP; Fri, 3 Apr 2020 19:24:53 +0000 (GMT) From: "Lucas A. M. Magalhaes" To: libc-alpha@sourceware.org Subject: [PATCH v7] Fix time/tst-cpuclock1 intermitent failures Date: Fri, 3 Apr 2020 16:24:52 -0300 Message-Id: <20200403192452.5608-1-lamm@linux.ibm.com> X-Mailer: git-send-email 2.20.1 In-Reply-To: <20200331113438.10103-1-lamm@linux.ibm.com> References: <20200331113438.10103-1-lamm@linux.ibm.com> MIME-Version: 1.0 X-TM-AS-GCONF: 00 X-Proofpoint-Virus-Version: vendor=fsecure engine=2.50.10434:6.0.138, 18.0.676 definitions=2020-04-03_15:2020-04-03, 2020-04-03 signatures=0 X-Proofpoint-Spam-Details: rule=outbound_notspam policy=outbound score=0 lowpriorityscore=0 suspectscore=0 impostorscore=0 mlxscore=0 phishscore=0 clxscore=1015 bulkscore=0 malwarescore=0 spamscore=0 mlxlogscore=999 adultscore=0 priorityscore=1501 classifier=spam adjust=0 reason=mlx scancount=1 engine=8.12.0-2003020000 definitions=main-2004030154 X-Spam-Status: No, score=-25.7 required=5.0 tests=BAYES_00, GIT_PATCH_0, GIT_PATCH_1, GIT_PATCH_2, GIT_PATCH_3, KAM_DMARC_STATUS, KAM_SHORT, RCVD_IN_DNSWL_LOW, SPF_HELO_NONE, SPF_PASS, TXREP autolearn=ham autolearn_force=no version=3.4.2 X-Spam-Checker-Version: SpamAssassin 3.4.2 (2018-09-13) on server2.sourceware.org X-BeenThere: libc-alpha@sourceware.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: Libc-alpha mailing list List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Fri, 03 Apr 2020 19:25:01 -0000 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, 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 | 55 +++++++++++++++ support/timespec.h | 6 ++ support/tst-timespec.c | 147 +++++++++++++++++++++++++++++++++++++++++ time/tst-cpuclock1.c | 48 +++++--------- 5 files changed, 227 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..f6b3f87bb1 100644 --- a/support/timespec.c +++ b/support/timespec.c @@ -19,6 +19,8 @@ #include #include #include +#include +#include void test_timespec_before_impl (const char *file, int line, @@ -57,3 +59,56 @@ test_timespec_equal_or_after_impl (const char *file, int line, (intmax_t) diff.tv_sec, (intmax_t) diff.tv_nsec); } } + +/* 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; +} + +#define TIMESPEC_SHRINK(time, shrinked) \ +{ \ + if (INT_MULTIPLY_WRAPV(time.tv_sec, TIMESPEC_HZ, &shrinked)) \ + { \ + shrinked = (time.tv_sec < 0) ? TYPE_MINIMUM(long): TYPE_MAXIMUM(long); \ + } \ + if (INT_ADD_WRAPV(shrinked, time.tv_nsec, &shrinked)) \ + { \ + shrinked = (time.tv_nsec < 0) ? TYPE_MINIMUM(long): TYPE_MAXIMUM(long); \ + } \ +} \ + +/* 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; + TIMESPEC_SHRINK(expected, expected_norm); + /* Don't divide by zero */ + assert(expected_norm != 0); + TIMESPEC_SHRINK(observed, observed_norm); + 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..86040627c2 100644 --- a/support/timespec.h +++ b/support/timespec.h @@ -48,6 +48,12 @@ void test_timespec_equal_or_after_impl (const char *file, int line, const struct timespec left, const struct timespec right); +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..06d817a421 --- /dev/null +++ b/support/tst-timespec.c @@ -0,0 +1,147 @@ +/* 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 + . */ + +#include +#include +#include + +struct timespec_test_case +{ + struct timespec expected; + struct timespec observed; + double upper_bound; + double lower_bound; + int result; +}; + +struct timespec_test_case test_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 (test_cases) / sizeof (test_cases); + for (i = 0; i < ntests; i++) + { + TEST_COMPARE (support_timespec_check_in_range + (test_cases[i].expected, test_cases[i].observed, + test_cases[i].lower_bound, + test_cases[i].upper_bound), test_cases[i].result); + } + return 0; +} + +#include 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 #include #include +#include /* 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);