[PATCH v4 0/2] ibmvtpm: Avoid error message when process gets signal while waiting

From: Stefan Berger <stefanb@linux.ibm.com>

This series of patches fixes an issue related to the ibmvtpm driver causing
unnecessary kernel log messages when a process is interrupted while waiting
for the TPM to respond. The aborted wait causes the core TPM driver to emit
the log message. The solution is to convert the driver to use the normal
polling loop to wait for TPM responses.

   Stefan

v4:
 - Reverted order of patches

v3:
 - Split into two patches

Stefan Berger (2):
  tpm: ibmvtpm: Avoid error message when process gets signal while
    waiting
  tpm: ibmvtpm: Rename tpm_process_cmd to tpm_status and define flag

 drivers/char/tpm/tpm_ibmvtpm.c | 31 ++++++++++++++++++-------------
 drivers/char/tpm/tpm_ibmvtpm.h |  3 ++-
 2 files changed, 20 insertions(+), 14 deletions(-)

-- 
2.31.1

From: Stefan Berger <stefanb@linux.ibm.com>

Rename the field tpm_processing_cmd to tpm_status in ibmvtpm_dev and set
the TPM_STATUS_BUSY flag while the vTPM is busy processing a command.

Signed-off-by: Stefan Berger <stefanb@linux.ibm.com>
Cc: Nayna Jain <nayna@linux.ibm.com>
Cc: George Wilson <redacted>
---
 drivers/char/tpm/tpm_ibmvtpm.c | 15 ++++++++-------
 drivers/char/tpm/tpm_ibmvtpm.h |  3 ++-
 2 files changed, 10 insertions(+), 8 deletions(-)

diff --git a/drivers/char/tpm/tpm_ibmvtpm.c b/drivers/char/tpm/tpm_ibmvtpm.c
index 7a9eca5768f8..5d795866b483 100644
--- a/drivers/char/tpm/tpm_ibmvtpm.c
+++ b/drivers/char/tpm/tpm_ibmvtpm.c

@@ -215,11 +215,12 @@ static int tpm_ibmvtpm_send(struct tpm_chip *chip, u8 *buf, size_t count)
 		return -EIO;
 	}
 
-	if (ibmvtpm->tpm_processing_cmd) {
+	if ((ibmvtpm->tpm_status & TPM_STATUS_BUSY)) {
 		dev_info(ibmvtpm->dev,
 		         "Need to wait for TPM to finish\n");
 		/* wait for previous command to finish */
-		sig = wait_event_interruptible(ibmvtpm->wq, !ibmvtpm->tpm_processing_cmd);
+		sig = wait_event_interruptible(ibmvtpm->wq,
+				(ibmvtpm->tpm_status & TPM_STATUS_BUSY) == 0);
 		if (sig)
 			return -EINTR;
 	}

@@ -232,7 +233,7 @@ static int tpm_ibmvtpm_send(struct tpm_chip *chip, u8 *buf, size_t count)
 	 * set the processing flag before the Hcall, since we may get the
 	 * result (interrupt) before even being able to check rc.
 	 */
-	ibmvtpm->tpm_processing_cmd = true;
+	ibmvtpm->tpm_status |= TPM_STATUS_BUSY;
 
 again:
 	rc = ibmvtpm_send_crq(ibmvtpm->vdev,

@@ -250,7 +251,7 @@ static int tpm_ibmvtpm_send(struct tpm_chip *chip, u8 *buf, size_t count)
 			goto again;
 		}
 		dev_err(ibmvtpm->dev, "tpm_ibmvtpm_send failed rc=%d\n", rc);
-		ibmvtpm->tpm_processing_cmd = false;
+		ibmvtpm->tpm_status &= ~TPM_STATUS_BUSY;
 	}
 
 	spin_unlock(&ibmvtpm->rtce_lock);

@@ -266,7 +267,7 @@ static u8 tpm_ibmvtpm_status(struct tpm_chip *chip)
 {
 	struct ibmvtpm_dev *ibmvtpm = dev_get_drvdata(&chip->dev);
 
-	return ibmvtpm->tpm_processing_cmd;
+	return ibmvtpm->tpm_status;
 }
 
 /**

@@ -454,7 +455,7 @@ static const struct tpm_class_ops tpm_ibmvtpm = {
 	.send = tpm_ibmvtpm_send,
 	.cancel = tpm_ibmvtpm_cancel,
 	.status = tpm_ibmvtpm_status,
-	.req_complete_mask = true,
+	.req_complete_mask = TPM_STATUS_BUSY,
 	.req_complete_val = 0,
 	.req_canceled = tpm_ibmvtpm_req_canceled,
 };

@@ -547,7 +548,7 @@ static void ibmvtpm_crq_process(struct ibmvtpm_crq *crq,
 		case VTPM_TPM_COMMAND_RES:
 			/* len of the data in rtce buffer */
 			ibmvtpm->res_len = be16_to_cpu(crq->len);
-			ibmvtpm->tpm_processing_cmd = false;
+			ibmvtpm->tpm_status &= ~TPM_STATUS_BUSY;
 			wake_up_interruptible(&ibmvtpm->wq);
 			return;
 		default:

diff --git a/drivers/char/tpm/tpm_ibmvtpm.h b/drivers/char/tpm/tpm_ibmvtpm.h
index 51198b137461..252f1cccdfc5 100644
--- a/drivers/char/tpm/tpm_ibmvtpm.h
+++ b/drivers/char/tpm/tpm_ibmvtpm.h

@@ -41,7 +41,8 @@ struct ibmvtpm_dev {
 	wait_queue_head_t wq;
 	u16 res_len;
 	u32 vtpm_version;
-	u8 tpm_processing_cmd;
+	u8 tpm_status;
+#define TPM_STATUS_BUSY		(1 << 0) /* vtpm is processing a command */
 };
 
 #define CRQ_RES_BUF_SIZE	PAGE_SIZE

-- 
2.31.1

On Mon, Aug 09, 2021 at 03:21:59PM -0400, Stefan Berger wrote:

Declare this already in the fix, and just leave the rename here.

 };
 
 #define CRQ_RES_BUF_SIZE	PAGE_SIZE
-- 
2.31.1

Otherwise, these look fine.

/Jarkko

On 8/10/21 1:58 PM, Jarkko Sakkinen wrote:

On Mon, Aug 09, 2021 at 03:21:59PM -0400, Stefan Berger wrote:

quoted

From: Stefan Berger <stefanb@linux.ibm.com>

Rename the field tpm_processing_cmd to tpm_status in ibmvtpm_dev and set
the TPM_STATUS_BUSY flag while the vTPM is busy processing a command.


  		default:

diff --git a/drivers/char/tpm/tpm_ibmvtpm.h b/drivers/char/tpm/tpm_ibmvtpm.h
index 51198b137461..252f1cccdfc5 100644
--- a/drivers/char/tpm/tpm_ibmvtpm.h
+++ b/drivers/char/tpm/tpm_ibmvtpm.h

@@ -41,7 +41,8 @@ struct ibmvtpm_dev {
  	wait_queue_head_t wq;
  	u16 res_len;
  	u32 vtpm_version;
-	u8 tpm_processing_cmd;
+	u8 tpm_status;
+#define TPM_STATUS_BUSY		(1 << 0) /* vtpm is processing a command */

Declare this already in the fix, and just leave the rename here.

You mean the fix patch does not use 'true' anymore but uses the 
TPM_STATUS_BUSY flag already but the name is still tpm_processing_cmd? 
And literally only the renaming of this field is done in the 2nd patch?


    Stefan

quoted

  };
  
  #define CRQ_RES_BUF_SIZE	PAGE_SIZE
-- 
2.31.1

Otherwise, these look fine.

/Jarkko

On Tue, Aug 10, 2021 at 09:50:55PM -0400, Stefan Berger wrote:

On 8/10/21 1:58 PM, Jarkko Sakkinen wrote:

quoted

On Mon, Aug 09, 2021 at 03:21:59PM -0400, Stefan Berger wrote:

quoted

From: Stefan Berger <stefanb@linux.ibm.com>

Rename the field tpm_processing_cmd to tpm_status in ibmvtpm_dev and set
the TPM_STATUS_BUSY flag while the vTPM is busy processing a command.


  		default:

diff --git a/drivers/char/tpm/tpm_ibmvtpm.h b/drivers/char/tpm/tpm_ibmvtpm.h
index 51198b137461..252f1cccdfc5 100644
--- a/drivers/char/tpm/tpm_ibmvtpm.h
+++ b/drivers/char/tpm/tpm_ibmvtpm.h

@@ -41,7 +41,8 @@ struct ibmvtpm_dev {
  	wait_queue_head_t wq;
  	u16 res_len;
  	u32 vtpm_version;
-	u8 tpm_processing_cmd;
+	u8 tpm_status;
+#define TPM_STATUS_BUSY		(1 << 0) /* vtpm is processing a command */

Declare this already in the fix, and just leave the rename here.

You mean the fix patch does not use 'true' anymore but uses the
TPM_STATUS_BUSY flag already but the name is still tpm_processing_cmd? And
literally only the renaming of this field is done in the 2nd patch?

I can fixup these patches, and use '1', instead of true. No need to send
new ones.

Acked-by: Jarkko Sakkinen <jarkko@kernel.org>

/Jarkko

On 8/10/21 10:10 PM, Jarkko Sakkinen wrote:

On Tue, Aug 10, 2021 at 09:50:55PM -0400, Stefan Berger wrote:

quoted

On 8/10/21 1:58 PM, Jarkko Sakkinen wrote:

quoted

On Mon, Aug 09, 2021 at 03:21:59PM -0400, Stefan Berger wrote:

quoted

From: Stefan Berger <stefanb@linux.ibm.com>

Rename the field tpm_processing_cmd to tpm_status in ibmvtpm_dev and set
the TPM_STATUS_BUSY flag while the vTPM is busy processing a command.


   		default:

diff --git a/drivers/char/tpm/tpm_ibmvtpm.h b/drivers/char/tpm/tpm_ibmvtpm.h
index 51198b137461..252f1cccdfc5 100644
--- a/drivers/char/tpm/tpm_ibmvtpm.h
+++ b/drivers/char/tpm/tpm_ibmvtpm.h

@@ -41,7 +41,8 @@ struct ibmvtpm_dev {
   	wait_queue_head_t wq;
   	u16 res_len;
   	u32 vtpm_version;
-	u8 tpm_processing_cmd;
+	u8 tpm_status;
+#define TPM_STATUS_BUSY		(1 << 0) /* vtpm is processing a command */

Declare this already in the fix, and just leave the rename here.

You mean the fix patch does not use 'true' anymore but uses the
TPM_STATUS_BUSY flag already but the name is still tpm_processing_cmd? And
literally only the renaming of this field is done in the 2nd patch?

I can fixup these patches, and use '1', instead of true. No need to send
new ones.

Acked-by: Jarkko Sakkinen <jarkko@kernel.org>

THANKS!

   Stefan

/Jarkko

On Wed, Aug 11, 2021 at 08:15:14AM -0400, Stefan Berger wrote:

On 8/10/21 10:10 PM, Jarkko Sakkinen wrote:

quoted

On Tue, Aug 10, 2021 at 09:50:55PM -0400, Stefan Berger wrote:

quoted

On 8/10/21 1:58 PM, Jarkko Sakkinen wrote:

quoted

On Mon, Aug 09, 2021 at 03:21:59PM -0400, Stefan Berger wrote:

quoted

From: Stefan Berger <stefanb@linux.ibm.com>

Rename the field tpm_processing_cmd to tpm_status in ibmvtpm_dev and set
the TPM_STATUS_BUSY flag while the vTPM is busy processing a command.


   		default:

diff --git a/drivers/char/tpm/tpm_ibmvtpm.h b/drivers/char/tpm/tpm_ibmvtpm.h
index 51198b137461..252f1cccdfc5 100644
--- a/drivers/char/tpm/tpm_ibmvtpm.h
+++ b/drivers/char/tpm/tpm_ibmvtpm.h

@@ -41,7 +41,8 @@ struct ibmvtpm_dev {
   	wait_queue_head_t wq;
   	u16 res_len;
   	u32 vtpm_version;
-	u8 tpm_processing_cmd;
+	u8 tpm_status;
+#define TPM_STATUS_BUSY		(1 << 0) /* vtpm is processing a command */

Declare this already in the fix, and just leave the rename here.

You mean the fix patch does not use 'true' anymore but uses the
TPM_STATUS_BUSY flag already but the name is still tpm_processing_cmd? And
literally only the renaming of this field is done in the 2nd patch?

I can fixup these patches, and use '1', instead of true. No need to send
new ones.

Acked-by: Jarkko Sakkinen <jarkko@kernel.org>

I applied the first. If you have only one flag that you even
document as "processing the command" in the inline comment,
it makes absolutely no sense to rename it, as the current
name perfectly documents what it exactly is.

/Jarkko

From: Stefan Berger <stefanb@linux.ibm.com>

When rngd is run as root then lots of these types of message will appear
in the kernel log if the TPM has been configured to provide random bytes:

[ 7406.275163] tpm tpm0: tpm_transmit: tpm_recv: error -4

The issue is caused by the following call that is interrupted while
waiting for the TPM's response.

sig = wait_event_interruptible(ibmvtpm->wq, !ibmvtpm->tpm_processing_cmd);

Rather than waiting for the response in the low level driver, have it use
the polling loop in tpm_try_transmit() that uses a command's duration to
poll until a result has been returned by the TPM, thus ending when the
timeout has occurred but not responding to signals and ctrl-c anymore. To
stay in this polling loop extend tpm_ibmvtpm_status() to return
'true' for as long as the vTPM is indicated as being busy in
tpm_processing_cmd. Since the loop requires the TPM's timeouts, get them
now using tpm_get_timeouts() after setting the TPM2 version flag on the
chip.

To recreat the resolved issue start rngd like this:

sudo rngd -r /dev/hwrng -t
sudo rngd -r /dev/tpm0 -t

Link: https://bugzilla.redhat.com/show_bug.cgi?id=1981473
Fixes: 6674ff145eef ("tpm_ibmvtpm: properly handle interrupted packet receptions")
Cc: Nayna Jain <nayna@linux.ibm.com>
Cc: George Wilson <redacted>
Reported-by: Nageswara R Sastry <redacted>
Signed-off-by: Stefan Berger <stefanb@linux.ibm.com>
---
 drivers/char/tpm/tpm_ibmvtpm.c | 20 ++++++++++++--------
 drivers/char/tpm/tpm_ibmvtpm.h |  2 +-
 2 files changed, 13 insertions(+), 9 deletions(-)

diff --git a/drivers/char/tpm/tpm_ibmvtpm.c b/drivers/char/tpm/tpm_ibmvtpm.c
index 903604769de9..7a9eca5768f8 100644
--- a/drivers/char/tpm/tpm_ibmvtpm.c
+++ b/drivers/char/tpm/tpm_ibmvtpm.c

@@ -106,17 +106,12 @@ static int tpm_ibmvtpm_recv(struct tpm_chip *chip, u8 *buf, size_t count)
 {
 	struct ibmvtpm_dev *ibmvtpm = dev_get_drvdata(&chip->dev);
 	u16 len;
-	int sig;
 
 	if (!ibmvtpm->rtce_buf) {
 		dev_err(ibmvtpm->dev, "ibmvtpm device is not ready\n");
 		return 0;
 	}
 
-	sig = wait_event_interruptible(ibmvtpm->wq, !ibmvtpm->tpm_processing_cmd);
-	if (sig)
-		return -EINTR;
-
 	len = ibmvtpm->res_len;
 
 	if (count < len) {

@@ -269,7 +264,9 @@ static void tpm_ibmvtpm_cancel(struct tpm_chip *chip)
 
 static u8 tpm_ibmvtpm_status(struct tpm_chip *chip)
 {
-	return 0;
+	struct ibmvtpm_dev *ibmvtpm = dev_get_drvdata(&chip->dev);
+
+	return ibmvtpm->tpm_processing_cmd;
 }
 
 /**

@@ -457,7 +454,7 @@ static const struct tpm_class_ops tpm_ibmvtpm = {
 	.send = tpm_ibmvtpm_send,
 	.cancel = tpm_ibmvtpm_cancel,
 	.status = tpm_ibmvtpm_status,
-	.req_complete_mask = 0,
+	.req_complete_mask = true,
 	.req_complete_val = 0,
 	.req_canceled = tpm_ibmvtpm_req_canceled,
 };

@@ -688,8 +685,15 @@ static int tpm_ibmvtpm_probe(struct vio_dev *vio_dev,
 		goto init_irq_cleanup;
 	}
 
-	if (!strcmp(id->compat, "IBM,vtpm20")) {
+
+	if (!strcmp(id->compat, "IBM,vtpm20"))
 		chip->flags |= TPM_CHIP_FLAG_TPM2;
+
+	rc = tpm_get_timeouts(chip);
+	if (rc)
+		goto init_irq_cleanup;
+
+	if (chip->flags & TPM_CHIP_FLAG_TPM2) {
 		rc = tpm2_get_cc_attrs_tbl(chip);
 		if (rc)
 			goto init_irq_cleanup;

diff --git a/drivers/char/tpm/tpm_ibmvtpm.h b/drivers/char/tpm/tpm_ibmvtpm.h
index b92aa7d3e93e..51198b137461 100644
--- a/drivers/char/tpm/tpm_ibmvtpm.h
+++ b/drivers/char/tpm/tpm_ibmvtpm.h

@@ -41,7 +41,7 @@ struct ibmvtpm_dev {
 	wait_queue_head_t wq;
 	u16 res_len;
 	u32 vtpm_version;
-	bool tpm_processing_cmd;
+	u8 tpm_processing_cmd;
 };
 
 #define CRQ_RES_BUF_SIZE	PAGE_SIZE

-- 
2.31.1

On 10/08/21 12:51 am, Stefan Berger wrote:

From: Stefan Berger <stefanb@linux.ibm.com>

When rngd is run as root then lots of these types of message will appear
in the kernel log if the TPM has been configured to provide random bytes:

[ 7406.275163] tpm tpm0: tpm_transmit: tpm_recv: error -4

The issue is caused by the following call that is interrupted while
waiting for the TPM's response.

sig = wait_event_interruptible(ibmvtpm->wq, !ibmvtpm->tpm_processing_cmd);

Rather than waiting for the response in the low level driver, have it use
the polling loop in tpm_try_transmit() that uses a command's duration to
poll until a result has been returned by the TPM, thus ending when the
timeout has occurred but not responding to signals and ctrl-c anymore. To
stay in this polling loop extend tpm_ibmvtpm_status() to return
'true' for as long as the vTPM is indicated as being busy in
tpm_processing_cmd. Since the loop requires the TPM's timeouts, get them
now using tpm_get_timeouts() after setting the TPM2 version flag on the
chip.

To recreat the resolved issue start rngd like this:

sudo rngd -r /dev/hwrng -t
sudo rngd -r /dev/tpm0 -t

Link: https://bugzilla.redhat.com/show_bug.cgi?id=1981473
Fixes: 6674ff145eef ("tpm_ibmvtpm: properly handle interrupted packet receptions")
Cc: Nayna Jain <nayna@linux.ibm.com>
Cc: George Wilson <redacted>
Reported-by: Nageswara R Sastry <redacted>
Signed-off-by: Stefan Berger <stefanb@linux.ibm.com>

Tested-by: Nageswara R Sastry <redacted>

Tested with /dev/hwrng and /dev/tpm0 and not seen any tpm errors from 
the kernel.

-- 
Thanks and Regards
R.Nageswara Sastry