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

[Joonas Lahtinen]

On Fri, 2017-10-06 at 00:56 +0000, Srivatsa, Anusha wrote:
> > -----Original Message-----
> > From: Joonas Lahtinen [mailto:joonas.lahtinen at linux.intel.com]
> > Sent: Wednesday, October 4, 2017 5:52 AM
> > To: Tvrtko Ursulin <tvrtko.ursulin at linux.intel.com>; Srivatsa, Anusha
> > <anusha.srivatsa at intel.com>; intel-gfx at lists.freedesktop.org
> > Cc: Daniel Vetter <daniel.vetter at ffwll.ch>; Sundaresan, Sujaritha
> > <sujaritha.sundaresan at 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 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>
> > 
> > <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
-- 
Joonas Lahtinen
Open Source Technology Center
Intel Corporation