2021-01-23 01:48:28

by Lukasz Majczak

Subject: [PATCH] tpm_tis: Add missing start/stop_tpm_chip calls

There is a missing call to start_tpm_chip before the call to
the tpm_get_timeouts() and tpm_tis_probe_irq_single(). As the current
approach maight work for tpm2, it fails for tpm1.x - in that case
call to tpm_get_timeouts() or tpm_tis_probe_irq_single() tries to
transmit TPM commands on a disabled chip what what doesn't succeed
and in turn causes tpm_tis_core_init() to fail.
Tested on Samsung Chromebook Pro (Caroline).

Signed-off-by: Lukasz Majczak <[email protected]>
---
drivers/char/tpm/tpm_tis_core.c | 5 +++++
1 file changed, 5 insertions(+)

diff --git a/drivers/char/tpm/tpm_tis_core.c b/drivers/char/tpm/tpm_tis_core.c
index 92c51c6cfd1b..ff0e5fe46a9d 100644
--- a/drivers/char/tpm/tpm_tis_core.c
+++ b/drivers/char/tpm/tpm_tis_core.c
@@ -1063,12 +1063,16 @@ int tpm_tis_core_init(struct device *dev, struct tpm_tis_data *priv, int irq,
init_waitqueue_head(&priv->read_queue);
init_waitqueue_head(&priv->int_queue);
if (irq != -1) {
+ rc = tpm_chip_start(chip);
+ if (rc)
+ goto out_err;
/* Before doing irq testing issue a command to the TPM in polling mode
* to make sure it works. May as well use that command to set the
* proper timeouts for the driver.
*/
if (tpm_get_timeouts(chip)) {
dev_err(dev, "Could not get TPM timeouts and durations\n");
+ tpm_chip_stop(chip);
rc = -ENODEV;
goto out_err;
}
@@ -1085,6 +1089,7 @@ int tpm_tis_core_init(struct device *dev, struct tpm_tis_data *priv, int irq,
} else {
tpm_tis_probe_irq(chip, intmask);
}
+ tpm_chip_stop(chip);
}

rc = tpm_chip_register(chip);
--
2.25.1

2021-01-25 18:31:33

by Jarkko Sakkinen

Subject: Re: [PATCH] tpm_tis: Add missing start/stop_tpm_chip calls

On Sat, Jan 23, 2021 at 02:42:47AM +0100, Lukasz Majczak wrote:
> There is a missing call to start_tpm_chip before the call to
> the tpm_get_timeouts() and tpm_tis_probe_irq_single(). As the current
> approach maight work for tpm2, it fails for tpm1.x - in that case
> call to tpm_get_timeouts() or tpm_tis_probe_irq_single() tries to
> transmit TPM commands on a disabled chip what what doesn't succeed
> and in turn causes tpm_tis_core_init() to fail.
> Tested on Samsung Chromebook Pro (Caroline).
>
> Signed-off-by: Lukasz Majczak <[email protected]>

Do you have a log demonstrating the failure?

/Jarkko

2021-01-26 02:01:15

by Guenter Roeck

Subject: Re: [PATCH] tpm_tis: Add missing start/stop_tpm_chip calls

Hi Lukasz,

On Sat, Jan 23, 2021 at 02:42:47AM +0100, Lukasz Majczak wrote:
> There is a missing call to start_tpm_chip before the call to
> the tpm_get_timeouts() and tpm_tis_probe_irq_single(). As the current
> approach maight work for tpm2, it fails for tpm1.x - in that case
> call to tpm_get_timeouts() or tpm_tis_probe_irq_single() tries to
> transmit TPM commands on a disabled chip what what doesn't succeed

s/what what/what/

> and in turn causes tpm_tis_core_init() to fail.
> Tested on Samsung Chromebook Pro (Caroline).
>
> Signed-off-by: Lukasz Majczak <[email protected]>
> ---
> drivers/char/tpm/tpm_tis_core.c | 5 +++++
> 1 file changed, 5 insertions(+)
>
> diff --git a/drivers/char/tpm/tpm_tis_core.c b/drivers/char/tpm/tpm_tis_core.c
> index 92c51c6cfd1b..ff0e5fe46a9d 100644
> --- a/drivers/char/tpm/tpm_tis_core.c
> +++ b/drivers/char/tpm/tpm_tis_core.c
> @@ -1063,12 +1063,16 @@ int tpm_tis_core_init(struct device *dev, struct tpm_tis_data *priv, int irq,
> init_waitqueue_head(&priv->read_queue);
> init_waitqueue_head(&priv->int_queue);
> if (irq != -1) {
> + rc = tpm_chip_start(chip);

Unless I am missing something, the underlying problem seems to be
the calls to tpm1_getcap(). From other code calling this function,
it looks like it may only require tpm_clk_enable() to work.

With that in mind, would it possibly be better to call tpm_clk_enable()
and tpm_clk_disable() around the calls to tpm1_getcap(), ie in
tpm1_get_timeouts() and in tpm_tis_gen_interrupt() ?

This would avoid the unnecessary calls to tpm_chip_start() and
tpm_chip_stop() for tpm2 chips.

Thanks,
Guenter


> + if (rc)
> + goto out_err;
> /* Before doing irq testing issue a command to the TPM in polling mode
> * to make sure it works. May as well use that command to set the
> * proper timeouts for the driver.
> */
> if (tpm_get_timeouts(chip)) {
> dev_err(dev, "Could not get TPM timeouts and durations\n");
> + tpm_chip_stop(chip);
> rc = -ENODEV;
> goto out_err;
> }
> @@ -1085,6 +1089,7 @@ int tpm_tis_core_init(struct device *dev, struct tpm_tis_data *priv, int irq,
> } else {
> tpm_tis_probe_irq(chip, intmask);
> }
> + tpm_chip_stop(chip);
> }
>
> rc = tpm_chip_register(chip);

2021-01-26 19:27:04

by Lukasz Majczak

Subject: Re: [PATCH] tpm_tis: Add missing start/stop_tpm_chip calls

Hi Jarkko, Guenter

Yes, here are the logs when failure occurs -
https://gist.github.com/semihalf-majczak-lukasz/1575461f585f1e7fb1e9366b8eceaab9
Look for a phrase "TPM returned invalid status"

Guenter - good suggestion - I will try to keep it as tight as possible.

Best regards,
Lukasz

pon., 25 sty 2021 o 18:18 Guenter Roeck <[email protected]> napisał(a):
>
> Hi Lukasz,
>
> On Sat, Jan 23, 2021 at 02:42:47AM +0100, Lukasz Majczak wrote:
> > There is a missing call to start_tpm_chip before the call to
> > the tpm_get_timeouts() and tpm_tis_probe_irq_single(). As the current
> > approach maight work for tpm2, it fails for tpm1.x - in that case
> > call to tpm_get_timeouts() or tpm_tis_probe_irq_single() tries to
> > transmit TPM commands on a disabled chip what what doesn't succeed
>
> s/what what/what/
>
> > and in turn causes tpm_tis_core_init() to fail.
> > Tested on Samsung Chromebook Pro (Caroline).
> >
> > Signed-off-by: Lukasz Majczak <[email protected]>
> > ---
> > drivers/char/tpm/tpm_tis_core.c | 5 +++++
> > 1 file changed, 5 insertions(+)
> >
> > diff --git a/drivers/char/tpm/tpm_tis_core.c b/drivers/char/tpm/tpm_tis_core.c
> > index 92c51c6cfd1b..ff0e5fe46a9d 100644
> > --- a/drivers/char/tpm/tpm_tis_core.c
> > +++ b/drivers/char/tpm/tpm_tis_core.c
> > @@ -1063,12 +1063,16 @@ int tpm_tis_core_init(struct device *dev, struct tpm_tis_data *priv, int irq,
> > init_waitqueue_head(&priv->read_queue);
> > init_waitqueue_head(&priv->int_queue);
> > if (irq != -1) {
> > + rc = tpm_chip_start(chip);
>
> Unless I am missing something, the underlying problem seems to be
> the calls to tpm1_getcap(). From other code calling this function,
> it looks like it may only require tpm_clk_enable() to work.
>
> With that in mind, would it possibly be better to call tpm_clk_enable()
> and tpm_clk_disable() around the calls to tpm1_getcap(), ie in
> tpm1_get_timeouts() and in tpm_tis_gen_interrupt() ?
>
> This would avoid the unnecessary calls to tpm_chip_start() and
> tpm_chip_stop() for tpm2 chips.
>
> Thanks,
> Guenter
>
>
> > + if (rc)
> > + goto out_err;
> > /* Before doing irq testing issue a command to the TPM in polling mode
> > * to make sure it works. May as well use that command to set the
> > * proper timeouts for the driver.
> > */
> > if (tpm_get_timeouts(chip)) {
> > dev_err(dev, "Could not get TPM timeouts and durations\n");
> > + tpm_chip_stop(chip);
> > rc = -ENODEV;
> > goto out_err;
> > }
> > @@ -1085,6 +1089,7 @@ int tpm_tis_core_init(struct device *dev, struct tpm_tis_data *priv, int irq,
> > } else {
> > tpm_tis_probe_irq(chip, intmask);
> > }
> > + tpm_chip_stop(chip);
> > }
> >
> > rc = tpm_chip_register(chip);

2021-01-27 00:36:07

by James Bottomley

Subject: Re: [PATCH] tpm_tis: Add missing start/stop_tpm_chip calls

On Tue, 2021-01-26 at 16:46 +0100, Łukasz Majczak wrote:
> Hi Jarkko, Guenter
>
> Yes, here are the logs when failure occurs -
> https://gist.github.com/semihalf-majczak-lukasz/1575461f585f1e7fb1e9366b8eceaab9
> Look for a phrase "TPM returned invalid status"

We've had other reports of this:

https://lore.kernel.org/linux-integrity/[email protected]/
https://lore.kernel.org/linux-integrity/[email protected]/

The problem is some TIS TPMs don't begin in the correct locality so we
have to set it. When I proposed the check, I also proposed a fix for
this problem:

https://lore.kernel.org/linux-integrity/[email protected]/

But it's part of a series that never went upstream. Part of the reason
was Jarkko proposed the get/put patch to fix this instead, but that
never went upstream either. We need to decide an approach and apply
one or other fixes.

James

2021-01-27 19:51:44

by Tj (Elloe Linux)

Subject: Re: [PATCH] tpm_tis: Add missing start/stop_tpm_chip calls

On 26/01/2021 16:46, James Bottomley wrote:
> On Tue, 2021-01-26 at 16:46 +0100, Łukasz Majczak wrote:
>> Hi Jarkko, Guenter
>>
>> Yes, here are the logs when failure occurs -
>> https://gist.github.com/semihalf-majczak-lukasz/1575461f585f1e7fb1e9366b8eceaab9
>> Look for a phrase "TPM returned invalid status"
>
> We've had other reports of this:
>
> https://lore.kernel.org/linux-integrity/[email protected]/
> https://lore.kernel.org/linux-integrity/[email protected]/
>
> The problem is some TIS TPMs don't begin in the correct locality so we
> have to set it. When I proposed the check, I also proposed a fix for
> this problem:
>
> https://lore.kernel.org/linux-integrity/[email protected]/
>
This patch solves the error messages on top of -rc5

> But it's part of a series that never went upstream. Part of the reason
> was Jarkko proposed the get/put patch to fix this instead, but that
> never went upstream either. We need to decide an approach and apply
> one or other fixes.
>
> James
>
>

2021-01-28 06:03:50

by Jarkko Sakkinen

Subject: Re: [PATCH] tpm_tis: Add missing start/stop_tpm_chip calls

On Tue, Jan 26, 2021 at 08:46:48AM -0800, James Bottomley wrote:
> On Tue, 2021-01-26 at 16:46 +0100, Łukasz Majczak wrote:
> > Hi Jarkko, Guenter
> >
> > Yes, here are the logs when failure occurs -
> > https://gist.github.com/semihalf-majczak-lukasz/1575461f585f1e7fb1e9366b8eceaab9
> > Look for a phrase "TPM returned invalid status"
>
> We've had other reports of this:
>
> https://lore.kernel.org/linux-integrity/[email protected]/
> https://lore.kernel.org/linux-integrity/[email protected]/
>
> The problem is some TIS TPMs don't begin in the correct locality so we
> have to set it. When I proposed the check, I also proposed a fix for
> this problem:
>
> https://lore.kernel.org/linux-integrity/[email protected]/
>
> But it's part of a series that never went upstream. Part of the reason
> was Jarkko proposed the get/put patch to fix this instead, but that
> never went upstream either. We need to decide an approach and apply
> one or other fixes.

Can you remind me what I proposed? I remember only proposing removing
interrupt code.

Can you pick up just 1/5 and 2/5 from that serieis and send them as a
mini series?

I had one remark for 1/5, which can be found here:

https://lore.kernel.org/linux-integrity/[email protected]/

I don't think there was never argument on locality changes.

/Jarkko

2021-01-28 13:11:49

by Lukasz Majczak

Subject: [PATCH v2] tpm_tis: Add missing tpm_request/relinquish_locality calls

There is a missing call to tpm_request_locality before the call to
the tpm_get_timeouts() and tpm_tis_probe_irq_single(). As the current
approach might work for tpm2, it fails for tpm1.x - in that case
call to tpm_get_timeouts() or tpm_tis_probe_irq_single()
without locality fails and in turn causes tpm_tis_core_init() to fail.
Tested on Samsung Chromebook Pro (Caroline).

Signed-off-by: Lukasz Majczak <[email protected]>
---
Jarkko, James, Guenter

I’m aware about the other thread, but it seems to be dead for a few months.
Here is the small patch as fixing this specific issue
would allow us to unblock the ChromeOs development.
We want to upstream all of our patches,
so the ChromeOs will not diverge even more,
so I'm hoping this could be applied, if you see it neat enough.

Best regards,
Lukasz

v1 -> v2:
- fixed typos
- as there is no need to enable clock, switched to
use only tpm_request/relinquish_locality calls
- narrowed down boundaries of tpm_request/relinquish_locality calls

drivers/char/tpm/tpm-chip.c | 4 ++--
drivers/char/tpm/tpm-interface.c | 11 +++++++++--
drivers/char/tpm/tpm.h | 2 ++
drivers/char/tpm/tpm_tis_core.c | 12 ++++++++++--
4 files changed, 23 insertions(+), 6 deletions(-)

diff --git a/drivers/char/tpm/tpm-chip.c b/drivers/char/tpm/tpm-chip.c
index ddaeceb7e109..5351963a4b19 100644
--- a/drivers/char/tpm/tpm-chip.c
+++ b/drivers/char/tpm/tpm-chip.c
@@ -32,7 +32,7 @@ struct class *tpm_class;
struct class *tpmrm_class;
dev_t tpm_devt;

-static int tpm_request_locality(struct tpm_chip *chip)
+int tpm_request_locality(struct tpm_chip *chip)
{
int rc;

@@ -47,7 +47,7 @@ static int tpm_request_locality(struct tpm_chip *chip)
return 0;
}

-static void tpm_relinquish_locality(struct tpm_chip *chip)
+void tpm_relinquish_locality(struct tpm_chip *chip)
{
int rc;

diff --git a/drivers/char/tpm/tpm-interface.c b/drivers/char/tpm/tpm-interface.c
index 1621ce818705..69309b2bea6a 100644
--- a/drivers/char/tpm/tpm-interface.c
+++ b/drivers/char/tpm/tpm-interface.c
@@ -243,8 +243,15 @@ int tpm_get_timeouts(struct tpm_chip *chip)

if (chip->flags & TPM_CHIP_FLAG_TPM2)
return tpm2_get_timeouts(chip);
- else
- return tpm1_get_timeouts(chip);
+ else {
+ ssize_t ret = tpm_request_locality(chip);
+
+ if (ret)
+ return ret;
+ ret = tpm1_get_timeouts(chip);
+ tpm_relinquish_locality(chip);
+ return ret;
+ }
}
EXPORT_SYMBOL_GPL(tpm_get_timeouts);

diff --git a/drivers/char/tpm/tpm.h b/drivers/char/tpm/tpm.h
index 947d1db0a5cc..8c13008437dd 100644
--- a/drivers/char/tpm/tpm.h
+++ b/drivers/char/tpm/tpm.h
@@ -193,6 +193,8 @@ static inline void tpm_msleep(unsigned int delay_msec)

int tpm_chip_start(struct tpm_chip *chip);
void tpm_chip_stop(struct tpm_chip *chip);
+int tpm_request_locality(struct tpm_chip *chip);
+void tpm_relinquish_locality(struct tpm_chip *chip);
struct tpm_chip *tpm_find_get_ops(struct tpm_chip *chip);
__must_check int tpm_try_get_ops(struct tpm_chip *chip);
void tpm_put_ops(struct tpm_chip *chip);
diff --git a/drivers/char/tpm/tpm_tis_core.c b/drivers/char/tpm/tpm_tis_core.c
index 92c51c6cfd1b..0ae675e8cf2f 100644
--- a/drivers/char/tpm/tpm_tis_core.c
+++ b/drivers/char/tpm/tpm_tis_core.c
@@ -754,9 +754,17 @@ static int tpm_tis_gen_interrupt(struct tpm_chip *chip)

if (chip->flags & TPM_CHIP_FLAG_TPM2)
return tpm2_get_tpm_pt(chip, 0x100, &cap2, desc);
- else
- return tpm1_getcap(chip, TPM_CAP_PROP_TIS_TIMEOUT, &cap, desc,
+ else {
+ ssize_t ret = tpm_request_locality(chip);
+
+ if (ret)
+ return ret;
+ ret = tpm1_getcap(chip, TPM_CAP_PROP_TIS_TIMEOUT, &cap, desc,
0);
+ tpm_relinquish_locality(chip);
+ return ret;
+ }
+
}

/* Register the IRQ and issue a command that will cause an interrupt. If an
--
2.25.1

2021-01-28 17:43:22

by Guenter Roeck

Subject: Re: [PATCH v2] tpm_tis: Add missing tpm_request/relinquish_locality calls

Hi Lukasz,

On Thu, Jan 28, 2021 at 02:07:53PM +0100, Lukasz Majczak wrote:
> There is a missing call to tpm_request_locality before the call to
> the tpm_get_timeouts() and tpm_tis_probe_irq_single(). As the current
> approach might work for tpm2, it fails for tpm1.x - in that case
> call to tpm_get_timeouts() or tpm_tis_probe_irq_single()
> without locality fails and in turn causes tpm_tis_core_init() to fail.
> Tested on Samsung Chromebook Pro (Caroline).
>
> Signed-off-by: Lukasz Majczak <[email protected]>
> ---
> Jarkko, James, Guenter
>
> I’m aware about the other thread, but it seems to be dead for a few months.
> Here is the small patch as fixing this specific issue
> would allow us to unblock the ChromeOs development.
> We want to upstream all of our patches,
> so the ChromeOs will not diverge even more,
> so I'm hoping this could be applied, if you see it neat enough.
>
> Best regards,
> Lukasz
>
> v1 -> v2:
> - fixed typos
> - as there is no need to enable clock, switched to
> use only tpm_request/relinquish_locality calls
> - narrowed down boundaries of tpm_request/relinquish_locality calls
>
> drivers/char/tpm/tpm-chip.c | 4 ++--
> drivers/char/tpm/tpm-interface.c | 11 +++++++++--
> drivers/char/tpm/tpm.h | 2 ++
> drivers/char/tpm/tpm_tis_core.c | 12 ++++++++++--
> 4 files changed, 23 insertions(+), 6 deletions(-)
>
> diff --git a/drivers/char/tpm/tpm-chip.c b/drivers/char/tpm/tpm-chip.c
> index ddaeceb7e109..5351963a4b19 100644
> --- a/drivers/char/tpm/tpm-chip.c
> +++ b/drivers/char/tpm/tpm-chip.c
> @@ -32,7 +32,7 @@ struct class *tpm_class;
> struct class *tpmrm_class;
> dev_t tpm_devt;
>
> -static int tpm_request_locality(struct tpm_chip *chip)
> +int tpm_request_locality(struct tpm_chip *chip)
> {
> int rc;
>
> @@ -47,7 +47,7 @@ static int tpm_request_locality(struct tpm_chip *chip)
> return 0;
> }
>
> -static void tpm_relinquish_locality(struct tpm_chip *chip)
> +void tpm_relinquish_locality(struct tpm_chip *chip)
> {
> int rc;
>
> diff --git a/drivers/char/tpm/tpm-interface.c b/drivers/char/tpm/tpm-interface.c
> index 1621ce818705..69309b2bea6a 100644
> --- a/drivers/char/tpm/tpm-interface.c
> +++ b/drivers/char/tpm/tpm-interface.c
> @@ -243,8 +243,15 @@ int tpm_get_timeouts(struct tpm_chip *chip)
>
> if (chip->flags & TPM_CHIP_FLAG_TPM2)
> return tpm2_get_timeouts(chip);
> - else
> - return tpm1_get_timeouts(chip);
> + else {

{ } needed around if part of if/else statement.

> + ssize_t ret = tpm_request_locality(chip);
> +
> + if (ret)
> + return ret;
> + ret = tpm1_get_timeouts(chip);
> + tpm_relinquish_locality(chip);
> + return ret;
> + }
> }
> EXPORT_SYMBOL_GPL(tpm_get_timeouts);
>
> diff --git a/drivers/char/tpm/tpm.h b/drivers/char/tpm/tpm.h
> index 947d1db0a5cc..8c13008437dd 100644
> --- a/drivers/char/tpm/tpm.h
> +++ b/drivers/char/tpm/tpm.h
> @@ -193,6 +193,8 @@ static inline void tpm_msleep(unsigned int delay_msec)
>
> int tpm_chip_start(struct tpm_chip *chip);
> void tpm_chip_stop(struct tpm_chip *chip);
> +int tpm_request_locality(struct tpm_chip *chip);
> +void tpm_relinquish_locality(struct tpm_chip *chip);
> struct tpm_chip *tpm_find_get_ops(struct tpm_chip *chip);
> __must_check int tpm_try_get_ops(struct tpm_chip *chip);
> void tpm_put_ops(struct tpm_chip *chip);
> diff --git a/drivers/char/tpm/tpm_tis_core.c b/drivers/char/tpm/tpm_tis_core.c
> index 92c51c6cfd1b..0ae675e8cf2f 100644
> --- a/drivers/char/tpm/tpm_tis_core.c
> +++ b/drivers/char/tpm/tpm_tis_core.c
> @@ -754,9 +754,17 @@ static int tpm_tis_gen_interrupt(struct tpm_chip *chip)
>
> if (chip->flags & TPM_CHIP_FLAG_TPM2)
> return tpm2_get_tpm_pt(chip, 0x100, &cap2, desc);
> - else
> - return tpm1_getcap(chip, TPM_CAP_PROP_TIS_TIMEOUT, &cap, desc,
> + else {
> + ssize_t ret = tpm_request_locality(chip);
> +
> + if (ret)
> + return ret;
> + ret = tpm1_getcap(chip, TPM_CAP_PROP_TIS_TIMEOUT, &cap, desc,
> 0);
> + tpm_relinquish_locality(chip);
> + return ret;
> + }
> +

James' earlier patch does not address the problem in tpm_get_timeouts().
However, it states that "interrupt registers are only writeable in
the current locality" and "TPM_CHIP_FLAG_IRQ never gets set initially".
So the question is if the above is sufficient, or if James' patch
(requesting locality for all of tpm_tis_probe_irq_single and setting
TPM_CHIP_FLAG_IRQ) is needed. Unfortunately I can not answer that.

Guenter

> }
>
> /* Register the IRQ and issue a command that will cause an interrupt. If an
> --
> 2.25.1
>

2021-01-29 22:53:52

by Jarkko Sakkinen

Subject: Re: [PATCH] tpm_tis: Add missing start/stop_tpm_chip calls

On Mon, Jan 25, 2021 at 09:18:46AM -0800, Guenter Roeck wrote:
> Hi Lukasz,
>
> On Sat, Jan 23, 2021 at 02:42:47AM +0100, Lukasz Majczak wrote:
> > There is a missing call to start_tpm_chip before the call to
> > the tpm_get_timeouts() and tpm_tis_probe_irq_single(). As the current
> > approach maight work for tpm2, it fails for tpm1.x - in that case
> > call to tpm_get_timeouts() or tpm_tis_probe_irq_single() tries to
> > transmit TPM commands on a disabled chip what what doesn't succeed
>
> s/what what/what/

s/maight/might/

Also, would be nice to have the capatalization of acronyms correct
and consistent. E.g. tpm1.x should be rather written as "TPM 1.x
chips".

It's also incorrect to state that something fails for TPM 1.x chips,
unless you can somehow make a sense that every single TPM 1.x at wild
fails, which probably is not true.

> > and in turn causes tpm_tis_core_init() to fail.
> > Tested on Samsung Chromebook Pro (Caroline).

Anyone can tell me what does Caroline mean anyway?

> >
> > Signed-off-by: Lukasz Majczak <[email protected]>
> > ---
> > drivers/char/tpm/tpm_tis_core.c | 5 +++++
> > 1 file changed, 5 insertions(+)
> >
> > diff --git a/drivers/char/tpm/tpm_tis_core.c b/drivers/char/tpm/tpm_tis_core.c
> > index 92c51c6cfd1b..ff0e5fe46a9d 100644
> > --- a/drivers/char/tpm/tpm_tis_core.c
> > +++ b/drivers/char/tpm/tpm_tis_core.c
> > @@ -1063,12 +1063,16 @@ int tpm_tis_core_init(struct device *dev, struct tpm_tis_data *priv, int irq,
> > init_waitqueue_head(&priv->read_queue);
> > init_waitqueue_head(&priv->int_queue);
> > if (irq != -1) {
> > + rc = tpm_chip_start(chip);
>
> Unless I am missing something, the underlying problem seems to be
> the calls to tpm1_getcap(). From other code calling this function,
> it looks like it may only require tpm_clk_enable() to work.

I don't claim to be bus expert but afaik CLKRUN is used with to power
on/off clock, when using LPC bus.

Also, TPM interface specification speaks about CLKRUN in the section
6.3 "TPM LPC Hardware Protocol".

> With that in mind, would it possibly be better to call tpm_clk_enable()
> and tpm_clk_disable() around the calls to tpm1_getcap(), ie in
> tpm1_get_timeouts() and in tpm_tis_gen_interrupt() ?
>
> This would avoid the unnecessary calls to tpm_chip_start() and
> tpm_chip_stop() for tpm2 chips.

Not enough information about hardware and no klog. Cannot make much
conclusions with the information available.

> Thanks,
> Guenter

Off-topic: I noticed some dumb code in tpm_tis_core.c:

if (chip->ops->clk_enable != NULL)
chip->ops->clk_enable(chip, false);

These should be definitely changed as:

tpm_tis_clkrun_enable(chip, false);

->clk_enable() should be only used in tpm-interface.c.

Not a bug, just really stupid code (and harder to trace).

/Jarkko

2021-01-29 23:01:20

by Jarkko Sakkinen

Subject: Re: [PATCH] tpm_tis: Add missing start/stop_tpm_chip calls

On Tue, Jan 26, 2021 at 04:46:07PM +0100, Łukasz Majczak wrote:
> Hi Jarkko, Guenter
>
> Yes, here are the logs when failure occurs -
> https://gist.github.com/semihalf-majczak-lukasz/1575461f585f1e7fb1e9366b8eceaab9
> Look for a phrase "TPM returned invalid status"
>
> Guenter - good suggestion - I will try to keep it as tight as possible.
>
> Best regards,
> Lukasz

Is it possible for you try out with linux-next? Thanks. It's a known
issue, which ought to be fixed by now.

The log message is harmless, it'a warning not panic, and does not
endanger system stability. WARN()'s always dump stack trace. No oops
is happening.

/Jarkko

2021-01-29 23:04:27

by Jarkko Sakkinen

Subject: Re: [PATCH] tpm_tis: Add missing start/stop_tpm_chip calls

On Sat, Jan 30, 2021 at 12:59:09AM +0200, Jarkko Sakkinen wrote:
> On Tue, Jan 26, 2021 at 04:46:07PM +0100, Łukasz Majczak wrote:
> > Hi Jarkko, Guenter
> >
> > Yes, here are the logs when failure occurs -
> > https://gist.github.com/semihalf-majczak-lukasz/1575461f585f1e7fb1e9366b8eceaab9
> > Look for a phrase "TPM returned invalid status"
> >
> > Guenter - good suggestion - I will try to keep it as tight as possible.
> >
> > Best regards,
> > Lukasz
>
> Is it possible for you try out with linux-next? Thanks. It's a known
> issue, which ought to be fixed by now.
>
> The log message is harmless, it'a warning not panic, and does not
> endanger system stability. WARN()'s always dump stack trace. No oops
> is happening.

The regression itself originates from 2006. It has just been unmasked
with "improved" logging.

/Jarkko

2021-01-29 23:35:49

by Guenter Roeck

Subject: Re: [PATCH] tpm_tis: Add missing start/stop_tpm_chip calls

On 1/29/21 2:49 PM, Jarkko Sakkinen wrote:
> On Mon, Jan 25, 2021 at 09:18:46AM -0800, Guenter Roeck wrote:
>> Hi Lukasz,
>>
>> On Sat, Jan 23, 2021 at 02:42:47AM +0100, Lukasz Majczak wrote:
>>> There is a missing call to start_tpm_chip before the call to
>>> the tpm_get_timeouts() and tpm_tis_probe_irq_single(). As the current
>>> approach maight work for tpm2, it fails for tpm1.x - in that case
>>> call to tpm_get_timeouts() or tpm_tis_probe_irq_single() tries to
>>> transmit TPM commands on a disabled chip what what doesn't succeed
>>
>> s/what what/what/
>
> s/maight/might/
>
> Also, would be nice to have the capatalization of acronyms correct
> and consistent. E.g. tpm1.x should be rather written as "TPM 1.x
> chips".
>
> It's also incorrect to state that something fails for TPM 1.x chips,
> unless you can somehow make a sense that every single TPM 1.x at wild
> fails, which probably is not true.
>
>>> and in turn causes tpm_tis_core_init() to fail.
>>> Tested on Samsung Chromebook Pro (Caroline).
>
> Anyone can tell me what does Caroline mean anyway?
>

"Caroline" is the code name for Samsung Chromebook Pro. The term
"Samsung Chromebook Pro (Caroline)" is quite widely used for this
system. Or, alternatively, "Caroline (Samsung Chromebook Pro)".

Guenter

2021-01-30 20:43:28

by Jarkko Sakkinen

Subject: Re: [PATCH v2] tpm_tis: Add missing tpm_request/relinquish_locality calls

On Thu, 2021-01-28 at 14:07 +0100, Lukasz Majczak wrote:
> There is a missing call to tpm_request_locality before the call to
> the tpm_get_timeouts() and tpm_tis_probe_irq_single(). As the current
> approach might work for tpm2, it fails for tpm1.x - in that case
> call to tpm_get_timeouts() or tpm_tis_probe_irq_single()
> without locality fails and in turn causes tpm_tis_core_init() to fail.
> Tested on Samsung Chromebook Pro (Caroline).
>
> Signed-off-by: Lukasz Majczak <[email protected]>

Is it possible that you test against linux-next and see if any
problems still arise? I've applied the locality fixes from James.

> ---
> Jarkko, James, Guenter
>
> I’m aware about the other thread, but it seems to be dead for a few months.
> Here is the small patch as fixing this specific issue
> would allow us to unblock the ChromeOs development.
> We want to upstream all of our patches,
> so the ChromeOs will not diverge even more,
> so I'm hoping this could be applied, if you see it neat enough.

The usual approach is that you construct a series picking the pre-existing
fixes and on top of that create your own, if any required.

> Best regards,
> Lukasz

/Jarkko

>
> v1 -> v2:
>  - fixed typos
>  - as there is no need to enable clock, switched to
>    use only tpm_request/relinquish_locality calls
>  - narrowed down boundaries of tpm_request/relinquish_locality calls
>  
>  drivers/char/tpm/tpm-chip.c      |  4 ++--
>  drivers/char/tpm/tpm-interface.c | 11 +++++++++--
>  drivers/char/tpm/tpm.h           |  2 ++
>  drivers/char/tpm/tpm_tis_core.c  | 12 ++++++++++--
>  4 files changed, 23 insertions(+), 6 deletions(-)
>
> diff --git a/drivers/char/tpm/tpm-chip.c b/drivers/char/tpm/tpm-chip.c
> index ddaeceb7e109..5351963a4b19 100644
> --- a/drivers/char/tpm/tpm-chip.c
> +++ b/drivers/char/tpm/tpm-chip.c
> @@ -32,7 +32,7 @@ struct class *tpm_class;
>  struct class *tpmrm_class;
>  dev_t tpm_devt;
>  
> -static int tpm_request_locality(struct tpm_chip *chip)
> +int tpm_request_locality(struct tpm_chip *chip)
>  {
>         int rc;
>  
> @@ -47,7 +47,7 @@ static int tpm_request_locality(struct tpm_chip *chip)
>         return 0;
>  }
>  
> -static void tpm_relinquish_locality(struct tpm_chip *chip)
> +void tpm_relinquish_locality(struct tpm_chip *chip)
>  {
>         int rc;
>  
> diff --git a/drivers/char/tpm/tpm-interface.c b/drivers/char/tpm/tpm-interface.c
> index 1621ce818705..69309b2bea6a 100644
> --- a/drivers/char/tpm/tpm-interface.c
> +++ b/drivers/char/tpm/tpm-interface.c
> @@ -243,8 +243,15 @@ int tpm_get_timeouts(struct tpm_chip *chip)
>  
>         if (chip->flags & TPM_CHIP_FLAG_TPM2)
>                 return tpm2_get_timeouts(chip);
> -       else
> -               return tpm1_get_timeouts(chip);
> +       else {
> +               ssize_t ret = tpm_request_locality(chip);
> +
> +               if (ret)
> +                       return ret;
> +               ret = tpm1_get_timeouts(chip);
> +               tpm_relinquish_locality(chip);
> +               return ret;
> +       }
>  }
>  EXPORT_SYMBOL_GPL(tpm_get_timeouts);
>  
> diff --git a/drivers/char/tpm/tpm.h b/drivers/char/tpm/tpm.h
> index 947d1db0a5cc..8c13008437dd 100644
> --- a/drivers/char/tpm/tpm.h
> +++ b/drivers/char/tpm/tpm.h
> @@ -193,6 +193,8 @@ static inline void tpm_msleep(unsigned int delay_msec)
>  
>  int tpm_chip_start(struct tpm_chip *chip);
>  void tpm_chip_stop(struct tpm_chip *chip);
> +int tpm_request_locality(struct tpm_chip *chip);
> +void tpm_relinquish_locality(struct tpm_chip *chip);
>  struct tpm_chip *tpm_find_get_ops(struct tpm_chip *chip);
>  __must_check int tpm_try_get_ops(struct tpm_chip *chip);
>  void tpm_put_ops(struct tpm_chip *chip);
> diff --git a/drivers/char/tpm/tpm_tis_core.c b/drivers/char/tpm/tpm_tis_core.c
> index 92c51c6cfd1b..0ae675e8cf2f 100644
> --- a/drivers/char/tpm/tpm_tis_core.c
> +++ b/drivers/char/tpm/tpm_tis_core.c
> @@ -754,9 +754,17 @@ static int tpm_tis_gen_interrupt(struct tpm_chip *chip)
>  
>         if (chip->flags & TPM_CHIP_FLAG_TPM2)
>                 return tpm2_get_tpm_pt(chip, 0x100, &cap2, desc);
> -       else
> -               return tpm1_getcap(chip, TPM_CAP_PROP_TIS_TIMEOUT, &cap, desc,
> +       else {
> +               ssize_t ret = tpm_request_locality(chip);
> +
> +               if (ret)
> +                       return ret;
> +               ret = tpm1_getcap(chip, TPM_CAP_PROP_TIS_TIMEOUT, &cap, desc,
>                                   0);
> +               tpm_relinquish_locality(chip);
> +               return ret;
> +       }
> +
>  }
>  
>  /* Register the IRQ and issue a command that will cause an interrupt. If an

2021-01-30 20:50:44

by Jarkko Sakkinen

Subject: Re: [PATCH v2] tpm_tis: Add missing tpm_request/relinquish_locality calls

On Sat, 2021-01-30 at 22:40 +0200, Jarkko Sakkinen wrote:
> On Thu, 2021-01-28 at 14:07 +0100, Lukasz Majczak wrote:
> > There is a missing call to tpm_request_locality before the call to
> > the tpm_get_timeouts() and tpm_tis_probe_irq_single(). As the current
> > approach might work for tpm2, it fails for tpm1.x - in that case
> > call to tpm_get_timeouts() or tpm_tis_probe_irq_single()
> > without locality fails and in turn causes tpm_tis_core_init() to fail.
> > Tested on Samsung Chromebook Pro (Caroline).
> >
> > Signed-off-by: Lukasz Majczak <[email protected]>
>
> Is it possible that you test against linux-next and see if any
> problems still arise? I've applied the locality fixes from James.

Also one nit: if any problems still persist, please add a snippet
from klog to your commit message.

/Jarkko

2021-01-30 23:55:49

by Guenter Roeck

Subject: Re: [PATCH] tpm_tis: Add missing start/stop_tpm_chip calls

On 1/29/21 2:59 PM, Jarkko Sakkinen wrote:
> On Tue, Jan 26, 2021 at 04:46:07PM +0100, Łukasz Majczak wrote:
>> Hi Jarkko, Guenter
>>
>> Yes, here are the logs when failure occurs -
>> https://gist.github.com/semihalf-majczak-lukasz/1575461f585f1e7fb1e9366b8eceaab9
>> Look for a phrase "TPM returned invalid status"
>>
>> Guenter - good suggestion - I will try to keep it as tight as possible.
>>
>> Best regards,
>> Lukasz
>
> Is it possible for you try out with linux-next? Thanks. It's a known
> issue, which ought to be fixed by now.
>
> The log message is harmless, it'a warning not panic, and does not
> endanger system stability. WARN()'s always dump stack trace. No oops
> is happening.
>

There is a note in the kernel documentation which states:

Note that the WARN()-family should only be used for "expected to
be unreachable" situations. If you want to warn about "reachable
but undesirable" situations, please use the pr_warn()-family of
functions.

It seems to me that "harmless" doesn't really fit the expected
use of WARN(). Should it possibly be converted to pr_warn() ?

Thanks,
Guenter

2021-01-31 00:45:34

by James Bottomley

Subject: Re: [PATCH] tpm_tis: Add missing start/stop_tpm_chip calls

On Sat, 2021-01-30 at 15:49 -0800, Guenter Roeck wrote:
> On 1/29/21 2:59 PM, Jarkko Sakkinen wrote:
> > On Tue, Jan 26, 2021 at 04:46:07PM +0100, Łukasz Majczak wrote:
> > > Hi Jarkko, Guenter
> > >
> > > Yes, here are the logs when failure occurs -
> > > https://gist.github.com/semihalf-majczak-lukasz/1575461f585f1e7fb1e9366b8eceaab9
> > > Look for a phrase "TPM returned invalid status"
> > >
> > > Guenter - good suggestion - I will try to keep it as tight as
> > > possible.
> > >
> > > Best regards,
> > > Lukasz
> >
> > Is it possible for you try out with linux-next? Thanks. It's a
> > known issue, which ought to be fixed by now.
> >
> > The log message is harmless, it'a warning not panic, and does not
> > endanger system stability. WARN()'s always dump stack trace. No
> > oops is happening.
> >
>
> There is a note in the kernel documentation which states:
>
> Note that the WARN()-family should only be used for "expected to
> be unreachable" situations. If you want to warn about "reachable
> but undesirable" situations, please use the pr_warn()-family of
> functions.

It fits the definition. The warning only triggers if the access is in
the wrong locality, which should be impossible, so the warning should
be unreachable.

James

> It seems to me that "harmless" doesn't really fit the expected
> use of WARN(). Should it possibly be converted to pr_warn() ?

2021-01-31 03:38:27

by Guenter Roeck

Subject: Re: [PATCH] tpm_tis: Add missing start/stop_tpm_chip calls

On 1/30/21 4:41 PM, James Bottomley wrote:
> On Sat, 2021-01-30 at 15:49 -0800, Guenter Roeck wrote:
>> On 1/29/21 2:59 PM, Jarkko Sakkinen wrote:
>>> On Tue, Jan 26, 2021 at 04:46:07PM +0100, Łukasz Majczak wrote:
>>>> Hi Jarkko, Guenter
>>>>
>>>> Yes, here are the logs when failure occurs -
>>>> https://gist.github.com/semihalf-majczak-lukasz/1575461f585f1e7fb1e9366b8eceaab9
>>>> Look for a phrase "TPM returned invalid status"
>>>>
>>>> Guenter - good suggestion - I will try to keep it as tight as
>>>> possible.
>>>>
>>>> Best regards,
>>>> Lukasz
>>>
>>> Is it possible for you try out with linux-next? Thanks. It's a
>>> known issue, which ought to be fixed by now.
>>>
>>> The log message is harmless, it'a warning not panic, and does not
>>> endanger system stability. WARN()'s always dump stack trace. No
>>> oops is happening.
>>>
>>
>> There is a note in the kernel documentation which states:
>>
>> Note that the WARN()-family should only be used for "expected to
>> be unreachable" situations. If you want to warn about "reachable
>> but undesirable" situations, please use the pr_warn()-family of
>> functions.
>
> It fits the definition. The warning only triggers if the access is in
> the wrong locality, which should be impossible, so the warning should
> be unreachable.
>
Thanks a lot for the clarification. So a warning traceback in the kernel
doesn't necessarily suggest that there is a serious problem that should
be fixed; it only means that some code is executed which should not be
reachable (but is otherwise harmless).

That makes me wonder, though, if it would make sense to mark such harmless
tracebacks differently. The terms "warning" and "harmless" sound like
a bit of a contradiction to me (especially for systems where panic_on_warn
is set).

Thanks,
Guenter

2021-01-31 04:24:14

by James Bottomley

Subject: Re: [PATCH] tpm_tis: Add missing start/stop_tpm_chip calls

On Sat, 2021-01-30 at 19:36 -0800, Guenter Roeck wrote:
> On 1/30/21 4:41 PM, James Bottomley wrote:
> > On Sat, 2021-01-30 at 15:49 -0800, Guenter Roeck wrote:
> > > On 1/29/21 2:59 PM, Jarkko Sakkinen wrote:
> > > > On Tue, Jan 26, 2021 at 04:46:07PM +0100, Łukasz Majczak wrote:
> > > > > Hi Jarkko, Guenter
> > > > >
> > > > > Yes, here are the logs when failure occurs -
> > > > > https://gist.github.com/semihalf-majczak-lukasz/1575461f585f1e7fb1e9366b8eceaab9
> > > > > Look for a phrase "TPM returned invalid status"
> > > > >
> > > > > Guenter - good suggestion - I will try to keep it as tight as
> > > > > possible.
> > > > >
> > > > > Best regards,
> > > > > Lukasz
> > > >
> > > > Is it possible for you try out with linux-next? Thanks. It's a
> > > > known issue, which ought to be fixed by now.
> > > >
> > > > The log message is harmless, it'a warning not panic, and does
> > > > not endanger system stability. WARN()'s always dump stack
> > > > trace. No oops is happening.
> > > >
> > >
> > > There is a note in the kernel documentation which states:
> > >
> > > Note that the WARN()-family should only be used for "expected to
> > > be unreachable" situations. If you want to warn about "reachable
> > > but undesirable" situations, please use the pr_warn()-family of
> > > functions.
> >
> > It fits the definition. The warning only triggers if the access is
> > in the wrong locality, which should be impossible, so the warning
> > should be unreachable.
> >
> Thanks a lot for the clarification. So a warning traceback in the
> kernel doesn't necessarily suggest that there is a serious problem
> that should be fixed; it only means that some code is executed which
> should not be reachable (but is otherwise harmless).
>
> That makes me wonder, though, if it would make sense to mark such
> harmless tracebacks differently. The terms "warning" and "harmless"
> sound like a bit of a contradiction to me (especially for systems
> where panic_on_warn is set).

Well, it's not harmless; because it occurs at start of day, it means we
clear the ineffective command and use default values and those happen
to work fine for the TPM in question, so the problem is pretty much
covered up. If it had occurred anywhere else it would result in a loss
of the command data with unknown ramifications to user space, possibly
leading to a TPM failure.

Hopefully this means this is the only place we screwed up, but you can
see why a scary warning and stack trace is appropriate: if it triggers,
something in the kernel violated the TPM command model.

James

2021-01-31 11:59:15

by Dirk Gouders

Subject: Re: [PATCH v2] tpm_tis: Add missing tpm_request/relinquish_locality calls

Jarkko Sakkinen <[email protected]> writes:

> On Thu, 2021-01-28 at 14:07 +0100, Lukasz Majczak wrote:
>> There is a missing call to tpm_request_locality before the call to
>> the tpm_get_timeouts() and tpm_tis_probe_irq_single(). As the current
>> approach might work for tpm2, it fails for tpm1.x - in that case
>> call to tpm_get_timeouts() or tpm_tis_probe_irq_single()
>> without locality fails and in turn causes tpm_tis_core_init() to fail.
>> Tested on Samsung Chromebook Pro (Caroline).
>>
>> Signed-off-by: Lukasz Majczak <[email protected]>
>
> Is it possible that you test against linux-next and see if any
> problems still arise? I've applied the locality fixes from James.

I tested current linux-next and the warning still appears,
unfortunately.

I then incrementally applied further patches from James' series [1] and
after "[PATCH v2 4/5] tpm_tis: fix IRQ probing" the warning has gone:

# dmesg | grep tpm
[ 7.220410] tpm_tis STM0125:00: 2.0 TPM (device-id 0x0, rev-id 78)
[ 7.322564] Modules linked in: iwlmvm(+) btusb btrtl btbcm btintel mac80211 amdgpu(+) iwlwifi drm_ttm_helper tpm_crb sdhci_pci ttm cqhci gpu_sched sdhci ccp cfg80211 rng_core tpm_tis tpm_tis_core tpm thinkpad_acpi(+) wmi nvram pinctrl_amd

You might notice there is another warning but that is rtc related and I
still have to find out if that is something I should report.

Dirk

[1] https://lore.kernel.org/linux-integrity/[email protected]/

>> ---
>> Jarkko, James, Guenter
>>
>> I’m aware about the other thread, but it seems to be dead for a few months.
>> Here is the small patch as fixing this specific issue
>> would allow us to unblock the ChromeOs development.
>> We want to upstream all of our patches,
>> so the ChromeOs will not diverge even more,
>> so I'm hoping this could be applied, if you see it neat enough.
>
> The usual approach is that you construct a series picking the pre-existing
> fixes and on top of that create your own, if any required.
>
>> Best regards,
>> Lukasz
>
> /Jarkko
>
>>
>> v1 -> v2:
>>  - fixed typos
>>  - as there is no need to enable clock, switched to
>>    use only tpm_request/relinquish_locality calls
>>  - narrowed down boundaries of tpm_request/relinquish_locality calls
>>  
>>  drivers/char/tpm/tpm-chip.c      |  4 ++--
>>  drivers/char/tpm/tpm-interface.c | 11 +++++++++--
>>  drivers/char/tpm/tpm.h           |  2 ++
>>  drivers/char/tpm/tpm_tis_core.c  | 12 ++++++++++--
>>  4 files changed, 23 insertions(+), 6 deletions(-)
>>
>> diff --git a/drivers/char/tpm/tpm-chip.c b/drivers/char/tpm/tpm-chip.c
>> index ddaeceb7e109..5351963a4b19 100644
>> --- a/drivers/char/tpm/tpm-chip.c
>> +++ b/drivers/char/tpm/tpm-chip.c
>> @@ -32,7 +32,7 @@ struct class *tpm_class;
>>  struct class *tpmrm_class;
>>  dev_t tpm_devt;
>>  
>> -static int tpm_request_locality(struct tpm_chip *chip)
>> +int tpm_request_locality(struct tpm_chip *chip)
>>  {
>>         int rc;
>>  
>> @@ -47,7 +47,7 @@ static int tpm_request_locality(struct tpm_chip *chip)
>>         return 0;
>>  }
>>  
>> -static void tpm_relinquish_locality(struct tpm_chip *chip)
>> +void tpm_relinquish_locality(struct tpm_chip *chip)
>>  {
>>         int rc;
>>  
>> diff --git a/drivers/char/tpm/tpm-interface.c b/drivers/char/tpm/tpm-interface.c
>> index 1621ce818705..69309b2bea6a 100644
>> --- a/drivers/char/tpm/tpm-interface.c
>> +++ b/drivers/char/tpm/tpm-interface.c
>> @@ -243,8 +243,15 @@ int tpm_get_timeouts(struct tpm_chip *chip)
>>  
>>         if (chip->flags & TPM_CHIP_FLAG_TPM2)
>>                 return tpm2_get_timeouts(chip);
>> -       else
>> -               return tpm1_get_timeouts(chip);
>> +       else {
>> +               ssize_t ret = tpm_request_locality(chip);
>> +
>> +               if (ret)
>> +                       return ret;
>> +               ret = tpm1_get_timeouts(chip);
>> +               tpm_relinquish_locality(chip);
>> +               return ret;
>> +       }
>>  }
>>  EXPORT_SYMBOL_GPL(tpm_get_timeouts);
>>  
>> diff --git a/drivers/char/tpm/tpm.h b/drivers/char/tpm/tpm.h
>> index 947d1db0a5cc..8c13008437dd 100644
>> --- a/drivers/char/tpm/tpm.h
>> +++ b/drivers/char/tpm/tpm.h
>> @@ -193,6 +193,8 @@ static inline void tpm_msleep(unsigned int delay_msec)
>>  
>>  int tpm_chip_start(struct tpm_chip *chip);
>>  void tpm_chip_stop(struct tpm_chip *chip);
>> +int tpm_request_locality(struct tpm_chip *chip);
>> +void tpm_relinquish_locality(struct tpm_chip *chip);
>>  struct tpm_chip *tpm_find_get_ops(struct tpm_chip *chip);
>>  __must_check int tpm_try_get_ops(struct tpm_chip *chip);
>>  void tpm_put_ops(struct tpm_chip *chip);
>> diff --git a/drivers/char/tpm/tpm_tis_core.c b/drivers/char/tpm/tpm_tis_core.c
>> index 92c51c6cfd1b..0ae675e8cf2f 100644
>> --- a/drivers/char/tpm/tpm_tis_core.c
>> +++ b/drivers/char/tpm/tpm_tis_core.c
>> @@ -754,9 +754,17 @@ static int tpm_tis_gen_interrupt(struct tpm_chip *chip)
>>  
>>         if (chip->flags & TPM_CHIP_FLAG_TPM2)
>>                 return tpm2_get_tpm_pt(chip, 0x100, &cap2, desc);
>> -       else
>> -               return tpm1_getcap(chip, TPM_CAP_PROP_TIS_TIMEOUT, &cap, desc,
>> +       else {
>> +               ssize_t ret = tpm_request_locality(chip);
>> +
>> +               if (ret)
>> +                       return ret;
>> +               ret = tpm1_getcap(chip, TPM_CAP_PROP_TIS_TIMEOUT, &cap, desc,
>>                                   0);
>> +               tpm_relinquish_locality(chip);
>> +               return ret;
>> +       }
>> +
>>  }
>>  
>>  /* Register the IRQ and issue a command that will cause an interrupt. If an

2021-02-02 22:38:51

by Jarkko Sakkinen

Subject: Re: [PATCH] tpm_tis: Add missing start/stop_tpm_chip calls

On Sat, Jan 30, 2021 at 03:49:09PM -0800, Guenter Roeck wrote:
> On 1/29/21 2:59 PM, Jarkko Sakkinen wrote:
> > On Tue, Jan 26, 2021 at 04:46:07PM +0100, Łukasz Majczak wrote:
> >> Hi Jarkko, Guenter
> >>
> >> Yes, here are the logs when failure occurs -
> >> https://gist.github.com/semihalf-majczak-lukasz/1575461f585f1e7fb1e9366b8eceaab9
> >> Look for a phrase "TPM returned invalid status"
> >>
> >> Guenter - good suggestion - I will try to keep it as tight as possible.
> >>
> >> Best regards,
> >> Lukasz
> >
> > Is it possible for you try out with linux-next? Thanks. It's a known
> > issue, which ought to be fixed by now.
> >
> > The log message is harmless, it'a warning not panic, and does not
> > endanger system stability. WARN()'s always dump stack trace. No oops
> > is happening.
> >
>
> There is a note in the kernel documentation which states:
>
> Note that the WARN()-family should only be used for "expected to
> be unreachable" situations. If you want to warn about "reachable
> but undesirable" situations, please use the pr_warn()-family of
> functions.
>
> It seems to me that "harmless" doesn't really fit the expected
> use of WARN(). Should it possibly be converted to pr_warn() ?

It should, and I agree that it was a mistake to merge the commit
that added this WARN(). I'm sending a late PR to Linus containing
just the James' fixes. I'll include one line change to that PR,
that does just what you suggested.

It also lacks useful information, i.e. the status.

I just send a fixed with your "suggested-by". Can you review and
ack it ASAP so that I can then go on and send PR to Linus?

/Jarkko

2021-02-02 22:45:14

by Lukasz Majczak

Subject: [PATCH v3] tpm_tis: Add missing tpm_request/relinquish_locality calls

There are missing calls to tpm_request_locality before the calls to
the tpm_get_timeouts() and tpm_tis_probe_irq_single() - both functions
internally send commands to the tpm. As the current
approach might work for tpm2, it fails for tpm1.x - in that case
call to tpm_get_timeouts() or tpm_tis_probe_irq_single()
without acquired locality fails and in turn causes tpm_tis_core_init()
to fail, it can be observed in the log with the following warning
trace:

[ 4.324298] TPM returned invalid status
[ 4.324806] WARNING: CPU: 2 PID: 1 at drivers/char/tpm/tpm_tis_core.c:275 tpm_tis_status+0x86/0x8f
[ 4.325888] Modules linked in:
[ 4.326287] CPU: 2 PID: 1 Comm: swapper/0 Tainted: G W 5.11.0-rc6-next-20210201-00003-g214461adb2e8 #43
[ 4.327406] Hardware name: Google Caroline/Caroline, BIOS Google_Caroline.7820.430.0 07/20/2018
[ 4.327918] RIP: 0010:tpm_tis_status+0x86/0x8f
[ 4.328323] Code: 28 00 00 00 48 3b 45 f0 75 24 89 d8 48 83 c4 10 5b 5d c3 c6 05 58 d9 28 01 01 31 db 48 c7 c7 73 52 98 9c 31 c0 e8 c2 17 b0 ff <0f> 0b eb cd e8 cf 4f 55 00 0f 1f 44 00 00 55 48 89 e56
[ 4.330592] RSP: 0000:ffff88810092f7a0 EFLAGS: 00010246
[ 4.331223] RAX: 691ee151166db100 RBX: 0000000000000000 RCX: 0000000000000001
[ 4.331860] RDX: 0000000000000006 RSI: ffffffff9c96d302 RDI: 00000000ffffffff
[ 4.332272] RBP: ffff88810092f7b8 R08: dffffc0000000000 R09: fffffbfff39c96ce
[ 4.332683] R10: fffffbfff39c96ce R11: 0000000000000001 R12: ffff8881053e2000
[ 4.333109] R13: 0000000065000000 R14: ffff888105d71000 R15: ffff888105cd2628
[ 4.333738] FS: 0000000000000000(0000) GS:ffff88842f200000(0000) knlGS:0000000000000000
[ 4.334432] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 4.334783] CR2: 0000000000000000 CR3: 0000000037828001 CR4: 00000000003706e0
[ 4.335196] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 4.335886] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 4.336793] Call Trace:
[ 4.337107] tpm_tis_send_data+0x3d/0x22f
[ 4.337506] tpm_tis_send_main+0x30/0xf5
[ 4.337746] tpm_transmit+0xbf/0x327
[ 4.338042] ? __alloc_pages_nodemask+0x261/0x36d
[ 4.338615] tpm_transmit_cmd+0x2c/0x93
[ 4.339109] tpm1_getcap+0x232/0x285
[ 4.339578] tpm1_get_timeouts+0x48/0x47d
[ 4.339964] ? lockdep_init_map_type+0x71/0x257
[ 4.340256] ? lockdep_init_map_type+0x71/0x257
[ 4.340719] ? __raw_spin_lock_init+0x40/0x69
[ 4.341208] tpm_tis_core_init+0x402/0x5ee
[ 4.341629] tpm_tis_init+0x11d/0x1a2
[ 4.341867] tpm_tis_pnp_init+0x91/0xb5
[ 4.342101] ? tis_int_handler+0x15f/0x15f
[ 4.342466] pnp_device_probe+0x79/0x9f
[ 4.342941] really_probe+0x149/0x4a8
[ 4.343412] driver_probe_device+0xd6/0x144
[ 4.343968] device_driver_attach+0x42/0x5b
[ 4.344382] __driver_attach+0xca/0x139
[ 4.344617] ? driver_attach+0x1f/0x1f
[ 4.344860] bus_for_each_dev+0x85/0xb7
[ 4.345096] bus_add_driver+0x12b/0x228
[ 4.345330] driver_register+0x64/0xed
[ 4.345560] init_tis+0xa5/0xeb
[ 4.345784] ? lock_is_held_type+0x100/0x141
[ 4.346044] ? tpm_init+0x106/0x106
[ 4.346259] ? rcu_read_lock_sched_held+0x41/0x7e
[ 4.346542] ? tpm_init+0x106/0x106
[ 4.346678] battery: ACPI: Battery Slot [BAT0] (battery present)
[ 4.346754] do_one_initcall+0x1b9/0x43d
[ 4.346776] ? asm_sysvec_apic_timer_interrupt+0x12/0x20
[ 4.347659] ? lockdep_hardirqs_on+0x8e/0x12e
[ 4.347937] ? lock_is_held_type+0x100/0x141
[ 4.348196] ? rcu_read_lock_sched_held+0x41/0x7e
[ 4.348477] do_initcall_level+0x99/0xa9
[ 4.348717] ? kernel_init+0xe/0x10a
[ 4.348954] do_initcalls+0x4e/0x79
[ 4.349170] kernel_init_freeable+0x15a/0x1ae
[ 4.349434] ? rest_init+0x1d6/0x1d6
[ 4.349655] kernel_init+0xe/0x10a
[ 4.349882] ret_from_fork+0x22/0x30
[ 4.350103] irq event stamp: 700039
[ 4.350318] hardirqs last enabled at (700047): [<ffffffff9b735265>] console_unlock+0x4be/0x538
[ 4.350836] hardirqs last disabled at (700056): [<ffffffff9b734e84>] console_unlock+0xdd/0x538
[ 4.351331] softirqs last enabled at (699522): [<ffffffff9c4004ec>] __do_softirq+0x4ec/0x539
[ 4.351835] softirqs last disabled at (699517): [<ffffffff9c200f62>] asm_call_irq_on_stack+0x12/0x20

Following the trace one can also notice a comment in the tpm_tis_status():

/*
* 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.
*/
In this case we don't have to call tpm_try_get_ops()
as both calls (tpm_get_timeouts() and tpm_tis_probe_irq_single()) are
in the tpm_tis_core_init function and don't require any locking or clock
enablement. Similar usage is in the probe_itpm() function also called
inside tpm_tis_core_init().
Tested on Samsung Chromebook Pro (Caroline).

Signed-off-by: Lukasz Majczak <[email protected]>
---
Hi Jarkko

I have checked the linux-next with James patches, also followed Dirk
suggestion applying remaining ones, although without any luck -
a warning trace was still present. As Guneter mentioned earlier, this
patch[1] doesn't address a lack of acquired locality in the
tpm_get_timeouts() and does it only for tpm_tis_probe_irq_single() but
also without a call to tpm_relinquish_locality().

Here are my logs from the clean linux-next master branch [2]
(with two James' patches present) and with my
patch applied[3]

Best regards,
Lukasz

[1] https://lore.kernel.org/linux-integrity/[email protected]/
[2] https://gist.github.com/semihalf-majczak-lukasz/f588c0684a6cc7d983bb9c4eb4bda586
[3] https://gist.github.com/semihalf-majczak-lukasz/88ede933bc7d28d806e3532850a04054

v2 -> v3:
- Added braces around if part of if/else statements
- Rebased to linux-next
- Updated commit message

drivers/char/tpm/tpm-chip.c | 4 ++--
drivers/char/tpm/tpm-interface.c | 13 ++++++++++---
drivers/char/tpm/tpm.h | 2 ++
drivers/char/tpm/tpm_tis_core.c | 14 +++++++++++---
4 files changed, 25 insertions(+), 8 deletions(-)

diff --git a/drivers/char/tpm/tpm-chip.c b/drivers/char/tpm/tpm-chip.c
index ddaeceb7e109..5351963a4b19 100644
--- a/drivers/char/tpm/tpm-chip.c
+++ b/drivers/char/tpm/tpm-chip.c
@@ -32,7 +32,7 @@ struct class *tpm_class;
struct class *tpmrm_class;
dev_t tpm_devt;

-static int tpm_request_locality(struct tpm_chip *chip)
+int tpm_request_locality(struct tpm_chip *chip)
{
int rc;

@@ -47,7 +47,7 @@ static int tpm_request_locality(struct tpm_chip *chip)
return 0;
}

-static void tpm_relinquish_locality(struct tpm_chip *chip)
+void tpm_relinquish_locality(struct tpm_chip *chip)
{
int rc;

diff --git a/drivers/char/tpm/tpm-interface.c b/drivers/char/tpm/tpm-interface.c
index 1621ce818705..2a9001d329f2 100644
--- a/drivers/char/tpm/tpm-interface.c
+++ b/drivers/char/tpm/tpm-interface.c
@@ -241,10 +241,17 @@ int tpm_get_timeouts(struct tpm_chip *chip)
if (chip->flags & TPM_CHIP_FLAG_HAVE_TIMEOUTS)
return 0;

- if (chip->flags & TPM_CHIP_FLAG_TPM2)
+ if (chip->flags & TPM_CHIP_FLAG_TPM2) {
return tpm2_get_timeouts(chip);
- else
- return tpm1_get_timeouts(chip);
+ } else {
+ ssize_t ret = tpm_request_locality(chip);
+
+ if (ret)
+ return ret;
+ ret = tpm1_get_timeouts(chip);
+ tpm_relinquish_locality(chip);
+ return ret;
+ }
}
EXPORT_SYMBOL_GPL(tpm_get_timeouts);

diff --git a/drivers/char/tpm/tpm.h b/drivers/char/tpm/tpm.h
index 947d1db0a5cc..8c13008437dd 100644
--- a/drivers/char/tpm/tpm.h
+++ b/drivers/char/tpm/tpm.h
@@ -193,6 +193,8 @@ static inline void tpm_msleep(unsigned int delay_msec)

int tpm_chip_start(struct tpm_chip *chip);
void tpm_chip_stop(struct tpm_chip *chip);
+int tpm_request_locality(struct tpm_chip *chip);
+void tpm_relinquish_locality(struct tpm_chip *chip);
struct tpm_chip *tpm_find_get_ops(struct tpm_chip *chip);
__must_check int tpm_try_get_ops(struct tpm_chip *chip);
void tpm_put_ops(struct tpm_chip *chip);
diff --git a/drivers/char/tpm/tpm_tis_core.c b/drivers/char/tpm/tpm_tis_core.c
index 431919d5f48a..d4f381d6356e 100644
--- a/drivers/char/tpm/tpm_tis_core.c
+++ b/drivers/char/tpm/tpm_tis_core.c
@@ -708,11 +708,19 @@ static int tpm_tis_gen_interrupt(struct tpm_chip *chip)
u32 cap2;
cap_t cap;

- if (chip->flags & TPM_CHIP_FLAG_TPM2)
+ if (chip->flags & TPM_CHIP_FLAG_TPM2) {
return tpm2_get_tpm_pt(chip, 0x100, &cap2, desc);
- else
- return tpm1_getcap(chip, TPM_CAP_PROP_TIS_TIMEOUT, &cap, desc,
+ } else {
+ ssize_t ret = tpm_request_locality(chip);
+
+ if (ret)
+ return ret;
+ ret = tpm1_getcap(chip, TPM_CAP_PROP_TIS_TIMEOUT, &cap, desc,
0);
+ tpm_relinquish_locality(chip);
+ return ret;
+ }
+
}

/* Register the IRQ and issue a command that will cause an interrupt. If an
--
2.25.1

2021-02-02 23:01:40

by Jarkko Sakkinen

Subject: Re: [PATCH] tpm_tis: Add missing start/stop_tpm_chip calls

On Sat, Jan 30, 2021 at 04:41:13PM -0800, James Bottomley wrote:
> On Sat, 2021-01-30 at 15:49 -0800, Guenter Roeck wrote:
> > On 1/29/21 2:59 PM, Jarkko Sakkinen wrote:
> > > On Tue, Jan 26, 2021 at 04:46:07PM +0100, Łukasz Majczak wrote:
> > > > Hi Jarkko, Guenter
> > > >
> > > > Yes, here are the logs when failure occurs -
> > > > https://gist.github.com/semihalf-majczak-lukasz/1575461f585f1e7fb1e9366b8eceaab9
> > > > Look for a phrase "TPM returned invalid status"
> > > >
> > > > Guenter - good suggestion - I will try to keep it as tight as
> > > > possible.
> > > >
> > > > Best regards,
> > > > Lukasz
> > >
> > > Is it possible for you try out with linux-next? Thanks. It's a
> > > known issue, which ought to be fixed by now.
> > >
> > > The log message is harmless, it'a warning not panic, and does not
> > > endanger system stability. WARN()'s always dump stack trace. No
> > > oops is happening.
> > >
> >
> > There is a note in the kernel documentation which states:
> >
> > Note that the WARN()-family should only be used for "expected to
> > be unreachable" situations. If you want to warn about "reachable
> > but undesirable" situations, please use the pr_warn()-family of
> > functions.
>
> It fits the definition. The warning only triggers if the access is in
> the wrong locality, which should be impossible, so the warning should
> be unreachable.

It's an overkill. Even in perfectly working kernel it's not impossible, as
sometimes hardware gives faulty data. I think that it also lacks the useful
information i.e. the status code.

I would useful WARN() only if the driver state could suffer. In this case
it doesn't. It only results failing transfer but kernel state is still
legit.

/Jarkko
>

2021-02-02 23:07:51

by Jarkko Sakkinen

Subject: Re: [PATCH v2] tpm_tis: Add missing tpm_request/relinquish_locality calls

On Sun, Jan 31, 2021 at 10:43:05AM +0100, Dirk Gouders wrote:
> Jarkko Sakkinen <[email protected]> writes:
>
> > On Thu, 2021-01-28 at 14:07 +0100, Lukasz Majczak wrote:
> >> There is a missing call to tpm_request_locality before the call to
> >> the tpm_get_timeouts() and tpm_tis_probe_irq_single(). As the current
> >> approach might work for tpm2, it fails for tpm1.x - in that case
> >> call to tpm_get_timeouts() or tpm_tis_probe_irq_single()
> >> without locality fails and in turn causes tpm_tis_core_init() to fail.
> >> Tested on Samsung Chromebook Pro (Caroline).
> >>
> >> Signed-off-by: Lukasz Majczak <[email protected]>
> >
> > Is it possible that you test against linux-next and see if any
> > problems still arise? I've applied the locality fixes from James.
>
> I tested current linux-next and the warning still appears,
> unfortunately.
>
> I then incrementally applied further patches from James' series [1] and
> after "[PATCH v2 4/5] tpm_tis: fix IRQ probing" the warning has gone:
>
> # dmesg | grep tpm
> [ 7.220410] tpm_tis STM0125:00: 2.0 TPM (device-id 0x0, rev-id 78)
> [ 7.322564] Modules linked in: iwlmvm(+) btusb btrtl btbcm btintel mac80211 amdgpu(+) iwlwifi drm_ttm_helper tpm_crb sdhci_pci ttm cqhci gpu_sched sdhci ccp cfg80211 rng_core tpm_tis tpm_tis_core tpm thinkpad_acpi(+) wmi nvram pinctrl_amd
>
> You might notice there is another warning but that is rtc related and I
> still have to find out if that is something I should report.

1/5 and 2/5 are on the other hand unconditionally "right things" to
do. In your case the resulting state will anyway just result a polling
driver and the kernel state remains stable.

WARN_ONCE() is clearly an overkill, as kernel does not have inconsistent
state. Using WARN_ONCE() was a mistake.

I sent this fix: https://lore.kernel.org/linux-integrity/[email protected]/T/#t

It will turn WARN_ONCE() to pr_warn_once() and also add the status code
to klog entry. It's sufficient in this case. For 3/5-5/5 we need more
time.

/Jarkko

2021-02-02 23:08:43

by Guenter Roeck

Subject: Re: [PATCH v3] tpm_tis: Add missing tpm_request/relinquish_locality calls

On Tue, Feb 02, 2021 at 04:51:39PM +0100, Lukasz Majczak wrote:
> There are missing calls to tpm_request_locality before the calls to
> the tpm_get_timeouts() and tpm_tis_probe_irq_single() - both functions
> internally send commands to the tpm. As the current
> approach might work for tpm2, it fails for tpm1.x - in that case
> call to tpm_get_timeouts() or tpm_tis_probe_irq_single()
> without acquired locality fails and in turn causes tpm_tis_core_init()
> to fail, it can be observed in the log with the following warning
> trace:
>
> [ 4.324298] TPM returned invalid status
> [ 4.324806] WARNING: CPU: 2 PID: 1 at drivers/char/tpm/tpm_tis_core.c:275 tpm_tis_status+0x86/0x8f
> [ 4.325888] Modules linked in:
> [ 4.326287] CPU: 2 PID: 1 Comm: swapper/0 Tainted: G W 5.11.0-rc6-next-20210201-00003-g214461adb2e8 #43
> [ 4.327406] Hardware name: Google Caroline/Caroline, BIOS Google_Caroline.7820.430.0 07/20/2018
> [ 4.327918] RIP: 0010:tpm_tis_status+0x86/0x8f
> [ 4.328323] Code: 28 00 00 00 48 3b 45 f0 75 24 89 d8 48 83 c4 10 5b 5d c3 c6 05 58 d9 28 01 01 31 db 48 c7 c7 73 52 98 9c 31 c0 e8 c2 17 b0 ff <0f> 0b eb cd e8 cf 4f 55 00 0f 1f 44 00 00 55 48 89 e56
> [ 4.330592] RSP: 0000:ffff88810092f7a0 EFLAGS: 00010246
> [ 4.331223] RAX: 691ee151166db100 RBX: 0000000000000000 RCX: 0000000000000001
> [ 4.331860] RDX: 0000000000000006 RSI: ffffffff9c96d302 RDI: 00000000ffffffff
> [ 4.332272] RBP: ffff88810092f7b8 R08: dffffc0000000000 R09: fffffbfff39c96ce
> [ 4.332683] R10: fffffbfff39c96ce R11: 0000000000000001 R12: ffff8881053e2000
> [ 4.333109] R13: 0000000065000000 R14: ffff888105d71000 R15: ffff888105cd2628
> [ 4.333738] FS: 0000000000000000(0000) GS:ffff88842f200000(0000) knlGS:0000000000000000
> [ 4.334432] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 4.334783] CR2: 0000000000000000 CR3: 0000000037828001 CR4: 00000000003706e0
> [ 4.335196] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> [ 4.335886] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
> [ 4.336793] Call Trace:
> [ 4.337107] tpm_tis_send_data+0x3d/0x22f
> [ 4.337506] tpm_tis_send_main+0x30/0xf5
> [ 4.337746] tpm_transmit+0xbf/0x327
> [ 4.338042] ? __alloc_pages_nodemask+0x261/0x36d
> [ 4.338615] tpm_transmit_cmd+0x2c/0x93
> [ 4.339109] tpm1_getcap+0x232/0x285
> [ 4.339578] tpm1_get_timeouts+0x48/0x47d
> [ 4.339964] ? lockdep_init_map_type+0x71/0x257
> [ 4.340256] ? lockdep_init_map_type+0x71/0x257
> [ 4.340719] ? __raw_spin_lock_init+0x40/0x69
> [ 4.341208] tpm_tis_core_init+0x402/0x5ee
> [ 4.341629] tpm_tis_init+0x11d/0x1a2
> [ 4.341867] tpm_tis_pnp_init+0x91/0xb5
> [ 4.342101] ? tis_int_handler+0x15f/0x15f
> [ 4.342466] pnp_device_probe+0x79/0x9f
> [ 4.342941] really_probe+0x149/0x4a8
> [ 4.343412] driver_probe_device+0xd6/0x144
> [ 4.343968] device_driver_attach+0x42/0x5b
> [ 4.344382] __driver_attach+0xca/0x139
> [ 4.344617] ? driver_attach+0x1f/0x1f
> [ 4.344860] bus_for_each_dev+0x85/0xb7
> [ 4.345096] bus_add_driver+0x12b/0x228
> [ 4.345330] driver_register+0x64/0xed
> [ 4.345560] init_tis+0xa5/0xeb
> [ 4.345784] ? lock_is_held_type+0x100/0x141
> [ 4.346044] ? tpm_init+0x106/0x106
> [ 4.346259] ? rcu_read_lock_sched_held+0x41/0x7e
> [ 4.346542] ? tpm_init+0x106/0x106
> [ 4.346678] battery: ACPI: Battery Slot [BAT0] (battery present)
> [ 4.346754] do_one_initcall+0x1b9/0x43d
> [ 4.346776] ? asm_sysvec_apic_timer_interrupt+0x12/0x20
> [ 4.347659] ? lockdep_hardirqs_on+0x8e/0x12e
> [ 4.347937] ? lock_is_held_type+0x100/0x141
> [ 4.348196] ? rcu_read_lock_sched_held+0x41/0x7e
> [ 4.348477] do_initcall_level+0x99/0xa9
> [ 4.348717] ? kernel_init+0xe/0x10a
> [ 4.348954] do_initcalls+0x4e/0x79
> [ 4.349170] kernel_init_freeable+0x15a/0x1ae
> [ 4.349434] ? rest_init+0x1d6/0x1d6
> [ 4.349655] kernel_init+0xe/0x10a
> [ 4.349882] ret_from_fork+0x22/0x30
> [ 4.350103] irq event stamp: 700039
> [ 4.350318] hardirqs last enabled at (700047): [<ffffffff9b735265>] console_unlock+0x4be/0x538
> [ 4.350836] hardirqs last disabled at (700056): [<ffffffff9b734e84>] console_unlock+0xdd/0x538
> [ 4.351331] softirqs last enabled at (699522): [<ffffffff9c4004ec>] __do_softirq+0x4ec/0x539
> [ 4.351835] softirqs last disabled at (699517): [<ffffffff9c200f62>] asm_call_irq_on_stack+0x12/0x20
>
> Following the trace one can also notice a comment in the tpm_tis_status():
>
> /*
> * 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.
> */
> In this case we don't have to call tpm_try_get_ops()
> as both calls (tpm_get_timeouts() and tpm_tis_probe_irq_single()) are
> in the tpm_tis_core_init function and don't require any locking or clock
> enablement. Similar usage is in the probe_itpm() function also called
> inside tpm_tis_core_init().
> Tested on Samsung Chromebook Pro (Caroline).
>
> Signed-off-by: Lukasz Majczak <[email protected]>

Reviewed-by: Guenter Roeck <[email protected]>

> ---
> Hi Jarkko
>
> I have checked the linux-next with James patches, also followed Dirk
> suggestion applying remaining ones, although without any luck -
> a warning trace was still present. As Guneter mentioned earlier, this
> patch[1] doesn't address a lack of acquired locality in the
> tpm_get_timeouts() and does it only for tpm_tis_probe_irq_single() but
> also without a call to tpm_relinquish_locality().
>
> Here are my logs from the clean linux-next master branch [2]
> (with two James' patches present) and with my
> patch applied[3]
>
> Best regards,
> Lukasz
>
> [1] https://lore.kernel.org/linux-integrity/[email protected]/
> [2] https://gist.github.com/semihalf-majczak-lukasz/f588c0684a6cc7d983bb9c4eb4bda586
> [3] https://gist.github.com/semihalf-majczak-lukasz/88ede933bc7d28d806e3532850a04054
>
> v2 -> v3:
> - Added braces around if part of if/else statements
> - Rebased to linux-next
> - Updated commit message
>
> drivers/char/tpm/tpm-chip.c | 4 ++--
> drivers/char/tpm/tpm-interface.c | 13 ++++++++++---
> drivers/char/tpm/tpm.h | 2 ++
> drivers/char/tpm/tpm_tis_core.c | 14 +++++++++++---
> 4 files changed, 25 insertions(+), 8 deletions(-)
>
> diff --git a/drivers/char/tpm/tpm-chip.c b/drivers/char/tpm/tpm-chip.c
> index ddaeceb7e109..5351963a4b19 100644
> --- a/drivers/char/tpm/tpm-chip.c
> +++ b/drivers/char/tpm/tpm-chip.c
> @@ -32,7 +32,7 @@ struct class *tpm_class;
> struct class *tpmrm_class;
> dev_t tpm_devt;
>
> -static int tpm_request_locality(struct tpm_chip *chip)
> +int tpm_request_locality(struct tpm_chip *chip)
> {
> int rc;
>
> @@ -47,7 +47,7 @@ static int tpm_request_locality(struct tpm_chip *chip)
> return 0;
> }
>
> -static void tpm_relinquish_locality(struct tpm_chip *chip)
> +void tpm_relinquish_locality(struct tpm_chip *chip)
> {
> int rc;
>
> diff --git a/drivers/char/tpm/tpm-interface.c b/drivers/char/tpm/tpm-interface.c
> index 1621ce818705..2a9001d329f2 100644
> --- a/drivers/char/tpm/tpm-interface.c
> +++ b/drivers/char/tpm/tpm-interface.c
> @@ -241,10 +241,17 @@ int tpm_get_timeouts(struct tpm_chip *chip)
> if (chip->flags & TPM_CHIP_FLAG_HAVE_TIMEOUTS)
> return 0;
>
> - if (chip->flags & TPM_CHIP_FLAG_TPM2)
> + if (chip->flags & TPM_CHIP_FLAG_TPM2) {
> return tpm2_get_timeouts(chip);
> - else
> - return tpm1_get_timeouts(chip);
> + } else {
> + ssize_t ret = tpm_request_locality(chip);
> +
> + if (ret)
> + return ret;
> + ret = tpm1_get_timeouts(chip);
> + tpm_relinquish_locality(chip);
> + return ret;
> + }
> }
> EXPORT_SYMBOL_GPL(tpm_get_timeouts);
>
> diff --git a/drivers/char/tpm/tpm.h b/drivers/char/tpm/tpm.h
> index 947d1db0a5cc..8c13008437dd 100644
> --- a/drivers/char/tpm/tpm.h
> +++ b/drivers/char/tpm/tpm.h
> @@ -193,6 +193,8 @@ static inline void tpm_msleep(unsigned int delay_msec)
>
> int tpm_chip_start(struct tpm_chip *chip);
> void tpm_chip_stop(struct tpm_chip *chip);
> +int tpm_request_locality(struct tpm_chip *chip);
> +void tpm_relinquish_locality(struct tpm_chip *chip);
> struct tpm_chip *tpm_find_get_ops(struct tpm_chip *chip);
> __must_check int tpm_try_get_ops(struct tpm_chip *chip);
> void tpm_put_ops(struct tpm_chip *chip);
> diff --git a/drivers/char/tpm/tpm_tis_core.c b/drivers/char/tpm/tpm_tis_core.c
> index 431919d5f48a..d4f381d6356e 100644
> --- a/drivers/char/tpm/tpm_tis_core.c
> +++ b/drivers/char/tpm/tpm_tis_core.c
> @@ -708,11 +708,19 @@ static int tpm_tis_gen_interrupt(struct tpm_chip *chip)
> u32 cap2;
> cap_t cap;
>
> - if (chip->flags & TPM_CHIP_FLAG_TPM2)
> + if (chip->flags & TPM_CHIP_FLAG_TPM2) {
> return tpm2_get_tpm_pt(chip, 0x100, &cap2, desc);
> - else
> - return tpm1_getcap(chip, TPM_CAP_PROP_TIS_TIMEOUT, &cap, desc,
> + } else {
> + ssize_t ret = tpm_request_locality(chip);
> +
> + if (ret)
> + return ret;
> + ret = tpm1_getcap(chip, TPM_CAP_PROP_TIS_TIMEOUT, &cap, desc,
> 0);
> + tpm_relinquish_locality(chip);
> + return ret;
> + }
> +
> }
>
> /* Register the IRQ and issue a command that will cause an interrupt. If an
> --
> 2.25.1
>

2021-02-03 00:45:29

by Dirk Gouders

Subject: Re: [PATCH v3] tpm_tis: Add missing tpm_request/relinquish_locality calls

Lukasz Majczak <[email protected]> writes:

> There are missing calls to tpm_request_locality before the calls to
> the tpm_get_timeouts() and tpm_tis_probe_irq_single() - both functions
> internally send commands to the tpm. As the current
> approach might work for tpm2, it fails for tpm1.x - in that case
> call to tpm_get_timeouts() or tpm_tis_probe_irq_single()
> without acquired locality fails and in turn causes tpm_tis_core_init()
> to fail, it can be observed in the log with the following warning
> trace:
>
> [ 4.324298] TPM returned invalid status
> [ 4.324806] WARNING: CPU: 2 PID: 1 at drivers/char/tpm/tpm_tis_core.c:275 tpm_tis_status+0x86/0x8f
> [ 4.325888] Modules linked in:
> [ 4.326287] CPU: 2 PID: 1 Comm: swapper/0 Tainted: G W 5.11.0-rc6-next-20210201-00003-g214461adb2e8 #43
> [ 4.327406] Hardware name: Google Caroline/Caroline, BIOS Google_Caroline.7820.430.0 07/20/2018
> [ 4.327918] RIP: 0010:tpm_tis_status+0x86/0x8f
> [ 4.328323] Code: 28 00 00 00 48 3b 45 f0 75 24 89 d8 48 83 c4 10 5b 5d c3 c6 05 58 d9 28 01 01 31 db 48 c7 c7 73 52 98 9c 31 c0 e8 c2 17 b0 ff <0f> 0b eb cd e8 cf 4f 55 00 0f 1f 44 00 00 55 48 89 e56
> [ 4.330592] RSP: 0000:ffff88810092f7a0 EFLAGS: 00010246
> [ 4.331223] RAX: 691ee151166db100 RBX: 0000000000000000 RCX: 0000000000000001
> [ 4.331860] RDX: 0000000000000006 RSI: ffffffff9c96d302 RDI: 00000000ffffffff
> [ 4.332272] RBP: ffff88810092f7b8 R08: dffffc0000000000 R09: fffffbfff39c96ce
> [ 4.332683] R10: fffffbfff39c96ce R11: 0000000000000001 R12: ffff8881053e2000
> [ 4.333109] R13: 0000000065000000 R14: ffff888105d71000 R15: ffff888105cd2628
> [ 4.333738] FS: 0000000000000000(0000) GS:ffff88842f200000(0000) knlGS:0000000000000000
> [ 4.334432] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 4.334783] CR2: 0000000000000000 CR3: 0000000037828001 CR4: 00000000003706e0
> [ 4.335196] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> [ 4.335886] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
> [ 4.336793] Call Trace:
> [ 4.337107] tpm_tis_send_data+0x3d/0x22f
> [ 4.337506] tpm_tis_send_main+0x30/0xf5
> [ 4.337746] tpm_transmit+0xbf/0x327
> [ 4.338042] ? __alloc_pages_nodemask+0x261/0x36d
> [ 4.338615] tpm_transmit_cmd+0x2c/0x93
> [ 4.339109] tpm1_getcap+0x232/0x285
> [ 4.339578] tpm1_get_timeouts+0x48/0x47d
> [ 4.339964] ? lockdep_init_map_type+0x71/0x257
> [ 4.340256] ? lockdep_init_map_type+0x71/0x257
> [ 4.340719] ? __raw_spin_lock_init+0x40/0x69
> [ 4.341208] tpm_tis_core_init+0x402/0x5ee
> [ 4.341629] tpm_tis_init+0x11d/0x1a2
> [ 4.341867] tpm_tis_pnp_init+0x91/0xb5
> [ 4.342101] ? tis_int_handler+0x15f/0x15f
> [ 4.342466] pnp_device_probe+0x79/0x9f
> [ 4.342941] really_probe+0x149/0x4a8
> [ 4.343412] driver_probe_device+0xd6/0x144
> [ 4.343968] device_driver_attach+0x42/0x5b
> [ 4.344382] __driver_attach+0xca/0x139
> [ 4.344617] ? driver_attach+0x1f/0x1f
> [ 4.344860] bus_for_each_dev+0x85/0xb7
> [ 4.345096] bus_add_driver+0x12b/0x228
> [ 4.345330] driver_register+0x64/0xed
> [ 4.345560] init_tis+0xa5/0xeb
> [ 4.345784] ? lock_is_held_type+0x100/0x141
> [ 4.346044] ? tpm_init+0x106/0x106
> [ 4.346259] ? rcu_read_lock_sched_held+0x41/0x7e
> [ 4.346542] ? tpm_init+0x106/0x106
> [ 4.346678] battery: ACPI: Battery Slot [BAT0] (battery present)
> [ 4.346754] do_one_initcall+0x1b9/0x43d
> [ 4.346776] ? asm_sysvec_apic_timer_interrupt+0x12/0x20
> [ 4.347659] ? lockdep_hardirqs_on+0x8e/0x12e
> [ 4.347937] ? lock_is_held_type+0x100/0x141
> [ 4.348196] ? rcu_read_lock_sched_held+0x41/0x7e
> [ 4.348477] do_initcall_level+0x99/0xa9
> [ 4.348717] ? kernel_init+0xe/0x10a
> [ 4.348954] do_initcalls+0x4e/0x79
> [ 4.349170] kernel_init_freeable+0x15a/0x1ae
> [ 4.349434] ? rest_init+0x1d6/0x1d6
> [ 4.349655] kernel_init+0xe/0x10a
> [ 4.349882] ret_from_fork+0x22/0x30
> [ 4.350103] irq event stamp: 700039
> [ 4.350318] hardirqs last enabled at (700047): [<ffffffff9b735265>] console_unlock+0x4be/0x538
> [ 4.350836] hardirqs last disabled at (700056): [<ffffffff9b734e84>] console_unlock+0xdd/0x538
> [ 4.351331] softirqs last enabled at (699522): [<ffffffff9c4004ec>] __do_softirq+0x4ec/0x539
> [ 4.351835] softirqs last disabled at (699517): [<ffffffff9c200f62>] asm_call_irq_on_stack+0x12/0x20
>
> Following the trace one can also notice a comment in the tpm_tis_status():
>
> /*
> * 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.
> */
> In this case we don't have to call tpm_try_get_ops()
> as both calls (tpm_get_timeouts() and tpm_tis_probe_irq_single()) are
> in the tpm_tis_core_init function and don't require any locking or clock
> enablement. Similar usage is in the probe_itpm() function also called
> inside tpm_tis_core_init().
> Tested on Samsung Chromebook Pro (Caroline).
>
> Signed-off-by: Lukasz Majczak <[email protected]>
> ---
> Hi Jarkko
>
> I have checked the linux-next with James patches, also followed Dirk
> suggestion applying remaining ones, although without any luck -
> a warning trace was still present. As Guneter mentioned earlier, this
> patch[1] doesn't address a lack of acquired locality in the
> tpm_get_timeouts() and does it only for tpm_tis_probe_irq_single() but
> also without a call to tpm_relinquish_locality().
>
> Here are my logs from the clean linux-next master branch [2]
> (with two James' patches present) and with my
> patch applied[3]
>
> Best regards,
> Lukasz
>
> [1] https://lore.kernel.org/linux-integrity/[email protected]/
> [2] https://gist.github.com/semihalf-majczak-lukasz/f588c0684a6cc7d983bb9c4eb4bda586
> [3] https://gist.github.com/semihalf-majczak-lukasz/88ede933bc7d28d806e3532850a04054
>
> v2 -> v3:
> - Added braces around if part of if/else statements
> - Rebased to linux-next
> - Updated commit message
>
> drivers/char/tpm/tpm-chip.c | 4 ++--
> drivers/char/tpm/tpm-interface.c | 13 ++++++++++---
> drivers/char/tpm/tpm.h | 2 ++
> drivers/char/tpm/tpm_tis_core.c | 14 +++++++++++---
> 4 files changed, 25 insertions(+), 8 deletions(-)
>
> diff --git a/drivers/char/tpm/tpm-chip.c b/drivers/char/tpm/tpm-chip.c
> index ddaeceb7e109..5351963a4b19 100644
> --- a/drivers/char/tpm/tpm-chip.c
> +++ b/drivers/char/tpm/tpm-chip.c
> @@ -32,7 +32,7 @@ struct class *tpm_class;
> struct class *tpmrm_class;
> dev_t tpm_devt;
>
> -static int tpm_request_locality(struct tpm_chip *chip)
> +int tpm_request_locality(struct tpm_chip *chip)
> {
> int rc;
> @@ -47,7 +47,7 @@ static int tpm_request_locality(struct tpm_chip *chip)
> return 0;
> }
>
> -static void tpm_relinquish_locality(struct tpm_chip *chip)
> +void tpm_relinquish_locality(struct tpm_chip *chip)
> {
> int rc;
>

Here, it seems

+EXPORT_SYMBOL_GPL(tpm_request_locality);

and

+EXPORT_SYMBOL_GPL(tpm_relinquish_locality);

are needed. Otherwise building tpm* modules fails:

ERROR: modpost: "tpm_request_locality" [drivers/char/tpm/tpm_tis_core.ko] undefined!
ERROR: modpost: "tpm_relinquish_locality" [drivers/char/tpm/tpm_tis_core.ko] undefined!
make[1]: *** [scripts/Makefile.modpost:132: Module.symvers] Error 1
make[1]: *** Deleting file 'Module.symvers'
make: *** [Makefile:1405: modules] Error 2

Otherwise, testing this patch results in no more warning

TPM returned invalid status: 0xff

and also no more warnings:

tpm tpm0: tpm_try_transmit: send(): error -5
tpm tpm0: [Firmware Bug]: TPM interrupt not working, polling instead

Dirk

> diff --git a/drivers/char/tpm/tpm-interface.c b/drivers/char/tpm/tpm-interface.c
> index 1621ce818705..2a9001d329f2 100644
> --- a/drivers/char/tpm/tpm-interface.c
> +++ b/drivers/char/tpm/tpm-interface.c
> @@ -241,10 +241,17 @@ int tpm_get_timeouts(struct tpm_chip *chip)
> if (chip->flags & TPM_CHIP_FLAG_HAVE_TIMEOUTS)
> return 0;
>
> - if (chip->flags & TPM_CHIP_FLAG_TPM2)
> + if (chip->flags & TPM_CHIP_FLAG_TPM2) {
> return tpm2_get_timeouts(chip);
> - else
> - return tpm1_get_timeouts(chip);
> + } else {
> + ssize_t ret = tpm_request_locality(chip);
> +
> + if (ret)
> + return ret;
> + ret = tpm1_get_timeouts(chip);
> + tpm_relinquish_locality(chip);
> + return ret;
> + }
> }
> EXPORT_SYMBOL_GPL(tpm_get_timeouts);
>
> diff --git a/drivers/char/tpm/tpm.h b/drivers/char/tpm/tpm.h
> index 947d1db0a5cc..8c13008437dd 100644
> --- a/drivers/char/tpm/tpm.h
> +++ b/drivers/char/tpm/tpm.h
> @@ -193,6 +193,8 @@ static inline void tpm_msleep(unsigned int delay_msec)
>
> int tpm_chip_start(struct tpm_chip *chip);
> void tpm_chip_stop(struct tpm_chip *chip);
> +int tpm_request_locality(struct tpm_chip *chip);
> +void tpm_relinquish_locality(struct tpm_chip *chip);
> struct tpm_chip *tpm_find_get_ops(struct tpm_chip *chip);
> __must_check int tpm_try_get_ops(struct tpm_chip *chip);
> void tpm_put_ops(struct tpm_chip *chip);
> diff --git a/drivers/char/tpm/tpm_tis_core.c b/drivers/char/tpm/tpm_tis_core.c
> index 431919d5f48a..d4f381d6356e 100644
> --- a/drivers/char/tpm/tpm_tis_core.c
> +++ b/drivers/char/tpm/tpm_tis_core.c
> @@ -708,11 +708,19 @@ static int tpm_tis_gen_interrupt(struct tpm_chip *chip)
> u32 cap2;
> cap_t cap;
>
> - if (chip->flags & TPM_CHIP_FLAG_TPM2)
> + if (chip->flags & TPM_CHIP_FLAG_TPM2) {
> return tpm2_get_tpm_pt(chip, 0x100, &cap2, desc);
> - else
> - return tpm1_getcap(chip, TPM_CAP_PROP_TIS_TIMEOUT, &cap, desc,
> + } else {
> + ssize_t ret = tpm_request_locality(chip);
> +
> + if (ret)
> + return ret;
> + ret = tpm1_getcap(chip, TPM_CAP_PROP_TIS_TIMEOUT, &cap, desc,
> 0);
> + tpm_relinquish_locality(chip);
> + return ret;
> + }
> +
> }
>
> /* Register the IRQ and issue a command that will cause an interrupt. If an

2021-02-03 00:50:49

by Lukasz Majczak

Subject: [PATCH v4] tpm_tis: Add missing tpm_request/relinquish_locality calls

There are missing calls to tpm_request_locality before the calls to
the tpm_get_timeouts() and tpm_tis_probe_irq_single() - both functions
internally send commands to the tpm. As the current
approach might work for tpm2, it fails for tpm1.x - in that case
call to tpm_get_timeouts() or tpm_tis_probe_irq_single()
without acquired locality fails and in turn causes tpm_tis_core_init()
to fail, it can be observed in the log with the following warning
trace:

[ 4.324298] TPM returned invalid status
[ 4.324806] WARNING: CPU: 2 PID: 1 at drivers/char/tpm/tpm_tis_core.c:275 tpm_tis_status+0x86/0x8f
[ 4.325888] Modules linked in:
[ 4.326287] CPU: 2 PID: 1 Comm: swapper/0 Tainted: G W 5.11.0-rc6-next-20210201-00003-g214461adb2e8 #43
[ 4.327406] Hardware name: Google Caroline/Caroline, BIOS Google_Caroline.7820.430.0 07/20/2018
[ 4.327918] RIP: 0010:tpm_tis_status+0x86/0x8f
[ 4.328323] Code: 28 00 00 00 48 3b 45 f0 75 24 89 d8 48 83 c4 10 5b 5d c3 c6 05 58 d9 28 01 01 31 db 48 c7 c7 73 52 98 9c 31 c0 e8 c2 17 b0 ff <0f> 0b eb cd e8 cf 4f 55 00 0f 1f 44 00 00 55 48 89 e56
[ 4.330592] RSP: 0000:ffff88810092f7a0 EFLAGS: 00010246
[ 4.331223] RAX: 691ee151166db100 RBX: 0000000000000000 RCX: 0000000000000001
[ 4.331860] RDX: 0000000000000006 RSI: ffffffff9c96d302 RDI: 00000000ffffffff
[ 4.332272] RBP: ffff88810092f7b8 R08: dffffc0000000000 R09: fffffbfff39c96ce
[ 4.332683] R10: fffffbfff39c96ce R11: 0000000000000001 R12: ffff8881053e2000
[ 4.333109] R13: 0000000065000000 R14: ffff888105d71000 R15: ffff888105cd2628
[ 4.333738] FS: 0000000000000000(0000) GS:ffff88842f200000(0000) knlGS:0000000000000000
[ 4.334432] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 4.334783] CR2: 0000000000000000 CR3: 0000000037828001 CR4: 00000000003706e0
[ 4.335196] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 4.335886] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 4.336793] Call Trace:
[ 4.337107] tpm_tis_send_data+0x3d/0x22f
[ 4.337506] tpm_tis_send_main+0x30/0xf5
[ 4.337746] tpm_transmit+0xbf/0x327
[ 4.338042] ? __alloc_pages_nodemask+0x261/0x36d
[ 4.338615] tpm_transmit_cmd+0x2c/0x93
[ 4.339109] tpm1_getcap+0x232/0x285
[ 4.339578] tpm1_get_timeouts+0x48/0x47d
[ 4.339964] ? lockdep_init_map_type+0x71/0x257
[ 4.340256] ? lockdep_init_map_type+0x71/0x257
[ 4.340719] ? __raw_spin_lock_init+0x40/0x69
[ 4.341208] tpm_tis_core_init+0x402/0x5ee
[ 4.341629] tpm_tis_init+0x11d/0x1a2
[ 4.341867] tpm_tis_pnp_init+0x91/0xb5
[ 4.342101] ? tis_int_handler+0x15f/0x15f
[ 4.342466] pnp_device_probe+0x79/0x9f
[ 4.342941] really_probe+0x149/0x4a8
[ 4.343412] driver_probe_device+0xd6/0x144
[ 4.343968] device_driver_attach+0x42/0x5b
[ 4.344382] __driver_attach+0xca/0x139
[ 4.344617] ? driver_attach+0x1f/0x1f
[ 4.344860] bus_for_each_dev+0x85/0xb7
[ 4.345096] bus_add_driver+0x12b/0x228
[ 4.345330] driver_register+0x64/0xed
[ 4.345560] init_tis+0xa5/0xeb
[ 4.345784] ? lock_is_held_type+0x100/0x141
[ 4.346044] ? tpm_init+0x106/0x106
[ 4.346259] ? rcu_read_lock_sched_held+0x41/0x7e
[ 4.346542] ? tpm_init+0x106/0x106
[ 4.346678] battery: ACPI: Battery Slot [BAT0] (battery present)
[ 4.346754] do_one_initcall+0x1b9/0x43d
[ 4.346776] ? asm_sysvec_apic_timer_interrupt+0x12/0x20
[ 4.347659] ? lockdep_hardirqs_on+0x8e/0x12e
[ 4.347937] ? lock_is_held_type+0x100/0x141
[ 4.348196] ? rcu_read_lock_sched_held+0x41/0x7e
[ 4.348477] do_initcall_level+0x99/0xa9
[ 4.348717] ? kernel_init+0xe/0x10a
[ 4.348954] do_initcalls+0x4e/0x79
[ 4.349170] kernel_init_freeable+0x15a/0x1ae
[ 4.349434] ? rest_init+0x1d6/0x1d6
[ 4.349655] kernel_init+0xe/0x10a
[ 4.349882] ret_from_fork+0x22/0x30
[ 4.350103] irq event stamp: 700039
[ 4.350318] hardirqs last enabled at (700047): [<ffffffff9b735265>] console_unlock+0x4be/0x538
[ 4.350836] hardirqs last disabled at (700056): [<ffffffff9b734e84>] console_unlock+0xdd/0x538
[ 4.351331] softirqs last enabled at (699522): [<ffffffff9c4004ec>] __do_softirq+0x4ec/0x539
[ 4.351835] softirqs last disabled at (699517): [<ffffffff9c200f62>] asm_call_irq_on_stack+0x12/0x20

Following the trace one can also notice a comment in the tpm_tis_status():

/*
* 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.
*/
In this case we don't have to call tpm_try_get_ops()
as both calls (tpm_get_timeouts() and tpm_tis_probe_irq_single()) are
in the tpm_tis_core_init function and don't require any locking or clock
enablement. Similar usage is in the probe_itpm() function also called
inside tpm_tis_core_init().
Tested on Samsung Chromebook Pro (Caroline).

Signed-off-by: Lukasz Majczak <[email protected]>
Reviewed-by: Guenter Roeck <[email protected]>
---
Hi Dirk,

Good catch, thank you.

v3 -> v4:
- Added EXPORT_SYMBOL_GPL for tpm_request_locality/tpm_relinquish_locality

drivers/char/tpm/tpm-chip.c | 6 ++++--
drivers/char/tpm/tpm-interface.c | 13 ++++++++++---
drivers/char/tpm/tpm.h | 2 ++
drivers/char/tpm/tpm_tis_core.c | 14 +++++++++++---
4 files changed, 27 insertions(+), 8 deletions(-)

diff --git a/drivers/char/tpm/tpm-chip.c b/drivers/char/tpm/tpm-chip.c
index ddaeceb7e109..ce9c2650fbe5 100644
--- a/drivers/char/tpm/tpm-chip.c
+++ b/drivers/char/tpm/tpm-chip.c
@@ -32,7 +32,7 @@ struct class *tpm_class;
struct class *tpmrm_class;
dev_t tpm_devt;

-static int tpm_request_locality(struct tpm_chip *chip)
+int tpm_request_locality(struct tpm_chip *chip)
{
int rc;

@@ -46,8 +46,9 @@ static int tpm_request_locality(struct tpm_chip *chip)
chip->locality = rc;
return 0;
}
+EXPORT_SYMBOL_GPL(tpm_request_locality);

-static void tpm_relinquish_locality(struct tpm_chip *chip)
+void tpm_relinquish_locality(struct tpm_chip *chip)
{
int rc;

@@ -60,6 +61,7 @@ static void tpm_relinquish_locality(struct tpm_chip *chip)

chip->locality = -1;
}
+EXPORT_SYMBOL_GPL(tpm_relinquish_locality);

static int tpm_cmd_ready(struct tpm_chip *chip)
{
diff --git a/drivers/char/tpm/tpm-interface.c b/drivers/char/tpm/tpm-interface.c
index 1621ce818705..2a9001d329f2 100644
--- a/drivers/char/tpm/tpm-interface.c
+++ b/drivers/char/tpm/tpm-interface.c
@@ -241,10 +241,17 @@ int tpm_get_timeouts(struct tpm_chip *chip)
if (chip->flags & TPM_CHIP_FLAG_HAVE_TIMEOUTS)
return 0;

- if (chip->flags & TPM_CHIP_FLAG_TPM2)
+ if (chip->flags & TPM_CHIP_FLAG_TPM2) {
return tpm2_get_timeouts(chip);
- else
- return tpm1_get_timeouts(chip);
+ } else {
+ ssize_t ret = tpm_request_locality(chip);
+
+ if (ret)
+ return ret;
+ ret = tpm1_get_timeouts(chip);
+ tpm_relinquish_locality(chip);
+ return ret;
+ }
}
EXPORT_SYMBOL_GPL(tpm_get_timeouts);

diff --git a/drivers/char/tpm/tpm.h b/drivers/char/tpm/tpm.h
index 947d1db0a5cc..8c13008437dd 100644
--- a/drivers/char/tpm/tpm.h
+++ b/drivers/char/tpm/tpm.h
@@ -193,6 +193,8 @@ static inline void tpm_msleep(unsigned int delay_msec)

int tpm_chip_start(struct tpm_chip *chip);
void tpm_chip_stop(struct tpm_chip *chip);
+int tpm_request_locality(struct tpm_chip *chip);
+void tpm_relinquish_locality(struct tpm_chip *chip);
struct tpm_chip *tpm_find_get_ops(struct tpm_chip *chip);
__must_check int tpm_try_get_ops(struct tpm_chip *chip);
void tpm_put_ops(struct tpm_chip *chip);
diff --git a/drivers/char/tpm/tpm_tis_core.c b/drivers/char/tpm/tpm_tis_core.c
index 431919d5f48a..d4f381d6356e 100644
--- a/drivers/char/tpm/tpm_tis_core.c
+++ b/drivers/char/tpm/tpm_tis_core.c
@@ -708,11 +708,19 @@ static int tpm_tis_gen_interrupt(struct tpm_chip *chip)
u32 cap2;
cap_t cap;

- if (chip->flags & TPM_CHIP_FLAG_TPM2)
+ if (chip->flags & TPM_CHIP_FLAG_TPM2) {
return tpm2_get_tpm_pt(chip, 0x100, &cap2, desc);
- else
- return tpm1_getcap(chip, TPM_CAP_PROP_TIS_TIMEOUT, &cap, desc,
+ } else {
+ ssize_t ret = tpm_request_locality(chip);
+
+ if (ret)
+ return ret;
+ ret = tpm1_getcap(chip, TPM_CAP_PROP_TIS_TIMEOUT, &cap, desc,
0);
+ tpm_relinquish_locality(chip);
+ return ret;
+ }
+
}

/* Register the IRQ and issue a command that will cause an interrupt. If an
--
2.25.1

2021-02-03 00:53:20

by Jarkko Sakkinen

Subject: Re: [PATCH v3] tpm_tis: Add missing tpm_request/relinquish_locality calls

On Tue, Feb 02, 2021 at 04:51:39PM +0100, Lukasz Majczak wrote:
> There are missing calls to tpm_request_locality before the calls to
> the tpm_get_timeouts() and tpm_tis_probe_irq_single() - both functions
> internally send commands to the tpm. As the current
> approach might work for tpm2, it fails for tpm1.x - in that case
> call to tpm_get_timeouts() or tpm_tis_probe_irq_single()
> without acquired locality fails and in turn causes tpm_tis_core_init()
> to fail, it can be observed in the log with the following warning
> trace:

I said earlier about proper capitalizations of the acronyms.

E.g. "tpm1.x" has no meaning. TPM 1.x has. There's also a few other
similar examples.

>
> [ 4.324298] TPM returned invalid status
> [ 4.324806] WARNING: CPU: 2 PID: 1 at drivers/char/tpm/tpm_tis_core.c:275 tpm_tis_status+0x86/0x8f

To make the commit message shorter you could snip from here.

> [ 4.325888] Modules linked in:
> [ 4.326287] CPU: 2 PID: 1 Comm: swapper/0 Tainted: G W 5.11.0-rc6-next-20210201-00003-g214461adb2e8 #43
> [ 4.327406] Hardware name: Google Caroline/Caroline, BIOS Google_Caroline.7820.430.0 07/20/2018
> [ 4.327918] RIP: 0010:tpm_tis_status+0x86/0x8f
> [ 4.328323] Code: 28 00 00 00 48 3b 45 f0 75 24 89 d8 48 83 c4 10 5b 5d c3 c6 05 58 d9 28 01 01 31 db 48 c7 c7 73 52 98 9c 31 c0 e8 c2 17 b0 ff <0f> 0b eb cd e8 cf 4f 55 00 0f 1f 44 00 00 55 48 89 e56
> [ 4.330592] RSP: 0000:ffff88810092f7a0 EFLAGS: 00010246
> [ 4.331223] RAX: 691ee151166db100 RBX: 0000000000000000 RCX: 0000000000000001
> [ 4.331860] RDX: 0000000000000006 RSI: ffffffff9c96d302 RDI: 00000000ffffffff
> [ 4.332272] RBP: ffff88810092f7b8 R08: dffffc0000000000 R09: fffffbfff39c96ce
> [ 4.332683] R10: fffffbfff39c96ce R11: 0000000000000001 R12: ffff8881053e2000
> [ 4.333109] R13: 0000000065000000 R14: ffff888105d71000 R15: ffff888105cd2628
> [ 4.333738] FS: 0000000000000000(0000) GS:ffff88842f200000(0000) knlGS:0000000000000000
> [ 4.334432] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 4.334783] CR2: 0000000000000000 CR3: 0000000037828001 CR4: 00000000003706e0
> [ 4.335196] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> [ 4.335886] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
> [ 4.336793] Call Trace:
> [ 4.337107] tpm_tis_send_data+0x3d/0x22f
> [ 4.337506] tpm_tis_send_main+0x30/0xf5
> [ 4.337746] tpm_transmit+0xbf/0x327
> [ 4.338042] ? __alloc_pages_nodemask+0x261/0x36d
> [ 4.338615] tpm_transmit_cmd+0x2c/0x93
> [ 4.339109] tpm1_getcap+0x232/0x285
> [ 4.339578] tpm1_get_timeouts+0x48/0x47d
> [ 4.339964] ? lockdep_init_map_type+0x71/0x257
> [ 4.340256] ? lockdep_init_map_type+0x71/0x257
> [ 4.340719] ? __raw_spin_lock_init+0x40/0x69
> [ 4.341208] tpm_tis_core_init+0x402/0x5ee
> [ 4.341629] tpm_tis_init+0x11d/0x1a2
> [ 4.341867] tpm_tis_pnp_init+0x91/0xb5
> [ 4.342101] ? tis_int_handler+0x15f/0x15f
> [ 4.342466] pnp_device_probe+0x79/0x9f
> [ 4.342941] really_probe+0x149/0x4a8
> [ 4.343412] driver_probe_device+0xd6/0x144
> [ 4.343968] device_driver_attach+0x42/0x5b
> [ 4.344382] __driver_attach+0xca/0x139
> [ 4.344617] ? driver_attach+0x1f/0x1f
> [ 4.344860] bus_for_each_dev+0x85/0xb7
> [ 4.345096] bus_add_driver+0x12b/0x228
> [ 4.345330] driver_register+0x64/0xed
> [ 4.345560] init_tis+0xa5/0xeb
> [ 4.345784] ? lock_is_held_type+0x100/0x141
> [ 4.346044] ? tpm_init+0x106/0x106
> [ 4.346259] ? rcu_read_lock_sched_held+0x41/0x7e
> [ 4.346542] ? tpm_init+0x106/0x106
> [ 4.346678] battery: ACPI: Battery Slot [BAT0] (battery present)
> [ 4.346754] do_one_initcall+0x1b9/0x43d
> [ 4.346776] ? asm_sysvec_apic_timer_interrupt+0x12/0x20
> [ 4.347659] ? lockdep_hardirqs_on+0x8e/0x12e
> [ 4.347937] ? lock_is_held_type+0x100/0x141
> [ 4.348196] ? rcu_read_lock_sched_held+0x41/0x7e
> [ 4.348477] do_initcall_level+0x99/0xa9
> [ 4.348717] ? kernel_init+0xe/0x10a
> [ 4.348954] do_initcalls+0x4e/0x79
> [ 4.349170] kernel_init_freeable+0x15a/0x1ae
> [ 4.349434] ? rest_init+0x1d6/0x1d6
> [ 4.349655] kernel_init+0xe/0x10a
> [ 4.349882] ret_from_fork+0x22/0x30
> [ 4.350103] irq event stamp: 700039
> [ 4.350318] hardirqs last enabled at (700047): [<ffffffff9b735265>] console_unlock+0x4be/0x538
> [ 4.350836] hardirqs last disabled at (700056): [<ffffffff9b734e84>] console_unlock+0xdd/0x538
> [ 4.351331] softirqs last enabled at (699522): [<ffffffff9c4004ec>] __do_softirq+0x4ec/0x539
> [ 4.351835] softirqs last disabled at (699517): [<ffffffff9c200f62>] asm_call_irq_on_stack+0x12/0x20
>
> Following the trace one can also notice a comment in the tpm_tis_status():
>
> /*
> * 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.
> */
> In this case we don't have to call tpm_try_get_ops()

Do not use "we". Write in imperative term.

> as both calls (tpm_get_timeouts() and tpm_tis_probe_irq_single()) are
> in the tpm_tis_core_init function and don't require any locking or clock
> enablement. Similar usage is in the probe_itpm() function also called
> inside tpm_tis_core_init().

You use parentheses incosistently here. E.g. tpm_tis_core_init has them
in some sentences, and in some it doesn't.

> Tested on Samsung Chromebook Pro (Caroline).
>
> Signed-off-by: Lukasz Majczak <[email protected]>
> ---
> Hi Jarkko
>
> I have checked the linux-next with James patches, also followed Dirk
> suggestion applying remaining ones, although without any luck -
> a warning trace was still present. As Guneter mentioned earlier, this
> patch[1] doesn't address a lack of acquired locality in the
> tpm_get_timeouts() and does it only for tpm_tis_probe_irq_single() but
> also without a call to tpm_relinquish_locality().
>
> Here are my logs from the clean linux-next master branch [2]
> (with two James' patches present) and with my
> patch applied[3]
>
> Best regards,
> Lukasz

Ok. Please also take care fixing the cosmetic things, which you
clearly haven't done (like writing acronyms correctly).

> [1] https://lore.kernel.org/linux-integrity/[email protected]/
> [2] https://gist.github.com/semihalf-majczak-lukasz/f588c0684a6cc7d983bb9c4eb4bda586
> [3] https://gist.github.com/semihalf-majczak-lukasz/88ede933bc7d28d806e3532850a04054
>
> v2 -> v3:
> - Added braces around if part of if/else statements
> - Rebased to linux-next
> - Updated commit message
>
> drivers/char/tpm/tpm-chip.c | 4 ++--
> drivers/char/tpm/tpm-interface.c | 13 ++++++++++---
> drivers/char/tpm/tpm.h | 2 ++
> drivers/char/tpm/tpm_tis_core.c | 14 +++++++++++---
> 4 files changed, 25 insertions(+), 8 deletions(-)
>
> diff --git a/drivers/char/tpm/tpm-chip.c b/drivers/char/tpm/tpm-chip.c
> index ddaeceb7e109..5351963a4b19 100644
> --- a/drivers/char/tpm/tpm-chip.c
> +++ b/drivers/char/tpm/tpm-chip.c
> @@ -32,7 +32,7 @@ struct class *tpm_class;
> struct class *tpmrm_class;
> dev_t tpm_devt;
>
> -static int tpm_request_locality(struct tpm_chip *chip)
> +int tpm_request_locality(struct tpm_chip *chip)
> {
> int rc;
>
> @@ -47,7 +47,7 @@ static int tpm_request_locality(struct tpm_chip *chip)
> return 0;
> }
>
> -static void tpm_relinquish_locality(struct tpm_chip *chip)
> +void tpm_relinquish_locality(struct tpm_chip *chip)
> {
> int rc;

You need to export the symbols.

> diff --git a/drivers/char/tpm/tpm-interface.c b/drivers/char/tpm/tpm-interface.c
> index 1621ce818705..2a9001d329f2 100644
> --- a/drivers/char/tpm/tpm-interface.c
> +++ b/drivers/char/tpm/tpm-interface.c
> @@ -241,10 +241,17 @@ int tpm_get_timeouts(struct tpm_chip *chip)
> if (chip->flags & TPM_CHIP_FLAG_HAVE_TIMEOUTS)
> return 0;
>
> - if (chip->flags & TPM_CHIP_FLAG_TPM2)
> + if (chip->flags & TPM_CHIP_FLAG_TPM2) {
> return tpm2_get_timeouts(chip);
> - else
> - return tpm1_get_timeouts(chip);
> + } else {
> + ssize_t ret = tpm_request_locality(chip);
> +
> + if (ret)
> + return ret;
> + ret = tpm1_get_timeouts(chip);
> + tpm_relinquish_locality(chip);
> + return ret;
> + }
> }
> EXPORT_SYMBOL_GPL(tpm_get_timeouts);
>
> diff --git a/drivers/char/tpm/tpm.h b/drivers/char/tpm/tpm.h
> index 947d1db0a5cc..8c13008437dd 100644
> --- a/drivers/char/tpm/tpm.h
> +++ b/drivers/char/tpm/tpm.h
> @@ -193,6 +193,8 @@ static inline void tpm_msleep(unsigned int delay_msec)
>
> int tpm_chip_start(struct tpm_chip *chip);
> void tpm_chip_stop(struct tpm_chip *chip);
> +int tpm_request_locality(struct tpm_chip *chip);
> +void tpm_relinquish_locality(struct tpm_chip *chip);
> struct tpm_chip *tpm_find_get_ops(struct tpm_chip *chip);
> __must_check int tpm_try_get_ops(struct tpm_chip *chip);
> void tpm_put_ops(struct tpm_chip *chip);
> diff --git a/drivers/char/tpm/tpm_tis_core.c b/drivers/char/tpm/tpm_tis_core.c
> index 431919d5f48a..d4f381d6356e 100644
> --- a/drivers/char/tpm/tpm_tis_core.c
> +++ b/drivers/char/tpm/tpm_tis_core.c
> @@ -708,11 +708,19 @@ static int tpm_tis_gen_interrupt(struct tpm_chip *chip)
> u32 cap2;
> cap_t cap;
>
> - if (chip->flags & TPM_CHIP_FLAG_TPM2)
> + if (chip->flags & TPM_CHIP_FLAG_TPM2) {
> return tpm2_get_tpm_pt(chip, 0x100, &cap2, desc);
> - else
> - return tpm1_getcap(chip, TPM_CAP_PROP_TIS_TIMEOUT, &cap, desc,
> + } else {
> + ssize_t ret = tpm_request_locality(chip);
> +
> + if (ret)
> + return ret;
> + ret = tpm1_getcap(chip, TPM_CAP_PROP_TIS_TIMEOUT, &cap, desc,
> 0);
> + tpm_relinquish_locality(chip);
> + return ret;
> + }

Why this and nost just call tpm_chip_start()?

> +
> }
>
> /* Register the IRQ and issue a command that will cause an interrupt. If an
> --
> 2.25.1
>
>

/Jarkko

2021-02-03 00:53:21

by Jarkko Sakkinen

Subject: Re: [PATCH v4] tpm_tis: Add missing tpm_request/relinquish_locality calls

On Tue, Feb 02, 2021 at 08:57:24PM +0100, Lukasz Majczak wrote:
> There are missing calls to tpm_request_locality before the calls to
> the tpm_get_timeouts() and tpm_tis_probe_irq_single() - both functions
> internally send commands to the tpm. As the current
> approach might work for tpm2, it fails for tpm1.x - in that case
> call to tpm_get_timeouts() or tpm_tis_probe_irq_single()
> without acquired locality fails and in turn causes tpm_tis_core_init()
> to fail, it can be observed in the log with the following warning
> trace:

Ignoring this version.

/Jarkko

2021-02-03 01:00:07

by Jarkko Sakkinen

Subject: Re: [PATCH v3] tpm_tis: Add missing tpm_request/relinquish_locality calls

On Tue, Feb 02, 2021 at 08:29:50AM -0800, Guenter Roeck wrote:
> On Tue, Feb 02, 2021 at 04:51:39PM +0100, Lukasz Majczak wrote:
> > There are missing calls to tpm_request_locality before the calls to
> > the tpm_get_timeouts() and tpm_tis_probe_irq_single() - both functions
> > internally send commands to the tpm. As the current
> > approach might work for tpm2, it fails for tpm1.x - in that case
> > call to tpm_get_timeouts() or tpm_tis_probe_irq_single()
> > without acquired locality fails and in turn causes tpm_tis_core_init()
> > to fail, it can be observed in the log with the following warning
> > trace:
> >
> > [ 4.324298] TPM returned invalid status
> > [ 4.324806] WARNING: CPU: 2 PID: 1 at drivers/char/tpm/tpm_tis_core.c:275 tpm_tis_status+0x86/0x8f
> > [ 4.325888] Modules linked in:
> > [ 4.326287] CPU: 2 PID: 1 Comm: swapper/0 Tainted: G W 5.11.0-rc6-next-20210201-00003-g214461adb2e8 #43
> > [ 4.327406] Hardware name: Google Caroline/Caroline, BIOS Google_Caroline.7820.430.0 07/20/2018
> > [ 4.327918] RIP: 0010:tpm_tis_status+0x86/0x8f
> > [ 4.328323] Code: 28 00 00 00 48 3b 45 f0 75 24 89 d8 48 83 c4 10 5b 5d c3 c6 05 58 d9 28 01 01 31 db 48 c7 c7 73 52 98 9c 31 c0 e8 c2 17 b0 ff <0f> 0b eb cd e8 cf 4f 55 00 0f 1f 44 00 00 55 48 89 e56
> > [ 4.330592] RSP: 0000:ffff88810092f7a0 EFLAGS: 00010246
> > [ 4.331223] RAX: 691ee151166db100 RBX: 0000000000000000 RCX: 0000000000000001
> > [ 4.331860] RDX: 0000000000000006 RSI: ffffffff9c96d302 RDI: 00000000ffffffff
> > [ 4.332272] RBP: ffff88810092f7b8 R08: dffffc0000000000 R09: fffffbfff39c96ce
> > [ 4.332683] R10: fffffbfff39c96ce R11: 0000000000000001 R12: ffff8881053e2000
> > [ 4.333109] R13: 0000000065000000 R14: ffff888105d71000 R15: ffff888105cd2628
> > [ 4.333738] FS: 0000000000000000(0000) GS:ffff88842f200000(0000) knlGS:0000000000000000
> > [ 4.334432] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> > [ 4.334783] CR2: 0000000000000000 CR3: 0000000037828001 CR4: 00000000003706e0
> > [ 4.335196] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> > [ 4.335886] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
> > [ 4.336793] Call Trace:
> > [ 4.337107] tpm_tis_send_data+0x3d/0x22f
> > [ 4.337506] tpm_tis_send_main+0x30/0xf5
> > [ 4.337746] tpm_transmit+0xbf/0x327
> > [ 4.338042] ? __alloc_pages_nodemask+0x261/0x36d
> > [ 4.338615] tpm_transmit_cmd+0x2c/0x93
> > [ 4.339109] tpm1_getcap+0x232/0x285
> > [ 4.339578] tpm1_get_timeouts+0x48/0x47d
> > [ 4.339964] ? lockdep_init_map_type+0x71/0x257
> > [ 4.340256] ? lockdep_init_map_type+0x71/0x257
> > [ 4.340719] ? __raw_spin_lock_init+0x40/0x69
> > [ 4.341208] tpm_tis_core_init+0x402/0x5ee
> > [ 4.341629] tpm_tis_init+0x11d/0x1a2
> > [ 4.341867] tpm_tis_pnp_init+0x91/0xb5
> > [ 4.342101] ? tis_int_handler+0x15f/0x15f
> > [ 4.342466] pnp_device_probe+0x79/0x9f
> > [ 4.342941] really_probe+0x149/0x4a8
> > [ 4.343412] driver_probe_device+0xd6/0x144
> > [ 4.343968] device_driver_attach+0x42/0x5b
> > [ 4.344382] __driver_attach+0xca/0x139
> > [ 4.344617] ? driver_attach+0x1f/0x1f
> > [ 4.344860] bus_for_each_dev+0x85/0xb7
> > [ 4.345096] bus_add_driver+0x12b/0x228
> > [ 4.345330] driver_register+0x64/0xed
> > [ 4.345560] init_tis+0xa5/0xeb
> > [ 4.345784] ? lock_is_held_type+0x100/0x141
> > [ 4.346044] ? tpm_init+0x106/0x106
> > [ 4.346259] ? rcu_read_lock_sched_held+0x41/0x7e
> > [ 4.346542] ? tpm_init+0x106/0x106
> > [ 4.346678] battery: ACPI: Battery Slot [BAT0] (battery present)
> > [ 4.346754] do_one_initcall+0x1b9/0x43d
> > [ 4.346776] ? asm_sysvec_apic_timer_interrupt+0x12/0x20
> > [ 4.347659] ? lockdep_hardirqs_on+0x8e/0x12e
> > [ 4.347937] ? lock_is_held_type+0x100/0x141
> > [ 4.348196] ? rcu_read_lock_sched_held+0x41/0x7e
> > [ 4.348477] do_initcall_level+0x99/0xa9
> > [ 4.348717] ? kernel_init+0xe/0x10a
> > [ 4.348954] do_initcalls+0x4e/0x79
> > [ 4.349170] kernel_init_freeable+0x15a/0x1ae
> > [ 4.349434] ? rest_init+0x1d6/0x1d6
> > [ 4.349655] kernel_init+0xe/0x10a
> > [ 4.349882] ret_from_fork+0x22/0x30
> > [ 4.350103] irq event stamp: 700039
> > [ 4.350318] hardirqs last enabled at (700047): [<ffffffff9b735265>] console_unlock+0x4be/0x538
> > [ 4.350836] hardirqs last disabled at (700056): [<ffffffff9b734e84>] console_unlock+0xdd/0x538
> > [ 4.351331] softirqs last enabled at (699522): [<ffffffff9c4004ec>] __do_softirq+0x4ec/0x539
> > [ 4.351835] softirqs last disabled at (699517): [<ffffffff9c200f62>] asm_call_irq_on_stack+0x12/0x20
> >
> > Following the trace one can also notice a comment in the tpm_tis_status():
> >
> > /*
> > * 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.
> > */
> > In this case we don't have to call tpm_try_get_ops()
> > as both calls (tpm_get_timeouts() and tpm_tis_probe_irq_single()) are
> > in the tpm_tis_core_init function and don't require any locking or clock
> > enablement. Similar usage is in the probe_itpm() function also called
> > inside tpm_tis_core_init().
> > Tested on Samsung Chromebook Pro (Caroline).
> >
> > Signed-off-by: Lukasz Majczak <[email protected]>
>
> Reviewed-by: Guenter Roeck <[email protected]>

Had to check but I already gave my comments here about the commit message
issues:

https://lore.kernel.org/linux-integrity/[email protected]/

Also there was so many version of this shot to air that I lost track why
not just use chip_start()/stop(). The change IMHO has only gone worse from
the first version... But I haven't checked every possible version of this
(because three versions came simultaneously, I checked v3, because it was
first that mutt showed me)>

/Jarkko

2021-02-03 01:01:45

by Jarkko Sakkinen

Subject: Re: [PATCH v3] tpm_tis: Add missing tpm_request/relinquish_locality calls

On Wed, Feb 03, 2021 at 02:05:17AM +0200, Jarkko Sakkinen wrote:
> On Tue, Feb 02, 2021 at 11:49:11PM +0200, Jarkko Sakkinen wrote:
> > On Tue, Feb 02, 2021 at 04:51:39PM +0100, Lukasz Majczak wrote:
> > > There are missing calls to tpm_request_locality before the calls to
> > > the tpm_get_timeouts() and tpm_tis_probe_irq_single() - both functions
> > > internally send commands to the tpm. As the current
> > > approach might work for tpm2, it fails for tpm1.x - in that case
> > > call to tpm_get_timeouts() or tpm_tis_probe_irq_single()
> > > without acquired locality fails and in turn causes tpm_tis_core_init()
> > > to fail, it can be observed in the log with the following warning
> > > trace:
> >
> > I said earlier about proper capitalizations of the acronyms.
> >
> > E.g. "tpm1.x" has no meaning. TPM 1.x has. There's also a few other
> > similar examples.
> >
> > >
> > > [ 4.324298] TPM returned invalid status
> > > [ 4.324806] WARNING: CPU: 2 PID: 1 at drivers/char/tpm/tpm_tis_core.c:275 tpm_tis_status+0x86/0x8f
> >
> > To make the commit message shorter you could snip from here.
> >
> > > [ 4.325888] Modules linked in:
> > > [ 4.326287] CPU: 2 PID: 1 Comm: swapper/0 Tainted: G W 5.11.0-rc6-next-20210201-00003-g214461adb2e8 #43
> > > [ 4.327406] Hardware name: Google Caroline/Caroline, BIOS Google_Caroline.7820.430.0 07/20/2018
> > > [ 4.327918] RIP: 0010:tpm_tis_status+0x86/0x8f
> > > [ 4.328323] Code: 28 00 00 00 48 3b 45 f0 75 24 89 d8 48 83 c4 10 5b 5d c3 c6 05 58 d9 28 01 01 31 db 48 c7 c7 73 52 98 9c 31 c0 e8 c2 17 b0 ff <0f> 0b eb cd e8 cf 4f 55 00 0f 1f 44 00 00 55 48 89 e56
> > > [ 4.330592] RSP: 0000:ffff88810092f7a0 EFLAGS: 00010246
> > > [ 4.331223] RAX: 691ee151166db100 RBX: 0000000000000000 RCX: 0000000000000001
> > > [ 4.331860] RDX: 0000000000000006 RSI: ffffffff9c96d302 RDI: 00000000ffffffff
> > > [ 4.332272] RBP: ffff88810092f7b8 R08: dffffc0000000000 R09: fffffbfff39c96ce
> > > [ 4.332683] R10: fffffbfff39c96ce R11: 0000000000000001 R12: ffff8881053e2000
> > > [ 4.333109] R13: 0000000065000000 R14: ffff888105d71000 R15: ffff888105cd2628
> > > [ 4.333738] FS: 0000000000000000(0000) GS:ffff88842f200000(0000) knlGS:0000000000000000
> > > [ 4.334432] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> > > [ 4.334783] CR2: 0000000000000000 CR3: 0000000037828001 CR4: 00000000003706e0
> > > [ 4.335196] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> > > [ 4.335886] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
> > > [ 4.336793] Call Trace:
> > > [ 4.337107] tpm_tis_send_data+0x3d/0x22f
> > > [ 4.337506] tpm_tis_send_main+0x30/0xf5
> > > [ 4.337746] tpm_transmit+0xbf/0x327
> > > [ 4.338042] ? __alloc_pages_nodemask+0x261/0x36d
> > > [ 4.338615] tpm_transmit_cmd+0x2c/0x93
> > > [ 4.339109] tpm1_getcap+0x232/0x285
> > > [ 4.339578] tpm1_get_timeouts+0x48/0x47d
> > > [ 4.339964] ? lockdep_init_map_type+0x71/0x257
> > > [ 4.340256] ? lockdep_init_map_type+0x71/0x257
> > > [ 4.340719] ? __raw_spin_lock_init+0x40/0x69
> > > [ 4.341208] tpm_tis_core_init+0x402/0x5ee
> > > [ 4.341629] tpm_tis_init+0x11d/0x1a2
> > > [ 4.341867] tpm_tis_pnp_init+0x91/0xb5
> > > [ 4.342101] ? tis_int_handler+0x15f/0x15f
> > > [ 4.342466] pnp_device_probe+0x79/0x9f
> > > [ 4.342941] really_probe+0x149/0x4a8
> > > [ 4.343412] driver_probe_device+0xd6/0x144
> > > [ 4.343968] device_driver_attach+0x42/0x5b
> > > [ 4.344382] __driver_attach+0xca/0x139
> > > [ 4.344617] ? driver_attach+0x1f/0x1f
> > > [ 4.344860] bus_for_each_dev+0x85/0xb7
> > > [ 4.345096] bus_add_driver+0x12b/0x228
> > > [ 4.345330] driver_register+0x64/0xed
> > > [ 4.345560] init_tis+0xa5/0xeb
> > > [ 4.345784] ? lock_is_held_type+0x100/0x141
> > > [ 4.346044] ? tpm_init+0x106/0x106
> > > [ 4.346259] ? rcu_read_lock_sched_held+0x41/0x7e
> > > [ 4.346542] ? tpm_init+0x106/0x106
> > > [ 4.346678] battery: ACPI: Battery Slot [BAT0] (battery present)
> > > [ 4.346754] do_one_initcall+0x1b9/0x43d
> > > [ 4.346776] ? asm_sysvec_apic_timer_interrupt+0x12/0x20
> > > [ 4.347659] ? lockdep_hardirqs_on+0x8e/0x12e
> > > [ 4.347937] ? lock_is_held_type+0x100/0x141
> > > [ 4.348196] ? rcu_read_lock_sched_held+0x41/0x7e
> > > [ 4.348477] do_initcall_level+0x99/0xa9
> > > [ 4.348717] ? kernel_init+0xe/0x10a
> > > [ 4.348954] do_initcalls+0x4e/0x79
> > > [ 4.349170] kernel_init_freeable+0x15a/0x1ae
> > > [ 4.349434] ? rest_init+0x1d6/0x1d6
> > > [ 4.349655] kernel_init+0xe/0x10a
> > > [ 4.349882] ret_from_fork+0x22/0x30
> > > [ 4.350103] irq event stamp: 700039
> > > [ 4.350318] hardirqs last enabled at (700047): [<ffffffff9b735265>] console_unlock+0x4be/0x538
> > > [ 4.350836] hardirqs last disabled at (700056): [<ffffffff9b734e84>] console_unlock+0xdd/0x538
> > > [ 4.351331] softirqs last enabled at (699522): [<ffffffff9c4004ec>] __do_softirq+0x4ec/0x539
> > > [ 4.351835] softirqs last disabled at (699517): [<ffffffff9c200f62>] asm_call_irq_on_stack+0x12/0x20
> > >
> > > Following the trace one can also notice a comment in the tpm_tis_status():
> > >
> > > /*
> > > * 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.
> > > */
> > > In this case we don't have to call tpm_try_get_ops()
> >
> > Do not use "we". Write in imperative term.
> >
> > > as both calls (tpm_get_timeouts() and tpm_tis_probe_irq_single()) are
> > > in the tpm_tis_core_init function and don't require any locking or clock
> > > enablement. Similar usage is in the probe_itpm() function also called
> > > inside tpm_tis_core_init().
> >
> > You use parentheses incosistently here. E.g. tpm_tis_core_init has them
> > in some sentences, and in some it doesn't.
> >
> > > Tested on Samsung Chromebook Pro (Caroline).
> > >
> > > Signed-off-by: Lukasz Majczak <[email protected]>
> > > ---
> > > Hi Jarkko
> > >
> > > I have checked the linux-next with James patches, also followed Dirk
> > > suggestion applying remaining ones, although without any luck -
> > > a warning trace was still present. As Guneter mentioned earlier, this
> > > patch[1] doesn't address a lack of acquired locality in the
> > > tpm_get_timeouts() and does it only for tpm_tis_probe_irq_single() but
> > > also without a call to tpm_relinquish_locality().
> > >
> > > Here are my logs from the clean linux-next master branch [2]
> > > (with two James' patches present) and with my
> > > patch applied[3]
> > >
> > > Best regards,
> > > Lukasz
> >
> > Ok. Please also take care fixing the cosmetic things, which you
> > clearly haven't done (like writing acronyms correctly).
> >
> > > [1] https://lore.kernel.org/linux-integrity/[email protected]/
> > > [2] https://gist.github.com/semihalf-majczak-lukasz/f588c0684a6cc7d983bb9c4eb4bda586
> > > [3] https://gist.github.com/semihalf-majczak-lukasz/88ede933bc7d28d806e3532850a04054
> > >
> > > v2 -> v3:
> > > - Added braces around if part of if/else statements
> > > - Rebased to linux-next
> > > - Updated commit message
> > >
> > > drivers/char/tpm/tpm-chip.c | 4 ++--
> > > drivers/char/tpm/tpm-interface.c | 13 ++++++++++---
> > > drivers/char/tpm/tpm.h | 2 ++
> > > drivers/char/tpm/tpm_tis_core.c | 14 +++++++++++---
> > > 4 files changed, 25 insertions(+), 8 deletions(-)
> > >
> > > diff --git a/drivers/char/tpm/tpm-chip.c b/drivers/char/tpm/tpm-chip.c
> > > index ddaeceb7e109..5351963a4b19 100644
> > > --- a/drivers/char/tpm/tpm-chip.c
> > > +++ b/drivers/char/tpm/tpm-chip.c
> > > @@ -32,7 +32,7 @@ struct class *tpm_class;
> > > struct class *tpmrm_class;
> > > dev_t tpm_devt;
> > >
> > > -static int tpm_request_locality(struct tpm_chip *chip)
> > > +int tpm_request_locality(struct tpm_chip *chip)
> > > {
> > > int rc;
> > >
> > > @@ -47,7 +47,7 @@ static int tpm_request_locality(struct tpm_chip *chip)
> > > return 0;
> > > }
> > >
> > > -static void tpm_relinquish_locality(struct tpm_chip *chip)
> > > +void tpm_relinquish_locality(struct tpm_chip *chip)
> > > {
> > > int rc;
> >
> > You need to export the symbols.
> >
> > > diff --git a/drivers/char/tpm/tpm-interface.c b/drivers/char/tpm/tpm-interface.c
> > > index 1621ce818705..2a9001d329f2 100644
> > > --- a/drivers/char/tpm/tpm-interface.c
> > > +++ b/drivers/char/tpm/tpm-interface.c
> > > @@ -241,10 +241,17 @@ int tpm_get_timeouts(struct tpm_chip *chip)
> > > if (chip->flags & TPM_CHIP_FLAG_HAVE_TIMEOUTS)
> > > return 0;
> > >
> > > - if (chip->flags & TPM_CHIP_FLAG_TPM2)
> > > + if (chip->flags & TPM_CHIP_FLAG_TPM2) {
> > > return tpm2_get_timeouts(chip);
> > > - else
> > > - return tpm1_get_timeouts(chip);
> > > + } else {
> > > + ssize_t ret = tpm_request_locality(chip);
> > > +
> > > + if (ret)
> > > + return ret;
> > > + ret = tpm1_get_timeouts(chip);
> > > + tpm_relinquish_locality(chip);
> > > + return ret;
> > > + }
> > > }
> > > EXPORT_SYMBOL_GPL(tpm_get_timeouts);
> > >
> > > diff --git a/drivers/char/tpm/tpm.h b/drivers/char/tpm/tpm.h
> > > index 947d1db0a5cc..8c13008437dd 100644
> > > --- a/drivers/char/tpm/tpm.h
> > > +++ b/drivers/char/tpm/tpm.h
> > > @@ -193,6 +193,8 @@ static inline void tpm_msleep(unsigned int delay_msec)
> > >
> > > int tpm_chip_start(struct tpm_chip *chip);
> > > void tpm_chip_stop(struct tpm_chip *chip);
> > > +int tpm_request_locality(struct tpm_chip *chip);
> > > +void tpm_relinquish_locality(struct tpm_chip *chip);
> > > struct tpm_chip *tpm_find_get_ops(struct tpm_chip *chip);
> > > __must_check int tpm_try_get_ops(struct tpm_chip *chip);
> > > void tpm_put_ops(struct tpm_chip *chip);
> > > diff --git a/drivers/char/tpm/tpm_tis_core.c b/drivers/char/tpm/tpm_tis_core.c
> > > index 431919d5f48a..d4f381d6356e 100644
> > > --- a/drivers/char/tpm/tpm_tis_core.c
> > > +++ b/drivers/char/tpm/tpm_tis_core.c
> > > @@ -708,11 +708,19 @@ static int tpm_tis_gen_interrupt(struct tpm_chip *chip)
> > > u32 cap2;
> > > cap_t cap;
> > >
> > > - if (chip->flags & TPM_CHIP_FLAG_TPM2)
> > > + if (chip->flags & TPM_CHIP_FLAG_TPM2) {
> > > return tpm2_get_tpm_pt(chip, 0x100, &cap2, desc);
> > > - else
> > > - return tpm1_getcap(chip, TPM_CAP_PROP_TIS_TIMEOUT, &cap, desc,
> > > + } else {
> > > + ssize_t ret = tpm_request_locality(chip);
> > > +
> > > + if (ret)
> > > + return ret;
> > > + ret = tpm1_getcap(chip, TPM_CAP_PROP_TIS_TIMEOUT, &cap, desc,
> > > 0);
> > > + tpm_relinquish_locality(chip);
> > > + return ret;
> > > + }
> >
> > Why this and nost just call tpm_chip_start()?
>
> I.e. see tpm2_probe().
>
> Also, add these in place:
>
> Cc: [email protected]
> Fixes: a3fbfae82b4c ("tpm: take TPM chip power gating out of tpm_transmit()")
>
> Also a minor rant (appericiate the fix a lot in all cases): please hold on
> until there's some window to see your patch. I did not understand the
> reason for all these different versions.
>
> Also remember the fix the minor glitches in the commit message that I
> pointed out.
>
> And again, thanks for fixing the issue.

I'll hold on up until I get a new version version before sending my PR
together with two of James' earlier fixes.

/Jarkko

2021-02-03 01:02:30

by Jarkko Sakkinen

Subject: Re: [PATCH v3] tpm_tis: Add missing tpm_request/relinquish_locality calls

On Tue, Feb 02, 2021 at 11:49:11PM +0200, Jarkko Sakkinen wrote:
> On Tue, Feb 02, 2021 at 04:51:39PM +0100, Lukasz Majczak wrote:
> > There are missing calls to tpm_request_locality before the calls to
> > the tpm_get_timeouts() and tpm_tis_probe_irq_single() - both functions
> > internally send commands to the tpm. As the current
> > approach might work for tpm2, it fails for tpm1.x - in that case
> > call to tpm_get_timeouts() or tpm_tis_probe_irq_single()
> > without acquired locality fails and in turn causes tpm_tis_core_init()
> > to fail, it can be observed in the log with the following warning
> > trace:
>
> I said earlier about proper capitalizations of the acronyms.
>
> E.g. "tpm1.x" has no meaning. TPM 1.x has. There's also a few other
> similar examples.
>
> >
> > [ 4.324298] TPM returned invalid status
> > [ 4.324806] WARNING: CPU: 2 PID: 1 at drivers/char/tpm/tpm_tis_core.c:275 tpm_tis_status+0x86/0x8f
>
> To make the commit message shorter you could snip from here.
>
> > [ 4.325888] Modules linked in:
> > [ 4.326287] CPU: 2 PID: 1 Comm: swapper/0 Tainted: G W 5.11.0-rc6-next-20210201-00003-g214461adb2e8 #43
> > [ 4.327406] Hardware name: Google Caroline/Caroline, BIOS Google_Caroline.7820.430.0 07/20/2018
> > [ 4.327918] RIP: 0010:tpm_tis_status+0x86/0x8f
> > [ 4.328323] Code: 28 00 00 00 48 3b 45 f0 75 24 89 d8 48 83 c4 10 5b 5d c3 c6 05 58 d9 28 01 01 31 db 48 c7 c7 73 52 98 9c 31 c0 e8 c2 17 b0 ff <0f> 0b eb cd e8 cf 4f 55 00 0f 1f 44 00 00 55 48 89 e56
> > [ 4.330592] RSP: 0000:ffff88810092f7a0 EFLAGS: 00010246
> > [ 4.331223] RAX: 691ee151166db100 RBX: 0000000000000000 RCX: 0000000000000001
> > [ 4.331860] RDX: 0000000000000006 RSI: ffffffff9c96d302 RDI: 00000000ffffffff
> > [ 4.332272] RBP: ffff88810092f7b8 R08: dffffc0000000000 R09: fffffbfff39c96ce
> > [ 4.332683] R10: fffffbfff39c96ce R11: 0000000000000001 R12: ffff8881053e2000
> > [ 4.333109] R13: 0000000065000000 R14: ffff888105d71000 R15: ffff888105cd2628
> > [ 4.333738] FS: 0000000000000000(0000) GS:ffff88842f200000(0000) knlGS:0000000000000000
> > [ 4.334432] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> > [ 4.334783] CR2: 0000000000000000 CR3: 0000000037828001 CR4: 00000000003706e0
> > [ 4.335196] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> > [ 4.335886] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
> > [ 4.336793] Call Trace:
> > [ 4.337107] tpm_tis_send_data+0x3d/0x22f
> > [ 4.337506] tpm_tis_send_main+0x30/0xf5
> > [ 4.337746] tpm_transmit+0xbf/0x327
> > [ 4.338042] ? __alloc_pages_nodemask+0x261/0x36d
> > [ 4.338615] tpm_transmit_cmd+0x2c/0x93
> > [ 4.339109] tpm1_getcap+0x232/0x285
> > [ 4.339578] tpm1_get_timeouts+0x48/0x47d
> > [ 4.339964] ? lockdep_init_map_type+0x71/0x257
> > [ 4.340256] ? lockdep_init_map_type+0x71/0x257
> > [ 4.340719] ? __raw_spin_lock_init+0x40/0x69
> > [ 4.341208] tpm_tis_core_init+0x402/0x5ee
> > [ 4.341629] tpm_tis_init+0x11d/0x1a2
> > [ 4.341867] tpm_tis_pnp_init+0x91/0xb5
> > [ 4.342101] ? tis_int_handler+0x15f/0x15f
> > [ 4.342466] pnp_device_probe+0x79/0x9f
> > [ 4.342941] really_probe+0x149/0x4a8
> > [ 4.343412] driver_probe_device+0xd6/0x144
> > [ 4.343968] device_driver_attach+0x42/0x5b
> > [ 4.344382] __driver_attach+0xca/0x139
> > [ 4.344617] ? driver_attach+0x1f/0x1f
> > [ 4.344860] bus_for_each_dev+0x85/0xb7
> > [ 4.345096] bus_add_driver+0x12b/0x228
> > [ 4.345330] driver_register+0x64/0xed
> > [ 4.345560] init_tis+0xa5/0xeb
> > [ 4.345784] ? lock_is_held_type+0x100/0x141
> > [ 4.346044] ? tpm_init+0x106/0x106
> > [ 4.346259] ? rcu_read_lock_sched_held+0x41/0x7e
> > [ 4.346542] ? tpm_init+0x106/0x106
> > [ 4.346678] battery: ACPI: Battery Slot [BAT0] (battery present)
> > [ 4.346754] do_one_initcall+0x1b9/0x43d
> > [ 4.346776] ? asm_sysvec_apic_timer_interrupt+0x12/0x20
> > [ 4.347659] ? lockdep_hardirqs_on+0x8e/0x12e
> > [ 4.347937] ? lock_is_held_type+0x100/0x141
> > [ 4.348196] ? rcu_read_lock_sched_held+0x41/0x7e
> > [ 4.348477] do_initcall_level+0x99/0xa9
> > [ 4.348717] ? kernel_init+0xe/0x10a
> > [ 4.348954] do_initcalls+0x4e/0x79
> > [ 4.349170] kernel_init_freeable+0x15a/0x1ae
> > [ 4.349434] ? rest_init+0x1d6/0x1d6
> > [ 4.349655] kernel_init+0xe/0x10a
> > [ 4.349882] ret_from_fork+0x22/0x30
> > [ 4.350103] irq event stamp: 700039
> > [ 4.350318] hardirqs last enabled at (700047): [<ffffffff9b735265>] console_unlock+0x4be/0x538
> > [ 4.350836] hardirqs last disabled at (700056): [<ffffffff9b734e84>] console_unlock+0xdd/0x538
> > [ 4.351331] softirqs last enabled at (699522): [<ffffffff9c4004ec>] __do_softirq+0x4ec/0x539
> > [ 4.351835] softirqs last disabled at (699517): [<ffffffff9c200f62>] asm_call_irq_on_stack+0x12/0x20
> >
> > Following the trace one can also notice a comment in the tpm_tis_status():
> >
> > /*
> > * 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.
> > */
> > In this case we don't have to call tpm_try_get_ops()
>
> Do not use "we". Write in imperative term.
>
> > as both calls (tpm_get_timeouts() and tpm_tis_probe_irq_single()) are
> > in the tpm_tis_core_init function and don't require any locking or clock
> > enablement. Similar usage is in the probe_itpm() function also called
> > inside tpm_tis_core_init().
>
> You use parentheses incosistently here. E.g. tpm_tis_core_init has them
> in some sentences, and in some it doesn't.
>
> > Tested on Samsung Chromebook Pro (Caroline).
> >
> > Signed-off-by: Lukasz Majczak <[email protected]>
> > ---
> > Hi Jarkko
> >
> > I have checked the linux-next with James patches, also followed Dirk
> > suggestion applying remaining ones, although without any luck -
> > a warning trace was still present. As Guneter mentioned earlier, this
> > patch[1] doesn't address a lack of acquired locality in the
> > tpm_get_timeouts() and does it only for tpm_tis_probe_irq_single() but
> > also without a call to tpm_relinquish_locality().
> >
> > Here are my logs from the clean linux-next master branch [2]
> > (with two James' patches present) and with my
> > patch applied[3]
> >
> > Best regards,
> > Lukasz
>
> Ok. Please also take care fixing the cosmetic things, which you
> clearly haven't done (like writing acronyms correctly).
>
> > [1] https://lore.kernel.org/linux-integrity/[email protected]/
> > [2] https://gist.github.com/semihalf-majczak-lukasz/f588c0684a6cc7d983bb9c4eb4bda586
> > [3] https://gist.github.com/semihalf-majczak-lukasz/88ede933bc7d28d806e3532850a04054
> >
> > v2 -> v3:
> > - Added braces around if part of if/else statements
> > - Rebased to linux-next
> > - Updated commit message
> >
> > drivers/char/tpm/tpm-chip.c | 4 ++--
> > drivers/char/tpm/tpm-interface.c | 13 ++++++++++---
> > drivers/char/tpm/tpm.h | 2 ++
> > drivers/char/tpm/tpm_tis_core.c | 14 +++++++++++---
> > 4 files changed, 25 insertions(+), 8 deletions(-)
> >
> > diff --git a/drivers/char/tpm/tpm-chip.c b/drivers/char/tpm/tpm-chip.c
> > index ddaeceb7e109..5351963a4b19 100644
> > --- a/drivers/char/tpm/tpm-chip.c
> > +++ b/drivers/char/tpm/tpm-chip.c
> > @@ -32,7 +32,7 @@ struct class *tpm_class;
> > struct class *tpmrm_class;
> > dev_t tpm_devt;
> >
> > -static int tpm_request_locality(struct tpm_chip *chip)
> > +int tpm_request_locality(struct tpm_chip *chip)
> > {
> > int rc;
> >
> > @@ -47,7 +47,7 @@ static int tpm_request_locality(struct tpm_chip *chip)
> > return 0;
> > }
> >
> > -static void tpm_relinquish_locality(struct tpm_chip *chip)
> > +void tpm_relinquish_locality(struct tpm_chip *chip)
> > {
> > int rc;
>
> You need to export the symbols.
>
> > diff --git a/drivers/char/tpm/tpm-interface.c b/drivers/char/tpm/tpm-interface.c
> > index 1621ce818705..2a9001d329f2 100644
> > --- a/drivers/char/tpm/tpm-interface.c
> > +++ b/drivers/char/tpm/tpm-interface.c
> > @@ -241,10 +241,17 @@ int tpm_get_timeouts(struct tpm_chip *chip)
> > if (chip->flags & TPM_CHIP_FLAG_HAVE_TIMEOUTS)
> > return 0;
> >
> > - if (chip->flags & TPM_CHIP_FLAG_TPM2)
> > + if (chip->flags & TPM_CHIP_FLAG_TPM2) {
> > return tpm2_get_timeouts(chip);
> > - else
> > - return tpm1_get_timeouts(chip);
> > + } else {
> > + ssize_t ret = tpm_request_locality(chip);
> > +
> > + if (ret)
> > + return ret;
> > + ret = tpm1_get_timeouts(chip);
> > + tpm_relinquish_locality(chip);
> > + return ret;
> > + }
> > }
> > EXPORT_SYMBOL_GPL(tpm_get_timeouts);
> >
> > diff --git a/drivers/char/tpm/tpm.h b/drivers/char/tpm/tpm.h
> > index 947d1db0a5cc..8c13008437dd 100644
> > --- a/drivers/char/tpm/tpm.h
> > +++ b/drivers/char/tpm/tpm.h
> > @@ -193,6 +193,8 @@ static inline void tpm_msleep(unsigned int delay_msec)
> >
> > int tpm_chip_start(struct tpm_chip *chip);
> > void tpm_chip_stop(struct tpm_chip *chip);
> > +int tpm_request_locality(struct tpm_chip *chip);
> > +void tpm_relinquish_locality(struct tpm_chip *chip);
> > struct tpm_chip *tpm_find_get_ops(struct tpm_chip *chip);
> > __must_check int tpm_try_get_ops(struct tpm_chip *chip);
> > void tpm_put_ops(struct tpm_chip *chip);
> > diff --git a/drivers/char/tpm/tpm_tis_core.c b/drivers/char/tpm/tpm_tis_core.c
> > index 431919d5f48a..d4f381d6356e 100644
> > --- a/drivers/char/tpm/tpm_tis_core.c
> > +++ b/drivers/char/tpm/tpm_tis_core.c
> > @@ -708,11 +708,19 @@ static int tpm_tis_gen_interrupt(struct tpm_chip *chip)
> > u32 cap2;
> > cap_t cap;
> >
> > - if (chip->flags & TPM_CHIP_FLAG_TPM2)
> > + if (chip->flags & TPM_CHIP_FLAG_TPM2) {
> > return tpm2_get_tpm_pt(chip, 0x100, &cap2, desc);
> > - else
> > - return tpm1_getcap(chip, TPM_CAP_PROP_TIS_TIMEOUT, &cap, desc,
> > + } else {
> > + ssize_t ret = tpm_request_locality(chip);
> > +
> > + if (ret)
> > + return ret;
> > + ret = tpm1_getcap(chip, TPM_CAP_PROP_TIS_TIMEOUT, &cap, desc,
> > 0);
> > + tpm_relinquish_locality(chip);
> > + return ret;
> > + }
>
> Why this and nost just call tpm_chip_start()?

I.e. see tpm2_probe().

Also, add these in place:

Cc: [email protected]
Fixes: a3fbfae82b4c ("tpm: take TPM chip power gating out of tpm_transmit()")

Also a minor rant (appericiate the fix a lot in all cases): please hold on
until there's some window to see your patch. I did not understand the
reason for all these different versions.

Also remember the fix the minor glitches in the commit message that I
pointed out.

And again, thanks for fixing the issue.

/Jarkko

2021-02-03 12:01:09

by Dirk Gouders

Subject: Re: [PATCH v3] tpm_tis: Add missing tpm_request/relinquish_locality calls

Dirk Gouders <[email protected]> writes:

> Lukasz Majczak <[email protected]> writes:
>
>> There are missing calls to tpm_request_locality before the calls to
>> the tpm_get_timeouts() and tpm_tis_probe_irq_single() - both functions
>> internally send commands to the tpm. As the current
>> approach might work for tpm2, it fails for tpm1.x - in that case
>> call to tpm_get_timeouts() or tpm_tis_probe_irq_single()
>> without acquired locality fails and in turn causes tpm_tis_core_init()
>> to fail, it can be observed in the log with the following warning
>> trace:
>>
>> [ 4.324298] TPM returned invalid status
>> [ 4.324806] WARNING: CPU: 2 PID: 1 at drivers/char/tpm/tpm_tis_core.c:275 tpm_tis_status+0x86/0x8f
>> [ 4.325888] Modules linked in:
>> [ 4.326287] CPU: 2 PID: 1 Comm: swapper/0 Tainted: G W 5.11.0-rc6-next-20210201-00003-g214461adb2e8 #43
>> [ 4.327406] Hardware name: Google Caroline/Caroline, BIOS Google_Caroline.7820.430.0 07/20/2018
>> [ 4.327918] RIP: 0010:tpm_tis_status+0x86/0x8f
>> [ 4.328323] Code: 28 00 00 00 48 3b 45 f0 75 24 89 d8 48 83 c4 10 5b 5d c3 c6 05 58 d9 28 01 01 31 db 48 c7 c7 73 52 98 9c 31 c0 e8 c2 17 b0 ff <0f> 0b eb cd e8 cf 4f 55 00 0f 1f 44 00 00 55 48 89 e56
>> [ 4.330592] RSP: 0000:ffff88810092f7a0 EFLAGS: 00010246
>> [ 4.331223] RAX: 691ee151166db100 RBX: 0000000000000000 RCX: 0000000000000001
>> [ 4.331860] RDX: 0000000000000006 RSI: ffffffff9c96d302 RDI: 00000000ffffffff
>> [ 4.332272] RBP: ffff88810092f7b8 R08: dffffc0000000000 R09: fffffbfff39c96ce
>> [ 4.332683] R10: fffffbfff39c96ce R11: 0000000000000001 R12: ffff8881053e2000
>> [ 4.333109] R13: 0000000065000000 R14: ffff888105d71000 R15: ffff888105cd2628
>> [ 4.333738] FS: 0000000000000000(0000) GS:ffff88842f200000(0000) knlGS:0000000000000000
>> [ 4.334432] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>> [ 4.334783] CR2: 0000000000000000 CR3: 0000000037828001 CR4: 00000000003706e0
>> [ 4.335196] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
>> [ 4.335886] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
>> [ 4.336793] Call Trace:
>> [ 4.337107] tpm_tis_send_data+0x3d/0x22f
>> [ 4.337506] tpm_tis_send_main+0x30/0xf5
>> [ 4.337746] tpm_transmit+0xbf/0x327
>> [ 4.338042] ? __alloc_pages_nodemask+0x261/0x36d
>> [ 4.338615] tpm_transmit_cmd+0x2c/0x93
>> [ 4.339109] tpm1_getcap+0x232/0x285
>> [ 4.339578] tpm1_get_timeouts+0x48/0x47d
>> [ 4.339964] ? lockdep_init_map_type+0x71/0x257
>> [ 4.340256] ? lockdep_init_map_type+0x71/0x257
>> [ 4.340719] ? __raw_spin_lock_init+0x40/0x69
>> [ 4.341208] tpm_tis_core_init+0x402/0x5ee
>> [ 4.341629] tpm_tis_init+0x11d/0x1a2
>> [ 4.341867] tpm_tis_pnp_init+0x91/0xb5
>> [ 4.342101] ? tis_int_handler+0x15f/0x15f
>> [ 4.342466] pnp_device_probe+0x79/0x9f
>> [ 4.342941] really_probe+0x149/0x4a8
>> [ 4.343412] driver_probe_device+0xd6/0x144
>> [ 4.343968] device_driver_attach+0x42/0x5b
>> [ 4.344382] __driver_attach+0xca/0x139
>> [ 4.344617] ? driver_attach+0x1f/0x1f
>> [ 4.344860] bus_for_each_dev+0x85/0xb7
>> [ 4.345096] bus_add_driver+0x12b/0x228
>> [ 4.345330] driver_register+0x64/0xed
>> [ 4.345560] init_tis+0xa5/0xeb
>> [ 4.345784] ? lock_is_held_type+0x100/0x141
>> [ 4.346044] ? tpm_init+0x106/0x106
>> [ 4.346259] ? rcu_read_lock_sched_held+0x41/0x7e
>> [ 4.346542] ? tpm_init+0x106/0x106
>> [ 4.346678] battery: ACPI: Battery Slot [BAT0] (battery present)
>> [ 4.346754] do_one_initcall+0x1b9/0x43d
>> [ 4.346776] ? asm_sysvec_apic_timer_interrupt+0x12/0x20
>> [ 4.347659] ? lockdep_hardirqs_on+0x8e/0x12e
>> [ 4.347937] ? lock_is_held_type+0x100/0x141
>> [ 4.348196] ? rcu_read_lock_sched_held+0x41/0x7e
>> [ 4.348477] do_initcall_level+0x99/0xa9
>> [ 4.348717] ? kernel_init+0xe/0x10a
>> [ 4.348954] do_initcalls+0x4e/0x79
>> [ 4.349170] kernel_init_freeable+0x15a/0x1ae
>> [ 4.349434] ? rest_init+0x1d6/0x1d6
>> [ 4.349655] kernel_init+0xe/0x10a
>> [ 4.349882] ret_from_fork+0x22/0x30
>> [ 4.350103] irq event stamp: 700039
>> [ 4.350318] hardirqs last enabled at (700047): [<ffffffff9b735265>] console_unlock+0x4be/0x538
>> [ 4.350836] hardirqs last disabled at (700056): [<ffffffff9b734e84>] console_unlock+0xdd/0x538
>> [ 4.351331] softirqs last enabled at (699522): [<ffffffff9c4004ec>] __do_softirq+0x4ec/0x539
>> [ 4.351835] softirqs last disabled at (699517): [<ffffffff9c200f62>] asm_call_irq_on_stack+0x12/0x20
>>
>> Following the trace one can also notice a comment in the tpm_tis_status():
>>
>> /*
>> * 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.
>> */
>> In this case we don't have to call tpm_try_get_ops()
>> as both calls (tpm_get_timeouts() and tpm_tis_probe_irq_single()) are
>> in the tpm_tis_core_init function and don't require any locking or clock
>> enablement. Similar usage is in the probe_itpm() function also called
>> inside tpm_tis_core_init().
>> Tested on Samsung Chromebook Pro (Caroline).
>>
>> Signed-off-by: Lukasz Majczak <[email protected]>
>> ---
>> Hi Jarkko
>>
>> I have checked the linux-next with James patches, also followed Dirk
>> suggestion applying remaining ones, although without any luck -
>> a warning trace was still present. As Guneter mentioned earlier, this
>> patch[1] doesn't address a lack of acquired locality in the
>> tpm_get_timeouts() and does it only for tpm_tis_probe_irq_single() but
>> also without a call to tpm_relinquish_locality().
>>
>> Here are my logs from the clean linux-next master branch [2]
>> (with two James' patches present) and with my
>> patch applied[3]
>>
>> Best regards,
>> Lukasz
>>
>> [1] https://lore.kernel.org/linux-integrity/[email protected]/
>> [2] https://gist.github.com/semihalf-majczak-lukasz/f588c0684a6cc7d983bb9c4eb4bda586
>> [3] https://gist.github.com/semihalf-majczak-lukasz/88ede933bc7d28d806e3532850a04054
>>
>> v2 -> v3:
>> - Added braces around if part of if/else statements
>> - Rebased to linux-next
>> - Updated commit message
>>
>> drivers/char/tpm/tpm-chip.c | 4 ++--
>> drivers/char/tpm/tpm-interface.c | 13 ++++++++++---
>> drivers/char/tpm/tpm.h | 2 ++
>> drivers/char/tpm/tpm_tis_core.c | 14 +++++++++++---
>> 4 files changed, 25 insertions(+), 8 deletions(-)
>>
>> diff --git a/drivers/char/tpm/tpm-chip.c b/drivers/char/tpm/tpm-chip.c
>> index ddaeceb7e109..5351963a4b19 100644
>> --- a/drivers/char/tpm/tpm-chip.c
>> +++ b/drivers/char/tpm/tpm-chip.c
>> @@ -32,7 +32,7 @@ struct class *tpm_class;
>> struct class *tpmrm_class;
>> dev_t tpm_devt;
>>
>> -static int tpm_request_locality(struct tpm_chip *chip)
>> +int tpm_request_locality(struct tpm_chip *chip)
>> {
>> int rc;
>> @@ -47,7 +47,7 @@ static int tpm_request_locality(struct tpm_chip *chip)
>> return 0;
>> }
>>
>> -static void tpm_relinquish_locality(struct tpm_chip *chip)
>> +void tpm_relinquish_locality(struct tpm_chip *chip)
>> {
>> int rc;
>>
>
> Here, it seems
>
> +EXPORT_SYMBOL_GPL(tpm_request_locality);
>
> and
>
> +EXPORT_SYMBOL_GPL(tpm_relinquish_locality);
>
> are needed. Otherwise building tpm* modules fails:
>
> ERROR: modpost: "tpm_request_locality" [drivers/char/tpm/tpm_tis_core.ko] undefined!
> ERROR: modpost: "tpm_relinquish_locality" [drivers/char/tpm/tpm_tis_core.ko] undefined!
> make[1]: *** [scripts/Makefile.modpost:132: Module.symvers] Error 1
> make[1]: *** Deleting file 'Module.symvers'
> make: *** [Makefile:1405: modules] Error 2
>
> Otherwise, testing this patch results in no more warning
>
> TPM returned invalid status: 0xff
>
> and also no more warnings:
>
> tpm tpm0: tpm_try_transmit: send(): error -5
> tpm tpm0: [Firmware Bug]: TPM interrupt not working, polling instead
>
> Dirk
>
>> diff --git a/drivers/char/tpm/tpm-interface.c b/drivers/char/tpm/tpm-interface.c
>> index 1621ce818705..2a9001d329f2 100644
>> --- a/drivers/char/tpm/tpm-interface.c
>> +++ b/drivers/char/tpm/tpm-interface.c
>> @@ -241,10 +241,17 @@ int tpm_get_timeouts(struct tpm_chip *chip)
>> if (chip->flags & TPM_CHIP_FLAG_HAVE_TIMEOUTS)
>> return 0;
>>
>> - if (chip->flags & TPM_CHIP_FLAG_TPM2)
>> + if (chip->flags & TPM_CHIP_FLAG_TPM2) {
>> return tpm2_get_timeouts(chip);
>> - else
>> - return tpm1_get_timeouts(chip);
>> + } else {
>> + ssize_t ret = tpm_request_locality(chip);
>> +
>> + if (ret)
>> + return ret;
>> + ret = tpm1_get_timeouts(chip);
>> + tpm_relinquish_locality(chip);
>> + return ret;
>> + }
>> }
>> EXPORT_SYMBOL_GPL(tpm_get_timeouts);
>>
>> diff --git a/drivers/char/tpm/tpm.h b/drivers/char/tpm/tpm.h
>> index 947d1db0a5cc..8c13008437dd 100644
>> --- a/drivers/char/tpm/tpm.h
>> +++ b/drivers/char/tpm/tpm.h
>> @@ -193,6 +193,8 @@ static inline void tpm_msleep(unsigned int delay_msec)
>>
>> int tpm_chip_start(struct tpm_chip *chip);
>> void tpm_chip_stop(struct tpm_chip *chip);
>> +int tpm_request_locality(struct tpm_chip *chip);
>> +void tpm_relinquish_locality(struct tpm_chip *chip);
>> struct tpm_chip *tpm_find_get_ops(struct tpm_chip *chip);
>> __must_check int tpm_try_get_ops(struct tpm_chip *chip);
>> void tpm_put_ops(struct tpm_chip *chip);
>> diff --git a/drivers/char/tpm/tpm_tis_core.c b/drivers/char/tpm/tpm_tis_core.c
>> index 431919d5f48a..d4f381d6356e 100644
>> --- a/drivers/char/tpm/tpm_tis_core.c
>> +++ b/drivers/char/tpm/tpm_tis_core.c
>> @@ -708,11 +708,19 @@ static int tpm_tis_gen_interrupt(struct tpm_chip *chip)
>> u32 cap2;
>> cap_t cap;
>>
>> - if (chip->flags & TPM_CHIP_FLAG_TPM2)
>> + if (chip->flags & TPM_CHIP_FLAG_TPM2) {
>> return tpm2_get_tpm_pt(chip, 0x100, &cap2, desc);
>> - else
>> - return tpm1_getcap(chip, TPM_CAP_PROP_TIS_TIMEOUT, &cap, desc,
>> + } else {
>> + ssize_t ret = tpm_request_locality(chip);
>> +
>> + if (ret)
>> + return ret;
>> + ret = tpm1_getcap(chip, TPM_CAP_PROP_TIS_TIMEOUT, &cap, desc,
>> 0);
>> + tpm_relinquish_locality(chip);
>> + return ret;
>> + }
>> +
>> }
>>
>> /* Register the IRQ and issue a command that will cause an interrupt. If an

My apologies for just more noise from here.

But I think it could be important that I withdraw my above statement
concerning positive test results on my hardware.

I was now trying to understand Lukasz' fix and started wondering how
changes in the case of !(chip->flags & TPM_CHIP_FLAG_TPM2) could affect
my environment: tpm_tis STM0125:00: 2.0 TPM (device-id 0x0, rev-id 78).

So, I became very nervous and re-did several tests and it
(understandably) turned out that Lukasz' patch does not affect my machine
at all -- nearly: the only effect I noticed is that tpm_tis doesn't get
loaded automatically with his patch applied. I have to load it manually
but then get the familiar log messages.

But the tests I based my wrong statement on were done with static
tpm_tis, because of symbols not having been exported (V3).
I now noticed that tpm_tis behaves different depending on if it is built
static or as a module (latest tests done with
5.11.0-rc6-next-20210202-x86_64+).

In the static case, all I see in the logs is:

[ 2.673818] tpm_tis STM0125:00: 2.0 TPM (device-id 0x0, rev-id 78)

Perhaps there are better ways to access and test TPM but I tested it
using getrandom: no further messages in the kernel log were generated.

If tpm_tis it is built as a module the behavior is the one with warnings
and falling back to polling.

Dirk

2021-02-03 13:45:46

by Lukasz Majczak

Subject: Re: [PATCH v3] tpm_tis: Add missing tpm_request/relinquish_locality calls

Hi Jarkko, Dirk,

Jarkko,
Thank you for your points - I will try to fix all you have mentioned.
I think it would be good to clarify a few things, before going with
the next version. Regarding use tpm_chip_start/stop() around
tpm2_probe() call - I have followed the similar way it is done in the
probe_itpm() function, where is also a call to tpm_tis_send_data()
guarded by request/release_locality(). I have tested it on the Samsung
Chromebook Pro (which reports TPM 1.2 / Cr50) and it was sufficient
(e.g. I didn't have to enable the clock) to get rid of a trace
mentioned in the commit message....but now writing these words I'm
starting to think that using tpm_chip_start/stop() could be safer from
a point of view of other TPMs... so if you suggest using
tpm_chip_start/stop() shall I also add it to the probe_itpm() (instead
of request/release_locality()) ?

Dirk,
Thanks for the clarification. Regarding the issue you observe - I
wanted to address at first the one that is generating the trace
(please check the commit message) because it was leading to returning
an error in the tpm_tis_status() function causing TPM module not
initialized at all in the end - requesting locality before the call to
the tpm_tis_send_data() has helped in my case (my test environment). I
am aware of the second issue - "TPM interrupt not working, polling
instead", but as it is not as critical as the first one, I decided to
work on it later.

Thank you once again for all your input and sorry for a confusion with
sending patches.

Best regards,
Lukasz


śr., 3 lut 2021 o 12:56 Dirk Gouders <[email protected]> napisał(a):
>
> Dirk Gouders <[email protected]> writes:
>
> > Lukasz Majczak <[email protected]> writes:
> >
> >> There are missing calls to tpm_request_locality before the calls to
> >> the tpm_get_timeouts() and tpm_tis_probe_irq_single() - both functions
> >> internally send commands to the tpm. As the current
> >> approach might work for tpm2, it fails for tpm1.x - in that case
> >> call to tpm_get_timeouts() or tpm_tis_probe_irq_single()
> >> without acquired locality fails and in turn causes tpm_tis_core_init()
> >> to fail, it can be observed in the log with the following warning
> >> trace:
> >>
> >> [ 4.324298] TPM returned invalid status
> >> [ 4.324806] WARNING: CPU: 2 PID: 1 at drivers/char/tpm/tpm_tis_core.c:275 tpm_tis_status+0x86/0x8f
> >> [ 4.325888] Modules linked in:
> >> [ 4.326287] CPU: 2 PID: 1 Comm: swapper/0 Tainted: G W 5.11.0-rc6-next-20210201-00003-g214461adb2e8 #43
> >> [ 4.327406] Hardware name: Google Caroline/Caroline, BIOS Google_Caroline.7820.430.0 07/20/2018
> >> [ 4.327918] RIP: 0010:tpm_tis_status+0x86/0x8f
> >> [ 4.328323] Code: 28 00 00 00 48 3b 45 f0 75 24 89 d8 48 83 c4 10 5b 5d c3 c6 05 58 d9 28 01 01 31 db 48 c7 c7 73 52 98 9c 31 c0 e8 c2 17 b0 ff <0f> 0b eb cd e8 cf 4f 55 00 0f 1f 44 00 00 55 48 89 e56
> >> [ 4.330592] RSP: 0000:ffff88810092f7a0 EFLAGS: 00010246
> >> [ 4.331223] RAX: 691ee151166db100 RBX: 0000000000000000 RCX: 0000000000000001
> >> [ 4.331860] RDX: 0000000000000006 RSI: ffffffff9c96d302 RDI: 00000000ffffffff
> >> [ 4.332272] RBP: ffff88810092f7b8 R08: dffffc0000000000 R09: fffffbfff39c96ce
> >> [ 4.332683] R10: fffffbfff39c96ce R11: 0000000000000001 R12: ffff8881053e2000
> >> [ 4.333109] R13: 0000000065000000 R14: ffff888105d71000 R15: ffff888105cd2628
> >> [ 4.333738] FS: 0000000000000000(0000) GS:ffff88842f200000(0000) knlGS:0000000000000000
> >> [ 4.334432] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> >> [ 4.334783] CR2: 0000000000000000 CR3: 0000000037828001 CR4: 00000000003706e0
> >> [ 4.335196] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> >> [ 4.335886] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
> >> [ 4.336793] Call Trace:
> >> [ 4.337107] tpm_tis_send_data+0x3d/0x22f
> >> [ 4.337506] tpm_tis_send_main+0x30/0xf5
> >> [ 4.337746] tpm_transmit+0xbf/0x327
> >> [ 4.338042] ? __alloc_pages_nodemask+0x261/0x36d
> >> [ 4.338615] tpm_transmit_cmd+0x2c/0x93
> >> [ 4.339109] tpm1_getcap+0x232/0x285
> >> [ 4.339578] tpm1_get_timeouts+0x48/0x47d
> >> [ 4.339964] ? lockdep_init_map_type+0x71/0x257
> >> [ 4.340256] ? lockdep_init_map_type+0x71/0x257
> >> [ 4.340719] ? __raw_spin_lock_init+0x40/0x69
> >> [ 4.341208] tpm_tis_core_init+0x402/0x5ee
> >> [ 4.341629] tpm_tis_init+0x11d/0x1a2
> >> [ 4.341867] tpm_tis_pnp_init+0x91/0xb5
> >> [ 4.342101] ? tis_int_handler+0x15f/0x15f
> >> [ 4.342466] pnp_device_probe+0x79/0x9f
> >> [ 4.342941] really_probe+0x149/0x4a8
> >> [ 4.343412] driver_probe_device+0xd6/0x144
> >> [ 4.343968] device_driver_attach+0x42/0x5b
> >> [ 4.344382] __driver_attach+0xca/0x139
> >> [ 4.344617] ? driver_attach+0x1f/0x1f
> >> [ 4.344860] bus_for_each_dev+0x85/0xb7
> >> [ 4.345096] bus_add_driver+0x12b/0x228
> >> [ 4.345330] driver_register+0x64/0xed
> >> [ 4.345560] init_tis+0xa5/0xeb
> >> [ 4.345784] ? lock_is_held_type+0x100/0x141
> >> [ 4.346044] ? tpm_init+0x106/0x106
> >> [ 4.346259] ? rcu_read_lock_sched_held+0x41/0x7e
> >> [ 4.346542] ? tpm_init+0x106/0x106
> >> [ 4.346678] battery: ACPI: Battery Slot [BAT0] (battery present)
> >> [ 4.346754] do_one_initcall+0x1b9/0x43d
> >> [ 4.346776] ? asm_sysvec_apic_timer_interrupt+0x12/0x20
> >> [ 4.347659] ? lockdep_hardirqs_on+0x8e/0x12e
> >> [ 4.347937] ? lock_is_held_type+0x100/0x141
> >> [ 4.348196] ? rcu_read_lock_sched_held+0x41/0x7e
> >> [ 4.348477] do_initcall_level+0x99/0xa9
> >> [ 4.348717] ? kernel_init+0xe/0x10a
> >> [ 4.348954] do_initcalls+0x4e/0x79
> >> [ 4.349170] kernel_init_freeable+0x15a/0x1ae
> >> [ 4.349434] ? rest_init+0x1d6/0x1d6
> >> [ 4.349655] kernel_init+0xe/0x10a
> >> [ 4.349882] ret_from_fork+0x22/0x30
> >> [ 4.350103] irq event stamp: 700039
> >> [ 4.350318] hardirqs last enabled at (700047): [<ffffffff9b735265>] console_unlock+0x4be/0x538
> >> [ 4.350836] hardirqs last disabled at (700056): [<ffffffff9b734e84>] console_unlock+0xdd/0x538
> >> [ 4.351331] softirqs last enabled at (699522): [<ffffffff9c4004ec>] __do_softirq+0x4ec/0x539
> >> [ 4.351835] softirqs last disabled at (699517): [<ffffffff9c200f62>] asm_call_irq_on_stack+0x12/0x20
> >>
> >> Following the trace one can also notice a comment in the tpm_tis_status():
> >>
> >> /*
> >> * 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.
> >> */
> >> In this case we don't have to call tpm_try_get_ops()
> >> as both calls (tpm_get_timeouts() and tpm_tis_probe_irq_single()) are
> >> in the tpm_tis_core_init function and don't require any locking or clock
> >> enablement. Similar usage is in the probe_itpm() function also called
> >> inside tpm_tis_core_init().
> >> Tested on Samsung Chromebook Pro (Caroline).
> >>
> >> Signed-off-by: Lukasz Majczak <[email protected]>
> >> ---
> >> Hi Jarkko
> >>
> >> I have checked the linux-next with James patches, also followed Dirk
> >> suggestion applying remaining ones, although without any luck -
> >> a warning trace was still present. As Guneter mentioned earlier, this
> >> patch[1] doesn't address a lack of acquired locality in the
> >> tpm_get_timeouts() and does it only for tpm_tis_probe_irq_single() but
> >> also without a call to tpm_relinquish_locality().
> >>
> >> Here are my logs from the clean linux-next master branch [2]
> >> (with two James' patches present) and with my
> >> patch applied[3]
> >>
> >> Best regards,
> >> Lukasz
> >>
> >> [1] https://lore.kernel.org/linux-integrity/[email protected]/
> >> [2] https://gist.github.com/semihalf-majczak-lukasz/f588c0684a6cc7d983bb9c4eb4bda586
> >> [3] https://gist.github.com/semihalf-majczak-lukasz/88ede933bc7d28d806e3532850a04054
> >>
> >> v2 -> v3:
> >> - Added braces around if part of if/else statements
> >> - Rebased to linux-next
> >> - Updated commit message
> >>
> >> drivers/char/tpm/tpm-chip.c | 4 ++--
> >> drivers/char/tpm/tpm-interface.c | 13 ++++++++++---
> >> drivers/char/tpm/tpm.h | 2 ++
> >> drivers/char/tpm/tpm_tis_core.c | 14 +++++++++++---
> >> 4 files changed, 25 insertions(+), 8 deletions(-)
> >>
> >> diff --git a/drivers/char/tpm/tpm-chip.c b/drivers/char/tpm/tpm-chip.c
> >> index ddaeceb7e109..5351963a4b19 100644
> >> --- a/drivers/char/tpm/tpm-chip.c
> >> +++ b/drivers/char/tpm/tpm-chip.c
> >> @@ -32,7 +32,7 @@ struct class *tpm_class;
> >> struct class *tpmrm_class;
> >> dev_t tpm_devt;
> >>
> >> -static int tpm_request_locality(struct tpm_chip *chip)
> >> +int tpm_request_locality(struct tpm_chip *chip)
> >> {
> >> int rc;
> >> @@ -47,7 +47,7 @@ static int tpm_request_locality(struct tpm_chip *chip)
> >> return 0;
> >> }
> >>
> >> -static void tpm_relinquish_locality(struct tpm_chip *chip)
> >> +void tpm_relinquish_locality(struct tpm_chip *chip)
> >> {
> >> int rc;
> >>
> >
> > Here, it seems
> >
> > +EXPORT_SYMBOL_GPL(tpm_request_locality);
> >
> > and
> >
> > +EXPORT_SYMBOL_GPL(tpm_relinquish_locality);
> >
> > are needed. Otherwise building tpm* modules fails:
> >
> > ERROR: modpost: "tpm_request_locality" [drivers/char/tpm/tpm_tis_core.ko] undefined!
> > ERROR: modpost: "tpm_relinquish_locality" [drivers/char/tpm/tpm_tis_core.ko] undefined!
> > make[1]: *** [scripts/Makefile.modpost:132: Module.symvers] Error 1
> > make[1]: *** Deleting file 'Module.symvers'
> > make: *** [Makefile:1405: modules] Error 2
> >
> > Otherwise, testing this patch results in no more warning
> >
> > TPM returned invalid status: 0xff
> >
> > and also no more warnings:
> >
> > tpm tpm0: tpm_try_transmit: send(): error -5
> > tpm tpm0: [Firmware Bug]: TPM interrupt not working, polling instead
> >
> > Dirk
> >
> >> diff --git a/drivers/char/tpm/tpm-interface.c b/drivers/char/tpm/tpm-interface.c
> >> index 1621ce818705..2a9001d329f2 100644
> >> --- a/drivers/char/tpm/tpm-interface.c
> >> +++ b/drivers/char/tpm/tpm-interface.c
> >> @@ -241,10 +241,17 @@ int tpm_get_timeouts(struct tpm_chip *chip)
> >> if (chip->flags & TPM_CHIP_FLAG_HAVE_TIMEOUTS)
> >> return 0;
> >>
> >> - if (chip->flags & TPM_CHIP_FLAG_TPM2)
> >> + if (chip->flags & TPM_CHIP_FLAG_TPM2) {
> >> return tpm2_get_timeouts(chip);
> >> - else
> >> - return tpm1_get_timeouts(chip);
> >> + } else {
> >> + ssize_t ret = tpm_request_locality(chip);
> >> +
> >> + if (ret)
> >> + return ret;
> >> + ret = tpm1_get_timeouts(chip);
> >> + tpm_relinquish_locality(chip);
> >> + return ret;
> >> + }
> >> }
> >> EXPORT_SYMBOL_GPL(tpm_get_timeouts);
> >>
> >> diff --git a/drivers/char/tpm/tpm.h b/drivers/char/tpm/tpm.h
> >> index 947d1db0a5cc..8c13008437dd 100644
> >> --- a/drivers/char/tpm/tpm.h
> >> +++ b/drivers/char/tpm/tpm.h
> >> @@ -193,6 +193,8 @@ static inline void tpm_msleep(unsigned int delay_msec)
> >>
> >> int tpm_chip_start(struct tpm_chip *chip);
> >> void tpm_chip_stop(struct tpm_chip *chip);
> >> +int tpm_request_locality(struct tpm_chip *chip);
> >> +void tpm_relinquish_locality(struct tpm_chip *chip);
> >> struct tpm_chip *tpm_find_get_ops(struct tpm_chip *chip);
> >> __must_check int tpm_try_get_ops(struct tpm_chip *chip);
> >> void tpm_put_ops(struct tpm_chip *chip);
> >> diff --git a/drivers/char/tpm/tpm_tis_core.c b/drivers/char/tpm/tpm_tis_core.c
> >> index 431919d5f48a..d4f381d6356e 100644
> >> --- a/drivers/char/tpm/tpm_tis_core.c
> >> +++ b/drivers/char/tpm/tpm_tis_core.c
> >> @@ -708,11 +708,19 @@ static int tpm_tis_gen_interrupt(struct tpm_chip *chip)
> >> u32 cap2;
> >> cap_t cap;
> >>
> >> - if (chip->flags & TPM_CHIP_FLAG_TPM2)
> >> + if (chip->flags & TPM_CHIP_FLAG_TPM2) {
> >> return tpm2_get_tpm_pt(chip, 0x100, &cap2, desc);
> >> - else
> >> - return tpm1_getcap(chip, TPM_CAP_PROP_TIS_TIMEOUT, &cap, desc,
> >> + } else {
> >> + ssize_t ret = tpm_request_locality(chip);
> >> +
> >> + if (ret)
> >> + return ret;
> >> + ret = tpm1_getcap(chip, TPM_CAP_PROP_TIS_TIMEOUT, &cap, desc,
> >> 0);
> >> + tpm_relinquish_locality(chip);
> >> + return ret;
> >> + }
> >> +
> >> }
> >>
> >> /* Register the IRQ and issue a command that will cause an interrupt. If an
>
> My apologies for just more noise from here.
>
> But I think it could be important that I withdraw my above statement
> concerning positive test results on my hardware.
>
> I was now trying to understand Lukasz' fix and started wondering how
> changes in the case of !(chip->flags & TPM_CHIP_FLAG_TPM2) could affect
> my environment: tpm_tis STM0125:00: 2.0 TPM (device-id 0x0, rev-id 78).
>
> So, I became very nervous and re-did several tests and it
> (understandably) turned out that Lukasz' patch does not affect my machine
> at all -- nearly: the only effect I noticed is that tpm_tis doesn't get
> loaded automatically with his patch applied. I have to load it manually
> but then get the familiar log messages.
>
> But the tests I based my wrong statement on were done with static
> tpm_tis, because of symbols not having been exported (V3).
> I now noticed that tpm_tis behaves different depending on if it is built
> static or as a module (latest tests done with
> 5.11.0-rc6-next-20210202-x86_64+).
>
> In the static case, all I see in the logs is:
>
> [ 2.673818] tpm_tis STM0125:00: 2.0 TPM (device-id 0x0, rev-id 78)
>
> Perhaps there are better ways to access and test TPM but I tested it
> using getrandom: no further messages in the kernel log were generated.
>
> If tpm_tis it is built as a module the behavior is the one with warnings
> and falling back to polling.
>
> Dirk

2021-02-04 02:23:09

by Jarkko Sakkinen

Subject: Re: [PATCH v3] tpm_tis: Add missing tpm_request/relinquish_locality calls

On Wed, Feb 03, 2021 at 02:43:44PM +0100, Lukasz Majczak wrote:
> Hi Jarkko, Dirk,
>
> Jarkko,
> Thank you for your points - I will try to fix all you have mentioned.
> I think it would be good to clarify a few things, before going with
> the next version. Regarding use tpm_chip_start/stop() around
> tpm2_probe() call - I have followed the similar way it is done in the
> probe_itpm() function, where is also a call to tpm_tis_send_data()
> guarded by request/release_locality(). I have tested it on the Samsung
> Chromebook Pro (which reports TPM 1.2 / Cr50) and it was sufficient
> (e.g. I didn't have to enable the clock) to get rid of a trace
> mentioned in the commit message....but now writing these words I'm
> starting to think that using tpm_chip_start/stop() could be safer from
> a point of view of other TPMs... so if you suggest using
> tpm_chip_start/stop() shall I also add it to the probe_itpm() (instead
> of request/release_locality()) ?
>
> Dirk,
> Thanks for the clarification. Regarding the issue you observe - I
> wanted to address at first the one that is generating the trace
> (please check the commit message) because it was leading to returning
> an error in the tpm_tis_status() function causing TPM module not
> initialized at all in the end - requesting locality before the call to
> the tpm_tis_send_data() has helped in my case (my test environment). I
> am aware of the second issue - "TPM interrupt not working, polling
> instead", but as it is not as critical as the first one, I decided to
> work on it later.
>
> Thank you once again for all your input and sorry for a confusion with
> sending patches.

NP, thanks for doing this. Just take your time and polish the cosmetic
things. Especially for bug fixes a clean changelog is essential.

> Best regards,
> Lukasz

/Jarkko