Re: [Bugme-new] [Bug 14020] New: Stack trace when running smartctl on an USB disk

Re: [Bugme-new] [Bug 14020] New: Stack trace when running smartctl on an USB disk

[Andrew Morton]

(switched to email.  Please respond via emailed reply-to-all, not via the
bugzilla web interface).

On Thu, 20 Aug 2009 02:13:27 GMT
bugzilla-daemon@bugzilla.kernel.org wrote:

> http://bugzilla.kernel.org/show_bug.cgi?id=14020
> 
>            Summary: Stack trace when running smartctl on an USB disk
>            Product: Drivers
>            Version: 2.5
>     Kernel Version: 2.6.31-rc6
>           Platform: All
>         OS/Version: Linux
>               Tree: Mainline
>             Status: NEW
>           Severity: normal
>           Priority: P1
>          Component: USB
>         AssignedTo: greg@kroah.com
>         ReportedBy: rbrito@ime.usp.br
>         Regression: No
> 
> 
> Hi.
> 
> Trying to see the status of a drive of mine that is in an USB enclosure, I
> issued the command:
> 
>   # smartctl -d usbcypress -a /dev/sda
> 
> What I got in return was:
> 
> "task smartctl:1513 blocked for more than 120 seconds" with a subsequent stack
> trace, listed below.

Yup, that's a bug.  I assume that smartctl never recovered?

I don't know if it's a scsi bug or a usb bug.  Probably the latter?

> 
> [66493.029171] usb-storage: device scan complete
> [66493.029657] scsi 4:0:0:0: Direct-Access     ST375064 0A                   
> PQ: 0 ANSI: 0
> [66493.032385] sd 4:0:0:0: [sda] 1465149168 512-byte logical blocks: (750
> GB/698 GiB)
> [66493.033515] sd 4:0:0:0: [sda] Write Protect is off
> [66493.033522] sd 4:0:0:0: [sda] Mode Sense: 33 00 00 00
> [66493.033526] sd 4:0:0:0: [sda] Assuming drive cache: write through
> [66493.035501] sd 4:0:0:0: [sda] Assuming drive cache: write through
> [66493.035508]  sda: sda1
> [66493.056139] sd 4:0:0:0: [sda] Assuming drive cache: write through
> [66493.056149] sd 4:0:0:0: [sda] Attached SCSI disk
> [66493.407349] EXT4-fs (sda1): barriers enabled
> [66493.436357] kjournald2 starting: pid 1407, dev sda1:8, commit interval 5
> seconds
> [66493.437049] EXT4-fs (sda1): internal journal on sda1:8
> [66493.437058] EXT4-fs (sda1): delayed allocation enabled
> [66493.437063] EXT4-fs: file extents enabled
> [66493.483105] EXT4-fs: mballoc enabled
> [66493.483135] EXT4-fs (sda1): mounted filesystem with ordered data mode
> [66696.806018] usb 1-1: reset high speed USB device using ehci_hcd and address
> 4
> [66714.806020] usb 1-1: reset high speed USB device using ehci_hcd and address
> 4
> [66714.920809] program smartctl is using a deprecated SCSI ioctl, please
> convert it to SG_IO
> [66775.806017] usb 1-1: reset high speed USB device using ehci_hcd and address
> 4
> [66836.806019] usb 1-1: reset high speed USB device using ehci_hcd and address
> 4
> [66840.171050] INFO: task smartctl:1513 blocked for more than 120 seconds.
> [66840.171055] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this
> message.
> [66840.171060] smartctl      D ffff8800014a79c0     0  1513   1298 0x00000004
> [66840.171068]  ffff88006fa52120 0000000000000082 0000000000000001
> 0000000000000001
> [66840.171075]  00000000000109c0 000000000000c858 ffff88006fa54f80
> ffff88006fa552f8
> [66840.171083]  000000007c863500 ffff88005e15fd68 ffff88006fa552f8
> ffff88005e15fd70
> [66840.171090] Call Trace:
> [66840.171102]  [<ffffffff812571d6>] ? schedule_timeout+0x1e/0xb8
> [66840.171136]  [<ffffffffa006f2ca>] ? scsi_request_fn+0x355/0x423 [scsi_mod]
> [66840.171155]  [<ffffffff8103ecb7>] ? del_timer+0x59/0x62
> [66840.171165]  [<ffffffff812566c6>] ? wait_for_common+0xaa/0x10b
> [66840.171176]  [<ffffffff81030067>] ? default_wake_function+0x0/0x9
> [66840.171186]  [<ffffffff81107348>] ? __generic_unplug_device+0x12/0x2c
> [66840.171197]  [<ffffffff8110a6a4>] ? blk_execute_rq+0x93/0xab
> [66840.171205]  [<ffffffff8110a869>] ? blk_recount_segments+0x17/0x27
> [66840.171214]  [<ffffffff81105576>] ? blk_rq_bio_prep+0x39/0x69
> [66840.171224]  [<ffffffff8110d96e>] ? sg_scsi_ioctl+0x229/0x2ad
> [66840.171233]  [<ffffffff8110dd44>] ? scsi_cmd_ioctl+0x352/0x39e
> [66840.171242]  [<ffffffff8106991e>] ? filemap_fault+0x5e/0x36d
> [66840.171252]  [<ffffffff8107a2a8>] ? __do_fault+0x34b/0x386
> [66840.171261]  [<ffffffff81113c30>] ? kobject_get+0x12/0x17
> [66840.171275]  [<ffffffffa02337e0>] ? sd_ioctl+0x78/0xa6 [sd_mod]
> [66840.171284]  [<ffffffff8110b5b9>] ? __blkdev_driver_ioctl+0x69/0x7e
> [66840.171292]  [<ffffffff8110bdc4>] ? blkdev_ioctl+0x7d2/0x806
> [66840.171301]  [<ffffffff8106991e>] ? filemap_fault+0x5e/0x36d
> [66840.171309]  [<ffffffff8107a2a8>] ? __do_fault+0x34b/0x386
> [66840.171320]  [<ffffffff810b6c99>] ? block_ioctl+0x38/0x3c
> [66840.171329]  [<ffffffff810a020e>] ? vfs_ioctl+0x21/0x6c
> [66840.171338]  [<ffffffff810a0712>] ? do_vfs_ioctl+0x443/0x47b
> [66840.171347]  [<ffffffff81021e4c>] ? do_page_fault+0x1fe/0x212
> [66840.171356]  [<ffffffff810a0787>] ? sys_ioctl+0x3d/0x5c
> [66840.171366]  [<ffffffff8100b02b>] ? system_call_fastpath+0x16/0x1b
> [66855.596877] usb 1-1: USB disconnect, address 4
> 
> I am not sure if I can reproduce it, but I can try. If anything is needed,
> please, just let me know and I'll do my best to provide the necessary
> information.
> 

Re: [Bugme-new] [Bug 14020] New: Stack trace when running smartctl on an USB disk

[Rogério Brito]

Hi, Andrew & Co.

On Aug 20 2009, Andrew Morton wrote:
> On Thu, 20 Aug 2009 02:13:27 GMT
> bugzilla-daemon-590EEB7GvNiWaY/ihj7yzEB+6BGkLq7r@public.gmane.org wrote:
> > Trying to see the status of a drive of mine that is in an USB enclosure, I
> > issued the command:
> > 
> >   # smartctl -d usbcypress -a /dev/sda
> > 
> > What I got in return was:
> > 
> > "task smartctl:1513 blocked for more than 120 seconds" with a subsequent stack
> > trace, listed below.
> 
> Yup, that's a bug.

Thanks for the confirmation.

> I assume that smartctl never recovered?

Yes, sorry for not mentioning this explicitly. smartctl hang there and
was uninterruptible. :-(

> I don't know if it's a scsi bug or a usb bug.  Probably the latter?

Again, just reiterating, what I said before, even though I am not sure
if I can reproduce it, I will try to.

And if any further information about my hardware is needed, please, just
let me know.


Thanks, Rogério Brito.

-- 
Rogério Brito : rbrito@{mackenzie,ime.usp}.br : GPG key 1024D/7C2CAEB8
http://www.ime.usp.br/~rbrito : http://meusite.mackenzie.com.br/rbrito
Projects: algorithms.berlios.de : lame.sf.net : vrms.alioth.debian.org
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo-u79uwXL29TY76Z2rM5mHXA@public.gmane.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [Bugme-new] [Bug 14020] New: Stack trace when running smartctl on an USB disk

[Alan Stern]

On Thu, 20 Aug 2009, [utf-8] Rogério Brito wrote:

> Again, just reiterating, what I said before, even though I am not sure
> if I can reproduce it, I will try to.

A usbmon trace showing what happens when you plug in the drive and 
when you run smartctl would help.

Alan Stern

--
To unsubscribe from this list: send the line "unsubscribe linux-scsi" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [Bugme-new] [Bug 14020] New: Stack trace when running smartctl on an USB disk

[Rogério Brito]

Hi, Alan, Andrew and others.

On Aug 21 2009, Alan Stern wrote:
> On Thu, 20 Aug 2009, Rogério Brito wrote:
> 
> > Again, just reiterating, what I said before, even though I am not sure
> > if I can reproduce it, I will try to.
> 
> A usbmon trace showing what happens when you plug in the drive and 
> when you run smartctl would help.

Well, I'll just go grab the sources to usbmon. In the mean time, I just
issued the command with a freshly compiled 2.6.31-rc7 and the problem
persists:

,----
|  5581 pts/1    D+     0:00 ./smartctl -d usbcypress -a /dev/sda
`----

(And the stack traces too).

I will be replying with the usbmon trace ASAP.


Thanks, Rogério Brito.

-- 
Rogério Brito : rbrito@{mackenzie,ime.usp}.br : GPG key 1024D/7C2CAEB8
http://www.ime.usp.br/~rbrito : http://meusite.mackenzie.com.br/rbrito
Projects: algorithms.berlios.de : lame.sf.net : vrms.alioth.debian.org
--
To unsubscribe from this list: send the line "unsubscribe linux-scsi" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [Bugme-new] [Bug 14020] New: Stack trace when running smartctl on an USB disk

[Rogério Brito]

Hi, it's me again.

On Aug 22 2009, Rogério Brito wrote:
> In the mean time, I just issued the command with a freshly compiled
> 2.6.31-rc7 and the problem persists:
(...)

Well, after some minutes (the time that I took to check my computer and
to compose the previous message), I got two stack traces (attached to
this message) and smartctl has just finished:

,----
| chagas:/tmp/sbin# ./smartctl -d usbcypress -a /dev/sda
| smartctl 5.39 2009-08-20 r2876 [x86_64-unknown-linux-gnu] (local build)
| Copyright (C) 2002-9 by Bruce Allen, http://smartmontools.sourceforge.net
| 
| === START OF INFORMATION SECTION ===
| Device Model:     [No Information Found]
| Serial Number:    [No Information Found]
| Firmware Version: [No Information Found]
| Device is:        Not in smartctl database [for details use: -P showall]
| ATA Version is:   1
| ATA Standard is:  Exact ATA specification draft version not indicated
| Local Time is:    Sat Aug 22 16:13:12 2009 BRT
| SMART is only available in ATA Version 3 Revision 3 or greater.
| We will try to proceed in spite of this.
| SMART support is: Ambiguous - ATA IDENTIFY DEVICE words 82-83 don't show if SMART supported.
| A mandatory SMART command failed: exiting. To continue, add one or more '-T permissive' options.
| chagas:/tmp/sbin#
`----

Does this help (at least a bit), before I get usbmon working? I just
wanted to report something that could be an extra data point.


Regards, Rogério Brito.

-- 
Rogério Brito : rbrito@{mackenzie,ime.usp}.br : GPG key 1024D/7C2CAEB8
http://www.ime.usp.br/~rbrito : http://meusite.mackenzie.com.br/rbrito
Projects: algorithms.berlios.de : lame.sf.net : vrms.alioth.debian.org
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo-u79uwXL29TY76Z2rM5mHXA@public.gmane.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [Bugme-new] [Bug 14020] New: Stack trace when running smartctl on an USB disk

[Rogério Brito]

[-- Attachment #1: Type: text/plain, Size: 371 bytes --]

On Aug 22 2009, Rogério Brito wrote:
> Hi, it's me again.
(...)

The eternal problems between humans and attachments... :-(


Regards, Rogério Brito.

-- 
Rogério Brito : rbrito@{mackenzie,ime.usp}.br : GPG key 1024D/7C2CAEB8
http://www.ime.usp.br/~rbrito : http://meusite.mackenzie.com.br/rbrito
Projects: algorithms.berlios.de : lame.sf.net : vrms.alioth.debian.org

[-- Attachment #2: smartctl.txt --]
[-- Type: text/plain, Size: 6828 bytes --]

[ 3557.766018] usb 1-1: new high speed USB device using ehci_hcd and address 2
[ 3557.880845] usb 1-1: New USB device found, idVendor=06e1, idProduct=d185
[ 3557.880852] usb 1-1: New USB device strings: Mfr=56, Product=78, SerialNumber=100
[ 3557.880856] usb 1-1: Product: USB2.0 Storage Device
[ 3557.880859] usb 1-1: Manufacturer: ADS Technologies lnc.
[ 3557.880862] usb 1-1: SerialNumber: A9EA07106E8C
[ 3557.880990] usb 1-1: configuration #1 chosen from 1 choice
[ 3557.912142] Initializing USB Mass Storage driver...
[ 3557.913540] scsi2 : SCSI emulation for USB Mass Storage devices
[ 3557.915028] usb-storage: device found at 2
[ 3557.915033] usb-storage: waiting for device to settle before scanning
[ 3557.915068] usbcore: registered new interface driver usb-storage
[ 3557.915075] USB Mass Storage support registered.
[ 3562.915318] usb-storage: device scan complete
[ 3562.915795] scsi 2:0:0:0: Direct-Access     ST375064 0A                    PQ: 0 ANSI: 0
[ 3562.951132] sd 2:0:0:0: [sda] 1465149168 512-byte logical blocks: (750 GB/698 GiB)
[ 3562.951998] sd 2:0:0:0: [sda] Write Protect is off
[ 3562.952017] sd 2:0:0:0: [sda] Mode Sense: 33 00 00 00
[ 3562.952024] sd 2:0:0:0: [sda] Assuming drive cache: write through
[ 3562.953873] sd 2:0:0:0: [sda] Assuming drive cache: write through
[ 3562.953879]  sda: sda1
[ 3562.978866] sd 2:0:0:0: [sda] Assuming drive cache: write through
[ 3562.978873] sd 2:0:0:0: [sda] Attached SCSI disk
[ 3563.422546] EXT4-fs (sda1): barriers enabled
[ 3563.451546] kjournald2 starting: pid 5527, dev sda1:8, commit interval 5 seconds
[ 3563.452641] EXT4-fs (sda1): internal journal on sda1:8
[ 3563.452649] EXT4-fs (sda1): delayed allocation enabled
[ 3563.452655] EXT4-fs: file extents enabled
[ 3563.500069] EXT4-fs: mballoc enabled
[ 3563.500103] EXT4-fs (sda1): mounted filesystem with ordered data mode
[ 4205.806025] usb 1-1: reset high speed USB device using ehci_hcd and address 2
[ 4205.920895] program smartctl is using a deprecated SCSI ioctl, please convert it to SG_IO
[ 4266.806022] usb 1-1: reset high speed USB device using ehci_hcd and address 2
[ 4327.806033] usb 1-1: reset high speed USB device using ehci_hcd and address 2
[ 4388.807021] usb 1-1: reset high speed USB device using ehci_hcd and address 2
[ 4440.168050] INFO: task smartctl:5581 blocked for more than 120 seconds.
[ 4440.168055] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 4440.168060] smartctl      D ffff8800014ad9c0     0  5581   2677 0x00000000
[ 4440.168068]  ffff8800681bf740 0000000000000086 0000000000000001 0000000000000001
[ 4440.168075]  00000000000109c0 000000000000c858 ffff8800681be360 ffff8800681be6d8
[ 4440.168082]  000000007c8713b0 ffff880068051d68 ffff8800681be6d8 ffff880068051d70
[ 4440.168089] Call Trace:
[ 4440.168103]  [<ffffffff812594de>] ? schedule_timeout+0x1e/0xb8
[ 4440.168138]  [<ffffffffa00482ca>] ? scsi_request_fn+0x355/0x423 [scsi_mod]
[ 4440.168146]  [<ffffffff8103ec9f>] ? del_timer+0x59/0x62
[ 4440.168152]  [<ffffffff812589ce>] ? wait_for_common+0xaa/0x10b
[ 4440.168159]  [<ffffffff81030077>] ? default_wake_function+0x0/0x9
[ 4440.168167]  [<ffffffff81107298>] ? __generic_unplug_device+0x12/0x2c
[ 4440.168173]  [<ffffffff8110a5f4>] ? blk_execute_rq+0x93/0xab
[ 4440.168178]  [<ffffffff8110a7b9>] ? blk_recount_segments+0x17/0x27
[ 4440.168184]  [<ffffffff811054c6>] ? blk_rq_bio_prep+0x39/0x69
[ 4440.168190]  [<ffffffff8110d8be>] ? sg_scsi_ioctl+0x229/0x2ad
[ 4440.168196]  [<ffffffff8110dc94>] ? scsi_cmd_ioctl+0x352/0x39e
[ 4440.168202]  [<ffffffff81069912>] ? filemap_fault+0x5e/0x36d
[ 4440.168208]  [<ffffffff8107a2a8>] ? __do_fault+0x34b/0x386
[ 4440.168214]  [<ffffffff81113b80>] ? kobject_get+0x12/0x17
[ 4440.168225]  [<ffffffffa026c7e0>] ? sd_ioctl+0x78/0xa6 [sd_mod]
[ 4440.168230]  [<ffffffff8110b509>] ? __blkdev_driver_ioctl+0x69/0x7e
[ 4440.168236]  [<ffffffff8110bd14>] ? blkdev_ioctl+0x7d2/0x806
[ 4440.168241]  [<ffffffff81069912>] ? filemap_fault+0x5e/0x36d
[ 4440.168246]  [<ffffffff8107a2a8>] ? __do_fault+0x34b/0x386
[ 4440.168254]  [<ffffffff810b6c71>] ? block_ioctl+0x38/0x3c
[ 4440.168261]  [<ffffffff810a01fa>] ? vfs_ioctl+0x21/0x6c
[ 4440.168266]  [<ffffffff810a06fe>] ? do_vfs_ioctl+0x443/0x47b
[ 4440.168272]  [<ffffffff81021e5c>] ? do_page_fault+0x1fe/0x212
[ 4440.168277]  [<ffffffff810a0773>] ? sys_ioctl+0x3d/0x5c
[ 4440.168284]  [<ffffffff8100b02b>] ? system_call_fastpath+0x16/0x1b
[ 4449.806034] usb 1-1: reset high speed USB device using ehci_hcd and address 2
[ 4510.807023] usb 1-1: reset high speed USB device using ehci_hcd and address 2
[ 4560.168054] INFO: task smartctl:5581 blocked for more than 120 seconds.
[ 4560.168060] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 4560.168064] smartctl      D ffff8800014ad9c0     0  5581   2677 0x00000000
[ 4560.168072]  ffff8800681bf740 0000000000000086 0000000000000001 0000000000000001
[ 4560.168080]  00000000000109c0 000000000000c858 ffff8800681be360 ffff8800681be6d8
[ 4560.168087]  000000007c8713b0 ffff880068051d68 ffff8800681be6d8 ffff880068051d70
[ 4560.168095] Call Trace:
[ 4560.168108]  [<ffffffff812594de>] ? schedule_timeout+0x1e/0xb8
[ 4560.168142]  [<ffffffffa00482ca>] ? scsi_request_fn+0x355/0x423 [scsi_mod]
[ 4560.168150]  [<ffffffff8103ec9f>] ? del_timer+0x59/0x62
[ 4560.168155]  [<ffffffff812589ce>] ? wait_for_common+0xaa/0x10b
[ 4560.168163]  [<ffffffff81030077>] ? default_wake_function+0x0/0x9
[ 4560.168171]  [<ffffffff81107298>] ? __generic_unplug_device+0x12/0x2c
[ 4560.168177]  [<ffffffff8110a5f4>] ? blk_execute_rq+0x93/0xab
[ 4560.168182]  [<ffffffff8110a7b9>] ? blk_recount_segments+0x17/0x27
[ 4560.168188]  [<ffffffff811054c6>] ? blk_rq_bio_prep+0x39/0x69
[ 4560.168194]  [<ffffffff8110d8be>] ? sg_scsi_ioctl+0x229/0x2ad
[ 4560.168200]  [<ffffffff8110dc94>] ? scsi_cmd_ioctl+0x352/0x39e
[ 4560.168206]  [<ffffffff81069912>] ? filemap_fault+0x5e/0x36d
[ 4560.168213]  [<ffffffff8107a2a8>] ? __do_fault+0x34b/0x386
[ 4560.168219]  [<ffffffff81113b80>] ? kobject_get+0x12/0x17
[ 4560.168229]  [<ffffffffa026c7e0>] ? sd_ioctl+0x78/0xa6 [sd_mod]
[ 4560.168235]  [<ffffffff8110b509>] ? __blkdev_driver_ioctl+0x69/0x7e
[ 4560.168240]  [<ffffffff8110bd14>] ? blkdev_ioctl+0x7d2/0x806
[ 4560.168246]  [<ffffffff81069912>] ? filemap_fault+0x5e/0x36d
[ 4560.168251]  [<ffffffff8107a2a8>] ? __do_fault+0x34b/0x386
[ 4560.168259]  [<ffffffff810b6c71>] ? block_ioctl+0x38/0x3c
[ 4560.168266]  [<ffffffff810a01fa>] ? vfs_ioctl+0x21/0x6c
[ 4560.168271]  [<ffffffff810a06fe>] ? do_vfs_ioctl+0x443/0x47b
[ 4560.168277]  [<ffffffff81021e5c>] ? do_page_fault+0x1fe/0x212
[ 4560.168283]  [<ffffffff810a0773>] ? sys_ioctl+0x3d/0x5c
[ 4560.168289]  [<ffffffff8100b02b>] ? system_call_fastpath+0x16/0x1b
[ 4571.806026] usb 1-1: reset high speed USB device using ehci_hcd and address 2

Re: [Bugme-new] [Bug 14020] New: Stack trace when running smartctl on an USB disk

[Alan Stern]

On Sat, 22 Aug 2009, [utf-8] Rogério Brito wrote:

> Well, after some minutes (the time that I took to check my computer and
> to compose the previous message), I got two stack traces (attached to
> this message) and smartctl has just finished:

...

> Does this help (at least a bit), before I get usbmon working? I just
> wanted to report something that could be an extra data point.

It doesn't help.  I need to see the usbmon output.

Alan Stern

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo-u79uwXL29TY76Z2rM5mHXA@public.gmane.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

[PATCH] usb: fix paths in usbmon documentation

[Rogério Brito]

Hi there.

On Aug 21 2009, Alan Stern wrote:
> On Thu, 20 Aug 2009, Rogério Brito wrote:
> > Again, just reiterating, what I said before, even though I am not sure
> > if I can reproduce it, I will try to.
> 
> A usbmon trace showing what happens when you plug in the drive and 
> when you run smartctl would help.

The documentation for usbmon in the kernel 2.6.31-rc7 kernel doesn't
match what the kernel exposes in the debug fs tree. This patch fixes it.

Signed-off-by: Rogério Brito <rbrito@ime.usp.br>

---

diff --git a/Documentation/usb/usbmon.txt b/Documentation/usb/usbmon.txt
index 6c3c625..ea05cf7 100644
--- a/Documentation/usb/usbmon.txt
+++ b/Documentation/usb/usbmon.txt
@@ -33,7 +33,7 @@ if usbmon is built into the kernel.
 
 Verify that bus sockets are present.
 
-# ls /sys/kernel/debug/usbmon
+# ls /sys/kernel/debug/usb/usbmon
 0s  0u  1s  1t  1u  2s  2t  2u  3s  3t  3u  4s  4t  4u
 #
 
@@ -58,11 +58,11 @@ Bus=03 means it's bus 3.
 
 3. Start 'cat'
 
-# cat /sys/kernel/debug/usbmon/3u > /tmp/1.mon.out
+# cat /sys/kernel/debug/usb/usbmon/3u > /tmp/1.mon.out
 
 to listen on a single bus, otherwise, to listen on all buses, type:
 
-# cat /sys/kernel/debug/usbmon/0u > /tmp/1.mon.out
+# cat /sys/kernel/debug/usb/usbmon/0u > /tmp/1.mon.out
 
 This process will be reading until killed. Naturally, the output can be
 redirected to a desirable location. This is preferred, because it is going


-- 
Rogério Brito : rbrito@{mackenzie,ime.usp}.br : GPG key 1024D/7C2CAEB8
http://www.ime.usp.br/~rbrito : http://meusite.mackenzie.com.br/rbrito
Projects: algorithms.berlios.de : lame.sf.net : vrms.alioth.debian.org
--
To unsubscribe from this list: send the line "unsubscribe linux-scsi" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [Bugme-new] [Bug 14020] New: Stack trace when running smartctl on an USB disk

[Rogério Brito]

[-- Attachment #1: Type: text/plain, Size: 494 bytes --]

Hi, Alan.

On Aug 21 2009, Alan Stern wrote:
> A usbmon trace showing what happens when you plug in the drive and
> when you run smartctl would help.

The requested trace is attached to this message. Please let me know if
you need more information.


Thanks, Rogério Brito.

-- 
Rogério Brito : rbrito@{mackenzie,ime.usp}.br : GPG key 1024D/7C2CAEB8
http://www.ime.usp.br/~rbrito : http://meusite.mackenzie.com.br/rbrito
Projects: algorithms.berlios.de : lame.sf.net : vrms.alioth.debian.org

[-- Attachment #2: usbmon-dump.txt.bz2 --]
[-- Type: application/octet-stream, Size: 13644 bytes --]

Re: [Bugme-new] [Bug 14020] New: Stack trace when running smartctl on an USB disk

[Alan Stern]

On Sat, 22 Aug 2009, [utf-8] Rogério Brito wrote:

> Hi, Alan.
> 
> On Aug 21 2009, Alan Stern wrote:
> > A usbmon trace showing what happens when you plug in the drive and
> > when you run smartctl would help.
> 
> The requested trace is attached to this message. Please let me know if
> you need more information.

The trace shows that something (presumably smartctl) sends a command
the drive doesn't understand.  The drive then violates the USB
mass-storage protocol, sending an invalid response.  The kernel waits
for a proper response but nothing more happens, so after 30 seconds the
command times out and is aborted and the drive is reset.  The command
then gets retried, and the same thing happens again.  The retries take
so long that the kernel complains about smartctl being blocked for more
than 120 seconds -- that's the reason for the stack dump.

So the problem has several causes.  One is that the drive is buggy (it
doesn't respond with an error code in the proper way when it receives a
command it doesn't understand).  Another is that smartctl is trying to
send commands in a form the drive can't handle.  Finally, there's the
problem about all the retries taking too long.

Perhaps you can blame the kernel for spending too much time on retries, 
but the other two are the fault of the drive and smartctl.

Alan Stern

--
To unsubscribe from this list: send the line "unsubscribe linux-scsi" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [Bugme-new] [Bug 14020] New: Stack trace when running smartctl on an USB disk

[Rogério Brito]

Hi again, Alan.

(Sorry if this message seems messed up, but I am not using my regular  
mailer right now, unfortunately).

On 2009-08-22, at 21:17, Alan Stern wrote:

> On Sat, 22 Aug 2009, Rogério Brito wrote:
>
>> The requested trace is attached to this message. Please let me  
>> know if
>> you need more information.
>
> The trace shows that something (presumably smartctl) sends a command
> the drive doesn't understand.  The drive then violates the USB
> mass-storage protocol, sending an invalid response.

Right.

> The kernel waits
> for a proper response but nothing more happens, so after 30 seconds  
> the
> command times out and is aborted and the drive is reset.

I'm not with the kernel sources here (so, I can't check the code),  
but is there any option to be able to log such invalid responses when  
the kernel gets one? Perhaps the verbose USB logging does that?

> The command
> then gets retried, and the same thing happens again.  The retries take
> so long that the kernel complains about smartctl being blocked for  
> more
> than 120 seconds -- that's the reason for the stack dump.

Right.

Geeez, Alan, is there any vendor out there that gets the USB  
implementation according to the specs?

This is the 3rd USB device that I sent you some message about where  
the kernel moans about something that it doesn't understand (I can  
get you the vendor and device ids when I get home).

I will test with some other devices that I have, just to see what  
their response is. :-(

> So the problem has several causes.  One is that the drive is buggy (it
> doesn't respond with an error code in the proper way when it  
> receives a
> command it doesn't understand).  Another is that smartctl is trying to
> send commands in a form the drive can't handle.

That's probably not smartctl, but the user (me) that is telling it to  
use a given command set to check if the USB adapter understands/ 
allows pass-thru of the SMART protocol to the drive.

> Finally, there's the
> problem about all the retries taking too long.

Is there anything that could be done about this?

> Perhaps you can blame the kernel for spending too much time on  
> retries,
> but the other two are the fault of the drive and smartctl.

I understand the p-o-v of the kernel: some devices need a little bit  
more time on a retry, while others don't. There's no way to hardcode  
a once and for all behavior. It seems that an expensive solution to  
this would be to create (yet) another list of blacklisted devices  
(how many lists of quirks do we have in the kernel already---this is  
really causing some bloat, especially for some embedded devices). :-(

OTOH, creating blacklists seem to not be the adequate (let alone  
"right") solution (see the ASUS/it87 monitoring cause) in many  
situations. :-/


Thanks for your always kind messages, Rogério Brito.

Re: [Bugme-new] [Bug 14020] New: Stack trace when running smartctl on an USB disk

[Alan Stern]

On Sun, 23 Aug 2009, Rogério Brito wrote:

> > The trace shows that something (presumably smartctl) sends a command
> > the drive doesn't understand.  The drive then violates the USB
> > mass-storage protocol, sending an invalid response.
> 
> Right.
> 
> > The kernel waits
> > for a proper response but nothing more happens, so after 30 seconds  
> > the
> > command times out and is aborted and the drive is reset.
> 
> I'm not with the kernel sources here (so, I can't check the code),  
> but is there any option to be able to log such invalid responses when  
> the kernel gets one? Perhaps the verbose USB logging does that?

There's no way to log the invalid responses because the kernel doesn't
realize they are invalid.  However the resets _do_ get logged; you can
see them in the logs you sent.

> > The command
> > then gets retried, and the same thing happens again.  The retries take
> > so long that the kernel complains about smartctl being blocked for  
> > more
> > than 120 seconds -- that's the reason for the stack dump.
> 
> Right.
> 
> Geeez, Alan, is there any vendor out there that gets the USB  
> implementation according to the specs?

There are some... but a lot of them mess it up.  :-(

> This is the 3rd USB device that I sent you some message about where  
> the kernel moans about something that it doesn't understand (I can  
> get you the vendor and device ids when I get home).
> 
> I will test with some other devices that I have, just to see what  
> their response is. :-(

Be sure to get usbmon traces.

> > So the problem has several causes.  One is that the drive is buggy (it
> > doesn't respond with an error code in the proper way when it  
> > receives a
> > command it doesn't understand).  Another is that smartctl is trying to
> > send commands in a form the drive can't handle.
> 
> That's probably not smartctl, but the user (me) that is telling it to  
> use a given command set to check if the USB adapter understands/ 
> allows pass-thru of the SMART protocol to the drive.

Yes, it's entirely possible that this adapter does not understand the 
pass-thru protocol you tried.  Isn't there more than one such protocol?

> > Finally, there's the
> > problem about all the retries taking too long.
> 
> Is there anything that could be done about this?

The length of each timeout is adjustable in sysfs, but I don't remember 
what attribute file you need to change.

Also, you could follow the instructions in those stack dumps.  They are
only warnings, not errors, and you can prevent the kernel from issuing
them.

> > Perhaps you can blame the kernel for spending too much time on  
> > retries,
> > but the other two are the fault of the drive and smartctl.
> 
> I understand the p-o-v of the kernel: some devices need a little bit  
> more time on a retry, while others don't. There's no way to hardcode  
> a once and for all behavior. It seems that an expensive solution to  
> this would be to create (yet) another list of blacklisted devices  
> (how many lists of quirks do we have in the kernel already---this is  
> really causing some bloat, especially for some embedded devices). :-(
> 
> OTOH, creating blacklists seem to not be the adequate (let alone  
> "right") solution (see the ASUS/it87 monitoring cause) in many  
> situations. :-/
> 
> 
> Thanks for your always kind messages, Rogério Brito.

You're welcome.

Alan Stern

--
To unsubscribe from this list: send the line "unsubscribe linux-scsi" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [Bugme-new] [Bug 14020] New: Stack trace when running smartctl on an USB disk

[Douglas Gilbert]

Rogério Brito wrote:
> Hi again, Alan.
> 
> (Sorry if this message seems messed up, but I am not using my regular 
> mailer right now, unfortunately).
> 
> On 2009-08-22, at 21:17, Alan Stern wrote:
> 
>> On Sat, 22 Aug 2009, Rogério Brito wrote:
>>
>>> The requested trace is attached to this message. Please let me know if
>>> you need more information.
>>
>> The trace shows that something (presumably smartctl) sends a command
>> the drive doesn't understand.  The drive then violates the USB
>> mass-storage protocol, sending an invalid response.
> 
> Right.
> 
>> The kernel waits
>> for a proper response but nothing more happens, so after 30 seconds the
>> command times out and is aborted and the drive is reset.
> 
> I'm not with the kernel sources here (so, I can't check the code), but 
> is there any option to be able to log such invalid responses when the 
> kernel gets one? Perhaps the verbose USB logging does that?
> 
>> The command
>> then gets retried, and the same thing happens again.  The retries take
>> so long that the kernel complains about smartctl being blocked for more
>> than 120 seconds -- that's the reason for the stack dump.
> 
> Right.
> 
> Geeez, Alan, is there any vendor out there that gets the USB 
> implementation according to the specs?

The fact that you invoked:
   smartctl -d usbcypress -a /dev/sda

means that the cypress chip does not comply with SAT.
To find out what commands are being sent (via the SG_IO
ioctl I presume) by smartctl please try adding:
   '-r ioctl,3'
to the above invocation.


Doug Gilbert

Re: [Bugme-new] [Bug 14020] New: Stack trace when running smartctl on an USB disk

[Rogério Brito]

Hi, People.

On Sep 01 2009, Alan Stern wrote:
> Should this bug report be closed out?

Please, just wait a little bit more. I'm just getting recovered from
being ill (my health is not very good, unfortunately).

That with some network (and e-mail) outages made things difficult. I'm
just getting back now.

I'm going to test the suggestion from Douglas right now.


Thanks, Rogério Brito.

-- 
Rogério Brito : rbrito@{mackenzie,ime.usp}.br : GPG key 1024D/7C2CAEB8
http://www.ime.usp.br/~rbrito : http://meusite.mackenzie.com.br/rbrito
Projects: algorithms.berlios.de : lame.sf.net : vrms.alioth.debian.org
--
To unsubscribe from this list: send the line "unsubscribe linux-scsi" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html