define and use trace macros

discussed with kettenis

5 files changed, 460 insertions, 133 deletions

diff --git a/sys/dev/pci/drm/i915/i915_drv.c b/sys/dev/pci/drm/i915/i915_drv.c
index 17c2e8ed516..a71a13b150d 100644
--- a/sys/dev/pci/drm/i915/i915_drv.c
+++ b/sys/dev/pci/drm/i915/i915_drv.c
@@ -1,4 +1,4 @@
-/* $OpenBSD: i915_drv.c,v 1.81 2015/04/18 11:21:12 jsg Exp $ */
+/* $OpenBSD: i915_drv.c,v 1.82 2015/04/18 11:41:28 jsg Exp $ */
 /*
  * Copyright (c) 2008-2009 Owain G. Ainsworth <oga@openbsd.org>
  *
@@ -49,8 +49,8 @@
 #include <dev/pci/drm/drm.h>
 #include <dev/pci/drm/i915_drm.h>
 #include "i915_drv.h"
-#include "intel_drv.h"
 #include "i915_trace.h"
+#include "intel_drv.h"
 
 #include <machine/pmap.h>
 
diff --git a/sys/dev/pci/drm/i915/i915_drv.h b/sys/dev/pci/drm/i915/i915_drv.h
index 5fa4dda51a3..ecec03e0aa9 100644
--- a/sys/dev/pci/drm/i915/i915_drv.h
+++ b/sys/dev/pci/drm/i915/i915_drv.h
@@ -1,4 +1,4 @@
-/* $OpenBSD: i915_drv.h,v 1.61 2015/04/17 00:54:42 jsg Exp $ */
+/* $OpenBSD: i915_drv.h,v 1.62 2015/04/18 11:41:28 jsg Exp $ */
 /* i915_drv.h -- Private header for the I915 driver -*- linux-c -*-
  */
 /*
@@ -1339,6 +1339,8 @@ struct drm_i915_file_private {
 
 #define GT_FREQUENCY_MULTIPLIER 50
 
+#include "i915_trace.h"
+
 /**
  * RC6 is a special power stage which allows the GPU to enter an very
  * low-voltage mode when idle, using down to 0V while at this stage.  This
diff --git a/sys/dev/pci/drm/i915/i915_gem.c b/sys/dev/pci/drm/i915/i915_gem.c
index e9609ebbb04..4e5f4515520 100644
--- a/sys/dev/pci/drm/i915/i915_gem.c
+++ b/sys/dev/pci/drm/i915/i915_gem.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: i915_gem.c,v 1.92 2015/04/17 00:54:42 jsg Exp $	*/
+/*	$OpenBSD: i915_gem.c,v 1.93 2015/04/18 11:41:28 jsg Exp $	*/
 /*
  * Copyright (c) 2008-2009 Owain G. Ainsworth <oga@openbsd.org>
  *
@@ -3200,9 +3200,9 @@ i915_gem_clflush_object(struct drm_i915_gem_object *obj)
 	if (obj->cache_level != I915_CACHE_NONE)
 		return;
 
-#if 0
 	trace_i915_gem_object_clflush(obj);
 
+#if 0
 	drm_clflush_sg(obj->pages);
 #else
 {
diff --git a/sys/dev/pci/drm/i915/i915_trace.h b/sys/dev/pci/drm/i915/i915_trace.h
index 1bffe656e48..b381f7a77a0 100644
--- a/sys/dev/pci/drm/i915/i915_trace.h
+++ b/sys/dev/pci/drm/i915/i915_trace.h
@@ -1,126 +1,451 @@
-/*	$OpenBSD: i915_trace.h,v 1.11 2015/04/12 17:10:07 kettenis Exp $	*/
-/*
- * Copyright (c) 2013 Mark Kettenis <kettenis@openbsd.org>
- *
- * Permission to use, copy, modify, and distribute this software for any
- * purpose with or without fee is hereby granted, provided that the above
- * copyright notice and this permission notice appear in all copies.
- *
- * THE SOFTWARE IS PROVIDED "AS IS" AND THE AUTHOR DISCLAIMS ALL WARRANTIES
- * WITH REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES OF
- * MERCHANTABILITY AND FITNESS. IN NO EVENT SHALL THE AUTHOR BE LIABLE FOR
- * ANY SPECIAL, DIRECT, INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES
- * WHATSOEVER RESULTING FROM LOSS OF USE, DATA OR PROFITS, WHETHER IN AN
- * ACTION OF CONTRACT, NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING OUT OF
- * OR IN CONNECTION WITH THE USE OR PERFORMANCE OF THIS SOFTWARE.
- */
-
-static inline void
-trace_i915_gem_object_create(struct drm_i915_gem_object *obj)
-{
-}
-
-static inline void
-trace_i915_gem_object_destroy(struct drm_i915_gem_object *obj)
-{
-}
-
-static inline void
-trace_i915_gem_request_add(struct intel_ring_buffer *ring, u32 seqno)
-{
-}
-
-static inline void
-trace_i915_gem_request_complete(struct intel_ring_buffer *ring, u32 seqno)
-{
-}
-
-static inline void
-trace_i915_gem_request_retire(struct intel_ring_buffer *ring, u32 seqno)
-{
-}
-
-static inline void
-trace_i915_gem_request_wait_begin(struct intel_ring_buffer *ring, u32 seqno)
-{
-}
-
-static inline void
-trace_i915_gem_request_wait_end(struct intel_ring_buffer *ring, u32 seqno)
-{
-}
-
-static inline void
-trace_i915_ring_wait_begin(struct intel_ring_buffer *ring)
-{
-}
-
-static inline void
-trace_i915_ring_wait_end(struct intel_ring_buffer *ring)
-{
-}
-
-static inline void
-trace_i915_flip_request(int plane, struct drm_i915_gem_object *obj)
-{
-}
-
-static inline void
-trace_i915_flip_complete(int plane, struct drm_i915_gem_object *obj)
-{
-}
-
-static inline void
-trace_i915_gem_object_change_domain(struct drm_i915_gem_object *obj,
-				    u32 old_read, u32 old_write)
-{
-}
-
-static inline void
-trace_i915_gem_object_pwrite(struct drm_i915_gem_object *obj,
-			     u32 offset, u32 len)
-{
-}
-
-static inline void
-trace_i915_gem_object_pread(struct drm_i915_gem_object *obj,
-			    u32 offset, u32 len)
-{
-}
-
-static inline void
-trace_i915_gem_object_bind(struct drm_i915_gem_object *obj, bool mappable)
-{
-}
-
-static inline void
-trace_i915_gem_object_unbind(struct drm_i915_gem_object *obj)
-{
-}
-
-static inline void
-trace_i915_reg_rw(bool write, u32 reg, u64 val, int len)
-{
-}
-
-static inline void
-trace_i915_gem_evict(struct drm_device *dev, u32 size, u32 align, bool mappable)
-{
-}
-
-static inline void
-trace_i915_gem_evict_everything(struct drm_device *dev)
-{
-}
-
-static inline void
-trace_i915_gem_ring_dispatch(struct intel_ring_buffer *ring, u32 seqno,
-			     u32 flags)
-{
-}
-
-static inline void
-trace_i915_gem_ring_flush(struct intel_ring_buffer *ring, u32 invalidate,
-			     u32 flush)
-{
-}
+/*	$OpenBSD: i915_trace.h,v 1.12 2015/04/18 11:41:28 jsg Exp $	*/
+#if !defined(_I915_TRACE_H_) || defined(TRACE_HEADER_MULTI_READ)
+#define _I915_TRACE_H_
+
+#include <dev/pci/drm/drmP.h>
+#include "i915_drv.h"
+#include "intel_ringbuffer.h"
+
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM i915
+#define TRACE_SYSTEM_STRING __stringify(TRACE_SYSTEM)
+#define TRACE_INCLUDE_FILE i915_trace
+
+/* object tracking */
+
+TRACE_EVENT(i915_gem_object_create,
+	    TP_PROTO(struct drm_i915_gem_object *obj),
+	    TP_ARGS(obj),
+
+	    TP_STRUCT__entry(
+			     __field(struct drm_i915_gem_object *, obj)
+			     __field(u32, size)
+			     ),
+
+	    TP_fast_assign(
+			   __entry->obj = obj;
+			   __entry->size = obj->base.size;
+			   ),
+
+	    TP_printk("obj=%p, size=%u", __entry->obj, __entry->size)
+);
+
+TRACE_EVENT(i915_gem_object_bind,
+	    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, offset)
+			     __field(u32, size)
+			     __field(bool, mappable)
+			     ),
+
+	    TP_fast_assign(
+			   __entry->obj = obj;
+			   __entry->offset = obj->gtt_space->start;
+			   __entry->size = obj->gtt_space->size;
+			   __entry->mappable = mappable;
+			   ),
+
+	    TP_printk("obj=%p, offset=%08x size=%x%s",
+		      __entry->obj, __entry->offset, __entry->size,
+		      __entry->mappable ? ", mappable" : "")
+);
+
+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_fast_assign(
+			   __entry->obj = obj;
+			   __entry->offset = obj->gtt_space->start;
+			   __entry->size = obj->gtt_space->size;
+			   ),
+
+	    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)
+			     __field(u32, read_domains)
+			     __field(u32, write_domain)
+			     ),
+
+	    TP_fast_assign(
+			   __entry->obj = obj;
+			   __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=%02x=>%02x, write=%02x=>%02x",
+		      __entry->obj,
+		      __entry->read_domains >> 16,
+		      __entry->read_domains & 0xffff,
+		      __entry->write_domain >> 16,
+		      __entry->write_domain & 0xffff)
+);
+
+TRACE_EVENT(i915_gem_object_pwrite,
+	    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, 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, offset=%u, len=%u",
+		      __entry->obj, __entry->offset, __entry->len)
+);
+
+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_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_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)
+);
+
+TRACE_EVENT(i915_gem_evict,
+	    TP_PROTO(struct drm_device *dev, u32 size, u32 align, bool mappable),
+	    TP_ARGS(dev, size, align, mappable),
+
+	    TP_STRUCT__entry(
+			     __field(u32, dev)
+			     __field(u32, size)
+			     __field(u32, align)
+			     __field(bool, mappable)
+			    ),
+
+	    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" : "")
+);
+
+TRACE_EVENT(i915_gem_evict_everything,
+	    TP_PROTO(struct drm_device *dev),
+	    TP_ARGS(dev),
+
+	    TP_STRUCT__entry(
+			     __field(u32, dev)
+			    ),
+
+	    TP_fast_assign(
+			   __entry->dev = dev->primary->index;
+			  ),
+
+	    TP_printk("dev=%d", __entry->dev)
+);
+
+TRACE_EVENT(i915_gem_ring_dispatch,
+	    TP_PROTO(struct intel_ring_buffer *ring, u32 seqno, u32 flags),
+	    TP_ARGS(ring, seqno, flags),
+
+	    TP_STRUCT__entry(
+			     __field(u32, dev)
+			     __field(u32, ring)
+			     __field(u32, seqno)
+			     __field(u32, flags)
+			     ),
+
+	    TP_fast_assign(
+			   __entry->dev = ring->dev->primary->index;
+			   __entry->ring = ring->id;
+			   __entry->seqno = seqno;
+			   __entry->flags = flags;
+			   i915_trace_irq_get(ring, seqno);
+			   ),
+
+	    TP_printk("dev=%u, ring=%u, seqno=%u, flags=%x",
+		      __entry->dev, __entry->ring, __entry->seqno, __entry->flags)
+);
+
+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, ring)
+			     __field(u32, invalidate)
+			     __field(u32, flush)
+			     ),
+
+	    TP_fast_assign(
+			   __entry->dev = ring->dev->primary->index;
+			   __entry->ring = ring->id;
+			   __entry->invalidate = invalidate;
+			   __entry->flush = flush;
+			   ),
+
+	    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 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 = ring->dev->primary->index;
+			   __entry->ring = ring->id;
+			   __entry->seqno = seqno;
+			   ),
+
+	    TP_printk("dev=%u, ring=%u, seqno=%u",
+		      __entry->dev, __entry->ring, __entry->seqno)
+);
+
+DEFINE_EVENT(i915_gem_request, i915_gem_request_add,
+	    TP_PROTO(struct intel_ring_buffer *ring, u32 seqno),
+	    TP_ARGS(ring, 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 intel_ring_buffer *ring, u32 seqno),
+	    TP_ARGS(ring, seqno)
+);
+
+TRACE_EVENT(i915_gem_request_wait_begin,
+	    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)
+			     __field(bool, blocking)
+			     ),
+
+	    /* NB: the blocking information is racy since mutex_is_locked
+	     * doesn't check that the current thread holds the lock. The only
+	     * other option would be to pass the boolean information of whether
+	     * or not the class was blocking down through the stack which is
+	     * less desirable.
+	     */
+	    TP_fast_assign(
+			   __entry->dev = ring->dev->primary->index;
+			   __entry->ring = ring->id;
+			   __entry->seqno = seqno;
+			   __entry->blocking = mutex_is_locked(&ring->dev->struct_mutex);
+			   ),
+
+	    TP_printk("dev=%u, ring=%u, seqno=%u, blocking=%s",
+		      __entry->dev, __entry->ring, __entry->seqno,
+		      __entry->blocking ?  "yes (NB)" : "no")
+);
+
+DEFINE_EVENT(i915_gem_request, i915_gem_request_wait_end,
+	    TP_PROTO(struct intel_ring_buffer *ring, u32 seqno),
+	    TP_ARGS(ring, seqno)
+);
+
+DECLARE_EVENT_CLASS(i915_ring,
+	    TP_PROTO(struct intel_ring_buffer *ring),
+	    TP_ARGS(ring),
+
+	    TP_STRUCT__entry(
+			     __field(u32, dev)
+			     __field(u32, ring)
+			     ),
+
+	    TP_fast_assign(
+			   __entry->dev = ring->dev->primary->index;
+			   __entry->ring = ring->id;
+			   ),
+
+	    TP_printk("dev=%u, ring=%u", __entry->dev, __entry->ring)
+);
+
+DEFINE_EVENT(i915_ring, i915_ring_wait_begin,
+	    TP_PROTO(struct intel_ring_buffer *ring),
+	    TP_ARGS(ring)
+);
+
+DEFINE_EVENT(i915_ring, i915_ring_wait_end,
+	    TP_PROTO(struct intel_ring_buffer *ring),
+	    TP_ARGS(ring)
+);
+
+TRACE_EVENT(i915_flip_request,
+	    TP_PROTO(int plane, struct drm_i915_gem_object *obj),
+
+	    TP_ARGS(plane, obj),
+
+	    TP_STRUCT__entry(
+		    __field(int, plane)
+		    __field(struct drm_i915_gem_object *, obj)
+		    ),
+
+	    TP_fast_assign(
+		    __entry->plane = plane;
+		    __entry->obj = obj;
+		    ),
+
+	    TP_printk("plane=%d, obj=%p", __entry->plane, __entry->obj)
+);
+
+TRACE_EVENT(i915_flip_complete,
+	    TP_PROTO(int plane, struct drm_i915_gem_object *obj),
+
+	    TP_ARGS(plane, obj),
+
+	    TP_STRUCT__entry(
+		    __field(int, plane)
+		    __field(struct drm_i915_gem_object *, obj)
+		    ),
+
+	    TP_fast_assign(
+		    __entry->plane = plane;
+		    __entry->obj = obj;
+		    ),
+
+	    TP_printk("plane=%d, obj=%p", __entry->plane, __entry->obj)
+);
+
+TRACE_EVENT(i915_reg_rw,
+	TP_PROTO(bool write, u32 reg, u64 val, int len),
+
+	TP_ARGS(write, reg, val, len),
+
+	TP_STRUCT__entry(
+		__field(u64, val)
+		__field(u32, reg)
+		__field(u16, write)
+		__field(u16, len)
+		),
+
+	TP_fast_assign(
+		__entry->val = (u64)val;
+		__entry->reg = reg;
+		__entry->write = write;
+		__entry->len = 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))
+);
+
+TRACE_EVENT(intel_gpu_freq_change,
+	    TP_PROTO(u32 freq),
+	    TP_ARGS(freq),
+
+	    TP_STRUCT__entry(
+			     __field(u32, freq)
+			     ),
+
+	    TP_fast_assign(
+			   __entry->freq = freq;
+			   ),
+
+	    TP_printk("new_freq=%u", __entry->freq)
+);
+
+#endif /* _I915_TRACE_H_ */
+
+/* This part must be outside protection */
+#undef TRACE_INCLUDE_PATH
+#define TRACE_INCLUDE_PATH .
diff --git a/sys/dev/pci/drm/i915/intel_pm.c b/sys/dev/pci/drm/i915/intel_pm.c
index 0571757d690..5701329e1ab 100644
--- a/sys/dev/pci/drm/i915/intel_pm.c
+++ b/sys/dev/pci/drm/i915/intel_pm.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: intel_pm.c,v 1.32 2015/04/12 11:26:54 jsg Exp $	*/
+/*	$OpenBSD: intel_pm.c,v 1.33 2015/04/18 11:41:29 jsg Exp $	*/
 /*
  * Copyright © 2012 Intel Corporation
  *
@@ -2488,7 +2488,7 @@ void gen6_set_rps(struct drm_device *dev, u8 val)
 
 	dev_priv->rps.cur_delay = val;
 
-//	trace_intel_gpu_freq_change(val * 50);
+	trace_intel_gpu_freq_change(val * 50);
 }
 
 static void gen6_disable_rps(struct drm_device *dev)