[igt-dev] [PATCH i-g-t v2] tests/kms_flip: improve logging when timing out

[Arkadiusz Hiler]

On Mon, Jun 17, 2019 at 03:57:15PM +0300, Simon Ser wrote:
> Signed-off-by: Simon Ser <simon.ser at intel.com>
> Bugzilla: https://bugs.freedesktop.org/show_bug.cgi?id=105363

Since there is CI bug associated with this assert we would need to
adjust the filters before mergeing. Please make sure that this happens.

> ---
> 
> v2: clarify log message
> 
>  tests/kms_flip.c | 7 +++++--
>  1 file changed, 5 insertions(+), 2 deletions(-)
> 
> diff --git a/tests/kms_flip.c b/tests/kms_flip.c
> index 2a158d97bbec..6eadb71b3ed9 100755
> --- a/tests/kms_flip.c
> +++ b/tests/kms_flip.c
> @@ -686,14 +686,17 @@ static unsigned int run_test_step(struct test_output *o)
>  	    !(o->pending_events & EVENT_VBLANK) && o->flip_state.count > 0) {
>  		struct vblank_reply reply;
>  		unsigned int exp_seq;
> -		unsigned long start;
> +		unsigned long start, end;
> 
>  		exp_seq = o->flip_state.current_seq;
>  		start = gettime_us();
>  		do_or_die(__wait_for_vblank(TEST_VBLANK_ABSOLUTE |
>  					    TEST_VBLANK_BLOCK, o->pipe, exp_seq,
>  					    0, &reply));
> -		igt_assert(gettime_us() - start < 500);
> +		end = gettime_us();
> +		igt_assert_f(end - start < 500, "Vblank wait took longer than "
> +			     "expected: %luus >= %dus",
> +			     end - start, 500);

What about adding an igt_debug() for the (end - start)? That would help
us to understand how long does it usually take, so we would have a
baseline for comparison.

>  		igt_assert_eq(reply.sequence, exp_seq);
>  		igt_assert(timercmp(&reply.ts, &o->flip_state.last_ts, ==));
>  	}
> --
> 2.22.0
> 
> _______________________________________________
> igt-dev mailing list
> igt-dev at lists.freedesktop.org
> https://lists.freedesktop.org/mailman/listinfo/igt-dev