diff mbox

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

Message ID 20170807161430.23308-16-michal.wajdeczko@intel.com (mailing list archive)
State New, archived
Headers show

Commit Message

Michal Wajdeczko Aug. 7, 2017, 4:14 p.m. UTC 
During debug we may want to investigate all communication
from the Guc. Add proper tracing macros in debug config.

v2: convert remaining DRM_DEBUG into new CT_DEBUG (Michal)

Signed-off-by: Michal Wajdeczko <michal.wajdeczko@intel.com>
---
 drivers/gpu/drm/i915/intel_guc_ct.c | 41 +++++++++++++++++++++++++++----------
 1 file changed, 30 insertions(+), 11 deletions(-)

Comments

Daniele Ceraolo Spurio Aug. 7, 2017, 6:42 p.m. UTC | #1 
On 07/08/17 09:14, Michal Wajdeczko wrote:
> During debug we may want to investigate all communication
> from the Guc. Add proper tracing macros in debug config.
> 
> v2: convert remaining DRM_DEBUG into new CT_DEBUG (Michal)
> 
> Signed-off-by: Michal Wajdeczko <michal.wajdeczko@intel.com>
> ---
>   drivers/gpu/drm/i915/intel_guc_ct.c | 41 +++++++++++++++++++++++++++----------
>   1 file changed, 30 insertions(+), 11 deletions(-)
> 
> diff --git a/drivers/gpu/drm/i915/intel_guc_ct.c b/drivers/gpu/drm/i915/intel_guc_ct.c
> index e6912be..568fbc0 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

Personally I'd prefer to have a separate kconfig for this (e.g. 
CONFIG_DRM_I915_DEBUG_GUC) as this can be quite verbose in some 
GuC-centric scenarios.

-Daniele

> +#define CT_DEBUG_DRIVER(...)	DRM_DEBUG_DRIVER(__VA_ARGS__)
> +#else
> +#define CT_DEBUG_DRIVER(...)
> +#endif
> +
>   struct ct_request {
>   	struct list_head link;
>   	u32 fence;
> @@ -69,8 +75,8 @@ static inline const char *guc_ct_buffer_type_to_str(u32 type)
>   static void guc_ct_buffer_desc_init(struct guc_ct_buffer_desc *desc,
>   				    u32 cmds_addr, u32 size, u32 owner)
>   {
> -	DRM_DEBUG_DRIVER("CT: desc %p init addr=%#x size=%u owner=%u\n",
> -			 desc, cmds_addr, size, owner);
> +	CT_DEBUG_DRIVER("CT: desc %p init addr=%#x size=%u owner=%u\n",
> +			desc, cmds_addr, size, owner);
>   	memset(desc, 0, sizeof(*desc));
>   	desc->addr = cmds_addr;
>   	desc->size = size;
> @@ -79,8 +85,8 @@ static void guc_ct_buffer_desc_init(struct guc_ct_buffer_desc *desc,
>   
>   static void guc_ct_buffer_desc_reset(struct guc_ct_buffer_desc *desc)
>   {
> -	DRM_DEBUG_DRIVER("CT: desc %p reset head=%u tail=%u\n",
> -			 desc, desc->head, desc->tail);
> +	CT_DEBUG_DRIVER("CT: desc %p reset head=%u tail=%u\n",
> +			desc, desc->head, desc->tail);
>   	desc->head = 0;
>   	desc->tail = 0;
>   	desc->is_in_error = 0;
> @@ -176,7 +182,7 @@ static int ctch_init(struct intel_guc *guc,
>   		err = PTR_ERR(blob);
>   		goto err_vma;
>   	}
> -	DRM_DEBUG_DRIVER("CT: vma base=%#x\n", guc_ggtt_offset(ctch->vma));
> +	CT_DEBUG_DRIVER("CT: vma base=%#x\n", guc_ggtt_offset(ctch->vma));
>   
>   	/* store pointers to desc and cmds */
>   	for (i = 0; i < ARRAY_SIZE(ctch->ctbs); i++) {
> @@ -190,8 +196,8 @@ static int ctch_init(struct intel_guc *guc,
>   err_vma:
>   	i915_vma_unpin_and_release(&ctch->vma);
>   err_out:
> -	DRM_DEBUG_DRIVER("CT: channel %d initialization failed; err=%d\n",
> -			 ctch->owner, err);
> +	CT_DEBUG_DRIVER("CT: channel %d initialization failed; err=%d\n",
> +			ctch->owner, err);
>   	return err;
>   }
>   
> @@ -211,8 +217,8 @@ static int ctch_open(struct intel_guc *guc,
>   	int err;
>   	int i;
>   
> -	DRM_DEBUG_DRIVER("CT: channel %d reopen=%s\n",
> -			 ctch->owner, yesno(ctch_is_open(ctch)));
> +	CT_DEBUG_DRIVER("CT: channel %d reopen=%s\n",
> +			ctch->owner, yesno(ctch_is_open(ctch)));
>   
>   	if (!ctch->vma) {
>   		err = ctch_init(guc, ctch);
> @@ -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;
>   
> @@ -500,6 +510,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);
> @@ -546,10 +559,12 @@ static int ctb_read(struct intel_guc_ct_buffer *ctb, u32 *data)
>   	/* beware of buffer wrap case */
>   	if (unlikely(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;
> @@ -567,6 +582,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;
> @@ -592,12 +608,13 @@ static int guc_handle_response(struct intel_guc *guc, const u32 *msg)
>   		DRM_ERROR("CT: corrupted status %*phn\n", 4*len, msg);
>   		status = INTEL_GUC_STATUS_GENERIC_FAIL;
>   	}
> +	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) {
>   		if (req->fence != fence) {
> -			DRM_DEBUG_DRIVER("CT: request %u awaits response\n",
> -					 req->fence);
> +			CT_DEBUG_DRIVER("CT: request %u awaits response\n",
> +					req->fence);
>   			continue;
>   		}
>   		req->response_len = len - 3;
> @@ -623,6 +640,7 @@ static int guc_handle_request(struct intel_guc *guc, const u32 *msg)
>   
>   	GEM_BUG_ON(ct_header_is_response(header));
>   	/* Request message layout beyond header is request specific */
> +	CT_DEBUG_DRIVER("CT: request %#x\n", ct_header_get_action(header));
>   
>   	request = kmalloc(sizeof(*request) + 4*len, GFP_ATOMIC);
>   	if (unlikely(!request)) {
> @@ -662,6 +680,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:
>
diff mbox

Patch

diff --git a/drivers/gpu/drm/i915/intel_guc_ct.c b/drivers/gpu/drm/i915/intel_guc_ct.c
index e6912be..568fbc0 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;
@@ -69,8 +75,8 @@  static inline const char *guc_ct_buffer_type_to_str(u32 type)
 static void guc_ct_buffer_desc_init(struct guc_ct_buffer_desc *desc,
 				    u32 cmds_addr, u32 size, u32 owner)
 {
-	DRM_DEBUG_DRIVER("CT: desc %p init addr=%#x size=%u owner=%u\n",
-			 desc, cmds_addr, size, owner);
+	CT_DEBUG_DRIVER("CT: desc %p init addr=%#x size=%u owner=%u\n",
+			desc, cmds_addr, size, owner);
 	memset(desc, 0, sizeof(*desc));
 	desc->addr = cmds_addr;
 	desc->size = size;
@@ -79,8 +85,8 @@  static void guc_ct_buffer_desc_init(struct guc_ct_buffer_desc *desc,
 
 static void guc_ct_buffer_desc_reset(struct guc_ct_buffer_desc *desc)
 {
-	DRM_DEBUG_DRIVER("CT: desc %p reset head=%u tail=%u\n",
-			 desc, desc->head, desc->tail);
+	CT_DEBUG_DRIVER("CT: desc %p reset head=%u tail=%u\n",
+			desc, desc->head, desc->tail);
 	desc->head = 0;
 	desc->tail = 0;
 	desc->is_in_error = 0;
@@ -176,7 +182,7 @@  static int ctch_init(struct intel_guc *guc,
 		err = PTR_ERR(blob);
 		goto err_vma;
 	}
-	DRM_DEBUG_DRIVER("CT: vma base=%#x\n", guc_ggtt_offset(ctch->vma));
+	CT_DEBUG_DRIVER("CT: vma base=%#x\n", guc_ggtt_offset(ctch->vma));
 
 	/* store pointers to desc and cmds */
 	for (i = 0; i < ARRAY_SIZE(ctch->ctbs); i++) {
@@ -190,8 +196,8 @@  static int ctch_init(struct intel_guc *guc,
 err_vma:
 	i915_vma_unpin_and_release(&ctch->vma);
 err_out:
-	DRM_DEBUG_DRIVER("CT: channel %d initialization failed; err=%d\n",
-			 ctch->owner, err);
+	CT_DEBUG_DRIVER("CT: channel %d initialization failed; err=%d\n",
+			ctch->owner, err);
 	return err;
 }
 
@@ -211,8 +217,8 @@  static int ctch_open(struct intel_guc *guc,
 	int err;
 	int i;
 
-	DRM_DEBUG_DRIVER("CT: channel %d reopen=%s\n",
-			 ctch->owner, yesno(ctch_is_open(ctch)));
+	CT_DEBUG_DRIVER("CT: channel %d reopen=%s\n",
+			ctch->owner, yesno(ctch_is_open(ctch)));
 
 	if (!ctch->vma) {
 		err = ctch_init(guc, ctch);
@@ -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;
 
@@ -500,6 +510,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);
@@ -546,10 +559,12 @@  static int ctb_read(struct intel_guc_ct_buffer *ctb, u32 *data)
 	/* beware of buffer wrap case */
 	if (unlikely(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;
@@ -567,6 +582,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;
@@ -592,12 +608,13 @@  static int guc_handle_response(struct intel_guc *guc, const u32 *msg)
 		DRM_ERROR("CT: corrupted status %*phn\n", 4*len, msg);
 		status = INTEL_GUC_STATUS_GENERIC_FAIL;
 	}
+	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) {
 		if (req->fence != fence) {
-			DRM_DEBUG_DRIVER("CT: request %u awaits response\n",
-					 req->fence);
+			CT_DEBUG_DRIVER("CT: request %u awaits response\n",
+					req->fence);
 			continue;
 		}
 		req->response_len = len - 3;
@@ -623,6 +640,7 @@  static int guc_handle_request(struct intel_guc *guc, const u32 *msg)
 
 	GEM_BUG_ON(ct_header_is_response(header));
 	/* Request message layout beyond header is request specific */
+	CT_DEBUG_DRIVER("CT: request %#x\n", ct_header_get_action(header));
 
 	request = kmalloc(sizeof(*request) + 4*len, GFP_ATOMIC);
 	if (unlikely(!request)) {
@@ -662,6 +680,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: