drm/i915/execlists: Show preemption progress in GEM_TRACE

We already emit a GEM_TRACE for when we start preemption, but we lack
one to show when the preemption is completed and we return to the regular
queue. This is to continue the investigation into the mysterious

<0>[  197.854177]   <idle>-0       1..s1 197837017us : execlists_submission_tasklet: rcs0 cs-irq head=0 [0], tail=0 [0]
<0>[  197.854209] drv_self-6008    2.... 197837390us : reset_common_ring: rcs0 seqno=15515
<0>[  197.854240] drv_self-6008    2.... 197837415us : reset_common_ring: bcs0 seqno=0
<0>[  197.854270] drv_self-6008    2.... 197837443us : reset_common_ring: vcs0 seqno=0
<0>[  197.854300] drv_self-6008    2.... 197837463us : reset_common_ring: vcs1 seqno=0
<0>[  197.854330] drv_self-6008    2.... 197837482us : reset_common_ring: vecs0 seqno=0
<0>[  197.854360] ksoftirq-23      2..s. 197838341us : execlists_submission_tasklet: bcs0 in[0]:  ctx=0.1, seqno=1dce7
<0>[  197.854392]   <idle>-0       1..s1 197838347us : execlists_submission_tasklet: bcs0 cs-irq head=0 [0], tail=0 [0]
<0>[  197.854423] ksoftirq-23      2..s. 197838354us : execlists_submission_tasklet: vcs0 in[0]:  ctx=0.1, seqno=1d027
<0>[  197.854456] ksoftirq-23      2.Ns. 197838361us : execlists_submission_tasklet: vcs1 in[0]:  ctx=0.1, seqno=1e738
<0>[  197.854488] ksoftirq-23      2.Ns. 197838366us : execlists_submission_tasklet: vecs0 in[0]:  ctx=0.1, seqno=235aa
<0>[  197.854520] ksoftirq-23      2.Ns. 197838376us : execlists_submission_tasklet: rcs0 in[0]:  ctx=0.1, seqno=15518
<0>[  197.854552]   <idle>-0       1..s1 197853285us : execlists_submission_tasklet: rcs0 cs-irq head=0 [0], tail=7 [7]
<0>[  197.854584]   <idle>-0       1..s1 197853285us : execlists_submission_tasklet: rcs0 csb[1]: status=0x00000018:0x00000000
<0>[  197.854616]   <idle>-0       1..s1 197853286us : execlists_submission_tasklet: rcs0 out[0]: ctx=0.0, seqno=0

Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>
Cc: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
Link: https://patchwork.freedesktop.org/patch/msgid/20171222132742.4272-1-chris@chris-wilson.co.uk
Reviewed-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>

drivers/gpu/drm/i915/intel_lrc.c

@@ -861,9 +861,10 @@ static void execlists_submission_tasklet(unsigned long data)
 			 */
 
 			status = READ_ONCE(buf[2 * head]); /* maybe mmio! */
-			GEM_TRACE("%s csb[%d]: status=0x%08x:0x%08x\n",
+			GEM_TRACE("%s csb[%d]: status=0x%08x:0x%08x, active=0x%x\n",
 				  engine->name, head,
-				  status, buf[2*head + 1]);
+				  status, buf[2*head + 1],
+				  execlists->active);
 
 			if (status & (GEN8_CTX_STATUS_IDLE_ACTIVE |
 				      GEN8_CTX_STATUS_PREEMPTED))
@@ -881,6 +882,8 @@ static void execlists_submission_tasklet(unsigned long data)
 
 			if (status & GEN8_CTX_STATUS_COMPLETE &&
 			    buf[2*head + 1] == PREEMPT_ID) {
+				GEM_TRACE("%s preempt-idle\n", engine->name);
+
 				execlists_cancel_port_requests(execlists);
 				execlists_unwind_incomplete_requests(execlists);