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

[Srivatsa, Anusha]

>-----Original Message-----
>From: Wajdeczko, Michal
>Sent: Friday, August 25, 2017 5:35 AM
>To: Srivatsa, Anusha <anusha.srivatsa at intel.com>
>Cc: intel-gfx at lists.freedesktop.org; Mateo Lozano, Oscar
><oscar.mateo at intel.com>
>Subject: Re: [PATCH] drm/i915/guc: Add GuC Load time to debugfs
>
>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 ?

Hmmm... I thought by this time in the code the load will be over and hence we read the stautus registers. 
 Yes adding as a dmesg too, will be helpful.

Anusha
>
>>  	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.

Adding to intel_uc_fw makes sense. But  I wonder if we need a usecase to know the huc load time.... nothing wrong to add though.
Thanks for your inputs!

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