Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]


Groups > linux.kernel > #1419878

[PATCH v6 2/5] tpm: Add optional logging of TPM command durations

From Ed Swierk <eswierk@skyportsystems.com>
Newsgroups linux.kernel
Subject [PATCH v6 2/5] tpm: Add optional logging of TPM command durations
Date 2016-06-11 04:00 +0200
Message-ID <rIGnn-55z-3@gated-at.bofh.it> (permalink)
References <rHULM-6Am-3@gated-at.bofh.it> <rIGnn-55z-5@gated-at.bofh.it>
Organization linux.* mail to news gateway

Show all headers | View raw


Some TPMs violate their own advertised command durations. This is much
easier to debug with data about how long each command actually takes
to complete. Add debug messages that can be enabled by running

  echo -n 'module tpm +p' >/sys/kernel/debug/dynamic_debug/control

on a kernel configured with DYNAMIC_DEBUG=y.

Signed-off-by: Ed Swierk <eswierk@skyportsystems.com>
Reviewed-by: Jarkko Sakkinen <jarkko.sakkinen@linux.intel.com>
---
 drivers/char/tpm/tpm-interface.c | 17 +++++++++++++----
 1 file changed, 13 insertions(+), 4 deletions(-)

diff --git a/drivers/char/tpm/tpm-interface.c b/drivers/char/tpm/tpm-interface.c
index c50637d..cc1e5bc 100644
--- a/drivers/char/tpm/tpm-interface.c
+++ b/drivers/char/tpm/tpm-interface.c
@@ -333,13 +333,14 @@ ssize_t tpm_transmit(struct tpm_chip *chip, const char *buf,
 {
 	ssize_t rc;
 	u32 count, ordinal;
-	unsigned long stop;
+	unsigned long start, stop;
 
 	if (bufsiz > TPM_BUFSIZE)
 		bufsiz = TPM_BUFSIZE;
 
 	count = be32_to_cpu(*((__be32 *) (buf + 2)));
 	ordinal = be32_to_cpu(*((__be32 *) (buf + 6)));
+	dev_dbg(chip->pdev, "starting command %d count %d\n", ordinal, count);
 	if (count == 0)
 		return -ENODATA;
 	if (count > bufsiz) {
@@ -360,18 +361,24 @@ ssize_t tpm_transmit(struct tpm_chip *chip, const char *buf,
 	if (chip->vendor.irq)
 		goto out_recv;
 
+	start = jiffies;
 	if (chip->flags & TPM_CHIP_FLAG_TPM2)
-		stop = jiffies + tpm2_calc_ordinal_duration(chip, ordinal);
+		stop = start + tpm2_calc_ordinal_duration(chip, ordinal);
 	else
-		stop = jiffies + tpm_calc_ordinal_duration(chip, ordinal);
+		stop = start + tpm_calc_ordinal_duration(chip, ordinal);
 	do {
 		u8 status = chip->ops->status(chip);
 		if ((status & chip->ops->req_complete_mask) ==
-		    chip->ops->req_complete_val)
+		    chip->ops->req_complete_val) {
+			dev_dbg(chip->pdev, "completed command %d in %d ms\n",
+				ordinal, jiffies_to_msecs(jiffies - start));
 			goto out_recv;
+		}
 
 		if (chip->ops->req_canceled(chip, status)) {
 			dev_err(chip->pdev, "Operation Canceled\n");
+			dev_dbg(chip->pdev, "canceled command %d after %d ms\n",
+				ordinal, jiffies_to_msecs(jiffies - start));
 			rc = -ECANCELED;
 			goto out;
 		}
@@ -382,6 +389,8 @@ ssize_t tpm_transmit(struct tpm_chip *chip, const char *buf,
 
 	chip->ops->cancel(chip);
 	dev_err(chip->pdev, "Operation Timed out\n");
+	dev_dbg(chip->pdev, "command %d timed out after %d ms\n", ordinal,
+		jiffies_to_msecs(jiffies - start));
 	rc = -ETIME;
 	goto out;
 
-- 
1.9.1

Back to linux.kernel | Previous | NextPrevious in thread | Next in thread | Find similar | Unroll thread


Thread

[PATCH v4 0/4] tpm: Command duration logging and chip-specific override Ed Swierk <eswierk@skyportsystems.com> - 2016-06-08 02:50 +0200
  [PATCH v4 1/4] tpm_tis: Improve reporting of IO errors Ed Swierk <eswierk@skyportsystems.com> - 2016-06-08 02:50 +0200
  [PATCH v5 0/4] tpm: Command duration logging and chip-specific override Ed Swierk <eswierk@skyportsystems.com> - 2016-06-09 01:10 +0200
    [PATCH v5 4/4] tpm_tis: Increase ST19NP18 TPM command duration to avoid chip lockup Ed Swierk <eswierk@skyportsystems.com> - 2016-06-09 01:10 +0200
    [PATCH v5 3/4] tpm: Allow TPM chip drivers to override reported command durations Ed Swierk <eswierk@skyportsystems.com> - 2016-06-09 01:10 +0200
      Re: [PATCH v5 3/4] tpm: Allow TPM chip drivers to override reported  command durations Jarkko Sakkinen <jarkko.sakkinen@linux.intel.com> - 2016-06-10 14:30 +0200
        Re: [PATCH v5 3/4] tpm: Allow TPM chip drivers to override reported  command durations Ed Swierk <eswierk@skyportsystems.com> - 2016-06-10 19:40 +0200
          Re: [PATCH v5 3/4] tpm: Allow TPM chip drivers to override reported  command durations Jarkko Sakkinen <jarkko.sakkinen@linux.intel.com> - 2016-06-10 21:50 +0200
            Re: [PATCH v5 3/4] tpm: Allow TPM chip drivers to override reported  command durations Ed Swierk <eswierk@skyportsystems.com> - 2016-06-11 04:00 +0200
    [PATCH v5 2/4] tpm: Add optional logging of TPM command durations Ed Swierk <eswierk@skyportsystems.com> - 2016-06-09 01:10 +0200
    [PATCH v5 1/4] tpm_tis: Improve reporting of IO errors Ed Swierk <eswierk@skyportsystems.com> - 2016-06-09 01:10 +0200
    [PATCH v6 2/5] tpm: Add optional logging of TPM command durations Ed Swierk <eswierk@skyportsystems.com> - 2016-06-11 04:00 +0200
    [PATCH v6 4/5] tpm: Allow TPM chip drivers to override reported command durations Ed Swierk <eswierk@skyportsystems.com> - 2016-06-11 04:00 +0200
      Re: [PATCH v6 4/5] tpm: Allow TPM chip drivers to override reported  command durations Jarkko Sakkinen <jarkko.sakkinen@linux.intel.com> - 2016-06-16 22:30 +0200
    [PATCH v6 5/5] tpm_tis: Increase ST19NP18 TPM command duration to avoid chip lockup Ed Swierk <eswierk@skyportsystems.com> - 2016-06-11 04:00 +0200
    [PATCH v6 0/5] tpm: Command duration logging and chip-specific override Ed Swierk <eswierk@skyportsystems.com> - 2016-06-11 04:00 +0200
      [PATCH v6 1/5] tpm_tis: Improve reporting of IO errors Ed Swierk <eswierk@skyportsystems.com> - 2016-06-11 04:00 +0200
      [PATCH v6 3/5] tpm: Factor out reading of timeout and duration capabilities Ed Swierk <eswierk@skyportsystems.com> - 2016-06-11 04:00 +0200
        Re: [PATCH v6 3/5] tpm: Factor out reading of timeout and duration  capabilities Jarkko Sakkinen <jarkko.sakkinen@linux.intel.com> - 2016-06-16 22:30 +0200
        Re: [PATCH v6 3/5] tpm: Factor out reading of timeout and duration  capabilities Jarkko Sakkinen <jarkko.sakkinen@linux.intel.com> - 2016-06-19 14:20 +0200
      [PATCH v7 2/5] tpm: Add optional logging of TPM command durations Ed Swierk <eswierk@skyportsystems.com> - 2016-06-21 04:00 +0200
      [PATCH v7 5/5] tpm_tis: Increase ST19NP18 TPM command duration to avoid chip lockup Ed Swierk <eswierk@skyportsystems.com> - 2016-06-21 04:00 +0200
        Re: [PATCH v7 5/5] tpm_tis: Increase ST19NP18 TPM command duration  to avoid chip lockup Jarkko Sakkinen <jarkko.sakkinen@linux.intel.com> - 2016-06-21 23:00 +0200
      [PATCH v7 4/5] tpm: Allow TPM chip drivers to override reported command durations Ed Swierk <eswierk@skyportsystems.com> - 2016-06-21 04:00 +0200
        Re: [PATCH v7 4/5] tpm: Allow TPM chip drivers to override reported  command durations Jarkko Sakkinen <jarkko.sakkinen@linux.intel.com> - 2016-06-21 23:00 +0200
      [PATCH v7 0/5] tpm: Command duration logging and chip-specific override Ed Swierk <eswierk@skyportsystems.com> - 2016-06-21 04:10 +0200
        [PATCH v7 1/5] tpm_tis: Improve reporting of IO errors Ed Swierk <eswierk@skyportsystems.com> - 2016-06-21 04:10 +0200
        [PATCH v7 3/5] tpm: Clean up reading of timeout and duration capabilities Ed Swierk <eswierk@skyportsystems.com> - 2016-06-21 05:00 +0200
          Re: [PATCH v7 3/5] tpm: Clean up reading of timeout and duration  capabilities Jarkko Sakkinen <jarkko.sakkinen@linux.intel.com> - 2016-06-21 23:40 +0200
          Re: [PATCH v7 3/5] tpm: Clean up reading of timeout and duration capabilities Ed Swierk <eswierk@skyportsystems.com> - 2016-06-22 02:30 +0200
            Re: [PATCH v7 3/5] tpm: Clean up reading of timeout and duration  capabilities Jarkko Sakkinen <jarkko.sakkinen@linux.intel.com> - 2016-06-22 13:00 +0200
        [PATCH v8 4/5] tpm: Allow TPM chip drivers to override reported command durations Ed Swierk <eswierk@skyportsystems.com> - 2016-06-22 03:20 +0200
        [PATCH v8 1/5] tpm_tis: Improve reporting of IO errors Ed Swierk <eswierk@skyportsystems.com> - 2016-06-22 03:20 +0200
        [PATCH v8 2/5] tpm: Add optional logging of TPM command durations Ed Swierk <eswierk@skyportsystems.com> - 2016-06-22 03:20 +0200
        [PATCH v8 3/5] tpm: Clean up reading of timeout and duration capabilities Ed Swierk <eswierk@skyportsystems.com> - 2016-06-22 03:20 +0200
        [PATCH v8 0/5] tpm: Command duration logging and chip-specific override Ed Swierk <eswierk@skyportsystems.com> - 2016-06-22 03:20 +0200
          [PATCH v8 5/5] tpm_tis: Increase ST19NP18 TPM command duration to avoid chip lockup Ed Swierk <eswierk@skyportsystems.com> - 2016-06-22 03:20 +0200

csiph-web