Bug#584273: previous dmesg logs were incomplete
What's happening here is that this TPM seems to not be setting a proper
status flag after a command is sent to it, so the device driver keeps
waiting for such status flag to be set and then timeouts the attempt.
The TPM has three timeout values, and the longest one is by default
2min, given the TPM can take a good amount of time to perform asymmetric
operations. If the command being sent to the TPM isn't recognized by the
device driver, it assumes the timeout should be the maximum.
So, to accommodate this TPM the device driver should just wait for such
status to be set, in case it's doesn't, set an internal (device driver
space) flag to stop returning an error after the timeout gets reached.
I've sent a patch to a redhat bugzilla #530393 to check which ordinal is
being sent to this TPM, since it shouldn't use the 2min timeout for all
commands, just for the ones that aren't hardset in the device driver,
and also prints the status value after a command was sent to it. I'd
appreciate if someone could return the results when with the patch, but
for now I'm going to send a patch that implements the workaround I've
mentioned above.
Thanks,
Rajiv Andrade
Security Development
IBM Linux Technology Center
On Thu, 2010-06-03 at 00:16 +0100, Ben Hutchings wrote:
> Here's what's happening:
>
> On Wed, 2010-06-02 at 22:45 +0200, Tshepang Lekhonkhobe wrote:
> [...]
> > [ 2.430983] kjournald starting. Commit interval 5 seconds
> > [ 2.431049] EXT3-fs: mounted filesystem with ordered data mode.
>
> Root filesystem is mounted.
>
> [...]
> > [ 4.908444] tpm_tis 00:0b: 1.2 TPM (device-id 0xB, rev-id 16)
>
> tpm_tis is loaded. I thought it was loaded from the initramfs, but I
> was wrong. This is why 'blacklist=tpm_tis' on the kernel command line
> did not work. Instead, you should add:
>
> blacklist tpm_tis
>
> to the file /etc/modprobe.d/blacklist.conf.
>
> tpm_tis now tries to send 3 commands to the TPM, but doesn't receive any
> response. Eventually it gives up on them (time-out). For this whole
> time it is holding a lock which blocks parport_pc (parallel port driver)
> from initialising:
>
> [...]
> > [ 127.164184] tpm_tis 00:0b: tpm_transmit: tpm_send: error 4294967234
> [...]
> > [ 240.560099] INFO: task modprobe:700 blocked for more than 120 seconds.
> > [ 240.560107] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
> > disables this message.
> > [ 240.560114] modprobe D c14b47e0 0 700 635 0x00000000
> > [ 240.560126] f678f300 00000086 f67abe6c c14b47e0 00000000 c1415040
> > c1415040 c1410604
> > [ 240.560141] f678f4bc c2a08040 00000001 24b6f700 00000001 00000001
> > 00000000 00000000
> > [ 240.560156] c2a03604 f678f4bc fffedfd3 000007ff 00000078 00000000
> > 00000000 000007ff
> > [ 240.560171] Call Trace:
> > [ 240.560188] [<c126cda9>] ? schedule_timeout+0x20/0xb0
> > [ 240.560201] [<c10f33fa>] ? sysfs_find_dirent+0x13/0x23
> > [ 240.560210] [<c10f3805>] ? sysfs_addrm_finish+0x13/0x199
> > [ 240.560218] [<c10f354f>] ? sysfs_add_one+0x11/0xb8
> > [ 240.560226] [<c126d588>] ? __down_common+0x7c/0xbe
> > [ 240.560250] [<c1047bcf>] ? down+0x1f/0x2c
> > [ 240.560262] [<c11b2a05>] ? __driver_attach+0x27/0x5b
> > [ 240.560270] [<c11b238d>] ? bus_for_each_dev+0x37/0x5f
> > [ 240.560280] [<c11b281d>] ? driver_attach+0x11/0x13
> > [ 240.560289] [<c11b29de>] ? __driver_attach+0x0/0x5b
> > [ 240.560297] [<c11b1e55>] ? bus_add_driver+0x99/0x1c5
> > [ 240.560306] [<c11b2c4f>] ? driver_register+0x87/0xe0
> > [ 240.560324] [<f8488318>] ? parport_pc_init+0x284/0x330 [parport_pc]
> > [ 240.560341] [<f8488094>] ? parport_pc_init+0x0/0x330 [parport_pc]
> > [ 240.560350] [<c100113e>] ? do_one_initcall+0x55/0x155
> > [ 240.560360] [<c1057dd9>] ? sys_init_module+0xa7/0x1d7
> > [ 240.560368] [<c10030fb>] ? sysenter_do_call+0x12/0x28
> [...]
> > [ 249.420078] tpm_tis 00:0b: tpm_transmit: tpm_send: error 4294967234
> [...]
> > [ 360.560086] INFO: task modprobe:700 blocked for more than 120 seconds.
> > [ 360.560094] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
> > disables this message.
> > [ 360.560101] modprobe D c14b47e0 0 700 635 0x00000000
> > [ 360.560112] f678f300 00000086 f67abe6c c14b47e0 00000000 c1415040
> > c1415040 c1410604
> > [ 360.560128] f678f4bc c2a08040 00000001 24b6f700 00000001 00000001
> > 00000000 00000000
> > [ 360.560143] c2a03604 f678f4bc fffedfd3 000007ff 00000078 00000000
> > 00000000 000007ff
> > [ 360.560158] Call Trace:
> > [ 360.560177] [<c126cda9>] ? schedule_timeout+0x20/0xb0
> > [ 360.560189] [<c10f33fa>] ? sysfs_find_dirent+0x13/0x23
> > [ 360.560198] [<c10f3805>] ? sysfs_addrm_finish+0x13/0x199
> > [ 360.560206] [<c10f354f>] ? sysfs_add_one+0x11/0xb8
> > [ 360.560214] [<c126d588>] ? __down_common+0x7c/0xbe
> > [ 360.560261] [<c1047bcf>] ? down+0x1f/0x2c
> > [ 360.560277] [<c11b2a05>] ? __driver_attach+0x27/0x5b
> > [ 360.560285] [<c11b238d>] ? bus_for_each_dev+0x37/0x5f
> > [ 360.560296] [<c11b281d>] ? driver_attach+0x11/0x13
> > [ 360.560305] [<c11b29de>] ? __driver_attach+0x0/0x5b
> > [ 360.560313] [<c11b1e55>] ? bus_add_driver+0x99/0x1c5
> > [ 360.560323] [<c11b2c4f>] ? driver_register+0x87/0xe0
> > [ 360.560342] [<f8488318>] ? parport_pc_init+0x284/0x330 [parport_pc]
> > [ 360.560358] [<f8488094>] ? parport_pc_init+0x0/0x330 [parport_pc]
> > [ 360.560368] [<c100113e>] ? do_one_initcall+0x55/0x155
> > [ 360.560378] [<c1057dd9>] ? sys_init_module+0xa7/0x1d7
> > [ 360.560386] [<c10030fb>] ? sysenter_do_call+0x12/0x28
> > [ 370.172112] tpm_tis 00:0b: tpm_transmit: tpm_send: error 4294967234
>
> Now tpm_tis is done and releases the lock, so parport_pc can continue:
>
> > [ 370.175858] parport_pc 00:0a: activated
> > [ 370.175869] parport_pc 00:0a: reported by Plug and Play ACPI
> > [ 370.175998] parport0: PC-style at 0x378 (0x778), irq 5 [PCSPP,TRISTATE]
> > [ 370.276537] lp0: using parport0 (interrupt-driven).
> [...]
>
> While you can work around this through blacklist.conf, there is at least
> two bugs here:
> 1. The time-out used in tpm_tis is too long. (Or the time-out set by
> the BIOS is too long, and tpm/tpm_tis are blindly trusting it.)
> 2. tpm_tis is ignoring the lack of response to these initial commands
> and is struggling on rather than treating it as a failure.
>
> I assume that this is only happening now because tpm_tis was not
> previously loaded automatically; this was changed in stable version
> 2.6.32.12 (Debian version 2.6.32-12). This may have been a bad move,
> considering these bugs.
>
> Ben.
>
Reply to: