Bug#690505: broken usb device breaks direct i/o even to non-usb drives
On Mon, Oct 15, 2012 at 4:28 AM, Jonathan Nieder <jrnieder@gmail.com> wrote:
> Hi,
>
> mail user wrote:
>
>> plugging in a fake (128 that later turned out to be just 2Gb) flashdrive
>> in the usb port, dd it to /dev/null, ctrl-c, dd zeroes to it, ctrl-c,
>> dd unresponsive to ctrl-c
>
> Thanks for a clear report. That sounds like a serious bug. Is it
> reproducible?
Thanks for the fast reply. Yes, it is reproductible
>
> If so, full "dmesg" output after reproducing it and running
>
> echo w >/proc/sysrq-trigger
>
> would be very interesting.
pasted here: http://paste.debian.net/200555/
Ben: no forced rmmod this time.
exact steps performed:
root@homerouter:~# dd if=/dev/zero bs=32M|tr '\000' '\377'|pv -br|dd
of=/dev/sdb bs=32M
^C19+0 records in
18+0 records out
603979776 bytes (604 MB) copied, 17.3839 s, 34.7 MB/s
---
Mon Oct 15 04:43:38 2012 8117 tail -f /var/log/all
Mon Oct 15 04:46:31 2012 8171 [flush-8:16]
Mon Oct 15 04:47:22 2012 8219 udevd --daemon
Mon Oct 15 04:47:22 2012 8220 udevd --daemon
Mon Oct 15 04:50:48 2012 8261 [kworker/1:1]
Mon Oct 15 04:52:08 2012 8290 dd of=/dev/sdb bs=32M
Mon Oct 15 04:52:25 2012 8293 /sbin/blkid -o udev -p /dev/sdb <- this
launched at the time I pressed ctrl-c
Mon Oct 15 04:52:59 2012 8297 ps -eo lstart,pid,cmd
---
then udevd started complaining
(lots of) Oct 15 04:53:27 homerouter udevd[8219]: timeout: killing
'/sbin/blkid -o udev -p
/dev/sdb' [8293]
then later:
Oct 15 04:57:49 homerouter kernel: [ 7080.616052] INFO: task
blkid:8293 blockedfor more than 120 seconds.
Oct 15 04:57:49 homerouter kernel: [ 7080.616100] "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Oct 15 04:57:49 homerouter kernel: [ 7080.616163] blkid D
ffff88011bc93740 0 8293 1 0x00000004
Oct 15 04:57:49 homerouter kernel: [ 7080.616243] ffff88011408a040
0000000000000086 0000000000000000 ffff880116f080c0
Oct 15 04:57:49 homerouter kernel: [ 7080.616369] 0000000000013740
ffff880109739fd8 ffff880109739fd8 ffff88011408a040
Oct 15 04:57:49 homerouter kernel: [ 7080.616496] 0000000000000100
0000000109739b60 ffff880109739b60 ffff88011214f3d8
Oct 15 04:57:49 homerouter kernel: [ 7080.616622] Call Trace:
Oct 15 04:57:49 homerouter kernel: [ 7080.616662]
[<ffffffff8134a2cf>] ? __mutex_lock_common.isra.5+0xff/0x164
Oct 15 04:57:49 homerouter kernel: [ 7080.616706]
[<ffffffff8134a1bd>] ? mutex_lock+0x1a/0x2d
Oct 15 04:57:49 homerouter kernel: [ 7080.616748]
[<ffffffff81121565>] ? __blkdev_get+0x9a/0x3a9
Oct 15 04:57:49 homerouter kernel: [ 7080.616806]
[<ffffffff81121b1b>] ? blkdev_get+0x2a7/0x2a7
Oct 15 04:57:49 homerouter kernel: [ 7080.616848]
[<ffffffff81121a3b>] ? blkdev_get+0x1c7/0x2a7
Oct 15 04:57:49 homerouter kernel: [ 7080.616889]
[<ffffffff81036457>] ? should_resched+0x5/0x23
Oct 15 04:57:49 homerouter kernel: [ 7080.616931]
[<ffffffff81121b1b>] ? blkdev_get+0x2a7/0x2a7
Oct 15 04:57:49 homerouter kernel: [ 7080.616973]
[<ffffffff810f7c66>] ? __dentry_open+0x19c/0x2b3
Oct 15 04:57:49 homerouter kernel: [ 7080.617015]
[<ffffffff811010c8>] ? dget+0x12/0x1e
Oct 15 04:57:49 homerouter kernel: [ 7080.617055]
[<ffffffff81104239>] ? do_last+0x553/0x58d
Oct 15 04:57:49 homerouter kernel: [ 7080.617095]
[<ffffffff8110486b>] ? path_openat+0xce/0x32a
Oct 15 04:57:49 homerouter kernel: [ 7080.617137]
[<ffffffff810cd779>] ? pte_offset_kernel+0x16/0x35
Oct 15 04:57:49 homerouter kernel: [ 7080.617179]
[<ffffffff81104b89>] ? do_filp_open+0x2a/0x6e
Oct 15 04:57:49 homerouter kernel: [ 7080.617220]
[<ffffffff813499cf>] ? _cond_resched+0x7/0x1c
Oct 15 04:57:49 homerouter kernel: [ 7080.617263]
[<ffffffff811b29d9>] ? __strncpy_from_user+0x18/0x48
Oct 15 04:57:49 homerouter kernel: [ 7080.617306]
[<ffffffff8110d8bf>] ? alloc_fd+0x64/0x109
Oct 15 04:57:49 homerouter kernel: [ 7080.617346]
[<ffffffff810f8b3b>] ? do_sys_open+0x5e/0xe5
Oct 15 04:57:49 homerouter kernel: [ 7080.617388]
[<ffffffff8134fc92>] ? system_call_fastpath+0x16/0x1b
>
> [...]
>> then
>> rmmod -f usb-storage
>>
>> then
>> unplug the flashdrive
>>
>> * What was the outcome of this action?
>>
>> forced removal of usb-storage produced the following kernel dmesg
>> (ignore the tainted message, it is from the zfs/spl modules):
>>
>> Oct 15 00:40:50 homerouter kernel: [88756.711046] Disabling lock debugging due to kernel taint
>> Oct 15 00:40:50 homerouter kernel: [88756.711092] usbcore: deregistering interface driver usb-storage
>> Oct 15 00:40:51 homerouter kernel: [88757.349748] BUG: unable to handle kernel paging request at ffffffffa05b9020
>> Oct 15 00:40:51 homerouter kernel: [88757.349831] IP: [<ffffffffa018ef60>] scsi_device_put+0x11/0x3c [scsi_mod]
>
> Yeah, this part doesn't surprise me. Forced unloading of a module
> doesn't generally work very well --- it's a hack to cope with some bad
> situations, but generally the best policy is to reboot ASAP
> afterwards.
>
> Hope that helps,
> Jonathan
Reply to: