Bug#690505: linux-image-3.2.0-3-amd64: broken usb device breaks direct i/o even to non-usb drives
Package: src:linux Version: 3.2.23-1 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 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] 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 ]--- 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, "177ELF211 3 > |