Re: [Intel-gfx] [PATCH v2 15/16] drm/i915/guc: Trace messages from CT while in debug

2017-08-07 Thread Daniele Ceraolo Spurio 



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 
---
  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(>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, , 4, ,
+   4*(len - 1), [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(>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;

[Intel-gfx] [PATCH v2 15/16] drm/i915/guc: Trace messages from CT while in debug

2017-08-07 Thread Michal Wajdeczko 
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 
---
 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
+#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(>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, , 4, ,
+   4*(len - 1), [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(>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 =