ATA pass-through commands preventing external HDD to be mounted
Affects | Status | Importance | Assigned to | Milestone | |
---|---|---|---|---|---|
Linux |
Expired
|
Medium
|
|||
OEM Priority Project |
Fix Released
|
High
|
Unassigned | ||
hdparm (Ubuntu) |
Fix Released
|
High
|
Canonical Foundations Team | ||
Lucid |
Fix Released
|
High
|
Canonical Foundations Team |
Bug Description
Binary package hint: udev
I've got seven external hard drives in use and two of them fail to mount in lucid.
I get these errors in my syslog/kern.log:
Jan 27 17:27:47 klaus-imac kernel: [ 116.220416] usb-storage: device scan complete
Jan 27 17:27:47 klaus-imac kernel: [ 116.222506] scsi 6:0:0:0: Direct-Access TOSHIBA MK5055GSX 0002 PQ: 0 ANSI: 0
Jan 27 17:27:47 klaus-imac kernel: [ 116.222823] sd 6:0:0:0: Attached scsi generic sg3 type 0
Jan 27 17:27:47 klaus-imac kernel: [ 116.225149] sd 6:0:0:0: [sdb] 976773168 512-byte logical blocks: (500 GB/465 GiB)
Jan 27 17:27:47 klaus-imac kernel: [ 116.225998] sd 6:0:0:0: [sdb] Write Protect is off
Jan 27 17:27:47 klaus-imac kernel: [ 116.226000] sd 6:0:0:0: [sdb] Mode Sense: 03 00 00 00
Jan 27 17:27:47 klaus-imac kernel: [ 116.226002] sd 6:0:0:0: [sdb] Assuming drive cache: write through
Jan 27 17:27:47 klaus-imac kernel: [ 116.227509] sd 6:0:0:0: [sdb] Assuming drive cache: write through
Jan 27 17:27:47 klaus-imac kernel: [ 116.227511] sdb: sdb1
Jan 27 17:27:47 klaus-imac kernel: [ 116.263544] sd 6:0:0:0: [sdb] Assuming drive cache: write through
Jan 27 17:27:47 klaus-imac kernel: [ 116.263549] sd 6:0:0:0: [sdb] Attached SCSI disk
Jan 27 17:27:55 klaus-imac kernel: [ 124.120514] usb 2-1.4: reset high speed USB device using ehci_hcd and address 6
Jan 27 17:28:03 klaus-imac kernel: [ 132.120379] usb 2-1.4: reset high speed USB device using ehci_hcd and address 6
Jan 27 17:30:07 klaus-imac kernel: [ 256.130303] usb 2-1.4: reset high speed USB device using ehci_hcd and address 6
Jan 27 17:30:11 klaus-imac kernel: [ 260.419828] applesmc: wait status failed: 5 != 0
Jan 27 17:30:38 klaus-imac kernel: [ 287.121304] usb 2-1.4: reset high speed USB device using ehci_hcd and address 6
Jan 27 17:31:03 klaus-imac kernel: [ 312.501640] kjournald starting. Commit interval 5 seconds
Jan 27 17:31:03 klaus-imac kernel: [ 312.501644] EXT3-fs warning: checktime reached, running e2fsck is recommended
Jan 27 17:31:03 klaus-imac kernel: [ 312.510681] EXT3 FS on dm-0, internal journal
Jan 27 17:31:03 klaus-imac kernel: [ 312.510685] EXT3-fs: mounted filesystem with writeback data mode.
Jan 27 17:31:09 klaus-imac kernel: [ 318.090472] usb 2-1.4: reset high speed USB device using ehci_hcd and address 6
Jan 27 17:31:09 klaus-imac kernel: [ 318.202065] sd 6:0:0:0: [sdb] Unhandled error code
Jan 27 17:31:09 klaus-imac kernel: [ 318.202074] sd 6:0:0:0: [sdb] Result: hostbyte=DID_ABORT driverbyte=
Jan 27 17:31:09 klaus-imac kernel: [ 318.202083] sd 6:0:0:0: [sdb] CDB: Read(10): 28 00 00 00 00 00 00 00 20 00
Jan 27 17:31:09 klaus-imac kernel: [ 318.202104] end_request: I/O error, dev sdb, sector 0
Jan 27 17:31:09 klaus-imac kernel: [ 318.202115] Buffer I/O error on device sdb, logical block 0
Jan 27 17:31:09 klaus-imac kernel: [ 318.202126] Buffer I/O error on device sdb, logical block 1
Jan 27 17:31:09 klaus-imac kernel: [ 318.202133] Buffer I/O error on device sdb, logical block 2
Jan 27 17:31:09 klaus-imac kernel: [ 318.202140] Buffer I/O error on device sdb, logical block 3
Jan 27 17:31:40 klaus-imac kernel: [ 349.092930] usb 2-1.4: reset high speed USB device using ehci_hcd and address 6
Jan 27 17:32:11 klaus-imac kernel: [ 380.090465] usb 2-1.4: reset high speed USB device using ehci_hcd and address 6
Jan 27 17:32:42 klaus-imac kernel: [ 411.096963] usb 2-1.4: reset high speed USB device using ehci_hcd and address 6
Jan 27 17:33:13 klaus-imac kernel: [ 442.090455] usb 2-1.4: reset high speed USB device using ehci_hcd and address 6
Jan 27 17:33:44 klaus-imac kernel: [ 473.130475] usb 2-1.4: reset high speed USB device using ehci_hcd and address 6
Jan 27 17:34:15 klaus-imac kernel: [ 504.122969] usb 2-1.4: reset high speed USB device using ehci_hcd and address 6
Jan 27 17:34:15 klaus-imac kernel: [ 504.234568] sd 6:0:0:0: [sdb] Unhandled error code
Jan 27 17:34:15 klaus-imac kernel: [ 504.234577] sd 6:0:0:0: [sdb] Result: hostbyte=DID_ABORT driverbyte=
Jan 27 17:34:15 klaus-imac kernel: [ 504.234586] sd 6:0:0:0: [sdb] CDB: Read(10): 28 00 00 00 00 3f 00 00 f0 00
Jan 27 17:34:15 klaus-imac kernel: [ 504.234608] end_request: I/O error, dev sdb, sector 63
Jan 27 17:34:15 klaus-imac kernel: [ 504.234620] Buffer I/O error on device sdb1, logical block 0
Jan 27 17:34:15 klaus-imac kernel: [ 504.234630] Buffer I/O error on device sdb1, logical block 1
Jan 27 17:34:15 klaus-imac kernel: [ 504.234638] Buffer I/O error on device sdb1, logical block 2
Jan 27 17:34:15 klaus-imac kernel: [ 504.234644] Buffer I/O error on device sdb1, logical block 3
Jan 27 17:34:15 klaus-imac kernel: [ 504.234658] Buffer I/O error on device sdb1, logical block 4
Jan 27 17:34:15 klaus-imac kernel: [ 504.234664] Buffer I/O error on device sdb1, logical block 5
Jan 27 17:34:15 klaus-imac kernel: [ 504.234671] Buffer I/O error on device sdb1, logical block 6
Jan 27 17:34:15 klaus-imac kernel: [ 504.234677] Buffer I/O error on device sdb1, logical block 7
Jan 27 17:34:15 klaus-imac kernel: [ 504.234684] Buffer I/O error on device sdb1, logical block 8
Jan 27 17:34:15 klaus-imac kernel: [ 504.234690] Buffer I/O error on device sdb1, logical block 9
Jan 27 17:34:46 klaus-imac kernel: [ 535.090446] usb 2-1.4: reset high speed USB device using ehci_hcd and address 6
Jan 27 17:35:17 klaus-imac kernel: [ 566.120432] usb 2-1.4: reset high speed USB device using ehci_hcd and address 6
Jan 27 17:35:48 klaus-imac kernel: [ 597.122905] usb 2-1.4: reset high speed USB device using ehci_hcd and address 6
Jan 27 17:36:19 klaus-imac kernel: [ 628.120448] usb 2-1.4: reset high speed USB device using ehci_hcd and address 6
Jan 27 17:36:50 klaus-imac kernel: [ 659.090435] usb 2-1.4: reset high speed USB device using ehci_hcd and address 6
Jan 27 17:37:21 klaus-imac kernel: [ 690.100430] usb 2-1.4: reset high speed USB device using ehci_hcd and address 6
Jan 27 17:37:21 klaus-imac kernel: [ 690.204190] sd 6:0:0:0: [sdb] Unhandled error code
Jan 27 17:37:21 klaus-imac kernel: [ 690.204200] sd 6:0:0:0: [sdb] Result: hostbyte=DID_ABORT driverbyte=
Jan 27 17:37:21 klaus-imac kernel: [ 690.204204] sd 6:0:0:0: [sdb] CDB: Read(10): 28 00 00 00 01 2f 00 00 10 00
Jan 27 17:37:21 klaus-imac kernel: [ 690.204213] end_request: I/O error, dev sdb, sector 303
Jan 27 17:37:21 klaus-imac kernel: [ 690.204218] __ratelimit: 110 callbacks suppressed
Jan 27 17:37:21 klaus-imac kernel: [ 690.204221] Buffer I/O error on device sdb1, logical block 120
Jan 27 17:37:21 klaus-imac kernel: [ 690.204225] Buffer I/O error on device sdb1, logical block 121
Jan 27 17:37:21 klaus-imac kernel: [ 690.204228] Buffer I/O error on device sdb1, logical block 122
Jan 27 17:37:21 klaus-imac kernel: [ 690.204230] Buffer I/O error on device sdb1, logical block 123
Jan 27 17:37:21 klaus-imac kernel: [ 690.204234] Buffer I/O error on device sdb1, logical block 124
Jan 27 17:37:21 klaus-imac kernel: [ 690.204236] Buffer I/O error on device sdb1, logical block 125
Jan 27 17:37:21 klaus-imac kernel: [ 690.204239] Buffer I/O error on device sdb1, logical block 126
Jan 27 17:37:21 klaus-imac kernel: [ 690.204242] Buffer I/O error on device sdb1, logical block 127
Jan 27 17:37:52 klaus-imac kernel: [ 721.122941] usb 2-1.4: reset high speed USB device using ehci_hcd and address 6
Jan 27 17:38:23 klaus-imac kernel: [ 752.092932] usb 2-1.4: reset high speed USB device using ehci_hcd and address 6
Jan 27 17:38:54 klaus-imac kernel: [ 783.092942] usb 2-1.4: reset high speed USB device using ehci_hcd and address 6
Jan 27 17:39:25 klaus-imac kernel: [ 814.093405] usb 2-1.4: reset high speed USB device using ehci_hcd and address 6
Jan 27 17:39:28 klaus-imac kernel: [ 817.584599] sd 6:0:0:0: timing out command, waited 180s
Jan 27 17:39:28 klaus-imac kernel: [ 817.584621] sd 6:0:0:0: [sdb] Unhandled error code
Jan 27 17:39:28 klaus-imac kernel: [ 817.584626] sd 6:0:0:0: [sdb] Result: hostbyte=DID_ERROR driverbyte=
Jan 27 17:39:28 klaus-imac kernel: [ 817.584636] sd 6:0:0:0: [sdb] CDB: Read(10): 28 00 00 00 00 3f 00 00 08 00
Jan 27 17:39:28 klaus-imac kernel: [ 817.584657] end_request: I/O error, dev sdb, sector 63
Jan 27 17:39:28 klaus-imac kernel: [ 817.584667] Buffer I/O error on device sdb1, logical block 0
Jan 27 17:39:28 klaus-imac kernel: [ 817.584678] Buffer I/O error on device sdb1, logical block 1
Jan 27 17:39:28 klaus-imac kernel: [ 817.584685] Buffer I/O error on device sdb1, logical block 2
Jan 27 17:39:28 klaus-imac kernel: [ 817.584691] Buffer I/O error on device sdb1, logical block 3
The problem affects two different chipsets and is reproducable on lucid on three different machines with the same external hard drives which work fine on karmic for instance.
I took the problem to the linux-usb list and submitted a usbmon trace. Alan Stern looked at it and he found these entries suspicious:
> ffff88001b083e40 2655717029 S Bo:2:015:2 -115 31 = 55534243 21000000 00000000 00001085 06200005 00fe0000 00000000 40ef00
> ffff88001b083e40 2655717090 C Bo:2:015:2 0 31 >
> ffff88001b083e40 2655717123 S Bi:2:015:1 -115 13 <
> ffff88001b083e40 2655731738 C Bi:2:015:1 0 13 = 55534253 21000000 00000000 00
> ffff88001b083e40 2655732007 S Bo:2:015:2 -115 31 = 55534243 22000000 00020000 80001085 082e0000 00000000 00000000 40ec00
> ffff88001b083e40 2655732099 C Bo:2:015:2 0 31 >
> ffff8800afe263c0 2655732126 S Bi:2:015:1 -115 512 <
> ffff8800afe263c0 2655748859 C Bi:2:015:1 -121 13 = 55534253 22000000 00020000 00
> ffff88001b083e40 2655748906 S Bi:2:015:1 -115 13 <
> ffff88001b083e40 2663266469 C Bi:2:015:1 -104 0
From Alan's comment on it:
"The shows a sequence of two ATA pass-through commands being sent to the
device. I don't know what those commands are or what program was
responsible for sending them; as far as I'm aware nothing in the kernel
will do it. Perhaps some program started by udev is responsible.
Looking through your udev rules might pinpoint the culprit.
Anyway, the first command doesn't seem to cause any difficulty, but the
second command fails completely. Instead of sending data in its
response, the device sends a status message. The kernel gets this,
thinks it is data, and then waits for the status to come -- which of
course never happens. So the kernel resets the device and tries
issuing the same command again, with the same result."
The complete history can be found here: http://
ProblemType: Bug
Architecture: amd64
CustomUdevRuleF
Date: Sun Jan 31 08:45:03 2010
DistroRelease: Ubuntu 10.04
InstallationMedia: Ubuntu 10.04 "Lucid Lynx" - Alpha amd64 (20100113)
MachineType: Apple Inc. iMac8,1
NonfreeKernelMo
Package: udev 149-5
ProcCmdLine: BOOT_IMAGE=
ProcEnviron:
LANG=de_AT.utf8
SHELL=/bin/bash
ProcVersionSign
SourcePackage: udev
Uname: Linux 2.6.32-12-generic x86_64
dmi.bios.date: 02/09/08
dmi.bios.vendor: Apple Inc.
dmi.bios.version: IM81.88Z.
dmi.board.
dmi.board.name: Mac-F227BEC8
dmi.board.vendor: Apple Inc.
dmi.board.version: PVT
dmi.chassis.
dmi.chassis.type: 13
dmi.chassis.vendor: Apple Inc.
dmi.chassis.
dmi.modalias: dmi:bvnAppleInc
dmi.product.name: iMac8,1
dmi.product.
dmi.sys.vendor: Apple Inc.
tags: | added: regression-potential |
Changed in udev (Ubuntu): | |
assignee: | nobody → Canonical Foundations Team (canonical-foundations) |
affects: | udev (Ubuntu) → linux (Ubuntu) |
tags: | added: lucid-upgrade-testing |
Changed in oem-priority: | |
importance: | Undecided → Critical |
Changed in oem-priority: | |
importance: | Critical → High |
Changed in oem-priority: | |
status: | New → Fix Released |
Changed in linux: | |
status: | Unknown → Incomplete |
Changed in linux: | |
importance: | Unknown → Medium |
Changed in linux: | |
status: | Incomplete → Expired |
I dont' know, but it's similar problem https:/ /bugs.launchpad .net/ubuntu/ intrepid/ +source/ linux/+ bug/264789?