[PATCH 2/5] drm/i915: make waiting trace events more useful

[ben at bwidawsk.net (Ben Widawsky)]

With the new timeout parameter it is somewhat more useful to get trace
events for each iteration of the loop with values we care about.

Signed-off-by: Ben Widawsky <ben at bwidawsk.net>
---
 drivers/gpu/drm/i915/i915_gem.c   |    7 +++---
 drivers/gpu/drm/i915/i915_trace.h |   45 +++++++++++++++++++++++++++++++------
 2 files changed, 42 insertions(+), 10 deletions(-)

diff --git a/drivers/gpu/drm/i915/i915_gem.c b/drivers/gpu/drm/i915/i915_gem.c
index 3c7e632..19ef8bd 100644
--- a/drivers/gpu/drm/i915/i915_gem.c
+++ b/drivers/gpu/drm/i915/i915_gem.c
@@ -1841,8 +1841,6 @@ static int __wait_seqno(struct intel_ring_buffer *ring, u32 seqno,
 	if (i915_seqno_passed(ring->get_seqno(ring), seqno))
 		return 0;
 
-	trace_i915_gem_request_wait_begin(ring, seqno);
-
 	if (timeout == NULL) {
 		timeout = &dummy_time;
 		wait_forever = true;
@@ -1859,6 +1857,8 @@ static int __wait_seqno(struct intel_ring_buffer *ring, u32 seqno,
 	(i915_seqno_passed(ring->get_seqno(ring), seqno) || \
 	atomic_read(&dev_priv->mm.wedged))
 	do {
+		trace_i915_gem_seqno_wait_begin(ring, seqno, timeout_jiffies);
+
 		if (interruptible)
 			end = wait_event_interruptible_timeout(ring->irq_queue,
 							       EXIT_COND,
@@ -1869,12 +1869,13 @@ static int __wait_seqno(struct intel_ring_buffer *ring, u32 seqno,
 
 		if (atomic_read(&dev_priv->mm.wedged))
 			end = -EAGAIN;
+
+		trace_i915_gem_seqno_wait_end(ring, seqno, end);
 	} while(end == 0 && wait_forever);
 
 	jiffies_to_timespec(jiffies - before, &temp);
 
 	ring->irq_put(ring);
-	trace_i915_gem_request_wait_end(ring, seqno);
 #undef EXIT_COND
 
 	jiffies_to_timespec(end, timeout);
diff --git a/drivers/gpu/drm/i915/i915_trace.h b/drivers/gpu/drm/i915/i915_trace.h
index dac7bba..2a4f535 100644
--- a/drivers/gpu/drm/i915/i915_trace.h
+++ b/drivers/gpu/drm/i915/i915_trace.h
@@ -311,16 +311,47 @@ DEFINE_EVENT(i915_gem_request, i915_gem_request_retire,
 	    TP_ARGS(ring, seqno)
 );
 
-DEFINE_EVENT(i915_gem_request, i915_gem_request_wait_begin,
-	    TP_PROTO(struct intel_ring_buffer *ring, u32 seqno),
-	    TP_ARGS(ring, seqno)
-);
+TRACE_EVENT(i915_gem_seqno_wait_begin,
+	    TP_PROTO(struct intel_ring_buffer *ring, u32 seqno, unsigned long timeout),
+	    TP_ARGS(ring, seqno, timeout),
 
-DEFINE_EVENT(i915_gem_request, i915_gem_request_wait_end,
-	    TP_PROTO(struct intel_ring_buffer *ring, u32 seqno),
-	    TP_ARGS(ring, seqno)
+	    TP_STRUCT__entry(
+		    __field(struct intel_ring_buffer *, ring)
+		    __field(u32, seqno)
+		    __field(unsigned long, timeout)
+		    ),
+
+	    TP_fast_assign(
+		    __entry->ring = ring;
+		    __entry->seqno = seqno;
+		    __entry->timeout = timeout;
+		    ),
+
+	    TP_printk("ring=%p, seqno=%u, timeout=%lu", __entry->ring,
+							__entry->seqno,
+							__entry->timeout)
 );
 
+TRACE_EVENT(i915_gem_seqno_wait_end,
+	    TP_PROTO(struct intel_ring_buffer *ring, u32 seqno, long ret),
+	    TP_ARGS(ring, seqno, ret),
+
+	    TP_STRUCT__entry(
+		    __field(struct intel_ring_buffer *, ring)
+		    __field(u32, seqno)
+		    __field(long, ret)
+		    ),
+
+	    TP_fast_assign(
+		    __entry->ring = ring;
+		    __entry->seqno = seqno;
+		    __entry->ret = ret;
+		    ),
+
+	    TP_printk("ring=%p, seqno=%u, ret=%ld", __entry->ring,
+						    __entry->seqno,
+						    __entry->ret)
+);
 DECLARE_EVENT_CLASS(i915_ring,
 	    TP_PROTO(struct intel_ring_buffer *ring),
 	    TP_ARGS(ring),
-- 
1.7.10