On 11/07/16 19:01, Dave Gordon wrote:

Where we're going to continue regardless of the problem, rather than fail, then the message should be a WARNing rather than an ERROR.

Signed-off-by: Dave Gordon david.s.gordon@intel.com

drivers/gpu/drm/i915/i915_guc_submission.c | 18 +++++++----------- 1 file changed, 7 insertions(+), 11 deletions(-)

diff --git a/drivers/gpu/drm/i915/i915_guc_submission.c b/drivers/gpu/drm/i915/i915_guc_submission.c index 2112e02..e299b64 100644 --- a/drivers/gpu/drm/i915/i915_guc_submission.c +++ b/drivers/gpu/drm/i915/i915_guc_submission.c @@ -114,10 +114,8 @@ static int host2guc_action(struct intel_guc *guc, u32 *data, u32 len) if (ret != -ETIMEDOUT) ret = -EIO;

• DRM_ERROR("GUC: host2guc action 0x%X failed. ret=%d "
  

• 		"status=0x%08X response=0x%08X\n",
  

• 		data[0], ret, status,
  

• 		I915_READ(SOFT_SCRATCH(15)));
  

• DRM_WARN("Action 0x%X failed; ret=%d status=0x%08X response=0x%08X\n",
  

• 	 data[0], ret, status, I915_READ(SOFT_SCRATCH(15)));
  

Hm, this does propagate the error code to the callers some which will act and log the failure. Majority won't though - like suspend/resume etc. In those cases it feels more like an error than a warning.

dev_priv->guc.action_fail += 1;
dev_priv->guc.action_err = ret;

@@ -553,8 +551,8 @@ static int guc_ring_doorbell(struct i915_guc_client *gc) if (db_ret.db_status == GUC_DOORBELL_DISABLED) break;

• DRM_ERROR("Cookie mismatch. Expected %d, returned %d\n",
  

• 	  db_cmp.cookie, db_ret.cookie);
  

• DRM_WARN("Cookie mismatch. Expected %d, found %d\n",
  

• 	 db_cmp.cookie, db_ret.cookie);
  

This one is interesting, error is propagated out a bit but then ignored in actual command submission.

If the above message means command will not be submitted error is probably more appropriate. Or perhaps we cannot tell if the command was submitted or not in this case?

/* update the cookie to newly read cookie from GuC */
db_cmp.cookie = db_ret.cookie;

@@ -726,8 +724,8 @@ static void guc_init_doorbell_hw(struct intel_guc *guc) /* Restore to original value */ err = guc_update_doorbell_id(guc, client, db_id); if (err)

• DRM_ERROR("Failed to restore doorbell to %d, err %d\n",
  

• 	db_id, err);
  

• DRM_WARN("Failed to restore doorbell to %d, err %d\n",
  

• 	 db_id, err);
  
  

  for (i = 0; i < GUC_MAX_DOORBELLS; ++i) { i915_reg_t drbreg = GEN8_DRBREGL(i);

@@ -819,8 +817,6 @@ static void guc_init_doorbell_hw(struct intel_guc *guc) return client;

err:

• DRM_ERROR("FAILED to create priority %u GuC client!\n", priority);
• guc_client_free(dev_priv, client); return NULL; }

@@ -998,7 +994,7 @@ int i915_guc_submission_enable(struct drm_i915_private *dev_priv) GUC_CTX_PRIORITY_KMD_NORMAL, dev_priv->kernel_context); if (!client) {

• DRM_ERROR("Failed to create execbuf guc_client\n");
  

• DRM_ERROR("Failed to create normal GuC client!\n");
  

  return -ENOMEM; }

Regards,

Tvrtko

On 12/07/16 10:27, Chris Wilson wrote:

On Tue, Jul 12, 2016 at 10:20:43AM +0100, Tvrtko Ursulin wrote:

...

On 11/07/16 19:01, Dave Gordon wrote:

...

@@ -553,8 +551,8 @@ static int guc_ring_doorbell(struct i915_guc_client *gc) if (db_ret.db_status == GUC_DOORBELL_DISABLED) break;

• DRM_ERROR("Cookie mismatch. Expected %d, returned %d\n",
  

• 	  db_cmp.cookie, db_ret.cookie);
  

• DRM_WARN("Cookie mismatch. Expected %d, found %d\n",
  

• 	 db_cmp.cookie, db_ret.cookie);
  

This one is interesting, error is propagated out a bit but then ignored in actual command submission.

If the above message means command will not be submitted error is probably more appropriate. Or perhaps we cannot tell if the command was submitted or not in this case?

It's insignificant. An actual error would result in a GPU hang, and without being recorded in the error state any message here is useless.

I don't agree that it is useless, if it is a very unexpected situation it deserves to be logged. People do store and look at logs when things go bad.

Regards,

Tvrtko

On 11/07/16 19:01, Dave Gordon wrote:

Some downgraded from DRM_ERROR() to DRM_WARN(), some eliminated, and a few upgraded from DRM_INFO() to DRM_NOTE() or DRM_WARN().

Signed-off-by: Dave Gordon david.s.gordon@intel.com

drivers/gpu/drm/i915/intel_guc_loader.c | 20 ++++++++++---------- 1 file changed, 10 insertions(+), 10 deletions(-)

diff --git a/drivers/gpu/drm/i915/intel_guc_loader.c b/drivers/gpu/drm/i915/intel_guc_loader.c index 605c696..fd032eb 100644 --- a/drivers/gpu/drm/i915/intel_guc_loader.c +++ b/drivers/gpu/drm/i915/intel_guc_loader.c @@ -140,12 +140,14 @@ static u32 get_gttype(struct drm_i915_private *dev_priv)

static u32 get_core_family(struct drm_i915_private *dev_priv) {

• switch (INTEL_INFO(dev_priv)->gen) {

• u32 gen = INTEL_GEN(dev_priv);

• switch (gen) { case 9: return GFXCORE_FAMILY_GEN9;

  default:

• DRM_ERROR("GUC: unsupported core family\n");
  

• DRM_WARN("GEN%d does not support GuC operation\n", gen);
  

  return GFXCORE_FAMILY_UNKNOWN; } }

@@ -433,7 +435,7 @@ int intel_guc_setup(struct drm_device *dev) goto fail; } else if (*fw_path == '\0') { /* Device has a GuC but we don't know what f/w to load? */

• DRM_INFO("No GuC firmware known for this platform\n");
  

• DRM_WARN("No GuC firmware known for this platform\n");
  

  err = -ENODEV; goto fail; }

@@ -471,10 +473,8 @@ int intel_guc_setup(struct drm_device *dev) * that the state and timing are fairly predictable */ err = i915_reset_guc(dev_priv);

• if (err) {
  

• 	DRM_ERROR("GuC reset failed: %d\n", err);
  

• if (err)
  goto fail;
  

• }
  
  

  err = guc_ucode_xfer(dev_priv); if (!err)

@@ -532,15 +532,15 @@ int intel_guc_setup(struct drm_device *dev) else if (err == 0) DRM_INFO("GuC firmware load skipped\n"); else if (ret != -EIO)

• DRM_INFO("GuC firmware load failed: %d\n", err);
  

• DRM_NOTE("GuC firmware load failed: %d\n", err);
  

  else

• DRM_ERROR("GuC firmware load failed: %d\n", err);
  

• DRM_WARN("GuC firmware load failed: %d\n", err);
  
  

  if (i915.enable_guc_submission) { if (fw_path == NULL) DRM_INFO("GuC submission without firmware not supported\n"); if (ret == 0)

• 	DRM_INFO("Falling back from GuC submission to execlist mode\n");
  

• 	DRM_NOTE("Falling back from GuC submission to execlist mode\n");
  

  else DRM_ERROR("GuC init failed: %d\n", ret); }

@@ -656,7 +656,7 @@ static void guc_fw_fetch(struct drm_device *dev, struct intel_guc_fw *guc_fw) fail: DRM_DEBUG_DRIVER("GuC fw fetch status FAIL; err %d, fw %p, obj %p\n", err, fw, guc_fw->guc_fw_obj);

• DRM_ERROR("Failed to fetch GuC firmware from %s (error %d)\n",

• DRM_WARN("Failed to fetch GuC firmware from %s (error %d)\n", guc_fw->guc_fw_path, err);

  mutex_lock(&dev->struct_mutex);

R-b if you also change all the other DRM_ERRORs in guc_fw_fetch to DRM_DEBUG_DRIVER and merge this last two log lines (DRM_DEBUG_DRIVER + DRM_WARN) to one. :)

Regards,

Tvrtko

On 12/07/16 14:28, Dave Gordon wrote:

On 12/07/16 10:06, Tvrtko Ursulin wrote:

...

On 11/07/16 19:01, Dave Gordon wrote:

...

We had only DRM_INFO() and DRM_ERROR(), whereas the underlying printk() provides several other useful intermediate levels such as NOTICE and WARNING. So this patch fills out the set by providing both regular and once-only macros for each of the levels INFO, NOTICE, and WARNING, using a common underlying macro that does all the token-pasting.

DRM_ERROR is unchanged, as it's not just a printk wrapper.

Signed-off-by: Dave Gordon david.s.gordon@intel.com

include/drm/drmP.h | 26 ++++++++++++++++++++------ 1 file changed, 20 insertions(+), 6 deletions(-)

diff --git a/include/drm/drmP.h b/include/drm/drmP.h index cf918e3e..82648b1 100644 --- a/include/drm/drmP.h +++ b/include/drm/drmP.h @@ -162,6 +162,26 @@ void drm_err(const char *format, ...); /** \name Macros to make printk easier */ /*@{*/

+#define _DRM_PRINTK(once, level, fmt, ...) \

• do { \

•    printk##once(KERN_##level "[" DRM_NAME "] " fmt,    \
  

•             ##__VA_ARGS__);                \
  

• } while (0)

+#define DRM_INFO(fmt, ...) \

• _DRM_PRINTK(, INFO, fmt, ##__VA_ARGS__)

+#define DRM_NOTE(fmt, ...) \

• _DRM_PRINTK(, NOTICE, fmt, ##__VA_ARGS__)

To me DRM_NOTICE would be better to keep consistent with kernel naming for the equivalent log level.

Maybe, but then we'd probably want DRM_WARNING() as well, and the names get cumbersome, especially when you want to tag "_ONCE" on the end as well. I liked the consistency of {INFO,NOTE,WARN} all being four letters ;)

Any comments from dri-devel on INFO/NOTE/WARN vs INFO/NOTICE/WARNING? Or any other suggestions?

Luckily kernel offers us precedent to avoid the DRM_WARNING verbosity and establish the only exception where log level symbolic name does not match the printk helper name. :)

#define pr_emerg(fmt, ...) \ printk(KERN_EMERG pr_fmt(fmt), ##__VA_ARGS__) #define pr_alert(fmt, ...) \ printk(KERN_ALERT pr_fmt(fmt), ##__VA_ARGS__) #define pr_crit(fmt, ...) \ printk(KERN_CRIT pr_fmt(fmt), ##__VA_ARGS__) #define pr_err(fmt, ...) \ printk(KERN_ERR pr_fmt(fmt), ##__VA_ARGS__) #define pr_warning(fmt, ...) \ printk(KERN_WARNING pr_fmt(fmt), ##__VA_ARGS__) #define pr_warn pr_warning #define pr_notice(fmt, ...) \ printk(KERN_NOTICE pr_fmt(fmt), ##__VA_ARGS__) #define pr_info(fmt, ...) \ printk(KERN_INFO pr_fmt(fmt), ##__VA_ARGS__)

And short form is indeed more popular:

$ grep pr_warn( drivers/ -r | wc -l 1935 $ grep pr_warning( drivers/ -r | wc -l 141

Regards,

Tvrtko

On Tue, Jul 12, 2016 at 03:53:55PM +0100, Dave Gordon wrote:

On 12/07/16 15:25, Daniel Vetter wrote:

...

On Mon, Jul 11, 2016 at 07:01:27PM +0100, Dave Gordon wrote:

...

We had only DRM_INFO() and DRM_ERROR(), whereas the underlying printk() provides several other useful intermediate levels such as NOTICE and WARNING. So this patch fills out the set by providing both regular and once-only macros for each of the levels INFO, NOTICE, and WARNING, using a common underlying macro that does all the token-pasting.

DRM_ERROR is unchanged, as it's not just a printk wrapper.

Signed-off-by: Dave Gordon david.s.gordon@intel.com

I'm not sure what exactly the brave new drm debug model should look like (probably some form of pimped dynamic debug printk, to be able to be backwards compatible with the gazillion of blog posts recommending to capture dmesg with drm.debug=0xe). But extending these is probably not what we want ... -Daniel

These are not debug of any sort, these message are intended to be seen by the user (or administrator), and these macros allow us to emit the messages at the most appropriate kernel message level.

Hm ok, I guess we can extend them for that. -Daniel

.Dave.

...

...

---

include/drm/drmP.h | 26 ++++++++++++++++++++------ 1 file changed, 20 insertions(+), 6 deletions(-)

diff --git a/include/drm/drmP.h b/include/drm/drmP.h index cf918e3e..82648b1 100644 --- a/include/drm/drmP.h +++ b/include/drm/drmP.h @@ -162,6 +162,26 @@ void drm_err(const char *format, ...); /** \name Macros to make printk easier */ /*@{*/

+#define _DRM_PRINTK(once, level, fmt, ...) \

• do { \

• printk##once(KERN_##level "[" DRM_NAME "] " fmt,	\
  

• 	     ##__VA_ARGS__);				\
  

• } while (0)

+#define DRM_INFO(fmt, ...) \

• _DRM_PRINTK(, INFO, fmt, ##__VA_ARGS__)

+#define DRM_NOTE(fmt, ...) \

• _DRM_PRINTK(, NOTICE, fmt, ##__VA_ARGS__)

+#define DRM_WARN(fmt, ...) \

• _DRM_PRINTK(, WARNING, fmt, ##__VA_ARGS__)

+#define DRM_INFO_ONCE(fmt, ...) \

• _DRM_PRINTK(_once, INFO, fmt, __VA_ARGS__)

+#define DRM_NOTE_ONCE(fmt, ...) \

• _DRM_PRINTK(_once, NOTICE, fmt, ##__VA_ARGS__)

+#define DRM_WARN_ONCE(fmt, ...) \

• _DRM_PRINTK(_once, WARNING, fmt, ##__VA_ARGS__)
• /**
  • Error output.

@@ -187,12 +207,6 @@ void drm_err(const char *format, ...); drm_err(fmt, ##__VA_ARGS__); \ })

-#define DRM_INFO(fmt, ...) \

• printk(KERN_INFO "[" DRM_NAME "] " fmt, ##__VA_ARGS__)

-#define DRM_INFO_ONCE(fmt, ...) \

• printk_once(KERN_INFO "[" DRM_NAME "] " fmt, ##__VA_ARGS__)
• /**
  • Debug output.

-- 1.9.1

---

Intel-gfx mailing list Intel-gfx@lists.freedesktop.org https://lists.freedesktop.org/mailman/listinfo/intel-gfx