diff mbox series

[i-g-t] i915/i915_pm_rc6_residency: Show where the time is spent

Message ID 20200408125946.2054864-1-chris@chris-wilson.co.uk (mailing list archive)
State New, archived
Headers show
Series [i-g-t] i915/i915_pm_rc6_residency: Show where the time is spent | expand

Commit Message

Chris Wilson April 8, 2020, 12:59 p.m. UTC 
Sometimes the bg_load only wakes up once or twice in 3s. That's
just unbelievable, so include some measurements to see how long the
load spends in submission & waiting.

Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>
---
 tests/i915/i915_pm_rc6_residency.c | 12 +++++++++++-
 1 file changed, 11 insertions(+), 1 deletion(-)

Comments

Andi Shyti April 9, 2020, 8:43 p.m. UTC | #1 
Hi Chris,

On Wed, Apr 08, 2020 at 01:59:46PM +0100, Chris Wilson wrote:
> Sometimes the bg_load only wakes up once or twice in 3s. That's
> just unbelievable, so include some measurements to see how long the
> load spends in submission & waiting.
> 
> Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

Reviewed-by: Andi Shyti <andi.shyti@intel.com>

Andi
diff mbox series

Patch

diff --git a/tests/i915/i915_pm_rc6_residency.c b/tests/i915/i915_pm_rc6_residency.c
index cd1a6c8d6..15efba186 100644
--- a/tests/i915/i915_pm_rc6_residency.c
+++ b/tests/i915/i915_pm_rc6_residency.c
@@ -304,11 +304,13 @@  static void bg_load(int i915, unsigned int flags, unsigned long *ctl)
 
 	sigaction(SIGINT, &act, NULL);
 	do {
+		uint64_t submit, wait, elapsed;
 		struct timespec tv = {};
 
 		igt_nsec_elapsed(&tv);
 
 		gem_execbuf(i915, &execbuf);
+		submit = igt_nsec_elapsed(&tv);
 		if (flags & WAITBOOST) {
 			gem_sync(i915, obj.handle);
 			if (flags & ONCE)
@@ -317,6 +319,7 @@  static void bg_load(int i915, unsigned int flags, unsigned long *ctl)
 			while (gem_bo_busy(i915, obj.handle))
 				usleep(0);
 		}
+		wait = igt_nsec_elapsed(&tv);
 		ctl[1]++;
 
 		/*
@@ -330,8 +333,15 @@  static void bg_load(int i915, unsigned int flags, unsigned long *ctl)
 		if (!gem_has_execlists(i915))
 			igt_drop_caches_set(i915, DROP_IDLE);
 
+		elapsed = igt_nsec_elapsed(&tv);
+		igt_info("Pulse took %.3fms (submit %.1fus, wait %.1fus, idle %.1fus)\n",
+			 1e-6 * elapsed,
+			 1e-3 * submit,
+			 1e-3 * (wait - submit),
+			 1e-3 * (elapsed - wait));
+
 		/* aim for ~1% busy */
-		usleep(min(igt_nsec_elapsed(&tv) / 10, 50 * 1000));
+		usleep(min(elapsed / 10, 50 * 1000));
 	} while (!READ_ONCE(*ctl));
 }