[Intel-gfx] [PATCH 1/2] drm/i915/guc: Add GuC Load time to dmesg log.

[Michal Wajdeczko]

On Wed, 01 Nov 2017 01:11:20 +0100, Anusha Srivatsa  
<anusha.srivatsa at intel.com> wrote:

> Calculate the time that GuC takes to load using
> jiffies. This information could be very useful in
   ^^^^^^^
This is no longer true.

> determining if GuC is taking unreasonably long time
> to load in a certain platforms.
>
> v2: Calculate time before logs are collected.
> Move the guc_load_time variable as a part of
> intel_uc_fw struct. Store only final result
> which is to be exported to debugfs. (Michal)
> Add the load time in the print message as well.
>
> v3: Remove debugfs entry. Remove local variable
> guc_finish_load. (Daniel, Tvrtko)
>
> v4: Use ktime_get() instead of jiffies. Use DRM_NOTE
> if time taken to load is more than the threshold. On
> load times within acceptable range, use DRM_DEBUG_DRIVER
> (Tvrtko)
>
> v5: Rebased. Do not expose the load time variable in a global
> struct (Tvrtko, Joonas)
>
> Cc: Chris Wilson <chris at chris-wilson.co.uk>
> Cc: Daniel Vetter <daniel.vetter at ffwll.ch>
> Cc: Michal Wajdeczko <michal.wajdeczko at intel.com>
> Cc: Oscar Mateo <oscar.mateo at intel.com>
> Cc: Sujaritha Sundaresan <sujaritha.sundaresan at intel.com>
> Cc: Tvrtko Ursulin <tvrtko.ursulin at intel.com>
> Signed-off-by: Anusha Srivatsa <anusha.srivatsa at intel.com>
> ---
>  drivers/gpu/drm/i915/intel_guc_fw.c | 11 +++++++++--
>  1 file changed, 9 insertions(+), 2 deletions(-)
>
> diff --git a/drivers/gpu/drm/i915/intel_guc_fw.c  
> b/drivers/gpu/drm/i915/intel_guc_fw.c
> index ef67a36..4ce9a30 100644
> --- a/drivers/gpu/drm/i915/intel_guc_fw.c
> +++ b/drivers/gpu/drm/i915/intel_guc_fw.c
> @@ -133,7 +133,8 @@ static int guc_ucode_xfer_dma(struct  
> drm_i915_private *dev_priv,
>  	unsigned long offset;
>  	struct sg_table *sg = vma->pages;
>  	u32 status, rsa[UOS_RSA_SCRATCH_MAX_COUNT];
> -	int i, ret = 0;
> +	int i, ret = 0, load_time;

Note that ktime_ms_delta() return type is s64 not int.

> +	ktime_t start_load;

s/start_load/now ?

> 	/* where RSA signature starts */
>  	offset = guc_fw->rsa_offset;
> @@ -160,6 +161,7 @@ static int guc_ucode_xfer_dma(struct  
> drm_i915_private *dev_priv,
>  	I915_WRITE(DMA_ADDR_1_HIGH, DMA_ADDRESS_SPACE_WOPCM);
> 	/* Finally start the DMA */
> +	start_load = ktime_get();

Maybe we should either update comment with note about taking start time
or move ktime_get call before that comment to avoid confusion..

>  	I915_WRITE(DMA_CTRL, _MASKED_BIT_ENABLE(UOS_MOVE | START_DMA));
> 	/*
> @@ -172,13 +174,18 @@ static int guc_ucode_xfer_dma(struct  
> drm_i915_private *dev_priv,
>  	 */
>  	ret = wait_for(guc_ucode_response(dev_priv, &status), 100);
> +	load_time = ktime_ms_delta(ktime_get(), start_load);
> +
>  	DRM_DEBUG_DRIVER("DMA status 0x%x, GuC status 0x%x\n",
>  			I915_READ(DMA_CTRL), status);
> 	if ((status & GS_BOOTROM_MASK) == GS_BOOTROM_RSA_FAILED) {
>  		DRM_ERROR("GuC firmware signature verification failed\n");
>  		ret = -ENOEXEC;
> -	}
> +	} else if (load_time > 20)
> +		DRM_NOTE("GuC load takes more than acceptable threshold\n");

Please add threshold and actual load time to the message to let user
know that times

> +	else
> +		DRM_DEBUG_DRIVER("GuC loaded in %d ms\n", load_time);

And I'm not sure that we can rely on 'load_time' on timeout in wait_for.

> 	DRM_DEBUG_DRIVER("returning %d\n", ret);