Re: [PATCH igt] igt/kms_flip: Calibrate timestamp errors

[Daniel Vetter <daniel@ffwll.ch>]

On Mon, Oct 24, 2016 at 09:54:52AM +0100, Chris Wilson wrote:
> We assert that the interval between a vblank and a flip corresponds with
> the computed frametime derived from the modeline. However, historically
> the dotclock is unreliable (in error of about 1%) for VBT supplied data
> about LVDS panels - the situation looks to be much improved with eDP at
> least. The simple fact that we cannot rely on the manufacturer's supplied
> modeline causes us to fail the test. So before we claim a driver failure,
> do a calibration pass and check for inconsistencies with the modeline.
> 
> Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

Yeah, throwing some decent stats at this makes sense.

> ---
>  tests/kms_flip.c | 73 ++++++++++++++++++++++++++++++++++++++++++++++++++++++--
>  1 file changed, 71 insertions(+), 2 deletions(-)
> 
> diff --git a/tests/kms_flip.c b/tests/kms_flip.c
> index b30e07c..44aec75 100644
> --- a/tests/kms_flip.c
> +++ b/tests/kms_flip.c
> @@ -26,6 +26,7 @@
>  #endif
>  
>  #include "igt.h"
> +
>  #include <cairo.h>
>  #include <errno.h>
>  #include <fcntl.h>
> @@ -43,6 +44,7 @@
>  #include <time.h>
>  #include <pthread.h>
>  
> +#include "igt_stats.h"
>  
>  #define TEST_DPMS		(1 << 0)
>  #define TEST_WITH_DUMMY_BCS	(1 << 1)
> @@ -175,6 +177,8 @@ struct test_output {
>  	int seq_step;
>  	unsigned int pending_events;
>  	int flip_count;
> +
> +	double ts_error;
>  };
>  
>  
> @@ -698,7 +702,7 @@ static void check_state(const struct test_output *o, const struct event_state *e
>  			  elapsed, expected, expected * 0.005,
>  			  fabs((elapsed - expected) / expected) * 100);
>  
> -		igt_assert_f(fabs((elapsed - expected) / expected) <= 0.005,
> +		igt_assert_f(fabs(elapsed - expected) / expected <= o->ts_error,
>  			     "inconsistent %s ts/seq: last %ld.%06ld/%u, current %ld.%06ld/%u: elapsed=%.1fus expected=%.1fus\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,
> @@ -1301,6 +1305,71 @@ static void free_test_output(struct test_output *o)
>  	}
>  }
>  
> +static double calibrate_ts(struct test_output *o, int crtc_idx)
> +{
> +#define CALIBRATE_TS_STEPS 16
> +	drmVBlank wait;
> +	igt_stats_t stats;
> +	uint32_t last_seq;
> +	uint64_t last_timestamp;
> +	double expected;
> +	double mean;
> +	double stddev;
> +	double median;
> +	int n;
> +
> +	memset(&wait, 0, sizeof(wait));
> +	wait.request.type = kmstest_get_vbl_flag(crtc_idx);
> +	wait.request.type |= DRM_VBLANK_ABSOLUTE | DRM_VBLANK_NEXTONMISS;
> +	do_or_die(drmWaitVBlank(drm_fd, &wait));
> +
> +	last_seq = wait.reply.sequence;
> +	last_timestamp = wait.reply.tval_sec;
> +	last_timestamp *= 1000000;
> +	last_timestamp += wait.reply.tval_usec;
> +
> +	memset(&wait, 0, sizeof(wait));
> +	wait.request.type = kmstest_get_vbl_flag(crtc_idx);
> +	wait.request.type |= DRM_VBLANK_ABSOLUTE | DRM_VBLANK_EVENT;
> +	wait.request.sequence = last_seq;
> +	for (n = 0; n < CALIBRATE_TS_STEPS; n++) {
> +		++wait.request.sequence;
> +		do_or_die(drmWaitVBlank(drm_fd, &wait));
> +	}
> +
> +	igt_stats_init_with_size(&stats, CALIBRATE_TS_STEPS);
> +	for (n = 0; n < CALIBRATE_TS_STEPS; n++) {
> +		struct drm_event_vblank ev;
> +		uint64_t now;
> +
> +		igt_assert(read(drm_fd, &ev, sizeof(ev)) == sizeof(ev));
> +		igt_assert_eq(ev.sequence, last_seq + 1);
> +
> +		now = ev.tv_sec;
> +		now *= 1000000;
> +		now += ev.tv_usec;
> +
> +		igt_stats_push(&stats, now - last_timestamp);
> +
> +		last_timestamp = now;
> +		last_seq = ev.sequence;
> +	}
> +
> +	expected = frame_time(o);
> +
> +	mean = igt_stats_get_mean(&stats);
> +	stddev = igt_stats_get_std_deviation(&stats);
> +	median = igt_stats_get_median(&stats);
> +
> +	igt_info("Expected frametime: %.0fus; measured %.1fus +- %.3fus accuracy %.2f%%; median %.1fus error=%.1f%%\n",
> +		 expected, mean, stddev, 100 * 6 * stddev / mean,
> +		 median, 100* fabs(median - expected) / expected);
> +	igt_assert(6 * stddev / mean < 0.005); /* 99% accuracy within 0.5% */
> +	igt_require(fabs(mean - expected) < 2*stddev);

I think an igt_require_f here with an explanation of what's going on would
be good here.

Also with this patch we should be able to throw out the hacks for tv-out.
I only added those because the reported mode-timings are massively off
(due to the magic tv scaler thing) from the real timestamps we receive.
Auto-detecting this is much better.

And another issue: Failing to match the reported mode timings is a driver
bug. I think a separate testcase which _only_ does the ts calibration (and
makes it a fail/pass instead of require/pass) would be great. I think
having an expectation that the timings userspace asks for is the timing it
gets would be great for kms ;-)

Ack on the patch.
-Daniel

> +
> +	return 2*fabs(median - expected) / expected;
> +}
> +
>  static void run_test_on_crtc_set(struct test_output *o, int *crtc_idxs,
>  				 int crtc_count, int duration_ms)
>  {
> @@ -1404,7 +1473,7 @@ static void run_test_on_crtc_set(struct test_output *o, int *crtc_idxs,
>  
>  	/* quiescent the hw a bit so ensure we don't miss a single frame */
>  	if (o->flags & TEST_CHECK_TS)
> -		sleep(1);
> +		o->ts_error = calibrate_ts(o, crtc_idxs[0]);
>  
>  	igt_assert_eq(do_page_flip(o, o->fb_ids[1], true), 0);
>  	wait_for_events(o);
> -- 
> 2.10.1
> 
> _______________________________________________
> Intel-gfx mailing list
> Intel-gfx@lists.freedesktop.org
> https://lists.freedesktop.org/mailman/listinfo/intel-gfx

-- 
Daniel Vetter
Software Engineer, Intel Corporation
http://blog.ffwll.ch
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx