[PATCH v2] tpm: Replace WARN_ONCE() with dev_err_once() in tpm_tis_status()

[PATCH v2] tpm: Replace WARN_ONCE() with dev_err_once() in tpm_tis_status()

[Jarkko Sakkinen]

Do not torn down the system when getting invalid status from a TPM chip.
This can happen when panic-on-warn is used.

In addition, print out the value of TPM_STS.x instead of "invalid
status". In order to get the earlier benefits for forensics, also call
dump_stack().

Link: https://lore.kernel.org/keyrings/YKzlTR1AzUigShtZ@kroah.com/
Fixes: 55707d531af6 ("tpm_tis: Add a check for invalid status")
Cc: stable@vger.kernel.org
Cc: Hans de Goede <hdegoede@redhat.com>
Cc: Greg KH <greg@kroah.com>
Signed-off-by: Jarkko Sakkinen <jarkko@kernel.org>
---

v2:
Dump also stack only once.

 drivers/char/tpm/tpm_tis_core.c | 28 ++++++++++++++++++++--------
 1 file changed, 20 insertions(+), 8 deletions(-)

diff --git a/drivers/char/tpm/tpm_tis_core.c b/drivers/char/tpm/tpm_tis_core.c
index 55b9d3965ae1..ce410f19eff2 100644
--- a/drivers/char/tpm/tpm_tis_core.c
+++ b/drivers/char/tpm/tpm_tis_core.c
@@ -188,21 +188,33 @@ static int request_locality(struct tpm_chip *chip, int l)
 static u8 tpm_tis_status(struct tpm_chip *chip)
 {
 	struct tpm_tis_data *priv = dev_get_drvdata(&chip->dev);
-	int rc;
+	static unsigned long klog_once;
 	u8 status;
+	int rc;
 
 	rc = tpm_tis_read8(priv, TPM_STS(priv->locality), &status);
 	if (rc < 0)
 		return 0;
 
 	if (unlikely((status & TPM_STS_READ_ZERO) != 0)) {
-		/*
-		 * If this trips, the chances are the read is
-		 * returning 0xff because the locality hasn't been
-		 * acquired.  Usually because tpm_try_get_ops() hasn't
-		 * been called before doing a TPM operation.
-		 */
-		WARN_ONCE(1, "TPM returned invalid status\n");
+		if  (!test_and_set_bit(BIT(0), &klog_once)) {
+			/*
+			 * If this trips, the chances are the read is
+			 * returning 0xff because the locality hasn't been
+			 * acquired.  Usually because tpm_try_get_ops() hasn't
+			 * been called before doing a TPM operation.
+			 */
+			dev_err(&chip->dev, "invalid TPM_STS.x 0x%02x, dumping stack for forensics\n",
+				status);
+
+			/*
+			 * Dump stack for forensics, as invalid TPM_STS.x could be
+			 * potentially triggered by impaired tpm_try_get_ops() or
+			 * tpm_find_get_ops().
+			 */
+			dump_stack();
+		}
+
 		return 0;
 	}
 
-- 
2.31.1

Re: [PATCH v2] tpm: Replace WARN_ONCE() with dev_err_once() in tpm_tis_status()

[Greg KH]

On Mon, May 31, 2021 at 08:34:27AM +0300, Jarkko Sakkinen wrote:
> Do not torn down the system when getting invalid status from a TPM chip.
> This can happen when panic-on-warn is used.
> 
> In addition, print out the value of TPM_STS.x instead of "invalid
> status". In order to get the earlier benefits for forensics, also call
> dump_stack().
> 
> Link: https://lore.kernel.org/keyrings/YKzlTR1AzUigShtZ@kroah.com/
> Fixes: 55707d531af6 ("tpm_tis: Add a check for invalid status")
> Cc: stable@vger.kernel.org
> Cc: Hans de Goede <hdegoede@redhat.com>
> Cc: Greg KH <greg@kroah.com>
> Signed-off-by: Jarkko Sakkinen <jarkko@kernel.org>
> ---
> 
> v2:
> Dump also stack only once.

Huh?

> 
>  drivers/char/tpm/tpm_tis_core.c | 28 ++++++++++++++++++++--------
>  1 file changed, 20 insertions(+), 8 deletions(-)
> 
> diff --git a/drivers/char/tpm/tpm_tis_core.c b/drivers/char/tpm/tpm_tis_core.c
> index 55b9d3965ae1..ce410f19eff2 100644
> --- a/drivers/char/tpm/tpm_tis_core.c
> +++ b/drivers/char/tpm/tpm_tis_core.c
> @@ -188,21 +188,33 @@ static int request_locality(struct tpm_chip *chip, int l)
>  static u8 tpm_tis_status(struct tpm_chip *chip)
>  {
>  	struct tpm_tis_data *priv = dev_get_drvdata(&chip->dev);
> -	int rc;
> +	static unsigned long klog_once;
>  	u8 status;
> +	int rc;
>  
>  	rc = tpm_tis_read8(priv, TPM_STS(priv->locality), &status);
>  	if (rc < 0)
>  		return 0;
>  
>  	if (unlikely((status & TPM_STS_READ_ZERO) != 0)) {
> -		/*
> -		 * If this trips, the chances are the read is
> -		 * returning 0xff because the locality hasn't been
> -		 * acquired.  Usually because tpm_try_get_ops() hasn't
> -		 * been called before doing a TPM operation.
> -		 */
> -		WARN_ONCE(1, "TPM returned invalid status\n");
> +		if  (!test_and_set_bit(BIT(0), &klog_once)) {

Odd whitespace...

Anyway, why?  Isn't this what the ratelimit stuff should give you?  How
badly is this being tripped so much so that you need to only do this
once per entire system and not per-device?

thanks,

greg k-h

Re: [PATCH v2] tpm: Replace WARN_ONCE() with dev_err_once() in tpm_tis_status()

[Jarkko Sakkinen]

On Mon, May 31, 2021 at 07:50:41AM +0200, Greg KH wrote:
> On Mon, May 31, 2021 at 08:34:27AM +0300, Jarkko Sakkinen wrote:
> > Do not torn down the system when getting invalid status from a TPM chip.
> > This can happen when panic-on-warn is used.
> > 
> > In addition, print out the value of TPM_STS.x instead of "invalid
> > status". In order to get the earlier benefits for forensics, also call
> > dump_stack().
> > 
> > Link: https://lore.kernel.org/keyrings/YKzlTR1AzUigShtZ@kroah.com/
> > Fixes: 55707d531af6 ("tpm_tis: Add a check for invalid status")
> > Cc: stable@vger.kernel.org
> > Cc: Hans de Goede <hdegoede@redhat.com>
> > Cc: Greg KH <greg@kroah.com>
> > Signed-off-by: Jarkko Sakkinen <jarkko@kernel.org>
> > ---
> > 
> > v2:
> > Dump also stack only once.
> 
> Huh?
> 
> > 
> >  drivers/char/tpm/tpm_tis_core.c | 28 ++++++++++++++++++++--------
> >  1 file changed, 20 insertions(+), 8 deletions(-)
> > 
> > diff --git a/drivers/char/tpm/tpm_tis_core.c b/drivers/char/tpm/tpm_tis_core.c
> > index 55b9d3965ae1..ce410f19eff2 100644
> > --- a/drivers/char/tpm/tpm_tis_core.c
> > +++ b/drivers/char/tpm/tpm_tis_core.c
> > @@ -188,21 +188,33 @@ static int request_locality(struct tpm_chip *chip, int l)
> >  static u8 tpm_tis_status(struct tpm_chip *chip)
> >  {
> >  	struct tpm_tis_data *priv = dev_get_drvdata(&chip->dev);
> > -	int rc;
> > +	static unsigned long klog_once;
> >  	u8 status;
> > +	int rc;
> >  
> >  	rc = tpm_tis_read8(priv, TPM_STS(priv->locality), &status);
> >  	if (rc < 0)
> >  		return 0;
> >  
> >  	if (unlikely((status & TPM_STS_READ_ZERO) != 0)) {
> > -		/*
> > -		 * If this trips, the chances are the read is
> > -		 * returning 0xff because the locality hasn't been
> > -		 * acquired.  Usually because tpm_try_get_ops() hasn't
> > -		 * been called before doing a TPM operation.
> > -		 */
> > -		WARN_ONCE(1, "TPM returned invalid status\n");
> > +		if  (!test_and_set_bit(BIT(0), &klog_once)) {
> 
> Odd whitespace...
> 
> Anyway, why?  Isn't this what the ratelimit stuff should give you?  How
> badly is this being tripped so much so that you need to only do this
> once per entire system and not per-device?

The problem with "v1" was that the message was printed once, but the
dump_stack() was called however many times. And ratelimited stuff is
afaik only for printk's, there's no ratelimited dump_stack().

What you're saying makes sense tho. It would be sane behaviour to do
this once-per-device, instead of just once.

Since struct tpm_chip already has a bitmask flags, I'll just add a
TPM_CHIP_FLAG_INVALID_STATUS, and:

        if (test_and_set_bit(TPM_CHIP_FLAG_INVALID_STATUS, &chip->flags)) {
                /* ... */

> thanks,
> 
> greg k-h

Thank you.

/Jarkko