diff mbox

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

Message ID 1507077693-3636-1-git-send-email-anusha.srivatsa@intel.com (mailing list archive)
State New, archived
Headers show

Commit Message

Srivatsa, Anusha Oct. 4, 2017, 12:41 a.m. UTC
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@chris-wilson.co.uk>
Cc: Tvrtko ursulin <tvrtko.ursulin@intel.com>
Cc: Daniel Vetter <daniel.vetter@ffwll.ch>
Cc: Sujaritha Sundaresan <sujaritha.sundaresan@intel.com>
Cc: Oscar Mateo <oscar.mateo@intel.com>
Cc: Michal Wajdeczko <michal.wajdeczko@intel.com>
Signed-off-by: Anusha Srivatsa <anusha.srivatsa@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(-)

Comments

Tvrtko Ursulin Oct. 4, 2017, 8:16 a.m. UTC | #1
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@chris-wilson.co.uk>
> Cc: Tvrtko ursulin <tvrtko.ursulin@intel.com>
> Cc: Daniel Vetter <daniel.vetter@ffwll.ch>
> Cc: Sujaritha Sundaresan <sujaritha.sundaresan@intel.com>
> Cc: Oscar Mateo <oscar.mateo@intel.com>
> Cc: Michal Wajdeczko <michal.wajdeczko@intel.com>
> Signed-off-by: Anusha Srivatsa <anusha.srivatsa@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 {
>
Joonas Lahtinen Oct. 4, 2017, 12:51 p.m. UTC | #2
On Wed, 2017-10-04 at 09:16 +0100, Tvrtko Ursulin wrote:
> 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@chris-wilson.co.uk>
> > Cc: Tvrtko ursulin <tvrtko.ursulin@intel.com>
> > Cc: Daniel Vetter <daniel.vetter@ffwll.ch>
> > Cc: Sujaritha Sundaresan <sujaritha.sundaresan@intel.com>
> > Cc: Oscar Mateo <oscar.mateo@intel.com>
> > Cc: Michal Wajdeczko <michal.wajdeczko@intel.com>
> > Signed-off-by: Anusha Srivatsa <anusha.srivatsa@intel.com>

<SNIP>

> > @@ -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?

We decided not to expose it through debugfs, so let's try to avoid a
variable, too.

Regards, Joonas

PS. Also, lets try to get to the habit of having the S-o-b: and Cc:s in
chronological order. Less fixing for committers when applying patches.
Srivatsa, Anusha Oct. 6, 2017, 12:41 a.m. UTC | #3
>-----Original Message-----

>From: Tvrtko Ursulin [mailto:tvrtko.ursulin@linux.intel.com]

>Sent: Wednesday, October 4, 2017 1:17 AM

>To: Srivatsa, Anusha <anusha.srivatsa@intel.com>; intel-

>gfx@lists.freedesktop.org

>Cc: Sundaresan, Sujaritha <sujaritha.sundaresan@intel.com>; Daniel Vetter

><daniel.vetter@ffwll.ch>

>Subject: Re: [Intel-gfx] [PATCH 1/2] drm/i915/guc: Add GuC Load time to dmesg

>log.

>

>

>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@chris-wilson.co.uk>

>> Cc: Tvrtko ursulin <tvrtko.ursulin@intel.com>

>> Cc: Daniel Vetter <daniel.vetter@ffwll.ch>

>> Cc: Sujaritha Sundaresan <sujaritha.sundaresan@intel.com>

>> Cc: Oscar Mateo <oscar.mateo@intel.com>

>> Cc: Michal Wajdeczko <michal.wajdeczko@intel.com>

>> Signed-off-by: Anusha Srivatsa <anusha.srivatsa@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?


We can have an IGT that checks the load time and fails if its greater than the threshold.... for that it could be useful to have load time this way?

>Also, where ever it is (global or local) unsigned int is enough since you picked ms

>as the resolution.


Unsigned int is a better approach. 
Will change to unsigned int Tvrtko, thanks for suggestion.

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

>>
Srivatsa, Anusha Oct. 6, 2017, 12:56 a.m. UTC | #4
>-----Original Message-----

>From: Joonas Lahtinen [mailto:joonas.lahtinen@linux.intel.com]

>Sent: Wednesday, October 4, 2017 5:52 AM

>To: Tvrtko Ursulin <tvrtko.ursulin@linux.intel.com>; Srivatsa, Anusha

><anusha.srivatsa@intel.com>; intel-gfx@lists.freedesktop.org

>Cc: Daniel Vetter <daniel.vetter@ffwll.ch>; Sundaresan, Sujaritha

><sujaritha.sundaresan@intel.com>

>Subject: Re: [Intel-gfx] [PATCH 1/2] drm/i915/guc: Add GuC Load time to dmesg

>log.

>

>On Wed, 2017-10-04 at 09:16 +0100, Tvrtko Ursulin wrote:

>> 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@chris-wilson.co.uk>

>> > Cc: Tvrtko ursulin <tvrtko.ursulin@intel.com>

>> > Cc: Daniel Vetter <daniel.vetter@ffwll.ch>

>> > Cc: Sujaritha Sundaresan <sujaritha.sundaresan@intel.com>

>> > Cc: Oscar Mateo <oscar.mateo@intel.com>

>> > Cc: Michal Wajdeczko <michal.wajdeczko@intel.com>

>> > Signed-off-by: Anusha Srivatsa <anusha.srivatsa@intel.com>

>

><SNIP>

>

>> > @@ -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?

>

>We decided not to expose it through , so let's try to avoid a variable, too.

 Hi Joonas,

The order of prints will then be:
GuC firmware status: fetch SUCCESS load PENDING
GuC loaded in x ms
GuC loaded/submission enabled  firmware <path_to_firmware>_major.minor.bin version major.minor

Compared to

GuC firmware status: fetch SUCCESS load PENDING
GuC loaded/submission enabled  firmware <path_to_firmware>_platform_major.minor.bin version major.minor
GuC loaded in x ms

I felt the second one looked a better sequence, but I will change if that’s the majority.

Thanks,
Anusha
>Regards, Joonas

>

>PS. Also, lets try to get to the habit of having the S-o-b: and Cc:s in chronological

>order. Less fixing for committers when applying patches.


Will keep in mind, thanks

Anusha
>Joonas Lahtinen

>Open Source Technology Center

>Intel Corporation
Joonas Lahtinen Oct. 6, 2017, 6:29 a.m. UTC | #5
On Fri, 2017-10-06 at 00:56 +0000, Srivatsa, Anusha wrote:
> > -----Original Message-----
> > From: Joonas Lahtinen [mailto:joonas.lahtinen@linux.intel.com]
> > Sent: Wednesday, October 4, 2017 5:52 AM
> > To: Tvrtko Ursulin <tvrtko.ursulin@linux.intel.com>; Srivatsa, Anusha
> > <anusha.srivatsa@intel.com>; intel-gfx@lists.freedesktop.org
> > Cc: Daniel Vetter <daniel.vetter@ffwll.ch>; Sundaresan, Sujaritha
> > <sujaritha.sundaresan@intel.com>
> > Subject: Re: [Intel-gfx] [PATCH 1/2] drm/i915/guc: Add GuC Load time to dmesg
> > log.
> > 
> > On Wed, 2017-10-04 at 09:16 +0100, Tvrtko Ursulin wrote:
> > > 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@chris-wilson.co.uk>
> > > > Cc: Tvrtko ursulin <tvrtko.ursulin@intel.com>
> > > > Cc: Daniel Vetter <daniel.vetter@ffwll.ch>
> > > > Cc: Sujaritha Sundaresan <sujaritha.sundaresan@intel.com>
> > > > Cc: Oscar Mateo <oscar.mateo@intel.com>
> > > > Cc: Michal Wajdeczko <michal.wajdeczko@intel.com>
> > > > Signed-off-by: Anusha Srivatsa <anusha.srivatsa@intel.com>
> > 
> > <SNIP>
> > 
> > > > @@ -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?
> > 
> > We decided not to expose it through , so let's try to avoid a variable, too.
> 
>  Hi Joonas,
> 
> The order of prints will then be:
> GuC firmware status: fetch SUCCESS load PENDING
> GuC loaded in x ms
> GuC loaded/submission enabled  firmware <path_to_firmware>_major.minor.bin version major.minor

But is not this the more logical one, too? Say we would enable the
asynchronous loading of GuC firmware, and we could simultaneously
fallback to ELSP and start using the system. So there could be
considerable time between GuC being loaded and GuC submission being
enabled. So I might tie the firmware path information to the GuC loaded
message.

Also, if we have printk timestamping available, would not the
information be readable from there, just calculate delta between
firmware status changing from PENDING to LOADED? It won't hurt to
explicitly compute it for the user, of course.

Regards, Joonas

> 
> Compared to
> 
> GuC firmware status: fetch SUCCESS load PENDING
> GuC loaded/submission enabled  firmware <path_to_firmware>_platform_major.minor.bin version major.minor
> GuC loaded in x ms
> 
> I felt the second one looked a better sequence, but I will change if that’s the majority.
> 
> Thanks,
> Anusha
> > Regards, Joonas
> > 
> > PS. Also, lets try to get to the habit of having the S-o-b: and Cc:s in chronological
> > order. Less fixing for committers when applying patches.
> 
> Will keep in mind, thanks
> 
> Anusha
> > Joonas Lahtinen
> > Open Source Technology Center
> > Intel Corporation
Srivatsa, Anusha Oct. 9, 2017, 5:24 p.m. UTC | #6
>-----Original Message-----

>From: Joonas Lahtinen [mailto:joonas.lahtinen@linux.intel.com]

>Sent: Thursday, October 5, 2017 11:30 PM

>To: Srivatsa, Anusha <anusha.srivatsa@intel.com>; Tvrtko Ursulin

><tvrtko.ursulin@linux.intel.com>; intel-gfx@lists.freedesktop.org

>Cc: Daniel Vetter <daniel.vetter@ffwll.ch>; Sundaresan, Sujaritha

><sujaritha.sundaresan@intel.com>

>Subject: Re: [Intel-gfx] [PATCH 1/2] drm/i915/guc: Add GuC Load time to dmesg

>log.

>

>On Fri, 2017-10-06 at 00:56 +0000, Srivatsa, Anusha wrote:

>> > -----Original Message-----

>> > From: Joonas Lahtinen [mailto:joonas.lahtinen@linux.intel.com]

>> > Sent: Wednesday, October 4, 2017 5:52 AM

>> > To: Tvrtko Ursulin <tvrtko.ursulin@linux.intel.com>; Srivatsa,

>> > Anusha <anusha.srivatsa@intel.com>; intel-gfx@lists.freedesktop.org

>> > Cc: Daniel Vetter <daniel.vetter@ffwll.ch>; Sundaresan, Sujaritha

>> > <sujaritha.sundaresan@intel.com>

>> > Subject: Re: [Intel-gfx] [PATCH 1/2] drm/i915/guc: Add GuC Load time

>> > to dmesg log.

>> >

>> > On Wed, 2017-10-04 at 09:16 +0100, Tvrtko Ursulin wrote:

>> > > 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@chris-wilson.co.uk>

>> > > > Cc: Tvrtko ursulin <tvrtko.ursulin@intel.com>

>> > > > Cc: Daniel Vetter <daniel.vetter@ffwll.ch>

>> > > > Cc: Sujaritha Sundaresan <sujaritha.sundaresan@intel.com>

>> > > > Cc: Oscar Mateo <oscar.mateo@intel.com>

>> > > > Cc: Michal Wajdeczko <michal.wajdeczko@intel.com>

>> > > > Signed-off-by: Anusha Srivatsa <anusha.srivatsa@intel.com>

>> >

>> > <SNIP>

>> >

>> > > > @@ -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?

>> >

>> > We decided not to expose it through , so let's try to avoid a variable, too.

>>

>>  Hi Joonas,

>>

>> The order of prints will then be:

>> GuC firmware status: fetch SUCCESS load PENDING GuC loaded in x ms GuC

>> loaded/submission enabled  firmware <path_to_firmware>_major.minor.bin

>> version major.minor

>

>But is not this the more logical one, too? Say we would enable the asynchronous

>loading of GuC firmware, and we could simultaneously fallback to ELSP and start

>using the system. So there could be considerable time between GuC being loaded

>and GuC submission being enabled. So I might tie the firmware path information

>to the GuC loaded message.

>

>Also, if we have printk timestamping available, would not the information be

>readable from there, just calculate delta between firmware status changing from

>PENDING to LOADED? It won't hurt to explicitly compute it for the user, of

>course.



Agreed. Will remove the variable altogether.

Thanks a lot Joonas.
Anusha

>Regards, Joonas

>

>>

>> Compared to

>>

>> GuC firmware status: fetch SUCCESS load PENDING GuC loaded/submission

>> enabled  firmware <path_to_firmware>_platform_major.minor.bin version

>> major.minor GuC loaded in x ms

>>

>> I felt the second one looked a better sequence, but I will change if that’s the

>majority.

>>

>> Thanks,

>> Anusha

>> > Regards, Joonas

>> >

>> > PS. Also, lets try to get to the habit of having the S-o-b: and Cc:s

>> > in chronological order. Less fixing for committers when applying patches.

>>

>> Will keep in mind, thanks

>>

>> Anusha

>> > Joonas Lahtinen

>> > Open Source Technology Center

>> > Intel Corporation

>--

>Joonas Lahtinen

>Open Source Technology Center

>Intel Corporation
diff mbox

Patch

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);
+
 	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 {