[Intel-gfx] [PATCH] drm/i915/guc: Add GuC Load time to debugfs

[Michal Wajdeczko]

On Thu, Aug 24, 2017 at 09:38:06PM -0700, Anusha Srivatsa wrote:
> Calculate the time that GuC takes to load.
> This information could be very useful in
> determining if GuC is taking unreasonably long time
> to load in a certain platforms.
> 
> Cc: Oscar Mateo <oscar.mateo at intel.com>
> Cc: Michal Wajdeczko <michal.wajdeczko at intel.com>
> Signed-off-by: Anusha Srivatsa <anusha.srivatsa at intel.com>
> ---
>  drivers/gpu/drm/i915/i915_debugfs.c     | 4 ++++
>  drivers/gpu/drm/i915/intel_guc_loader.c | 4 ++++
>  drivers/gpu/drm/i915/intel_uc.h         | 3 +++
>  3 files changed, 11 insertions(+)
> 
> diff --git a/drivers/gpu/drm/i915/i915_debugfs.c b/drivers/gpu/drm/i915/i915_debugfs.c
> index 48572b157222..9283fc714705 100644
> --- a/drivers/gpu/drm/i915/i915_debugfs.c
> +++ b/drivers/gpu/drm/i915/i915_debugfs.c
> @@ -2379,6 +2379,10 @@ static int i915_guc_load_status_info(struct seq_file *m, void *data)
>  		guc_fw->major_ver_wanted, guc_fw->minor_ver_wanted);
>  	seq_printf(m, "\tversion found: %d.%d\n",
>  		guc_fw->major_ver_found, guc_fw->minor_ver_found);
> +	seq_printf(m, "\tLoad time is %lu ms\n",
> +		   jiffies_to_msecs(dev_priv->guc.guc_finish_load -
> +		   dev_priv->guc.guc_start_load));
> +
>  	seq_printf(m, "\theader: offset is %d; size = %d\n",
>  		guc_fw->header_offset, guc_fw->header_size);
>  	seq_printf(m, "\tuCode: offset is %d; size = %d\n",
> diff --git a/drivers/gpu/drm/i915/intel_guc_loader.c b/drivers/gpu/drm/i915/intel_guc_loader.c
> index 8b0ae7fce7f2..1c5059b930f9 100644
> --- a/drivers/gpu/drm/i915/intel_guc_loader.c
> +++ b/drivers/gpu/drm/i915/intel_guc_loader.c
> @@ -194,6 +194,7 @@ static inline bool guc_ucode_response(struct drm_i915_private *dev_priv,
>  static int guc_ucode_xfer_dma(struct drm_i915_private *dev_priv,
>  			      struct i915_vma *vma)
>  {
> +	struct intel_guc *guc = &dev_priv->guc;
>  	struct intel_uc_fw *guc_fw = &dev_priv->guc.fw;
>  	unsigned long offset;
>  	struct sg_table *sg = vma->pages;
> @@ -226,6 +227,7 @@ static int guc_ucode_xfer_dma(struct drm_i915_private *dev_priv,
>  
>  	/* Finally start the DMA */
>  	I915_WRITE(DMA_CTRL, _MASKED_BIT_ENABLE(UOS_MOVE | START_DMA));
> +	guc->guc_start_load = jiffies;
>  
>  	/*
>  	 * Wait for the DMA to complete & the GuC to start up.
> @@ -240,6 +242,8 @@ static int guc_ucode_xfer_dma(struct drm_i915_private *dev_priv,
>  	DRM_DEBUG_DRIVER("DMA status 0x%x, GuC status 0x%x\n",
>  			I915_READ(DMA_CTRL), status);
>  
> +	guc->guc_finish_load = jiffies;
> +

On error/timeout we don't know if loading was finished/completed and your
calculations will be wrong. End time shall be captured before any debug logs
to more accurate. Btw, if loading time is so important, maybe it should be
also printed here as part of above DRM_DEBUG ?

>  	if ((status & GS_BOOTROM_MASK) == GS_BOOTROM_RSA_FAILED) {
>  		DRM_ERROR("GuC firmware signature verification failed\n");
>  		ret = -ENOEXEC;
> diff --git a/drivers/gpu/drm/i915/intel_uc.h b/drivers/gpu/drm/i915/intel_uc.h
> index 22ae52b17b0f..3d5a15ed1995 100644
> --- a/drivers/gpu/drm/i915/intel_uc.h
> +++ b/drivers/gpu/drm/i915/intel_uc.h
> @@ -210,6 +210,9 @@ struct intel_guc {
>  
>  	/* GuC's FW specific notify function */
>  	void (*notify)(struct intel_guc *guc);
> +
> +	unsigned long guc_start_load;
> +	unsigned long guc_finish_load;

No need to keep both jiffies here. Calculate "load_time_in_ms" in the
loader function and store only final result. Maybe better place for
this result would be "intel_uc_fw" ? Then we can do the same for Huc.

-Michal

>  };
>  
>  struct intel_huc {
> -- 
> 2.11.0
>