drm/i915: Refine tracepoints

A lot of minor tweaks to fix the tracepoints, improve the outputting for
ftrace, and to generally make the tracepoints useful again. It is a start
and enough to begin identifying performance issues and gaps in our
coverage.

Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

1 files changed, 204 insertions, 97 deletions

diff --git a/drivers/gpu/drm/i915/i915_trace.h b/drivers/gpu/drm/i915/i915_trace.h
index 7f0fc3ed61aa..d623fefbfaca 100644
--- a/drivers/gpu/drm/i915/i915_trace.h
+++ b/drivers/gpu/drm/i915/i915_trace.h
@@ -7,6 +7,7 @@
 
 #include <drm/drmP.h>
 #include "i915_drv.h"
+#include "intel_ringbuffer.h"
 
 #undef TRACE_SYSTEM
 #define TRACE_SYSTEM i915
@@ -16,9 +17,7 @@
 /* object tracking */
 
 TRACE_EVENT(i915_gem_object_create,
-
             TP_PROTO(struct drm_i915_gem_object *obj),
-
             TP_ARGS(obj),
 
             TP_STRUCT__entry(
@@ -35,33 +34,51 @@ TRACE_EVENT(i915_gem_object_create,
 );
 
 TRACE_EVENT(i915_gem_object_bind,
-
-            TP_PROTO(struct drm_i915_gem_object *obj, u32 gtt_offset, bool mappable),
-
-            TP_ARGS(obj, gtt_offset, mappable),
+            TP_PROTO(struct drm_i915_gem_object *obj, bool mappable),
+            TP_ARGS(obj, mappable),
 
             TP_STRUCT__entry(
                              __field(struct drm_i915_gem_object *, obj)
-                             __field(u32, gtt_offset)
+                             __field(u32, offset)
+                             __field(u32, size)
                              __field(bool, mappable)
                              ),
 
             TP_fast_assign(
                            __entry->obj = obj;
-                           __entry->gtt_offset = gtt_offset;
+                           __entry->offset = obj->gtt_space->start;
+                           __entry->size = obj->gtt_space->size;
                            __entry->mappable = mappable;
                            ),
 
-            TP_printk("obj=%p, gtt_offset=%08x%s",
-                      __entry->obj, __entry->gtt_offset,
+            TP_printk("obj=%p, offset=%08x size=%x%s",
+                      __entry->obj, __entry->offset, __entry->size,
                       __entry->mappable ? ", mappable" : "")
 );
 
-TRACE_EVENT(i915_gem_object_change_domain,
+TRACE_EVENT(i915_gem_object_unbind,
+            TP_PROTO(struct drm_i915_gem_object *obj),
+            TP_ARGS(obj),
+
+            TP_STRUCT__entry(
+                             __field(struct drm_i915_gem_object *, obj)
+                             __field(u32, offset)
+                             __field(u32, size)
+                             ),
 
-            TP_PROTO(struct drm_i915_gem_object *obj, uint32_t old_read_domains, uint32_t old_write_domain),
+            TP_fast_assign(
+                           __entry->obj = obj;
+                           __entry->offset = obj->gtt_space->start;
+                           __entry->size = obj->gtt_space->size;
+                           ),
 
-            TP_ARGS(obj, old_read_domains, old_write_domain),
+            TP_printk("obj=%p, offset=%08x size=%x",
+                      __entry->obj, __entry->offset, __entry->size)
+);
+
+TRACE_EVENT(i915_gem_object_change_domain,
+            TP_PROTO(struct drm_i915_gem_object *obj, u32 old_read, u32 old_write),
+            TP_ARGS(obj, old_read, old_write),
 
             TP_STRUCT__entry(
                              __field(struct drm_i915_gem_object *, obj)
@@ -71,177 +88,264 @@ TRACE_EVENT(i915_gem_object_change_domain,
 
             TP_fast_assign(
                            __entry->obj = obj;
-                           __entry->read_domains = obj->base.read_domains | (old_read_domains << 16);
-                           __entry->write_domain = obj->base.write_domain | (old_write_domain << 16);
+                           __entry->read_domains = obj->base.read_domains | (old_read << 16);
+                           __entry->write_domain = obj->base.write_domain | (old_write << 16);
                            ),
 
-            TP_printk("obj=%p, read=%04x, write=%04x",
+            TP_printk("obj=%p, read=%02x=>%02x, write=%02x=>%02x",
                       __entry->obj,
-                      __entry->read_domains, __entry->write_domain)
+                      __entry->read_domains >> 16,
+                      __entry->read_domains & 0xffff,
+                      __entry->write_domain >> 16,
+                      __entry->write_domain & 0xffff)
 );
 
-DECLARE_EVENT_CLASS(i915_gem_object,
+TRACE_EVENT(i915_gem_object_pwrite,
+            TP_PROTO(struct drm_i915_gem_object *obj, u32 offset, u32 len),
+            TP_ARGS(obj, offset, len),
 
-            TP_PROTO(struct drm_i915_gem_object *obj),
+            TP_STRUCT__entry(
+                             __field(struct drm_i915_gem_object *, obj)
+                             __field(u32, offset)
+                             __field(u32, len)
+                             ),
 
-            TP_ARGS(obj),
+            TP_fast_assign(
+                           __entry->obj = obj;
+                           __entry->offset = offset;
+                           __entry->len = len;
+                           ),
+
+            TP_printk("obj=%p, offset=%u, len=%u",
+                      __entry->obj, __entry->offset, __entry->len)
+);
+
+TRACE_EVENT(i915_gem_object_pread,
+            TP_PROTO(struct drm_i915_gem_object *obj, u32 offset, u32 len),
+            TP_ARGS(obj, offset, len),
 
             TP_STRUCT__entry(
                              __field(struct drm_i915_gem_object *, obj)
+                             __field(u32, offset)
+                             __field(u32, len)
                              ),
 
             TP_fast_assign(
                            __entry->obj = obj;
+                           __entry->offset = offset;
+                           __entry->len = len;
                            ),
 
-            TP_printk("obj=%p", __entry->obj)
+            TP_printk("obj=%p, offset=%u, len=%u",
+                      __entry->obj, __entry->offset, __entry->len)
 );
 
-DEFINE_EVENT(i915_gem_object, i915_gem_object_clflush,
+TRACE_EVENT(i915_gem_object_fault,
+            TP_PROTO(struct drm_i915_gem_object *obj, u32 index, bool gtt, bool write),
+            TP_ARGS(obj, index, gtt, write),
+
+            TP_STRUCT__entry(
+                             __field(struct drm_i915_gem_object *, obj)
+                             __field(u32, index)
+                             __field(bool, gtt)
+                             __field(bool, write)
+                             ),
+
+            TP_fast_assign(
+                           __entry->obj = obj;
+                           __entry->index = index;
+                           __entry->gtt = gtt;
+                           __entry->write = write;
+                           ),
 
+            TP_printk("obj=%p, %s index=%u %s",
+                      __entry->obj,
+                      __entry->gtt ? "GTT" : "CPU",
+                      __entry->index,
+                      __entry->write ? ", writable" : "")
+);
+
+DECLARE_EVENT_CLASS(i915_gem_object,
             TP_PROTO(struct drm_i915_gem_object *obj),
+            TP_ARGS(obj),
 
-            TP_ARGS(obj)
+            TP_STRUCT__entry(
+                             __field(struct drm_i915_gem_object *, obj)
+                             ),
+
+            TP_fast_assign(
+                           __entry->obj = obj;
+                           ),
+
+            TP_printk("obj=%p", __entry->obj)
 );
 
-DEFINE_EVENT(i915_gem_object, i915_gem_object_unbind,
+DEFINE_EVENT(i915_gem_object, i915_gem_object_clflush,
+             TP_PROTO(struct drm_i915_gem_object *obj),
+             TP_ARGS(obj)
+);
 
+DEFINE_EVENT(i915_gem_object, i915_gem_object_destroy,
             TP_PROTO(struct drm_i915_gem_object *obj),
-
             TP_ARGS(obj)
 );
 
-DEFINE_EVENT(i915_gem_object, i915_gem_object_destroy,
+TRACE_EVENT(i915_gem_evict,
+            TP_PROTO(struct drm_device *dev, u32 size, u32 align, bool mappable),
+            TP_ARGS(dev, size, align, mappable),
 
-            TP_PROTO(struct drm_i915_gem_object *obj),
+            TP_STRUCT__entry(
+                             __field(u32, dev)
+                             __field(u32, size)
+                             __field(u32, align)
+                             __field(bool, mappable)
+                            ),
 
-            TP_ARGS(obj)
+            TP_fast_assign(
+                           __entry->dev = dev->primary->index;
+                           __entry->size = size;
+                           __entry->align = align;
+                           __entry->mappable = mappable;
+                          ),
+
+            TP_printk("dev=%d, size=%d, align=%d %s",
+                      __entry->dev, __entry->size, __entry->align,
+                      __entry->mappable ? ", mappable" : "")
 );
 
-/* batch tracing */
+TRACE_EVENT(i915_gem_evict_everything,
+            TP_PROTO(struct drm_device *dev, bool purgeable),
+            TP_ARGS(dev, purgeable),
 
-TRACE_EVENT(i915_gem_request_submit,
+            TP_STRUCT__entry(
+                             __field(u32, dev)
+                             __field(bool, purgeable)
+                            ),
+
+            TP_fast_assign(
+                           __entry->dev = dev->primary->index;
+                           __entry->purgeable = purgeable;
+                          ),
 
-            TP_PROTO(struct drm_device *dev, u32 seqno),
+            TP_printk("dev=%d%s",
+                      __entry->dev,
+                      __entry->purgeable ? ", purgeable only" : "")
+);
 
-            TP_ARGS(dev, seqno),
+TRACE_EVENT(i915_gem_ring_dispatch,
+            TP_PROTO(struct intel_ring_buffer *ring, u32 seqno),
+            TP_ARGS(ring, seqno),
 
             TP_STRUCT__entry(
                              __field(u32, dev)
+                             __field(u32, ring)
                              __field(u32, seqno)
                              ),
 
             TP_fast_assign(
-                           __entry->dev = dev->primary->index;
+                           __entry->dev = ring->dev->primary->index;
+                           __entry->ring = ring->id;
                            __entry->seqno = seqno;
-                           i915_trace_irq_get(dev, seqno);
+                           i915_trace_irq_get(ring, seqno);
                            ),
 
-            TP_printk("dev=%u, seqno=%u", __entry->dev, __entry->seqno)
+            TP_printk("dev=%u, ring=%u, seqno=%u",
+                      __entry->dev, __entry->ring, __entry->seqno)
 );
 
-TRACE_EVENT(i915_gem_request_flush,
-
-            TP_PROTO(struct drm_device *dev, u32 seqno,
-                     u32 flush_domains, u32 invalidate_domains),
-
-            TP_ARGS(dev, seqno, flush_domains, invalidate_domains),
+TRACE_EVENT(i915_gem_ring_flush,
+            TP_PROTO(struct intel_ring_buffer *ring, u32 invalidate, u32 flush),
+            TP_ARGS(ring, invalidate, flush),
 
             TP_STRUCT__entry(
                              __field(u32, dev)
-                             __field(u32, seqno)
-                             __field(u32, flush_domains)
-                             __field(u32, invalidate_domains)
+                             __field(u32, ring)
+                             __field(u32, invalidate)
+                             __field(u32, flush)
                              ),
 
             TP_fast_assign(
-                           __entry->dev = dev->primary->index;
-                           __entry->seqno = seqno;
-                           __entry->flush_domains = flush_domains;
-                           __entry->invalidate_domains = invalidate_domains;
+                           __entry->dev = ring->dev->primary->index;
+                           __entry->ring = ring->id;
+                           __entry->invalidate = invalidate;
+                           __entry->flush = flush;
                            ),
 
-            TP_printk("dev=%u, seqno=%u, flush=%04x, invalidate=%04x",
-                      __entry->dev, __entry->seqno,
-                      __entry->flush_domains, __entry->invalidate_domains)
+            TP_printk("dev=%u, ring=%x, invalidate=%04x, flush=%04x",
+                      __entry->dev, __entry->ring,
+                      __entry->invalidate, __entry->flush)
 );
 
 DECLARE_EVENT_CLASS(i915_gem_request,
-
-            TP_PROTO(struct drm_device *dev, u32 seqno),
-
-            TP_ARGS(dev, seqno),
+            TP_PROTO(struct intel_ring_buffer *ring, u32 seqno),
+            TP_ARGS(ring, seqno),
 
             TP_STRUCT__entry(
                              __field(u32, dev)
+                             __field(u32, ring)
                              __field(u32, seqno)
                              ),
 
             TP_fast_assign(
-                           __entry->dev = dev->primary->index;
+                           __entry->dev = ring->dev->primary->index;
+                           __entry->ring = ring->id;
                            __entry->seqno = seqno;
                            ),
 
-            TP_printk("dev=%u, seqno=%u", __entry->dev, __entry->seqno)
+            TP_printk("dev=%u, ring=%u, seqno=%u",
+                      __entry->dev, __entry->ring, __entry->seqno)
 );
 
-DEFINE_EVENT(i915_gem_request, i915_gem_request_complete,
-
-            TP_PROTO(struct drm_device *dev, u32 seqno),
+DEFINE_EVENT(i915_gem_request, i915_gem_request_add,
+            TP_PROTO(struct intel_ring_buffer *ring, u32 seqno),
+            TP_ARGS(ring, seqno)
+);
 
-            TP_ARGS(dev, seqno)
+DEFINE_EVENT(i915_gem_request, i915_gem_request_complete,
+            TP_PROTO(struct intel_ring_buffer *ring, u32 seqno),
+            TP_ARGS(ring, seqno)
 );
 
 DEFINE_EVENT(i915_gem_request, i915_gem_request_retire,
-
-            TP_PROTO(struct drm_device *dev, u32 seqno),
-
-            TP_ARGS(dev, seqno)
+            TP_PROTO(struct intel_ring_buffer *ring, u32 seqno),
+            TP_ARGS(ring, seqno)
 );
 
 DEFINE_EVENT(i915_gem_request, i915_gem_request_wait_begin,
-
-            TP_PROTO(struct drm_device *dev, u32 seqno),
-
-            TP_ARGS(dev, seqno)
+            TP_PROTO(struct intel_ring_buffer *ring, u32 seqno),
+            TP_ARGS(ring, seqno)
 );
 
 DEFINE_EVENT(i915_gem_request, i915_gem_request_wait_end,
-
-            TP_PROTO(struct drm_device *dev, u32 seqno),
-
-            TP_ARGS(dev, seqno)
+            TP_PROTO(struct intel_ring_buffer *ring, u32 seqno),
+            TP_ARGS(ring, seqno)
 );
 
 DECLARE_EVENT_CLASS(i915_ring,
-
-            TP_PROTO(struct drm_device *dev),
-
-            TP_ARGS(dev),
+            TP_PROTO(struct intel_ring_buffer *ring),
+            TP_ARGS(ring),
 
             TP_STRUCT__entry(
                              __field(u32, dev)
+                             __field(u32, ring)
                              ),
 
             TP_fast_assign(
-                           __entry->dev = dev->primary->index;
+                           __entry->dev = ring->dev->primary->index;
+                           __entry->ring = ring->id;
                            ),
 
-            TP_printk("dev=%u", __entry->dev)
+            TP_printk("dev=%u, ring=%u", __entry->dev, __entry->ring)
 );
 
 DEFINE_EVENT(i915_ring, i915_ring_wait_begin,
-
-            TP_PROTO(struct drm_device *dev),
-
-            TP_ARGS(dev)
+            TP_PROTO(struct intel_ring_buffer *ring),
+            TP_ARGS(ring)
 );
 
 DEFINE_EVENT(i915_ring, i915_ring_wait_end,
-
-            TP_PROTO(struct drm_device *dev),
-
-            TP_ARGS(dev)
+            TP_PROTO(struct intel_ring_buffer *ring),
+            TP_ARGS(ring)
 );
 
 TRACE_EVENT(i915_flip_request,
@@ -281,26 +385,29 @@ TRACE_EVENT(i915_flip_complete,
 );
 
 TRACE_EVENT(i915_reg_rw,
-           TP_PROTO(int cmd, uint32_t reg, uint64_t val, int len),
+           TP_PROTO(bool write, u32 reg, u64 val, int len),
 
-           TP_ARGS(cmd, reg, val, len),
+           TP_ARGS(write, reg, val, len),
 
            TP_STRUCT__entry(
-                   __field(int, cmd)
-                   __field(uint32_t, reg)
-                   __field(uint64_t, val)
-                   __field(int, len)
+                   __field(u64, val)
+                   __field(u32, reg)
+                   __field(u16, write)
+                   __field(u16, len)
                    ),
 
            TP_fast_assign(
-                   __entry->cmd = cmd;
+                   __entry->val = (u64)val;
                    __entry->reg = reg;
-                   __entry->val = (uint64_t)val;
+                   __entry->write = write;
                    __entry->len = len;
                    ),
 
-           TP_printk("cmd=%c, reg=0x%x, val=0x%llx, len=%d",
-                     __entry->cmd, __entry->reg, __entry->val, __entry->len)
+           TP_printk("%s reg=0x%x, len=%d, val=(0x%x, 0x%x)",
+                     __entry->write ? "write" : "read",
+                     __entry->reg, __entry->len,
+                     (u32)(__entry->val & 0xffffffff),
+                     (u32)(__entry->val >> 32))
 );
 
 #endif /* _I915_TRACE_H_ */