[v4] Fix time/tst-cpuclock1 intermitent failures

  This test fails intermittently in systems with heavy load as
CLOCK_PROCESS_CPUTIME_ID is subject to scheduler pressure.  Thus the
test boundaries where relaxed to keep it from fail on this systems.

A refactor of the spent time checking was made with some support
functions.  With the advantage to represent time jitter in percent
of the target.

The values used by the test boundaries are all empirical.

---

Hi,

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/timespec.c   | 34 ++++++++++++++++++++++++++++++++
 support/timespec.h   |  6 ++++++
 time/tst-cpuclock1.c | 46 +++++++++++++++-----------------------------
 3 files changed, 55 insertions(+), 31 deletions(-)
  

On Mär 10 2020, Lucas A. M. Magalhaes wrote:

> diff --git a/time/tst-cpuclock1.c b/time/tst-cpuclock1.c
> index 0120906f23..0c67a61e0d 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,19 +156,13 @@ 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)
> +  support_timespec_normalize(after);
> +  support_timespec_normalize(before);
> +  struct timespec diff = timespec_sub(after, before);
> +  if (!support_timespec_check_in_range(sleeptime, diff, .0025,  1.3))

Style: space before paren.

Andreas.
  

On 3/10/20 12:20 PM, Lucas A. M. Magalhaes wrote:
> This test fails intermittently in systems with heavy load as
> CLOCK_PROCESS_CPUTIME_ID is subject to scheduler pressure.  Thus the
> test boundaries where relaxed to keep it from fail on this systems.
> 
> A refactor of the spent time checking was made with some support
> functions.  With the advantage to represent time jitter in percent
> of the target.
> 
> The values used by the test boundaries are all empirical.

Getting closer. Still needs some work. See suggestions below for v5.

> ---
> 
> Hi,
> 
> 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/timespec.c   | 34 ++++++++++++++++++++++++++++++++
>  support/timespec.h   |  6 ++++++
>  time/tst-cpuclock1.c | 46 +++++++++++++++-----------------------------
>  3 files changed, 55 insertions(+), 31 deletions(-)
> 
> diff --git a/support/timespec.c b/support/timespec.c
> index ea6b947546..babe7801a2 100644
> --- a/support/timespec.c
> +++ b/support/timespec.c
> @@ -19,6 +19,7 @@
>  #include <support/timespec.h>
>  #include <stdio.h>
>  #include <stdint.h>
> +#include <assert.h>

OK.

>  
>  void
>  test_timespec_before_impl (const char *file, int line,
> @@ -57,3 +58,36 @@ 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.  */
> +struct timespec
> +support_timespec_normalize (struct timespec t)
> +{
> +  t.tv_sec += t.tv_nsec / TIMESPEC_HZ;
> +  t.tv_nsec -= t.tv_nsec % TIMESPEC_HZ;

(1) This doesn't seem correct.

{ 0, 1000000001 } - initial value
{ 1, 1000000001 } - +1s
{ 1, 1000000000 } - -1ns

Expected:
{ 1, 1}

Suggest:
t.tv_sec += t.tv_nsec / TIMESPEC_HZ;
t.tv_nsec = t.tv_nsec % TIMESPEC_HZ;

See my comment below about test cases.

(2) Don't modify arguments, return modified argument.

> +  return t;
> +}
> +
> +/* Returns TRUE if deviation to base ratio is within the specified bounds, and
> +FALSE otherwise.

Suggest:

"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(base, deviation, .5, 1.2);
> +
> +will check if
> +
> +.5 <= deviation/base <= 1.2
> +
> +In other words it will check if deviation time is within 50% to 120% of
> +the base time.  */

(3) Use expected and observed everywhere.

I would say "base" is the "expected" value.

I would say "deviation" is the "observed" value.

> +int
> +support_timespec_check_in_range (struct timespec base, struct timespec deviation,
> +			      double lower_bound, double upper_bound)
> +{
> +  assert (upper_bound >= lower_bound);
> +  long base_norm = base.tv_sec * TIMESPEC_HZ + base.tv_nsec;
> +  long deviation_norm = deviation.tv_sec * TIMESPEC_HZ + deviation.tv_nsec;
> +  double ratio = (double)deviation_norm / base_norm;
> +  return (lower_bound <= ratio && ratio <= upper_bound);
> +}

(4) Add test cases.

Could you please add a handful of test cases in support/ for this new function?

That way we prove it's working as expected on all systems.

You should test positive and negative times.

You should test times inside the range, outside the range, and exactly on 
lower and upper range boundaries.

> diff --git a/support/timespec.h b/support/timespec.h
> index c5852dfe75..98d18663d0 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 t);
> +
> +int support_timespec_check_in_range (struct timespec base, struct timespec deviation,
> +				  double upper_bound, double lower_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/time/tst-cpuclock1.c b/time/tst-cpuclock1.c
> index 0120906f23..0c67a61e0d 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,19 +156,13 @@ 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)
> +  support_timespec_normalize(after);
> +  support_timespec_normalize(before);
> +  struct timespec diff = timespec_sub(after, before);


(5) Compose like this with new function that returns new struct.

diff = timespec_sub (support_timespec_normalize (before),
		     support_timespec_normalize (after));

> +  if (!support_timespec_check_in_range(sleeptime, diff, .0025,  1.3))

(6) Need comments explaining magic constants.

>      {
>        printf ("before - after %ju.%.9ju outside reasonable range\n",
> -	      (uintmax_t) diff.tv_sec, (uintmax_t) diff.tv_nsec);
> +	    (uintmax_t) diff.tv_sec, (uintmax_t) diff.tv_nsec);
>        result = 1;
>      }
>  
> @@ -194,19 +189,12 @@ 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)
> +	  support_timespec_normalize(afterns);
> +	  diff = timespec_sub(afterns, after);

(5) Likewise.


> +	  if (!support_timespec_check_in_range(sleeptime, diff, .71, 1.6))

(6) Likewise.

>  	    {
>  	      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;
>  	    }
>  	}
> @@ -241,17 +229,13 @@ do_test (void)
>    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)
> +  support_timespec_normalize(dead);
> +  diff = timespec_sub(dead, after);

(5) Likewise.

> +  sleeptime.tv_nsec = 100000000;
> +  if (!support_timespec_check_in_range(sleeptime, diff, .7, 1.6))

(6) Likewise.

>      {
>        printf ("dead - after %ju.%.9ju outside reasonable range\n",
> -	      (uintmax_t) diff.tv_sec, (uintmax_t) diff.tv_nsec);
> +	     (uintmax_t) diff.tv_sec, (uintmax_t) diff.tv_nsec);
>        result = 1;
>      }
>  
> -- 2.20.1