[PATCH 0/2] tpm: Stop retrying TPMs that have stopped working

[PATCH 0/2] tpm: Stop retrying TPMs that have stopped working

[Breno Leitao]

On Meta's datacenter, given the size, TPMs that stop working write about
54 million lines a day to the kernel log, because nothing in the kernel
gives up on them.

Two cases make up nearly all of it.

Some TPMs stop responding. Every command then fails only after the
transport timeout, while the hwrng thread and userspace keep sending
more.

The goal is to retire TPM that are not properly working, similarly to
what was done for EFI in commit 4b2c033b5bc971 ("efi/runtime-wrappers:
retire the worker if a wedged call ever returns")

This feature aim to disable the chip once its commands have kept timing,
instead of keeping it in this desolate state.

Disabling the chip makes the failure explicit: the log gets one line
saying the TPM is disabled, and every later command fails at once
instead of timing out. 

A health-check daemon, such as machine checker, can then detect
the broken hardware and send the machine to repair.

Signed-off-by: Breno Leitao <leitao@debian.org>
---
Breno Leitao (2):
      tpm: Disable a TPM that stops responding
      tpm: Disable a TPM whose hwrng reads keep failing

 drivers/char/tpm/tpm-chip.c      | 20 +++++++++++++++++++-
 drivers/char/tpm/tpm-interface.c | 29 +++++++++++++++++++++++++++++
 include/linux/tpm.h              |  3 +++
 3 files changed, 51 insertions(+), 1 deletion(-)
---
base-commit: 630059a5a632377b9b7b487baccde92b7ae1dd47
change-id: 20261110-tpm_unresponsive-a5f71c1db026

Best regards,
--  
Breno Leitao <leitao@debian.org>

[PATCH 1/2] tpm: Disable a TPM that stops responding

[Breno Leitao]

A TPM that stops responding fails each command only after the transport
timeout, and its callers keep sending more: the hwrng thread every 10
seconds forever, and userspace through /dev/tpmrm0. Each attempt holds
tpm_mutex for the whole timeout and logs an error:

  tpm tpm0: invalid TPM_STS.x 0xff, dumping stack for forensics
  tpm tpm0: tpm_try_transmit: send(): error -62
  tpm tpm0: tpm_try_transmit: send(): error -62
  ...

The core already stops using a TPM it cannot trust: tpm_try_get_ops()
fails with -EIO once TPM_CHIP_FLAG_DISABLE is set, which
tpm2_load_null() does when it cannot restore the null key. Set the same
flag when commands have kept timing out for ten minutes, with none
completing in between.

A completed command, whatever its TPM return code, resets the clock. A
disabled TPM stays disabled until the driver is rebound or the machine
reboots.

Signed-off-by: Breno Leitao <leitao@debian.org>
---
 drivers/char/tpm/tpm-interface.c | 29 +++++++++++++++++++++++++++++
 include/linux/tpm.h              |  2 ++
 2 files changed, 31 insertions(+)

diff --git a/drivers/char/tpm/tpm-interface.c b/drivers/char/tpm/tpm-interface.c
index e0385b16616b46..c6278ef8d1095e 100644
--- a/drivers/char/tpm/tpm-interface.c
+++ b/drivers/char/tpm/tpm-interface.c
@@ -30,6 +30,8 @@
 
 #include "tpm.h"
 
+#define TPM_UNRESPONSIVE_TIMEOUT	(10 * 60 * HZ)
+
 /*
  * Bug workaround - some TPM's don't flush the most
  * recently changed pcr on suspend, so force the flush
@@ -206,6 +208,31 @@ static ssize_t tpm_try_transmit(struct tpm_chip *chip, void *buf, size_t bufsiz)
 	return rc ? rc : len;
 }
 
+/*
+ * Disable the TPM once commands keep timing out for TPM_UNRESPONSIVE_TIMEOUT.
+ * A few timeouts are not enough: some TPMs stall for half a minute and recover.
+ */
+static void tpm_check_unresponsive(struct tpm_chip *chip, ssize_t ret)
+{
+	if (ret >= 0) {
+		chip->nr_timeouts = 0;
+		return;
+	}
+	if (ret != -ETIME || (chip->flags & TPM_CHIP_FLAG_DISABLE))
+		return;
+	if (!chip->nr_timeouts++) {
+		chip->first_timeout = jiffies;
+		return;
+	}
+	if (time_before(jiffies,
+			chip->first_timeout + TPM_UNRESPONSIVE_TIMEOUT))
+		return;
+
+	dev_err(&chip->dev, "%u commands timed out in %lu seconds, disabling the TPM\n",
+		chip->nr_timeouts, (jiffies - chip->first_timeout) / HZ);
+	chip->flags |= TPM_CHIP_FLAG_DISABLE;
+}
+
 /**
  * tpm_transmit - Internal kernel interface to transmit TPM commands.
  * @chip:	a TPM chip to use
@@ -268,6 +295,8 @@ ssize_t tpm_transmit(struct tpm_chip *chip, u8 *buf, size_t bufsiz)
 		delay_msec *= 2;
 		memcpy(buf, save, save_size);
 	}
+
+	tpm_check_unresponsive(chip, ret);
 	return ret;
 }
 
diff --git a/include/linux/tpm.h b/include/linux/tpm.h
index 0db277af45c393..4264c87a04d98c 100644
--- a/include/linux/tpm.h
+++ b/include/linux/tpm.h
@@ -131,6 +131,8 @@ struct tpm_chip {
 	struct hwrng hwrng;
 
 	struct mutex tpm_mutex;	/* tpm is processing */
+	unsigned int nr_timeouts;	/* consecutive command timeouts */
+	unsigned long first_timeout;	/* jiffies */
 
 	unsigned long timeout_a; /* jiffies */
 	unsigned long timeout_b; /* jiffies */

-- 
2.53.0-Meta

[PATCH 2/2] tpm: Disable a TPM whose hwrng reads keep failing

[Breno Leitao]

The hwrng core retries a failed read every 10 seconds, forever. When the
TPM keeps answering GetRandom with an error, each retry logs a line:

  tpm tpm0: A TPM error (256) occurred attempting get random
  tpm tpm0: A TPM error (256) occurred attempting get random
  ...

Neither clears on its own, and the TPM does answer, so the timeout check
in tpm_transmit() never fires.

After 60 failed reads in a row, ~ten minutes of retries on my system,
set TPM_CHIP_FLAG_DISABLE as tpm_transmit() does for a TPM that stopped
responding. Later reads then fail in tpm_try_get_ops() without sending
the TPM a command. A successful read resets the count. A handful of
failures is not enough, since some TPMs stall for half a minute and then
recover.

This also takes the TPM away from userspace, which could otherwise
still send TPM2_Startup or query the failure mode. Rebinding the driver
brings it back.

Signed-off-by: Breno Leitao <leitao@debian.org>
---
 drivers/char/tpm/tpm-chip.c | 20 +++++++++++++++++++-
 include/linux/tpm.h         |  1 +
 2 files changed, 20 insertions(+), 1 deletion(-)

diff --git a/drivers/char/tpm/tpm-chip.c b/drivers/char/tpm/tpm-chip.c
index 0be5dbfaa72ebf..d94ea462a5ef0c 100644
--- a/drivers/char/tpm/tpm-chip.c
+++ b/drivers/char/tpm/tpm-chip.c
@@ -466,11 +466,29 @@ static int tpm_add_legacy_sysfs(struct tpm_chip *chip)
 	return 0;
 }
 
+#define TPM_HWRNG_MAX_FAILURES	60	/* ~10 minutes of retries */
+
 static int tpm_hwrng_read(struct hwrng *rng, void *data, size_t max, bool wait)
 {
 	struct tpm_chip *chip = container_of(rng, struct tpm_chip, hwrng);
+	int rc;
+
+	rc = tpm_get_random(chip, data, max);
+	if (rc > 0) {
+		chip->hwrng_failures = 0;
+		return rc;
+	}
+
+	if (++chip->hwrng_failures == TPM_HWRNG_MAX_FAILURES &&
+	    !(chip->flags & TPM_CHIP_FLAG_DISABLE)) {
+		dev_err(&chip->dev, "hwrng: %u reads failed in a row, disabling the TPM\n",
+			chip->hwrng_failures);
+		mutex_lock(&chip->tpm_mutex);
+		chip->flags |= TPM_CHIP_FLAG_DISABLE;
+		mutex_unlock(&chip->tpm_mutex);
+	}
 
-	return tpm_get_random(chip, data, max);
+	return rc;
 }
 
 static bool tpm_is_hwrng_enabled(struct tpm_chip *chip)
diff --git a/include/linux/tpm.h b/include/linux/tpm.h
index 4264c87a04d98c..402b5160db962c 100644
--- a/include/linux/tpm.h
+++ b/include/linux/tpm.h
@@ -129,6 +129,7 @@ struct tpm_chip {
 
 	char hwrng_name[64];
 	struct hwrng hwrng;
+	unsigned int hwrng_failures;	/* consecutive failed reads */
 
 	struct mutex tpm_mutex;	/* tpm is processing */
 	unsigned int nr_timeouts;	/* consecutive command timeouts */

-- 
2.53.0-Meta