Bug#690504: linux-image-2.6-amd64: broken usb device breaks direct i/o even to non-usb drives
Package: linux-image-2.6-amd64
Version: 3.2+45
Severity: important
Dear Maintainer,
*** Please consider answering these questions, where appropriate ***
* What led up to the situation?
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
kernel dmesg at connect:
Oct 15 00:27:38 homerouter kernel: [87964.904034] usb 8-4: new high-speed USB device number 3 using ehci_hcd
Oct 15 00:27:38 homerouter kernel: [87965.203846] usb 8-4: New USB device found, idVendor=0011, idProduct=7788
Oct 15 00:27:38 homerouter kernel: [87965.203894] usb 8-4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Oct 15 00:27:38 homerouter kernel: [87965.203941] usb 8-4: Product: Mass Storage
Oct 15 00:27:38 homerouter kernel: [87965.203981] usb 8-4: Manufacturer: Generic
Oct 15 00:27:38 homerouter kernel: [87965.204031] usb 8-4: SerialNumber: BEF961F3
Oct 15 00:27:39 homerouter kernel: [87965.330025] usbcore: registered new interface driver uas
Oct 15 00:27:39 homerouter kernel: [87965.343501] Initializing USB Mass Storage driver...
Oct 15 00:27:39 homerouter kernel: [87965.343628] scsi4 : usb-storage 8-4:1.0
Oct 15 00:27:39 homerouter kernel: [87965.343733] usbcore: registered new interface driver usb-storage
Oct 15 00:27:39 homerouter kernel: [87965.343777] USB Mass Storage support registered.
Oct 15 00:27:40 homerouter kernel: [87966.342129] scsi 4:0:0:0: Direct-Access Generic Flash Disk 8.00 PQ: 0 ANSI: 2
Oct 15 00:27:40 homerouter kernel: [87966.342817] sd 4:0:0:0: Attached scsi generic sg3 type 0
Oct 15 00:27:40 homerouter kernel: [87966.344361] sd 4:0:0:0: [sdc] 270336000 512-byte logical blocks: (138 GB/128 GiB)
Oct 15 00:27:40 homerouter kernel: [87966.345477] sd 4:0:0:0: [sdc] Write Protect is off
Oct 15 00:27:40 homerouter kernel: [87966.345527] sd 4:0:0:0: [sdc] Mode Sense: 03 00 00 00
Oct 15 00:27:40 homerouter kernel: [87966.345980] sd 4:0:0:0: [sdc] No Caching mode page present
Oct 15 00:27:40 homerouter kernel: [87966.346028] sd 4:0:0:0: [sdc] Assuming drive cache: write through
Oct 15 00:27:40 homerouter kernel: [87966.348736] sd 4:0:0:0: [sdc] No Caching mode page present
Oct 15 00:27:40 homerouter kernel: [87966.348782] sd 4:0:0:0: [sdc] Assuming drive cache: write through
Oct 15 00:27:40 homerouter kernel: [87966.673992] sdc: unknown partition table
Oct 15 00:27:40 homerouter kernel: [87966.676613] sd 4:0:0:0: [sdc] No Caching mode page present
Oct 15 00:27:40 homerouter kernel: [87966.676659] sd 4:0:0:0: [sdc] Assuming drive cache: write through
Oct 15 00:27:40 homerouter kernel: [87966.676703] sd 4:0:0:0: [sdc] Attached SCSI removable disk
* What exactly did you do (or not do) that was effective (or
ineffective)?
modprobe -r usb-storage, which proved ineffective
then
rmmod -f usb-storage
which 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]
Oct 15 00:40:51 homerouter kernel: [88757.349902] PGD 1607067 PUD 160b063 PMD 115785067 PTE 0
Oct 15 00:40:51 homerouter kernel: [88757.350012] Oops: 0000 [#1] SMP
Oct 15 00:40:51 homerouter kernel: [88757.350083] CPU 1
Oct 15 00:40:51 homerouter kernel: [88757.350105] Modules linked in: uas nfnetlink_log nfnetlink pppoe pppox ppp_generic slhc bluetooth drbd lru_cache cn tun ip6table_filter ip6_tables ebtable_nat ebtables iscsi_trgt(O) crc32c ipt_LOG ipt_REJECT xt_recent xt_multiport xt_conntrack iptable_filter xt_TCPMSS xt_tcpmss iptable_mangle ipt_MASQUERADE xt_tcpudp iptable_nat nf_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_conntrack ip_tables x_tables ib_iser rdma_cm ib_addr iw_cm ib_cm ib_sa ib_mad ib_core iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi fuse bridge stp smsc47b397 loop kvm_intel kvm tpm_infineon snd_hda_codec_analog snd_hda_intel snd_hda_codec snd_hwdep snd_pcm_oss snd_mixer_oss snd_pcm acpi_cpufreq snd_page_alloc snd_timer i915 drm_kms_helper drm hp_wmi asix mcs7830 snd i2c_algo_bit sparse_keymap usbnet soundcore rfkill tpm_tis tpm tpm_bios iTCO_wdt mperf i2c_core psmouse iTCO_vendor_support pcspkr processor wmi video coretemp evdev thermal_sys serio_raw button ext4 c
rc16 jbd2 mbcache raid1 md_mod dm_mirror
Oct 15 00:40:51 homerouter kernel: dm_region_hash dm_log dm_mod sg sr_mod cdrom sd_mod crc_t10dif ata_generic uhci_hcd floppy e100 mii ata_piix ehci_hcd libata scsi_mod e1000e usbcore usb_common [last unloaded: usb_storage]
Oct 15 00:40:51 homerouter kernel: [88757.352003]
Oct 15 00:40:51 homerouter kernel: [88757.352003] Pid: 22299, comm: dd Tainted: G R O 3.2.0-3-amd64 #1 Hewlett-Packard HP Compaq dc5800 Microtower/2820h
Oct 15 00:40:51 homerouter kernel: [88757.352003] RIP: 0010:[<ffffffffa018ef60>] [<ffffffffa018ef60>] scsi_device_put+0x11/0x3c [scsi_mod]
Oct 15 00:40:51 homerouter kernel: [88757.352003] RSP: 0018:ffff8801044dbe48 EFLAGS: 00010286
Oct 15 00:40:51 homerouter kernel: [88757.352003] RAX: ffffffffa05b9020 RBX: ffff880115e1a400 RCX: 00000000ffffffff
Oct 15 00:40:51 homerouter kernel: [88757.352003] RDX: 0000000000000000 RSI: ffff880115fd58a0 RDI: ffff880112b71800
Oct 15 00:40:51 homerouter kernel: [88757.352003] RBP: ffff880112b71800 R08: dead000000100100 R09: 0000000000000000
Oct 15 00:40:51 homerouter kernel: [88757.352003] R10: 0000000000000000 R11: 0000000000000000 R12: 000000000000001e
Oct 15 00:40:51 homerouter kernel: [88757.352003] R13: ffff880105c29af8 R14: ffff880114ecf000 R15: ffff880111e0f6d8
Oct 15 00:40:51 homerouter kernel: [88757.352003] FS: 00007fba1fde8700(0000) GS:ffff88011bc80000(0000) knlGS:0000000000000000
Oct 15 00:40:51 homerouter kernel: [88757.352003] CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Oct 15 00:40:51 homerouter kernel: [88757.352003] CR2: ffffffffa05b9020 CR3: 00000001034d4000 CR4: 00000000000006e0
Oct 15 00:40:51 homerouter kernel: [88757.352003] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Oct 15 00:40:51 homerouter kernel: [88757.352003] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Oct 15 00:40:51 homerouter kernel: [88757.352003] Process dd (pid: 22299, threadinfo ffff8801044da000, task ffff880113f4ce20)
Oct 15 00:40:51 homerouter kernel: [88757.352003] Stack:
Oct 15 00:40:51 homerouter kernel: [88757.352003] dead000000100100 ffff880115e1a400 ffff880112b71800 ffffffffa002fb6c
Oct 15 00:40:51 homerouter kernel: [88757.352003] 0000000000000000 ffff880115e1a400 ffff880112b71800 ffffffffa0030473
Oct 15 00:40:51 homerouter kernel: [88757.352003] 0000000000000000 ffff880111e0f6c0 0000000000000000 ffffffff81121312
Oct 15 00:40:51 homerouter kernel: [88757.352003] Call Trace:
Oct 15 00:40:51 homerouter kernel: [88757.352003] [<ffffffffa002fb6c>] ? scsi_disk_put+0x28/0x38 [sd_mod]
Oct 15 00:40:51 homerouter kernel: [88757.352003] [<ffffffffa0030473>] ? sd_release+0xa0/0xa6 [sd_mod]
Oct 15 00:40:51 homerouter kernel: [88757.352003] [<ffffffff81121312>] ? __blkdev_put+0xc1/0x168
Oct 15 00:40:51 homerouter kernel: [88757.352003] [<ffffffff8119ec5e>] ? disk_flush_events+0x48/0x5a
Oct 15 00:40:51 homerouter kernel: [88757.352003] [<ffffffff810fa30d>] ? fput+0xf9/0x1a1
Oct 15 00:40:51 homerouter kernel: [88757.352003] [<ffffffff810f8036>] ? filp_close+0x62/0x6a
Oct 15 00:40:51 homerouter kernel: [88757.352003] [<ffffffff810f80cc>] ? sys_close+0x8e/0xcb
Oct 15 00:40:51 homerouter kernel: [88757.352003] [<ffffffff8134fc92>] ? system_call_fastpath+0x16/0x1b
Oct 15 00:40:51 homerouter kernel: [88757.352003] Code: 4d 8b 6d 10 49 83 ed 10 49 8d 45 10 49 39 c6 75 c8 5b 5d 41 5c 41 5d 41 5e c3 55 48 89 fd 53 41 50 48 8b 07 48 8b 80 b8 00 00 00 <48> 8b 18 48 85 db 74 14 48 89 df e8 d7 2f ee e0 85 c0 74 08 48
Oct 15 00:40:51 homerouter kernel: [88757.352003] RIP [<ffffffffa018ef60>] scsi_device_put+0x11/0x3c [scsi_mod]
Oct 15 00:40:51 homerouter kernel: [88757.352003] RSP <ffff8801044dbe48>
Oct 15 00:40:51 homerouter kernel: [88757.352003] CR2: ffffffffa05b9020
Oct 15 00:40:51 homerouter kernel: [88757.352003] ---[ end trace 31a604df3c5f331d ]---
then
unplug the flashdrive
* What was the outcome of this action?
udev entered in unusable state:
* spawned processes that remained in D state
26785 ? D 0:00 /lib/udev/ata_id --export /dev/sdb
26786 ? D 0:00 /lib/udev/ata_id --export /dev/sda
26874 ? D 0:00 /sbin/mdadm --detail --export /dev/md0
* spammed the system logs with lines like this:
Oct 14 11:56:07 homerouter udevd[27438]: timeout: killing '/sbin/mdadm \
--detail --export /dev/md0' [27631]
processes requesting direct i/o access to local hard drives attached to
onboard pci sata ahci controller failed to complete
(hdparm, smartd, lshw, hwinfo)
for example,
"root@homerouter:~# strace -f fdisk -l /dev/sda
execve("/sbin/fdisk", ["fdisk", "-l", "/dev/sda"], [/* 24 vars */]) = 0
brk(0) = 0x16f0000
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fa6c3d71000
access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=69342, ...}) = 0
mmap(NULL, 69342, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fa6c3d60000
close(3) = 0
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
open("/lib/x86_64-linux-gnu/libblkid.so.1", O_RDONLY) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0Pn\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=159856, ...}) = 0
mmap(NULL, 2255016, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fa6c392d000
mprotect(0x7fa6c3950000, 2097152, PROT_NONE) = 0
mmap(0x7fa6c3b50000, 16384, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x23000) = 0x7fa6c3b50000
close(3) = 0
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
open("/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\300\357\1\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=1583120, ...}) = 0
mmap(NULL, 3696728, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fa6c35a6000
mprotect(0x7fa6c3723000, 2097152, PROT_NONE) = 0
mmap(0x7fa6c3923000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x17d000) = 0x7fa6c3923000
mmap(0x7fa6c3928000, 18520, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fa6c3928000
close(3) = 0
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
open("/lib/x86_64-linux-gnu/libuuid.so.1", O_RDONLY) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\0\31\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=18896, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fa6c3d5f000
mmap(NULL, 2113968, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fa6c33a1000
mprotect(0x7fa6c33a5000, 2093056, PROT_NONE) = 0
mmap(0x7fa6c35a4000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x3000) = 0x7fa6c35a4000
close(3) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fa6c3d5d000
arch_prctl(ARCH_SET_FS, 0x7fa6c3d5d740) = 0
mprotect(0x7fa6c35a4000, 4096, PROT_READ) = 0
mprotect(0x7fa6c3923000, 16384, PROT_READ) = 0
mprotect(0x7fa6c3b50000, 12288, PROT_READ) = 0
mprotect(0x616000, 4096, PROT_READ) = 0
mprotect(0x7fa6c3d73000, 4096, PROT_READ) = 0
munmap(0x7fa6c3d60000, 69342) = 0
brk(0) = 0x16f0000
brk(0x1711000) = 0x1711000
open("/usr/lib/locale/locale-archive", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=1534672, ...}) = 0
mmap(NULL, 1534672, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fa6c3be6000
close(3) = 0
open("/dev/sda", O_RDONLY" <- and nothing else beyond this point.
* What outcome did you expect instead?
safely handle this situation
*** End of the template - remove these lines ***
-- System Information:
Debian Release: wheezy/sid
APT prefers testing
APT policy: (500, 'testing')
Architecture: amd64 (x86_64)
Kernel: Linux 3.2.0-3-amd64 (SMP w/2 CPU cores)
Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash
Versions of packages linux-image-2.6-amd64 depends on:
ii linux-image-amd64 3.2+45
linux-image-2.6-amd64 recommends no packages.
linux-image-2.6-amd64 suggests no packages.
-- debconf-show failed
Reply to: