Re: [PATCH i-g-t v1 1/1] runner/executor: Use bootime for time checks

[Peter Senna Tschudin <peter.senna@linux.intel.com>]

Hi Kamil,

On 3/28/2025 5:33 PM, Kamil Konieczny wrote:
> Runner is printing time to stdout/stderr with CLOCK_BOOTTIME but
> when measuring time for a test it is using an igt library which
> uses CLOCK_MONOTONIC. This leads to an errors when calculating
> time left for tests using suspend or hibernate. For example log:
> 
> [77.376851] [020/123] (932s left) kms_flip (2x-flip-vs-suspend)
> [77.592412] Starting subtest: 2x-flip-vs-suspend
> [77.604996] Starting dynamic subtest: AB-DP2-HDMI-A3
> [115.135795] Dynamic subtest AB-DP2-HDMI-A3: SUCCESS (6.776s)
> 
> shows test runs for around 6 seconds, while wall time shows
> it took around 38 seconds.
> 
>   Create a separate, runner specific function for time measure
> and use it where current time is needed.
> 
> Cc: Ewelina Musial <ewelina.musial@intel.com>
> Cc: Petri Latvala <adrinael@adrinael.net>
> Reported-by: Karol Krol <karol.krol@intel.com>
> Signed-off-by: Kamil Konieczny <kamil.konieczny@linux.intel.com>
> ---
>  runner/executor.c | 13 +++++++++----
>  1 file changed, 9 insertions(+), 4 deletions(-)
> 
> diff --git a/runner/executor.c b/runner/executor.c
> index 9c8bf90f0..30e2420af 100644
> --- a/runner/executor.c
> +++ b/runner/executor.c
> @@ -47,6 +47,12 @@ static struct {
>  	size_t num_dogs;
>  } watchdogs;
>  
> +static void runner_gettime(struct timespec *tv)
> +{
> +	if (clock_gettime(CLOCK_BOOTTIME, tv))
> +		clock_gettime(CLOCK_REALTIME, tv);
> +}

Tested-by: Peter Senna Tschudin <peter.senna@linux.intel.com>
Reviewed-by: Peter Senna Tschudin <peter.senna@linux.intel.com>



> +
>  __attribute__((format(printf, 2, 3)))
>  static void __logf__(FILE *stream, const char *fmt, ...)
>  {
> @@ -54,8 +60,7 @@ static void __logf__(FILE *stream, const char *fmt, ...)
>  	struct timespec tv;
>  	va_list ap;
>  
> -	if (clock_gettime(CLOCK_BOOTTIME, &tv))
> -		clock_gettime(CLOCK_REALTIME, &tv);
> +	runner_gettime(&tv);
>  	fprintf(stream, "[%ld.%06ld] ", tv.tv_sec, tv.tv_nsec / 1000);
>  
>  	va_start(ap, fmt);
> @@ -961,7 +966,7 @@ static int monitor_output(pid_t child,
>  	bool socket_comms_used = false; /* whether the test actually uses comms */
>  	bool results_received = false; /* whether we already have test results that might need overriding if we detect an abort condition */
>  
> -	igt_gettime(&time_beg);
> +	runner_gettime(&time_beg);
>  	time_last_activity = time_last_subtest = time_killed = time_beg;
>  
>  	if (errfd > nfds)
> @@ -1024,7 +1029,7 @@ static int monitor_output(pid_t child,
>  			return -1;
>  		}
>  
> -		igt_gettime(&time_now);
> +		runner_gettime(&time_now);
>  
>  		/* TODO: Refactor these handlers to their own functions */
>  		if (outfd >= 0 && FD_ISSET(outfd, &set)) {