[i-g-t] igt: tests: kms_vblank: Stop using magic value

Submitted by Lisovskiy, Stanislav on March 19, 2019, 1:46 p.m.

Details

Message ID 20190319134622.5168-1-stanislav.lisovskiy@intel.com
State New
Headers show
Series "igt: tests: kms_vblank: Stop using magic value" ( rev: 1 ) in IGT

Not browsing as part of any series.

Commit Message

Lisovskiy, Stanislav March 19, 2019, 1:46 p.m.
Lot of tests fail, when assertion checking
how many vblanks should have passed during
suspend/resume is compared to magic value 150.

At the same time even for failed cases, sometimes
it is clearly visible that there were no issue -
simply suspend took longer on that machine.
If suspend took around 10 s and we get roughly
60 vblanks per second the value then should be
around 600 and not 150.

This change removes 150 magic value and starts
to use calculation of what it is expected to
be instead of being hardcoded.

Bugzilla: https://bugs.freedesktop.org/show_bug.cgi?id=104894
Signed-off-by: Stanislav Lisovskiy <stanislav.lisovskiy@intel.com>
---
 tests/kms_vblank.c | 15 +++++++++++++--
 1 file changed, 13 insertions(+), 2 deletions(-)

Patch hide | download patch | download mbox

diff --git a/tests/kms_vblank.c b/tests/kms_vblank.c
index dafadb58..80b2a23a 100644
--- a/tests/kms_vblank.c
+++ b/tests/kms_vblank.c
@@ -338,8 +338,13 @@  static void vblank_ts_cont(data_t *data, int fd, int nchildren)
 	igt_output_t *output = data->output;
 	int seq1, seq2;
 	union drm_wait_vblank vbl;
+	struct timespec start, end;
+	int estimated_vblanks = 0;
+	int vrefresh = igt_output_get_mode(output)->vrefresh;
+	double time_elapsed;
 
 	seq1 = get_vblank(fd, data->pipe, 0);
+	clock_gettime(CLOCK_MONOTONIC, &start);
 
 	if (data->flags & DPMS) {
 		igt_output_set_prop_value(output, IGT_CONNECTOR_DPMS, DRM_MODE_DPMS_OFF);
@@ -377,11 +382,17 @@  static void vblank_ts_cont(data_t *data, int fd, int nchildren)
 	}
 
 	seq2 = get_vblank(fd, data->pipe, 0);
+	clock_gettime(CLOCK_MONOTONIC, &end);
+
+	time_elapsed = igt_time_elapsed(&start, &end);
+	estimated_vblanks = (int)(time_elapsed * vrefresh) + 1;
 
 	igt_debug("testing ts continuity: Current frame %u, old frame %u\n", seq2, seq1);
 
-	igt_assert_f(seq2 - seq1 >= 0, "unexpected vblank seq %u, should be >= %u\n", seq2, seq1);
-	igt_assert_f(seq2 - seq1 <= 150, "unexpected vblank seq %u, should be < %u\n", seq2, seq1 + 150);
+	igt_assert_f(seq2 - seq1 >= 0, "elapsed %f(%d vblanks) unexpected vblank seq %u, should be >= %u\n", time_elapsed,
+			estimated_vblanks, seq2, seq1);
+	igt_assert_f(seq2 - seq1 <= estimated_vblanks, "elapsed %f(%d vblanks) unexpected vblank seq %u, should be < %u\n", time_elapsed,
+			estimated_vblanks, seq2, seq1 + estimated_vblanks);
 }
 
 static void run_subtests_for_pipe(data_t *data)

Comments

On Tue, 2019-03-19 at 15:46 +0200, Stanislav Lisovskiy wrote:
> Lot of tests fail, when assertion checking

> how many vblanks should have passed during

> suspend/resume is compared to magic value 150.

> 

> At the same time even for failed cases, sometimes

> it is clearly visible that there were no issue -

> simply suspend took longer on that machine.

> If suspend took around 10 s and we get roughly

> 60 vblanks per second the value then should be

> around 600 and not 150.

> 

> This change removes 150 magic value and starts

> to use calculation of what it is expected to

> be instead of being hardcoded.

> 

> Bugzilla: https://bugs.freedesktop.org/show_bug.cgi?id=104894

> Signed-off-by: Stanislav Lisovskiy <stanislav.lisovskiy@intel.com>

> ---

>  tests/kms_vblank.c | 15 +++++++++++++--

>  1 file changed, 13 insertions(+), 2 deletions(-)


Martin, could you please comment, what was I supposed to fix
here, based on our offline discussion, as I seem to have forgotten
this already..

> 

> diff --git a/tests/kms_vblank.c b/tests/kms_vblank.c

> index dafadb58..80b2a23a 100644

> --- a/tests/kms_vblank.c

> +++ b/tests/kms_vblank.c

> @@ -338,8 +338,13 @@ static void vblank_ts_cont(data_t *data, int fd,

> int nchildren)

>  	igt_output_t *output = data->output;

>  	int seq1, seq2;

>  	union drm_wait_vblank vbl;

> +	struct timespec start, end;

> +	int estimated_vblanks = 0;

> +	int vrefresh = igt_output_get_mode(output)->vrefresh;

> +	double time_elapsed;

>  

>  	seq1 = get_vblank(fd, data->pipe, 0);

> +	clock_gettime(CLOCK_MONOTONIC, &start);

>  

>  	if (data->flags & DPMS) {

>  		igt_output_set_prop_value(output, IGT_CONNECTOR_DPMS,

> DRM_MODE_DPMS_OFF);

> @@ -377,11 +382,17 @@ static void vblank_ts_cont(data_t *data, int

> fd, int nchildren)

>  	}

>  

>  	seq2 = get_vblank(fd, data->pipe, 0);

> +	clock_gettime(CLOCK_MONOTONIC, &end);

> +

> +	time_elapsed = igt_time_elapsed(&start, &end);

> +	estimated_vblanks = (int)(time_elapsed * vrefresh) + 1;

>  

>  	igt_debug("testing ts continuity: Current frame %u, old frame

> %u\n", seq2, seq1);

>  

> -	igt_assert_f(seq2 - seq1 >= 0, "unexpected vblank seq %u,

> should be >= %u\n", seq2, seq1);

> -	igt_assert_f(seq2 - seq1 <= 150, "unexpected vblank seq %u,

> should be < %u\n", seq2, seq1 + 150);

> +	igt_assert_f(seq2 - seq1 >= 0, "elapsed %f(%d vblanks)

> unexpected vblank seq %u, should be >= %u\n", time_elapsed,

> +			estimated_vblanks, seq2, seq1);

> +	igt_assert_f(seq2 - seq1 <= estimated_vblanks, "elapsed %f(%d

> vblanks) unexpected vblank seq %u, should be < %u\n", time_elapsed,

> +			estimated_vblanks, seq2, seq1 +

> estimated_vblanks);

>  }

>  

>  static void run_subtests_for_pipe(data_t *data)
On 02/04/2019 16:00, Lisovskiy, Stanislav wrote:
> On Tue, 2019-03-19 at 15:46 +0200, Stanislav Lisovskiy wrote:
>> Lot of tests fail, when assertion checking
>> how many vblanks should have passed during
>> suspend/resume is compared to magic value 150.
>>
>> At the same time even for failed cases, sometimes
>> it is clearly visible that there were no issue -
>> simply suspend took longer on that machine.
>> If suspend took around 10 s and we get roughly
>> 60 vblanks per second the value then should be
>> around 600 and not 150.
>>
>> This change removes 150 magic value and starts
>> to use calculation of what it is expected to
>> be instead of being hardcoded.
>>
>> Bugzilla: https://bugs.freedesktop.org/show_bug.cgi?id=104894
>> Signed-off-by: Stanislav Lisovskiy <stanislav.lisovskiy@intel.com>
>> ---
>>  tests/kms_vblank.c | 15 +++++++++++++--
>>  1 file changed, 13 insertions(+), 2 deletions(-)
> 
> Martin, could you please comment, what was I supposed to fix
> here, based on our offline discussion, as I seem to have forgotten
> this already..

Pretty sure what I was asking was to make a window of acceptable vblank
values, for example [expected-2, expected+2].

The reason why we can't be sure what value this will be is because we
don't know how early vblank gets disabled compared to when the monotonic
counter gets disabled. This is especially true in the presence of
multiple monitors (no idea if we first wait for vblank on all monitors
before suspend or not).

I hope this is what you wanted to hear!
> 
>>
>> diff --git a/tests/kms_vblank.c b/tests/kms_vblank.c
>> index dafadb58..80b2a23a 100644
>> --- a/tests/kms_vblank.c
>> +++ b/tests/kms_vblank.c
>> @@ -338,8 +338,13 @@ static void vblank_ts_cont(data_t *data, int fd,
>> int nchildren)
>>  	igt_output_t *output = data->output;
>>  	int seq1, seq2;
>>  	union drm_wait_vblank vbl;
>> +	struct timespec start, end;
>> +	int estimated_vblanks = 0;
>> +	int vrefresh = igt_output_get_mode(output)->vrefresh;
>> +	double time_elapsed;
>>  
>>  	seq1 = get_vblank(fd, data->pipe, 0);
>> +	clock_gettime(CLOCK_MONOTONIC, &start);
>>  
>>  	if (data->flags & DPMS) {
>>  		igt_output_set_prop_value(output, IGT_CONNECTOR_DPMS,
>> DRM_MODE_DPMS_OFF);
>> @@ -377,11 +382,17 @@ static void vblank_ts_cont(data_t *data, int
>> fd, int nchildren)
>>  	}
>>  
>>  	seq2 = get_vblank(fd, data->pipe, 0);
>> +	clock_gettime(CLOCK_MONOTONIC, &end);
>> +
>> +	time_elapsed = igt_time_elapsed(&start, &end);
>> +	estimated_vblanks = (int)(time_elapsed * vrefresh) + 1;
>>  
>>  	igt_debug("testing ts continuity: Current frame %u, old frame
>> %u\n", seq2, seq1);
>>  
>> -	igt_assert_f(seq2 - seq1 >= 0, "unexpected vblank seq %u,
>> should be >= %u\n", seq2, seq1);
>> -	igt_assert_f(seq2 - seq1 <= 150, "unexpected vblank seq %u,
>> should be < %u\n", seq2, seq1 + 150);
>> +	igt_assert_f(seq2 - seq1 >= 0, "elapsed %f(%d vblanks)
>> unexpected vblank seq %u, should be >= %u\n", time_elapsed,
>> +			estimated_vblanks, seq2, seq1);
>> +	igt_assert_f(seq2 - seq1 <= estimated_vblanks, "elapsed %f(%d
>> vblanks) unexpected vblank seq %u, should be < %u\n", time_elapsed,
>> +			estimated_vblanks, seq2, seq1 +
>> estimated_vblanks);
>>  }
>>  
>>  static void run_subtests_for_pipe(data_t *data)
>
On Tue, 2019-04-02 at 16:16 +0300, Martin Peres wrote:
> On 02/04/2019 16:00, Lisovskiy, Stanislav wrote:

> > On Tue, 2019-03-19 at 15:46 +0200, Stanislav Lisovskiy wrote:

> > > Lot of tests fail, when assertion checking

> > > how many vblanks should have passed during

> > > suspend/resume is compared to magic value 150.

> > > 

> > > At the same time even for failed cases, sometimes

> > > it is clearly visible that there were no issue -

> > > simply suspend took longer on that machine.

> > > If suspend took around 10 s and we get roughly

> > > 60 vblanks per second the value then should be

> > > around 600 and not 150.

> > > 

> > > This change removes 150 magic value and starts

> > > to use calculation of what it is expected to

> > > be instead of being hardcoded.

> > > 

> > > Bugzilla: https://bugs.freedesktop.org/show_bug.cgi?id=104894

> > > Signed-off-by: Stanislav Lisovskiy <stanislav.lisovskiy@intel.com

> > > >

> > > ---

> > >  tests/kms_vblank.c | 15 +++++++++++++--

> > >  1 file changed, 13 insertions(+), 2 deletions(-)

> > 

> > Martin, could you please comment, what was I supposed to fix

> > here, based on our offline discussion, as I seem to have forgotten

> > this already..

> 

> Pretty sure what I was asking was to make a window of acceptable

> vblank

> values, for example [expected-2, expected+2].

> 

> The reason why we can't be sure what value this will be is because we

> don't know how early vblank gets disabled compared to when the

> monotonic

> counter gets disabled. This is especially true in the presence of

> multiple monitors (no idea if we first wait for vblank on all

> monitors

> before suspend or not).

> 

> I hope this is what you wanted to hear!


Yes, exactly. Thank you, I remember now :)

> > 

> > > 

> > > diff --git a/tests/kms_vblank.c b/tests/kms_vblank.c

> > > index dafadb58..80b2a23a 100644

> > > --- a/tests/kms_vblank.c

> > > +++ b/tests/kms_vblank.c

> > > @@ -338,8 +338,13 @@ static void vblank_ts_cont(data_t *data, int

> > > fd,

> > > int nchildren)

> > >  	igt_output_t *output = data->output;

> > >  	int seq1, seq2;

> > >  	union drm_wait_vblank vbl;

> > > +	struct timespec start, end;

> > > +	int estimated_vblanks = 0;

> > > +	int vrefresh = igt_output_get_mode(output)->vrefresh;

> > > +	double time_elapsed;

> > >  

> > >  	seq1 = get_vblank(fd, data->pipe, 0);

> > > +	clock_gettime(CLOCK_MONOTONIC, &start);

> > >  

> > >  	if (data->flags & DPMS) {

> > >  		igt_output_set_prop_value(output, IGT_CONNECTOR_DPMS,

> > > DRM_MODE_DPMS_OFF);

> > > @@ -377,11 +382,17 @@ static void vblank_ts_cont(data_t *data,

> > > int

> > > fd, int nchildren)

> > >  	}

> > >  

> > >  	seq2 = get_vblank(fd, data->pipe, 0);

> > > +	clock_gettime(CLOCK_MONOTONIC, &end);

> > > +

> > > +	time_elapsed = igt_time_elapsed(&start, &end);

> > > +	estimated_vblanks = (int)(time_elapsed * vrefresh) + 1;

> > >  

> > >  	igt_debug("testing ts continuity: Current frame %u, old frame

> > > %u\n", seq2, seq1);

> > >  

> > > -	igt_assert_f(seq2 - seq1 >= 0, "unexpected vblank seq %u,

> > > should be >= %u\n", seq2, seq1);

> > > -	igt_assert_f(seq2 - seq1 <= 150, "unexpected vblank seq %u,

> > > should be < %u\n", seq2, seq1 + 150);

> > > +	igt_assert_f(seq2 - seq1 >= 0, "elapsed %f(%d vblanks)

> > > unexpected vblank seq %u, should be >= %u\n", time_elapsed,

> > > +			estimated_vblanks, seq2, seq1);

> > > +	igt_assert_f(seq2 - seq1 <= estimated_vblanks, "elapsed %f(%d

> > > vblanks) unexpected vblank seq %u, should be < %u\n",

> > > time_elapsed,

> > > +			estimated_vblanks, seq2, seq1 +

> > > estimated_vblanks);

> > >  }

> > >  

> > >  static void run_subtests_for_pipe(data_t *data)

> 

>