[PATCH i-g-t 1/6] tests/kms_flip: Print timestamps in a consistent form

[PATCH i-g-t 1/6] tests/kms_flip: Print timestamps in a consistent form

[ville.syrjala]

From: Ville Syrjälä <ville.syrjala@linux.intel.com>

Signed-off-by: Ville Syrjälä <ville.syrjala@linux.intel.com>
---
 tests/kms_flip.c | 14 +++++++-------
 1 file changed, 7 insertions(+), 7 deletions(-)

diff --git a/tests/kms_flip.c b/tests/kms_flip.c
index 6ec97d0a8534..f61d199b648f 100644
--- a/tests/kms_flip.c
+++ b/tests/kms_flip.c
@@ -132,11 +132,11 @@ struct event_state {
 static void dump_event_state(const struct event_state *es)
 {
 	igt_debug("name = %s\n"
-		  "last_ts = %ld.%ld usec\n"
-		  "last_received_ts = %ld.%ld usec\n"
+		  "last_ts = %ld.%06ld\n"
+		  "last_received_ts = %ld.%06ld\n"
 		  "last_seq = %u\n"
-		  "current_ts = %ld.%ld usec\n"
-		  "current_received_ts = %ld.%ld usec\n"
+		  "current_ts = %ld.%06ld\n"
+		  "current_received_ts = %ld.%06ld\n"
 		  "current_seq = %u\n"
 		  "count = %u\n"
 		  "seq_step = %d\n",
@@ -650,7 +650,7 @@ static void check_state(struct test_output *o, struct event_state *es)
 	timersub(&es->current_ts, &es->current_received_ts, &diff);
 	if (!analog_tv_connector(o)) {
 		igt_assert_f(diff.tv_sec < 0 || (diff.tv_sec == 0 && diff.tv_usec <= 2000),
-			     "%s ts delayed for too long: %lds, %ldusec\n",
+			     "%s ts delayed for too long: %ld.%06ld\n",
 			     es->name, diff.tv_sec, diff.tv_usec);
 
 	}
@@ -661,7 +661,7 @@ static void check_state(struct test_output *o, struct event_state *es)
 	timersub(&es->current_ts, &es->last_received_ts, &diff);
 	igt_assert_f(timercmp(&es->last_received_ts, &es->current_ts, <),
 		     "%s ts before the %s was issued!\n"
-		     "timerdiff %lds, %ldusec\n",
+		     "timerdiff %ld.%06ld\n",
 		     es->name, es->name,
 		     diff.tv_sec, diff.tv_usec);
 
@@ -694,7 +694,7 @@ static void check_state(struct test_output *o, struct event_state *es)
 
 		igt_assert_f(fabs((((double) diff.tv_usec) - usec_interflip) /
 				  usec_interflip) <= 0.005,
-			     "inter-%s ts jitter: %lds, %ldusec\n",
+			     "inter-%s ts jitter: %ld.%06ld\n",
 			     es->name, diff.tv_sec, diff.tv_usec);
 
 		igt_assert_f(es->current_seq == es->last_seq + o->seq_step,
-- 
2.7.4

_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

[PATCH i-g-t 2/6] tests/kms_flip: Constify some function arguments

[ville.syrjala]

From: Ville Syrjälä <ville.syrjala@linux.intel.com>

Signed-off-by: Ville Syrjälä <ville.syrjala@linux.intel.com>
---
 tests/kms_flip.c | 9 +++++----
 1 file changed, 5 insertions(+), 4 deletions(-)

diff --git a/tests/kms_flip.c b/tests/kms_flip.c
index f61d199b648f..7b526b5e8593 100644
--- a/tests/kms_flip.c
+++ b/tests/kms_flip.c
@@ -531,7 +531,7 @@ static int do_wait_for_vblank(struct test_output *o, int pipe_id,
 }
 
 static bool
-analog_tv_connector(struct test_output *o)
+analog_tv_connector(const struct test_output *o)
 {
 	uint32_t connector_type = o->kconnector[0]->connector_type;
 
@@ -574,7 +574,7 @@ static void page_flip_handler(int fd, unsigned int frame, unsigned int sec,
 		event_handler(&o->flip_state, frame, sec, usec);
 }
 
-static double frame_time(struct test_output *o)
+static double frame_time(const struct test_output *o)
 {
 	return 1000.0 * o->kmode[0].htotal * o->kmode[0].vtotal / o->kmode[0].clock;
 }
@@ -640,7 +640,7 @@ static void vblank_handler(int fd, unsigned int frame, unsigned int sec,
 	fixup_premature_vblank_ts(o, &o->vblank_state);
 }
 
-static void check_state(struct test_output *o, struct event_state *es)
+static void check_state(const struct test_output *o, const struct event_state *es)
 {
 	struct timeval diff;
 	double usec_interflip;
@@ -1173,7 +1173,8 @@ fb_is_bound(struct test_output *o, int fb)
 	return true;
 }
 
-static void check_final_state(struct test_output *o, struct event_state *es,
+static void check_final_state(const struct test_output *o,
+			      const struct event_state *es,
 			      unsigned int elapsed)
 {
 	igt_assert_f(es->count > 0,
-- 
2.7.4

_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

[PATCH i-g-t 3/6] tests/kms_flip: Use USEC_PER_SEC

[ville.syrjala]

From: Ville Syrjälä <ville.syrjala@linux.intel.com>

Replace some opencoded numbers with USEC_PER_SEC, and
print the usec_diff with 6 decimal digits to make things
more consistent.

Signed-off-by: Ville Syrjälä <ville.syrjala@linux.intel.com>
---
 tests/kms_flip.c | 6 +++---
 1 file changed, 3 insertions(+), 3 deletions(-)

diff --git a/tests/kms_flip.c b/tests/kms_flip.c
index 7b526b5e8593..743e4ad8f673 100644
--- a/tests/kms_flip.c
+++ b/tests/kms_flip.c
@@ -717,15 +717,15 @@ static void check_state_correlation(struct test_output *o,
 		return;
 
 	timersub(&es2->current_ts, &es1->current_ts, &tv_diff);
-	usec_diff = tv_diff.tv_sec * 1000 * 1000 + tv_diff.tv_usec;
+	usec_diff = tv_diff.tv_sec * USEC_PER_SEC + tv_diff.tv_usec;
 
 	seq_diff = es2->current_seq - es1->current_seq;
 	ftime = frame_time(o);
 	usec_diff -= seq_diff * ftime;
 
 	igt_assert_f(fabs(usec_diff) / ftime <= 0.005,
-		     "timestamp mismatch between %s and %s (diff %.4f sec)\n",
-		     es1->name, es2->name, usec_diff / 1000 / 1000);
+		     "timestamp mismatch between %s and %s (diff %.6f sec)\n",
+		     es1->name, es2->name, usec_diff / USEC_PER_SEC);
 }
 
 static void check_all_state(struct test_output *o,
-- 
2.7.4

_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

[PATCH i-g-t 4/6] tests/kms_flip: Account for diff.tv_secs in jitter check

[ville.syrjala]

From: Ville Syrjälä <ville.syrjala@linux.intel.com>

Include diff.tv_secs in the jitter comparison.

Signed-off-by: Ville Syrjälä <ville.syrjala@linux.intel.com>
---
 tests/kms_flip.c | 8 +++++---
 1 file changed, 5 insertions(+), 3 deletions(-)

diff --git a/tests/kms_flip.c b/tests/kms_flip.c
index 743e4ad8f673..7718e950b823 100644
--- a/tests/kms_flip.c
+++ b/tests/kms_flip.c
@@ -643,7 +643,6 @@ static void vblank_handler(int fd, unsigned int frame, unsigned int sec,
 static void check_state(const struct test_output *o, const struct event_state *es)
 {
 	struct timeval diff;
-	double usec_interflip;
 
 	dump_event_state(es);
 
@@ -689,10 +688,13 @@ static void check_state(const struct test_output *o, const struct event_state *e
 	}
 
 	if ((o->flags & TEST_CHECK_TS) && (!analog_tv_connector(o))) {
+		double usec_interflip, usec_diff;
+
 		timersub(&es->current_ts, &es->last_ts, &diff);
-		usec_interflip = (double)o->seq_step * frame_time(o);
+		usec_diff = diff.tv_sec * USEC_PER_SEC + diff.tv_usec;
 
-		igt_assert_f(fabs((((double) diff.tv_usec) - usec_interflip) /
+		usec_interflip = o->seq_step * frame_time(o);
+		igt_assert_f(fabs((usec_diff - usec_interflip) /
 				  usec_interflip) <= 0.005,
 			     "inter-%s ts jitter: %ld.%06ld\n",
 			     es->name, diff.tv_sec, diff.tv_usec);
-- 
2.7.4

_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

[PATCH i-g-t 5/6] tests/kms_flip: Print the expected diff between two events

[ville.syrjala]

From: Ville Syrjälä <ville.syrjala@linux.intel.com>

To aid in diagnosing failures, print out the expected time
difference between the two events.

Signed-off-by: Ville Syrjälä <ville.syrjala@linux.intel.com>
---
 tests/kms_flip.c | 5 +++--
 1 file changed, 3 insertions(+), 2 deletions(-)

diff --git a/tests/kms_flip.c b/tests/kms_flip.c
index 7718e950b823..f685c945feb1 100644
--- a/tests/kms_flip.c
+++ b/tests/kms_flip.c
@@ -696,8 +696,9 @@ static void check_state(const struct test_output *o, const struct event_state *e
 		usec_interflip = o->seq_step * frame_time(o);
 		igt_assert_f(fabs((usec_diff - usec_interflip) /
 				  usec_interflip) <= 0.005,
-			     "inter-%s ts jitter: %ld.%06ld\n",
-			     es->name, diff.tv_sec, diff.tv_usec);
+			     "inter-%s ts jitter: %ld.%06ld, expected %.6f\n",
+			     es->name, diff.tv_sec, diff.tv_usec,
+			     usec_interflip / USEC_PER_SEC);
 
 		igt_assert_f(es->current_seq == es->last_seq + o->seq_step,
 			     "unexpected %s seq %u, expected %u\n",
-- 
2.7.4

_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

[PATCH i-g-t 6/6] tests/kms_flip: Check that the last vs. current seq/ts are consistent

[ville.syrjala]

From: Ville Syrjälä <ville.syrjala@linux.intel.com>

Let's make sure the ts vs. seq difference between the current and last
events match.

Signed-off-by: Ville Syrjälä <ville.syrjala@linux.intel.com>
---
 tests/kms_flip.c | 7 +++++++
 1 file changed, 7 insertions(+)

diff --git a/tests/kms_flip.c b/tests/kms_flip.c
index f685c945feb1..72899d9a7157 100644
--- a/tests/kms_flip.c
+++ b/tests/kms_flip.c
@@ -693,6 +693,13 @@ static void check_state(const struct test_output *o, const struct event_state *e
 		timersub(&es->current_ts, &es->last_ts, &diff);
 		usec_diff = diff.tv_sec * USEC_PER_SEC + diff.tv_usec;
 
+		usec_interflip = (es->current_seq - es->last_seq) * frame_time(o);
+		igt_assert_f(fabs((usec_diff - usec_interflip) /
+				  usec_interflip) <= 0.005,
+			     "inconsistent %s ts/seq: last %ld.%06ld/%u, current %ld.%06ld/%u\n",
+			     es->name, es->last_ts.tv_sec, es->last_ts.tv_usec, es->last_seq,
+			     es->current_ts.tv_sec, es->current_ts.tv_usec, es->current_seq);
+
 		usec_interflip = o->seq_step * frame_time(o);
 		igt_assert_f(fabs((usec_diff - usec_interflip) /
 				  usec_interflip) <= 0.005,
-- 
2.7.4

_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

Re: [PATCH i-g-t 1/6] tests/kms_flip: Print timestamps in a consistent form

[Chris Wilson]

On Tue, Jun 21, 2016 at 08:25:27PM +0300, ville.syrjala@linux.intel.com wrote:
> From: Ville Syrjälä <ville.syrjala@linux.intel.com>

Would it be possible for writing timing requirement tests for individual
updates of planes on the same CRTC? E.g. making sure that legacy cursor
doesn't block pageflips and vice versa. Also extending that to
independent updates of primary vs sprite planes?
-Chris

-- 
Chris Wilson, Intel Open Source Technology Centre
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

Re: [PATCH i-g-t 1/6] tests/kms_flip: Print timestamps in a consistent form

[Ville Syrjälä]

On Wed, Jun 22, 2016 at 01:34:16PM +0100, Chris Wilson wrote:
> On Tue, Jun 21, 2016 at 08:25:27PM +0300, ville.syrjala@linux.intel.com wrote:
> > From: Ville Syrjälä <ville.syrjala@linux.intel.com>
> 
> Would it be possible for writing timing requirement tests for individual
> updates of planes on the same CRTC? E.g. making sure that legacy cursor
> doesn't block pageflips and vice versa. Also extending that to
> independent updates of primary vs sprite planes?

I guess all that should be doable.

I was also thinking we should at least have some kind of basic
performance benchmark for atomic ioctls. Eg. do TEST_ONLY ioctls
with different sets of properties and make sure we don't totally
suck.

-- 
Ville Syrjälä
Intel OTC
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

Re: [PATCH i-g-t 1/6] tests/kms_flip: Print timestamps in a consistent form

[Chris Wilson]

On Wed, Jun 22, 2016 at 04:01:12PM +0300, Ville Syrjälä wrote:
> On Wed, Jun 22, 2016 at 01:34:16PM +0100, Chris Wilson wrote:
> > On Tue, Jun 21, 2016 at 08:25:27PM +0300, ville.syrjala@linux.intel.com wrote:
> > > From: Ville Syrjälä <ville.syrjala@linux.intel.com>
> > 
> > Would it be possible for writing timing requirement tests for individual
> > updates of planes on the same CRTC? E.g. making sure that legacy cursor
> > doesn't block pageflips and vice versa. Also extending that to
> > independent updates of primary vs sprite planes?
> 
> I guess all that should be doable.
> 
> I was also thinking we should at least have some kind of basic
> performance benchmark for atomic ioctls. Eg. do TEST_ONLY ioctls
> with different sets of properties and make sure we don't totally
> suck.

Would it fit into kms_flip?

For starters, I'm going to try and replicate the current cursor bogosity
inside ./kms_cursor_legacy. Biggest challenge is defining pass/fail
criteria. :|
-chris

-- 
Chris Wilson, Intel Open Source Technology Centre
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

Re: [PATCH i-g-t 1/6] tests/kms_flip: Print timestamps in a consistent form

[Ville Syrjälä]

On Wed, Jun 22, 2016 at 02:11:51PM +0100, Chris Wilson wrote:
> On Wed, Jun 22, 2016 at 04:01:12PM +0300, Ville Syrjälä wrote:
> > On Wed, Jun 22, 2016 at 01:34:16PM +0100, Chris Wilson wrote:
> > > On Tue, Jun 21, 2016 at 08:25:27PM +0300, ville.syrjala@linux.intel.com wrote:
> > > > From: Ville Syrjälä <ville.syrjala@linux.intel.com>
> > > 
> > > Would it be possible for writing timing requirement tests for individual
> > > updates of planes on the same CRTC? E.g. making sure that legacy cursor
> > > doesn't block pageflips and vice versa. Also extending that to
> > > independent updates of primary vs sprite planes?
> > 
> > I guess all that should be doable.
> > 
> > I was also thinking we should at least have some kind of basic
> > performance benchmark for atomic ioctls. Eg. do TEST_ONLY ioctls
> > with different sets of properties and make sure we don't totally
> > suck.
> 
> Would it fit into kms_flip?

Possibly, but I wouldn't. Maybe if we would try to split up the main
test function into different functions for different tests instead of
continuing with the flag galore. But still I'd probably prefer a
separate test so the the entire thing easier to read.

> 
> For starters, I'm going to try and replicate the current cursor bogosity
> inside ./kms_cursor_legacy. Biggest challenge is defining pass/fail
> criteria. :|

What do we need?
- make sure >1 cursor updates can be performed per frame w/o errors/blocking.
- issue >1 one cursor updates, followed by a flip that should not error/block
- issue flip, followed by >1 cursor updates that should not error/block

Maybe crc check at the end to make sure it's really the last submitted
thing that got latched. And maybe we should change the crc frame counter
to use the sw counter so we could check that update happens on the frame
we expected?

-- 
Ville Syrjälä
Intel OTC
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

Re: [PATCH i-g-t 1/6] tests/kms_flip: Print timestamps in a consistent form

[Chris Wilson]

On Wed, Jun 22, 2016 at 04:26:01PM +0300, Ville Syrjälä wrote:
> On Wed, Jun 22, 2016 at 02:11:51PM +0100, Chris Wilson wrote:
> > On Wed, Jun 22, 2016 at 04:01:12PM +0300, Ville Syrjälä wrote:
> > > On Wed, Jun 22, 2016 at 01:34:16PM +0100, Chris Wilson wrote:
> > > > On Tue, Jun 21, 2016 at 08:25:27PM +0300, ville.syrjala@linux.intel.com wrote:
> > > > > From: Ville Syrjälä <ville.syrjala@linux.intel.com>
> > > > 
> > > > Would it be possible for writing timing requirement tests for individual
> > > > updates of planes on the same CRTC? E.g. making sure that legacy cursor
> > > > doesn't block pageflips and vice versa. Also extending that to
> > > > independent updates of primary vs sprite planes?
> > > 
> > > I guess all that should be doable.
> > > 
> > > I was also thinking we should at least have some kind of basic
> > > performance benchmark for atomic ioctls. Eg. do TEST_ONLY ioctls
> > > with different sets of properties and make sure we don't totally
> > > suck.
> > 
> > Would it fit into kms_flip?
> 
> Possibly, but I wouldn't. Maybe if we would try to split up the main
> test function into different functions for different tests instead of
> continuing with the flag galore. But still I'd probably prefer a
> separate test so the the entire thing easier to read.
> 
> > 
> > For starters, I'm going to try and replicate the current cursor bogosity
> > inside ./kms_cursor_legacy. Biggest challenge is defining pass/fail
> > criteria. :|
> 
> What do we need?
> - make sure >1 cursor updates can be performed per frame w/o errors/blocking.
> - issue >1 one cursor updates, followed by a flip that should not error/block
> - issue flip, followed by >1 cursor updates that should not error/block

I've put together an initial sketch to try and load as many cursor
updates before the the pageflip as possible to try and detect if (a) the
cursor updates are then synchronous with each other and (b) if the
pageflip serialises with the cursor updates. That's enough to catch the
current bug (and I think the previous cursor bug).
 
> Maybe crc check at the end to make sure it's really the last submitted
> thing that got latched. And maybe we should change the crc frame counter
> to use the sw counter so we could check that update happens on the frame
> we expected?

In theory, that should be caught by kms_cursor_crc, right? Probably
worth a look to see why we don't have a representative test case in BAT
(or if we do, why it was ineffective).
-Chris

-- 
Chris Wilson, Intel Open Source Technology Centre
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

Re: [PATCH i-g-t 1/6] tests/kms_flip: Print timestamps in a consistent form

[Ville Syrjälä]

On Wed, Jun 22, 2016 at 09:33:13PM +0100, Chris Wilson wrote:
> On Wed, Jun 22, 2016 at 04:26:01PM +0300, Ville Syrjälä wrote:
> > On Wed, Jun 22, 2016 at 02:11:51PM +0100, Chris Wilson wrote:
> > > On Wed, Jun 22, 2016 at 04:01:12PM +0300, Ville Syrjälä wrote:
> > > > On Wed, Jun 22, 2016 at 01:34:16PM +0100, Chris Wilson wrote:
> > > > > On Tue, Jun 21, 2016 at 08:25:27PM +0300, ville.syrjala@linux.intel.com wrote:
> > > > > > From: Ville Syrjälä <ville.syrjala@linux.intel.com>
> > > > > 
> > > > > Would it be possible for writing timing requirement tests for individual
> > > > > updates of planes on the same CRTC? E.g. making sure that legacy cursor
> > > > > doesn't block pageflips and vice versa. Also extending that to
> > > > > independent updates of primary vs sprite planes?
> > > > 
> > > > I guess all that should be doable.
> > > > 
> > > > I was also thinking we should at least have some kind of basic
> > > > performance benchmark for atomic ioctls. Eg. do TEST_ONLY ioctls
> > > > with different sets of properties and make sure we don't totally
> > > > suck.
> > > 
> > > Would it fit into kms_flip?
> > 
> > Possibly, but I wouldn't. Maybe if we would try to split up the main
> > test function into different functions for different tests instead of
> > continuing with the flag galore. But still I'd probably prefer a
> > separate test so the the entire thing easier to read.
> > 
> > > 
> > > For starters, I'm going to try and replicate the current cursor bogosity
> > > inside ./kms_cursor_legacy. Biggest challenge is defining pass/fail
> > > criteria. :|
> > 
> > What do we need?
> > - make sure >1 cursor updates can be performed per frame w/o errors/blocking.
> > - issue >1 one cursor updates, followed by a flip that should not error/block
> > - issue flip, followed by >1 cursor updates that should not error/block
> 
> I've put together an initial sketch to try and load as many cursor
> updates before the the pageflip as possible to try and detect if (a) the
> cursor updates are then synchronous with each other and (b) if the
> pageflip serialises with the cursor updates. That's enough to catch the
> current bug (and I think the previous cursor bug).
>  
> > Maybe crc check at the end to make sure it's really the last submitted
> > thing that got latched. And maybe we should change the crc frame counter
> > to use the sw counter so we could check that update happens on the frame
> > we expected?
> 
> In theory, that should be caught by kms_cursor_crc, right? Probably
> worth a look to see why we don't have a representative test case in BAT
> (or if we do, why it was ineffective).

I don't think that one tries multiple updates per frame. It might even
do one update every n frames on account of starting/stopping the crc
capture around every check, which implies a few extra vblank waits
IIRC.

-- 
Ville Syrjälä
Intel OTC
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx