Message ID | 5142094D.2070305@fold.natur.cuni.cz (mailing list archive) |
---|---|
State | New, archived |
Delegated to: | Bjorn Helgaas |
Headers | show |
Hi Martin, I'm really having trouble following you here. Please don't try to tell me what you think the root cause of the issue is. Just tell me exactly (in a paragraph or less) what your symptoms are. Sending lots of log files and lsusb output at me isn't helpful if I don't know what your issue is. Sarah Sharp On Thu, Mar 14, 2013 at 06:30:53PM +0100, Martin Mokrejs wrote: > [resend, no dmesg attached] > > Hi, > happened to me again that I plugged in some devcie into my USB3 socket > in my laptop (usually use an external HUB). Don't believe this is a new > issue as a whole, I am facing this time to time since 3.3 time when I bought > the laptop. > But now, I realized the first device works but subsequently plugged in > devices do not show up until until I run 'lsusb -vv'. Simple 'lsusb -v' > or 'lsusb -t' is not enough. The port starts to work after dmesg logs: > > > [ 1445.597641] pcieport 0000:00:1c.4: PME# disabled > [ 1445.617667] xhci_hcd 0000:0b:00.0: PME# disabled > > I believe lsusb -vv while querying for the detailed device info triggers > a fix. > > Funny, but maybe this will help us to understand why my express card slot > somehow relates to the USB3 proivided by the TexasInstruments chip. This > is a SandyBridge-based Dell Vostro 3550 laptop. I should add that on the usb > mailing list about a year ago some TexasInstruments developer published that > they had a hardware bug in a "USB redriver", and as my laptop was made in > fall 2011 I am likely having having the buggy HW. If I remember right, the > report was about the problem that once you pluging a USB2 device into the XHCI > slot, subsequently plugged in USB3 devices won't negotiate at SuperSpeed until > you power off computer. So, I think I face a different issue but had to mention > this. > > I use pcie_aspm=off on my kernel command line. I tried to catch some usb traffic > on the dead port but the file from usbmon is really empty until I do the > 'lsusb -vv'. I tried to turn off the usb powersaving at runtime but I do not > have the file to do: > > # echo -n -1 > /sys/bus/usb/devices/3-0\:1.0/power/autosuspend > > :( > > # ls -la /sys/bus/usb/devices/3-0\:1.0/power/ > total 0 > drwxr-xr-x 2 root root 0 Mar 14 13:11 . > drwxr-xr-x 6 root root 0 Mar 14 13:58 .. > -rw-r--r-- 1 root root 4096 Mar 14 13:11 async > -r--r--r-- 1 root root 4096 Mar 14 13:11 runtime_active_kids > -r--r--r-- 1 root root 4096 Mar 14 13:11 runtime_enabled > -r--r--r-- 1 root root 4096 Mar 14 13:11 runtime_status > -r--r--r-- 1 root root 4096 Mar 14 13:11 runtime_usage > # > > I feel related could be patches under thread: "usb: add usb port auto power off mechanism" > > > Below is a dmesg since a cold boot. I plugged in a mouse into the USB3 socket. > > [ 91.463285] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_suspend: 0 > [ 91.463377] xhci_hcd 0000:0b:00.0: PME# enabled > [ 447.389700] xhci_hcd 0000:0b:00.0: PME# disabled > [ 447.389711] xhci_hcd 0000:0b:00.0: enabling bus mastering > [ 447.389787] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_resume: 0 > [ 447.389819] usb usb3: usb wakeup-resume > > Was detected. Unplugged the mouse. > > [ 459.600056] usb 3-2: USB disconnect, device number 2 > [ 459.600058] usb 3-2: unregistering device > [ 459.600059] usb 3-2: unregistering interface 3-2:1.0 > [ 459.600622] xhci_hcd 0000:0b:00.0: shutdown urb ffff88040a641870 ep1in-intr > [ 459.702564] usb 3-2: usb_disable_device nuking all URBs > [ 459.707948] usb 3-2: Successful Endpoint Configure command > [ 459.860892] hub 3-0:1.0: debounce: port 2: total 100ms stable 100ms status 0x100 > [ 459.860910] hub 3-0:1.0: hub_suspend > [ 459.860917] usb usb3: bus auto-suspend, wakeup 1 > [ 459.860981] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_suspend: 0 > [ 459.861070] xhci_hcd 0000:0b:00.0: PME# enabled > > Then I put the mouse back, I think it was not detected after until I did the lsusb > trick. I am not sure, sorry, but is not that important. I was repeating test once > again and just forgot now this detail. So below just that the mouse got detected, > either thanks to lsusb -vv or not. > > [ 536.745422] xhci_hcd 0000:0b:00.0: PME# disabled > [ 536.745435] xhci_hcd 0000:0b:00.0: enabling bus mastering > [ 536.745487] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_resume: 0 > [ 536.745493] usb usb3: usb auto-resume > [ 536.745509] hub 3-0:1.0: hub_resume > [ 536.745579] hub 3-0:1.0: port 2: status 0301 change 0001 > > Then a mouse disconnect: > > [ 652.232958] usb 3-2: USB disconnect, device number 3 > [ 652.232960] usb 3-2: unregistering device > [ 652.232961] usb 3-2: unregistering interface 3-2:1.0 > [ 652.233148] xhci_hcd 0000:0b:00.0: shutdown urb ffff88040b1ee288 ep1in-intr > [ 652.333325] usb 3-2: usb_disable_device nuking all URBs > [ 652.337096] usb 3-2: Successful Endpoint Configure command > [ 652.492164] hub 3-0:1.0: debounce: port 2: total 100ms stable 100ms status 0x100 > [ 652.492183] hub 3-0:1.0: hub_suspend > [ 652.492190] usb usb3: bus auto-suspend, wakeup 1 > [ 652.492254] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_suspend: 0 > [ 652.492341] xhci_hcd 0000:0b:00.0: PME# enabled > [ 652.522157] pcieport 0000:00:1c.4: PME# enabled > > [ 688.128198] kmemleak: 1 new suspected memory leaks (see /sys/kernel/debug/kmemleak) > > Note above two things pcieport started to mess in. I you look what xhci_hcd printed > in previous attempts the was NO pcieport involved around, at all. Now, provided > that I reported the kmemleak multiple times this year: > > unreferenced object 0xffff88040b4a0690 (size 256): > comm "swapper/0", pid 1, jiffies 4294937581 (age 17428.760s) > hex dump (first 32 bytes): > 00 00 00 00 ad 4e ad de ff ff ff ff 00 00 00 00 .....N.......... > ff ff ff ff ff ff ff ff d8 9f 57 82 ff ff ff ff ..........W..... > backtrace: > [<ffffffff815fcec7>] kmemleak_alloc+0x21/0x3e > [<ffffffff81117ac4>] slab_post_alloc_hook+0x28/0x2a > [<ffffffff8111a18f>] __kmalloc+0xf3/0x105 > [<ffffffff8132b20c>] kzalloc.constprop.14+0xe/0x10 > [<ffffffff8132b66d>] device_private_init+0x14/0x63 > [<ffffffff8132d790>] dev_set_drvdata+0x19/0x2f > [<ffffffff813f19d1>] i801_probe+0x5e/0x41a > [<ffffffff812924d8>] local_pci_probe+0x39/0x61 > [<ffffffff812936fb>] pci_device_probe+0xc6/0xf3 > [<ffffffff8132dd59>] driver_probe_device+0xa9/0x1c1 > [<ffffffff8132decb>] __driver_attach+0x5a/0x7e > [<ffffffff8132c5f3>] bus_for_each_dev+0x5c/0x88 > [<ffffffff8132d8f6>] driver_attach+0x19/0x1b > [<ffffffff8132d4c6>] bus_add_driver+0xa8/0x1fa > [<ffffffff8132e33d>] driver_register+0x8c/0x106 > [<ffffffff812932f6>] __pci_register_driver+0x5c/0x60 > > I believe this is related to the issue, somehow. > > Now I started usbmon, so lets follow another attempt to repeat the bug. For clarity, > I will plug into the socket a kayboard, and it won't work until I do 'lsusb -vv'. > I pressed then space on the keyboard and that worked immediately (keyboard was dead > until lsusb -vv and also dmesg did not log anything). > > So, lsusb -vv: > > [ 802.986036] pcieport 0000:00:1c.4: PME# disabled > [ 803.016008] xhci_hcd 0000:0b:00.0: PME# disabled > [ 803.016021] xhci_hcd 0000:0b:00.0: enabling bus mastering > [ 803.016078] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_resume: 0 > [ 803.016085] usb usb3: usb auto-resume > [ 803.016103] hub 3-0:1.0: hub_resume > [ 803.016172] hub 3-0:1.0: port 2: status 0301 change 0001 > > unplug of the keyboard: > > [ 821.621331] usb usb4: usb auto-resume > [ 821.621347] hub 4-0:1.0: hub_resume > [ 821.621405] hub 4-0:1.0: state 7 ports 2 chg 0000 evt 0000 > [ 821.622047] hub 4-0:1.0: hub_suspend > [ 821.622053] usb usb4: bus auto-suspend, wakeup 1 > [ 967.433533] hub 3-0:1.0: state 7 ports 2 chg 0000 evt 0004 > [ 967.433768] hub 3-0:1.0: port 2, status 0100, change 0001, 12 Mb/s > [ 967.433771] usb 3-2: USB disconnect, device number 4 > [ 967.433772] usb 3-2: unregistering device > [ 967.433775] usb 3-2: unregistering interface 3-2:1.0 > [ 967.433946] xhci_hcd 0000:0b:00.0: shutdown urb ffff88040a641948 ep1in-intr > [ 967.579130] usb 3-2: usb_disable_device nuking all URBs > [ 967.584494] usb 3-2: Successful Endpoint Configure command > [ 967.798027] hub 3-0:1.0: debounce: port 2: total 100ms stable 100ms status 0x100 > [ 967.798046] hub 3-0:1.0: hub_suspend > [ 967.798075] usb usb3: bus auto-suspend, wakeup 1 > [ 967.798155] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_suspend: 0 > [ 967.798242] xhci_hcd 0000:0b:00.0: PME# enabled > [ 967.828015] pcieport 0000:00:1c.4: PME# enabled > > > You see? pcieport is messing with > 00:1c.4 PCI bridge: Intel Corporation 6 Series/C200 Series Chipset Family PCI Express Root Port 5 (rev b5) (prog-if 00 [Normal decode]) > > I unplugged and replugged the keyboard multiple times and it did not work, so > I connected the mouse used in the very beginning right after cold boot, still > not working. But these were likely logged due to that. > > [ 1063.263014] pcieport 0000:00:1c.4: PME# disabled > [ 1063.272918] pcieport 0000:00:1c.4: PME# enabled > [ 1063.312915] pcieport 0000:00:1c.4: PME# disabled > [ 1063.322906] pcieport 0000:00:1c.4: PME# enabled > [ 1070.132666] pcieport 0000:00:1c.4: PME# disabled > [ 1070.142559] pcieport 0000:00:1c.4: PME# enabled > [ 1070.182601] pcieport 0000:00:1c.4: PME# disabled > [ 1070.192644] pcieport 0000:00:1c.4: PME# enabled > > After doing 'lsusb -vv' I rescued the USB3 socket and it detected the mouse. > > [ 1108.504953] pcieport 0000:00:1c.4: PME# disabled > [ 1108.525010] xhci_hcd 0000:0b:00.0: PME# disabled > [ 1108.525023] xhci_hcd 0000:0b:00.0: enabling bus mastering > [ 1108.525069] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_resume: 0 > [ 1108.525075] usb usb3: usb auto-resume > [ 1108.525094] hub 3-0:1.0: hub_resume > [ 1108.525196] hub 3-0:1.0: port 2: status 0301 change 0001 > > I unplugged the mouse: > > [ 1230.618019] usb 3-2: unregistering device > [ 1230.618020] usb 3-2: unregistering interface 3-2:1.0 > [ 1230.618188] xhci_hcd 0000:0b:00.0: shutdown urb ffff88040b1ee288 ep1in-intr > [ 1230.711764] usb 3-2: usb_disable_device nuking all URBs > [ 1230.715101] usb 3-2: Successful Endpoint Configure command > [ 1230.870763] hub 3-0:1.0: debounce: port 2: total 100ms stable 100ms status 0x100 > [ 1230.870782] hub 3-0:1.0: hub_suspend > [ 1230.870797] usb usb3: bus auto-suspend, wakeup 1 > [ 1230.870862] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_suspend: 0 > [ 1230.870950] xhci_hcd 0000:0b:00.0: PME# enabled > [ 1230.900730] pcieport 0000:00:1c.4: PME# enabled > > > In summary, note that *immediately before the line* "xhci_hcd 0000:0b:00.0: PME# disabled" > must appear "pcieport 0000:00:1c.4: PME# disabled". Don't know who is the blocker. > But in reverse order the PME# are being enabled after a device is unplugged from the USB3 > socket. > > During the tests I had an eSATA in the express card slot since cold boot but don't think > it is relevant here. The express slot is 01.c7 device and the card would be 11.0. > > > > > I will send to Alan and Sarah two files directly (thank you for their inspection): ;) > > The first part of testing is in usbmon_0u.bin (repeatedly connecting a mouse). > > The latter in usbmon_0u_mouse_unplug_keyboard_insert.bin. Both files should demonstrate > the same issue although in the latter file it might be easier to see because the keyboard > was plugged in after a mouse and was not detected until 'lsusb -vv'. > > > > > > Below is when a keyboard is connected to the dead USB3 socket: > > # diff -u -w lspci_vvvxxx_mouse_unplugged.txt lspci_vvvxxx_mouse_unplugged_keyboard_inserted.txt > --- lspci_vvvxxx_mouse_unplugged.txt 2013-03-14 12:22:34.000000000 +0100 > +++ lspci_vvvxxx_mouse_unplugged_keyboard_inserted.txt 2013-03-14 12:25:06.000000000 +0100 > @@ -747,7 +747,7 @@ > Region 2: Memory at f7d10000 (64-bit, non-prefetchable) [size=8K] > Capabilities: [40] Power Management version 3 > Flags: PMEClk- DSI- D1+ D2+ AuxCurrent=100mA PME(D0+,D1+,D2+,D3hot+,D3cold+) > - Status: D3 NoSoftRst+ PME-Enable+ DSel=0 DScale=0 PME- > + Status: D3 NoSoftRst+ PME-Enable+ DSel=0 DScale=0 PME+ > Capabilities: [48] MSI: Enable- Count=1/8 Maskable- 64bit+ > Address: 0000000000000000 Data: 0000 > Capabilities: [70] Express (v2) Endpoint, MSI 00 > @@ -785,7 +785,7 @@ > 10: 04 00 d0 f7 00 00 00 00 04 00 d1 f7 00 00 00 00 > 20: 00 00 00 00 00 00 00 00 00 00 00 00 28 10 b3 04 > 30: 00 00 00 00 40 00 00 00 00 00 00 00 0b 01 00 00 > -40: 01 48 83 fe 0b 01 00 00 05 70 86 00 00 00 00 00 > +40: 01 48 83 fe 0b 81 00 00 05 70 86 00 00 00 00 00 > 50: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 > 60: 30 20 00 00 00 00 00 00 00 00 00 00 00 00 00 00 > 70: 10 c0 02 00 c3 8f 90 05 00 20 19 00 12 3c 07 00 > > > Now, when the port is rescued by lsusb -vv, the following can be seen: > > # diff -u -w lspci_vv_mouse_unplugged_keyboard_inserted.txt lspci_vv_mouse_unplugged_keyboard_inserted_kb_alive.txt > --- lspci_vv_mouse_unplugged_keyboard_inserted.txt 2013-03-14 12:25:13.000000000 +0100 > +++ lspci_vv_mouse_unplugged_keyboard_inserted_kb_alive.txt 2013-03-14 12:26:42.000000000 +0100 > @@ -276,7 +276,7 @@ > Capabilities: [90] Subsystem: Dell Device 04b3 > Capabilities: [a0] Power Management version 2 > Flags: PMEClk- DSI- D1- D2- AuxCurrent=0mA PME(D0+,D1-,D2-,D3hot+,D3cold+) > - Status: D3 NoSoftRst- PME-Enable+ DSel=0 DScale=0 PME- > + Status: D0 NoSoftRst- PME-Enable- DSel=0 DScale=0 PME- > Kernel driver in use: pcieport > > 00:1c.7 PCI bridge: Intel Corporation 6 Series/C200 Series Chipset Family PCI Express Root Port 8 (rev b5) (prog-if 00 [Normal decode]) > @@ -476,14 +476,15 @@ > > 0b:00.0 USB controller: Texas Instruments TUSB73x0 SuperSpeed USB 3.0 xHCI Host Controller (rev 02) (prog-if 30 [XHCI]) > Subsystem: Dell Device 04b3 > - Control: I/O- Mem+ BusMaster- SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx+ > + Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx+ > Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx- > + Latency: 0, Cache Line Size: 64 bytes > Interrupt: pin A routed to IRQ 16 > Region 0: Memory at f7d00000 (64-bit, non-prefetchable) [size=64K] > Region 2: Memory at f7d10000 (64-bit, non-prefetchable) [size=8K] > Capabilities: [40] Power Management version 3 > Flags: PMEClk- DSI- D1+ D2+ AuxCurrent=100mA PME(D0+,D1+,D2+,D3hot+,D3cold+) > - Status: D3 NoSoftRst+ PME-Enable+ DSel=0 DScale=0 PME+ > + Status: D0 NoSoftRst+ PME-Enable- DSel=0 DScale=0 PME- > Capabilities: [48] MSI: Enable- Count=1/8 Maskable- 64bit+ > Address: 0000000000000000 Data: 0000 > Capabilities: [70] Express (v2) Endpoint, MSI 00 > # > > > > The difference in lsusb output is probably useless as it just shows that once the socket > was working the keyboard was picked up by a driver. Looks like yet another PCI issue. > At least no diffs in iomem. ;) > > > Thanks, > Martin > -- To unsubscribe from this list: send the line "unsubscribe linux-pci" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Hi Sarah, in this particular thread, the USB3 socket of the laptop works once I plugin a device. When I unplug it and insert same or another device it appears to be dead until I use 'lsusb -vvv'. After that, I see in dmesg the two lines: [ 1445.597641] pcieport 0000:00:1c.4: PME# disabled [ 1445.617667] xhci_hcd 0000:0b:00.0: PME# disabled That's the whole story. Thank you, Martin Sarah Sharp wrote: > Hi Martin, > > I'm really having trouble following you here. Please don't try to tell > me what you think the root cause of the issue is. Just tell me exactly > (in a paragraph or less) what your symptoms are. > > Sending lots of log files and lsusb output at me isn't helpful if I > don't know what your issue is. > > Sarah Sharp > > On Thu, Mar 14, 2013 at 06:30:53PM +0100, Martin Mokrejs wrote: >> [resend, no dmesg attached] >> >> Hi, >> happened to me again that I plugged in some devcie into my USB3 socket >> in my laptop (usually use an external HUB). Don't believe this is a new >> issue as a whole, I am facing this time to time since 3.3 time when I bought >> the laptop. >> But now, I realized the first device works but subsequently plugged in >> devices do not show up until until I run 'lsusb -vv'. Simple 'lsusb -v' >> or 'lsusb -t' is not enough. The port starts to work after dmesg logs: >> >> >> [ 1445.597641] pcieport 0000:00:1c.4: PME# disabled >> [ 1445.617667] xhci_hcd 0000:0b:00.0: PME# disabled >> >> I believe lsusb -vv while querying for the detailed device info triggers >> a fix. >> >> Funny, but maybe this will help us to understand why my express card slot >> somehow relates to the USB3 proivided by the TexasInstruments chip. This >> is a SandyBridge-based Dell Vostro 3550 laptop. I should add that on the usb >> mailing list about a year ago some TexasInstruments developer published that >> they had a hardware bug in a "USB redriver", and as my laptop was made in >> fall 2011 I am likely having having the buggy HW. If I remember right, the >> report was about the problem that once you pluging a USB2 device into the XHCI >> slot, subsequently plugged in USB3 devices won't negotiate at SuperSpeed until >> you power off computer. So, I think I face a different issue but had to mention >> this. >> >> I use pcie_aspm=off on my kernel command line. I tried to catch some usb traffic >> on the dead port but the file from usbmon is really empty until I do the >> 'lsusb -vv'. I tried to turn off the usb powersaving at runtime but I do not >> have the file to do: >> >> # echo -n -1 > /sys/bus/usb/devices/3-0\:1.0/power/autosuspend >> >> :( >> >> # ls -la /sys/bus/usb/devices/3-0\:1.0/power/ >> total 0 >> drwxr-xr-x 2 root root 0 Mar 14 13:11 . >> drwxr-xr-x 6 root root 0 Mar 14 13:58 .. >> -rw-r--r-- 1 root root 4096 Mar 14 13:11 async >> -r--r--r-- 1 root root 4096 Mar 14 13:11 runtime_active_kids >> -r--r--r-- 1 root root 4096 Mar 14 13:11 runtime_enabled >> -r--r--r-- 1 root root 4096 Mar 14 13:11 runtime_status >> -r--r--r-- 1 root root 4096 Mar 14 13:11 runtime_usage >> # >> >> I feel related could be patches under thread: "usb: add usb port auto power off mechanism" >> >> >> Below is a dmesg since a cold boot. I plugged in a mouse into the USB3 socket. >> >> [ 91.463285] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_suspend: 0 >> [ 91.463377] xhci_hcd 0000:0b:00.0: PME# enabled >> [ 447.389700] xhci_hcd 0000:0b:00.0: PME# disabled >> [ 447.389711] xhci_hcd 0000:0b:00.0: enabling bus mastering >> [ 447.389787] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_resume: 0 >> [ 447.389819] usb usb3: usb wakeup-resume >> >> Was detected. Unplugged the mouse. >> >> [ 459.600056] usb 3-2: USB disconnect, device number 2 >> [ 459.600058] usb 3-2: unregistering device >> [ 459.600059] usb 3-2: unregistering interface 3-2:1.0 >> [ 459.600622] xhci_hcd 0000:0b:00.0: shutdown urb ffff88040a641870 ep1in-intr >> [ 459.702564] usb 3-2: usb_disable_device nuking all URBs >> [ 459.707948] usb 3-2: Successful Endpoint Configure command >> [ 459.860892] hub 3-0:1.0: debounce: port 2: total 100ms stable 100ms status 0x100 >> [ 459.860910] hub 3-0:1.0: hub_suspend >> [ 459.860917] usb usb3: bus auto-suspend, wakeup 1 >> [ 459.860981] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_suspend: 0 >> [ 459.861070] xhci_hcd 0000:0b:00.0: PME# enabled >> >> Then I put the mouse back, I think it was not detected after until I did the lsusb >> trick. I am not sure, sorry, but is not that important. I was repeating test once >> again and just forgot now this detail. So below just that the mouse got detected, >> either thanks to lsusb -vv or not. >> >> [ 536.745422] xhci_hcd 0000:0b:00.0: PME# disabled >> [ 536.745435] xhci_hcd 0000:0b:00.0: enabling bus mastering >> [ 536.745487] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_resume: 0 >> [ 536.745493] usb usb3: usb auto-resume >> [ 536.745509] hub 3-0:1.0: hub_resume >> [ 536.745579] hub 3-0:1.0: port 2: status 0301 change 0001 >> >> Then a mouse disconnect: >> >> [ 652.232958] usb 3-2: USB disconnect, device number 3 >> [ 652.232960] usb 3-2: unregistering device >> [ 652.232961] usb 3-2: unregistering interface 3-2:1.0 >> [ 652.233148] xhci_hcd 0000:0b:00.0: shutdown urb ffff88040b1ee288 ep1in-intr >> [ 652.333325] usb 3-2: usb_disable_device nuking all URBs >> [ 652.337096] usb 3-2: Successful Endpoint Configure command >> [ 652.492164] hub 3-0:1.0: debounce: port 2: total 100ms stable 100ms status 0x100 >> [ 652.492183] hub 3-0:1.0: hub_suspend >> [ 652.492190] usb usb3: bus auto-suspend, wakeup 1 >> [ 652.492254] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_suspend: 0 >> [ 652.492341] xhci_hcd 0000:0b:00.0: PME# enabled >> [ 652.522157] pcieport 0000:00:1c.4: PME# enabled >> >> [ 688.128198] kmemleak: 1 new suspected memory leaks (see /sys/kernel/debug/kmemleak) >> >> Note above two things pcieport started to mess in. I you look what xhci_hcd printed >> in previous attempts the was NO pcieport involved around, at all. Now, provided >> that I reported the kmemleak multiple times this year: >> >> unreferenced object 0xffff88040b4a0690 (size 256): >> comm "swapper/0", pid 1, jiffies 4294937581 (age 17428.760s) >> hex dump (first 32 bytes): >> 00 00 00 00 ad 4e ad de ff ff ff ff 00 00 00 00 .....N.......... >> ff ff ff ff ff ff ff ff d8 9f 57 82 ff ff ff ff ..........W..... >> backtrace: >> [<ffffffff815fcec7>] kmemleak_alloc+0x21/0x3e >> [<ffffffff81117ac4>] slab_post_alloc_hook+0x28/0x2a >> [<ffffffff8111a18f>] __kmalloc+0xf3/0x105 >> [<ffffffff8132b20c>] kzalloc.constprop.14+0xe/0x10 >> [<ffffffff8132b66d>] device_private_init+0x14/0x63 >> [<ffffffff8132d790>] dev_set_drvdata+0x19/0x2f >> [<ffffffff813f19d1>] i801_probe+0x5e/0x41a >> [<ffffffff812924d8>] local_pci_probe+0x39/0x61 >> [<ffffffff812936fb>] pci_device_probe+0xc6/0xf3 >> [<ffffffff8132dd59>] driver_probe_device+0xa9/0x1c1 >> [<ffffffff8132decb>] __driver_attach+0x5a/0x7e >> [<ffffffff8132c5f3>] bus_for_each_dev+0x5c/0x88 >> [<ffffffff8132d8f6>] driver_attach+0x19/0x1b >> [<ffffffff8132d4c6>] bus_add_driver+0xa8/0x1fa >> [<ffffffff8132e33d>] driver_register+0x8c/0x106 >> [<ffffffff812932f6>] __pci_register_driver+0x5c/0x60 >> >> I believe this is related to the issue, somehow. >> >> Now I started usbmon, so lets follow another attempt to repeat the bug. For clarity, >> I will plug into the socket a kayboard, and it won't work until I do 'lsusb -vv'. >> I pressed then space on the keyboard and that worked immediately (keyboard was dead >> until lsusb -vv and also dmesg did not log anything). >> >> So, lsusb -vv: >> >> [ 802.986036] pcieport 0000:00:1c.4: PME# disabled >> [ 803.016008] xhci_hcd 0000:0b:00.0: PME# disabled >> [ 803.016021] xhci_hcd 0000:0b:00.0: enabling bus mastering >> [ 803.016078] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_resume: 0 >> [ 803.016085] usb usb3: usb auto-resume >> [ 803.016103] hub 3-0:1.0: hub_resume >> [ 803.016172] hub 3-0:1.0: port 2: status 0301 change 0001 >> >> unplug of the keyboard: >> >> [ 821.621331] usb usb4: usb auto-resume >> [ 821.621347] hub 4-0:1.0: hub_resume >> [ 821.621405] hub 4-0:1.0: state 7 ports 2 chg 0000 evt 0000 >> [ 821.622047] hub 4-0:1.0: hub_suspend >> [ 821.622053] usb usb4: bus auto-suspend, wakeup 1 >> [ 967.433533] hub 3-0:1.0: state 7 ports 2 chg 0000 evt 0004 >> [ 967.433768] hub 3-0:1.0: port 2, status 0100, change 0001, 12 Mb/s >> [ 967.433771] usb 3-2: USB disconnect, device number 4 >> [ 967.433772] usb 3-2: unregistering device >> [ 967.433775] usb 3-2: unregistering interface 3-2:1.0 >> [ 967.433946] xhci_hcd 0000:0b:00.0: shutdown urb ffff88040a641948 ep1in-intr >> [ 967.579130] usb 3-2: usb_disable_device nuking all URBs >> [ 967.584494] usb 3-2: Successful Endpoint Configure command >> [ 967.798027] hub 3-0:1.0: debounce: port 2: total 100ms stable 100ms status 0x100 >> [ 967.798046] hub 3-0:1.0: hub_suspend >> [ 967.798075] usb usb3: bus auto-suspend, wakeup 1 >> [ 967.798155] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_suspend: 0 >> [ 967.798242] xhci_hcd 0000:0b:00.0: PME# enabled >> [ 967.828015] pcieport 0000:00:1c.4: PME# enabled >> >> >> You see? pcieport is messing with >> 00:1c.4 PCI bridge: Intel Corporation 6 Series/C200 Series Chipset Family PCI Express Root Port 5 (rev b5) (prog-if 00 [Normal decode]) >> >> I unplugged and replugged the keyboard multiple times and it did not work, so >> I connected the mouse used in the very beginning right after cold boot, still >> not working. But these were likely logged due to that. >> >> [ 1063.263014] pcieport 0000:00:1c.4: PME# disabled >> [ 1063.272918] pcieport 0000:00:1c.4: PME# enabled >> [ 1063.312915] pcieport 0000:00:1c.4: PME# disabled >> [ 1063.322906] pcieport 0000:00:1c.4: PME# enabled >> [ 1070.132666] pcieport 0000:00:1c.4: PME# disabled >> [ 1070.142559] pcieport 0000:00:1c.4: PME# enabled >> [ 1070.182601] pcieport 0000:00:1c.4: PME# disabled >> [ 1070.192644] pcieport 0000:00:1c.4: PME# enabled >> >> After doing 'lsusb -vv' I rescued the USB3 socket and it detected the mouse. >> >> [ 1108.504953] pcieport 0000:00:1c.4: PME# disabled >> [ 1108.525010] xhci_hcd 0000:0b:00.0: PME# disabled >> [ 1108.525023] xhci_hcd 0000:0b:00.0: enabling bus mastering >> [ 1108.525069] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_resume: 0 >> [ 1108.525075] usb usb3: usb auto-resume >> [ 1108.525094] hub 3-0:1.0: hub_resume >> [ 1108.525196] hub 3-0:1.0: port 2: status 0301 change 0001 >> >> I unplugged the mouse: >> >> [ 1230.618019] usb 3-2: unregistering device >> [ 1230.618020] usb 3-2: unregistering interface 3-2:1.0 >> [ 1230.618188] xhci_hcd 0000:0b:00.0: shutdown urb ffff88040b1ee288 ep1in-intr >> [ 1230.711764] usb 3-2: usb_disable_device nuking all URBs >> [ 1230.715101] usb 3-2: Successful Endpoint Configure command >> [ 1230.870763] hub 3-0:1.0: debounce: port 2: total 100ms stable 100ms status 0x100 >> [ 1230.870782] hub 3-0:1.0: hub_suspend >> [ 1230.870797] usb usb3: bus auto-suspend, wakeup 1 >> [ 1230.870862] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_suspend: 0 >> [ 1230.870950] xhci_hcd 0000:0b:00.0: PME# enabled >> [ 1230.900730] pcieport 0000:00:1c.4: PME# enabled >> >> >> In summary, note that *immediately before the line* "xhci_hcd 0000:0b:00.0: PME# disabled" >> must appear "pcieport 0000:00:1c.4: PME# disabled". Don't know who is the blocker. >> But in reverse order the PME# are being enabled after a device is unplugged from the USB3 >> socket. >> >> During the tests I had an eSATA in the express card slot since cold boot but don't think >> it is relevant here. The express slot is 01.c7 device and the card would be 11.0. >> >> >> >> >> I will send to Alan and Sarah two files directly (thank you for their inspection): ;) >> >> The first part of testing is in usbmon_0u.bin (repeatedly connecting a mouse). >> >> The latter in usbmon_0u_mouse_unplug_keyboard_insert.bin. Both files should demonstrate >> the same issue although in the latter file it might be easier to see because the keyboard >> was plugged in after a mouse and was not detected until 'lsusb -vv'. >> >> >> >> >> >> Below is when a keyboard is connected to the dead USB3 socket: >> >> # diff -u -w lspci_vvvxxx_mouse_unplugged.txt lspci_vvvxxx_mouse_unplugged_keyboard_inserted.txt >> --- lspci_vvvxxx_mouse_unplugged.txt 2013-03-14 12:22:34.000000000 +0100 >> +++ lspci_vvvxxx_mouse_unplugged_keyboard_inserted.txt 2013-03-14 12:25:06.000000000 +0100 >> @@ -747,7 +747,7 @@ >> Region 2: Memory at f7d10000 (64-bit, non-prefetchable) [size=8K] >> Capabilities: [40] Power Management version 3 >> Flags: PMEClk- DSI- D1+ D2+ AuxCurrent=100mA PME(D0+,D1+,D2+,D3hot+,D3cold+) >> - Status: D3 NoSoftRst+ PME-Enable+ DSel=0 DScale=0 PME- >> + Status: D3 NoSoftRst+ PME-Enable+ DSel=0 DScale=0 PME+ >> Capabilities: [48] MSI: Enable- Count=1/8 Maskable- 64bit+ >> Address: 0000000000000000 Data: 0000 >> Capabilities: [70] Express (v2) Endpoint, MSI 00 >> @@ -785,7 +785,7 @@ >> 10: 04 00 d0 f7 00 00 00 00 04 00 d1 f7 00 00 00 00 >> 20: 00 00 00 00 00 00 00 00 00 00 00 00 28 10 b3 04 >> 30: 00 00 00 00 40 00 00 00 00 00 00 00 0b 01 00 00 >> -40: 01 48 83 fe 0b 01 00 00 05 70 86 00 00 00 00 00 >> +40: 01 48 83 fe 0b 81 00 00 05 70 86 00 00 00 00 00 >> 50: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 >> 60: 30 20 00 00 00 00 00 00 00 00 00 00 00 00 00 00 >> 70: 10 c0 02 00 c3 8f 90 05 00 20 19 00 12 3c 07 00 >> >> >> Now, when the port is rescued by lsusb -vv, the following can be seen: >> >> # diff -u -w lspci_vv_mouse_unplugged_keyboard_inserted.txt lspci_vv_mouse_unplugged_keyboard_inserted_kb_alive.txt >> --- lspci_vv_mouse_unplugged_keyboard_inserted.txt 2013-03-14 12:25:13.000000000 +0100 >> +++ lspci_vv_mouse_unplugged_keyboard_inserted_kb_alive.txt 2013-03-14 12:26:42.000000000 +0100 >> @@ -276,7 +276,7 @@ >> Capabilities: [90] Subsystem: Dell Device 04b3 >> Capabilities: [a0] Power Management version 2 >> Flags: PMEClk- DSI- D1- D2- AuxCurrent=0mA PME(D0+,D1-,D2-,D3hot+,D3cold+) >> - Status: D3 NoSoftRst- PME-Enable+ DSel=0 DScale=0 PME- >> + Status: D0 NoSoftRst- PME-Enable- DSel=0 DScale=0 PME- >> Kernel driver in use: pcieport >> >> 00:1c.7 PCI bridge: Intel Corporation 6 Series/C200 Series Chipset Family PCI Express Root Port 8 (rev b5) (prog-if 00 [Normal decode]) >> @@ -476,14 +476,15 @@ >> >> 0b:00.0 USB controller: Texas Instruments TUSB73x0 SuperSpeed USB 3.0 xHCI Host Controller (rev 02) (prog-if 30 [XHCI]) >> Subsystem: Dell Device 04b3 >> - Control: I/O- Mem+ BusMaster- SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx+ >> + Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx+ >> Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx- >> + Latency: 0, Cache Line Size: 64 bytes >> Interrupt: pin A routed to IRQ 16 >> Region 0: Memory at f7d00000 (64-bit, non-prefetchable) [size=64K] >> Region 2: Memory at f7d10000 (64-bit, non-prefetchable) [size=8K] >> Capabilities: [40] Power Management version 3 >> Flags: PMEClk- DSI- D1+ D2+ AuxCurrent=100mA PME(D0+,D1+,D2+,D3hot+,D3cold+) >> - Status: D3 NoSoftRst+ PME-Enable+ DSel=0 DScale=0 PME+ >> + Status: D0 NoSoftRst+ PME-Enable- DSel=0 DScale=0 PME- >> Capabilities: [48] MSI: Enable- Count=1/8 Maskable- 64bit+ >> Address: 0000000000000000 Data: 0000 >> Capabilities: [70] Express (v2) Endpoint, MSI 00 >> # >> >> >> >> The difference in lsusb output is probably useless as it just shows that once the socket >> was working the keyboard was picked up by a driver. Looks like yet another PCI issue. >> At least no diffs in iomem. ;) >> >> >> Thanks, >> Martin >> > -- > To unsubscribe from this list: send the line "unsubscribe linux-pci" in > the body of a message to majordomo@vger.kernel.org > More majordomo info at http://vger.kernel.org/majordomo-info.html > > -- To unsubscribe from this list: send the line "unsubscribe linux-pci" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
On Mon, Mar 18, 2013 at 06:20:12PM +0100, Martin Mokrejs wrote: > Hi Sarah, > in this particular thread, the USB3 socket of the laptop works once > I plugin a device. When I unplug it and insert same or another device it appears > to be dead until I use 'lsusb -vvv'. After that, I see in dmesg the two lines: Which kernel are you running on? We had a regression that involved dead ports after a USB disconnect in 3.8. This was was fixed in 3.8.3. Can you please retest with that kernel version? Sarah Sharp -- To unsubscribe from this list: send the line "unsubscribe linux-pci" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Sarah Sharp wrote: > On Mon, Mar 18, 2013 at 06:20:12PM +0100, Martin Mokrejs wrote: >> Hi Sarah, >> in this particular thread, the USB3 socket of the laptop works once >> I plugin a device. When I unplug it and insert same or another device it appears >> to be dead until I use 'lsusb -vvv'. After that, I see in dmesg the two lines: > > Which kernel are you running on? We had a regression that involved dead As the subject says, 3.8.2. I really started last week several different email threads, each independent. > ports after a USB disconnect in 3.8. This was was fixed in 3.8.3. Can > you please retest with that kernel version? Hmm, will do. What change do you mean exactly? BTW, how about this bugfix which just appeared at linux-pci? [PATCH] PCI: Remove not needed check in disable aspm link Thank you, Martin -- To unsubscribe from this list: send the line "unsubscribe linux-pci" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
On Mon, Mar 18, 2013 at 07:52:10PM +0100, Martin Mokrejs wrote: > Sarah Sharp wrote: > > On Mon, Mar 18, 2013 at 06:20:12PM +0100, Martin Mokrejs wrote: > >> Hi Sarah, > >> in this particular thread, the USB3 socket of the laptop works once > >> I plugin a device. When I unplug it and insert same or another device it appears > >> to be dead until I use 'lsusb -vvv'. After that, I see in dmesg the two lines: > > > > Which kernel are you running on? We had a regression that involved dead > > As the subject says, 3.8.2. I really started last week several different email > threads, each independent. > > > ports after a USB disconnect in 3.8. This was was fixed in 3.8.3. Can > > you please retest with that kernel version? > > Hmm, will do. What change do you mean exactly? Commit d79303047f25957a3e00d25cc1eddb82b3ee0f89 "USB: Fix connected device switch to Inactive state." along with three others. > BTW, how about this bugfix which just appeared at linux-pci? > [PATCH] PCI: Remove not needed check in disable aspm link I understand that you want to try and figure out on your own what bug you're hitting. I'm really happy you're enthusiastic about reporting and testing bug fixes. However, looking at random bug fix patches when we don't know the root cause is not very productive. I would suggest you read http://www.chiark.greenend.org.uk/~sgtatham/bugs.html, especially the "I think the tachyon modulation must be wrongly polarised" section. We have no hard proof that this is even a PCI bug. lsusb does cause the PCI host to wakeup out of D3, which triggers the PME disable messages you mentioned. However, lsusb also triggers the USB core to look at the roothub status registers. Without further debugging, we can't be sure if we lost a PCI wakeup from the port status change, or if the xHCI driver mishandled the USB device disconnect and running lsusb causes the USB core to notice the connect change. Let's rule out the most common case, the xHCI driver, first. Please, try 3.8.3 first, and if that doesn't help, turn on CONFIG_USB_DEBUG and CONFIG_USB_XHCI_HCD_DEBUGGING, and send me the dmesg from the time you first unplug the USB 3.0 device to when you replug it in and have to run `sudo lsusb -v` to get the device to appear. Sarah Sharp -- To unsubscribe from this list: send the line "unsubscribe linux-pci" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
--- lspci_vvvxxx_mouse_unplugged.txt 2013-03-14 12:22:34.000000000 +0100 +++ lspci_vvvxxx_mouse_unplugged_keyboard_inserted.txt 2013-03-14 12:25:06.000000000 +0100 @@ -747,7 +747,7 @@ Region 2: Memory at f7d10000 (64-bit, non-prefetchable) [size=8K] Capabilities: [40] Power Management version 3 Flags: PMEClk- DSI- D1+ D2+ AuxCurrent=100mA PME(D0+,D1+,D2+,D3hot+,D3cold+) - Status: D3 NoSoftRst+ PME-Enable+ DSel=0 DScale=0 PME- + Status: D3 NoSoftRst+ PME-Enable+ DSel=0 DScale=0 PME+ Capabilities: [48] MSI: Enable- Count=1/8 Maskable- 64bit+ Address: 0000000000000000 Data: 0000 Capabilities: [70] Express (v2) Endpoint, MSI 00 @@ -785,7 +785,7 @@ 10: 04 00 d0 f7 00 00 00 00 04 00 d1 f7 00 00 00 00 20: 00 00 00 00 00 00 00 00 00 00 00 00 28 10 b3 04 30: 00 00 00 00 40 00 00 00 00 00 00 00 0b 01 00 00 -40: 01 48 83 fe 0b 01 00 00 05 70 86 00 00 00 00 00 +40: 01 48 83 fe 0b 81 00 00 05 70 86 00 00 00 00 00 50: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 60: 30 20 00 00 00 00 00 00 00 00 00 00 00 00 00 00 70: 10 c0 02 00 c3 8f 90 05 00 20 19 00 12 3c 07 00 Now, when the port is rescued by lsusb -vv, the following can be seen: # diff -u -w lspci_vv_mouse_unplugged_keyboard_inserted.txt lspci_vv_mouse_unplugged_keyboard_inserted_kb_alive.txt --- lspci_vv_mouse_unplugged_keyboard_inserted.txt 2013-03-14 12:25:13.000000000 +0100 +++ lspci_vv_mouse_unplugged_keyboard_inserted_kb_alive.txt 2013-03-14 12:26:42.000000000 +0100 @@ -276,7 +276,7 @@ Capabilities: [90] Subsystem: Dell Device 04b3 Capabilities: [a0] Power Management version 2 Flags: PMEClk- DSI- D1- D2- AuxCurrent=0mA PME(D0+,D1-,D2-,D3hot+,D3cold+) - Status: D3 NoSoftRst- PME-Enable+ DSel=0 DScale=0 PME- + Status: D0 NoSoftRst- PME-Enable- DSel=0 DScale=0 PME- Kernel driver in use: pcieport 00:1c.7 PCI bridge: Intel Corporation 6 Series/C200 Series Chipset Family PCI Express Root Port 8 (rev b5) (prog-if 00 [Normal decode]) @@ -476,14 +476,15 @@ 0b:00.0 USB controller: Texas Instruments TUSB73x0 SuperSpeed USB 3.0 xHCI Host Controller (rev 02) (prog-if 30 [XHCI]) Subsystem: Dell Device 04b3 - Control: I/O- Mem+ BusMaster- SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx+ + Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx+ Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx- + Latency: 0, Cache Line Size: 64 bytes Interrupt: pin A routed to IRQ 16 Region 0: Memory at f7d00000 (64-bit, non-prefetchable) [size=64K] Region 2: Memory at f7d10000 (64-bit, non-prefetchable) [size=8K] Capabilities: [40] Power Management version 3 Flags: PMEClk- DSI- D1+ D2+ AuxCurrent=100mA PME(D0+,D1+,D2+,D3hot+,D3cold+) - Status: D3 NoSoftRst+ PME-Enable+ DSel=0 DScale=0 PME+ + Status: D0 NoSoftRst+ PME-Enable- DSel=0 DScale=0 PME- Capabilities: [48] MSI: Enable- Count=1/8 Maskable- 64bit+ Address: 0000000000000000 Data: 0000 Capabilities: [70] Express (v2) Endpoint, MSI 00