[PATCH 0/2] Improvements to GuC load failure handling

[PATCH 0/2] Improvements to GuC load failure handling

[John.C.Harrison]

From: John Harrison <John.C.Harrison@Intel.com>

Add more decoding of the GuC load failures. Also include information
about GT frequency to see if timeouts are due to a failure to boost
the clocks. Finally, increase the timeout to accommodate situations
where the clock boost does fail.

Signed-off-by: John Harrison <John.C.Harrison@Intel.com>


John Harrison (2):
  drm/i915/guc: Improve GuC load error reporting
  drm/i915/guc: Allow for very slow GuC loading

 .../gpu/drm/i915/gt/uc/abi/guc_errors_abi.h   |  17 +++
 drivers/gpu/drm/i915/gt/uc/intel_guc_fw.c     | 128 +++++++++++++++---
 drivers/gpu/drm/i915/gt/uc/intel_guc_reg.h    |   4 +-
 3 files changed, 127 insertions(+), 22 deletions(-)

-- 
2.39.1

[PATCH 1/2] drm/i915/guc: Improve GuC load error reporting

[John.C.Harrison]

From: John Harrison <John.C.Harrison@Intel.com>

There are multiple ways in which the GuC load can fail. The driver was
reporting the status register as is, but not everyone can read the
matrix unfiltered. So add decoding of the common error cases.

Also, remove the comment about interrupt based load completion
checking being not recommended. The interrupt was removed from the GuC
firmware some time ago so it is no longer an option anyway. While at
it, also abort the timeout if a known error code is reported. No need
to keep waiting if the GuC has already given up the load.

Signed-off-by: John Harrison <John.C.Harrison@Intel.com>
---
 .../gpu/drm/i915/gt/uc/abi/guc_errors_abi.h   | 17 ++++
 drivers/gpu/drm/i915/gt/uc/intel_guc_fw.c     | 95 +++++++++++++++----
 drivers/gpu/drm/i915/gt/uc/intel_guc_reg.h    |  4 +-
 3 files changed, 95 insertions(+), 21 deletions(-)

diff --git a/drivers/gpu/drm/i915/gt/uc/abi/guc_errors_abi.h b/drivers/gpu/drm/i915/gt/uc/abi/guc_errors_abi.h
index 8085fb1812748..750fe0c6d8529 100644
--- a/drivers/gpu/drm/i915/gt/uc/abi/guc_errors_abi.h
+++ b/drivers/gpu/drm/i915/gt/uc/abi/guc_errors_abi.h
@@ -21,6 +21,9 @@ enum intel_guc_load_status {
 	INTEL_GUC_LOAD_STATUS_ERROR_DEVID_BUILD_MISMATCH       = 0x02,
 	INTEL_GUC_LOAD_STATUS_GUC_PREPROD_BUILD_MISMATCH       = 0x03,
 	INTEL_GUC_LOAD_STATUS_ERROR_DEVID_INVALID_GUCTYPE      = 0x04,
+	INTEL_GUC_LOAD_STATUS_HWCONFIG_START                   = 0x05,
+	INTEL_GUC_LOAD_STATUS_HWCONFIG_DONE                    = 0x06,
+	INTEL_GUC_LOAD_STATUS_HWCONFIG_ERROR                   = 0x07,
 	INTEL_GUC_LOAD_STATUS_GDT_DONE                         = 0x10,
 	INTEL_GUC_LOAD_STATUS_IDT_DONE                         = 0x20,
 	INTEL_GUC_LOAD_STATUS_LAPIC_DONE                       = 0x30,
@@ -38,4 +41,18 @@ enum intel_guc_load_status {
 	INTEL_GUC_LOAD_STATUS_READY                            = 0xF0,
 };
 
+enum intel_bootrom_load_status {
+	INTEL_BOOTROM_STATUS_NO_KEY_FOUND                 = 0x13,
+	INTEL_BOOTROM_STATUS_AES_PROD_KEY_FOUND           = 0x1A,
+	INTEL_BOOTROM_STATUS_RSA_FAILED                   = 0x50,
+	INTEL_BOOTROM_STATUS_PAVPC_FAILED                 = 0x73,
+	INTEL_BOOTROM_STATUS_WOPCM_FAILED                 = 0x74,
+	INTEL_BOOTROM_STATUS_LOADLOC_FAILED               = 0x75,
+	INTEL_BOOTROM_STATUS_JUMP_PASSED                  = 0x76,
+	INTEL_BOOTROM_STATUS_JUMP_FAILED                  = 0x77,
+	INTEL_BOOTROM_STATUS_RC6CTXCONFIG_FAILED          = 0x79,
+	INTEL_BOOTROM_STATUS_MPUMAP_INCORRECT             = 0x7a,
+	INTEL_BOOTROM_STATUS_EXCEPTION                    = 0x7E,
+};
+
 #endif /* _ABI_GUC_ERRORS_ABI_H */
diff --git a/drivers/gpu/drm/i915/gt/uc/intel_guc_fw.c b/drivers/gpu/drm/i915/gt/uc/intel_guc_fw.c
index 69133420c78b2..2f5942606913d 100644
--- a/drivers/gpu/drm/i915/gt/uc/intel_guc_fw.c
+++ b/drivers/gpu/drm/i915/gt/uc/intel_guc_fw.c
@@ -88,31 +88,64 @@ static int guc_xfer_rsa(struct intel_uc_fw *guc_fw,
 /*
  * Read the GuC status register (GUC_STATUS) and store it in the
  * specified location; then return a boolean indicating whether
- * the value matches either of two values representing completion
- * of the GuC boot process.
+ * the value matches either completion or a known failure code.
  *
  * This is used for polling the GuC status in a wait_for()
  * loop below.
  */
-static inline bool guc_ready(struct intel_uncore *uncore, u32 *status)
+static inline bool guc_load_done(struct intel_uncore *uncore, u32 *status, bool *success)
 {
 	u32 val = intel_uncore_read(uncore, GUC_STATUS);
 	u32 uk_val = REG_FIELD_GET(GS_UKERNEL_MASK, val);
+	u32 br_val = REG_FIELD_GET(GS_BOOTROM_MASK, val);
 
 	*status = val;
-	return uk_val == INTEL_GUC_LOAD_STATUS_READY;
+	*success = true;
+	switch (uk_val) {
+	case INTEL_GUC_LOAD_STATUS_READY:
+		return true;
+
+	case INTEL_GUC_LOAD_STATUS_ERROR_DEVID_BUILD_MISMATCH:
+	case INTEL_GUC_LOAD_STATUS_GUC_PREPROD_BUILD_MISMATCH:
+	case INTEL_GUC_LOAD_STATUS_ERROR_DEVID_INVALID_GUCTYPE:
+	case INTEL_GUC_LOAD_STATUS_HWCONFIG_ERROR:
+	case INTEL_GUC_LOAD_STATUS_DPC_ERROR:
+	case INTEL_GUC_LOAD_STATUS_EXCEPTION:
+	case INTEL_GUC_LOAD_STATUS_INIT_DATA_INVALID:
+	case INTEL_GUC_LOAD_STATUS_MPU_DATA_INVALID:
+	case INTEL_GUC_LOAD_STATUS_INIT_MMIO_SAVE_RESTORE_INVALID:
+		*success = false;
+		return true;
+	}
+
+	switch (br_val) {
+	case INTEL_BOOTROM_STATUS_NO_KEY_FOUND:
+	case INTEL_BOOTROM_STATUS_RSA_FAILED:
+	case INTEL_BOOTROM_STATUS_PAVPC_FAILED:
+	case INTEL_BOOTROM_STATUS_WOPCM_FAILED:
+	case INTEL_BOOTROM_STATUS_LOADLOC_FAILED:
+	case INTEL_BOOTROM_STATUS_JUMP_FAILED:
+	case INTEL_BOOTROM_STATUS_RC6CTXCONFIG_FAILED:
+	case INTEL_BOOTROM_STATUS_MPUMAP_INCORRECT:
+	case INTEL_BOOTROM_STATUS_EXCEPTION:
+		*success = false;
+		return true;
+	}
+
+	return false;
 }
 
 static int guc_wait_ucode(struct intel_guc *guc)
 {
 	struct intel_gt *gt = guc_to_gt(guc);
 	struct intel_uncore *uncore = gt->uncore;
+	bool success;
 	u32 status;
 	int ret;
 
 	/*
 	 * Wait for the GuC to start up.
-	 * NB: Docs recommend not using the interrupt for completion.
+	 *
 	 * Measurements indicate this should take no more than 20ms
 	 * (assuming the GT clock is at maximum frequency). So, a
 	 * timeout here indicates that the GuC has failed and is unusable.
@@ -127,28 +160,52 @@ static int guc_wait_ucode(struct intel_guc *guc)
 	 * 200ms. Even at slowest clock, this should be sufficient. And
 	 * in the working case, a larger timeout makes no difference.
 	 */
-	ret = wait_for(guc_ready(uncore, &status), 200);
-	if (ret) {
-		guc_info(guc, "load failed: status = 0x%08X\n", status);
-		guc_info(guc, "load failed: status: Reset = %d, "
-			"BootROM = 0x%02X, UKernel = 0x%02X, "
-			"MIA = 0x%02X, Auth = 0x%02X\n",
-			REG_FIELD_GET(GS_MIA_IN_RESET, status),
-			REG_FIELD_GET(GS_BOOTROM_MASK, status),
-			REG_FIELD_GET(GS_UKERNEL_MASK, status),
-			REG_FIELD_GET(GS_MIA_MASK, status),
-			REG_FIELD_GET(GS_AUTH_STATUS_MASK, status));
-
-		if ((status & GS_BOOTROM_MASK) == GS_BOOTROM_RSA_FAILED) {
+	ret = wait_for(guc_load_done(uncore, &status, &success), 200);
+	if (ret || !success) {
+		u32 ukernel = REG_FIELD_GET(GS_UKERNEL_MASK, status);
+		u32 bootrom = REG_FIELD_GET(GS_BOOTROM_MASK, status);
+
+		guc_info(guc, "load failed: status = 0x%08X, ret = %d\n", status, ret);
+		guc_info(guc, "load failed: status: Reset = %d, BootROM = 0x%02X, UKernel = 0x%02X, MIA = 0x%02X, Auth = 0x%02X\n",
+			 REG_FIELD_GET(GS_MIA_IN_RESET, status),
+			 bootrom, ukernel,
+			 REG_FIELD_GET(GS_MIA_MASK, status),
+			 REG_FIELD_GET(GS_AUTH_STATUS_MASK, status));
+
+		switch (bootrom) {
+		case INTEL_BOOTROM_STATUS_NO_KEY_FOUND:
+			guc_info(guc, "invalid key requested, header = 0x%08X\n",
+				 intel_uncore_read(uncore, GUC_HEADER_INFO));
+			ret = -ENOEXEC;
+			break;
+
+		case INTEL_BOOTROM_STATUS_RSA_FAILED:
 			guc_info(guc, "firmware signature verification failed\n");
 			ret = -ENOEXEC;
+			break;
 		}
 
-		if (REG_FIELD_GET(GS_UKERNEL_MASK, status) == INTEL_GUC_LOAD_STATUS_EXCEPTION) {
+		switch (ukernel) {
+		case INTEL_GUC_LOAD_STATUS_EXCEPTION:
 			guc_info(guc, "firmware exception. EIP: %#x\n",
 				 intel_uncore_read(uncore, SOFT_SCRATCH(13)));
 			ret = -ENXIO;
+			break;
+
+		case INTEL_GUC_LOAD_STATUS_INIT_MMIO_SAVE_RESTORE_INVALID:
+			guc_info(guc, "illegal register in save/restore workaround list\n");
+			ret = -EPERM;
+			break;
+
+		case INTEL_GUC_LOAD_STATUS_HWCONFIG_START:
+			guc_info(guc, "still extracting hwconfig table.\n");
+			ret = -ETIMEDOUT;
+			break;
 		}
+
+		/* Uncommon/unexpected error, see earlier status code print for details */
+		if (ret == 0)
+			ret = -ENXIO;
 	}
 
 	return ret;
diff --git a/drivers/gpu/drm/i915/gt/uc/intel_guc_reg.h b/drivers/gpu/drm/i915/gt/uc/intel_guc_reg.h
index 9915de32e894e..3fd7988375020 100644
--- a/drivers/gpu/drm/i915/gt/uc/intel_guc_reg.h
+++ b/drivers/gpu/drm/i915/gt/uc/intel_guc_reg.h
@@ -18,8 +18,6 @@
 #define   GS_MIA_IN_RESET		  (0x01 << GS_RESET_SHIFT)
 #define   GS_BOOTROM_SHIFT		1
 #define   GS_BOOTROM_MASK		  (0x7F << GS_BOOTROM_SHIFT)
-#define   GS_BOOTROM_RSA_FAILED		  (0x50 << GS_BOOTROM_SHIFT)
-#define   GS_BOOTROM_JUMP_PASSED	  (0x76 << GS_BOOTROM_SHIFT)
 #define   GS_UKERNEL_SHIFT		8
 #define   GS_UKERNEL_MASK		  (0xFF << GS_UKERNEL_SHIFT)
 #define   GS_MIA_SHIFT			16
@@ -32,6 +30,8 @@
 #define   GS_AUTH_STATUS_BAD		  (0x01 << GS_AUTH_STATUS_SHIFT)
 #define   GS_AUTH_STATUS_GOOD		  (0x02 << GS_AUTH_STATUS_SHIFT)
 
+#define GUC_HEADER_INFO			_MMIO(0xc014)
+
 #define SOFT_SCRATCH(n)			_MMIO(0xc180 + (n) * 4)
 #define SOFT_SCRATCH_COUNT		16
 
-- 
2.39.1

Re: [Intel-gfx] [PATCH 1/2] drm/i915/guc: Improve GuC load error reporting

[Ceraolo Spurio, Daniele]

On 2/17/2023 3:47 PM, John.C.Harrison@Intel.com wrote:
> From: John Harrison <John.C.Harrison@Intel.com>
>
> There are multiple ways in which the GuC load can fail. The driver was
> reporting the status register as is, but not everyone can read the
> matrix unfiltered. So add decoding of the common error cases.
>
> Also, remove the comment about interrupt based load completion
> checking being not recommended. The interrupt was removed from the GuC
> firmware some time ago so it is no longer an option anyway. While at
> it, also abort the timeout if a known error code is reported. No need
> to keep waiting if the GuC has already given up the load.
>
> Signed-off-by: John Harrison <John.C.Harrison@Intel.com>
> ---
>   .../gpu/drm/i915/gt/uc/abi/guc_errors_abi.h   | 17 ++++
>   drivers/gpu/drm/i915/gt/uc/intel_guc_fw.c     | 95 +++++++++++++++----
>   drivers/gpu/drm/i915/gt/uc/intel_guc_reg.h    |  4 +-
>   3 files changed, 95 insertions(+), 21 deletions(-)
>
> diff --git a/drivers/gpu/drm/i915/gt/uc/abi/guc_errors_abi.h b/drivers/gpu/drm/i915/gt/uc/abi/guc_errors_abi.h
> index 8085fb1812748..750fe0c6d8529 100644
> --- a/drivers/gpu/drm/i915/gt/uc/abi/guc_errors_abi.h
> +++ b/drivers/gpu/drm/i915/gt/uc/abi/guc_errors_abi.h
> @@ -21,6 +21,9 @@ enum intel_guc_load_status {
>   	INTEL_GUC_LOAD_STATUS_ERROR_DEVID_BUILD_MISMATCH       = 0x02,
>   	INTEL_GUC_LOAD_STATUS_GUC_PREPROD_BUILD_MISMATCH       = 0x03,
>   	INTEL_GUC_LOAD_STATUS_ERROR_DEVID_INVALID_GUCTYPE      = 0x04,
> +	INTEL_GUC_LOAD_STATUS_HWCONFIG_START                   = 0x05,
> +	INTEL_GUC_LOAD_STATUS_HWCONFIG_DONE                    = 0x06,
> +	INTEL_GUC_LOAD_STATUS_HWCONFIG_ERROR                   = 0x07,
>   	INTEL_GUC_LOAD_STATUS_GDT_DONE                         = 0x10,
>   	INTEL_GUC_LOAD_STATUS_IDT_DONE                         = 0x20,
>   	INTEL_GUC_LOAD_STATUS_LAPIC_DONE                       = 0x30,
> @@ -38,4 +41,18 @@ enum intel_guc_load_status {
>   	INTEL_GUC_LOAD_STATUS_READY                            = 0xF0,
>   };
>   
> +enum intel_bootrom_load_status {
> +	INTEL_BOOTROM_STATUS_NO_KEY_FOUND                 = 0x13,
> +	INTEL_BOOTROM_STATUS_AES_PROD_KEY_FOUND           = 0x1A,
> +	INTEL_BOOTROM_STATUS_RSA_FAILED                   = 0x50,
> +	INTEL_BOOTROM_STATUS_PAVPC_FAILED                 = 0x73,
> +	INTEL_BOOTROM_STATUS_WOPCM_FAILED                 = 0x74,
> +	INTEL_BOOTROM_STATUS_LOADLOC_FAILED               = 0x75,
> +	INTEL_BOOTROM_STATUS_JUMP_PASSED                  = 0x76,
> +	INTEL_BOOTROM_STATUS_JUMP_FAILED                  = 0x77,
> +	INTEL_BOOTROM_STATUS_RC6CTXCONFIG_FAILED          = 0x79,
> +	INTEL_BOOTROM_STATUS_MPUMAP_INCORRECT             = 0x7a,

nit: you've used uppercase for the other hex characters, while only this 
one has a lowercase "a"

> +	INTEL_BOOTROM_STATUS_EXCEPTION                    = 0x7E,
> +};

I've double checked the defines against the specs and they all match.

> +
>   #endif /* _ABI_GUC_ERRORS_ABI_H */
> diff --git a/drivers/gpu/drm/i915/gt/uc/intel_guc_fw.c b/drivers/gpu/drm/i915/gt/uc/intel_guc_fw.c
> index 69133420c78b2..2f5942606913d 100644
> --- a/drivers/gpu/drm/i915/gt/uc/intel_guc_fw.c
> +++ b/drivers/gpu/drm/i915/gt/uc/intel_guc_fw.c
> @@ -88,31 +88,64 @@ static int guc_xfer_rsa(struct intel_uc_fw *guc_fw,
>   /*
>    * Read the GuC status register (GUC_STATUS) and store it in the
>    * specified location; then return a boolean indicating whether
> - * the value matches either of two values representing completion
> - * of the GuC boot process.
> + * the value matches either completion or a known failure code.
>    *
>    * This is used for polling the GuC status in a wait_for()
>    * loop below.
>    */
> -static inline bool guc_ready(struct intel_uncore *uncore, u32 *status)
> +static inline bool guc_load_done(struct intel_uncore *uncore, u32 *status, bool *success)
>   {
>   	u32 val = intel_uncore_read(uncore, GUC_STATUS);
>   	u32 uk_val = REG_FIELD_GET(GS_UKERNEL_MASK, val);
> +	u32 br_val = REG_FIELD_GET(GS_BOOTROM_MASK, val);
>   
>   	*status = val;
> -	return uk_val == INTEL_GUC_LOAD_STATUS_READY;
> +	*success = true;

It feels a bit weird to default this to true. If we don't return true 
from one of the switches below, we can end up returning false from the 
wait but leaving success to true. I understand that this is used more as 
a "not failed" flag rather than a success one, so it is functionally 
correct, but maybe rename it? not a blocker.

Apart from the nits, the patch LGTM:

Reviewed-by: Daniele Ceraolo Spurio <daniele.ceraolospurio@intel.com>

Daniele

> +	switch (uk_val) {
> +	case INTEL_GUC_LOAD_STATUS_READY:
> +		return true;
> +
> +	case INTEL_GUC_LOAD_STATUS_ERROR_DEVID_BUILD_MISMATCH:
> +	case INTEL_GUC_LOAD_STATUS_GUC_PREPROD_BUILD_MISMATCH:
> +	case INTEL_GUC_LOAD_STATUS_ERROR_DEVID_INVALID_GUCTYPE:
> +	case INTEL_GUC_LOAD_STATUS_HWCONFIG_ERROR:
> +	case INTEL_GUC_LOAD_STATUS_DPC_ERROR:
> +	case INTEL_GUC_LOAD_STATUS_EXCEPTION:
> +	case INTEL_GUC_LOAD_STATUS_INIT_DATA_INVALID:
> +	case INTEL_GUC_LOAD_STATUS_MPU_DATA_INVALID:
> +	case INTEL_GUC_LOAD_STATUS_INIT_MMIO_SAVE_RESTORE_INVALID:
> +		*success = false;
> +		return true;
> +	}
> +
> +	switch (br_val) {
> +	case INTEL_BOOTROM_STATUS_NO_KEY_FOUND:
> +	case INTEL_BOOTROM_STATUS_RSA_FAILED:
> +	case INTEL_BOOTROM_STATUS_PAVPC_FAILED:
> +	case INTEL_BOOTROM_STATUS_WOPCM_FAILED:
> +	case INTEL_BOOTROM_STATUS_LOADLOC_FAILED:
> +	case INTEL_BOOTROM_STATUS_JUMP_FAILED:
> +	case INTEL_BOOTROM_STATUS_RC6CTXCONFIG_FAILED:
> +	case INTEL_BOOTROM_STATUS_MPUMAP_INCORRECT:
> +	case INTEL_BOOTROM_STATUS_EXCEPTION:
> +		*success = false;
> +		return true;
> +	}
> +
> +	return false;
>   }
>   
>   static int guc_wait_ucode(struct intel_guc *guc)
>   {
>   	struct intel_gt *gt = guc_to_gt(guc);
>   	struct intel_uncore *uncore = gt->uncore;
> +	bool success;
>   	u32 status;
>   	int ret;
>   
>   	/*
>   	 * Wait for the GuC to start up.
> -	 * NB: Docs recommend not using the interrupt for completion.
> +	 *
>   	 * Measurements indicate this should take no more than 20ms
>   	 * (assuming the GT clock is at maximum frequency). So, a
>   	 * timeout here indicates that the GuC has failed and is unusable.
> @@ -127,28 +160,52 @@ static int guc_wait_ucode(struct intel_guc *guc)
>   	 * 200ms. Even at slowest clock, this should be sufficient. And
>   	 * in the working case, a larger timeout makes no difference.
>   	 */
> -	ret = wait_for(guc_ready(uncore, &status), 200);
> -	if (ret) {
> -		guc_info(guc, "load failed: status = 0x%08X\n", status);
> -		guc_info(guc, "load failed: status: Reset = %d, "
> -			"BootROM = 0x%02X, UKernel = 0x%02X, "
> -			"MIA = 0x%02X, Auth = 0x%02X\n",
> -			REG_FIELD_GET(GS_MIA_IN_RESET, status),
> -			REG_FIELD_GET(GS_BOOTROM_MASK, status),
> -			REG_FIELD_GET(GS_UKERNEL_MASK, status),
> -			REG_FIELD_GET(GS_MIA_MASK, status),
> -			REG_FIELD_GET(GS_AUTH_STATUS_MASK, status));
> -
> -		if ((status & GS_BOOTROM_MASK) == GS_BOOTROM_RSA_FAILED) {
> +	ret = wait_for(guc_load_done(uncore, &status, &success), 200);
> +	if (ret || !success) {
> +		u32 ukernel = REG_FIELD_GET(GS_UKERNEL_MASK, status);
> +		u32 bootrom = REG_FIELD_GET(GS_BOOTROM_MASK, status);
> +
> +		guc_info(guc, "load failed: status = 0x%08X, ret = %d\n", status, ret);
> +		guc_info(guc, "load failed: status: Reset = %d, BootROM = 0x%02X, UKernel = 0x%02X, MIA = 0x%02X, Auth = 0x%02X\n",
> +			 REG_FIELD_GET(GS_MIA_IN_RESET, status),
> +			 bootrom, ukernel,
> +			 REG_FIELD_GET(GS_MIA_MASK, status),
> +			 REG_FIELD_GET(GS_AUTH_STATUS_MASK, status));
> +
> +		switch (bootrom) {
> +		case INTEL_BOOTROM_STATUS_NO_KEY_FOUND:
> +			guc_info(guc, "invalid key requested, header = 0x%08X\n",
> +				 intel_uncore_read(uncore, GUC_HEADER_INFO));
> +			ret = -ENOEXEC;
> +			break;
> +
> +		case INTEL_BOOTROM_STATUS_RSA_FAILED:
>   			guc_info(guc, "firmware signature verification failed\n");
>   			ret = -ENOEXEC;
> +			break;
>   		}
>   
> -		if (REG_FIELD_GET(GS_UKERNEL_MASK, status) == INTEL_GUC_LOAD_STATUS_EXCEPTION) {
> +		switch (ukernel) {
> +		case INTEL_GUC_LOAD_STATUS_EXCEPTION:
>   			guc_info(guc, "firmware exception. EIP: %#x\n",
>   				 intel_uncore_read(uncore, SOFT_SCRATCH(13)));
>   			ret = -ENXIO;
> +			break;
> +
> +		case INTEL_GUC_LOAD_STATUS_INIT_MMIO_SAVE_RESTORE_INVALID:
> +			guc_info(guc, "illegal register in save/restore workaround list\n");
> +			ret = -EPERM;
> +			break;
> +
> +		case INTEL_GUC_LOAD_STATUS_HWCONFIG_START:
> +			guc_info(guc, "still extracting hwconfig table.\n");
> +			ret = -ETIMEDOUT;
> +			break;
>   		}
> +
> +		/* Uncommon/unexpected error, see earlier status code print for details */
> +		if (ret == 0)
> +			ret = -ENXIO;
>   	}
>   
>   	return ret;
> diff --git a/drivers/gpu/drm/i915/gt/uc/intel_guc_reg.h b/drivers/gpu/drm/i915/gt/uc/intel_guc_reg.h
> index 9915de32e894e..3fd7988375020 100644
> --- a/drivers/gpu/drm/i915/gt/uc/intel_guc_reg.h
> +++ b/drivers/gpu/drm/i915/gt/uc/intel_guc_reg.h
> @@ -18,8 +18,6 @@
>   #define   GS_MIA_IN_RESET		  (0x01 << GS_RESET_SHIFT)
>   #define   GS_BOOTROM_SHIFT		1
>   #define   GS_BOOTROM_MASK		  (0x7F << GS_BOOTROM_SHIFT)
> -#define   GS_BOOTROM_RSA_FAILED		  (0x50 << GS_BOOTROM_SHIFT)
> -#define   GS_BOOTROM_JUMP_PASSED	  (0x76 << GS_BOOTROM_SHIFT)
>   #define   GS_UKERNEL_SHIFT		8
>   #define   GS_UKERNEL_MASK		  (0xFF << GS_UKERNEL_SHIFT)
>   #define   GS_MIA_SHIFT			16
> @@ -32,6 +30,8 @@
>   #define   GS_AUTH_STATUS_BAD		  (0x01 << GS_AUTH_STATUS_SHIFT)
>   #define   GS_AUTH_STATUS_GOOD		  (0x02 << GS_AUTH_STATUS_SHIFT)
>   
> +#define GUC_HEADER_INFO			_MMIO(0xc014)
> +
>   #define SOFT_SCRATCH(n)			_MMIO(0xc180 + (n) * 4)
>   #define SOFT_SCRATCH_COUNT		16
>   

[PATCH 2/2] drm/i915/guc: Allow for very slow GuC loading

[John.C.Harrison]

From: John Harrison <John.C.Harrison@Intel.com>

A failure to load the GuC is occasionally observed where the GuC log
actually showed that the GuC had loaded just fine. The implication
being that the load just took ever so slightly longer than the 200ms
timeout. Given that the actual time should be tens of milliseconds at
the slowest, this should never happen. So far the issue has generally
been caused by a bad IFWI resulting in low frequencies during boot
(depsite the KMD requesting max frequency). However, the issue seems
to happen more often than one would like.

So a) increase the timeout so that the user still gets a working
system even in the case of slow load. And b) report the frequency
during the load to see if that is the case of the slow down.

Signed-off-by: John Harrison <John.C.Harrison@Intel.com>
---
 drivers/gpu/drm/i915/gt/uc/intel_guc_fw.c | 37 +++++++++++++++++++++--
 1 file changed, 34 insertions(+), 3 deletions(-)

diff --git a/drivers/gpu/drm/i915/gt/uc/intel_guc_fw.c b/drivers/gpu/drm/i915/gt/uc/intel_guc_fw.c
index 2f5942606913d..72e003f50617d 100644
--- a/drivers/gpu/drm/i915/gt/uc/intel_guc_fw.c
+++ b/drivers/gpu/drm/i915/gt/uc/intel_guc_fw.c
@@ -12,6 +12,7 @@
 #include "gt/intel_gt.h"
 #include "gt/intel_gt_mcr.h"
 #include "gt/intel_gt_regs.h"
+#include "gt/intel_rps.h"
 #include "intel_guc_fw.h"
 #include "intel_guc_print.h"
 #include "i915_drv.h"
@@ -139,9 +140,12 @@ static int guc_wait_ucode(struct intel_guc *guc)
 {
 	struct intel_gt *gt = guc_to_gt(guc);
 	struct intel_uncore *uncore = gt->uncore;
+	ktime_t before, after, delta;
 	bool success;
 	u32 status;
-	int ret;
+	int ret, count;
+	u64 delta_ms;
+	u32 before_freq;
 
 	/*
 	 * Wait for the GuC to start up.
@@ -159,13 +163,32 @@ static int guc_wait_ucode(struct intel_guc *guc)
 	 * issues to be resolved. In the meantime bump the timeout to
 	 * 200ms. Even at slowest clock, this should be sufficient. And
 	 * in the working case, a larger timeout makes no difference.
+	 *
+	 * IFWI updates have also been seen to cause sporadic failures due to
+	 * the requested frequency not being granted and thus the firmware
+	 * load is attempted at minimum frequency. That can lead to load times
+	 * in the seconds range. However, there is a limit on how long an
+	 * individual wait_for() can wait. So wrap it in a loop.
 	 */
-	ret = wait_for(guc_load_done(uncore, &status, &success), 200);
+	before_freq = intel_rps_read_actual_frequency(&uncore->gt->rps);
+	before = ktime_get();
+	for (count = 0; count < 20; count++) {
+		ret = wait_for(guc_load_done(uncore, &status, &success), 1000);
+		if (!ret || !success)
+			break;
+
+		guc_dbg(guc, "load still in progress, count = %d, freq = %dMHz\n",
+			count, intel_rps_read_actual_frequency(&uncore->gt->rps));
+	}
+	after = ktime_get();
+	delta = ktime_sub(after, before);
+	delta_ms = ktime_to_ms(delta);
 	if (ret || !success) {
 		u32 ukernel = REG_FIELD_GET(GS_UKERNEL_MASK, status);
 		u32 bootrom = REG_FIELD_GET(GS_BOOTROM_MASK, status);
 
-		guc_info(guc, "load failed: status = 0x%08X, ret = %d\n", status, ret);
+		guc_info(guc, "load failed: status = 0x%08X, time = %lldms, freq = %dMHz, ret = %d\n",
+			 status, delta_ms, intel_rps_read_actual_frequency(&uncore->gt->rps), ret);
 		guc_info(guc, "load failed: status: Reset = %d, BootROM = 0x%02X, UKernel = 0x%02X, MIA = 0x%02X, Auth = 0x%02X\n",
 			 REG_FIELD_GET(GS_MIA_IN_RESET, status),
 			 bootrom, ukernel,
@@ -206,6 +229,14 @@ static int guc_wait_ucode(struct intel_guc *guc)
 		/* Uncommon/unexpected error, see earlier status code print for details */
 		if (ret == 0)
 			ret = -ENXIO;
+	} else if (delta_ms > 200) {
+		guc_warn(guc, "excessive init time: %lldms! [freq = %dMHz, before = %dMHz, status = 0x%08X, count = %d, ret = %d]\n",
+			 delta_ms, intel_rps_read_actual_frequency(&uncore->gt->rps),
+			 before_freq, status, count, ret);
+	} else {
+		guc_dbg(guc, "init took %lldms, freq = %dMHz, before = %dMHz, status = 0x%08X, count = %d, ret = %d\n",
+			delta_ms, intel_rps_read_actual_frequency(&uncore->gt->rps),
+			before_freq, status, count, ret);
 	}
 
 	return ret;
-- 
2.39.1

Re: [Intel-gfx] [PATCH 2/2] drm/i915/guc: Allow for very slow GuC loading

[Ceraolo Spurio, Daniele]

On 2/17/2023 3:47 PM, John.C.Harrison@Intel.com wrote:
> From: John Harrison <John.C.Harrison@Intel.com>
>
> A failure to load the GuC is occasionally observed where the GuC log
> actually showed that the GuC had loaded just fine. The implication
> being that the load just took ever so slightly longer than the 200ms
> timeout. Given that the actual time should be tens of milliseconds at
> the slowest, this should never happen. So far the issue has generally
> been caused by a bad IFWI resulting in low frequencies during boot
> (depsite the KMD requesting max frequency). However, the issue seems
> to happen more often than one would like.
>
> So a) increase the timeout so that the user still gets a working
> system even in the case of slow load. And b) report the frequency
> during the load to see if that is the case of the slow down.

Some refs would be good here. From a quick search, these seems to match:

https://gitlab.freedesktop.org/drm/intel/-/issues/7931
https://gitlab.freedesktop.org/drm/intel/-/issues/8060
https://gitlab.freedesktop.org/drm/intel/-/issues/8083
https://gitlab.freedesktop.org/drm/intel/-/issues/8136
https://gitlab.freedesktop.org/drm/intel/-/issues/8137

>
> Signed-off-by: John Harrison <John.C.Harrison@Intel.com>
> ---
>   drivers/gpu/drm/i915/gt/uc/intel_guc_fw.c | 37 +++++++++++++++++++++--
>   1 file changed, 34 insertions(+), 3 deletions(-)
>
> diff --git a/drivers/gpu/drm/i915/gt/uc/intel_guc_fw.c b/drivers/gpu/drm/i915/gt/uc/intel_guc_fw.c
> index 2f5942606913d..72e003f50617d 100644
> --- a/drivers/gpu/drm/i915/gt/uc/intel_guc_fw.c
> +++ b/drivers/gpu/drm/i915/gt/uc/intel_guc_fw.c
> @@ -12,6 +12,7 @@
>   #include "gt/intel_gt.h"
>   #include "gt/intel_gt_mcr.h"
>   #include "gt/intel_gt_regs.h"
> +#include "gt/intel_rps.h"
>   #include "intel_guc_fw.h"
>   #include "intel_guc_print.h"
>   #include "i915_drv.h"
> @@ -139,9 +140,12 @@ static int guc_wait_ucode(struct intel_guc *guc)
>   {
>   	struct intel_gt *gt = guc_to_gt(guc);
>   	struct intel_uncore *uncore = gt->uncore;
> +	ktime_t before, after, delta;
>   	bool success;
>   	u32 status;
> -	int ret;
> +	int ret, count;
> +	u64 delta_ms;
> +	u32 before_freq;
>   
>   	/*
>   	 * Wait for the GuC to start up.
> @@ -159,13 +163,32 @@ static int guc_wait_ucode(struct intel_guc *guc)
>   	 * issues to be resolved. In the meantime bump the timeout to
>   	 * 200ms. Even at slowest clock, this should be sufficient. And
>   	 * in the working case, a larger timeout makes no difference.
> +	 *
> +	 * IFWI updates have also been seen to cause sporadic failures due to
> +	 * the requested frequency not being granted and thus the firmware
> +	 * load is attempted at minimum frequency. That can lead to load times
> +	 * in the seconds range. However, there is a limit on how long an
> +	 * individual wait_for() can wait. So wrap it in a loop.
>   	 */
> -	ret = wait_for(guc_load_done(uncore, &status, &success), 200);
> +	before_freq = intel_rps_read_actual_frequency(&uncore->gt->rps);
> +	before = ktime_get();
> +	for (count = 0; count < 20; count++) {
> +		ret = wait_for(guc_load_done(uncore, &status, &success), 1000);

Isn't 20 secs a bit too long for an in-place wait? I get that if the GuC 
doesn't load (or fail to) within a few secs the HW is likely toast, but 
still that seems a bit too long to me. What's the worst case load time 
ever observed? I suggest reducing the wait to 3 secs as a compromise, if 
that's bigger than the worst case.

The patch LGTM apart from this point.

Daniele

> +		if (!ret || !success)
> +			break;
> +
> +		guc_dbg(guc, "load still in progress, count = %d, freq = %dMHz\n",
> +			count, intel_rps_read_actual_frequency(&uncore->gt->rps));
> +	}
> +	after = ktime_get();
> +	delta = ktime_sub(after, before);
> +	delta_ms = ktime_to_ms(delta);
>   	if (ret || !success) {
>   		u32 ukernel = REG_FIELD_GET(GS_UKERNEL_MASK, status);
>   		u32 bootrom = REG_FIELD_GET(GS_BOOTROM_MASK, status);
>   
> -		guc_info(guc, "load failed: status = 0x%08X, ret = %d\n", status, ret);
> +		guc_info(guc, "load failed: status = 0x%08X, time = %lldms, freq = %dMHz, ret = %d\n",
> +			 status, delta_ms, intel_rps_read_actual_frequency(&uncore->gt->rps), ret);
>   		guc_info(guc, "load failed: status: Reset = %d, BootROM = 0x%02X, UKernel = 0x%02X, MIA = 0x%02X, Auth = 0x%02X\n",
>   			 REG_FIELD_GET(GS_MIA_IN_RESET, status),
>   			 bootrom, ukernel,
> @@ -206,6 +229,14 @@ static int guc_wait_ucode(struct intel_guc *guc)
>   		/* Uncommon/unexpected error, see earlier status code print for details */
>   		if (ret == 0)
>   			ret = -ENXIO;
> +	} else if (delta_ms > 200) {
> +		guc_warn(guc, "excessive init time: %lldms! [freq = %dMHz, before = %dMHz, status = 0x%08X, count = %d, ret = %d]\n",
> +			 delta_ms, intel_rps_read_actual_frequency(&uncore->gt->rps),
> +			 before_freq, status, count, ret);
> +	} else {
> +		guc_dbg(guc, "init took %lldms, freq = %dMHz, before = %dMHz, status = 0x%08X, count = %d, ret = %d\n",
> +			delta_ms, intel_rps_read_actual_frequency(&uncore->gt->rps),
> +			before_freq, status, count, ret);
>   	}
>   
>   	return ret;

Re: [Intel-gfx] [PATCH 2/2] drm/i915/guc: Allow for very slow GuC loading

[John Harrison]

On 3/3/2023 11:20, Ceraolo Spurio, Daniele wrote:
> On 2/17/2023 3:47 PM, John.C.Harrison@Intel.com wrote:
>> From: John Harrison <John.C.Harrison@Intel.com>
>>
>> A failure to load the GuC is occasionally observed where the GuC log
>> actually showed that the GuC had loaded just fine. The implication
>> being that the load just took ever so slightly longer than the 200ms
>> timeout. Given that the actual time should be tens of milliseconds at
>> the slowest, this should never happen. So far the issue has generally
>> been caused by a bad IFWI resulting in low frequencies during boot
>> (depsite the KMD requesting max frequency). However, the issue seems
>> to happen more often than one would like.
>>
>> So a) increase the timeout so that the user still gets a working
>> system even in the case of slow load. And b) report the frequency
>> during the load to see if that is the case of the slow down.
>
> Some refs would be good here. From a quick search, these seems to match:
>
> https://gitlab.freedesktop.org/drm/intel/-/issues/7931
> https://gitlab.freedesktop.org/drm/intel/-/issues/8060
> https://gitlab.freedesktop.org/drm/intel/-/issues/8083
> https://gitlab.freedesktop.org/drm/intel/-/issues/8136
> https://gitlab.freedesktop.org/drm/intel/-/issues/8137
Should these have a prefix tag? If so, what? 'closes' is not entirely 
accurate. This patch is just to help with debug of the underlying issue. 
And if the timeout is reduced then it won't necessarily allow a slow 
system to work. See below.


>
>>
>> Signed-off-by: John Harrison <John.C.Harrison@Intel.com>
>> ---
>>   drivers/gpu/drm/i915/gt/uc/intel_guc_fw.c | 37 +++++++++++++++++++++--
>>   1 file changed, 34 insertions(+), 3 deletions(-)
>>
>> diff --git a/drivers/gpu/drm/i915/gt/uc/intel_guc_fw.c 
>> b/drivers/gpu/drm/i915/gt/uc/intel_guc_fw.c
>> index 2f5942606913d..72e003f50617d 100644
>> --- a/drivers/gpu/drm/i915/gt/uc/intel_guc_fw.c
>> +++ b/drivers/gpu/drm/i915/gt/uc/intel_guc_fw.c
>> @@ -12,6 +12,7 @@
>>   #include "gt/intel_gt.h"
>>   #include "gt/intel_gt_mcr.h"
>>   #include "gt/intel_gt_regs.h"
>> +#include "gt/intel_rps.h"
>>   #include "intel_guc_fw.h"
>>   #include "intel_guc_print.h"
>>   #include "i915_drv.h"
>> @@ -139,9 +140,12 @@ static int guc_wait_ucode(struct intel_guc *guc)
>>   {
>>       struct intel_gt *gt = guc_to_gt(guc);
>>       struct intel_uncore *uncore = gt->uncore;
>> +    ktime_t before, after, delta;
>>       bool success;
>>       u32 status;
>> -    int ret;
>> +    int ret, count;
>> +    u64 delta_ms;
>> +    u32 before_freq;
>>         /*
>>        * Wait for the GuC to start up.
>> @@ -159,13 +163,32 @@ static int guc_wait_ucode(struct intel_guc *guc)
>>        * issues to be resolved. In the meantime bump the timeout to
>>        * 200ms. Even at slowest clock, this should be sufficient. And
>>        * in the working case, a larger timeout makes no difference.
>> +     *
>> +     * IFWI updates have also been seen to cause sporadic failures 
>> due to
>> +     * the requested frequency not being granted and thus the firmware
>> +     * load is attempted at minimum frequency. That can lead to load 
>> times
>> +     * in the seconds range. However, there is a limit on how long an
>> +     * individual wait_for() can wait. So wrap it in a loop.
>>        */
>> -    ret = wait_for(guc_load_done(uncore, &status, &success), 200);
>> +    before_freq = intel_rps_read_actual_frequency(&uncore->gt->rps);
>> +    before = ktime_get();
>> +    for (count = 0; count < 20; count++) {
>> +        ret = wait_for(guc_load_done(uncore, &status, &success), 1000);
>
> Isn't 20 secs a bit too long for an in-place wait? I get that if the 
> GuC doesn't load (or fail to) within a few secs the HW is likely 
> toast, but still that seems a bit too long to me. What's the worst 
> case load time ever observed? I suggest reducing the wait to 3 secs as 
> a compromise, if that's bigger than the worst case.
I can drop it to 3 for normal builds and keep 20 for 
CONFIG_DRM_I915_DEBUG_GEM builds. However, that won't actually be long 
enough for all slow situations. We have seen times of at least 11s when 
the GPU is running at minimum frequency. So, for CI runs we definitely 
want to keep the 20s limit. For end users? Is it better to wait for up 
to 20s or to boot in display only fallback mode? And note that this is a 
timeout only. A functional system will still complete in tens of 
milliseconds.

John.

>
> The patch LGTM apart from this point.
>
> Daniele
>
>> +        if (!ret || !success)
>> +            break;
>> +
>> +        guc_dbg(guc, "load still in progress, count = %d, freq = 
>> %dMHz\n",
>> +            count, intel_rps_read_actual_frequency(&uncore->gt->rps));
>> +    }
>> +    after = ktime_get();
>> +    delta = ktime_sub(after, before);
>> +    delta_ms = ktime_to_ms(delta);
>>       if (ret || !success) {
>>           u32 ukernel = REG_FIELD_GET(GS_UKERNEL_MASK, status);
>>           u32 bootrom = REG_FIELD_GET(GS_BOOTROM_MASK, status);
>>   -        guc_info(guc, "load failed: status = 0x%08X, ret = %d\n", 
>> status, ret);
>> +        guc_info(guc, "load failed: status = 0x%08X, time = %lldms, 
>> freq = %dMHz, ret = %d\n",
>> +             status, delta_ms, 
>> intel_rps_read_actual_frequency(&uncore->gt->rps), ret);
>>           guc_info(guc, "load failed: status: Reset = %d, BootROM = 
>> 0x%02X, UKernel = 0x%02X, MIA = 0x%02X, Auth = 0x%02X\n",
>>                REG_FIELD_GET(GS_MIA_IN_RESET, status),
>>                bootrom, ukernel,
>> @@ -206,6 +229,14 @@ static int guc_wait_ucode(struct intel_guc *guc)
>>           /* Uncommon/unexpected error, see earlier status code print 
>> for details */
>>           if (ret == 0)
>>               ret = -ENXIO;
>> +    } else if (delta_ms > 200) {
>> +        guc_warn(guc, "excessive init time: %lldms! [freq = %dMHz, 
>> before = %dMHz, status = 0x%08X, count = %d, ret = %d]\n",
>> +             delta_ms, 
>> intel_rps_read_actual_frequency(&uncore->gt->rps),
>> +             before_freq, status, count, ret);
>> +    } else {
>> +        guc_dbg(guc, "init took %lldms, freq = %dMHz, before = 
>> %dMHz, status = 0x%08X, count = %d, ret = %d\n",
>> +            delta_ms, 
>> intel_rps_read_actual_frequency(&uncore->gt->rps),
>> +            before_freq, status, count, ret);
>>       }
>>         return ret;
>

Re: [Intel-gfx] [PATCH 2/2] drm/i915/guc: Allow for very slow GuC loading

[Dixit, Ashutosh]

On Fri, 10 Mar 2023 17:01:42 -0800, John Harrison wrote:
>
> >> +	for (count = 0; count < 20; count++) {
> >> +		ret = wait_for(guc_load_done(uncore, &status, &success), 1000);
> >
> > Isn't 20 secs a bit too long for an in-place wait? I get that if the GuC
> > doesn't load (or fail to) within a few secs the HW is likely toast, but
> > still that seems a bit too long to me. What's the worst case load time
> > ever observed? I suggest reducing the wait to 3 secs as a compromise, if
> > that's bigger than the worst case.
>
> I can drop it to 3 for normal builds and keep 20 for
> CONFIG_DRM_I915_DEBUG_GEM builds. However, that won't actually be long
> enough for all slow situations. We have seen times of at least 11s when the
> GPU is running at minimum frequency. So, for CI runs we definitely want to
> keep the 20s limit. For end users? Is it better to wait for up to 20s or to
> boot in display only fallback mode? And note that this is a timeout only. A
> functional system will still complete in tens of milliseconds.

Just FYI, in this related patch:

https://patchwork.freedesktop.org/series/115003/#rev2

I am holding a mutex across GuC FW load, so very unlikely, but worst case a
thread can get blocked for the duration of the GuC reset/FW load.

Ashutosh

Re: [Intel-gfx] [PATCH 2/2] drm/i915/guc: Allow for very slow GuC loading

[Ceraolo Spurio, Daniele]

On 3/10/2023 5:01 PM, John Harrison wrote:
> On 3/3/2023 11:20, Ceraolo Spurio, Daniele wrote:
>> On 2/17/2023 3:47 PM, John.C.Harrison@Intel.com wrote:
>>> From: John Harrison <John.C.Harrison@Intel.com>
>>>
>>> A failure to load the GuC is occasionally observed where the GuC log
>>> actually showed that the GuC had loaded just fine. The implication
>>> being that the load just took ever so slightly longer than the 200ms
>>> timeout. Given that the actual time should be tens of milliseconds at
>>> the slowest, this should never happen. So far the issue has generally
>>> been caused by a bad IFWI resulting in low frequencies during boot
>>> (depsite the KMD requesting max frequency). However, the issue seems
>>> to happen more often than one would like.
>>>
>>> So a) increase the timeout so that the user still gets a working
>>> system even in the case of slow load. And b) report the frequency
>>> during the load to see if that is the case of the slow down.
>>
>> Some refs would be good here. From a quick search, these seems to match:
>>
>> https://gitlab.freedesktop.org/drm/intel/-/issues/7931
>> https://gitlab.freedesktop.org/drm/intel/-/issues/8060
>> https://gitlab.freedesktop.org/drm/intel/-/issues/8083
>> https://gitlab.freedesktop.org/drm/intel/-/issues/8136
>> https://gitlab.freedesktop.org/drm/intel/-/issues/8137
> Should these have a prefix tag? If so, what? 'closes' is not entirely 
> accurate. This patch is just to help with debug of the underlying 
> issue. And if the timeout is reduced then it won't necessarily allow a 
> slow system to work. See below.
>

For bugs we usually use either "References:" or "Closes:". I think the 
former fits more for this case.

>
>>
>>>
>>> Signed-off-by: John Harrison <John.C.Harrison@Intel.com>
>>> ---
>>>   drivers/gpu/drm/i915/gt/uc/intel_guc_fw.c | 37 
>>> +++++++++++++++++++++--
>>>   1 file changed, 34 insertions(+), 3 deletions(-)
>>>
>>> diff --git a/drivers/gpu/drm/i915/gt/uc/intel_guc_fw.c 
>>> b/drivers/gpu/drm/i915/gt/uc/intel_guc_fw.c
>>> index 2f5942606913d..72e003f50617d 100644
>>> --- a/drivers/gpu/drm/i915/gt/uc/intel_guc_fw.c
>>> +++ b/drivers/gpu/drm/i915/gt/uc/intel_guc_fw.c
>>> @@ -12,6 +12,7 @@
>>>   #include "gt/intel_gt.h"
>>>   #include "gt/intel_gt_mcr.h"
>>>   #include "gt/intel_gt_regs.h"
>>> +#include "gt/intel_rps.h"
>>>   #include "intel_guc_fw.h"
>>>   #include "intel_guc_print.h"
>>>   #include "i915_drv.h"
>>> @@ -139,9 +140,12 @@ static int guc_wait_ucode(struct intel_guc *guc)
>>>   {
>>>       struct intel_gt *gt = guc_to_gt(guc);
>>>       struct intel_uncore *uncore = gt->uncore;
>>> +    ktime_t before, after, delta;
>>>       bool success;
>>>       u32 status;
>>> -    int ret;
>>> +    int ret, count;
>>> +    u64 delta_ms;
>>> +    u32 before_freq;
>>>         /*
>>>        * Wait for the GuC to start up.
>>> @@ -159,13 +163,32 @@ static int guc_wait_ucode(struct intel_guc *guc)
>>>        * issues to be resolved. In the meantime bump the timeout to
>>>        * 200ms. Even at slowest clock, this should be sufficient. And
>>>        * in the working case, a larger timeout makes no difference.
>>> +     *
>>> +     * IFWI updates have also been seen to cause sporadic failures 
>>> due to
>>> +     * the requested frequency not being granted and thus the firmware
>>> +     * load is attempted at minimum frequency. That can lead to 
>>> load times
>>> +     * in the seconds range. However, there is a limit on how long an
>>> +     * individual wait_for() can wait. So wrap it in a loop.
>>>        */
>>> -    ret = wait_for(guc_load_done(uncore, &status, &success), 200);
>>> +    before_freq = intel_rps_read_actual_frequency(&uncore->gt->rps);
>>> +    before = ktime_get();
>>> +    for (count = 0; count < 20; count++) {
>>> +        ret = wait_for(guc_load_done(uncore, &status, &success), 
>>> 1000);
>>
>> Isn't 20 secs a bit too long for an in-place wait? I get that if the 
>> GuC doesn't load (or fail to) within a few secs the HW is likely 
>> toast, but still that seems a bit too long to me. What's the worst 
>> case load time ever observed? I suggest reducing the wait to 3 secs 
>> as a compromise, if that's bigger than the worst case.
> I can drop it to 3 for normal builds and keep 20 for 
> CONFIG_DRM_I915_DEBUG_GEM builds. However, that won't actually be long 
> enough for all slow situations. We have seen times of at least 11s 
> when the GPU is running at minimum frequency. So, for CI runs we 
> definitely want to keep the 20s limit. For end users? Is it better to 
> wait for up to 20s or to boot in display only fallback mode? And note 
> that this is a timeout only. A functional system will still complete 
> in tens of milliseconds.

I'd argue that the only way for us to go to multiple seconds is if the 
frequency goes below the efficient levels, which normally should only 
happen if the card cooling fails and the temperature goes out of 
control, in which case there are more pressing issues than a GuC load 
failure. I agree that having 3 secs normal and 20 for CI is a good 
compromise and if we ever see a very long timeout in CI we can 
investigate more.

Daniele

>
> John.
>
>>
>> The patch LGTM apart from this point.
>>
>> Daniele
>>
>>> +        if (!ret || !success)
>>> +            break;
>>> +
>>> +        guc_dbg(guc, "load still in progress, count = %d, freq = 
>>> %dMHz\n",
>>> +            count, intel_rps_read_actual_frequency(&uncore->gt->rps));
>>> +    }
>>> +    after = ktime_get();
>>> +    delta = ktime_sub(after, before);
>>> +    delta_ms = ktime_to_ms(delta);
>>>       if (ret || !success) {
>>>           u32 ukernel = REG_FIELD_GET(GS_UKERNEL_MASK, status);
>>>           u32 bootrom = REG_FIELD_GET(GS_BOOTROM_MASK, status);
>>>   -        guc_info(guc, "load failed: status = 0x%08X, ret = %d\n", 
>>> status, ret);
>>> +        guc_info(guc, "load failed: status = 0x%08X, time = %lldms, 
>>> freq = %dMHz, ret = %d\n",
>>> +             status, delta_ms, 
>>> intel_rps_read_actual_frequency(&uncore->gt->rps), ret);
>>>           guc_info(guc, "load failed: status: Reset = %d, BootROM = 
>>> 0x%02X, UKernel = 0x%02X, MIA = 0x%02X, Auth = 0x%02X\n",
>>>                REG_FIELD_GET(GS_MIA_IN_RESET, status),
>>>                bootrom, ukernel,
>>> @@ -206,6 +229,14 @@ static int guc_wait_ucode(struct intel_guc *guc)
>>>           /* Uncommon/unexpected error, see earlier status code 
>>> print for details */
>>>           if (ret == 0)
>>>               ret = -ENXIO;
>>> +    } else if (delta_ms > 200) {
>>> +        guc_warn(guc, "excessive init time: %lldms! [freq = %dMHz, 
>>> before = %dMHz, status = 0x%08X, count = %d, ret = %d]\n",
>>> +             delta_ms, 
>>> intel_rps_read_actual_frequency(&uncore->gt->rps),
>>> +             before_freq, status, count, ret);
>>> +    } else {
>>> +        guc_dbg(guc, "init took %lldms, freq = %dMHz, before = 
>>> %dMHz, status = 0x%08X, count = %d, ret = %d\n",
>>> +            delta_ms, 
>>> intel_rps_read_actual_frequency(&uncore->gt->rps),
>>> +            before_freq, status, count, ret);
>>>       }
>>>         return ret;
>>
>