drm/i915: convert HDCP DRM_ERROR into DRM_DEBUG

Submitted by Ramalingam C on Oct. 25, 2018, 6:17 p.m.

Details

Message ID 1540491472-7649-1-git-send-email-ramalingam.c@intel.com
State New
Headers show
Series "drm/i915: convert HDCP DRM_ERROR into DRM_DEBUG" ( rev: 1 ) in Intel GFX

Not browsing as part of any series.

Commit Message

Ramalingam C Oct. 25, 2018, 6:17 p.m.
Conceptually user should be knowing the feature status through uAPI.
So HDCP authentication failure information need not DRM_ERRORS.
They are needed only for ENG debugging.

And also in HDCP we tolerate the retries for HDCP authentication.
Hence if we print the failure info initial attempts as ERRORs CI will
fail the IGT.

So we present the information of the failures in form of DRM_DEBUG
msgs for debugging purpose.

Signed-off-by: Ramalingam C <ramalingam.c@intel.com>
---
 drivers/gpu/drm/i915/intel_hdcp.c | 46 +++++++++++++++++++--------------------
 1 file changed, 23 insertions(+), 23 deletions(-)

Patch hide | download patch | download mbox

diff --git a/drivers/gpu/drm/i915/intel_hdcp.c b/drivers/gpu/drm/i915/intel_hdcp.c
index 5b423a78518d..d92b04c3ed4e 100644
--- a/drivers/gpu/drm/i915/intel_hdcp.c
+++ b/drivers/gpu/drm/i915/intel_hdcp.c
@@ -166,8 +166,8 @@  static int intel_hdcp_load_keys(struct drm_i915_private *dev_priv)
 					      SKL_PCODE_LOAD_HDCP_KEYS, 1);
 		mutex_unlock(&dev_priv->pcu_lock);
 		if (ret) {
-			DRM_ERROR("Failed to initiate HDCP key load (%d)\n",
-			          ret);
+			DRM_DEBUG_KMS("Failed to initiate HDCP key load (%d)\n",
+				      ret);
 			return ret;
 		}
 	} else {
@@ -195,7 +195,7 @@  static int intel_write_sha_text(struct drm_i915_private *dev_priv, u32 sha_text)
 	I915_WRITE(HDCP_SHA_TEXT, sha_text);
 	if (intel_wait_for_register(dev_priv, HDCP_REP_CTL,
 				    HDCP_SHA1_READY, HDCP_SHA1_READY, 1)) {
-		DRM_ERROR("Timed out waiting for SHA1 ready\n");
+		DRM_DEBUG_KMS("Timed out waiting for SHA1 ready\n");
 		return -ETIMEDOUT;
 	}
 	return 0;
@@ -219,7 +219,7 @@  u32 intel_hdcp_get_repeater_ctl(struct intel_digital_port *intel_dig_port)
 	default:
 		break;
 	}
-	DRM_ERROR("Unknown port %d\n", port);
+	DRM_DEBUG_KMS("Unknown port %d\n", port);
 	return -EINVAL;
 }
 
@@ -448,7 +448,7 @@  int intel_hdcp_auth_downstream(struct intel_digital_port *intel_dig_port,
 
 	ret = intel_hdcp_poll_ksv_fifo(intel_dig_port, shim);
 	if (ret) {
-		DRM_ERROR("KSV list failed to become ready (%d)\n", ret);
+		DRM_DEBUG_KMS("KSV list failed to become ready (%d)\n", ret);
 		return ret;
 	}
 
@@ -458,7 +458,7 @@  int intel_hdcp_auth_downstream(struct intel_digital_port *intel_dig_port,
 
 	if (DRM_HDCP_MAX_DEVICE_EXCEEDED(bstatus[0]) ||
 	    DRM_HDCP_MAX_CASCADE_EXCEEDED(bstatus[1])) {
-		DRM_ERROR("Max Topology Limit Exceeded\n");
+		DRM_DEBUG_KMS("Max Topology Limit Exceeded\n");
 		return -EPERM;
 	}
 
@@ -494,7 +494,7 @@  int intel_hdcp_auth_downstream(struct intel_digital_port *intel_dig_port,
 	}
 
 	if (i == tries) {
-		DRM_ERROR("V Prime validation failed.(%d)\n", ret);
+		DRM_DEBUG_KMS("V Prime validation failed.(%d)\n", ret);
 		goto err;
 	}
 
@@ -543,7 +543,7 @@  static int intel_hdcp_auth(struct intel_digital_port *intel_dig_port,
 		if (ret)
 			return ret;
 		if (!hdcp_capable) {
-			DRM_ERROR("Panel is not HDCP capable\n");
+			DRM_DEBUG_KMS("Panel is not HDCP capable\n");
 			return -EINVAL;
 		}
 	}
@@ -557,7 +557,7 @@  static int intel_hdcp_auth(struct intel_digital_port *intel_dig_port,
 	if (intel_wait_for_register(dev_priv, PORT_HDCP_STATUS(port),
 				    HDCP_STATUS_AN_READY,
 				    HDCP_STATUS_AN_READY, 1)) {
-		DRM_ERROR("Timed out waiting for An\n");
+		DRM_DEBUG_KMS("Timed out waiting for An\n");
 		return -ETIMEDOUT;
 	}
 
@@ -594,7 +594,7 @@  static int intel_hdcp_auth(struct intel_digital_port *intel_dig_port,
 	/* Wait for R0 ready */
 	if (wait_for(I915_READ(PORT_HDCP_STATUS(port)) &
 		     (HDCP_STATUS_R0_READY | HDCP_STATUS_ENC), 1)) {
-		DRM_ERROR("Timed out waiting for R0 ready\n");
+		DRM_DEBUG_KMS("Timed out waiting for R0 ready\n");
 		return -ETIMEDOUT;
 	}
 
@@ -629,15 +629,15 @@  static int intel_hdcp_auth(struct intel_digital_port *intel_dig_port,
 	}
 
 	if (i == tries) {
-		DRM_ERROR("Timed out waiting for Ri prime match (%x)\n",
-			  I915_READ(PORT_HDCP_STATUS(port)));
+		DRM_DEBUG_KMS("Timed out waiting for Ri prime match (%x)\n",
+			      I915_READ(PORT_HDCP_STATUS(port)));
 		return -ETIMEDOUT;
 	}
 
 	/* Wait for encryption confirmation */
 	if (intel_wait_for_register(dev_priv, PORT_HDCP_STATUS(port),
 				    HDCP_STATUS_ENC, HDCP_STATUS_ENC, 20)) {
-		DRM_ERROR("Timed out waiting for encryption\n");
+		DRM_DEBUG_KMS("Timed out waiting for encryption\n");
 		return -ETIMEDOUT;
 	}
 
@@ -666,13 +666,13 @@  static int _intel_hdcp_disable(struct intel_connector *connector)
 	I915_WRITE(PORT_HDCP_CONF(port), 0);
 	if (intel_wait_for_register(dev_priv, PORT_HDCP_STATUS(port), ~0, 0,
 				    20)) {
-		DRM_ERROR("Failed to disable HDCP, timeout clearing status\n");
+		DRM_DEBUG_KMS("Failed to disable HDCP, timeout.\n");
 		return -ETIMEDOUT;
 	}
 
 	ret = connector->hdcp_shim->toggle_signalling(intel_dig_port, false);
 	if (ret) {
-		DRM_ERROR("Failed to disable HDCP signalling\n");
+		DRM_DEBUG_KMS("Failed to disable HDCP signalling\n");
 		return ret;
 	}
 
@@ -689,7 +689,7 @@  static int _intel_hdcp_enable(struct intel_connector *connector)
 		      connector->base.name, connector->base.base.id);
 
 	if (!hdcp_key_loadable(dev_priv)) {
-		DRM_ERROR("HDCP key Load is not possible\n");
+		DRM_DEBUG_KMS("HDCP key Load is not possible\n");
 		return -ENXIO;
 	}
 
@@ -700,7 +700,7 @@  static int _intel_hdcp_enable(struct intel_connector *connector)
 		intel_hdcp_clear_keys(dev_priv);
 	}
 	if (ret) {
-		DRM_ERROR("Could not load HDCP keys, (%d)\n", ret);
+		DRM_DEBUG_KMS("Could not load HDCP keys, (%d)\n", ret);
 		return ret;
 	}
 
@@ -717,7 +717,7 @@  static int _intel_hdcp_enable(struct intel_connector *connector)
 		_intel_hdcp_disable(connector);
 	}
 
-	DRM_ERROR("HDCP authentication failed (%d tries/%d)\n", tries, ret);
+	DRM_DEBUG_KMS("HDCP authentication failed (%d tries/%d)\n", tries, ret);
 	return ret;
 }
 
@@ -871,9 +871,9 @@  int intel_hdcp_check_link(struct intel_connector *connector)
 		goto out;
 
 	if (!(I915_READ(PORT_HDCP_STATUS(port)) & HDCP_STATUS_ENC)) {
-		DRM_ERROR("%s:%d HDCP check failed: link is not encrypted,%x\n",
-			  connector->base.name, connector->base.base.id,
-			  I915_READ(PORT_HDCP_STATUS(port)));
+		DRM_DEBUG_KMS("%s:%d HDCP Link is not encrypted,%x\n",
+			      connector->base.name, connector->base.base.id,
+			      I915_READ(PORT_HDCP_STATUS(port)));
 		ret = -ENXIO;
 		connector->hdcp_value = DRM_MODE_CONTENT_PROTECTION_DESIRED;
 		schedule_work(&connector->hdcp_prop_work);
@@ -895,7 +895,7 @@  int intel_hdcp_check_link(struct intel_connector *connector)
 
 	ret = _intel_hdcp_disable(connector);
 	if (ret) {
-		DRM_ERROR("Failed to disable hdcp (%d)\n", ret);
+		DRM_DEBUG_KMS("Failed to disable hdcp (%d)\n", ret);
 		connector->hdcp_value = DRM_MODE_CONTENT_PROTECTION_DESIRED;
 		schedule_work(&connector->hdcp_prop_work);
 		goto out;
@@ -903,7 +903,7 @@  int intel_hdcp_check_link(struct intel_connector *connector)
 
 	ret = _intel_hdcp_enable(connector);
 	if (ret) {
-		DRM_ERROR("Failed to enable hdcp (%d)\n", ret);
+		DRM_DEBUG_KMS("Failed to enable hdcp (%d)\n", ret);
 		connector->hdcp_value = DRM_MODE_CONTENT_PROTECTION_DESIRED;
 		schedule_work(&connector->hdcp_prop_work);
 		goto out;

Comments

On Thu, Oct 25, 2018 at 11:47:52PM +0530, Ramalingam C wrote:
> Conceptually user should be knowing the feature status through uAPI.
> So HDCP authentication failure information need not DRM_ERRORS.
> They are needed only for ENG debugging.
> 
> And also in HDCP we tolerate the retries for HDCP authentication.
> Hence if we print the failure info initial attempts as ERRORs CI will
> fail the IGT.
> 
> So we present the information of the failures in form of DRM_DEBUG
> msgs for debugging purpose.
> 
> Signed-off-by: Ramalingam C <ramalingam.c@intel.com>
> ---
>  drivers/gpu/drm/i915/intel_hdcp.c | 46 +++++++++++++++++++--------------------
>  1 file changed, 23 insertions(+), 23 deletions(-)
> 
> diff --git a/drivers/gpu/drm/i915/intel_hdcp.c b/drivers/gpu/drm/i915/intel_hdcp.c
> index 5b423a78518d..d92b04c3ed4e 100644
> --- a/drivers/gpu/drm/i915/intel_hdcp.c
> +++ b/drivers/gpu/drm/i915/intel_hdcp.c
> @@ -166,8 +166,8 @@ static int intel_hdcp_load_keys(struct drm_i915_private *dev_priv)
>  					      SKL_PCODE_LOAD_HDCP_KEYS, 1);
>  		mutex_unlock(&dev_priv->pcu_lock);
>  		if (ret) {
> -			DRM_ERROR("Failed to initiate HDCP key load (%d)\n",
> -			          ret);
> +			DRM_DEBUG_KMS("Failed to initiate HDCP key load (%d)\n",
> +				      ret);

This one indicates an i915 hw failure, not anything wrong with the sink.
So should stay at DRM_ERROR.

Btw I noticed that 2 DRM_DEBUG_KMS in intel_hdcp_validate_v_prime also
indicate programming/i915-side hw errors. So should be upgraded to
DRM_ERROR I think (but in a separate patch).

>  			return ret;
>  		}
>  	} else {
> @@ -195,7 +195,7 @@ static int intel_write_sha_text(struct drm_i915_private *dev_priv, u32 sha_text)
>  	I915_WRITE(HDCP_SHA_TEXT, sha_text);
>  	if (intel_wait_for_register(dev_priv, HDCP_REP_CTL,
>  				    HDCP_SHA1_READY, HDCP_SHA1_READY, 1)) {
> -		DRM_ERROR("Timed out waiting for SHA1 ready\n");
> +		DRM_DEBUG_KMS("Timed out waiting for SHA1 ready\n");

Same here.

>  		return -ETIMEDOUT;
>  	}
>  	return 0;
> @@ -219,7 +219,7 @@ u32 intel_hdcp_get_repeater_ctl(struct intel_digital_port *intel_dig_port)
>  	default:
>  		break;
>  	}
> -	DRM_ERROR("Unknown port %d\n", port);
> +	DRM_DEBUG_KMS("Unknown port %d\n", port);

Also a programming error.

>  	return -EINVAL;
>  }
>  
> @@ -448,7 +448,7 @@ int intel_hdcp_auth_downstream(struct intel_digital_port *intel_dig_port,
>  
>  	ret = intel_hdcp_poll_ksv_fifo(intel_dig_port, shim);
>  	if (ret) {
> -		DRM_ERROR("KSV list failed to become ready (%d)\n", ret);
> +		DRM_DEBUG_KMS("KSV list failed to become ready (%d)\n", ret);

This one is a sink issue, so correct to change to DRM_DEBUG_KMS. If I
don't comment, assume that I agree with your change.

>  		return ret;
>  	}
>  
> @@ -458,7 +458,7 @@ int intel_hdcp_auth_downstream(struct intel_digital_port *intel_dig_port,
>  
>  	if (DRM_HDCP_MAX_DEVICE_EXCEEDED(bstatus[0]) ||
>  	    DRM_HDCP_MAX_CASCADE_EXCEEDED(bstatus[1])) {
> -		DRM_ERROR("Max Topology Limit Exceeded\n");
> +		DRM_DEBUG_KMS("Max Topology Limit Exceeded\n");
>  		return -EPERM;
>  	}
>  
> @@ -494,7 +494,7 @@ int intel_hdcp_auth_downstream(struct intel_digital_port *intel_dig_port,
>  	}
>  
>  	if (i == tries) {
> -		DRM_ERROR("V Prime validation failed.(%d)\n", ret);
> +		DRM_DEBUG_KMS("V Prime validation failed.(%d)\n", ret);
>  		goto err;
>  	}
>  
> @@ -543,7 +543,7 @@ static int intel_hdcp_auth(struct intel_digital_port *intel_dig_port,
>  		if (ret)
>  			return ret;
>  		if (!hdcp_capable) {
> -			DRM_ERROR("Panel is not HDCP capable\n");
> +			DRM_DEBUG_KMS("Panel is not HDCP capable\n");
>  			return -EINVAL;
>  		}
>  	}
> @@ -557,7 +557,7 @@ static int intel_hdcp_auth(struct intel_digital_port *intel_dig_port,
>  	if (intel_wait_for_register(dev_priv, PORT_HDCP_STATUS(port),
>  				    HDCP_STATUS_AN_READY,
>  				    HDCP_STATUS_AN_READY, 1)) {
> -		DRM_ERROR("Timed out waiting for An\n");
> +		DRM_DEBUG_KMS("Timed out waiting for An\n");

Again this would indicate an i915 hw issue, so better to keep it at
DRM_ERROR.

>  		return -ETIMEDOUT;
>  	}
>  
> @@ -594,7 +594,7 @@ static int intel_hdcp_auth(struct intel_digital_port *intel_dig_port,
>  	/* Wait for R0 ready */
>  	if (wait_for(I915_READ(PORT_HDCP_STATUS(port)) &
>  		     (HDCP_STATUS_R0_READY | HDCP_STATUS_ENC), 1)) {
> -		DRM_ERROR("Timed out waiting for R0 ready\n");
> +		DRM_DEBUG_KMS("Timed out waiting for R0 ready\n");

Same, all the wait_for and wait_for_register indicate i915-side hw issues,
and should stay at DRM_ERROR. Otherwise we just reduce test coverage.
Please leave all of them as DRM_ERROR.

>  		return -ETIMEDOUT;
>  	}
>  
> @@ -629,15 +629,15 @@ static int intel_hdcp_auth(struct intel_digital_port *intel_dig_port,
>  	}
>  
>  	if (i == tries) {
> -		DRM_ERROR("Timed out waiting for Ri prime match (%x)\n",
> -			  I915_READ(PORT_HDCP_STATUS(port)));
> +		DRM_DEBUG_KMS("Timed out waiting for Ri prime match (%x)\n",
> +			      I915_READ(PORT_HDCP_STATUS(port)));
>  		return -ETIMEDOUT;
>  	}
>  
>  	/* Wait for encryption confirmation */
>  	if (intel_wait_for_register(dev_priv, PORT_HDCP_STATUS(port),
>  				    HDCP_STATUS_ENC, HDCP_STATUS_ENC, 20)) {
> -		DRM_ERROR("Timed out waiting for encryption\n");
> +		DRM_DEBUG_KMS("Timed out waiting for encryption\n");
>  		return -ETIMEDOUT;
>  	}
>  
> @@ -666,13 +666,13 @@ static int _intel_hdcp_disable(struct intel_connector *connector)
>  	I915_WRITE(PORT_HDCP_CONF(port), 0);
>  	if (intel_wait_for_register(dev_priv, PORT_HDCP_STATUS(port), ~0, 0,
>  				    20)) {
> -		DRM_ERROR("Failed to disable HDCP, timeout clearing status\n");
> +		DRM_DEBUG_KMS("Failed to disable HDCP, timeout.\n");
>  		return -ETIMEDOUT;
>  	}
>  
>  	ret = connector->hdcp_shim->toggle_signalling(intel_dig_port, false);
>  	if (ret) {
> -		DRM_ERROR("Failed to disable HDCP signalling\n");
> +		DRM_DEBUG_KMS("Failed to disable HDCP signalling\n");
>  		return ret;
>  	}
>  
> @@ -689,7 +689,7 @@ static int _intel_hdcp_enable(struct intel_connector *connector)
>  		      connector->base.name, connector->base.base.id);
>  
>  	if (!hdcp_key_loadable(dev_priv)) {
> -		DRM_ERROR("HDCP key Load is not possible\n");
> +		DRM_DEBUG_KMS("HDCP key Load is not possible\n");
>  		return -ENXIO;
>  	}
>  
> @@ -700,7 +700,7 @@ static int _intel_hdcp_enable(struct intel_connector *connector)
>  		intel_hdcp_clear_keys(dev_priv);
>  	}
>  	if (ret) {
> -		DRM_ERROR("Could not load HDCP keys, (%d)\n", ret);
> +		DRM_DEBUG_KMS("Could not load HDCP keys, (%d)\n", ret);
>  		return ret;
>  	}
>  
> @@ -717,7 +717,7 @@ static int _intel_hdcp_enable(struct intel_connector *connector)
>  		_intel_hdcp_disable(connector);
>  	}
>  
> -	DRM_ERROR("HDCP authentication failed (%d tries/%d)\n", tries, ret);
> +	DRM_DEBUG_KMS("HDCP authentication failed (%d tries/%d)\n", tries, ret);
>  	return ret;
>  }
>  
> @@ -871,9 +871,9 @@ int intel_hdcp_check_link(struct intel_connector *connector)
>  		goto out;
>  
>  	if (!(I915_READ(PORT_HDCP_STATUS(port)) & HDCP_STATUS_ENC)) {
> -		DRM_ERROR("%s:%d HDCP check failed: link is not encrypted,%x\n",
> -			  connector->base.name, connector->base.base.id,
> -			  I915_READ(PORT_HDCP_STATUS(port)));
> +		DRM_DEBUG_KMS("%s:%d HDCP Link is not encrypted,%x\n",
> +			      connector->base.name, connector->base.base.id,
> +			      I915_READ(PORT_HDCP_STATUS(port)));

Again I think this would indicate an i915 hw issue, let's leave at
DRM_ERROR.

>  		ret = -ENXIO;
>  		connector->hdcp_value = DRM_MODE_CONTENT_PROTECTION_DESIRED;
>  		schedule_work(&connector->hdcp_prop_work);
> @@ -895,7 +895,7 @@ int intel_hdcp_check_link(struct intel_connector *connector)
>  
>  	ret = _intel_hdcp_disable(connector);
>  	if (ret) {
> -		DRM_ERROR("Failed to disable hdcp (%d)\n", ret);
> +		DRM_DEBUG_KMS("Failed to disable hdcp (%d)\n", ret);

Disabling hdcp should always succeeds, again let's leave at DRM_ERROR.

>  		connector->hdcp_value = DRM_MODE_CONTENT_PROTECTION_DESIRED;
>  		schedule_work(&connector->hdcp_prop_work);
>  		goto out;
> @@ -903,7 +903,7 @@ int intel_hdcp_check_link(struct intel_connector *connector)
>  
>  	ret = _intel_hdcp_enable(connector);
>  	if (ret) {
> -		DRM_ERROR("Failed to enable hdcp (%d)\n", ret);
> +		DRM_DEBUG_KMS("Failed to enable hdcp (%d)\n", ret);

Yeah, this can fail when the sink is gone.

When you respin this, can you pls include the added patch to make the 2
debug outputs into DRM_ERROR, and the 4 patches you've identified we can
merge already? I want to make sure CI is still approving of all of them,
now that the kms_content_protection testcase has landed.

Thanks, Daniel

>  		connector->hdcp_value = DRM_MODE_CONTENT_PROTECTION_DESIRED;
>  		schedule_work(&connector->hdcp_prop_work);
>  		goto out;
> -- 
> 2.7.4
>
On Thu, Oct 25, 2018 at 11:47:52PM +0530, Ramalingam C wrote:
> Conceptually user should be knowing the feature status through uAPI.
> So HDCP authentication failure information need not DRM_ERRORS.
> They are needed only for ENG debugging.
> 
> And also in HDCP we tolerate the retries for HDCP authentication.
> Hence if we print the failure info initial attempts as ERRORs CI will
> fail the IGT.
> 
> So we present the information of the failures in form of DRM_DEBUG
> msgs for debugging purpose.

I really don't like this type of change, tbh. When I get field logs from a
customer, I don't have the option to ask them to turn drm.debug on, so I will
never see DRM_DEBUG level messages, breadcrumbs like these are critical.

IMO (and I know I'm fighting a losing battle here), we should replace the flakey
sinks in the CI lab, not run HDCP tests on flakey sinks, or fix the driver to
better accommodate flakey sinks. Please?

One other option is to add a new DEBUG category which is like DEBUG_ERR that we
can enable on our commandline from drm.debug. This option, while nice, would
probably be pretty hard to rollout and police.

Sean

> 
> Signed-off-by: Ramalingam C <ramalingam.c@intel.com>
> ---
>  drivers/gpu/drm/i915/intel_hdcp.c | 46 +++++++++++++++++++--------------------
>  1 file changed, 23 insertions(+), 23 deletions(-)
> 
> diff --git a/drivers/gpu/drm/i915/intel_hdcp.c b/drivers/gpu/drm/i915/intel_hdcp.c
> index 5b423a78518d..d92b04c3ed4e 100644
> --- a/drivers/gpu/drm/i915/intel_hdcp.c
> +++ b/drivers/gpu/drm/i915/intel_hdcp.c
> @@ -166,8 +166,8 @@ static int intel_hdcp_load_keys(struct drm_i915_private *dev_priv)
>  					      SKL_PCODE_LOAD_HDCP_KEYS, 1);
>  		mutex_unlock(&dev_priv->pcu_lock);
>  		if (ret) {
> -			DRM_ERROR("Failed to initiate HDCP key load (%d)\n",
> -			          ret);
> +			DRM_DEBUG_KMS("Failed to initiate HDCP key load (%d)\n",
> +				      ret);
>  			return ret;
>  		}
>  	} else {
> @@ -195,7 +195,7 @@ static int intel_write_sha_text(struct drm_i915_private *dev_priv, u32 sha_text)
>  	I915_WRITE(HDCP_SHA_TEXT, sha_text);
>  	if (intel_wait_for_register(dev_priv, HDCP_REP_CTL,
>  				    HDCP_SHA1_READY, HDCP_SHA1_READY, 1)) {
> -		DRM_ERROR("Timed out waiting for SHA1 ready\n");
> +		DRM_DEBUG_KMS("Timed out waiting for SHA1 ready\n");
>  		return -ETIMEDOUT;
>  	}
>  	return 0;
> @@ -219,7 +219,7 @@ u32 intel_hdcp_get_repeater_ctl(struct intel_digital_port *intel_dig_port)
>  	default:
>  		break;
>  	}
> -	DRM_ERROR("Unknown port %d\n", port);
> +	DRM_DEBUG_KMS("Unknown port %d\n", port);
>  	return -EINVAL;
>  }
>  
> @@ -448,7 +448,7 @@ int intel_hdcp_auth_downstream(struct intel_digital_port *intel_dig_port,
>  
>  	ret = intel_hdcp_poll_ksv_fifo(intel_dig_port, shim);
>  	if (ret) {
> -		DRM_ERROR("KSV list failed to become ready (%d)\n", ret);
> +		DRM_DEBUG_KMS("KSV list failed to become ready (%d)\n", ret);
>  		return ret;
>  	}
>  
> @@ -458,7 +458,7 @@ int intel_hdcp_auth_downstream(struct intel_digital_port *intel_dig_port,
>  
>  	if (DRM_HDCP_MAX_DEVICE_EXCEEDED(bstatus[0]) ||
>  	    DRM_HDCP_MAX_CASCADE_EXCEEDED(bstatus[1])) {
> -		DRM_ERROR("Max Topology Limit Exceeded\n");
> +		DRM_DEBUG_KMS("Max Topology Limit Exceeded\n");
>  		return -EPERM;
>  	}
>  
> @@ -494,7 +494,7 @@ int intel_hdcp_auth_downstream(struct intel_digital_port *intel_dig_port,
>  	}
>  
>  	if (i == tries) {
> -		DRM_ERROR("V Prime validation failed.(%d)\n", ret);
> +		DRM_DEBUG_KMS("V Prime validation failed.(%d)\n", ret);
>  		goto err;
>  	}
>  
> @@ -543,7 +543,7 @@ static int intel_hdcp_auth(struct intel_digital_port *intel_dig_port,
>  		if (ret)
>  			return ret;
>  		if (!hdcp_capable) {
> -			DRM_ERROR("Panel is not HDCP capable\n");
> +			DRM_DEBUG_KMS("Panel is not HDCP capable\n");
>  			return -EINVAL;
>  		}
>  	}
> @@ -557,7 +557,7 @@ static int intel_hdcp_auth(struct intel_digital_port *intel_dig_port,
>  	if (intel_wait_for_register(dev_priv, PORT_HDCP_STATUS(port),
>  				    HDCP_STATUS_AN_READY,
>  				    HDCP_STATUS_AN_READY, 1)) {
> -		DRM_ERROR("Timed out waiting for An\n");
> +		DRM_DEBUG_KMS("Timed out waiting for An\n");
>  		return -ETIMEDOUT;
>  	}
>  
> @@ -594,7 +594,7 @@ static int intel_hdcp_auth(struct intel_digital_port *intel_dig_port,
>  	/* Wait for R0 ready */
>  	if (wait_for(I915_READ(PORT_HDCP_STATUS(port)) &
>  		     (HDCP_STATUS_R0_READY | HDCP_STATUS_ENC), 1)) {
> -		DRM_ERROR("Timed out waiting for R0 ready\n");
> +		DRM_DEBUG_KMS("Timed out waiting for R0 ready\n");
>  		return -ETIMEDOUT;
>  	}
>  
> @@ -629,15 +629,15 @@ static int intel_hdcp_auth(struct intel_digital_port *intel_dig_port,
>  	}
>  
>  	if (i == tries) {
> -		DRM_ERROR("Timed out waiting for Ri prime match (%x)\n",
> -			  I915_READ(PORT_HDCP_STATUS(port)));
> +		DRM_DEBUG_KMS("Timed out waiting for Ri prime match (%x)\n",
> +			      I915_READ(PORT_HDCP_STATUS(port)));
>  		return -ETIMEDOUT;
>  	}
>  
>  	/* Wait for encryption confirmation */
>  	if (intel_wait_for_register(dev_priv, PORT_HDCP_STATUS(port),
>  				    HDCP_STATUS_ENC, HDCP_STATUS_ENC, 20)) {
> -		DRM_ERROR("Timed out waiting for encryption\n");
> +		DRM_DEBUG_KMS("Timed out waiting for encryption\n");
>  		return -ETIMEDOUT;
>  	}
>  
> @@ -666,13 +666,13 @@ static int _intel_hdcp_disable(struct intel_connector *connector)
>  	I915_WRITE(PORT_HDCP_CONF(port), 0);
>  	if (intel_wait_for_register(dev_priv, PORT_HDCP_STATUS(port), ~0, 0,
>  				    20)) {
> -		DRM_ERROR("Failed to disable HDCP, timeout clearing status\n");
> +		DRM_DEBUG_KMS("Failed to disable HDCP, timeout.\n");
>  		return -ETIMEDOUT;
>  	}
>  
>  	ret = connector->hdcp_shim->toggle_signalling(intel_dig_port, false);
>  	if (ret) {
> -		DRM_ERROR("Failed to disable HDCP signalling\n");
> +		DRM_DEBUG_KMS("Failed to disable HDCP signalling\n");
>  		return ret;
>  	}
>  
> @@ -689,7 +689,7 @@ static int _intel_hdcp_enable(struct intel_connector *connector)
>  		      connector->base.name, connector->base.base.id);
>  
>  	if (!hdcp_key_loadable(dev_priv)) {
> -		DRM_ERROR("HDCP key Load is not possible\n");
> +		DRM_DEBUG_KMS("HDCP key Load is not possible\n");
>  		return -ENXIO;
>  	}
>  
> @@ -700,7 +700,7 @@ static int _intel_hdcp_enable(struct intel_connector *connector)
>  		intel_hdcp_clear_keys(dev_priv);
>  	}
>  	if (ret) {
> -		DRM_ERROR("Could not load HDCP keys, (%d)\n", ret);
> +		DRM_DEBUG_KMS("Could not load HDCP keys, (%d)\n", ret);
>  		return ret;
>  	}
>  
> @@ -717,7 +717,7 @@ static int _intel_hdcp_enable(struct intel_connector *connector)
>  		_intel_hdcp_disable(connector);
>  	}
>  
> -	DRM_ERROR("HDCP authentication failed (%d tries/%d)\n", tries, ret);
> +	DRM_DEBUG_KMS("HDCP authentication failed (%d tries/%d)\n", tries, ret);
>  	return ret;
>  }
>  
> @@ -871,9 +871,9 @@ int intel_hdcp_check_link(struct intel_connector *connector)
>  		goto out;
>  
>  	if (!(I915_READ(PORT_HDCP_STATUS(port)) & HDCP_STATUS_ENC)) {
> -		DRM_ERROR("%s:%d HDCP check failed: link is not encrypted,%x\n",
> -			  connector->base.name, connector->base.base.id,
> -			  I915_READ(PORT_HDCP_STATUS(port)));
> +		DRM_DEBUG_KMS("%s:%d HDCP Link is not encrypted,%x\n",
> +			      connector->base.name, connector->base.base.id,
> +			      I915_READ(PORT_HDCP_STATUS(port)));
>  		ret = -ENXIO;
>  		connector->hdcp_value = DRM_MODE_CONTENT_PROTECTION_DESIRED;
>  		schedule_work(&connector->hdcp_prop_work);
> @@ -895,7 +895,7 @@ int intel_hdcp_check_link(struct intel_connector *connector)
>  
>  	ret = _intel_hdcp_disable(connector);
>  	if (ret) {
> -		DRM_ERROR("Failed to disable hdcp (%d)\n", ret);
> +		DRM_DEBUG_KMS("Failed to disable hdcp (%d)\n", ret);
>  		connector->hdcp_value = DRM_MODE_CONTENT_PROTECTION_DESIRED;
>  		schedule_work(&connector->hdcp_prop_work);
>  		goto out;
> @@ -903,7 +903,7 @@ int intel_hdcp_check_link(struct intel_connector *connector)
>  
>  	ret = _intel_hdcp_enable(connector);
>  	if (ret) {
> -		DRM_ERROR("Failed to enable hdcp (%d)\n", ret);
> +		DRM_DEBUG_KMS("Failed to enable hdcp (%d)\n", ret);
>  		connector->hdcp_value = DRM_MODE_CONTENT_PROTECTION_DESIRED;
>  		schedule_work(&connector->hdcp_prop_work);
>  		goto out;
> -- 
> 2.7.4
> 
> _______________________________________________
> Intel-gfx mailing list
> Intel-gfx@lists.freedesktop.org
> https://lists.freedesktop.org/mailman/listinfo/intel-gfx
So basically we want all logs related to HW failure and I915 programing should be errors whereas all sink specific errors in debug level.
I will prepare the change.

danvet, seanpaul has discussed few points about convenience of debugging on customer platforms. What is the take on it?

--Ram

On 10/26/2018 5:09 PM, Daniel Vetter wrote:
> On Thu, Oct 25, 2018 at 11:47:52PM +0530, Ramalingam C wrote:
>> Conceptually user should be knowing the feature status through uAPI.
>> So HDCP authentication failure information need not DRM_ERRORS.
>> They are needed only for ENG debugging.
>>
>> And also in HDCP we tolerate the retries for HDCP authentication.
>> Hence if we print the failure info initial attempts as ERRORs CI will
>> fail the IGT.
>>
>> So we present the information of the failures in form of DRM_DEBUG
>> msgs for debugging purpose.
>>
>> Signed-off-by: Ramalingam C <ramalingam.c@intel.com>
>> ---
>>   drivers/gpu/drm/i915/intel_hdcp.c | 46 +++++++++++++++++++--------------------
>>   1 file changed, 23 insertions(+), 23 deletions(-)
>>
>> diff --git a/drivers/gpu/drm/i915/intel_hdcp.c b/drivers/gpu/drm/i915/intel_hdcp.c
>> index 5b423a78518d..d92b04c3ed4e 100644
>> --- a/drivers/gpu/drm/i915/intel_hdcp.c
>> +++ b/drivers/gpu/drm/i915/intel_hdcp.c
>> @@ -166,8 +166,8 @@ static int intel_hdcp_load_keys(struct drm_i915_private *dev_priv)
>>   					      SKL_PCODE_LOAD_HDCP_KEYS, 1);
>>   		mutex_unlock(&dev_priv->pcu_lock);
>>   		if (ret) {
>> -			DRM_ERROR("Failed to initiate HDCP key load (%d)\n",
>> -			          ret);
>> +			DRM_DEBUG_KMS("Failed to initiate HDCP key load (%d)\n",
>> +				      ret);
> This one indicates an i915 hw failure, not anything wrong with the sink.
> So should stay at DRM_ERROR.
>
> Btw I noticed that 2 DRM_DEBUG_KMS in intel_hdcp_validate_v_prime also
> indicate programming/i915-side hw errors. So should be upgraded to
> DRM_ERROR I think (but in a separate patch).
>
>>   			return ret;
>>   		}
>>   	} else {
>> @@ -195,7 +195,7 @@ static int intel_write_sha_text(struct drm_i915_private *dev_priv, u32 sha_text)
>>   	I915_WRITE(HDCP_SHA_TEXT, sha_text);
>>   	if (intel_wait_for_register(dev_priv, HDCP_REP_CTL,
>>   				    HDCP_SHA1_READY, HDCP_SHA1_READY, 1)) {
>> -		DRM_ERROR("Timed out waiting for SHA1 ready\n");
>> +		DRM_DEBUG_KMS("Timed out waiting for SHA1 ready\n");
> Same here.
>
>>   		return -ETIMEDOUT;
>>   	}
>>   	return 0;
>> @@ -219,7 +219,7 @@ u32 intel_hdcp_get_repeater_ctl(struct intel_digital_port *intel_dig_port)
>>   	default:
>>   		break;
>>   	}
>> -	DRM_ERROR("Unknown port %d\n", port);
>> +	DRM_DEBUG_KMS("Unknown port %d\n", port);
> Also a programming error.
>
>>   	return -EINVAL;
>>   }
>>   
>> @@ -448,7 +448,7 @@ int intel_hdcp_auth_downstream(struct intel_digital_port *intel_dig_port,
>>   
>>   	ret = intel_hdcp_poll_ksv_fifo(intel_dig_port, shim);
>>   	if (ret) {
>> -		DRM_ERROR("KSV list failed to become ready (%d)\n", ret);
>> +		DRM_DEBUG_KMS("KSV list failed to become ready (%d)\n", ret);
> This one is a sink issue, so correct to change to DRM_DEBUG_KMS. If I
> don't comment, assume that I agree with your change.
>
>>   		return ret;
>>   	}
>>   
>> @@ -458,7 +458,7 @@ int intel_hdcp_auth_downstream(struct intel_digital_port *intel_dig_port,
>>   
>>   	if (DRM_HDCP_MAX_DEVICE_EXCEEDED(bstatus[0]) ||
>>   	    DRM_HDCP_MAX_CASCADE_EXCEEDED(bstatus[1])) {
>> -		DRM_ERROR("Max Topology Limit Exceeded\n");
>> +		DRM_DEBUG_KMS("Max Topology Limit Exceeded\n");
>>   		return -EPERM;
>>   	}
>>   
>> @@ -494,7 +494,7 @@ int intel_hdcp_auth_downstream(struct intel_digital_port *intel_dig_port,
>>   	}
>>   
>>   	if (i == tries) {
>> -		DRM_ERROR("V Prime validation failed.(%d)\n", ret);
>> +		DRM_DEBUG_KMS("V Prime validation failed.(%d)\n", ret);
>>   		goto err;
>>   	}
>>   
>> @@ -543,7 +543,7 @@ static int intel_hdcp_auth(struct intel_digital_port *intel_dig_port,
>>   		if (ret)
>>   			return ret;
>>   		if (!hdcp_capable) {
>> -			DRM_ERROR("Panel is not HDCP capable\n");
>> +			DRM_DEBUG_KMS("Panel is not HDCP capable\n");
>>   			return -EINVAL;
>>   		}
>>   	}
>> @@ -557,7 +557,7 @@ static int intel_hdcp_auth(struct intel_digital_port *intel_dig_port,
>>   	if (intel_wait_for_register(dev_priv, PORT_HDCP_STATUS(port),
>>   				    HDCP_STATUS_AN_READY,
>>   				    HDCP_STATUS_AN_READY, 1)) {
>> -		DRM_ERROR("Timed out waiting for An\n");
>> +		DRM_DEBUG_KMS("Timed out waiting for An\n");
> Again this would indicate an i915 hw issue, so better to keep it at
> DRM_ERROR.
>
>>   		return -ETIMEDOUT;
>>   	}
>>   
>> @@ -594,7 +594,7 @@ static int intel_hdcp_auth(struct intel_digital_port *intel_dig_port,
>>   	/* Wait for R0 ready */
>>   	if (wait_for(I915_READ(PORT_HDCP_STATUS(port)) &
>>   		     (HDCP_STATUS_R0_READY | HDCP_STATUS_ENC), 1)) {
>> -		DRM_ERROR("Timed out waiting for R0 ready\n");
>> +		DRM_DEBUG_KMS("Timed out waiting for R0 ready\n");
> Same, all the wait_for and wait_for_register indicate i915-side hw issues,
> and should stay at DRM_ERROR. Otherwise we just reduce test coverage.
> Please leave all of them as DRM_ERROR.
>
>>   		return -ETIMEDOUT;
>>   	}
>>   
>> @@ -629,15 +629,15 @@ static int intel_hdcp_auth(struct intel_digital_port *intel_dig_port,
>>   	}
>>   
>>   	if (i == tries) {
>> -		DRM_ERROR("Timed out waiting for Ri prime match (%x)\n",
>> -			  I915_READ(PORT_HDCP_STATUS(port)));
>> +		DRM_DEBUG_KMS("Timed out waiting for Ri prime match (%x)\n",
>> +			      I915_READ(PORT_HDCP_STATUS(port)));
>>   		return -ETIMEDOUT;
>>   	}
>>   
>>   	/* Wait for encryption confirmation */
>>   	if (intel_wait_for_register(dev_priv, PORT_HDCP_STATUS(port),
>>   				    HDCP_STATUS_ENC, HDCP_STATUS_ENC, 20)) {
>> -		DRM_ERROR("Timed out waiting for encryption\n");
>> +		DRM_DEBUG_KMS("Timed out waiting for encryption\n");
>>   		return -ETIMEDOUT;
>>   	}
>>   
>> @@ -666,13 +666,13 @@ static int _intel_hdcp_disable(struct intel_connector *connector)
>>   	I915_WRITE(PORT_HDCP_CONF(port), 0);
>>   	if (intel_wait_for_register(dev_priv, PORT_HDCP_STATUS(port), ~0, 0,
>>   				    20)) {
>> -		DRM_ERROR("Failed to disable HDCP, timeout clearing status\n");
>> +		DRM_DEBUG_KMS("Failed to disable HDCP, timeout.\n");
>>   		return -ETIMEDOUT;
>>   	}
>>   
>>   	ret = connector->hdcp_shim->toggle_signalling(intel_dig_port, false);
>>   	if (ret) {
>> -		DRM_ERROR("Failed to disable HDCP signalling\n");
>> +		DRM_DEBUG_KMS("Failed to disable HDCP signalling\n");
>>   		return ret;
>>   	}
>>   
>> @@ -689,7 +689,7 @@ static int _intel_hdcp_enable(struct intel_connector *connector)
>>   		      connector->base.name, connector->base.base.id);
>>   
>>   	if (!hdcp_key_loadable(dev_priv)) {
>> -		DRM_ERROR("HDCP key Load is not possible\n");
>> +		DRM_DEBUG_KMS("HDCP key Load is not possible\n");
>>   		return -ENXIO;
>>   	}
>>   
>> @@ -700,7 +700,7 @@ static int _intel_hdcp_enable(struct intel_connector *connector)
>>   		intel_hdcp_clear_keys(dev_priv);
>>   	}
>>   	if (ret) {
>> -		DRM_ERROR("Could not load HDCP keys, (%d)\n", ret);
>> +		DRM_DEBUG_KMS("Could not load HDCP keys, (%d)\n", ret);
>>   		return ret;
>>   	}
>>   
>> @@ -717,7 +717,7 @@ static int _intel_hdcp_enable(struct intel_connector *connector)
>>   		_intel_hdcp_disable(connector);
>>   	}
>>   
>> -	DRM_ERROR("HDCP authentication failed (%d tries/%d)\n", tries, ret);
>> +	DRM_DEBUG_KMS("HDCP authentication failed (%d tries/%d)\n", tries, ret);
>>   	return ret;
>>   }
>>   
>> @@ -871,9 +871,9 @@ int intel_hdcp_check_link(struct intel_connector *connector)
>>   		goto out;
>>   
>>   	if (!(I915_READ(PORT_HDCP_STATUS(port)) & HDCP_STATUS_ENC)) {
>> -		DRM_ERROR("%s:%d HDCP check failed: link is not encrypted,%x\n",
>> -			  connector->base.name, connector->base.base.id,
>> -			  I915_READ(PORT_HDCP_STATUS(port)));
>> +		DRM_DEBUG_KMS("%s:%d HDCP Link is not encrypted,%x\n",
>> +			      connector->base.name, connector->base.base.id,
>> +			      I915_READ(PORT_HDCP_STATUS(port)));
> Again I think this would indicate an i915 hw issue, let's leave at
> DRM_ERROR.
>
>>   		ret = -ENXIO;
>>   		connector->hdcp_value = DRM_MODE_CONTENT_PROTECTION_DESIRED;
>>   		schedule_work(&connector->hdcp_prop_work);
>> @@ -895,7 +895,7 @@ int intel_hdcp_check_link(struct intel_connector *connector)
>>   
>>   	ret = _intel_hdcp_disable(connector);
>>   	if (ret) {
>> -		DRM_ERROR("Failed to disable hdcp (%d)\n", ret);
>> +		DRM_DEBUG_KMS("Failed to disable hdcp (%d)\n", ret);
> Disabling hdcp should always succeeds, again let's leave at DRM_ERROR.
>
>>   		connector->hdcp_value = DRM_MODE_CONTENT_PROTECTION_DESIRED;
>>   		schedule_work(&connector->hdcp_prop_work);
>>   		goto out;
>> @@ -903,7 +903,7 @@ int intel_hdcp_check_link(struct intel_connector *connector)
>>   
>>   	ret = _intel_hdcp_enable(connector);
>>   	if (ret) {
>> -		DRM_ERROR("Failed to enable hdcp (%d)\n", ret);
>> +		DRM_DEBUG_KMS("Failed to enable hdcp (%d)\n", ret);
> Yeah, this can fail when the sink is gone.
>
> When you respin this, can you pls include the added patch to make the 2
> debug outputs into DRM_ERROR, and the 4 patches you've identified we can
> merge already? I want to make sure CI is still approving of all of them,
> now that the kms_content_protection testcase has landed.
>
> Thanks, Daniel
>
>>   		connector->hdcp_value = DRM_MODE_CONTENT_PROTECTION_DESIRED;
>>   		schedule_work(&connector->hdcp_prop_work);
>>   		goto out;
>> -- 
>> 2.7.4
>>