Re: [PATCH 1/2] drm/i915/guc: Add GuC Load time to debugfs

Tvrtko Ursulin <tvrtko.ursulin@xxxxxxxxxxxxxxx> · Mon, 11 Sep 2017 16:53:17 +0100

On 07/09/2017 18:07, Srivatsa, Anusha wrote:
-----Original Message-----
From: Tvrtko Ursulin [mailto:tvrtko.ursulin@xxxxxxxxxxxxxxx]
Sent: Thursday, September 7, 2017 1:49 AM
To: Srivatsa, Anusha <anusha.srivatsa@xxxxxxxxx>; intel-
gfx@xxxxxxxxxxxxxxxxxxxxx
Cc: Sundaresan, Sujaritha <sujaritha.sundaresan@xxxxxxxxx>
Subject: Re:  [PATCH 1/2] drm/i915/guc: Add GuC Load time to debugfs


On 07/09/2017 01:37, 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.

Do we need this in debugfs or a DRM_NOTE or something would be sufficient if
the load time is above certain threshold?

The intention was to have debug related info in a debugfs. DRM_NOTE will also be useful, we can do both. The load time can be as an entry in debugfs and if it's beyond a threshold - 20ms I assume, we can have a DRM_NOTE.
Does that sound good?

I'd rather avoid adding code (for debugfs) if the only purpose is to 
detect when the load takes too long. But maybe there is a different 
reason to have it, which I am not aware off so I don't know.

Also, what are the typical times here? Are jiffies precise enough? Could be only
10ms granularity on some kernels.

Usually guc load times are around 8ms to 10ms....
That’s a very good point. I thought jiffies are a good approach for this purpose, but if there is a better or more accurate way, I will be happy to go that direction.

ktime_get(_ns) I think.

Regards,

Tvrtko

Depending on the above, more or less applicable comments below:

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.

Cc: Sujaritha Sundaresan <sujaritha.sundaresan@xxxxxxxxx>
Cc: Oscar Mateo <oscar.mateo@xxxxxxxxx>
Cc: Michal Wajdeczko <michal.wajdeczko@xxxxxxxxx>
Signed-off-by: Anusha Srivatsa <anusha.srivatsa@xxxxxxxxx>
---
   drivers/gpu/drm/i915/i915_debugfs.c     | 3 +++
   drivers/gpu/drm/i915/intel_guc_loader.c | 8 ++++++++
   drivers/gpu/drm/i915/intel_uc.h         | 1 +
   3 files changed, 12 insertions(+)

diff --git a/drivers/gpu/drm/i915/i915_debugfs.c
b/drivers/gpu/drm/i915/i915_debugfs.c
index 48572b157222..e0b99dbc6608 100644
--- a/drivers/gpu/drm/i915/i915_debugfs.c
+++ b/drivers/gpu/drm/i915/i915_debugfs.c
@@ -2379,6 +2379,9 @@ 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, "\tGuC Load time is %lu ms\n",
+		   jiffies_to_msecs(guc_fw->guc_load_time));

OCD: "GuC load time: %lums" to make it more consistent with the other entries
here?

+
   	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..da917f84c471 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;
+	unsigned long guc_start_load, guc_finish_load;

   	/* where RSA signature starts */
   	offset = guc_fw->rsa_offset;
@@ -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_start_load = jiffies;

   	/*
   	 * Wait for the DMA to complete & the GuC to start up.
@@ -237,6 +239,9 @@ static int guc_ucode_xfer_dma(struct drm_i915_private
*dev_priv,
   	 */
   	ret = wait_for(guc_ucode_response(dev_priv, &status), 100);

+	guc_finish_load = jiffies;
+	guc_fw->guc_load_time = guc_finish_load - guc_start_load;

Strictly speaking you don't need the guc_finish_load local.

+
   	DRM_DEBUG_DRIVER("DMA status 0x%x, GuC status 0x%x\n",
   			I915_READ(DMA_CTRL), status);

@@ -372,6 +377,9 @@ 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("Time taken to load GuC is %lu\n",
+			 guc->fw.guc_load_time);
+
   	return 0;
   }

diff --git a/drivers/gpu/drm/i915/intel_uc.h
b/drivers/gpu/drm/i915/intel_uc.h index 22ae52b17b0f..52aa05d13863
100644
--- a/drivers/gpu/drm/i915/intel_uc.h
+++ b/drivers/gpu/drm/i915/intel_uc.h
@@ -154,6 +154,7 @@ struct intel_uc_fw {
   	uint32_t rsa_offset;
   	uint32_t ucode_size;
   	uint32_t ucode_offset;
+	unsigned long guc_load_time;

Looks wrong to add guc_ (and later huc_) prefixed members in the common
struct since both intel_guc and intel_huc encapsulate it. If you just had a single
field and called it load_time, wouldn't you get separate copies for guc and huc
automatically?

That’s a good point.
Neater approach too. Thanks Tvrtko!

Anusha
Regards,

Tvrtko

   };

   struct intel_guc_log {

_______________________________________________
Intel-gfx mailing list
Intel-gfx@xxxxxxxxxxxxxxxxxxxxx
https://lists.freedesktop.org/mailman/listinfo/intel-gfx







