[15/15] drm/i915/guc: Trace messages from CT while in debug

Commit Message

Michal Wajdeczko Aug. 4, 2017, 4:27 p.m. UTC

During debug we may want to investigate all communication
from the Guc. Add proper tracing macros in debug config.

Signed-off-by: Michal Wajdeczko <[e-mail]>
---
 drivers/gpu/drm/i915/intel_guc_ct.c | 19 +++++++++++++++++++
 1 file changed, 19 insertions(+)

Comments

Chris Wilson Aug. 4, 2017, 6:29 p.m. UTC | #1

Quoting Michal Wajdeczko (2017-08-04 17:27:12)
> During debug we may want to investigate all communication
> from the Guc. Add proper tracing macros in debug config.
> 
> Signed-off-by: Michal Wajdeczko <[e-mail]>
> ---
>  drivers/gpu/drm/i915/intel_guc_ct.c | 19 +++++++++++++++++++
>  1 file changed, 19 insertions(+)
> 
> diff --git a/drivers/gpu/drm/i915/intel_guc_ct.c b/drivers/gpu/drm/i915/intel_guc_ct.c
> index 9f7fc5e..71daad3 100644
> --- a/drivers/gpu/drm/i915/intel_guc_ct.c
> +++ b/drivers/gpu/drm/i915/intel_guc_ct.c
> @@ -24,6 +24,12 @@
>  #include "i915_drv.h"
>  #include "intel_guc_ct.h"
>  
> +#ifdef CONFIG_DRM_I915_DEBUG
> +#define CT_DEBUG_DRIVER(...)   DRM_DEBUG_DRIVER(__VA_ARGS__)
> +#else
> +#define CT_DEBUG_DRIVER(...)
> +#endif

+1. If we only use a single Kconfig, or enabled them for CI anyway, we
still run the risk of drowning in the noise.  Flooding CI dmesg has many
other unfortunate repercussions as well.

Oh well, back to the ddebug / trace_debug wishlist. (Being able to dump
the pertinent buffer on demand/error without flooding the test runner.)
-Chris

Patch

diff --git a/drivers/gpu/drm/i915/intel_guc_ct.c b/drivers/gpu/drm/i915/intel_guc_ct.c
index 9f7fc5e..71daad3 100644
--- a/drivers/gpu/drm/i915/intel_guc_ct.c
+++ b/drivers/gpu/drm/i915/intel_guc_ct.c
@@ -24,6 +24,12 @@ 
 #include "i915_drv.h"
 #include "intel_guc_ct.h"
 
+#ifdef CONFIG_DRM_I915_DEBUG
+#define CT_DEBUG_DRIVER(...)	DRM_DEBUG_DRIVER(__VA_ARGS__)
+#else
+#define CT_DEBUG_DRIVER(...)
+#endif
+
 struct ct_request {
 	struct list_head link;
 	u32 fence;
@@ -325,6 +331,10 @@  static int ctb_write(struct intel_guc_ct_buffer *ctb,
 		 (send_response ? GUC_CT_MSG_SEND_STATUS : 0) |
 		 (action[0] << GUC_CT_MSG_ACTION_SHIFT);
 
+	CT_DEBUG_DRIVER("CT: writing %*phn %*phn %*phn\n",
+			4, &header, 4, &fence,
+			4*(len - 1), &action[1]);
+
 	cmds[tail] = header;
 	tail = (tail + 1) % size;
 
@@ -496,6 +506,9 @@  static int intel_guc_send_ct(struct intel_guc *guc, const u32 *action, u32 len,
 	if (unlikely(ret < 0)) {
 		DRM_ERROR("CT: send action %#X failed; err=%d status=%#X\n",
 			  action[0], ret, status);
+	} else if (unlikely(ret)) {
+		CT_DEBUG_DRIVER("CT: send action %#x returned %d (%#x)\n",
+				action[0], ret, ret);
 	}
 
 	mutex_unlock(&guc->send_mutex);
@@ -542,10 +555,12 @@  static int ctb_read(struct intel_guc_ct_buffer *ctb, u32 *data)
 	/* beware of buffer wrap case */
 	if (available < 0)
 		available += size;
+	CT_DEBUG_DRIVER("CT: available %d (%u:%u)\n", available, head, tail);
 	GEM_BUG_ON(available < 0);
 
 	data[0] = cmds[head];
 	head = (head + 1) % size;
+	CT_DEBUG_DRIVER("CT: header %#x\n", data[0]);
 
 	/* message len with header */
 	len = ct_header_get_len(data[0]) + 1;
@@ -563,6 +578,7 @@  static int ctb_read(struct intel_guc_ct_buffer *ctb, u32 *data)
 		data[i] = cmds[head];
 		head = (head + 1) % size;
 	}
+	CT_DEBUG_DRIVER("CT: received %*phn\n", 4*len, data);
 
 	desc->head = head * 4;
 	return 0;
@@ -584,6 +600,7 @@  static int guc_handle_response(struct intel_guc *guc, const u32 *data)
 		DRM_ERROR("CT: corrupted response %*phn\n", 4*len, data);
 		return -EPROTO;
 	}
+	CT_DEBUG_DRIVER("CT: response fence %u status %#x\n", fence, status);
 
 	spin_lock_irqsave(&guc->ct.lock, flags);
 	list_for_each_entry(req, &guc->ct.pending_requests, link) {
@@ -615,6 +632,7 @@  static int guc_handle_request(struct intel_guc *guc, const u32 *data)
 
 	GEM_BUG_ON(ct_header_is_response(header));
 	/* data layout beyond header is request specific */
+	CT_DEBUG_DRIVER("CT: request %#x\n", ct_header_get_action(header));
 
 	request = kmalloc(sizeof(*request), GFP_ATOMIC);
 	if (unlikely(!request)) {
@@ -656,6 +674,7 @@  static bool guc_process_incoming_requests(struct intel_guc *guc)
 	header = request->data[0];
 	action = ct_header_get_action(header);
 	len = ct_header_get_len(header) + 1; /* also count header dw */
+	CT_DEBUG_DRIVER("CT: processing request %*phn\n", 4*len, request->data);
 
 	switch (action) {
 	case INTEL_GUC_ACTION_DEFAULT: