From: Alan Stern on
On Tue, 23 Feb 2010, Rafael J. Wysocki wrote:

> On Tuesday 23 February 2010, �kos Mar�y wrote:
> > Hi,
> >
> > I wonder if this is the write place to post this issue to, but I have a
> > proplem when trying go suspend or hibernate my system. after enabling
> > pm_trace by:
> >
> > echo 1 > /sys/power/pm_trace
> >
> > and then issuing pm-suspend, I get the following in dmesg:
> >
> > [ 685.833275] PM: Entering mem sleep
> > [ 685.833292] Suspending console(s) (use no_console_suspend to debug)
> > [ 685.993399] pm_op(): usb_dev_suspend+0x0/0x10 returns -2
> > [ 685.993404] PM: Device usb2 failed to suspend: error -2
> > [ 685.993408] PM: Some devices failed to suspend
> > [ 685.997009] PM: resume devices took 0.000 seconds
> > [ 685.997169] PM: Finishing wakeup.
> >
> > this is on 2.6.32.8, but on 2.6.33-rc8 I get the same results.
> >
> > trying to find out what device this is:
> >
> > $ lsusb
> > Bus 002 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
> > Bus 001 Device 003: ID 0bda:0159 Realtek Semiconductor Corp.
> > Bus 001 Device 004: ID 04f2:b16c Chicony Electronics Co., Ltd
> > Bus 001 Device 005: ID 03f0:231d Hewlett-Packard
> > Bus 001 Device 002: ID 8087:0020
> > Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
> >
> > my persumption is that "Device usb2" would be device 002 on bus 001
> > above, that is, 8087:0020.

It isn't. usb2 is the root hub device on bus 2, i.e., it is device 001
on bus 002.

> > googling for this USB id I found some
> > references here: http://forum.notebookreview.com/showthread.php?p=5906076 :
> >
> > Bus 001 Device 002: ID 8087:0020 Intel Corp. Integrated Rate Matching Hub
> >
> >
> > I wonder what could be done to make this device not sabotage the suspend
> > process?

You can get more information if you enable CONFIG_USB_DEBUG in your
kernel configuration. The most likely explanation is that the suspend
failed because one of the ports on that root hub issued a wakeup
request.

Alan Stern

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo(a)vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
From: Alan Stern on
On Wed, 24 Feb 2010, �kos Mar�y wrote:

> Alan,
>
> > You can get more information if you enable CONFIG_USB_DEBUG in your
> > kernel configuration. The most likely explanation is that the suspend
> > failed because one of the ports on that root hub issued a wakeup
> > request.
>
> I tried, and this is what I seem to be getting now:
>
>
> Feb 24 23:28:52 tonkachi kernel: [ 348.733460] PM: Syncing filesystems ...
> Feb 24 23:28:52 tonkachi kernel: [ 348.903106] done.
> Feb 24 23:28:52 tonkachi kernel: [ 348.903123] Freezing user space
> processes ... (elapsed 0.00 seconds) done.
> Feb 24 23:28:52 tonkachi kernel: [ 348.903808] Freezing remaining
> freezable tasks ... (elapsed 0.00 seconds) done.
> Feb 24 23:28:52 tonkachi kernel: [ 348.903952] Suspending console(s)
> (use no_console_suspend to debug)
> Feb 24 23:28:52 tonkachi kernel: [ 348.985903] xhci_hcd 0000:02:00.0:
> WARN: short transfer on control ep
> Feb 24 23:28:52 tonkachi kernel: [ 348.987274] PM: resume devices took
> 0.060 seconds
> Feb 24 23:28:52 tonkachi kernel: [ 348.987371] Restarting tasks ...
> Feb 24 23:28:52 tonkachi kernel: [ 348.988165] done.
>
>
> though I don't see the pm_op() error log anymore..
>
> would this make sense?

You should not be looking at the system log file; you should use the
output from dmesg.

By the way, I noticed above that you have xhci-hcd installed. As far
as I know, that driver does not yet support system suspend. You should
try unloading xhci-hcd before doing the suspend (both with and without
CONFIG_USB_DEBUG).

> actually, the whole USB susbsystem seems to be very fragile - I plug in
> a USB device, and the whole system freezes for about 5 seconds or more.
> then the device is registered (for example, a mouse). but I unplug and
> re-plug, and the device doesn't work anymore...
>
> or I plug in an external USB DVD drive - but if I unplug it, it is still
> listed in lsusb..

These separate issues deserve to be investigated more closely. The USB
stack is not supposed to be that fragile. Describe your environment
more fully and provide the dmesg log from a kernel with
CONFIG_USB_DEBUG enabled showing what happens during the experiments.

Alan Stern

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo(a)vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
From: Alan Stern on
On Thu, 25 Feb 2010, �kos Mar�y wrote:

> > By the way, I noticed above that you have xhci-hcd installed. As far
> > as I know, that driver does not yet support system suspend. You should
> > try unloading xhci-hcd before doing the suspend (both with and without
> > CONFIG_USB_DEBUG).
>
> wow, rmmod xhci - and the suspend goes through fine!
>
> what is this xhci thing anyway?

It is the driver for USB-3.0 controllers. It's relatively new and not
as mature as the USB-2.0 drivers.

I'm a little surprised that it is running on your system. Why would
you have USB-3.0 hardware?

> > These separate issues deserve to be investigated more closely. The USB
> > stack is not supposed to be that fragile. Describe your environment
> > more fully and provide the dmesg log from a kernel with
> > CONFIG_USB_DEBUG enabled showing what happens during the experiments.
>
> indeed. interestingly, xhci may be the culprit, as without xhci, the
> external DVD doesn't even register at all.
>
> loadind xhci, I get:
>
> Feb 25 17:33:50 tonkachi kernel: [ 168.203418] xhci_hcd 0000:02:00.0:
> PCI INT A -> GSI 16 (level, low) -> IRQ 16
> Feb 25 17:33:50 tonkachi kernel: [ 168.203568] xhci_hcd 0000:02:00.0:
> xHCI Host Controller
> Feb 25 17:33:50 tonkachi kernel: [ 168.203689] xhci_hcd 0000:02:00.0:
> new USB bus registered, assigned bus number 2
> Feb 25 17:33:50 tonkachi kernel: [ 168.203832] xhci_hcd 0000:02:00.0:
> irq 16, io mem 0xd4000000
> Feb 25 17:33:50 tonkachi kernel: [ 168.203875] usb usb2: config 1
> interface 0 altsetting 0 endpoint 0x81 has no SuperSpeed companion
> descriptor
> Feb 25 17:33:50 tonkachi kernel: [ 168.203912] usb usb2: New USB device
> found, idVendor=1d6b, idProduct=0002
> Feb 25 17:33:50 tonkachi kernel: [ 168.203919] usb usb2: New USB device
> strings: Mfr=3, Product=2, SerialNumber=1
> Feb 25 17:33:50 tonkachi kernel: [ 168.203925] usb usb2: Product: xHCI
> Host Controller
> Feb 25 17:33:50 tonkachi kernel: [ 168.203931] usb usb2: Manufacturer:
> Linux 2.6.32.8-usb-debug xhci_hcd
> Feb 25 17:33:50 tonkachi kernel: [ 168.203937] usb usb2: SerialNumber:
> 0000:02:00.0
> Feb 25 17:33:50 tonkachi kernel: [ 168.204089] usb usb2: configuration
> #1 chosen from 1 choice
> Feb 25 17:33:50 tonkachi kernel: [ 168.204198] hub 2-0:1.0: USB hub found
> Feb 25 17:33:50 tonkachi kernel: [ 168.204213] hub 2-0:1.0: 4 ports
> detected
>
>
> plugging in the USB DVD drive, there's a system 'freeze' for about 5
> seconds (nothing is responding, not even caps lock), then I get in syslog:
>
> Feb 25 17:34:39 tonkachi kernel: [ 217.433960] Registered led device:
> iwl-phy0::radio
> Feb 25 17:34:39 tonkachi kernel: [ 217.433990] Registered led device:
> iwl-phy0::assoc
> Feb 25 17:34:39 tonkachi kernel: [ 217.434020] Registered led device:
> iwl-phy0::RX
> Feb 25 17:34:39 tonkachi kernel: [ 217.434045] Registered led device:
> iwl-phy0::TX
> Feb 25 17:34:39 tonkachi kernel: [ 217.463366] usb 2-4: new high speed
> USB device using xhci_hcd and address 0
> Feb 25 17:34:39 tonkachi kernel: [ 217.485828] usb 2-4: New USB device
> found, idVendor=058f, idProduct=6254
> Feb 25 17:34:39 tonkachi kernel: [ 217.485834] usb 2-4: New USB device
> strings: Mfr=0, Product=0, SerialNumber=0
> Feb 25 17:34:39 tonkachi kernel: [ 217.485949] usb 2-4: configuration
> #1 chosen from 1 choice
> Feb 25 17:34:39 tonkachi kernel: [ 217.485963] usb 2-4: ep 0x81 -
> rounding interval to 2048 microframes
> Feb 25 17:34:39 tonkachi kernel: [ 217.487002] hub 2-4:1.0: USB hub found
> Feb 25 17:34:39 tonkachi kernel: [ 217.487502] xhci_hcd 0000:02:00.0:
> WARN: short transfer on control ep
> Feb 25 17:34:39 tonkachi kernel: [ 217.487533] hub 2-4:1.0: 3 ports
> detected
> Feb 25 17:34:40 tonkachi kernel: [ 217.782947] usb 2-4.1: new high
> speed USB device using xhci_hcd and address 0
> Feb 25 17:34:40 tonkachi kernel: [ 217.806372] xhci_hcd 0000:02:00.0:
> WARN: short transfer on control ep
> Feb 25 17:34:40 tonkachi kernel: [ 217.807238] xhci_hcd 0000:02:00.0:
> WARN: short transfer on control ep
> Feb 25 17:34:40 tonkachi kernel: [ 217.808106] xhci_hcd 0000:02:00.0:
> WARN: short transfer on control ep
> Feb 25 17:34:40 tonkachi kernel: [ 217.808996] xhci_hcd 0000:02:00.0:
> WARN: short transfer on control ep
> Feb 25 17:34:40 tonkachi kernel: [ 217.809420] usb 2-4.1: New USB
> device found, idVendor=152d, idProduct=2339
> Feb 25 17:34:40 tonkachi kernel: [ 217.809425] usb 2-4.1: New USB
> device strings: Mfr=1, Product=2, SerialNumber=5
> Feb 25 17:34:40 tonkachi kernel: [ 217.809430] usb 2-4.1: Product: USB
> to ATA/ATAPI Bridge
> Feb 25 17:34:40 tonkachi kernel: [ 217.809434] usb 2-4.1: Manufacturer:
> JMicron
> Feb 25 17:34:40 tonkachi kernel: [ 217.809437] usb 2-4.1: SerialNumber:
> 6A1713351FFF
> Feb 25 17:34:40 tonkachi kernel: [ 217.809574] usb 2-4.1: configuration
> #1 chosen from 1 choice
> Feb 25 17:34:40 tonkachi kernel: [ 217.811213] xhci_hcd 0000:02:00.0:
> WARN: short transfer on control ep
> Feb 25 17:34:40 tonkachi kernel: [ 217.812078] xhci_hcd 0000:02:00.0:
> WARN: short transfer on control ep
> Feb 25 17:34:40 tonkachi kernel: [ 217.840485] Initializing USB Mass
> Storage driver...
> Feb 25 17:34:40 tonkachi kernel: [ 217.840664] scsi6 : SCSI emulation
> for USB Mass Storage devices
> Feb 25 17:34:40 tonkachi kernel: [ 217.840795] usbcore: registered new
> interface driver usb-storage
> Feb 25 17:34:40 tonkachi kernel: [ 217.840800] USB Mass Storage support
> registered.
> Feb 25 17:34:45 tonkachi kernel: [ 222.833493] scsi 6:0:0:0: CD-ROM
> hp DVDRAM GT20L DC05 PQ: 0 ANSI: 0
> Feb 25 17:34:45 tonkachi kernel: [ 222.846361] xhci_hcd 0000:02:00.0:
> WARN: Stalled endpoint
> Feb 25 17:34:45 tonkachi kernel: [ 222.847589] sr0: scsi3-mmc drive:
> 24x/24x writer dvd-ram cd/rw xa/form2 cdda tray
> Feb 25 17:34:45 tonkachi kernel: [ 222.847597] Uniform CD-ROM driver
> Revision: 3.20
> Feb 25 17:34:45 tonkachi kernel: [ 222.849281] sr 6:0:0:0: Attached
> scsi generic sg2 type 5
> Feb 25 17:34:45 tonkachi kernel: [ 222.958589] xhci_hcd 0000:02:00.0:
> WARN: Stalled endpoint
>
>
> now, I unplug the USB DVD drive:
>
> Feb 25 17:35:38 tonkachi kernel: [ 276.374282] xhci_hcd 0000:02:00.0:
> WARN: transfer error on endpoint
> Feb 25 17:35:39 tonkachi kernel: [ 276.728151] xhci_hcd 0000:02:00.0:
> WARN: transfer error on endpoint
> Feb 25 17:35:39 tonkachi kernel: [ 276.728819] xhci_hcd 0000:02:00.0:
> WARN: transfer error on endpoint
>
>
> I plug it back in, with a DVD in the drive:
>
> Feb 25 17:41:21 tonkachi kernel: [ 618.701586] Registered led device:
> iwl-phy0::radio
> Feb 25 17:41:21 tonkachi kernel: [ 618.701619] Registered led device:
> iwl-phy0::assoc
> Feb 25 17:41:21 tonkachi kernel: [ 618.701649] Registered led device:
> iwl-phy0::RX
> Feb 25 17:41:21 tonkachi kernel: [ 618.701674] Registered led device:
> iwl-phy0::TX
> Feb 25 17:41:21 tonkachi kernel: [ 618.719536] usb 2-3: new high speed
> USB device using xhci_hcd and address 0
> Feb 25 17:41:21 tonkachi kernel: [ 618.742028] usb 2-3: New USB device
> found, idVendor=058f, idProduct=6254
> Feb 25 17:41:21 tonkachi kernel: [ 618.742034] usb 2-3: New USB device
> strings: Mfr=0, Product=0, SerialNumber=0
> Feb 25 17:41:21 tonkachi kernel: [ 618.742155] usb 2-3: configuration
> #1 chosen from 1 choice
> Feb 25 17:41:21 tonkachi kernel: [ 618.742168] usb 2-3: ep 0x81 -
> rounding interval to 2048 microframes
> Feb 25 17:41:21 tonkachi kernel: [ 618.743316] hub 2-3:1.0: USB hub found
> Feb 25 17:41:21 tonkachi kernel: [ 618.743794] xhci_hcd 0000:02:00.0:
> WARN: short transfer on control ep
> Feb 25 17:41:21 tonkachi kernel: [ 618.743830] hub 2-3:1.0: 3 ports
> detected
> Feb 25 17:41:21 tonkachi kernel: [ 619.045944] usb 2-3.1: new high
> speed USB device using xhci_hcd and address 0
> Feb 25 17:41:21 tonkachi kernel: [ 619.069424] xhci_hcd 0000:02:00.0:
> WARN: short transfer on control ep
> Feb 25 17:41:21 tonkachi kernel: [ 619.070295] xhci_hcd 0000:02:00.0:
> WARN: short transfer on control ep
> Feb 25 17:41:21 tonkachi kernel: [ 619.071173] xhci_hcd 0000:02:00.0:
> WARN: short transfer on control ep
> Feb 25 17:41:21 tonkachi kernel: [ 619.072042] xhci_hcd 0000:02:00.0:
> WARN: short transfer on control ep
> Feb 25 17:41:21 tonkachi kernel: [ 619.072398] usb 2-3.1: New USB
> device found, idVendor=152d, idProduct=2339
> Feb 25 17:41:21 tonkachi kernel: [ 619.072404] usb 2-3.1: New USB
> device strings: Mfr=1, Product=2, SerialNumber=5
> Feb 25 17:41:21 tonkachi kernel: [ 619.072408] usb 2-3.1: Product: USB
> to ATA/ATAPI Bridge
> Feb 25 17:41:21 tonkachi kernel: [ 619.072412] usb 2-3.1: Manufacturer:
> JMicron
> Feb 25 17:41:21 tonkachi kernel: [ 619.072416] usb 2-3.1: SerialNumber:
> 6A1713351FFF
> Feb 25 17:41:21 tonkachi kernel: [ 619.072530] usb 2-3.1: configuration
> #1 chosen from 1 choice
> Feb 25 17:41:21 tonkachi kernel: [ 619.074124] xhci_hcd 0000:02:00.0:
> WARN: short transfer on control ep
> Feb 25 17:41:21 tonkachi kernel: [ 619.074999] xhci_hcd 0000:02:00.0:
> WARN: short transfer on control ep
> Feb 25 17:41:21 tonkachi kernel: [ 619.075559] scsi7 : SCSI emulation
> for USB Mass Storage devices
>
>
>
> Feb 25 17:41:26 tonkachi kernel: [ 624.073472] scsi 7:0:0:0: CD-ROM
> hp DVDRAM GT20L DC05 PQ: 0 ANSI: 0
> Feb 25 17:41:26 tonkachi kernel: [ 624.086041] xhci_hcd 0000:02:00.0:
> WARN: Stalled endpoint
> Feb 25 17:41:26 tonkachi kernel: [ 624.087393] sr0: scsi3-mmc drive:
> 62x/62x writer dvd-ram cd/rw xa/form2 cdda tray
> Feb 25 17:41:26 tonkachi kernel: [ 624.088377] sr 7:0:0:0: Attached
> scsi generic sg2 type 5
> Feb 25 17:41:26 tonkachi kernel: [ 624.118679] xhci_hcd 0000:02:00.0:
> WARN: Stalled endpoint
> Feb 25 17:41:29 tonkachi kernel: [ 626.883451] xhci_hcd 0000:02:00.0:
> WARN: Stalled endpoint
> Feb 25 17:41:29 tonkachi kernel: [ 626.915739] xhci_hcd 0000:02:00.0:
> WARN: Stalled endpoint
> Feb 25 17:41:29 tonkachi kernel: [ 627.147000] xhci_hcd 0000:02:00.0:
> WARN: Stalled endpoint
> Feb 25 17:41:29 tonkachi kernel: [ 627.270741] xhci_hcd 0000:02:00.0:
> WARN: Stalled endpoint
>
>
> unplug:
>
> Feb 25 17:42:05 tonkachi kernel: [ 663.327552] xhci_hcd 0000:02:00.0:
> WARN: transfer error on endpoint
> Feb 25 17:42:06 tonkachi kernel: [ 663.364546] xhci_hcd 0000:02:00.0:
> WARN: transfer error on endpoint
> Feb 25 17:42:06 tonkachi kernel: [ 663.365228] xhci_hcd 0000:02:00.0:
> WARN: transfer error on endpoint
> Feb 25 17:42:10 tonkachi kernel: [ 667.360714] VFS: busy inodes on
> changed media or resized disk sr0
> Feb 25 17:42:10 tonkachi kernel: [ 667.360956] VFS: busy inodes on
> changed media or resized disk sr0
> Feb 25 17:42:10 tonkachi kernel: [ 667.361101] VFS: busy inodes on
> changed media or resized disk sr0
> Feb 25 17:42:10 tonkachi kernel: [ 667.362264] VFS: busy inodes on
> changed media or resized disk sr0
> Feb 25 17:42:10 tonkachi kernel: [ 667.363730] VFS: busy inodes on
> changed media or resized disk sr0
> Feb 25 17:42:10 tonkachi kernel: [ 667.377669] VFS: busy inodes on
> changed media or resized disk sr0
> Feb 25 17:42:10 tonkachi kernel: [ 667.377910] VFS: busy inodes on
> changed media or resized disk sr0
> Feb 25 17:42:10 tonkachi kernel: [ 667.378158] VFS: busy inodes on
> changed media or resized disk sr0
>
>
>
> plug back in:
>
> Feb 25 17:42:50 tonkachi kernel: [ 707.759089] Registered led device:
> iwl-phy0::radio
> Feb 25 17:42:50 tonkachi kernel: [ 707.759179] Registered led device:
> iwl-phy0::assoc
> Feb 25 17:42:50 tonkachi kernel: [ 707.759412] Registered led device:
> iwl-phy0::RX
> Feb 25 17:42:50 tonkachi kernel: [ 707.759572] Registered led device:
> iwl-phy0::TX
>
>
>
> but the disk does not register anymore :(

This is something Sarah should look into. She's the main developer
behind xhci-hcd.

Alan Stern

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo(a)vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
From: Sarah Sharp on
On Thu, Feb 25, 2010 at 12:46:59PM -0500, Alan Stern wrote:
> On Thu, 25 Feb 2010, �kos Mar�y wrote:
>
> > > By the way, I noticed above that you have xhci-hcd installed. As far
> > > as I know, that driver does not yet support system suspend. You should
> > > try unloading xhci-hcd before doing the suspend (both with and without
> > > CONFIG_USB_DEBUG).
> >
> > wow, rmmod xhci - and the suspend goes through fine!
> >
> > what is this xhci thing anyway?
>
> It is the driver for USB-3.0 controllers. It's relatively new and not
> as mature as the USB-2.0 drivers.
>
> I'm a little surprised that it is running on your system. Why would
> you have USB-3.0 hardware?

USB 3.0 hosts and devices are now available commercially. I think the
HP envy laptop has an integrated USB 3.0 host. �kos, which host
controller do you have? Is it a PCIe add-in card, a PCI express card,
or a port on a laptop?

The xHCI driver doesn't support PCI suspend, and it also doesn't support
suspending devices under the xHCI host. The xHCI hardware needs to do
some extra work when a device is suspended, and I haven't added that API
to the USB core yet. In short, power management sucks under xHCI. :-/

> > > These separate issues deserve to be investigated more closely. The USB
> > > stack is not supposed to be that fragile. Describe your environment
> > > more fully and provide the dmesg log from a kernel with
> > > CONFIG_USB_DEBUG enabled showing what happens during the experiments.
> >
> > indeed. interestingly, xhci may be the culprit, as without xhci, the
> > external DVD doesn't even register at all.
> >
> > loadind xhci, I get:
> >
> > Feb 25 17:33:50 tonkachi kernel: [ 168.203418] xhci_hcd 0000:02:00.0:
> > PCI INT A -> GSI 16 (level, low) -> IRQ 16
> > Feb 25 17:33:50 tonkachi kernel: [ 168.203568] xhci_hcd 0000:02:00.0:
> > xHCI Host Controller
> > Feb 25 17:33:50 tonkachi kernel: [ 168.203689] xhci_hcd 0000:02:00.0:
> > new USB bus registered, assigned bus number 2
> > Feb 25 17:33:50 tonkachi kernel: [ 168.203832] xhci_hcd 0000:02:00.0:
> > irq 16, io mem 0xd4000000
> > Feb 25 17:33:50 tonkachi kernel: [ 168.203875] usb usb2: config 1
> > interface 0 altsetting 0 endpoint 0x81 has no SuperSpeed companion
> > descriptor
> > Feb 25 17:33:50 tonkachi kernel: [ 168.203912] usb usb2: New USB device
> > found, idVendor=1d6b, idProduct=0002
> > Feb 25 17:33:50 tonkachi kernel: [ 168.203919] usb usb2: New USB device
> > strings: Mfr=3, Product=2, SerialNumber=1
> > Feb 25 17:33:50 tonkachi kernel: [ 168.203925] usb usb2: Product: xHCI
> > Host Controller
> > Feb 25 17:33:50 tonkachi kernel: [ 168.203931] usb usb2: Manufacturer:
> > Linux 2.6.32.8-usb-debug xhci_hcd
> > Feb 25 17:33:50 tonkachi kernel: [ 168.203937] usb usb2: SerialNumber:
> > 0000:02:00.0
> > Feb 25 17:33:50 tonkachi kernel: [ 168.204089] usb usb2: configuration
> > #1 chosen from 1 choice
> > Feb 25 17:33:50 tonkachi kernel: [ 168.204198] hub 2-0:1.0: USB hub found
> > Feb 25 17:33:50 tonkachi kernel: [ 168.204213] hub 2-0:1.0: 4 ports
> > detected
> >
> >
> > plugging in the USB DVD drive, there's a system 'freeze' for about 5
> > seconds (nothing is responding, not even caps lock), then I get in syslog:

Oh, freezes are not good. I wonder if the xHCI host is taking a long
time to respond to a hardware command? Can you turn on
CONFIG_USB_XHCI_HCD_DEBUGGING and send me the dmesg when you plug in the
device?

> > Feb 25 17:34:39 tonkachi kernel: [ 217.433960] Registered led device:
> > iwl-phy0::radio
> > Feb 25 17:34:39 tonkachi kernel: [ 217.433990] Registered led device:
> > iwl-phy0::assoc
> > Feb 25 17:34:39 tonkachi kernel: [ 217.434020] Registered led device:
> > iwl-phy0::RX
> > Feb 25 17:34:39 tonkachi kernel: [ 217.434045] Registered led device:
> > iwl-phy0::TX
> > Feb 25 17:34:39 tonkachi kernel: [ 217.463366] usb 2-4: new high speed
> > USB device using xhci_hcd and address 0
> > Feb 25 17:34:39 tonkachi kernel: [ 217.485828] usb 2-4: New USB device
> > found, idVendor=058f, idProduct=6254
> > Feb 25 17:34:39 tonkachi kernel: [ 217.485834] usb 2-4: New USB device
> > strings: Mfr=0, Product=0, SerialNumber=0
> > Feb 25 17:34:39 tonkachi kernel: [ 217.485949] usb 2-4: configuration
> > #1 chosen from 1 choice
> > Feb 25 17:34:39 tonkachi kernel: [ 217.485963] usb 2-4: ep 0x81 -
> > rounding interval to 2048 microframes
> > Feb 25 17:34:39 tonkachi kernel: [ 217.487002] hub 2-4:1.0: USB hub found

Did you plug in the DVD device behind a USB hub? Or is the hub a part
of the device?

> > Feb 25 17:34:39 tonkachi kernel: [ 217.487502] xhci_hcd 0000:02:00.0:
> > WARN: short transfer on control ep
> > Feb 25 17:34:39 tonkachi kernel: [ 217.487533] hub 2-4:1.0: 3 ports
> > detected
> > Feb 25 17:34:40 tonkachi kernel: [ 217.782947] usb 2-4.1: new high
> > speed USB device using xhci_hcd and address 0
> > Feb 25 17:34:40 tonkachi kernel: [ 217.806372] xhci_hcd 0000:02:00.0:
> > WARN: short transfer on control ep
> > Feb 25 17:34:40 tonkachi kernel: [ 217.807238] xhci_hcd 0000:02:00.0:
> > WARN: short transfer on control ep
> > Feb 25 17:34:40 tonkachi kernel: [ 217.808106] xhci_hcd 0000:02:00.0:
> > WARN: short transfer on control ep
> > Feb 25 17:34:40 tonkachi kernel: [ 217.808996] xhci_hcd 0000:02:00.0:
> > WARN: short transfer on control ep
> > Feb 25 17:34:40 tonkachi kernel: [ 217.809420] usb 2-4.1: New USB
> > device found, idVendor=152d, idProduct=2339
> > Feb 25 17:34:40 tonkachi kernel: [ 217.809425] usb 2-4.1: New USB
> > device strings: Mfr=1, Product=2, SerialNumber=5
> > Feb 25 17:34:40 tonkachi kernel: [ 217.809430] usb 2-4.1: Product: USB
> > to ATA/ATAPI Bridge
> > Feb 25 17:34:40 tonkachi kernel: [ 217.809434] usb 2-4.1: Manufacturer:
> > JMicron
> > Feb 25 17:34:40 tonkachi kernel: [ 217.809437] usb 2-4.1: SerialNumber:
> > 6A1713351FFF
> > Feb 25 17:34:40 tonkachi kernel: [ 217.809574] usb 2-4.1: configuration
> > #1 chosen from 1 choice
> > Feb 25 17:34:40 tonkachi kernel: [ 217.811213] xhci_hcd 0000:02:00.0:
> > WARN: short transfer on control ep
> > Feb 25 17:34:40 tonkachi kernel: [ 217.812078] xhci_hcd 0000:02:00.0:
> > WARN: short transfer on control ep
> > Feb 25 17:34:40 tonkachi kernel: [ 217.840485] Initializing USB Mass
> > Storage driver...
> > Feb 25 17:34:40 tonkachi kernel: [ 217.840664] scsi6 : SCSI emulation
> > for USB Mass Storage devices
> > Feb 25 17:34:40 tonkachi kernel: [ 217.840795] usbcore: registered new
> > interface driver usb-storage
> > Feb 25 17:34:40 tonkachi kernel: [ 217.840800] USB Mass Storage support
> > registered.
> > Feb 25 17:34:45 tonkachi kernel: [ 222.833493] scsi 6:0:0:0: CD-ROM
> > hp DVDRAM GT20L DC05 PQ: 0 ANSI: 0
> > Feb 25 17:34:45 tonkachi kernel: [ 222.846361] xhci_hcd 0000:02:00.0:
> > WARN: Stalled endpoint
> > Feb 25 17:34:45 tonkachi kernel: [ 222.847589] sr0: scsi3-mmc drive:
> > 24x/24x writer dvd-ram cd/rw xa/form2 cdda tray
> > Feb 25 17:34:45 tonkachi kernel: [ 222.847597] Uniform CD-ROM driver
> > Revision: 3.20
> > Feb 25 17:34:45 tonkachi kernel: [ 222.849281] sr 6:0:0:0: Attached
> > scsi generic sg2 type 5
> > Feb 25 17:34:45 tonkachi kernel: [ 222.958589] xhci_hcd 0000:02:00.0:
> > WARN: Stalled endpoint
> >
> >
> > now, I unplug the USB DVD drive:
> >
> > Feb 25 17:35:38 tonkachi kernel: [ 276.374282] xhci_hcd 0000:02:00.0:
> > WARN: transfer error on endpoint
> > Feb 25 17:35:39 tonkachi kernel: [ 276.728151] xhci_hcd 0000:02:00.0:
> > WARN: transfer error on endpoint
> > Feb 25 17:35:39 tonkachi kernel: [ 276.728819] xhci_hcd 0000:02:00.0:
> > WARN: transfer error on endpoint
> >
> >
> > I plug it back in, with a DVD in the drive:
> >
> > Feb 25 17:41:21 tonkachi kernel: [ 618.701586] Registered led device:
> > iwl-phy0::radio
> > Feb 25 17:41:21 tonkachi kernel: [ 618.701619] Registered led device:
> > iwl-phy0::assoc
> > Feb 25 17:41:21 tonkachi kernel: [ 618.701649] Registered led device:
> > iwl-phy0::RX
> > Feb 25 17:41:21 tonkachi kernel: [ 618.701674] Registered led device:
> > iwl-phy0::TX
> > Feb 25 17:41:21 tonkachi kernel: [ 618.719536] usb 2-3: new high speed
> > USB device using xhci_hcd and address 0
> > Feb 25 17:41:21 tonkachi kernel: [ 618.742028] usb 2-3: New USB device
> > found, idVendor=058f, idProduct=6254
> > Feb 25 17:41:21 tonkachi kernel: [ 618.742034] usb 2-3: New USB device
> > strings: Mfr=0, Product=0, SerialNumber=0
> > Feb 25 17:41:21 tonkachi kernel: [ 618.742155] usb 2-3: configuration
> > #1 chosen from 1 choice
> > Feb 25 17:41:21 tonkachi kernel: [ 618.742168] usb 2-3: ep 0x81 -
> > rounding interval to 2048 microframes

That looks like a rather long polling interval. Can you post the output
of `lsusb -vvv -d 058f:6254`?

> > Feb 25 17:41:21 tonkachi kernel: [ 618.743316] hub 2-3:1.0: USB hub found
> > Feb 25 17:41:21 tonkachi kernel: [ 618.743794] xhci_hcd 0000:02:00.0:
> > WARN: short transfer on control ep
> > Feb 25 17:41:21 tonkachi kernel: [ 618.743830] hub 2-3:1.0: 3 ports
> > detected
> > Feb 25 17:41:21 tonkachi kernel: [ 619.045944] usb 2-3.1: new high
> > speed USB device using xhci_hcd and address 0
> > Feb 25 17:41:21 tonkachi kernel: [ 619.069424] xhci_hcd 0000:02:00.0:
> > WARN: short transfer on control ep
> > Feb 25 17:41:21 tonkachi kernel: [ 619.070295] xhci_hcd 0000:02:00.0:
> > WARN: short transfer on control ep
> > Feb 25 17:41:21 tonkachi kernel: [ 619.071173] xhci_hcd 0000:02:00.0:
> > WARN: short transfer on control ep
> > Feb 25 17:41:21 tonkachi kernel: [ 619.072042] xhci_hcd 0000:02:00.0:
> > WARN: short transfer on control ep
> > Feb 25 17:41:21 tonkachi kernel: [ 619.072398] usb 2-3.1: New USB
> > device found, idVendor=152d, idProduct=2339
> > Feb 25 17:41:21 tonkachi kernel: [ 619.072404] usb 2-3.1: New USB
> > device strings: Mfr=1, Product=2, SerialNumber=5
> > Feb 25 17:41:21 tonkachi kernel: [ 619.072408] usb 2-3.1: Product: USB
> > to ATA/ATAPI Bridge
> > Feb 25 17:41:21 tonkachi kernel: [ 619.072412] usb 2-3.1: Manufacturer:
> > JMicron
> > Feb 25 17:41:21 tonkachi kernel: [ 619.072416] usb 2-3.1: SerialNumber:
> > 6A1713351FFF
> > Feb 25 17:41:21 tonkachi kernel: [ 619.072530] usb 2-3.1: configuration
> > #1 chosen from 1 choice
> > Feb 25 17:41:21 tonkachi kernel: [ 619.074124] xhci_hcd 0000:02:00.0:
> > WARN: short transfer on control ep
> > Feb 25 17:41:21 tonkachi kernel: [ 619.074999] xhci_hcd 0000:02:00.0:
> > WARN: short transfer on control ep
> > Feb 25 17:41:21 tonkachi kernel: [ 619.075559] scsi7 : SCSI emulation
> > for USB Mass Storage devices
> >
> >
> >
> > Feb 25 17:41:26 tonkachi kernel: [ 624.073472] scsi 7:0:0:0: CD-ROM
> > hp DVDRAM GT20L DC05 PQ: 0 ANSI: 0
> > Feb 25 17:41:26 tonkachi kernel: [ 624.086041] xhci_hcd 0000:02:00.0:
> > WARN: Stalled endpoint
> > Feb 25 17:41:26 tonkachi kernel: [ 624.087393] sr0: scsi3-mmc drive:
> > 62x/62x writer dvd-ram cd/rw xa/form2 cdda tray
> > Feb 25 17:41:26 tonkachi kernel: [ 624.088377] sr 7:0:0:0: Attached
> > scsi generic sg2 type 5
> > Feb 25 17:41:26 tonkachi kernel: [ 624.118679] xhci_hcd 0000:02:00.0:
> > WARN: Stalled endpoint
> > Feb 25 17:41:29 tonkachi kernel: [ 626.883451] xhci_hcd 0000:02:00.0:
> > WARN: Stalled endpoint
> > Feb 25 17:41:29 tonkachi kernel: [ 626.915739] xhci_hcd 0000:02:00.0:
> > WARN: Stalled endpoint
> > Feb 25 17:41:29 tonkachi kernel: [ 627.147000] xhci_hcd 0000:02:00.0:
> > WARN: Stalled endpoint
> > Feb 25 17:41:29 tonkachi kernel: [ 627.270741] xhci_hcd 0000:02:00.0:
> > WARN: Stalled endpoint

Can you read the DVD at this point?

> > unplug:
> >
> > Feb 25 17:42:05 tonkachi kernel: [ 663.327552] xhci_hcd 0000:02:00.0:
> > WARN: transfer error on endpoint
> > Feb 25 17:42:06 tonkachi kernel: [ 663.364546] xhci_hcd 0000:02:00.0:
> > WARN: transfer error on endpoint
> > Feb 25 17:42:06 tonkachi kernel: [ 663.365228] xhci_hcd 0000:02:00.0:
> > WARN: transfer error on endpoint
> > Feb 25 17:42:10 tonkachi kernel: [ 667.360714] VFS: busy inodes on
> > changed media or resized disk sr0
> > Feb 25 17:42:10 tonkachi kernel: [ 667.360956] VFS: busy inodes on
> > changed media or resized disk sr0
> > Feb 25 17:42:10 tonkachi kernel: [ 667.361101] VFS: busy inodes on
> > changed media or resized disk sr0
> > Feb 25 17:42:10 tonkachi kernel: [ 667.362264] VFS: busy inodes on
> > changed media or resized disk sr0
> > Feb 25 17:42:10 tonkachi kernel: [ 667.363730] VFS: busy inodes on
> > changed media or resized disk sr0
> > Feb 25 17:42:10 tonkachi kernel: [ 667.377669] VFS: busy inodes on
> > changed media or resized disk sr0
> > Feb 25 17:42:10 tonkachi kernel: [ 667.377910] VFS: busy inodes on
> > changed media or resized disk sr0
> > Feb 25 17:42:10 tonkachi kernel: [ 667.378158] VFS: busy inodes on
> > changed media or resized disk sr0

Did you unmount the DVD before you removed it? I'm not sure what the
VFS errors are, but it looks like VFS doesn't like you removing the
disk.

> > plug back in:
> >
> > Feb 25 17:42:50 tonkachi kernel: [ 707.759089] Registered led device:
> > iwl-phy0::radio
> > Feb 25 17:42:50 tonkachi kernel: [ 707.759179] Registered led device:
> > iwl-phy0::assoc
> > Feb 25 17:42:50 tonkachi kernel: [ 707.759412] Registered led device:
> > iwl-phy0::RX
> > Feb 25 17:42:50 tonkachi kernel: [ 707.759572] Registered led device:
> > iwl-phy0::TX
> >
> >
> >
> > but the disk does not register anymore :(
>
> This is something Sarah should look into. She's the main developer
> behind xhci-hcd.

Sarah Sharp
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo(a)vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
From: Alan Stern on
On Thu, 25 Feb 2010, Sarah Sharp wrote:

> > > now, I unplug the USB DVD drive:
> > >
> > > Feb 25 17:35:38 tonkachi kernel: [ 276.374282] xhci_hcd 0000:02:00.0:
> > > WARN: transfer error on endpoint
> > > Feb 25 17:35:39 tonkachi kernel: [ 276.728151] xhci_hcd 0000:02:00.0:
> > > WARN: transfer error on endpoint
> > > Feb 25 17:35:39 tonkachi kernel: [ 276.728819] xhci_hcd 0000:02:00.0:
> > > WARN: transfer error on endpoint

Shouldn't there be some messages here about "USB disconnect"? This
suggests there's something wrong with the root hub.

> > > I plug it back in, with a DVD in the drive:
> > >
> > > Feb 25 17:41:21 tonkachi kernel: [ 618.701586] Registered led device:
> > > iwl-phy0::radio
> > > Feb 25 17:41:21 tonkachi kernel: [ 618.701619] Registered led device:
> > > iwl-phy0::assoc
> > > Feb 25 17:41:21 tonkachi kernel: [ 618.701649] Registered led device:
> > > iwl-phy0::RX
> > > Feb 25 17:41:21 tonkachi kernel: [ 618.701674] Registered led device:
> > > iwl-phy0::TX
> > > Feb 25 17:41:21 tonkachi kernel: [ 618.719536] usb 2-3: new high speed
> > > USB device using xhci_hcd and address 0
> > > Feb 25 17:41:21 tonkachi kernel: [ 618.742028] usb 2-3: New USB device
> > > found, idVendor=058f, idProduct=6254
> > > Feb 25 17:41:21 tonkachi kernel: [ 618.742034] usb 2-3: New USB device
> > > strings: Mfr=0, Product=0, SerialNumber=0
> > > Feb 25 17:41:21 tonkachi kernel: [ 618.742155] usb 2-3: configuration
> > > #1 chosen from 1 choice
> > > Feb 25 17:41:21 tonkachi kernel: [ 618.742168] usb 2-3: ep 0x81 -
> > > rounding interval to 2048 microframes

You must have plugged it into a different port this time, yes?

> That looks like a rather long polling interval. Can you post the output
> of `lsusb -vvv -d 058f:6254`?

2048 microframes is 256 ms, the normal polling interval for hubs.

Alan Stern

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo(a)vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/