[PATCH v3 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

v3:
 - Split into two patches

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

 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.

Fixes: 6674ff145eef ("tpm_ibmvtpm: properly handle interrupted packet receptions")
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 | 14 ++++++++------
 drivers/char/tpm/tpm_ibmvtpm.h |  3 ++-
 2 files changed, 10 insertions(+), 7 deletions(-)

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

@@ -113,7 +113,8 @@ static int tpm_ibmvtpm_recv(struct tpm_chip *chip, u8 *buf, size_t count)
 		return 0;
 	}
 
-	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;
 

@@ -220,11 +221,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;
 	}

@@ -237,7 +239,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,

@@ -255,7 +257,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);

@@ -550,7 +552,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 b92aa7d3e93e..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;
-	bool 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

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_status & TPM_STATUS_BUSY) == 0);

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
TPM_STATUS_BUSY for as long as the vTPM is busy. 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>

---
v3L
 - split for renaming of tpm_processing_cmd

v2:
 - reworded commit text
---
 drivers/char/tpm/tpm_ibmvtpm.c | 21 ++++++++++++---------
 1 file changed, 12 insertions(+), 9 deletions(-)

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

@@ -106,18 +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_status & TPM_STATUS_BUSY) == 0);
-	if (sig)
-		return -EINTR;
-
 	len = ibmvtpm->res_len;
 
 	if (count < len) {

@@ -271,7 +265,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_status;
 }
 
 /**

@@ -459,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 = 0,
+	.req_complete_mask = TPM_STATUS_BUSY,
 	.req_complete_val = 0,
 	.req_canceled = tpm_ibmvtpm_req_canceled,
 };

@@ -690,8 +686,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;

-- 
2.31.1

On Thu, Aug 05, 2021 at 05:52:55PM -0400, Stefan Berger wrote:

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.

Fixes: 6674ff145eef ("tpm_ibmvtpm: properly handle interrupted packet receptions")
Signed-off-by: Stefan Berger <stefanb@linux.ibm.com>
Cc: Nayna Jain <nayna@linux.ibm.com>
Cc: George Wilson <redacted>

Please put the bug fix first because otherwise it will be dependent of this
patch, which is bad thing when it comes to backporting.

/Jarkko

On 8/6/21 7:25 AM, Jarkko Sakkinen wrote:

On Thu, Aug 05, 2021 at 05:52:55PM -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.

Fixes: 6674ff145eef ("tpm_ibmvtpm: properly handle interrupted packet receptions")
Signed-off-by: Stefan Berger <stefanb@linux.ibm.com>
Cc: Nayna Jain <nayna@linux.ibm.com>
Cc: George Wilson <redacted>

Please put the bug fix first because otherwise it will be dependent of this
patch, which is bad thing when it comes to backporting.

Yes, and that's why I have this one here also with a Fix tag. I 
basically don't want to logically '&' with the 'true' flag but want this 
TPM_STATUS_BUSY flag first.

    Stefan

/Jarkko

On Fri, Aug 06, 2021 at 08:08:27AM -0400, Stefan Berger wrote:

On 8/6/21 7:25 AM, Jarkko Sakkinen wrote:

quoted

On Thu, Aug 05, 2021 at 05:52:55PM -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.

Fixes: 6674ff145eef ("tpm_ibmvtpm: properly handle interrupted packet receptions")
Signed-off-by: Stefan Berger <stefanb@linux.ibm.com>
Cc: Nayna Jain <nayna@linux.ibm.com>
Cc: George Wilson <redacted>

Please put the bug fix first because otherwise it will be dependent of this
patch, which is bad thing when it comes to backporting.

Yes, and that's why I have this one here also with a Fix tag. I basically
don't want to logically '&' with the 'true' flag but want this
TPM_STATUS_BUSY flag first.

   Stefan

You can then just change the type to 'u8'.

/Jarkko