Hello,
On Wed, Feb 05, 2025 at 02:29:36PM +0000, Jonathan McDowell wrote:
> On Wed, Feb 05, 2025 at 02:26:05PM +0100, Michal Suchánek wrote:
> > On Fri, Jan 31, 2025 at 09:31:30PM +0200, Jarkko Sakkinen wrote:
> > > On Fri Jan 31, 2025 at 7:28 PM EET, Michal Suchánek wrote:
> > > > On Fri, Jan 31, 2025 at 07:12:06PM +0200, Jarkko Sakkinen wrote:
> > > > > On Fri Jan 31, 2025 at 3:02 PM EET, Michal Suchánek wrote:
> > > > > > It looks like the timeout_b is used exclusively as the ready
> > > > > > timeout *),
> > > > > > with various sources of the value depending on chip type.
> > > > > >
> > > > > > Then increasing it should not cause any problem other than the
> > > > > > kernel
> > > > > > waiting longer when the TPM chip is really stuck.
> > > > > >
> > > > > > * There is one instance of use of timeout_b for TPM_STS_VALID in
> > > > > > st33zp24_pm_resume.
> > > > >
> > > > > Possible for you to give a shot for patch and try it out for a while?
> > > > > I'm fine with 2x, or even 4x in this case.
> > > >
> > > > I will see what I can do. It will definitely take a while.
> > > >
> > > > How would you like to multiply it?
> > > >
> > > > At the sime the timeout_b is assigned, or at the time it's used?
> > > >
> > > > Any specific patch that you have in mind?
> > >
> > > I'll think about this a bit and send a patch with RFC tag. Might take
> > > to late next week.
> >
> > The ready timeout is not the only one exceeded:
> >
> > > Jan 29 19:01:55 localhost kernel: tpm tpm0: tpm_tis_send_data: 357:
> > > ready: Timed out (2232 of 2000 ms)
> > > Jan 29 19:01:55 localhost kernel: tpm tpm0: tpm_tis_send_data: 357:
> > > ready: Took (2232 of 2000 ms)
> > > Jan 30 09:08:20 localhost kernel: tpm tpm0: tpm_tis_send_data: 353:
> > > ready: Timed out (2228 of 2000 ms)
> > > Jan 30 09:08:20 localhost kernel: tpm tpm0: tpm_tis_send_data: 353:
> > > ready: Took (2228 of 2000 ms)
> > > Jan 30 14:26:16 localhost kernel: tpm tpm0: tpm_tis_send_data: 353: stat:
> > > Timed out (540 of 200 ms)
> > > Jan 30 14:26:16 localhost kernel: tpm tpm0: tpm_tis_send_data: 353: stat:
> > > Took (540 of 200 ms)
> > > Jan 30 23:25:13 localhost kernel: tpm tpm0: tpm_tis_send_data: 354: stat:
> > > Timed out (2224 of 200 ms)
> > > Jan 30 23:25:13 localhost kernel: tpm tpm0: tpm_tis_send_data: 354: stat:
> > > Took (2224 of 200 ms)
> > > Feb 01 05:25:33 localhost kernel: tpm tpm0: tpm_tis_send_data: 357:
> > > ready: Timed out (2228 of 2000 ms)
> > > Feb 01 05:25:33 localhost kernel: tpm tpm0: tpm_tis_send_data: 357:
> > > ready: Took (2228 of 2000 ms)
> > > Feb 01 07:02:53 localhost kernel: tpm tpm0: tpm_tis_send_data: 353: stat:
> > > Timed out (556 of 200 ms)
> > > Feb 01 07:02:53 localhost kernel: tpm tpm0: tpm_tis_send_data: 353: stat:
> > > Took (556 of 200 ms)
> > > Feb 01 09:26:22 localhost kernel: tpm tpm0: tpm_tis_send_data: 353: stat:
> > > Timed out (540 of 200 ms)
> > > Feb 01 09:26:22 localhost kernel: tpm tpm0: tpm_tis_send_data: 353: stat:
> > > Took (540 of 200 ms)
> > > Feb 02 02:45:35 localhost kernel: tpm tpm0: tpm_tis_send_data: 379: stat:
> > > Timed out (272 of 200 ms)
> > > Feb 02 02:45:35 localhost kernel: tpm tpm0: tpm_tis_send_data: 379: stat:
> > > Took (272 of 200 ms)
> > > Feb 02 03:40:04 localhost kernel: tpm tpm0: tpm_tis_send_data: 353: stat:
> > > Timed out (536 of 200 ms)
> > > Feb 02 03:40:04 localhost kernel: tpm tpm0: tpm_tis_send_data: 353: stat:
> > > Took (536 of 200 ms)
> > > Feb 02 04:09:50 localhost kernel: tpm tpm0: tpm_tis_send_data: 357:
> > > ready: Timed out (2236 of 2000 ms)
> > > Feb 02 04:09:50 localhost kernel: tpm tpm0: tpm_tis_send_data: 357:
> > > ready: Took (2236 of 2000 ms)
> > > Feb 02 09:57:41 localhost kernel: tpm tpm0: tpm_tis_send_data: 353: stat:
> > > Timed out (540 of 200 ms)
> > > Feb 02 09:57:41 localhost kernel: tpm tpm0: tpm_tis_send_data: 353: stat:
> > > Took (540 of 200 ms)
> > > Feb 02 10:59:00 localhost kernel: tpm tpm0: tpm_tis_send_data: 353: stat:
> > > Timed out (536 of 200 ms)
> > > Feb 02 10:59:00 localhost kernel: tpm tpm0: tpm_tis_send_data: 353: stat:
> > > Took (536 of 200 ms)
> > > Feb 03 03:58:09 localhost kernel: tpm tpm0: tpm_tis_send_data: 354: stat:
> > > Timed out (540 of 200 ms)
> > > Feb 03 03:58:09 localhost kernel: tpm tpm0: tpm_tis_send_data: 354: stat:
> > > Took (540 of 200 ms)
Another new failure:
Mar 25 23:06:20 localhost kernel: tpm tpm0: tpm_tis_send_data: 305: valid:
Timed out (212 of 200 ms)
Mar 25 23:06:20 localhost kernel: tpm tpm0: tpm_tis_send_data: 305: valid: Took
(212 of 200 ms)
which is CREATE PRIMARY, and happens on
tpm_tis MSFT0101:00: 2.0 TPM (device-id 0x1A, rev-id 16)
TPM Device
Vendor ID:
Specification Version: 2.0
Firmware Revision: 5.63
Description: INFINEON
Characteristics:
Family configurable via platform software support
OEM-specific Information: 0x00000000
With this we have ready timoeout which is 2000ms but the TPM takes
up to 2236ms, stat timeout which is 200ms and the TPM takes up to
2224ms, and valid timeout which is 200 ms and the TPM takes up to 212ms.
Given that I think it makes sense to replace all these timeouts with one
timeout that is something like 4 or 5s.
This does not address the other problem that when the rimeout triggers
on something like LOAD CONTEXT then the kernel and the TPM don't agree
on what the state of the context is.
Thanks
Michal
