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

[Tvrtko Ursulin]

On 04/10/2017 01:41, Anusha Srivatsa wrote:
> Calculate the time that GuC takes to load using
> jiffies. This information could be very useful in
> 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)
> 
> Cc: Chris Wilson <chris at chris-wilson.co.uk>
> Cc: Tvrtko ursulin <tvrtko.ursulin at intel.com>
> Cc: Daniel Vetter <daniel.vetter at ffwll.ch>
> Cc: Sujaritha Sundaresan <sujaritha.sundaresan at intel.com>
> 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/intel_guc_loader.c | 10 +++++++++-
>   drivers/gpu/drm/i915/intel_uc.h         |  1 +
>   2 files changed, 10 insertions(+), 1 deletion(-)
> 
> diff --git a/drivers/gpu/drm/i915/intel_guc_loader.c b/drivers/gpu/drm/i915/intel_guc_loader.c
> index c9e25be..a0b562c 100644
> --- a/drivers/gpu/drm/i915/intel_guc_loader.c
> +++ b/drivers/gpu/drm/i915/intel_guc_loader.c
> @@ -199,6 +199,7 @@ static int guc_ucode_xfer_dma(struct drm_i915_private *dev_priv,
>   	struct sg_table *sg = vma->pages;
>   	u32 status, rsa[UOS_RSA_SCRATCH_MAX_COUNT];
>   	int i, ret = 0;
> +	ktime_t start_load;
>   
>   	/* where RSA signature starts */
>   	offset = guc_fw->rsa_offset;
> @@ -225,6 +226,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();
>   	I915_WRITE(DMA_CTRL, _MASKED_BIT_ENABLE(UOS_MOVE | START_DMA));
>   
>   	/*
> @@ -237,13 +239,17 @@ static int guc_ucode_xfer_dma(struct drm_i915_private *dev_priv,
>   	 */
>   	ret = wait_for(guc_ucode_response(dev_priv, &status), 100);
>   
> +	guc_fw->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 (guc_fw->load_time > 20)
> +		DRM_NOTE("Time taken to load GuC is more than the acceptable \
> +			 threshold\n");
>   
>   	DRM_DEBUG_DRIVER("returning %d\n", ret);
>   
> @@ -373,6 +379,8 @@ int intel_guc_init_hw(struct intel_guc *guc)
>   		 guc->fw.path,
>   		 guc->fw.major_ver_found, guc->fw.minor_ver_found);
>   
> +	DRM_DEBUG_DRIVER("GuC is loaded in: %lld ms\n",guc->fw.load_time);
> +

If you move this debug to where the DRM_NOTE is you don't have to store 
the load time in the global structure. Unless there will be a reason in 
the future to have the value stored?

Also, where ever it is (global or local) unsigned int is enough since 
you picked ms as the resolution.

Regards,

Tvrtko

>   	return 0;
>   }
>   
> diff --git a/drivers/gpu/drm/i915/intel_uc.h b/drivers/gpu/drm/i915/intel_uc.h
> index 6966349..65b9674 100644
> --- a/drivers/gpu/drm/i915/intel_uc.h
> +++ b/drivers/gpu/drm/i915/intel_uc.h
> @@ -136,6 +136,7 @@ struct intel_uc_fw {
>   	uint32_t rsa_offset;
>   	uint32_t ucode_size;
>   	uint32_t ucode_offset;
> +	unsigned long long load_time;
>   };
>   
>   struct intel_guc_log {
>