[PATCH 0/6] drm: trace: Introduce drm_trace() and instrument drm_atomic.c

[PATCH 0/6] drm: trace: Introduce drm_trace() and instrument drm_atomic.c

[Sean Paul]

From: Sean Paul <seanpaul@chromium.org>

Hey all,
I'm back with another trace events patchset. My first attempt [1] went
better than expected, with enthusiasm for the idea and distain for the
implementation.

As promised, I went through and added proper trace events.

Before I get _too_ far, I wanted to post this set to get feedback on the
direction I'm going. I've gone back and forth on whether to introduce a
bunch of trace systems vs using the trace class enum. I've settled on
the trace class enum since it seems more extensible and easier to use in
production that just having the blunt "enable this system", or
the tedious "enable each event I'm interested in individually" methods.

So, consider this one an RFC unless we're all in agreement, in which
case we should apply it :)

Sean

[1]- https://patchwork.freedesktop.org/patch/335350/

Sean Paul (6):
  drm: trace: Make the vblank queued/delivered events classed
  drm: trace: Introduce drm_trace() and trace event classes
  drm: trace: Add trace events for atomic state lifetime
  drm: trace: Add crtc state trace events
  drm: trace: Add connector state tracing
  drm: trace: Add plane state tracing

 Documentation/gpu/drm-internals.rst |   9 +
 drivers/gpu/drm/drm_atomic.c        |  61 ++-
 drivers/gpu/drm/drm_trace.h         | 563 ++++++++++++++++++++++++++--
 drivers/gpu/drm/drm_vblank.c        |   8 +-
 4 files changed, 609 insertions(+), 32 deletions(-)

-- 
Sean Paul, Software Engineer, Google / Chromium OS

_______________________________________________
dri-devel mailing list
dri-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/dri-devel

[PATCH 1/6] drm: trace: Make the vblank queued/delivered events classed

[Sean Paul]

From: Sean Paul <seanpaul@chromium.org>

We can use an event class to remove some boilerplate for the event
queued/delivered trace events.

Signed-off-by: Sean Paul <seanpaul@chromium.org>
---
 drivers/gpu/drm/drm_trace.h | 27 +++++++++------------------
 1 file changed, 9 insertions(+), 18 deletions(-)

diff --git a/drivers/gpu/drm/drm_trace.h b/drivers/gpu/drm/drm_trace.h
index 11c6dd577e8ed..487bc3478efec 100644
--- a/drivers/gpu/drm/drm_trace.h
+++ b/drivers/gpu/drm/drm_trace.h
@@ -32,7 +32,7 @@ TRACE_EVENT(drm_vblank_event,
 			__entry->high_prec ? "true" : "false")
 );
 
-TRACE_EVENT(drm_vblank_event_queued,
+DECLARE_EVENT_CLASS(class_drm_vblank_event,
 	    TP_PROTO(struct drm_file *file, int crtc, unsigned int seq),
 	    TP_ARGS(file, crtc, seq),
 	    TP_STRUCT__entry(
@@ -45,25 +45,16 @@ TRACE_EVENT(drm_vblank_event_queued,
 		    __entry->crtc = crtc;
 		    __entry->seq = seq;
 		    ),
-	    TP_printk("file=%p, crtc=%d, seq=%u", __entry->file, __entry->crtc, \
+	    TP_printk("file=%p, crtc=%d, seq=%u", __entry->file, __entry->crtc,
 		      __entry->seq)
 );
-
-TRACE_EVENT(drm_vblank_event_delivered,
-	    TP_PROTO(struct drm_file *file, int crtc, unsigned int seq),
-	    TP_ARGS(file, crtc, seq),
-	    TP_STRUCT__entry(
-		    __field(struct drm_file *, file)
-		    __field(int, crtc)
-		    __field(unsigned int, seq)
-		    ),
-	    TP_fast_assign(
-		    __entry->file = file;
-		    __entry->crtc = crtc;
-		    __entry->seq = seq;
-		    ),
-	    TP_printk("file=%p, crtc=%d, seq=%u", __entry->file, __entry->crtc, \
-		      __entry->seq)
+DEFINE_EVENT(class_drm_vblank_event, drm_vblank_event_queued,
+	TP_PROTO(struct drm_file *file, int crtc, unsigned int seq),
+	TP_ARGS(file, crtc, seq)
+);
+DEFINE_EVENT(class_drm_vblank_event, drm_vblank_event_delivered,
+	TP_PROTO(struct drm_file *file, int crtc, unsigned int seq),
+	TP_ARGS(file, crtc, seq)
 );
 
 #endif /* _DRM_TRACE_H_ */
-- 
Sean Paul, Software Engineer, Google / Chromium OS

_______________________________________________
dri-devel mailing list
dri-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/dri-devel

[PATCH 2/6] drm: trace: Introduce drm_trace() and trace event classes

[Sean Paul]

From: Sean Paul <seanpaul@chromium.org>

This patch is the first step in expanding trace events in drm. It
introduces a new enum used to classify trace events as well as a couple
helper macros to issue trace events from around drm.

It's a bit of a toy right now since we're just converting one class
(vblank) and there aren't any error events in this class. However later
patches in this series will add more interesting classes.

Signed-off-by: Sean Paul <seanpaul@chromium.org>
---
 Documentation/gpu/drm-internals.rst |   9 +++
 drivers/gpu/drm/drm_trace.h         | 109 ++++++++++++++++++++++++++--
 drivers/gpu/drm/drm_vblank.c        |   8 +-
 3 files changed, 114 insertions(+), 12 deletions(-)

diff --git a/Documentation/gpu/drm-internals.rst b/Documentation/gpu/drm-internals.rst
index 966bd2d9f0ccd..ac87a94b7057a 100644
--- a/Documentation/gpu/drm-internals.rst
+++ b/Documentation/gpu/drm-internals.rst
@@ -176,6 +176,15 @@ Printer
 .. kernel-doc:: drivers/gpu/drm/drm_print.c
    :export:
 
+Tracing
+-------
+
+.. kernel-doc:: drivers/gpu/drm/drm_trace.h
+   :doc: overview
+
+.. kernel-doc:: drivers/gpu/drm/drm_trace.h
+   :internal:
+
 Utilities
 ---------
 
diff --git a/drivers/gpu/drm/drm_trace.h b/drivers/gpu/drm/drm_trace.h
index 487bc3478efec..19e5f04210586 100644
--- a/drivers/gpu/drm/drm_trace.h
+++ b/drivers/gpu/drm/drm_trace.h
@@ -7,21 +7,109 @@
 #include <linux/tracepoint.h>
 
 struct drm_file;
+/**
+ * DOC: overview
+ *
+ * DRM trace events can be used to trace important moments occurring in the DRM
+ * core or helpers without incurring a significant performance penalty (like you
+ * would with console logging).
+ */
+
+#if !defined(_DRM_TRACE_EVENT_CLASS_ENUM)
+#define _DRM_TRACE_EVENT_CLASS_ENUM
+
+/**
+ * enum drm_trace_event_class - the trace class of an event
+ *
+ * Trace events are broken into different classes (much the same as we do for
+ * console logging) to make sifting through the logs easier. If you want to
+ * isolate one or more classes (or disable a subset of classes), you can write
+ * an expession using the event_class entry field as a tracepoints filter. The
+ * event_class field is not printed as part of the trace log, it's just there
+ * for filtering.
+ *
+ * The classes are bitfields to make filtering easier, but also to allow trace
+ * events to be classified under multiple classes (ie: if you're tracing an
+ * error that occurred with a crtc, you can ensure that these events are
+ * surfaced for filters looking for either crtc or error classes).
+ *
+ * An example filter is:
+ *	Assume you want to view all trace events in failure paths, you would
+ *	write a filter which isolates events with the drm_trace_class_error bit
+ *	set in their event_class field. This allows you to enable all trace
+ *	events in the drm trace system and only consume errors.
+ *
+ *	; echo "event_class & 0x1" > /sys/kernel/tracing/events/drm/filter
+ *	; echo 1 > /sys/kernel/tracing/events/drm/enable
+ *
+ *	Similarly, to view all vblank traces plus any error traces, you select
+ *	both classes in the filter.
+ *
+ *	; echo "event_class & 0x3" > /sys/kernel/tracing/events/drm/filter
+ */
+enum drm_trace_event_class {
+	/**
+	 * @drm_trace_class_error: Denotes that the trace event is coming from
+	 * an error path.
+	 */
+	drm_trace_class_error		= BIT(0),
+
+	/**
+	 * @drm_trace_class_vblank: Use this to track trace events that track
+	 * vblanks and vblank events.
+	 */
+	drm_trace_class_vblank		= BIT(1),
+};
+
+/**
+ * drm_trace - add a drm trace event
+ * @_c: class name (the part that comes after drm_trace_class_)
+ * @_e: event name (the part that comes after drm_$class_)
+ *
+ * Use this macro to simplify adding a trace event for non-failure paths in
+ * drm code. The macro simply assembles the trace event from the class and name,
+ * and sets the correct event_code for this trace.
+ *
+ * It's recommended that this macro is not used in failure paths. For failure
+ * paths, use drm_trace_err().
+ */
+#define drm_trace(_c, _e, ...) \
+	trace_drm_##_c##_##_e(drm_trace_class_##_c, __VA_ARGS__)
+
+/**
+ * drm_trace_err - add a drm trace event in a failure path
+ * @_c: class name (the part that comes after drm_trace_class_)
+ * @_e: event name (the part that comes after drm_$class_)
+ *
+ * This is virtually the same as drm_trace(), however it sets the error class on
+ * the event as well. This is beneficial for those filtering events by
+ * class_error.
+ *
+ * For non-failure paths, please use drm_trace().
+ */
+#define drm_trace_err(_c, _e, ...)					\
+	trace_drm_##_c##_##_e(drm_trace_class_##_c | drm_trace_class_error, \
+			      __VA_ARGS__)
+
+#endif
 
 #undef TRACE_SYSTEM
 #define TRACE_SYSTEM drm
 #define TRACE_INCLUDE_FILE drm_trace
 
 TRACE_EVENT(drm_vblank_event,
-	    TP_PROTO(int crtc, unsigned int seq, ktime_t time, bool high_prec),
-	    TP_ARGS(crtc, seq, time, high_prec),
+	    TP_PROTO(unsigned int event_class, int crtc, unsigned int seq,
+		     ktime_t time, bool high_prec),
+	    TP_ARGS(event_class, crtc, seq, time, high_prec),
 	    TP_STRUCT__entry(
+		    __field(unsigned int, event_class)
 		    __field(int, crtc)
 		    __field(unsigned int, seq)
 		    __field(ktime_t, time)
 		    __field(bool, high_prec)
 		    ),
 	    TP_fast_assign(
+		    __entry->event_class = event_class;
 		    __entry->crtc = crtc;
 		    __entry->seq = seq;
 		    __entry->time = time;
@@ -33,14 +121,17 @@ TRACE_EVENT(drm_vblank_event,
 );
 
 DECLARE_EVENT_CLASS(class_drm_vblank_event,
-	    TP_PROTO(struct drm_file *file, int crtc, unsigned int seq),
-	    TP_ARGS(file, crtc, seq),
+	    TP_PROTO(unsigned int event_class, struct drm_file *file,
+		     int crtc, unsigned int seq),
+	    TP_ARGS(event_class, file, crtc, seq),
 	    TP_STRUCT__entry(
+		    __field(unsigned int, event_class)
 		    __field(struct drm_file *, file)
 		    __field(int, crtc)
 		    __field(unsigned int, seq)
 		    ),
 	    TP_fast_assign(
+		    __entry->event_class = event_class;
 		    __entry->file = file;
 		    __entry->crtc = crtc;
 		    __entry->seq = seq;
@@ -49,12 +140,14 @@ DECLARE_EVENT_CLASS(class_drm_vblank_event,
 		      __entry->seq)
 );
 DEFINE_EVENT(class_drm_vblank_event, drm_vblank_event_queued,
-	TP_PROTO(struct drm_file *file, int crtc, unsigned int seq),
-	TP_ARGS(file, crtc, seq)
+	TP_PROTO(unsigned int event_class, struct drm_file *file, int crtc,
+		 unsigned int seq),
+	TP_ARGS(event_class, file, crtc, seq)
 );
 DEFINE_EVENT(class_drm_vblank_event, drm_vblank_event_delivered,
-	TP_PROTO(struct drm_file *file, int crtc, unsigned int seq),
-	TP_ARGS(file, crtc, seq)
+	TP_PROTO(unsigned int event_class, struct drm_file *file, int crtc,
+		 unsigned int seq),
+	TP_ARGS(event_class, file, crtc, seq)
 );
 
 #endif /* _DRM_TRACE_H_ */
diff --git a/drivers/gpu/drm/drm_vblank.c b/drivers/gpu/drm/drm_vblank.c
index 1659b13b178c2..19a63a94586ad 100644
--- a/drivers/gpu/drm/drm_vblank.c
+++ b/drivers/gpu/drm/drm_vblank.c
@@ -880,7 +880,7 @@ static void send_vblank_event(struct drm_device *dev,
 		e->event.seq.time_ns = ktime_to_ns(now);
 		break;
 	}
-	trace_drm_vblank_event_delivered(e->base.file_priv, e->pipe, seq);
+	drm_trace(vblank, event_delivered, e->base.file_priv, e->pipe, seq);
 	drm_send_event_locked(dev, &e->base);
 }
 
@@ -1529,7 +1529,7 @@ static int drm_queue_vblank_event(struct drm_device *dev, unsigned int pipe,
 	DRM_DEBUG("event on vblank count %llu, current %llu, crtc %u\n",
 		  req_seq, seq, pipe);
 
-	trace_drm_vblank_event_queued(file_priv, pipe, req_seq);
+	drm_trace(vblank, event_queued, file_priv, pipe, req_seq);
 
 	e->sequence = req_seq;
 	if (vblank_passed(seq, req_seq)) {
@@ -1760,8 +1760,8 @@ static void drm_handle_vblank_events(struct drm_device *dev, unsigned int pipe)
 		send_vblank_event(dev, e, seq, now);
 	}
 
-	trace_drm_vblank_event(pipe, seq, now,
-			dev->driver->get_vblank_timestamp != NULL);
+	drm_trace(vblank, event, pipe, seq, now,
+		  dev->driver->get_vblank_timestamp != NULL);
 }
 
 /**
-- 
Sean Paul, Software Engineer, Google / Chromium OS

_______________________________________________
dri-devel mailing list
dri-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/dri-devel

[PATCH 3/6] drm: trace: Add trace events for atomic state lifetime

[Sean Paul]

From: Sean Paul <seanpaul@chromium.org>

Mirror some atomic debug messages which track a state through
allocation/clear/check/commit/free

Change-Id: I0387ddf4b2f1d84137a5b471e347878c04c6d0af
Signed-off-by: Sean Paul <seanpaul@chromium.org>
---
 drivers/gpu/drm/drm_atomic.c | 19 +++++---
 drivers/gpu/drm/drm_trace.h  | 84 ++++++++++++++++++++++++++++++++++++
 2 files changed, 98 insertions(+), 5 deletions(-)

diff --git a/drivers/gpu/drm/drm_atomic.c b/drivers/gpu/drm/drm_atomic.c
index 14aeaf7363210..93ca64af67f55 100644
--- a/drivers/gpu/drm/drm_atomic.c
+++ b/drivers/gpu/drm/drm_atomic.c
@@ -41,6 +41,7 @@
 
 #include "drm_crtc_internal.h"
 #include "drm_internal.h"
+#include "drm_trace.h"
 
 void __drm_crtc_commit_free(struct kref *kref)
 {
@@ -118,10 +119,11 @@ struct drm_atomic_state *
 drm_atomic_state_alloc(struct drm_device *dev)
 {
 	struct drm_mode_config *config = &dev->mode_config;
+	struct drm_atomic_state *state;
 
-	if (!config->funcs->atomic_state_alloc) {
-		struct drm_atomic_state *state;
-
+	if (config->funcs->atomic_state_alloc) {
+		state = config->funcs->atomic_state_alloc(dev);
+	} else {
 		state = kzalloc(sizeof(*state), GFP_KERNEL);
 		if (!state)
 			return NULL;
@@ -129,10 +131,10 @@ drm_atomic_state_alloc(struct drm_device *dev)
 			kfree(state);
 			return NULL;
 		}
-		return state;
 	}
 
-	return config->funcs->atomic_state_alloc(dev);
+	drm_trace(atomic, alloc, state);
+	return state;
 }
 EXPORT_SYMBOL(drm_atomic_state_alloc);
 
@@ -239,6 +241,7 @@ void drm_atomic_state_clear(struct drm_atomic_state *state)
 	struct drm_device *dev = state->dev;
 	struct drm_mode_config *config = &dev->mode_config;
 
+	drm_trace(atomic, clear, state);
 	if (config->funcs->atomic_state_clear)
 		config->funcs->atomic_state_clear(state);
 	else
@@ -261,6 +264,7 @@ void __drm_atomic_state_free(struct kref *ref)
 	drm_atomic_state_clear(state);
 
 	DRM_DEBUG_ATOMIC("Freeing atomic state %p\n", state);
+	drm_trace(atomic, free, state);
 
 	if (config->funcs->atomic_state_free) {
 		config->funcs->atomic_state_free(state);
@@ -1145,6 +1149,7 @@ int drm_atomic_check_only(struct drm_atomic_state *state)
 	int i, ret = 0;
 
 	DRM_DEBUG_ATOMIC("checking %p\n", state);
+	drm_trace(atomic, check, state);
 
 	for_each_oldnew_plane_in_state(state, plane, old_plane_state, new_plane_state, i) {
 		ret = drm_atomic_plane_check(old_plane_state, new_plane_state);
@@ -1179,6 +1184,7 @@ int drm_atomic_check_only(struct drm_atomic_state *state)
 		if (ret) {
 			DRM_DEBUG_ATOMIC("atomic driver check for %p failed: %d\n",
 					 state, ret);
+			drm_trace_err(atomic, check_failed, state);
 			return ret;
 		}
 	}
@@ -1193,6 +1199,7 @@ int drm_atomic_check_only(struct drm_atomic_state *state)
 		}
 	}
 
+	drm_trace(atomic, check_passed, state);
 	return 0;
 }
 EXPORT_SYMBOL(drm_atomic_check_only);
@@ -1221,6 +1228,7 @@ int drm_atomic_commit(struct drm_atomic_state *state)
 		return ret;
 
 	DRM_DEBUG_ATOMIC("committing %p\n", state);
+	drm_trace(atomic, commit, state);
 
 	return config->funcs->atomic_commit(state->dev, state, false);
 }
@@ -1250,6 +1258,7 @@ int drm_atomic_nonblocking_commit(struct drm_atomic_state *state)
 		return ret;
 
 	DRM_DEBUG_ATOMIC("committing %p nonblocking\n", state);
+	drm_trace(atomic, commit_nonblock, state);
 
 	return config->funcs->atomic_commit(state->dev, state, true);
 }
diff --git a/drivers/gpu/drm/drm_trace.h b/drivers/gpu/drm/drm_trace.h
index 19e5f04210586..5d56365d0b439 100644
--- a/drivers/gpu/drm/drm_trace.h
+++ b/drivers/gpu/drm/drm_trace.h
@@ -2,6 +2,9 @@
 #if !defined(_DRM_TRACE_H_) || defined(TRACE_HEADER_MULTI_READ)
 #define _DRM_TRACE_H_
 
+#include <drm/drm_atomic.h>
+
+#include <linux/kref.h>
 #include <linux/stringify.h>
 #include <linux/types.h>
 #include <linux/tracepoint.h>
@@ -59,6 +62,12 @@ enum drm_trace_event_class {
 	 * vblanks and vblank events.
 	 */
 	drm_trace_class_vblank		= BIT(1),
+
+	/**
+	 * @drm_trace_class_atomic: This class is used to track the top-level
+	 * atomic state from alloc to free and everywhere in between.
+	 */
+	drm_trace_class_atomic		= BIT(2),
 };
 
 /**
@@ -150,6 +159,81 @@ DEFINE_EVENT(class_drm_vblank_event, drm_vblank_event_delivered,
 	TP_ARGS(event_class, file, crtc, seq)
 );
 
+DECLARE_EVENT_CLASS(class_drm_atomic,
+	TP_PROTO(unsigned int event_class,
+		 const struct drm_atomic_state *state),
+	TP_ARGS(event_class, state),
+	TP_STRUCT__entry(
+		__field(unsigned int, event_class)
+		__field(const struct drm_atomic_state *, state)
+		__field(unsigned int, ref)
+		__field(bool, allow_modeset)
+		__field(bool, legacy_cursor_update)
+		__field(bool, async_update)
+		__field(bool, duplicated)
+		__field(unsigned int, num_connector)
+		__field(unsigned int, num_private_objs)
+	),
+	TP_fast_assign(
+		__entry->event_class = event_class;
+		__entry->state = state; /* Do not de-reference! */
+		__entry->ref = kref_read(&state->ref);
+		__entry->allow_modeset = state->allow_modeset;
+		__entry->legacy_cursor_update = state->legacy_cursor_update;
+		__entry->async_update = state->async_update;
+		__entry->duplicated = state->duplicated;
+		__entry->num_connector = state->num_connector;
+		__entry->num_private_objs = state->num_private_objs;
+	),
+	TP_printk("state=%pK ref=%d allow_modeset=%d legacy_cursor=%d "
+		  "async_update=%d duplicated=%d num_conn=%d num_priv_objs=%d",
+		  __entry->state, __entry->ref, __entry->allow_modeset,
+		  __entry->legacy_cursor_update, __entry->async_update,
+		  __entry->duplicated, __entry->num_connector,
+		  __entry->num_private_objs)
+);
+DEFINE_EVENT_PRINT(class_drm_atomic, drm_atomic_alloc,
+	TP_PROTO(unsigned int event_class,
+		 const struct drm_atomic_state *state),
+	TP_ARGS(event_class, state),
+	TP_printk("state=%pK", __entry->state)
+);
+DEFINE_EVENT(class_drm_atomic, drm_atomic_clear,
+	TP_PROTO(unsigned int event_class,
+		 const struct drm_atomic_state *state),
+	TP_ARGS(event_class, state)
+);
+DEFINE_EVENT(class_drm_atomic, drm_atomic_free,
+	TP_PROTO(unsigned int event_class,
+		 const struct drm_atomic_state *state),
+	TP_ARGS(event_class, state)
+);
+DEFINE_EVENT(class_drm_atomic, drm_atomic_check,
+	TP_PROTO(unsigned int event_class,
+		 const struct drm_atomic_state *state),
+	TP_ARGS(event_class, state)
+);
+DEFINE_EVENT(class_drm_atomic, drm_atomic_commit,
+	TP_PROTO(unsigned int event_class,
+		 const struct drm_atomic_state *state),
+	TP_ARGS(event_class, state)
+);
+DEFINE_EVENT(class_drm_atomic, drm_atomic_commit_nonblock,
+	TP_PROTO(unsigned int event_class,
+		 const struct drm_atomic_state *state),
+	TP_ARGS(event_class, state)
+);
+DEFINE_EVENT(class_drm_atomic, drm_atomic_check_passed,
+	TP_PROTO(unsigned int event_class,
+		 const struct drm_atomic_state *state),
+	TP_ARGS(event_class, state)
+);
+DEFINE_EVENT(class_drm_atomic, drm_atomic_check_failed,
+	TP_PROTO(unsigned int event_class,
+		 const struct drm_atomic_state *state),
+	TP_ARGS(event_class, state)
+);
+
 #endif /* _DRM_TRACE_H_ */
 
 /* This part must be outside protection */
-- 
Sean Paul, Software Engineer, Google / Chromium OS

_______________________________________________
dri-devel mailing list
dri-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/dri-devel

[PATCH 4/6] drm: trace: Add crtc state trace events

[Sean Paul]

From: Sean Paul <seanpaul@chromium.org>

Add tracing which tracks important crtc_state events through the atomic
core.

Signed-off-by: Sean Paul <seanpaul@chromium.org>
---
 drivers/gpu/drm/drm_atomic.c |  14 +++++
 drivers/gpu/drm/drm_trace.h  | 109 +++++++++++++++++++++++++++++++++++
 2 files changed, 123 insertions(+)

diff --git a/drivers/gpu/drm/drm_atomic.c b/drivers/gpu/drm/drm_atomic.c
index 93ca64af67f55..955650729115d 100644
--- a/drivers/gpu/drm/drm_atomic.c
+++ b/drivers/gpu/drm/drm_atomic.c
@@ -319,6 +319,7 @@ drm_atomic_get_crtc_state(struct drm_atomic_state *state,
 
 	DRM_DEBUG_ATOMIC("Added [CRTC:%d:%s] %p state to %p\n",
 			 crtc->base.id, crtc->name, crtc_state, state);
+	drm_trace(crtc, add, crtc_state);
 
 	return crtc_state;
 }
@@ -340,6 +341,8 @@ static int drm_atomic_crtc_check(const struct drm_crtc_state *old_crtc_state,
 	if (new_crtc_state->active && !new_crtc_state->enable) {
 		DRM_DEBUG_ATOMIC("[CRTC:%d:%s] active without enabled\n",
 				 crtc->base.id, crtc->name);
+		drm_trace_err(crtc, check_fail_active_not_enabled,
+			      new_crtc_state);
 		return -EINVAL;
 	}
 
@@ -350,6 +353,7 @@ static int drm_atomic_crtc_check(const struct drm_crtc_state *old_crtc_state,
 	    WARN_ON(new_crtc_state->enable && !new_crtc_state->mode_blob)) {
 		DRM_DEBUG_ATOMIC("[CRTC:%d:%s] enabled without mode blob\n",
 				 crtc->base.id, crtc->name);
+		drm_trace_err(crtc, check_fail_enable_no_mode, new_crtc_state);
 		return -EINVAL;
 	}
 
@@ -357,6 +361,7 @@ static int drm_atomic_crtc_check(const struct drm_crtc_state *old_crtc_state,
 	    WARN_ON(!new_crtc_state->enable && new_crtc_state->mode_blob)) {
 		DRM_DEBUG_ATOMIC("[CRTC:%d:%s] disabled with mode blob\n",
 				 crtc->base.id, crtc->name);
+		drm_trace_err(crtc, check_fail_mode_no_enable, new_crtc_state);
 		return -EINVAL;
 	}
 
@@ -374,9 +379,12 @@ static int drm_atomic_crtc_check(const struct drm_crtc_state *old_crtc_state,
 	    !new_crtc_state->active && !old_crtc_state->active) {
 		DRM_DEBUG_ATOMIC("[CRTC:%d:%s] requesting event but off\n",
 				 crtc->base.id, crtc->name);
+		drm_trace_err(crtc, check_fail_event_not_active,
+			      new_crtc_state);
 		return -EINVAL;
 	}
 
+	drm_trace(crtc, check_passed, new_crtc_state);
 	return 0;
 }
 
@@ -1057,6 +1065,8 @@ drm_atomic_add_affected_connectors(struct drm_atomic_state *state,
 
 	DRM_DEBUG_ATOMIC("Adding all current connectors for [CRTC:%d:%s] to %p\n",
 			 crtc->base.id, crtc->name, state);
+	drm_trace(crtc, add_affected_connectors, crtc_state);
+
 
 	/*
 	 * Changed connectors are already in @state, so only need to look
@@ -1111,6 +1121,7 @@ drm_atomic_add_affected_planes(struct drm_atomic_state *state,
 
 	DRM_DEBUG_ATOMIC("Adding all current planes for [CRTC:%d:%s] to %p\n",
 			 crtc->base.id, crtc->name, state);
+	drm_trace(crtc, add_affected_planes, old_crtc_state);
 
 	drm_for_each_plane_mask(plane, state->dev, old_crtc_state->plane_mask) {
 		struct drm_plane_state *plane_state =
@@ -1165,6 +1176,7 @@ int drm_atomic_check_only(struct drm_atomic_state *state)
 		if (ret) {
 			DRM_DEBUG_ATOMIC("[CRTC:%d:%s] atomic core check failed\n",
 					 crtc->base.id, crtc->name);
+			drm_trace_err(crtc, check_failed, new_crtc_state);
 			return ret;
 		}
 	}
@@ -1194,6 +1206,8 @@ int drm_atomic_check_only(struct drm_atomic_state *state)
 			if (drm_atomic_crtc_needs_modeset(new_crtc_state)) {
 				DRM_DEBUG_ATOMIC("[CRTC:%d:%s] requires full modeset\n",
 						 crtc->base.id, crtc->name);
+				drm_trace_err(crtc, check_fail_modeset_required,
+					      new_crtc_state);
 				return -EINVAL;
 			}
 		}
diff --git a/drivers/gpu/drm/drm_trace.h b/drivers/gpu/drm/drm_trace.h
index 5d56365d0b439..91880f650a7b3 100644
--- a/drivers/gpu/drm/drm_trace.h
+++ b/drivers/gpu/drm/drm_trace.h
@@ -3,6 +3,7 @@
 #define _DRM_TRACE_H_
 
 #include <drm/drm_atomic.h>
+#include <drm/drm_crtc.h>
 
 #include <linux/kref.h>
 #include <linux/stringify.h>
@@ -68,6 +69,12 @@ enum drm_trace_event_class {
 	 * atomic state from alloc to free and everywhere in between.
 	 */
 	drm_trace_class_atomic		= BIT(2),
+
+	/**
+	 * @drm_trace_class_crtc: This class is used to track crtc state through
+	 * the atomic core and helpers.
+	 */
+	drm_trace_class_crtc		= BIT(3),
 };
 
 /**
@@ -234,6 +241,108 @@ DEFINE_EVENT(class_drm_atomic, drm_atomic_check_failed,
 	TP_ARGS(event_class, state)
 );
 
+DECLARE_EVENT_CLASS(class_drm_crtc,
+	TP_PROTO(unsigned int event_class, const struct drm_crtc_state *state),
+	TP_ARGS(event_class, state),
+	TP_STRUCT__entry(
+		__field(unsigned int, event_class)
+		__field(const struct drm_atomic_state *, state)
+		__field(const struct drm_crtc_state *, crtc_state)
+		__field(const struct drm_crtc_commit *, commit)
+		__field(uint32_t, crtc_id)
+		__field(bool, enable)
+		__field(bool, active)
+		__field(bool, planes_changed)
+		__field(bool, mode_changed)
+		__field(bool, active_changed)
+		__field(bool, connectors_changed)
+		__field(bool, zpos_changed)
+		__field(bool, color_mgmt_changed)
+		__field(bool, no_vblank)
+		__field(bool, async_flip)
+		__field(bool, vrr_enabled)
+		__field(bool, self_refresh_active)
+		__field(u32, plane_mask)
+		__field(u32, connector_mask)
+		__field(u32, encoder_mask)
+	),
+	TP_fast_assign(
+		__entry->event_class = event_class;
+		__entry->state = state->state;
+		__entry->crtc_state = state;
+		__entry->crtc_id = state->crtc->base.id;
+		__entry->commit = state->commit;
+		__entry->enable = state->enable;
+		__entry->active = state->active;
+		__entry->planes_changed = state->planes_changed;
+		__entry->mode_changed = state->mode_changed;
+		__entry->active_changed = state->active_changed;
+		__entry->connectors_changed = state->connectors_changed;
+		__entry->zpos_changed = state->zpos_changed;
+		__entry->color_mgmt_changed = state->color_mgmt_changed;
+		__entry->no_vblank = state->no_vblank;
+		__entry->async_flip = state->async_flip;
+		__entry->vrr_enabled = state->vrr_enabled;
+		__entry->self_refresh_active = state->self_refresh_active;
+		__entry->plane_mask = state->plane_mask;
+		__entry->connector_mask = state->connector_mask;
+		__entry->encoder_mask = state->encoder_mask;
+	),
+	TP_printk("crtc_id=%u crtc_state=%pK state=%pK commit=%pK changed("
+		  "planes=%d mode=%d active=%d conn=%d zpos=%d color_mgmt=%d) "
+		  "state(enable=%d active=%d async_flip=%d vrr_enabled=%d "
+		  "self_refresh_active=%d no_vblank=%d) mask(plane=%x conn=%x "
+		  "enc=%x)",
+		  __entry->crtc_id, __entry->crtc_state, __entry->state,
+		  __entry->commit, __entry->planes_changed,
+		  __entry->mode_changed, __entry->active_changed,
+		  __entry->connectors_changed, __entry->zpos_changed,
+		  __entry->color_mgmt_changed, __entry->enable, __entry->active,
+		  __entry->async_flip, __entry->vrr_enabled,
+		  __entry->self_refresh_active, __entry->no_vblank,
+		  __entry->plane_mask, __entry->connector_mask,
+		  __entry->encoder_mask)
+);
+DEFINE_EVENT(class_drm_crtc, drm_crtc_add,
+	TP_PROTO(unsigned int event_class, const struct drm_crtc_state *state),
+	TP_ARGS(event_class, state)
+);
+DEFINE_EVENT(class_drm_crtc, drm_crtc_check_passed,
+	TP_PROTO(unsigned int event_class, const struct drm_crtc_state *state),
+	TP_ARGS(event_class, state)
+);
+DEFINE_EVENT(class_drm_crtc, drm_crtc_check_failed,
+	TP_PROTO(unsigned int event_class, const struct drm_crtc_state *state),
+	TP_ARGS(event_class, state)
+);
+DEFINE_EVENT(class_drm_crtc, drm_crtc_check_fail_active_not_enabled,
+	TP_PROTO(unsigned int event_class, const struct drm_crtc_state *state),
+	TP_ARGS(event_class, state)
+);
+DEFINE_EVENT(class_drm_crtc, drm_crtc_check_fail_enable_no_mode,
+	TP_PROTO(unsigned int event_class, const struct drm_crtc_state *state),
+	TP_ARGS(event_class, state)
+);
+DEFINE_EVENT(class_drm_crtc, drm_crtc_check_fail_mode_no_enable,
+	TP_PROTO(unsigned int event_class, const struct drm_crtc_state *state),
+	TP_ARGS(event_class, state)
+);
+DEFINE_EVENT(class_drm_crtc, drm_crtc_check_fail_event_not_active,
+	TP_PROTO(unsigned int event_class, const struct drm_crtc_state *state),
+	TP_ARGS(event_class, state)
+);
+DEFINE_EVENT(class_drm_crtc, drm_crtc_check_fail_modeset_required,
+	TP_PROTO(unsigned int event_class, const struct drm_crtc_state *state),
+	TP_ARGS(event_class, state)
+);
+DEFINE_EVENT(class_drm_crtc, drm_crtc_add_affected_connectors,
+	TP_PROTO(unsigned int event_class, const struct drm_crtc_state *state),
+	TP_ARGS(event_class, state)
+);
+DEFINE_EVENT(class_drm_crtc, drm_crtc_add_affected_planes,
+	TP_PROTO(unsigned int event_class, const struct drm_crtc_state *state),
+	TP_ARGS(event_class, state)
+);
 #endif /* _DRM_TRACE_H_ */
 
 /* This part must be outside protection */
-- 
Sean Paul, Software Engineer, Google / Chromium OS

_______________________________________________
dri-devel mailing list
dri-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/dri-devel

[PATCH 5/6] drm: trace: Add connector state tracing

[Sean Paul]

From: Sean Paul <seanpaul@chromium.org>

Add tracing which tracks important connector_state events through the atomic
core.

Signed-off-by: Sean Paul <seanpaul@chromium.org>
---
 drivers/gpu/drm/drm_atomic.c |  12 ++++-
 drivers/gpu/drm/drm_trace.h  | 101 +++++++++++++++++++++++++++++++++++
 2 files changed, 112 insertions(+), 1 deletion(-)

diff --git a/drivers/gpu/drm/drm_atomic.c b/drivers/gpu/drm/drm_atomic.c
index 955650729115d..5dcaf145f22ff 100644
--- a/drivers/gpu/drm/drm_atomic.c
+++ b/drivers/gpu/drm/drm_atomic.c
@@ -422,12 +422,15 @@ static int drm_atomic_connector_check(struct drm_connector *connector,
 	if (connector->max_bpc_property)
 		state->max_bpc = min(state->max_bpc, state->max_requested_bpc);
 
-	if ((connector->connector_type != DRM_MODE_CONNECTOR_WRITEBACK) || !writeback_job)
+	if ((connector->connector_type != DRM_MODE_CONNECTOR_WRITEBACK) || !writeback_job) {
+		drm_trace(connector, check_passed, state);
 		return 0;
+	}
 
 	if (writeback_job->fb && !state->crtc) {
 		DRM_DEBUG_ATOMIC("[CONNECTOR:%d:%s] framebuffer without CRTC\n",
 				 connector->base.id, connector->name);
+		drm_trace_err(connector, check_fail_writeback_no_crtc, state);
 		return -EINVAL;
 	}
 
@@ -439,6 +442,8 @@ static int drm_atomic_connector_check(struct drm_connector *connector,
 		DRM_DEBUG_ATOMIC("[CONNECTOR:%d:%s] has framebuffer, but [CRTC:%d] is off\n",
 				 connector->base.id, connector->name,
 				 state->crtc->base.id);
+		drm_trace_err(connector, check_fail_writeback_not_active,
+			      state);
 		return -EINVAL;
 	}
 
@@ -446,6 +451,8 @@ static int drm_atomic_connector_check(struct drm_connector *connector,
 		if (writeback_job->out_fence) {
 			DRM_DEBUG_ATOMIC("[CONNECTOR:%d:%s] requesting out-fence without framebuffer\n",
 					 connector->base.id, connector->name);
+			drm_trace_err(connector,
+				      check_fail_writeback_fence_no_fb, state);
 			return -EINVAL;
 		}
 
@@ -453,6 +460,7 @@ static int drm_atomic_connector_check(struct drm_connector *connector,
 		state->writeback_job = NULL;
 	}
 
+	drm_trace(connector, check_passed, state);
 	return 0;
 }
 
@@ -996,6 +1004,7 @@ drm_atomic_get_connector_state(struct drm_atomic_state *state,
 	DRM_DEBUG_ATOMIC("Added [CONNECTOR:%d:%s] %p state to %p\n",
 			 connector->base.id, connector->name,
 			 connector_state, state);
+	drm_trace(connector, add, connector_state);
 
 	if (connector_state->crtc) {
 		struct drm_crtc_state *crtc_state;
@@ -1186,6 +1195,7 @@ int drm_atomic_check_only(struct drm_atomic_state *state)
 		if (ret) {
 			DRM_DEBUG_ATOMIC("[CONNECTOR:%d:%s] atomic core check failed\n",
 					 conn->base.id, conn->name);
+			drm_trace_err(connector, check_failed, conn_state);
 			return ret;
 		}
 	}
diff --git a/drivers/gpu/drm/drm_trace.h b/drivers/gpu/drm/drm_trace.h
index 91880f650a7b3..c610e8d8c71ce 100644
--- a/drivers/gpu/drm/drm_trace.h
+++ b/drivers/gpu/drm/drm_trace.h
@@ -3,7 +3,9 @@
 #define _DRM_TRACE_H_
 
 #include <drm/drm_atomic.h>
+#include <drm/drm_connector.h>
 #include <drm/drm_crtc.h>
+#include <drm/drm_encoder.h>
 
 #include <linux/kref.h>
 #include <linux/stringify.h>
@@ -75,6 +77,12 @@ enum drm_trace_event_class {
 	 * the atomic core and helpers.
 	 */
 	drm_trace_class_crtc		= BIT(3),
+
+	/**
+	 * @drm_trace_class_connector: This class is used to track connector
+	 * state through the atomic core and helpers.
+	 */
+	drm_trace_class_connector	= BIT(4),
 };
 
 /**
@@ -343,6 +351,99 @@ DEFINE_EVENT(class_drm_crtc, drm_crtc_add_affected_planes,
 	TP_PROTO(unsigned int event_class, const struct drm_crtc_state *state),
 	TP_ARGS(event_class, state)
 );
+
+DECLARE_EVENT_CLASS(class_drm_connector,
+	TP_PROTO(unsigned int event_class,
+		 const struct drm_connector_state *state),
+	TP_ARGS(event_class, state),
+	TP_STRUCT__entry(
+		__field(unsigned int, event_class)
+		__field(uint32_t, conn_id)
+		__field(const struct drm_connector_state *, conn_state)
+		__field(const struct drm_atomic_state *, state)
+		__field(const struct drm_crtc_commit *, commit)
+		__field(uint32_t, crtc_id)
+		__field(uint32_t, best_encoder_id)
+		__field(enum drm_link_status, link_status)
+		__field(bool, self_refresh_aware)
+		__field(enum hdmi_picture_aspect, picture_aspect_ratio)
+		__field(unsigned int, content_type)
+		__field(unsigned int, hdcp_content_type)
+		__field(unsigned int, content_protection)
+		__field(unsigned int, scaling_mode)
+		__field(u32, colorspace)
+		__field(const struct drm_writeback_job *, writeback_job)
+		__field(u8, max_requested_bpc)
+		__field(u8, max_bpc)
+	),
+	TP_fast_assign(
+		__entry->event_class = event_class;
+		__entry->conn_id = state->connector->base.id;
+		__entry->conn_state = state;
+		__entry->state = state->state;
+		__entry->commit = state->commit;
+		__entry->crtc_id = state->crtc ? state->crtc->base.id : 0;
+		__entry->best_encoder_id = state->best_encoder ?
+					   state->best_encoder->base.id : 0;
+		__entry->link_status = state->link_status;
+		__entry->self_refresh_aware = state->self_refresh_aware;
+		__entry->picture_aspect_ratio= state->picture_aspect_ratio;
+		__entry->content_type = state->content_type;
+		__entry->hdcp_content_type = state->hdcp_content_type;
+		__entry->content_protection = state->content_protection;
+		__entry->scaling_mode = state->scaling_mode;
+		__entry->colorspace = state->colorspace;
+		__entry->writeback_job = state->writeback_job;
+		__entry->max_requested_bpc = state->max_requested_bpc;
+		__entry->max_bpc = state->max_bpc;
+	),
+	TP_printk("conn_id=%u conn_state=%pK state=%pK commit=%pK crtc_id=%u "
+		  "best_encoder_id=%u link_status=%d self_refresh_aware=%d "
+		  "picture_aspect_ratio=%d content_type=%u "
+		  "hdcp_content_type=%u content_protection=%u scaling_mode=%u "
+		  "colorspace=%u writeback_job=%pK max_requested_bpc=%u "
+		  "max_bpc=%u",
+		  __entry->conn_id, __entry->conn_state, __entry->state,
+		  __entry->commit, __entry->crtc_id, __entry->best_encoder_id,
+		  __entry->link_status, __entry->self_refresh_aware,
+		  __entry->picture_aspect_ratio, __entry->content_type,
+		  __entry->hdcp_content_type, __entry->content_protection,
+		  __entry->scaling_mode, __entry->colorspace,
+		  __entry->writeback_job, __entry->max_requested_bpc,
+		  __entry->max_bpc)
+);
+DEFINE_EVENT(class_drm_connector, drm_connector_add,
+	TP_PROTO(unsigned int event_class,
+		 const struct drm_connector_state *state),
+	TP_ARGS(event_class, state)
+);
+DEFINE_EVENT(class_drm_connector, drm_connector_check_passed,
+	TP_PROTO(unsigned int event_class,
+		 const struct drm_connector_state *state),
+	TP_ARGS(event_class, state)
+);
+DEFINE_EVENT(class_drm_connector, drm_connector_check_failed,
+	TP_PROTO(unsigned int event_class,
+		 const struct drm_connector_state *state),
+	TP_ARGS(event_class, state)
+);
+DEFINE_EVENT(class_drm_connector, drm_connector_check_fail_writeback_no_crtc,
+	TP_PROTO(unsigned int event_class,
+		 const struct drm_connector_state *state),
+	TP_ARGS(event_class, state)
+);
+DEFINE_EVENT(class_drm_connector, drm_connector_check_fail_writeback_not_active,
+	TP_PROTO(unsigned int event_class,
+		 const struct drm_connector_state *state),
+	TP_ARGS(event_class, state)
+);
+DEFINE_EVENT(class_drm_connector,
+	     drm_connector_check_fail_writeback_fence_no_fb,
+	TP_PROTO(unsigned int event_class,
+		 const struct drm_connector_state *state),
+	TP_ARGS(event_class, state)
+);
+
 #endif /* _DRM_TRACE_H_ */
 
 /* This part must be outside protection */
-- 
Sean Paul, Software Engineer, Google / Chromium OS

_______________________________________________
dri-devel mailing list
dri-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/dri-devel

[PATCH 6/6] drm: trace: Add plane state tracing

[Sean Paul]

From: Sean Paul <seanpaul@chromium.org>

Add tracing which tracks important plane_state events through the atomic
core.

Signed-off-by: Sean Paul <seanpaul@chromium.org>
---
 drivers/gpu/drm/drm_atomic.c |  16 +++-
 drivers/gpu/drm/drm_trace.h  | 143 +++++++++++++++++++++++++++++++++++
 2 files changed, 158 insertions(+), 1 deletion(-)

diff --git a/drivers/gpu/drm/drm_atomic.c b/drivers/gpu/drm/drm_atomic.c
index 5dcaf145f22ff..f68240d1d9ecf 100644
--- a/drivers/gpu/drm/drm_atomic.c
+++ b/drivers/gpu/drm/drm_atomic.c
@@ -513,6 +513,7 @@ drm_atomic_get_plane_state(struct drm_atomic_state *state,
 
 	DRM_DEBUG_ATOMIC("Added [PLANE:%d:%s] %p state to %p\n",
 			 plane->base.id, plane->name, plane_state, state);
+	drm_trace(plane, add, plane_state);
 
 	if (plane_state->crtc) {
 		struct drm_crtc_state *crtc_state;
@@ -570,22 +571,27 @@ static int drm_atomic_plane_check(const struct drm_plane_state *old_plane_state,
 	if (crtc && !fb) {
 		DRM_DEBUG_ATOMIC("[PLANE:%d:%s] CRTC set but no FB\n",
 				 plane->base.id, plane->name);
+		drm_trace_err(plane, check_fail_crtc_no_fb, new_plane_state);
 		return -EINVAL;
 	} else if (fb && !crtc) {
 		DRM_DEBUG_ATOMIC("[PLANE:%d:%s] FB set but no CRTC\n",
 				 plane->base.id, plane->name);
+		drm_trace_err(plane, check_fail_fb_no_crtc, new_plane_state);
 		return -EINVAL;
 	}
 
 	/* if disabled, we don't care about the rest of the state: */
-	if (!crtc)
+	if (!crtc) {
+		drm_trace(plane, check_passed, new_plane_state);
 		return 0;
+	}
 
 	/* Check whether this plane is usable on this CRTC */
 	if (!(plane->possible_crtcs & drm_crtc_mask(crtc))) {
 		DRM_DEBUG_ATOMIC("Invalid [CRTC:%d:%s] for [PLANE:%d:%s]\n",
 				 crtc->base.id, crtc->name,
 				 plane->base.id, plane->name);
+		drm_trace_err(plane, check_fail_crtc_impossible, new_plane_state);
 		return -EINVAL;
 	}
 
@@ -599,6 +605,7 @@ static int drm_atomic_plane_check(const struct drm_plane_state *old_plane_state,
 				 drm_get_format_name(fb->format->format,
 						     &format_name),
 				 fb->modifier);
+		drm_trace_err(plane, check_fail_format, new_plane_state);
 		return ret;
 	}
 
@@ -611,6 +618,7 @@ static int drm_atomic_plane_check(const struct drm_plane_state *old_plane_state,
 				 plane->base.id, plane->name,
 				 new_plane_state->crtc_w, new_plane_state->crtc_h,
 				 new_plane_state->crtc_x, new_plane_state->crtc_y);
+		drm_trace_err(plane, check_fail_crtc_coords, new_plane_state);
 		return -ERANGE;
 	}
 
@@ -634,6 +642,7 @@ static int drm_atomic_plane_check(const struct drm_plane_state *old_plane_state,
 				 new_plane_state->src_y >> 16,
 				 ((new_plane_state->src_y & 0xffff) * 15625) >> 10,
 				 fb->width, fb->height);
+		drm_trace_err(plane, check_fail_src_coords, new_plane_state);
 		return -ENOSPC;
 	}
 
@@ -651,6 +660,7 @@ static int drm_atomic_plane_check(const struct drm_plane_state *old_plane_state,
 			DRM_DEBUG_ATOMIC("[PLANE:%d:%s] invalid damage clip %d %d %d %d\n",
 					 plane->base.id, plane->name, clips->x1,
 					 clips->y1, clips->x2, clips->y2);
+			drm_trace_err(plane, check_fail_damage_clip, new_plane_state);
 			return -EINVAL;
 		}
 		clips++;
@@ -660,9 +670,12 @@ static int drm_atomic_plane_check(const struct drm_plane_state *old_plane_state,
 	if (plane_switching_crtc(old_plane_state, new_plane_state)) {
 		DRM_DEBUG_ATOMIC("[PLANE:%d:%s] switching CRTC directly\n",
 				 plane->base.id, plane->name);
+		drm_trace_err(plane, check_fail_switch_old, old_plane_state);
+		drm_trace_err(plane, check_fail_switch_new, new_plane_state);
 		return -EINVAL;
 	}
 
+	drm_trace(plane, check_passed, new_plane_state);
 	return 0;
 }
 
@@ -1176,6 +1189,7 @@ int drm_atomic_check_only(struct drm_atomic_state *state)
 		if (ret) {
 			DRM_DEBUG_ATOMIC("[PLANE:%d:%s] atomic core check failed\n",
 					 plane->base.id, plane->name);
+			drm_trace_err(plane, check_failed, new_plane_state);
 			return ret;
 		}
 	}
diff --git a/drivers/gpu/drm/drm_trace.h b/drivers/gpu/drm/drm_trace.h
index c610e8d8c71ce..7708810bbd660 100644
--- a/drivers/gpu/drm/drm_trace.h
+++ b/drivers/gpu/drm/drm_trace.h
@@ -6,6 +6,9 @@
 #include <drm/drm_connector.h>
 #include <drm/drm_crtc.h>
 #include <drm/drm_encoder.h>
+#include <drm/drm_fourcc.h>
+#include <drm/drm_plane.h>
+#include <drm/drm_rect.h>
 
 #include <linux/kref.h>
 #include <linux/stringify.h>
@@ -83,6 +86,12 @@ enum drm_trace_event_class {
 	 * state through the atomic core and helpers.
 	 */
 	drm_trace_class_connector	= BIT(4),
+
+	/**
+	 * @drm_trace_class_plane: This class is used to track plane state
+	 * through the atomic core and helpers.
+	 */
+	drm_trace_class_plane		= BIT(5),
 };
 
 /**
@@ -444,6 +453,140 @@ DEFINE_EVENT(class_drm_connector,
 	TP_ARGS(event_class, state)
 );
 
+DECLARE_EVENT_CLASS(class_drm_plane,
+	TP_PROTO(unsigned int event_class, const struct drm_plane_state *state),
+	TP_ARGS(event_class, state),
+	TP_STRUCT__entry(
+		__field(unsigned int, event_class)
+		__field(uint32_t, plane_id)
+		__field(const struct drm_plane_state *, plane_state)
+		__field(const struct drm_atomic_state *, state)
+		__field(const struct drm_crtc_commit *, commit)
+		__field(uint32_t, crtc_id)
+		__field(uint32_t, fb_id)
+		__field(uint32_t, fb_format)
+		__field(uint8_t, fb_planes)
+		__field(uint64_t, fb_modifier)
+		__field(const struct dma_fence *, fence)
+		__array(u8, crtc_coords, sizeof(struct drm_rect))
+		__array(u8, src_coords, sizeof(struct drm_rect))
+		__field(u32, alpha)
+		__field(uint32_t, pixel_blend_mode)
+		__field(unsigned int, rotation)
+		__field(unsigned int, zpos)
+		__field(unsigned int, normalized_zpos)
+		__field(enum drm_color_encoding, color_encoding)
+		__field(enum drm_color_range, color_range)
+		__field(bool, visible)
+		__array(u8, src, sizeof(struct drm_rect))
+		__array(u8, dst, sizeof(struct drm_rect))
+	),
+	TP_fast_assign(
+		__entry->event_class = event_class;
+		__entry->plane_id = state->plane->base.id;
+		__entry->plane_state = state;
+		__entry->state = state->state;
+		__entry->commit = state->commit;
+		__entry->crtc_id = state->crtc ? state->crtc->base.id : 0;
+		__entry->fb_id = state->fb ? state->fb->base.id : 0;
+		__entry->fb_format = state->fb ? state->fb->format->format :
+						 'E' << 24 | 'O' << 16 |
+						 'N' << 8 | 'N';
+		__entry->fb_planes = state->fb ? state->fb->format->num_planes :
+					0;
+		__entry->fb_modifier = state->fb ? state->fb->modifier : 0;
+		__entry->fence = state->fence;
+		((struct drm_rect *)__entry->crtc_coords)->x1 = state->crtc_x;
+		((struct drm_rect *)__entry->crtc_coords)->y1 = state->crtc_y;
+		((struct drm_rect *)__entry->crtc_coords)->x1 = state->crtc_w;
+		((struct drm_rect *)__entry->crtc_coords)->y2 = state->crtc_h;
+		((struct drm_rect *)__entry->src_coords)->x1 = state->src_x;
+		((struct drm_rect *)__entry->src_coords)->y1 = state->src_y;
+		((struct drm_rect *)__entry->src_coords)->x1 = state->src_w;
+		((struct drm_rect *)__entry->src_coords)->y2 = state->src_h;
+		__entry->alpha = state->alpha;
+		__entry->pixel_blend_mode = state->pixel_blend_mode;
+		__entry->rotation = state->rotation;
+		__entry->zpos = state->zpos;
+		__entry->normalized_zpos = state->normalized_zpos;
+		__entry->color_encoding = state->color_encoding;
+		__entry->color_range = state->color_range;
+		__entry->visible = state->visible;
+		memcpy(__entry->src, &state->src, sizeof(__entry->src));
+		memcpy(__entry->dst, &state->dst, sizeof(__entry->dst));
+	),
+	TP_printk("plane_id=%u plane_state=%pK state=%pK commit=%pK crtc_id=%u "
+		  "fb(id=%u fmt=%c%c%c%c planes=%u mod=%llu) fence=%pK crtc("
+		  DRM_RECT_FMT") src("DRM_RECT_FP_FMT") alpha=%u "
+		  "pixel_blend_mode=%u rotation=%u zpos=%u "
+		  "normalized_zpos=%u color_encoding=%d color_range=%d "
+		  "visible=%d src_rect("DRM_RECT_FP_FMT") dst_rect("
+		  DRM_RECT_FMT")",
+		  __entry->plane_id, __entry->plane_state, __entry->state,
+		  __entry->commit, __entry->crtc_id, __entry->fb_id,
+		  __entry->fb_format & 0xff,
+		  (__entry->fb_format >> 8) & 0xff,
+		  (__entry->fb_format >> 16) & 0xff,
+		  (__entry->fb_format >> 24) & 0x7f, __entry->fb_planes,
+		  __entry->fb_modifier, __entry->fence,
+		  DRM_RECT_ARG((const struct drm_rect *)__entry->crtc_coords),
+		  DRM_RECT_FP_ARG((const struct drm_rect *)__entry->src_coords),
+		  __entry->alpha, __entry->pixel_blend_mode, __entry->rotation,
+		  __entry->zpos, __entry->normalized_zpos,
+		  __entry->color_encoding, __entry->color_range,
+		  __entry->visible,
+		  DRM_RECT_FP_ARG((const struct drm_rect *)__entry->src),
+		  DRM_RECT_ARG((const struct drm_rect *)__entry->dst))
+);
+DEFINE_EVENT(class_drm_plane, drm_plane_add,
+	TP_PROTO(unsigned int event_class, const struct drm_plane_state *state),
+	TP_ARGS(event_class, state)
+);
+DEFINE_EVENT(class_drm_plane, drm_plane_check_fail_crtc_no_fb,
+	TP_PROTO(unsigned int event_class, const struct drm_plane_state *state),
+	TP_ARGS(event_class, state)
+);
+DEFINE_EVENT(class_drm_plane, drm_plane_check_fail_fb_no_crtc,
+	TP_PROTO(unsigned int event_class, const struct drm_plane_state *state),
+	TP_ARGS(event_class, state)
+);
+DEFINE_EVENT(class_drm_plane, drm_plane_check_fail_crtc_impossible,
+	TP_PROTO(unsigned int event_class, const struct drm_plane_state *state),
+	TP_ARGS(event_class, state)
+);
+DEFINE_EVENT(class_drm_plane, drm_plane_check_fail_format,
+	TP_PROTO(unsigned int event_class, const struct drm_plane_state *state),
+	TP_ARGS(event_class, state)
+);
+DEFINE_EVENT(class_drm_plane, drm_plane_check_fail_crtc_coords,
+	TP_PROTO(unsigned int event_class, const struct drm_plane_state *state),
+	TP_ARGS(event_class, state)
+);
+DEFINE_EVENT(class_drm_plane, drm_plane_check_fail_src_coords,
+	TP_PROTO(unsigned int event_class, const struct drm_plane_state *state),
+	TP_ARGS(event_class, state)
+);
+DEFINE_EVENT(class_drm_plane, drm_plane_check_fail_damage_clip,
+	TP_PROTO(unsigned int event_class, const struct drm_plane_state *state),
+	TP_ARGS(event_class, state)
+);
+DEFINE_EVENT(class_drm_plane, drm_plane_check_fail_switch_old,
+	TP_PROTO(unsigned int event_class, const struct drm_plane_state *state),
+	TP_ARGS(event_class, state)
+);
+DEFINE_EVENT(class_drm_plane, drm_plane_check_fail_switch_new,
+	TP_PROTO(unsigned int event_class, const struct drm_plane_state *state),
+	TP_ARGS(event_class, state)
+);
+DEFINE_EVENT(class_drm_plane, drm_plane_check_failed,
+	TP_PROTO(unsigned int event_class, const struct drm_plane_state *state),
+	TP_ARGS(event_class, state)
+);
+DEFINE_EVENT(class_drm_plane, drm_plane_check_passed,
+	TP_PROTO(unsigned int event_class, const struct drm_plane_state *state),
+	TP_ARGS(event_class, state)
+);
+
 #endif /* _DRM_TRACE_H_ */
 
 /* This part must be outside protection */
-- 
Sean Paul, Software Engineer, Google / Chromium OS

_______________________________________________
dri-devel mailing list
dri-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/dri-devel

Re: [PATCH 0/6] drm: trace: Introduce drm_trace() and instrument drm_atomic.c

[Pekka Paalanen]

[-- Attachment #1.1: Type: text/plain, Size: 2339 bytes --]

On Thu,  7 Nov 2019 16:02:59 -0500
Sean Paul <sean@poorly.run> wrote:

> From: Sean Paul <seanpaul@chromium.org>
> 
> Hey all,
> I'm back with another trace events patchset. My first attempt [1] went
> better than expected, with enthusiasm for the idea and distain for the
> implementation.
> 
> As promised, I went through and added proper trace events.
> 
> Before I get _too_ far, I wanted to post this set to get feedback on the
> direction I'm going. I've gone back and forth on whether to introduce a
> bunch of trace systems vs using the trace class enum. I've settled on
> the trace class enum since it seems more extensible and easier to use in
> production that just having the blunt "enable this system", or
> the tedious "enable each event I'm interested in individually" methods.
> 
> So, consider this one an RFC unless we're all in agreement, in which
> case we should apply it :)
>

Hi Sean,

thanks for working on this. I'm not at all familiar with the trace
infrastructure, so I'd like to know how flight recorder type of
behaviour (a continuously written fixed size ring buffer) can be
achieved. Let us have a display server in userspace which in production
hits an unexpected condition with DRM and needs to record information
for post-mortem debugging. What should it do to have a trace log after
the fact to attach with a bug report?

I assume that is a major use case for this new feature. Is performance
profiling another use case?

Is it ok to build userspace to rely on these trace events during normal
operations, e.g. for continuous adjustment of timings/timers?


Thanks,
pq


> 
> [1]- https://patchwork.freedesktop.org/patch/335350/
> 
> Sean Paul (6):
>   drm: trace: Make the vblank queued/delivered events classed
>   drm: trace: Introduce drm_trace() and trace event classes
>   drm: trace: Add trace events for atomic state lifetime
>   drm: trace: Add crtc state trace events
>   drm: trace: Add connector state tracing
>   drm: trace: Add plane state tracing
> 
>  Documentation/gpu/drm-internals.rst |   9 +
>  drivers/gpu/drm/drm_atomic.c        |  61 ++-
>  drivers/gpu/drm/drm_trace.h         | 563 ++++++++++++++++++++++++++--
>  drivers/gpu/drm/drm_vblank.c        |   8 +-
>  4 files changed, 609 insertions(+), 32 deletions(-)
> 


[-- Attachment #1.2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

[-- Attachment #2: Type: text/plain, Size: 159 bytes --]

_______________________________________________
dri-devel mailing list
dri-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/dri-devel

Re: [PATCH 0/6] drm: trace: Introduce drm_trace() and instrument drm_atomic.c

[Daniel Vetter]

On Fri, Nov 08, 2019 at 10:16:59AM +0200, Pekka Paalanen wrote:
> On Thu,  7 Nov 2019 16:02:59 -0500
> Sean Paul <sean@poorly.run> wrote:
> 
> > From: Sean Paul <seanpaul@chromium.org>
> > 
> > Hey all,
> > I'm back with another trace events patchset. My first attempt [1] went
> > better than expected, with enthusiasm for the idea and distain for the
> > implementation.
> > 
> > As promised, I went through and added proper trace events.
> > 
> > Before I get _too_ far, I wanted to post this set to get feedback on the
> > direction I'm going. I've gone back and forth on whether to introduce a
> > bunch of trace systems vs using the trace class enum. I've settled on
> > the trace class enum since it seems more extensible and easier to use in
> > production that just having the blunt "enable this system", or
> > the tedious "enable each event I'm interested in individually" methods.
> > 
> > So, consider this one an RFC unless we're all in agreement, in which
> > case we should apply it :)
> >
> 
> Hi Sean,
> 
> thanks for working on this. I'm not at all familiar with the trace
> infrastructure, so I'd like to know how flight recorder type of
> behaviour (a continuously written fixed size ring buffer) can be
> achieved. Let us have a display server in userspace which in production
> hits an unexpected condition with DRM and needs to record information
> for post-mortem debugging. What should it do to have a trace log after
> the fact to attach with a bug report?

Yeah I think this has the uapi smell, so would need the userspace side
too, once we agree on something.

> I assume that is a major use case for this new feature. Is performance
> profiling another use case?
> 
> Is it ok to build userspace to rely on these trace events during normal
> operations, e.g. for continuous adjustment of timings/timers?

Yeah I'm kinda freaked out about this. In the old thread we discussed the
question of whether dumping dmesg into tracepoints would make them uapi,
but no conclusion was reached.

Now instead we're going to duplicate a lot of these debug outputs, with
specific trace events, which is going to make them even more uapi. And a
lot of these are very much implementation details (drivers might change
their opinion on which other states they need for check/commit, e.g. if
they move a bunch of global state from crtcs into a new driver private
internal object). Explicit tracepoints with symbol value imo will have a
much higher chance that someone starts relying on them.

Also, dmesg is uapi too. Except there's a gentlemen's agreement that you
should depend upon it because it will make kernel engineers really pissed
if they can't change/move a specific string. So from that point I think
just dumping the existing debug strings as unstructured strings into trace
buffers is a much better idea. Plus no need to have the same information
duplicated in both a debug output and a tracepoint.

I think even slightly structured debug tracepoints (e.g. a simple
(drm_object_id, string) pair) would be too structured since then userspace
could start watching for events on specific things and maybe use that for
their retry loops after TEST_ONLY failures. Even though we have a lot of
debug output strings where that bit of structure is essentially there
already.

Aside from this a question on process ... I re-read the old thread and I'm
not sure how you concluded we've reached consensus on this here, seemed
all pretty inconclusive on the details and discussions died out?
-Daniel


> 
> 
> Thanks,
> pq
> 
> 
> > 
> > [1]- https://patchwork.freedesktop.org/patch/335350/
> > 
> > Sean Paul (6):
> >   drm: trace: Make the vblank queued/delivered events classed
> >   drm: trace: Introduce drm_trace() and trace event classes
> >   drm: trace: Add trace events for atomic state lifetime
> >   drm: trace: Add crtc state trace events
> >   drm: trace: Add connector state tracing
> >   drm: trace: Add plane state tracing
> > 
> >  Documentation/gpu/drm-internals.rst |   9 +
> >  drivers/gpu/drm/drm_atomic.c        |  61 ++-
> >  drivers/gpu/drm/drm_trace.h         | 563 ++++++++++++++++++++++++++--
> >  drivers/gpu/drm/drm_vblank.c        |   8 +-
> >  4 files changed, 609 insertions(+), 32 deletions(-)
> > 
> 



-- 
Daniel Vetter
Software Engineer, Intel Corporation
http://blog.ffwll.ch
_______________________________________________
dri-devel mailing list
dri-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/dri-devel

Re: [PATCH 0/6] drm: trace: Introduce drm_trace() and instrument drm_atomic.c

[Daniel Vetter]

On Fri, Nov 08, 2019 at 10:16:59AM +0200, Pekka Paalanen wrote:
> Is it ok to build userspace to rely on these trace events during normal
> operations, e.g. for continuous adjustment of timings/timers?

Aside discussion on this: If we add this (I think userspace might want
some information about the point of no return and why we missed it) then I
think we should expose that with an improved drm_event and clear
semantics.

If we start to encourage compositors to use tracepoints to figure out why
the kernel doesn't behave (TEST_ONLY failure, or missed flip target), and
use that for behaviour, we've baked implementation details into the uapi.
And then we're screwed.

So if you have any need for timing information that you see solved with a
tracepoint, pls bring this up so we can add proper uapi. And yes I know
that if someone doesn't we still need to keep that tracepoint working, but
with all things uapi the question isn't whether we'll screw up (we will),
but how often. And less often is massively better :-)
-Daniel
-- 
Daniel Vetter
Software Engineer, Intel Corporation
http://blog.ffwll.ch
_______________________________________________
dri-devel mailing list
dri-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/dri-devel

Re: [PATCH 0/6] drm: trace: Introduce drm_trace() and instrument drm_atomic.c

[Daniel Vetter]

On Fri, Nov 08, 2019 at 09:46:48AM +0100, Daniel Vetter wrote:
> On Fri, Nov 08, 2019 at 10:16:59AM +0200, Pekka Paalanen wrote:
> > On Thu,  7 Nov 2019 16:02:59 -0500
> > Sean Paul <sean@poorly.run> wrote:
> > 
> > > From: Sean Paul <seanpaul@chromium.org>
> > > 
> > > Hey all,
> > > I'm back with another trace events patchset. My first attempt [1] went
> > > better than expected, with enthusiasm for the idea and distain for the
> > > implementation.
> > > 
> > > As promised, I went through and added proper trace events.
> > > 
> > > Before I get _too_ far, I wanted to post this set to get feedback on the
> > > direction I'm going. I've gone back and forth on whether to introduce a
> > > bunch of trace systems vs using the trace class enum. I've settled on
> > > the trace class enum since it seems more extensible and easier to use in
> > > production that just having the blunt "enable this system", or
> > > the tedious "enable each event I'm interested in individually" methods.
> > > 
> > > So, consider this one an RFC unless we're all in agreement, in which
> > > case we should apply it :)
> > >
> > 
> > Hi Sean,
> > 
> > thanks for working on this. I'm not at all familiar with the trace
> > infrastructure, so I'd like to know how flight recorder type of
> > behaviour (a continuously written fixed size ring buffer) can be
> > achieved. Let us have a display server in userspace which in production
> > hits an unexpected condition with DRM and needs to record information
> > for post-mortem debugging. What should it do to have a trace log after
> > the fact to attach with a bug report?
> 
> Yeah I think this has the uapi smell, so would need the userspace side
> too, once we agree on something.
> 
> > I assume that is a major use case for this new feature. Is performance
> > profiling another use case?
> > 
> > Is it ok to build userspace to rely on these trace events during normal
> > operations, e.g. for continuous adjustment of timings/timers?
> 
> Yeah I'm kinda freaked out about this. In the old thread we discussed the
> question of whether dumping dmesg into tracepoints would make them uapi,
> but no conclusion was reached.
> 
> Now instead we're going to duplicate a lot of these debug outputs, with
> specific trace events, which is going to make them even more uapi. And a
> lot of these are very much implementation details (drivers might change
> their opinion on which other states they need for check/commit, e.g. if
> they move a bunch of global state from crtcs into a new driver private
> internal object). Explicit tracepoints with symbol value imo will have a
> much higher chance that someone starts relying on them.
> 
> Also, dmesg is uapi too. Except there's a gentlemen's agreement that you
> should depend upon it because it will make kernel engineers really pissed
> if they can't change/move a specific string. So from that point I think
> just dumping the existing debug strings as unstructured strings into trace
> buffers is a much better idea. Plus no need to have the same information
> duplicated in both a debug output and a tracepoint.
> 
> I think even slightly structured debug tracepoints (e.g. a simple
> (drm_object_id, string) pair) would be too structured since then userspace
> could start watching for events on specific things and maybe use that for
> their retry loops after TEST_ONLY failures. Even though we have a lot of
> debug output strings where that bit of structure is essentially there
> already.
> 
> Aside from this a question on process ... I re-read the old thread and I'm
> not sure how you concluded we've reached consensus on this here, seemed
> all pretty inconclusive on the details and discussions died out?

Reading the thread again I guess it was Joonas comment that tracepoints
are also uapi, and you concluded we can't do this at all.

The trouble is, _everything_ that's observeable from userspace is uapi. So
dmesg, timing of the code, ... For a real funky example of this look at
the ext4 regression, where better code resulted in less entropy generated
and the system hung at boot-up.

But on the flip side, it's only uapi we can't change if someone depends
upon it. For dmesg most people understand that parsing dmesg is bad taste,
so generally not a big problem. For tracepoints, especially if they come
with lots of structured uapi, it's a lot more "this is baked in forever".
But it doesn't have to be, with changed them quite a few times. But as a
rule of thumb, the more structured the data is you present to userspace,
the more likely they'll use it in actual control flow, and the more likely
a change will break userspace in a meaningful way.

Hence for debugging I think least amount of structure is best, plus huge
warnings that you really shouldn't use this for anything else than
debug logs. Anything more that leaks all these implementation details
gives me the chillies. And Pekka's question right off the bat with "can I
use this for tuning timers" kinda proves my point. If it loosk like
intentional uapi userspace will treat it like intentional uapi.
-Daniel


> -Daniel
> 
> 
> > 
> > 
> > Thanks,
> > pq
> > 
> > 
> > > 
> > > [1]- https://patchwork.freedesktop.org/patch/335350/
> > > 
> > > Sean Paul (6):
> > >   drm: trace: Make the vblank queued/delivered events classed
> > >   drm: trace: Introduce drm_trace() and trace event classes
> > >   drm: trace: Add trace events for atomic state lifetime
> > >   drm: trace: Add crtc state trace events
> > >   drm: trace: Add connector state tracing
> > >   drm: trace: Add plane state tracing
> > > 
> > >  Documentation/gpu/drm-internals.rst |   9 +
> > >  drivers/gpu/drm/drm_atomic.c        |  61 ++-
> > >  drivers/gpu/drm/drm_trace.h         | 563 ++++++++++++++++++++++++++--
> > >  drivers/gpu/drm/drm_vblank.c        |   8 +-
> > >  4 files changed, 609 insertions(+), 32 deletions(-)
> > > 
> > 
> 
> 
> 
> -- 
> Daniel Vetter
> Software Engineer, Intel Corporation
> http://blog.ffwll.ch

-- 
Daniel Vetter
Software Engineer, Intel Corporation
http://blog.ffwll.ch
_______________________________________________
dri-devel mailing list
dri-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/dri-devel

Re: [PATCH 0/6] drm: trace: Introduce drm_trace() and instrument drm_atomic.c

[Pekka Paalanen]

[-- Attachment #1.1: Type: text/plain, Size: 1996 bytes --]

On Fri, 8 Nov 2019 09:50:30 +0100
Daniel Vetter <daniel@ffwll.ch> wrote:

> On Fri, Nov 08, 2019 at 10:16:59AM +0200, Pekka Paalanen wrote:
> > Is it ok to build userspace to rely on these trace events during normal
> > operations, e.g. for continuous adjustment of timings/timers?  
> 
> Aside discussion on this: If we add this (I think userspace might want
> some information about the point of no return and why we missed it) then I
> think we should expose that with an improved drm_event and clear
> semantics.
> 
> If we start to encourage compositors to use tracepoints to figure out why
> the kernel doesn't behave (TEST_ONLY failure, or missed flip target), and
> use that for behaviour, we've baked implementation details into the uapi.
> And then we're screwed.
> 
> So if you have any need for timing information that you see solved with a
> tracepoint, pls bring this up so we can add proper uapi. And yes I know
> that if someone doesn't we still need to keep that tracepoint working, but
> with all things uapi the question isn't whether we'll screw up (we will),
> but how often. And less often is massively better :-)

Haha, sorry, that particular question was practically trolling, but
OTOH something I can well imagine someone doing. Trying to fish out
reasons for TEST_ONLY failing is a much better example.

On third hand, profiling tools probably would depend on some trace
points specifically.

As for the uapi for a DRM flight recorder, I'd be happy to have that in
Weston as my time permits. Alas, it needs two people and I can be only
one: either the reviewer or the author. :-)

I can see two ways to use a DRM flight recorder:
- a file you grab as a whole after the fact, or
- a stream you subscribe to and store the results in your own ring
  buffer

The former is simpler, the latter would allow interleaving DRM and app
notes as they happen rather than trying to rebuild a log from
timestamps afterwards.


Thanks,
pq

[-- Attachment #1.2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

[-- Attachment #2: Type: text/plain, Size: 159 bytes --]

_______________________________________________
dri-devel mailing list
dri-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/dri-devel

Re: [PATCH 0/6] drm: trace: Introduce drm_trace() and instrument drm_atomic.c

[Sean Paul]

On Fri, Nov 08, 2019 at 09:59:19AM +0100, Daniel Vetter wrote:
> On Fri, Nov 08, 2019 at 09:46:48AM +0100, Daniel Vetter wrote:
> > On Fri, Nov 08, 2019 at 10:16:59AM +0200, Pekka Paalanen wrote:
> > > On Thu,  7 Nov 2019 16:02:59 -0500
> > > Sean Paul <sean@poorly.run> wrote:
> > > 
> > > > From: Sean Paul <seanpaul@chromium.org>
> > > > 
> > > > Hey all,
> > > > I'm back with another trace events patchset. My first attempt [1] went
> > > > better than expected, with enthusiasm for the idea and distain for the
> > > > implementation.
> > > > 
> > > > As promised, I went through and added proper trace events.
> > > > 
> > > > Before I get _too_ far, I wanted to post this set to get feedback on the
> > > > direction I'm going. I've gone back and forth on whether to introduce a
> > > > bunch of trace systems vs using the trace class enum. I've settled on
> > > > the trace class enum since it seems more extensible and easier to use in
> > > > production that just having the blunt "enable this system", or
> > > > the tedious "enable each event I'm interested in individually" methods.
> > > > 
> > > > So, consider this one an RFC unless we're all in agreement, in which
> > > > case we should apply it :)
> > > >
> > > 
> > > Hi Sean,
> > > 
> > > thanks for working on this. I'm not at all familiar with the trace
> > > infrastructure, so I'd like to know how flight recorder type of
> > > behaviour (a continuously written fixed size ring buffer) can be
> > > achieved. Let us have a display server in userspace which in production
> > > hits an unexpected condition with DRM and needs to record information
> > > for post-mortem debugging. What should it do to have a trace log after
> > > the fact to attach with a bug report?
> > 
> > Yeah I think this has the uapi smell, so would need the userspace side
> > too, once we agree on something.
> > 

For our (Chrome OS) use, the uapi is pretty simple:

#! /usr/bin/env

mask=$1

pushd /sys/kernel/tracing
echo "event_class & $mask" > events/drm/filter
echo 1 > events/drm/enable
echo 1 > tracing_on
popd


Then when we need to log something:

cat /sys/kernel/tracing/trace_pipe



> > > I assume that is a major use case for this new feature. Is performance
> > > profiling another use case?

Not at the present.


> > > 
> > > Is it ok to build userspace to rely on these trace events during normal
> > > operations, e.g. for continuous adjustment of timings/timers?
> > 
> > Yeah I'm kinda freaked out about this. In the old thread we discussed the
> > question of whether dumping dmesg into tracepoints would make them uapi,
> > but no conclusion was reached.
> > 
> > Now instead we're going to duplicate a lot of these debug outputs, with
> > specific trace events, which is going to make them even more uapi. And a
> > lot of these are very much implementation details (drivers might change
> > their opinion on which other states they need for check/commit, e.g. if
> > they move a bunch of global state from crtcs into a new driver private
> > internal object). Explicit tracepoints with symbol value imo will have a
> > much higher chance that someone starts relying on them.
> > 
> > Also, dmesg is uapi too. Except there's a gentlemen's agreement that you
> > should depend upon it because it will make kernel engineers really pissed
> > if they can't change/move a specific string. So from that point I think
> > just dumping the existing debug strings as unstructured strings into trace
> > buffers is a much better idea. Plus no need to have the same information
> > duplicated in both a debug output and a tracepoint.
> > 
> > I think even slightly structured debug tracepoints (e.g. a simple
> > (drm_object_id, string) pair) would be too structured since then userspace
> > could start watching for events on specific things and maybe use that for
> > their retry loops after TEST_ONLY failures. Even though we have a lot of
> > debug output strings where that bit of structure is essentially there
> > already.
> > 
> > Aside from this a question on process ... I re-read the old thread and I'm
> > not sure how you concluded we've reached consensus on this here, seemed
> > all pretty inconclusive on the details and discussions died out?
> 
> Reading the thread again I guess it was Joonas comment that tracepoints
> are also uapi, and you concluded we can't do this at all.
> 
> The trouble is, _everything_ that's observeable from userspace is uapi. So
> dmesg, timing of the code, ... For a real funky example of this look at
> the ext4 regression, where better code resulted in less entropy generated
> and the system hung at boot-up.
> 
> But on the flip side, it's only uapi we can't change if someone depends
> upon it. For dmesg most people understand that parsing dmesg is bad taste,
> so generally not a big problem. For tracepoints, especially if they come
> with lots of structured uapi, it's a lot more "this is baked in forever".
> But it doesn't have to be, with changed them quite a few times. But as a
> rule of thumb, the more structured the data is you present to userspace,
> the more likely they'll use it in actual control flow, and the more likely
> a change will break userspace in a meaningful way.
> 
> Hence for debugging I think least amount of structure is best, plus huge
> warnings that you really shouldn't use this for anything else than
> debug logs. Anything more that leaks all these implementation details
> gives me the chillies. And Pekka's question right off the bat with "can I
> use this for tuning timers" kinda proves my point. If it loosk like
> intentional uapi userspace will treat it like intentional uapi.

So the more useful the data, the less desirable it is to surface :-)

Playing devil's advocate for a second (and probably exposing my naivity),
would it be _so_ bad if userspace inspected the traces for check failure
cause? If we remove a check in the core, the trace event just never
fires (no u/s breakage), if we change a check, we introduce a new trace
event to reflect reality and the old event goes quiet.

We could accrue some debt if a state variable changes since we'd have to keep
the structure of the trace event and tack on the end. To combat this we could
scrutinize the information exposed for each state and make sure that we're
choosing stable values (in the extreme we could limit the info to only
property-backed values). Additionally, we can always expose new trace events
if things change too dramatically and lean on the event classes/filtering for
versioning.

Sean


> -Daniel
> 
> 
> > -Daniel
> > 
> > 
> > > 
> > > 
> > > Thanks,
> > > pq
> > > 
> > > 
> > > > 
> > > > [1]- https://patchwork.freedesktop.org/patch/335350/
> > > > 
> > > > Sean Paul (6):
> > > >   drm: trace: Make the vblank queued/delivered events classed
> > > >   drm: trace: Introduce drm_trace() and trace event classes
> > > >   drm: trace: Add trace events for atomic state lifetime
> > > >   drm: trace: Add crtc state trace events
> > > >   drm: trace: Add connector state tracing
> > > >   drm: trace: Add plane state tracing
> > > > 
> > > >  Documentation/gpu/drm-internals.rst |   9 +
> > > >  drivers/gpu/drm/drm_atomic.c        |  61 ++-
> > > >  drivers/gpu/drm/drm_trace.h         | 563 ++++++++++++++++++++++++++--
> > > >  drivers/gpu/drm/drm_vblank.c        |   8 +-
> > > >  4 files changed, 609 insertions(+), 32 deletions(-)
> > > > 
> > > 
> > 
> > 
> > 
> > -- 
> > Daniel Vetter
> > Software Engineer, Intel Corporation
> > http://blog.ffwll.ch
> 
> -- 
> Daniel Vetter
> Software Engineer, Intel Corporation
> http://blog.ffwll.ch

-- 
Sean Paul, Software Engineer, Google / Chromium OS
_______________________________________________
dri-devel mailing list
dri-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/dri-devel

Re: [PATCH 0/6] drm: trace: Introduce drm_trace() and instrument drm_atomic.c

[Daniel Vetter]

On Fri, Nov 08, 2019 at 11:23:27AM -0500, Sean Paul wrote:
> On Fri, Nov 08, 2019 at 09:59:19AM +0100, Daniel Vetter wrote:
> > On Fri, Nov 08, 2019 at 09:46:48AM +0100, Daniel Vetter wrote:
> > > On Fri, Nov 08, 2019 at 10:16:59AM +0200, Pekka Paalanen wrote:
> > > > On Thu,  7 Nov 2019 16:02:59 -0500
> > > > Sean Paul <sean@poorly.run> wrote:
> > > > 
> > > > > From: Sean Paul <seanpaul@chromium.org>
> > > > > 
> > > > > Hey all,
> > > > > I'm back with another trace events patchset. My first attempt [1] went
> > > > > better than expected, with enthusiasm for the idea and distain for the
> > > > > implementation.
> > > > > 
> > > > > As promised, I went through and added proper trace events.
> > > > > 
> > > > > Before I get _too_ far, I wanted to post this set to get feedback on the
> > > > > direction I'm going. I've gone back and forth on whether to introduce a
> > > > > bunch of trace systems vs using the trace class enum. I've settled on
> > > > > the trace class enum since it seems more extensible and easier to use in
> > > > > production that just having the blunt "enable this system", or
> > > > > the tedious "enable each event I'm interested in individually" methods.
> > > > > 
> > > > > So, consider this one an RFC unless we're all in agreement, in which
> > > > > case we should apply it :)
> > > > >
> > > > 
> > > > Hi Sean,
> > > > 
> > > > thanks for working on this. I'm not at all familiar with the trace
> > > > infrastructure, so I'd like to know how flight recorder type of
> > > > behaviour (a continuously written fixed size ring buffer) can be
> > > > achieved. Let us have a display server in userspace which in production
> > > > hits an unexpected condition with DRM and needs to record information
> > > > for post-mortem debugging. What should it do to have a trace log after
> > > > the fact to attach with a bug report?
> > > 
> > > Yeah I think this has the uapi smell, so would need the userspace side
> > > too, once we agree on something.
> > > 
> 
> For our (Chrome OS) use, the uapi is pretty simple:
> 
> #! /usr/bin/env
> 
> mask=$1
> 
> pushd /sys/kernel/tracing
> echo "event_class & $mask" > events/drm/filter
> echo 1 > events/drm/enable
> echo 1 > tracing_on
> popd
> 
> 
> Then when we need to log something:
> 
> cat /sys/kernel/tracing/trace_pipe
> 
> 
> 
> > > > I assume that is a major use case for this new feature. Is performance
> > > > profiling another use case?
> 
> Not at the present.
> 
> 
> > > > 
> > > > Is it ok to build userspace to rely on these trace events during normal
> > > > operations, e.g. for continuous adjustment of timings/timers?
> > > 
> > > Yeah I'm kinda freaked out about this. In the old thread we discussed the
> > > question of whether dumping dmesg into tracepoints would make them uapi,
> > > but no conclusion was reached.
> > > 
> > > Now instead we're going to duplicate a lot of these debug outputs, with
> > > specific trace events, which is going to make them even more uapi. And a
> > > lot of these are very much implementation details (drivers might change
> > > their opinion on which other states they need for check/commit, e.g. if
> > > they move a bunch of global state from crtcs into a new driver private
> > > internal object). Explicit tracepoints with symbol value imo will have a
> > > much higher chance that someone starts relying on them.
> > > 
> > > Also, dmesg is uapi too. Except there's a gentlemen's agreement that you
> > > should depend upon it because it will make kernel engineers really pissed
> > > if they can't change/move a specific string. So from that point I think
> > > just dumping the existing debug strings as unstructured strings into trace
> > > buffers is a much better idea. Plus no need to have the same information
> > > duplicated in both a debug output and a tracepoint.
> > > 
> > > I think even slightly structured debug tracepoints (e.g. a simple
> > > (drm_object_id, string) pair) would be too structured since then userspace
> > > could start watching for events on specific things and maybe use that for
> > > their retry loops after TEST_ONLY failures. Even though we have a lot of
> > > debug output strings where that bit of structure is essentially there
> > > already.
> > > 
> > > Aside from this a question on process ... I re-read the old thread and I'm
> > > not sure how you concluded we've reached consensus on this here, seemed
> > > all pretty inconclusive on the details and discussions died out?
> > 
> > Reading the thread again I guess it was Joonas comment that tracepoints
> > are also uapi, and you concluded we can't do this at all.
> > 
> > The trouble is, _everything_ that's observeable from userspace is uapi. So
> > dmesg, timing of the code, ... For a real funky example of this look at
> > the ext4 regression, where better code resulted in less entropy generated
> > and the system hung at boot-up.
> > 
> > But on the flip side, it's only uapi we can't change if someone depends
> > upon it. For dmesg most people understand that parsing dmesg is bad taste,
> > so generally not a big problem. For tracepoints, especially if they come
> > with lots of structured uapi, it's a lot more "this is baked in forever".
> > But it doesn't have to be, with changed them quite a few times. But as a
> > rule of thumb, the more structured the data is you present to userspace,
> > the more likely they'll use it in actual control flow, and the more likely
> > a change will break userspace in a meaningful way.
> > 
> > Hence for debugging I think least amount of structure is best, plus huge
> > warnings that you really shouldn't use this for anything else than
> > debug logs. Anything more that leaks all these implementation details
> > gives me the chillies. And Pekka's question right off the bat with "can I
> > use this for tuning timers" kinda proves my point. If it loosk like
> > intentional uapi userspace will treat it like intentional uapi.
> 
> So the more useful the data, the less desirable it is to surface :-)
> 
> Playing devil's advocate for a second (and probably exposing my naivity),
> would it be _so_ bad if userspace inspected the traces for check failure
> cause? If we remove a check in the core, the trace event just never
> fires (no u/s breakage), if we change a check, we introduce a new trace
> event to reflect reality and the old event goes quiet.

At that point you've broken userspace if you're unlucky. Scenario.

1. userspace does a TEST_ONLY
2. it fails, but userspace sees the magic trace event, and does a Magic
Fallback (tm)
3. everyone is happy

2a. it still fails, but now the exact tracepoint is gone, or move
sufficiently that userspace doesn't spot it anymore.
3. userspace falls back to something dumb, maybe single fullscreen untiled
plane, resulting in a slide show
4. user is seriously pissed at the slideshow
5. one grumpy kernel maintainer gets to apply a few reverts

So yeah if we create a few nicely structured tracepoints "for debugging"
and compositor people spot then and go all "oh cool, I can use this",
we're screwed.

> We could accrue some debt if a state variable changes since we'd have to keep
> the structure of the trace event and tack on the end. To combat this we could
> scrutinize the information exposed for each state and make sure that we're
> choosing stable values (in the extreme we could limit the info to only
> property-backed values). Additionally, we can always expose new trace events
> if things change too dramatically and lean on the event classes/filtering for
> versioning.

You can't just expose new trace events, if userspace relies on the old
ones they have to keep working. Some subsystems are sufficiently paranoid
about that that the answer is "no tracepoint, sry". Which then results in
people doing dynamic tracing, which ofc is even worse from a "will it
break?" pov.

It's all a tradeoff, and at least personally I figured the debug dump
without any structure at all seemed like the least risky. Most reasonable
people already agree that enabling debugging and parsing dmesg is not a
good idea. Hopefully they'll have the same feeling about unstructured
debug crap dumped into tracepoints.

The only part that _will_ become uapi for that is the exact name of the
tracepoint, since userspace will need to know that one to be able to
enable it.
-Daniel

> 
> Sean
> 
> 
> > -Daniel
> > 
> > 
> > > -Daniel
> > > 
> > > 
> > > > 
> > > > 
> > > > Thanks,
> > > > pq
> > > > 
> > > > 
> > > > > 
> > > > > [1]- https://patchwork.freedesktop.org/patch/335350/
> > > > > 
> > > > > Sean Paul (6):
> > > > >   drm: trace: Make the vblank queued/delivered events classed
> > > > >   drm: trace: Introduce drm_trace() and trace event classes
> > > > >   drm: trace: Add trace events for atomic state lifetime
> > > > >   drm: trace: Add crtc state trace events
> > > > >   drm: trace: Add connector state tracing
> > > > >   drm: trace: Add plane state tracing
> > > > > 
> > > > >  Documentation/gpu/drm-internals.rst |   9 +
> > > > >  drivers/gpu/drm/drm_atomic.c        |  61 ++-
> > > > >  drivers/gpu/drm/drm_trace.h         | 563 ++++++++++++++++++++++++++--
> > > > >  drivers/gpu/drm/drm_vblank.c        |   8 +-
> > > > >  4 files changed, 609 insertions(+), 32 deletions(-)
> > > > > 
> > > > 
> > > 
> > > 
> > > 
> > > -- 
> > > Daniel Vetter
> > > Software Engineer, Intel Corporation
> > > http://blog.ffwll.ch
> > 
> > -- 
> > Daniel Vetter
> > Software Engineer, Intel Corporation
> > http://blog.ffwll.ch
> 
> -- 
> Sean Paul, Software Engineer, Google / Chromium OS

-- 
Daniel Vetter
Software Engineer, Intel Corporation
http://blog.ffwll.ch
_______________________________________________
dri-devel mailing list
dri-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/dri-devel