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.
--
Ben Hutchings
Once a job is fouled up, anything done to improve it makes it worse.
Attachment:
signature.asc
Description: This is a digitally signed message part