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. 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?
Akos
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. 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?
That's a good question for the USB people (CCed).
Rafael
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
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?
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..
Akos
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
Alan,
> You should not be looking at the system log file; you should use the
> output from dmesg.
indeed. I'm sorry about that.
looking at dmesg, its a long line of output. points of interest look
like the following:
[ 12.216797] hub 2-0:1.0: hub_suspend
[ 12.216811] usb usb2: bus auto-suspend
[ 12.216816] usb usb2: bus suspend fail, err -2
[ 12.216820] hub 2-0:1.0: hub_resume
[ 12.216864] hub 2-0:1.0: state 7 ports 4 chg 0000 evt 0000
[ 15.214004] hub 2-0:1.0: hub_suspend
[ 15.214015] usb usb2: bus auto-suspend
[ 15.214020] usb usb2: bus suspend fail, err -2
[ 15.214024] hub 2-0:1.0: hub_resume
[ 15.214055] hub 2-0:1.0: state 7 ports 4 chg 0000 evt 0000
[ 18.211195] hub 2-0:1.0: hub_suspend
[ 18.211206] usb usb2: bus auto-suspend
[ 18.211211] usb usb2: bus suspend fail, err -2
[ 18.211215] hub 2-0:1.0: hub_resume
[ 18.211254] hub 2-0:1.0: state 7 ports 4 chg 0000 evt 0000
[ 21.208379] hub 2-0:1.0: hub_suspend
[ 21.208389] usb usb2: bus auto-suspend
[ 21.208394] usb usb2: bus suspend fail, err -2
[ 21.208398] hub 2-0:1.0: hub_resume
[ 21.208432] hub 2-0:1.0: state 7 ports 4 chg 0000 evt 0000
[ 24.205564] hub 2-0:1.0: hub_suspend
[ 24.205578] usb usb2: bus auto-suspend
[ 24.205583] usb usb2: bus suspend fail, err -2
[ 24.205587] hub 2-0:1.0: hub_resume
[ 24.205624] hub 2-0:1.0: state 7 ports 4 chg 0000 evt 0000
...
[ 27.202742] hub 2-0:1.0: hub_suspend
[ 27.202755] usb usb2: bus auto-suspend
[ 27.202760] usb usb2: bus suspend fail, err -2
[ 27.202764] hub 2-0:1.0: hub_resume
[ 27.202807] hub 2-0:1.0: state 7 ports 4 chg 0000 evt 0000
[ 29.851255] usb usb2: uevent
[ 29.851420] usb 2-0:1.0: uevent
...
[ 30.209824] usb usb2: bus auto-suspend
[ 30.209828] usb usb2: bus suspend fail, err -2
[ 30.209833] hub 2-0:1.0: hub_resume
[ 30.209881] hub 2-0:1.0: state 7 ports 4 chg 0000 evt 0000
and a lot of the same, repeated all over. and then:
[ 407.210004] PM: Entering mem sleep
[ 407.210022] Suspending console(s) (use no_console_suspend to debug)
[ 407.368716] hub 2-0:1.0: hub_suspend
[ 407.368726] usb usb2: bus suspend
[ 407.368731] usb usb2: bus suspend fail, err -2
[ 407.368734] hub 2-0:1.0: hub_resume
[ 407.368768] pm_op(): usb_dev_suspend+0x0/0x10 returns -2
[ 407.368773] PM: Device usb2 failed to suspend: error -2
[ 407.368776] PM: Some devices failed to suspend
[ 407.371952] PM: resume devices took 0.000 seconds
[ 407.372122] PM: Finishing wakeup.
> 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?
> 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 :(
Akos
Alan,
> 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).
as I added xhci among the SUSPEND_MODULES for pm, I tried pm-hibernate
after a successful pm-suspend. but this doesn't work, the machine just
goes blank, and it doesn't power off. doing a power cycle boots it 'as
usual'.
how can one debug the hibernation process?
Akos
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
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
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
On Thu, Feb 25, 2010 at 02:36:02PM -0500, Alan Stern wrote:
> 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.
True. I can't tell exactly what's going on without
CONFIG_USB_XHCI_HCD_DEBUGGING. It's possible the xHCI host never
notified the driver of the disconnect, or there's a bug in the xHCI hub
emulation code.
Sarah Sharp
Alan Stern wrote:
> 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?
I might - this is a brand new HP Envy 15 laptop, which seems to be 'too
new' for Linux in a number of ways (e.g. video card, with the latest
10.2 official AMD binary driver 'sort of' working, hardware raid
controller for SSD, which only the mainline grub can handle, WiFi card
that is only supported in 2.6.32.x, etc.)
actually, it has 3 USB ports - two of them seem to have these issues.
the third USB port, which is phyisically both a USB and en eSATA port,
seems to work as expected.
> This is something Sarah should look into. She's the main developer
> behind xhci-hcd.
thanks for CC'ing her in..
Sarah Sharp wrote:
> 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?
see above, these are two ports on the side of the 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. :-/
for suspend, I seem to get along find with unloading / reloading the
xhci kernel module, as a workaround
> 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?
ok, I'll do that..
> Did you plug in the DVD device behind a USB hub? Or is the hub a part
> of the device?
I didn't use a USB hub. I plugged in the USB DVD right into the USB port
on the laptop. the HP Envy 15 does not have a built-in optical drive,
but you can order an external USB DVD-RW drive as an option. this is
what I have.
> That looks like a rather long polling interval. Can you post the output
> of `lsusb -vvv -d 058f:6254`?
sure, here you go:
# lsusb -vvv -d 058f:6254
Bus 002 Device 002: ID 058f:6254 Alcor Micro Corp. USB Hub
Device Descriptor:
bLength 18
bDescriptorType 1
bcdUSB 2.00
bDeviceClass 9 Hub
bDeviceSubClass 0 Unused
bDeviceProtocol 1 Single TT
bMaxPacketSize0 64
idVendor 0x058f Alcor Micro Corp.
idProduct 0x6254 USB Hub
bcdDevice 1.00
iManufacturer 0
iProduct 0
iSerial 0
bNumConfigurations 1
Configuration Descriptor:
bLength 9
bDescriptorType 2
wTotalLength 25
bNumInterfaces 1
bConfigurationValue 1
iConfiguration 0
bmAttributes 0xe0
Self Powered
Remote Wakeup
MaxPower 100mA
Interface Descriptor:
bLength 9
bDescriptorType 4
bInterfaceNumber 0
bAlternateSetting 0
bNumEndpoints 1
bInterfaceClass 9 Hub
bInterfaceSubClass 0 Unused
bInterfaceProtocol 0 Full speed (or root) hub
iInterface 0
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x81 EP 1 IN
bmAttributes 3
Transfer Type Interrupt
Synch Type None
Usage Type Data
wMaxPacketSize 0x0001 1x 1 bytes
bInterval 12
Hub Descriptor:
bLength 9
bDescriptorType 41
nNbrPorts 3
wHubCharacteristic 0x0080
Ganged power switching
Ganged overcurrent protection
TT think time 8 FS bits
Port indicators
bPwrOn2PwrGood 50 * 2 milli seconds
bHubContrCurrent 100 milli Ampere
DeviceRemovable 0x02
PortPwrCtrlMask 0xff
Hub Port Status:
Port 1: 0000.0503 highspeed power enable connect
Port 2: 0000.0100 power
Port 3: 0000.0100 power
Device Qualifier (for other device speed):
bLength 10
bDescriptorType 6
bcdUSB 2.00
bDeviceClass 9 Hub
bDeviceSubClass 0 Unused
bDeviceProtocol 0 Full speed (or root) hub
bMaxPacketSize0 64
bNumConfigurations 1
Device Status: 0x0001
Self Powered
though let me remind you that the same long delay happens when I plug in
other devices, like simple USB mice. also, if I plug in the same device
into the third USB port, it seems to work just fine. no 5 second freeze,
etc.
> Can you read the DVD at this point?
yes, after the first plug, it works as expected. after the unplug -
replug, it doesn't work. unless I unload the xhci module, and reload it.
> 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.
IMHO it got automatically mounted by gnome... (I saw it on my desktop as
a DVD drive)
Alan Stern wrote:
> You must have plugged it into a different port this time, yes?
I might have used the different of the two proplematic USB ports..
Sarah Sharp wrote:
> True. I can't tell exactly what's going on without
> CONFIG_USB_XHCI_HCD_DEBUGGING. It's possible the xHCI host never
> notified the driver of the disconnect, or there's a bug in the xHCI hub
> emulation code.
I'm recompiling the kernel with the above configuration setting, and
will send you an output..
thanks for spending time on this issue...
BTW, any ideas on why suspend works with unloading xhci, but hibernate
not working?
Akos
On Thu, 25 Feb 2010, ?kos Mar?y wrote:
> BTW, any ideas on why suspend works with unloading xhci, but hibernate
> not working?
That's a power management issue, not a USB problem. Rafael may be able
to help you. You'll probably want to start a new email thread on the
linux-pm mailing list.
Alan Stern
Sarah,
> True. I can't tell exactly what's going on without
> CONFIG_USB_XHCI_HCD_DEBUGGING. It's possible the xHCI host never
> notified the driver of the disconnect, or there's a bug in the xHCI hub
> emulation code.
after having turned this option on in the kernel, this is what I get
when plugging in the device:
Feb 25 23:32:14 tonkachi kernel: [ 100.473783] Registered led device:
iwl-phy0::radio
Feb 25 23:32:14 tonkachi kernel: [ 100.473812] Registered led device:
iwl-phy0::assoc
Feb 25 23:32:14 tonkachi kernel: [ 100.473839] Registered led device:
iwl-phy0::RX
Feb 25 23:32:14 tonkachi kernel: [ 100.473864] Registered led device:
iwl-phy0::TX
Feb 25 23:32:14 tonkachi kernel: [ 100.497848] usb 2-4: new high speed
USB device using xhci_hcd and address 0
Feb 25 23:32:14 tonkachi kernel: [ 100.520591] usb 2-4: New USB device
found, idVendor=058f, idProduct=6254
Feb 25 23:32:14 tonkachi kernel: [ 100.520595] usb 2-4: New USB device
strings: Mfr=0, Product=0, SerialNumber=0
Feb 25 23:32:14 tonkachi kernel: [ 100.520680] usb 2-4: configuration
#1 chosen from 1 choice
Feb 25 23:32:14 tonkachi kernel: [ 100.520732] usb 2-4: ep 0x81 -
rounding interval to 2048 microframes
Feb 25 23:32:14 tonkachi kernel: [ 100.522403] hub 2-4:1.0: USB hub found
Feb 25 23:32:14 tonkachi kernel: [ 100.522930] xhci_hcd 0000:02:00.0:
WARN: short transfer on control ep
Feb 25 23:32:14 tonkachi kernel: [ 100.523156] hub 2-4:1.0: 3 ports
detected
Feb 25 23:32:14 tonkachi kernel: [ 100.825758] usb 2-4.1: new high
speed USB device using xhci_hcd and address 0
Feb 25 23:32:14 tonkachi kernel: [ 100.848327] xhci_hcd 0000:02:00.0:
WARN: short transfer on control ep
Feb 25 23:32:14 tonkachi kernel: [ 100.849375] xhci_hcd 0000:02:00.0:
WARN: short transfer on control ep
Feb 25 23:32:14 tonkachi kernel: [ 100.850370] xhci_hcd 0000:02:00.0:
WARN: short transfer on control ep
Feb 25 23:32:14 tonkachi kernel: [ 100.851366] xhci_hcd 0000:02:00.0:
WARN: short transfer on control ep
Feb 25 23:32:14 tonkachi kernel: [ 100.851782] usb 2-4.1: New USB
device found, idVendor=152d, idProduct=2339
Feb 25 23:32:14 tonkachi kernel: [ 100.851785] usb 2-4.1: New USB
device strings: Mfr=1, Product=2, SerialNumber=5
Feb 25 23:32:14 tonkachi kernel: [ 100.851790] usb 2-4.1: Product: USB
to ATA/ATAPI Bridge
Feb 25 23:32:14 tonkachi kernel: [ 100.851792] usb 2-4.1: Manufacturer:
JMicron
Feb 25 23:32:14 tonkachi kernel: [ 100.851795] usb 2-4.1: SerialNumber:
6A1713351FFF
Feb 25 23:32:14 tonkachi kernel: [ 100.851873] usb 2-4.1: configuration
#1 chosen from 1 choice
Feb 25 23:32:14 tonkachi kernel: [ 100.854283] xhci_hcd 0000:02:00.0:
WARN: short transfer on control ep
Feb 25 23:32:14 tonkachi kernel: [ 100.855037] xhci_hcd 0000:02:00.0:
WARN: short transfer on control ep
Feb 25 23:32:14 tonkachi kernel: [ 100.879271] Initializing USB Mass
Storage driver...
Feb 25 23:32:14 tonkachi kernel: [ 100.879988] scsi6 : SCSI emulation
for USB Mass Storage devices
Feb 25 23:32:14 tonkachi kernel: [ 100.880141] usbcore: registered new
interface driver usb-storage
Feb 25 23:32:14 tonkachi kernel: [ 100.880147] USB Mass Storage support
registered.
Feb 25 23:32:19 tonkachi kernel: [ 105.884853] scsi 6:0:0:0: CD-ROM
hp DVDRAM GT20L DC05 PQ: 0 ANSI: 0
Feb 25 23:32:19 tonkachi kernel: <0: `MEM_WRITE_DWORD(3'b000,
32'hffffc90000hi0 00000.1fevhc anl0d0i 02-:e0x t2);
Feb 25 23:32:19 tonkachi kernel: x1.0: _ca0 00000000 01000000 02038000
Feb 25 23:32:19 tonkachi kernel: x1.0: `MEM_W_c70 000000 f__h:had
c2c]:00-:e0x t3);
Feb 25 23:32:19 tonkachi kernel: _tist us:i 00Tx] 5b78b073ndxh0.0
_c.]70h ]00t0:xhcf3) 754'hf);x.23000:02:00.0: `MEM_WRITE_DWORD(3'b000,
32'hffffc90000c7c024, 32'h8, 4'hf);
Feb 25 23:32:19 tonkachi kernel: 603n00nt 0<05.898876] xhci_hcd
0000:00h00MEM_WRITE_10 wn.8eh:0c>78 0 i_0 013Ue9:020)
Feb 25 23:32:19 tonkachi kernel: 02:00.i0h00.0: New dequeue pointer =
0x375b78d0 (DMA)
Feb 25 23:32:19 tonkachi kernel: 19
Feb 25 23:32:19 tonkachi kernel: 3d07` 300ee e_ i7c67 o5.899445] 9fc
Crned from h:0t8]__0td h096:: cs0000c63,v 005a/ed scsi 0
0dd00M_WRITE_DWORD(3'b000, 32'h50ns 01en2 ]]h00s0n/27 00670009[
903541] xhci0 00:_WRITE_DWORD(3'b000, 32'hffffc90000c7c024, 32'h8, 4'hf);
Feb 25 23:32:19 tonkachi kernel: n (D005.r0000:024 0
0dd00M_WRITE_DWORD(3'b000, 32'hffffc950ns0en2 ]]h00s0n/57 0067009[
907215] x0 0_WRITE_DWORD(3'b000, 32'hffffc90000c7c024, 32'h8, 4'hf);
Feb 25 23:32:19 tonkachi kernel: = 0i_hcd 0000:02:00.0:
`MEM_WRITE_DWORD(3'b000, 32'hffffc90000c7c808, 32'h3, 4'hf);
Feb 25 23:32:19 tonkachi kernel: n (D00090.rom0000:024 0
0dd00M_WRITE_DWORD(3'b000, 32'hffffc90000c50ns 09en2 ]]h00s0n/97
00670009[ 910899] x0 00:_WRITE_DWORD(3'b000, 32'hffffc90000c7c024,
32'h8, 4'hf);
Feb 25 23:32:19 tonkachi kernel: T5nt d:h0 c:0s0n/57 00.0I67009[
916128] x0 00:0_WRITE_DWORD(3'b000, 32'hffffc90000c7c024, 32'h8, 4'hf);
Feb 25 23:32:19 tonkachi kernel: 6 3]0D0xhci8hci_
0000:02:040]1000:02:00.0: In handle_tx_event
Feb 25 23:32:19 tonkachi kernel: [ 105.922881] xhci_hcd0hch0:
`MEM_WRI>f0OS _tx.0:c0990c_xh.0 8b0002c= 0>DMA)>[ 105.92000000ht0lo>2f
:n0e0cf0c40.09400[._> ee_1<0a1r000c700.xhci_hcd 0000:02:00.0: Endpoint
state = 0x1
Feb 25 23:32:19 tonkachi kernel: 2:0:00.0: In xhci_handle_event
Feb 25 23:32:19 tonkachi kernel: 19b lnd 6] :000 020300.0ic_ nn
=f0x10[10105.926503] xhci_hcd 0000:02:00.0: Event ring deq = 02hc::;3(:
c7c.r80h 1_d7 10xx.]0477x.:EWx 6:00>[ 5750c>000.0: @37805720 375b7a30
00`7>ff5.936369] 7dx0 0_e0 :434h1:EWx 6:007>[300700000.0: @37805730 37
<h05.936744] xhci_hcd 0000:02:00.0: xhci_handle_event - OS owns TRB
Feb 25 23:32:19 tonkachi kernel:
Feb 25 23:32:19 tonkachi kernel: 025<)nE_DW0vev8 urb= 0x1
Feb 25 23:32:19 tonkachi kernel: <750.07<h05.937960] xhci_hcd
0000:02:00.0: xhci_handle_event - OS owns TRB
Feb 25 23:32:19 tonkachi kernel:
Feb 25 23:32:19 tonkachi kernel: 025<)[nE_D0veve8 urb= 0x1
Feb 25 23:32:19 tonkachi kernel:
Feb 25 23:32:19 tonkachi kernel: 025<)[nE_D0vev8 urb= 0x1
Feb 25 23:32:19 tonkachi kernel: <750c.07<h05.945270] xhci_hcd
0000:02:00.0: xhci_handle_event - OS owns TRB
Feb 25 23:32:19 tonkachi kernel: se0D]<7>090<c xh: `MEM0'vcd
0000:02:00.0: xhci_handle_event - calling handle_tx_event
Feb 25 23:32:19 tonkachi kernel: <0.0: @37805430 375b7ad0 0,T:7>xhih [c
Feb 25 23:32:19 tonkachi kernel: 7x140 i6b 6:00l38,0.0:3]
xhci_01ie5R'vecd 0000:02:00.0: xhci_handle_event - calling handle_tx_event
Feb 25 23:32:19 tonkachi kernel: se0( 0:020i_h t dma_hcd 0000:02:00.0:
`M50537805460 375i8R 05c 005.0 7c0 c0c[f0:
Feb 25 23:32:19 tonkachi kernel: <370oinhcd 005107805470 375b7b00
00000000 01000000 02038001
Feb 25 23:32:19 tonkachi kernel: <37800ointhcd 0000:15.17805480
375d61f_,DI5d00019
Feb 25 23:32:19 tonkachi kernel: 1>d4x2d0i f: c
Feb 25 23:32:19 tonkachi kernel: 370oinhcd 0000:2i
Feb 25 23:32:19 tonkachi kernel: 00f[ 02:00.0: xhci_handle_event -
calling handle_tx_event
Feb 25 23:32:19 tonkachi kernel: 370ohcd 0051078054c0 375b7b30 00000000
01000000 02038001
Feb 25 23:32:20 tonkachi kernel: 37800ohcd 00005.178054d0 _,DI5.d 00009
Feb 25 23:32:20 tonkachi kernel: 1>d8x2d0i f:c
Feb 25 23:32:20 tonkachi kernel: 3780x4en = 0f1uh:5178054e0 375b7b40
00000000 01000000 0203800_,DI5d 00019
Feb 25 23:32:20 tonkachi kernel: 1>d62c0c f: Gc
Feb 25 23:32:20 tonkachi kernel: 37800oinhcd 0000:5.178054f0 375b7b50
00000000 01000000 02038001
Feb 25 23:32:20 tonkachi kernel: 1>d3x2c0c f: c
Feb 25 23:32:20 tonkachi kernel: 37800ohcd 0000:02:00.0: `M5.17805500
_,DIn5d00029
Feb 25 23:32:20 tonkachi kernel: 1>d8x2d0i f:
Feb 25 23:32:20 tonkachi kernel: 3780ohcd 00084nt0'3n 0000:02:00.0:
xhci_handle_event - calling handle_tx_event
Feb 25 23:32:20 tonkachi kernel: 60#hc
Feb 25 23:32:20 tonkachi kernel: : d A) 105.965349] xhci_hcd0cic:
`MEM_WR[c.S1tx00i
Feb 25 23:32:20 tonkachi kernel: 669dh8c001,a0:7 0[MA[ 10hh0:
`MEM_WRITE_DWORD(3'b000, 32'hffffc90000c7c024, 32'h8, 4'hf);
Feb 25 23:32:20 tonkachi kernel: [ 106.005103] xhci_hcd 0000:02:00.0:
WARN: Stalled endpoint
Feb 25 23:32:22 tonkachi kernel: <7008.h8Dhr:0:0248 ]0 158e 3x)
0nsf:02:00.0: Event ring deq =t867n = 13, sa008hc11Dhr:0:0209 ]0 198pe
00s)n:02:0t97cn = 31, status = 0
Feb 25 23:32:22 tonkachi kernel: 0i4<1= TfC (f>es uhcd 0000: f86c0, len
= 18, status = 0
with un-plugging, I get:
Feb 25 23:33:07 tonkachi kernel: [ 153.205311] xhci_hcd 0000:02:00.0:
WARN: transfer error on endpoint
Feb 25 23:33:08 tonkachi kernel: [ 154.008265] xhci_hcd 0000:02:00.0:
WARN: transfer error on endpoint
Feb 25 23:33:08 tonkachi kernel: [ 154.008995] xhci_hcd 0000:02:00.0:
WARN: transfer error on endpoint
at this point, rmmod xhci doesn't even work anymore, I get stuff during
/ around the rmmod like:
Feb 25 23:34:24 tonkachi kernel: [ 230.133711] xhci_hcd 0000:02:00.0:
remove, state 1
Feb 25 23:34:24 tonkachi kernel: [ 230.133727] usb usb2: USB
disconnect, address 1
Feb 25 23:34:24 tonkachi kernel: [ 230.133731] usb 2-4: USB disconnect,
address 2
Feb 25 23:34:24 tonkachi kernel: [ 230.133735] usb 2-4.1: USB
disconnect, address 3
at the end, with rmmod still not returning, but doing a re-plug, I get:
Feb 25 23:36:37 tonkachi kernel: [ 363.295298] rmmod D
ffff88002834fa28 0 2818 2802 0x00000004
Feb 25 23:36:37 tonkachi kernel: [ 363.295307] ffff88022f581b88
0000000000000086 0000000000000000 0000000000000282
Feb 25 23:36:37 tonkachi kernel: [ 363.295315] 00000000fffffffe
ffffffff81a0bf78 ffff88023fc3c8a0 00000000ffffe4be
Feb 25 23:36:37 tonkachi kernel: [ 363.295323] ffff8802332403c0
ffff88022f581fd8 000000000000fa28 ffff8802332403c0
Feb 25 23:36:37 tonkachi kernel: [ 363.295331] Call Trace:
Feb 25 23:36:37 tonkachi kernel: [ 363.295344] [<ffffffff813b3ff5>]
usb_kill_urb+0x85/0xc0
Feb 25 23:36:37 tonkachi kernel: [ 363.295353] [<ffffffff8107d8b0>] ?
autoremove_wake_function+0x0/0x40
Feb 25 23:36:37 tonkachi kernel: [ 363.295360] [<ffffffff813b43c6>] ?
usb_get_urb+0x16/0x20
Feb 25 23:36:37 tonkachi kernel: [ 363.295367] [<ffffffff813b27db>]
usb_hcd_flush_endpoint+0xcb/0x1b0
Feb 25 23:36:37 tonkachi kernel: [ 363.295374] [<ffffffff813b4d18>]
usb_disable_endpoint+0x58/0x90
Feb 25 23:36:37 tonkachi kernel: [ 363.295381] [<ffffffff813b4dd9>]
usb_disable_device+0x89/0x1f0
Feb 25 23:36:37 tonkachi kernel: [ 363.295388] [<ffffffff813adc3d>]
usb_disconnect+0xfd/0x180
Feb 25 23:36:37 tonkachi kernel: [ 363.295394] [<ffffffff813adbff>]
usb_disconnect+0xbf/0x180
Feb 25 23:36:37 tonkachi kernel: [ 363.295400] [<ffffffff813b1a5d>]
usb_remove_hcd+0xcd/0x130
Feb 25 23:36:37 tonkachi kernel: [ 363.295408] [<ffffffff813c2236>]
usb_hcd_pci_remove+0x26/0xa0
Feb 25 23:36:37 tonkachi kernel: [ 363.295416] [<ffffffff812a0fdf>]
pci_device_remove+0x2f/0x60
Feb 25 23:36:37 tonkachi kernel: [ 363.295433] [<ffffffff81334bd3>]
__device_release_driver+0x53/0xb0
Feb 25 23:36:37 tonkachi kernel: [ 363.295440] [<ffffffff81334cf8>]
driver_detach+0xc8/0xd0
Feb 25 23:36:37 tonkachi kernel: [ 363.295448] [<ffffffff81333c65>]
bus_remove_driver+0x85/0xe0
Feb 25 23:36:37 tonkachi kernel: [ 363.295456] [<ffffffff813352ba>]
driver_unregister+0x5a/0x90
Feb 25 23:36:37 tonkachi kernel: [ 363.295464] [<ffffffff812a12d0>]
pci_unregister_driver+0x40/0xb0
Feb 25 23:36:37 tonkachi kernel: [ 363.295476] [<ffffffffa0048b80>]
xhci_unregister_pci+0x10/0x20 [xhci]
Feb 25 23:36:37 tonkachi kernel: [ 363.295485] [<ffffffffa004e459>]
xhci_hcd_cleanup+0x9/0xb [xhci]
Feb 25 23:36:37 tonkachi kernel: [ 363.295493] [<ffffffff81095768>]
sys_delete_module+0x1a8/0x270
Feb 25 23:36:37 tonkachi kernel: [ 363.295500] [<ffffffff81081bd9>] ?
up_read+0x9/0x10
Feb 25 23:36:37 tonkachi kernel: [ 363.295510] [<ffffffff81011f82>]
system_call_fastpath+0x16/0x1b
please let me know what other debugging I should do..
Akos
On Thu, Feb 25, 2010 at 11:37:36PM +0100, ?kos Mar?y wrote:
> Sarah,
>
> > True. I can't tell exactly what's going on without
> > CONFIG_USB_XHCI_HCD_DEBUGGING. It's possible the xHCI host never
> > notified the driver of the disconnect, or there's a bug in the xHCI hub
> > emulation code.
>
> after having turned this option on in the kernel, this is what I get
> when plugging in the device:
>
> Feb 25 23:32:14 tonkachi kernel: [ 100.473783] Registered led device:
> iwl-phy0::radio
> Feb 25 23:32:14 tonkachi kernel: [ 100.473812] Registered led device:
> iwl-phy0::assoc
> Feb 25 23:32:14 tonkachi kernel: [ 100.473839] Registered led device:
> iwl-phy0::RX
> Feb 25 23:32:14 tonkachi kernel: [ 100.473864] Registered led device:
> iwl-phy0::TX
> Feb 25 23:32:14 tonkachi kernel: [ 100.497848] usb 2-4: new high speed
> USB device using xhci_hcd and address 0
> Feb 25 23:32:14 tonkachi kernel: [ 100.520591] usb 2-4: New USB device
> found, idVendor=058f, idProduct=6254
> Feb 25 23:32:14 tonkachi kernel: [ 100.520595] usb 2-4: New USB device
> strings: Mfr=0, Product=0, SerialNumber=0
> Feb 25 23:32:14 tonkachi kernel: [ 100.520680] usb 2-4: configuration
> #1 chosen from 1 choice
> Feb 25 23:32:14 tonkachi kernel: [ 100.520732] usb 2-4: ep 0x81 -
> rounding interval to 2048 microframes
> Feb 25 23:32:14 tonkachi kernel: [ 100.522403] hub 2-4:1.0: USB hub found
> Feb 25 23:32:14 tonkachi kernel: [ 100.522930] xhci_hcd 0000:02:00.0:
> WARN: short transfer on control ep
> Feb 25 23:32:14 tonkachi kernel: [ 100.523156] hub 2-4:1.0: 3 ports
> detected
> Feb 25 23:32:14 tonkachi kernel: [ 100.825758] usb 2-4.1: new high
> speed USB device using xhci_hcd and address 0
> Feb 25 23:32:14 tonkachi kernel: [ 100.848327] xhci_hcd 0000:02:00.0:
> WARN: short transfer on control ep
> Feb 25 23:32:14 tonkachi kernel: [ 100.849375] xhci_hcd 0000:02:00.0:
> WARN: short transfer on control ep
> Feb 25 23:32:14 tonkachi kernel: [ 100.850370] xhci_hcd 0000:02:00.0:
> WARN: short transfer on control ep
> Feb 25 23:32:14 tonkachi kernel: [ 100.851366] xhci_hcd 0000:02:00.0:
> WARN: short transfer on control ep
> Feb 25 23:32:14 tonkachi kernel: [ 100.851782] usb 2-4.1: New USB
> device found, idVendor=152d, idProduct=2339
> Feb 25 23:32:14 tonkachi kernel: [ 100.851785] usb 2-4.1: New USB
> device strings: Mfr=1, Product=2, SerialNumber=5
> Feb 25 23:32:14 tonkachi kernel: [ 100.851790] usb 2-4.1: Product: USB
> to ATA/ATAPI Bridge
> Feb 25 23:32:14 tonkachi kernel: [ 100.851792] usb 2-4.1: Manufacturer:
> JMicron
> Feb 25 23:32:14 tonkachi kernel: [ 100.851795] usb 2-4.1: SerialNumber:
> 6A1713351FFF
> Feb 25 23:32:14 tonkachi kernel: [ 100.851873] usb 2-4.1: configuration
> #1 chosen from 1 choice
> Feb 25 23:32:14 tonkachi kernel: [ 100.854283] xhci_hcd 0000:02:00.0:
> WARN: short transfer on control ep
> Feb 25 23:32:14 tonkachi kernel: [ 100.855037] xhci_hcd 0000:02:00.0:
> WARN: short transfer on control ep
> Feb 25 23:32:14 tonkachi kernel: [ 100.879271] Initializing USB Mass
> Storage driver...
> Feb 25 23:32:14 tonkachi kernel: [ 100.879988] scsi6 : SCSI emulation
> for USB Mass Storage devices
> Feb 25 23:32:14 tonkachi kernel: [ 100.880141] usbcore: registered new
> interface driver usb-storage
> Feb 25 23:32:14 tonkachi kernel: [ 100.880147] USB Mass Storage support
> registered.
> Feb 25 23:32:19 tonkachi kernel: [ 105.884853] scsi 6:0:0:0: CD-ROM
> hp DVDRAM GT20L DC05 PQ: 0 ANSI: 0
> Feb 25 23:32:19 tonkachi kernel: <0: `MEM_WRITE_DWORD(3'b000,
> 32'hffffc90000hi0 00000.1fevhc anl0d0i 02-:e0x t2);
> Feb 25 23:32:19 tonkachi kernel: x1.0: _ca0 00000000 01000000 02038000
> Feb 25 23:32:19 tonkachi kernel: x1.0: `MEM_W_c70 000000 f__h:had
> c2c]:00-:e0x t3);
> Feb 25 23:32:19 tonkachi kernel: _tist us:i 00Tx] 5b78b073ndxh0.0
> _c.]70h ]00t0:xhcf3) 754'hf);x.23000:02:00.0: `MEM_WRITE_DWORD(3'b000,
> 32'hffffc90000c7c024, 32'h8, 4'hf);
> Feb 25 23:32:19 tonkachi kernel: 603n00nt 0<05.898876] xhci_hcd
> 0000:00h00MEM_WRITE_10 wn.8eh:0c>78 0 i_0 013Ue9:020)
> Feb 25 23:32:19 tonkachi kernel: 02:00.i0h00.0: New dequeue pointer =
> 0x375b78d0 (DMA)
> Feb 25 23:32:19 tonkachi kernel: 19
> Feb 25 23:32:19 tonkachi kernel: 3d07` 300ee e_ i7c67 o5.899445] 9fc
It looks like you're getting log corruption from the xHCI driver being
too verbose now. :( I've been meaning to make a log level patch for the
driver and cut out the less-than-useful bits for while. Let me do a
quick pass at that so we can get the interesting information.
> with un-plugging, I get:
>
> Feb 25 23:33:07 tonkachi kernel: [ 153.205311] xhci_hcd 0000:02:00.0:
> WARN: transfer error on endpoint
> Feb 25 23:33:08 tonkachi kernel: [ 154.008265] xhci_hcd 0000:02:00.0:
> WARN: transfer error on endpoint
> Feb 25 23:33:08 tonkachi kernel: [ 154.008995] xhci_hcd 0000:02:00.0:
> WARN: transfer error on endpoint
There should be a lot more debugging here. Perhaps you were collecting
only the warning-level kernel messages? Did you send the full dmesg
from /var/log/kern.log or run `dmesg -n 8` before capturing the dmesg
input?
Actually, I wonder if 2.6.32 stable needs commit bcef3fd from 2.6.33.
If the xHCI driver wasn't cleaning up the endpoint rings properly after
a transfer error, I suppose the hardware could get wedged.
> at this point, rmmod xhci doesn't even work anymore, I get stuff during
> / around the rmmod like:
>
> Feb 25 23:34:24 tonkachi kernel: [ 230.133711] xhci_hcd 0000:02:00.0:
> remove, state 1
Aw, man, it looks like your xHCI disconnected from the bus. Something
was seriously wrong with the hardware. Still, the xHCI driver should
have failed gracefully in that case. That should have been handled by
commits c526d0d, e34b2fb, and e4ab05d, which are in 2.6.32 and 2.6.33.
> Feb 25 23:34:24 tonkachi kernel: [ 230.133727] usb usb2: USB
> disconnect, address 1
> Feb 25 23:34:24 tonkachi kernel: [ 230.133731] usb 2-4: USB disconnect,
> address 2
> Feb 25 23:34:24 tonkachi kernel: [ 230.133735] usb 2-4.1: USB
> disconnect, address 3
>
>
>
> at the end, with rmmod still not returning, but doing a re-plug, I get:
>
>
> Feb 25 23:36:37 tonkachi kernel: [ 363.295298] rmmod D
> ffff88002834fa28 0 2818 2802 0x00000004
> Feb 25 23:36:37 tonkachi kernel: [ 363.295307] ffff88022f581b88
> 0000000000000086 0000000000000000 0000000000000282
> Feb 25 23:36:37 tonkachi kernel: [ 363.295315] 00000000fffffffe
> ffffffff81a0bf78 ffff88023fc3c8a0 00000000ffffe4be
> Feb 25 23:36:37 tonkachi kernel: [ 363.295323] ffff8802332403c0
> ffff88022f581fd8 000000000000fa28 ffff8802332403c0
> Feb 25 23:36:37 tonkachi kernel: [ 363.295331] Call Trace:
> Feb 25 23:36:37 tonkachi kernel: [ 363.295344] [<ffffffff813b3ff5>]
> usb_kill_urb+0x85/0xc0
> Feb 25 23:36:37 tonkachi kernel: [ 363.295353] [<ffffffff8107d8b0>] ?
> autoremove_wake_function+0x0/0x40
> Feb 25 23:36:37 tonkachi kernel: [ 363.295360] [<ffffffff813b43c6>] ?
> usb_get_urb+0x16/0x20
> Feb 25 23:36:37 tonkachi kernel: [ 363.295367] [<ffffffff813b27db>]
> usb_hcd_flush_endpoint+0xcb/0x1b0
> Feb 25 23:36:37 tonkachi kernel: [ 363.295374] [<ffffffff813b4d18>]
> usb_disable_endpoint+0x58/0x90
> Feb 25 23:36:37 tonkachi kernel: [ 363.295381] [<ffffffff813b4dd9>]
> usb_disable_device+0x89/0x1f0
> Feb 25 23:36:37 tonkachi kernel: [ 363.295388] [<ffffffff813adc3d>]
> usb_disconnect+0xfd/0x180
> Feb 25 23:36:37 tonkachi kernel: [ 363.295394] [<ffffffff813adbff>]
> usb_disconnect+0xbf/0x180
> Feb 25 23:36:37 tonkachi kernel: [ 363.295400] [<ffffffff813b1a5d>]
> usb_remove_hcd+0xcd/0x130
> Feb 25 23:36:37 tonkachi kernel: [ 363.295408] [<ffffffff813c2236>]
> usb_hcd_pci_remove+0x26/0xa0
> Feb 25 23:36:37 tonkachi kernel: [ 363.295416] [<ffffffff812a0fdf>]
> pci_device_remove+0x2f/0x60
> Feb 25 23:36:37 tonkachi kernel: [ 363.295433] [<ffffffff81334bd3>]
> __device_release_driver+0x53/0xb0
> Feb 25 23:36:37 tonkachi kernel: [ 363.295440] [<ffffffff81334cf8>]
> driver_detach+0xc8/0xd0
> Feb 25 23:36:37 tonkachi kernel: [ 363.295448] [<ffffffff81333c65>]
> bus_remove_driver+0x85/0xe0
> Feb 25 23:36:37 tonkachi kernel: [ 363.295456] [<ffffffff813352ba>]
> driver_unregister+0x5a/0x90
> Feb 25 23:36:37 tonkachi kernel: [ 363.295464] [<ffffffff812a12d0>]
> pci_unregister_driver+0x40/0xb0
> Feb 25 23:36:37 tonkachi kernel: [ 363.295476] [<ffffffffa0048b80>]
> xhci_unregister_pci+0x10/0x20 [xhci]
> Feb 25 23:36:37 tonkachi kernel: [ 363.295485] [<ffffffffa004e459>]
> xhci_hcd_cleanup+0x9/0xb [xhci]
> Feb 25 23:36:37 tonkachi kernel: [ 363.295493] [<ffffffff81095768>]
> sys_delete_module+0x1a8/0x270
> Feb 25 23:36:37 tonkachi kernel: [ 363.295500] [<ffffffff81081bd9>] ?
> up_read+0x9/0x10
> Feb 25 23:36:37 tonkachi kernel: [ 363.295510] [<ffffffff81011f82>]
> system_call_fastpath+0x16/0x1b
If the hardware wasn't responding properly to commands, then URBs
wouldn't have been able to be killed, the USB core would have sat around
waiting on those URBs, and rmmod could never exit. I need a more
detailed log to figure out exactly why the hardware is wedged though.
Let me make the less-verbose debugging patch so you don't get log
corruption, and then we'll see what's going on.
Sarah Sharp
Hi ?kos~
On Thu, Feb 25, 2010 at 6:36 AM, ?kos Mar?y <[email protected]> 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?
>
> 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...
the whole system freezes for about 5 seconds or more?
I meet a very similar issue before on HP Envy 15 laptop when I plugged
usb device on xhci port.
My problem was BIOS still controlled xhci host controller.
Maybe you can try this patch.
http://markmail.org/message/vqcbzks4gnbrlir3
>
> or I plug in an external USB DVD drive - but if I unplug it, it is still
> listed in lsusb..
>
>
> Akos
>
> --
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to [email protected]
> More majordomo info at ?http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at ?http://www.tux.org/lkml/
>
--
Best Regards,
Edward
On Thu, 25 Feb 2010, Sarah Sharp wrote:
> > at this point, rmmod xhci doesn't even work anymore, I get stuff during
> > / around the rmmod like:
> >
> > Feb 25 23:34:24 tonkachi kernel: [ 230.133711] xhci_hcd 0000:02:00.0:
> > remove, state 1
>
> Aw, man, it looks like your xHCI disconnected from the bus. Something
> was seriously wrong with the hardware.
Why do you say that? Isn't this exactly the sort of thing you expect
to see in the log when xhci-hcd is unloaded?
Alan Stern
On Fri, Feb 26, 2010 at 11:12:50AM -0500, Alan Stern wrote:
> On Thu, 25 Feb 2010, Sarah Sharp wrote:
>
> > > at this point, rmmod xhci doesn't even work anymore, I get stuff during
> > > / around the rmmod like:
> > >
> > > Feb 25 23:34:24 tonkachi kernel: [ 230.133711] xhci_hcd 0000:02:00.0:
> > > remove, state 1
> >
> > Aw, man, it looks like your xHCI disconnected from the bus. Something
> > was seriously wrong with the hardware.
>
> Why do you say that? Isn't this exactly the sort of thing you expect
> to see in the log when xhci-hcd is unloaded?
Yes, I forgot he was unloading the driver. That's normal then.
Sarah Sharp
Sarah,
> Actually, I wonder if 2.6.32 stable needs commit bcef3fd from 2.6.33.
> If the xHCI driver wasn't cleaning up the endpoint rings properly after
> a transfer error, I suppose the hardware could get wedged.
I see. where would I get this commit from? I have to stick with 2.6.32,
as I'm using the binary ATI video driver, which doesn't work with 2.6.33...
> If the hardware wasn't responding properly to commands, then URBs
> wouldn't have been able to be killed, the USB core would have sat around
> waiting on those URBs, and rmmod could never exit. I need a more
> detailed log to figure out exactly why the hardware is wedged though.
> Let me make the less-verbose debugging patch so you don't get log
> corruption, and then we'll see what's going on.
let me know how I can use this..
Akos
Edward,
> the whole system freezes for about 5 seconds or more?
> I meet a very similar issue before on HP Envy 15 laptop when I plugged
> usb device on xhci port.
> My problem was BIOS still controlled xhci host controller.
> Maybe you can try this patch.
> http://markmail.org/message/vqcbzks4gnbrlir3
thanks, indeed, this seems to have solved the freezing issue!
Akos