[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <4F91F639.6000107@fold.natur.cuni.cz>
Date: Sat, 21 Apr 2012 01:50:17 +0200
From: Martin Mokrejs <mmokrejs@...d.natur.cuni.cz>
To: Yinghai Lu <yinghai@...nel.org>
CC: Sarah Sharp <sarah.a.sharp@...ux.intel.com>,
linux-pci@...r.kernel.org,
Linux Kernel Mailing List <linux-kernel@...r.kernel.org>
Subject: Re: 3.2.11: PCI Express card cannot be re-detected withing cca 60sec
timeframe
Yinghai Lu wrote:
> On Fri, Apr 20, 2012 at 10:28 AM, Martin Mokrejs
> <mmokrejs@...d.natur.cuni.cz> wrote:
>>
>>
>> [30595.338466] pciehp 0000:00:1c.7:pcie04: pcie_isr: intr_loc 108
>> [30595.338468] pciehp 0000:00:1c.7:pcie04: LinkState change
>> [30595.338471] pciehp 0000:00:1c.7:pcie04: lnk_status = 7011
>> [30595.338483] pciehp 0000:00:1c.7:pcie04: Presence/Notify input change
>> [30595.338486] pciehp 0000:00:1c.7:pcie04: Card present on Slot(7)
>> [30595.338491] pciehp 0000:00:1c.7:pcie04: Surprise Removal
>> [30595.338525] pciehp 0000:00:1c.7:pcie04: check_link_active: lnk_status = 7011
>> [30595.439441] pciehp 0000:00:1c.7:pcie04: pciehp_check_link_status: lnk_status = 7011
>> [30595.439543] pci 0000:11:00.0: [1033:0194] type 00 class 0x0c0330
>> [30595.439597] pci 0000:11:00.0: reg 10: [mem 0x00000000-0x00001fff 64bit]
>> [30595.439840] pci 0000:11:00.0: PME# supported from D0 D3hot
>> [30595.459499] pci 0000:11:00.0: BAR 0: assigned [mem 0xf6c00000-0xf6c01fff 64bit]
>> [30595.459542] pcieport 0000:00:1c.7: PCI bridge to [bus 11-16]
>> [30595.459545] pcieport 0000:00:1c.7: bridge window [io 0xc000-0xdfff]
>> [30595.459550] pcieport 0000:00:1c.7: bridge window [mem 0xf6c00000-0xf7cfffff]
>> [30595.459554] pcieport 0000:00:1c.7: bridge window [mem 0xf0000000-0xf10fffff 64bit pref]
>> [30595.459688] xhci_hcd 0000:11:00.0: enabling device (0100 -> 0102)
>> [30595.459894] xhci_hcd 0000:11:00.0: xHCI Host Controller
>> [30595.459900] xhci_hcd 0000:11:00.0: new USB bus registered, assigned bus number 5
>> [30595.460199] xhci_hcd 0000:11:00.0: irq 19, io mem 0xf6c00000
>> [30595.460306] xhci_hcd 0000:11:00.0: irq 54 for MSI/MSI-X
>> [30595.460310] xhci_hcd 0000:11:00.0: irq 55 for MSI/MSI-X
>> [30595.460314] xhci_hcd 0000:11:00.0: irq 56 for MSI/MSI-X
>> [30595.460318] xhci_hcd 0000:11:00.0: irq 57 for MSI/MSI-X
>> [30595.460321] xhci_hcd 0000:11:00.0: irq 58 for MSI/MSI-X
>> [30595.460472] usb usb5: New USB device found, idVendor=1d6b, idProduct=0002
>> [30595.460474] usb usb5: New USB device strings: Mfr=3, Product=2, SerialNumber=1
>> [30595.460475] usb usb5: Product: xHCI Host Controller
>> [30595.460476] usb usb5: Manufacturer: Linux 3.4.0-rc3-default xhci_hcd
>> [30595.460477] usb usb5: SerialNumber: 0000:11:00.0
>> [30595.460569] xHCI xhci_add_endpoint called for root hub
>> [30595.460579] xHCI xhci_check_bandwidth called for root hub
>> [30595.460600] hub 5-0:1.0: USB hub found
>> [30595.460611] hub 5-0:1.0: 2 ports detected
>> [30595.460706] xhci_hcd 0000:11:00.0: xHCI Host Controller
>> [30595.460711] xhci_hcd 0000:11:00.0: new USB bus registered, assigned bus number 6
>> [30595.463431] usb usb6: New USB device found, idVendor=1d6b, idProduct=0003
>> [30595.463433] usb usb6: New USB device strings: Mfr=3, Product=2, SerialNumber=1
>> [30595.463434] usb usb6: Product: xHCI Host Controller
>> [30595.463435] usb usb6: Manufacturer: Linux 3.4.0-rc3-default xhci_hcd
>> [30595.463437] usb usb6: SerialNumber: 0000:11:00.0
>> [30595.463506] xHCI xhci_add_endpoint called for root hub
>> [30595.463507] xHCI xhci_check_bandwidth called for root hub
>> [30595.463534] hub 6-0:1.0: USB hub found
>> [30595.463547] hub 6-0:1.0: 2 ports detected
>
> echo 1 > /sys/..../remove
>
>> [30607.046714] xhci_hcd 0000:11:00.0: remove, state 4
>> [30607.046719] usb usb6: USB disconnect, device number 1
>> [30607.046764] xHCI xhci_drop_endpoint called for root hub
>> [30607.046766] xHCI xhci_check_bandwidth called for root hub
>> [30607.065341] xhci_hcd 0000:11:00.0: USB bus 6 deregistered
>> [30607.065350] xhci_hcd 0000:11:00.0: remove, state 4
>> [30607.065353] usb usb5: USB disconnect, device number 1
>> [30607.065393] xHCI xhci_drop_endpoint called for root hub
>> [30607.065394] xHCI xhci_check_bandwidth called for root hub
>> [30607.065692] xhci_hcd 0000:11:00.0: USB bus 5 deregistered
>> [30607.065764] pci 0000:11:00.0: freeing pci_dev info
>
> physically remove that express card
>
>> [30616.630810] pciehp 0000:00:1c.7:pcie04: pcie_isr: intr_loc 108
>> [30616.630813] pciehp 0000:00:1c.7:pcie04: LinkState change
>> [30616.630816] pciehp 0000:00:1c.7:pcie04: lnk_status = 5011
>> [30616.630817] pciehp 0000:00:1c.7:pcie04: Presence/Notify input change
>> [30616.630820] pciehp 0000:00:1c.7:pcie04: Card not present on Slot(7)
>> [30616.630858] pciehp 0000:00:1c.7:pcie04: Surprise Removal
>> [30616.630888] pciehp 0000:00:1c.7:pcie04: Disabling domain:bus:device=0000:11:00
>> [30616.630891] pciehp 0000:00:1c.7:pcie04: pciehp_unconfigure_device: domain:bus:dev = 0000:11:00
>
> physical add...
>
>> [30708.233725] pciehp 0000:00:1c.7:pcie04: pcie_isr: intr_loc 108
>> [30708.233727] pciehp 0000:00:1c.7:pcie04: LinkState change
>> [30708.233738] pciehp 0000:00:1c.7:pcie04: lnk_status = 7011
>> [30708.233739] pciehp 0000:00:1c.7:pcie04: Presence/Notify input change
>> [30708.233742] pciehp 0000:00:1c.7:pcie04: Card present on Slot(7)
>> [30708.233781] pciehp 0000:00:1c.7:pcie04: Surprise Removal
>> [30708.233796] pciehp 0000:00:1c.7:pcie04: check_link_active: lnk_status = 7011
>> [30708.338477] pciehp 0000:00:1c.7:pcie04: pciehp_check_link_status: lnk_status = 7011
>> [30708.338581] pci 0000:11:00.0: [1033:0194] type 00 class 0x0c0330
>> [30708.338632] pci 0000:11:00.0: reg 10: [mem 0x00000000-0x00001fff 64bit]
>> [30708.338876] pci 0000:11:00.0: PME# supported from D0 D3hot
>> [30708.358538] pci 0000:11:00.0: BAR 0: assigned [mem 0xf6c00000-0xf6c01fff 64bit]
>> [30708.358575] pcieport 0000:00:1c.7: PCI bridge to [bus 11-16]
>> [30708.358588] pcieport 0000:00:1c.7: bridge window [io 0xc000-0xdfff]
>> [30708.358593] pcieport 0000:00:1c.7: bridge window [mem 0xf6c00000-0xf7cfffff]
>> [30708.358597] pcieport 0000:00:1c.7: bridge window [mem 0xf0000000-0xf10fffff 64bit pref]
>> [30708.358737] xhci_hcd 0000:11:00.0: enabling device (0100 -> 0102)
>> [30708.358791] xhci_hcd 0000:11:00.0: xHCI Host Controller
>> [30708.358799] xhci_hcd 0000:11:00.0: new USB bus registered, assigned bus number 5
>> [30708.359090] xhci_hcd 0000:11:00.0: irq 19, io mem 0xf6c00000
>> [30708.359192] xhci_hcd 0000:11:00.0: irq 54 for MSI/MSI-X
>> [30708.359196] xhci_hcd 0000:11:00.0: irq 55 for MSI/MSI-X
>> [30708.359199] xhci_hcd 0000:11:00.0: irq 56 for MSI/MSI-X
>> [30708.359203] xhci_hcd 0000:11:00.0: irq 57 for MSI/MSI-X
>> [30708.359207] xhci_hcd 0000:11:00.0: irq 58 for MSI/MSI-X
>> [30708.359357] usb usb5: New USB device found, idVendor=1d6b, idProduct=0002
>> [30708.359359] usb usb5: New USB device strings: Mfr=3, Product=2, SerialNumber=1
>> [30708.359360] usb usb5: Product: xHCI Host Controller
>> [30708.359361] usb usb5: Manufacturer: Linux 3.4.0-rc3-default xhci_hcd
>> [30708.359363] usb usb5: SerialNumber: 0000:11:00.0
>> [30708.359453] xHCI xhci_add_endpoint called for root hub
>> [30708.359456] xHCI xhci_check_bandwidth called for root hub
>> [30708.359496] hub 5-0:1.0: USB hub found
>> [30708.359509] hub 5-0:1.0: 2 ports detected
>> [30708.359571] xhci_hcd 0000:11:00.0: xHCI Host Controller
>> [30708.359574] xhci_hcd 0000:11:00.0: new USB bus registered, assigned bus number 6
>> [30708.362332] usb usb6: New USB device found, idVendor=1d6b, idProduct=0003
>> [30708.362335] usb usb6: New USB device strings: Mfr=3, Product=2, SerialNumber=1
>> [30708.362337] usb usb6: Product: xHCI Host Controller
>> [30708.362338] usb usb6: Manufacturer: Linux 3.4.0-rc3-default xhci_hcd
>> [30708.362340] usb usb6: SerialNumber: 0000:11:00.0
>> [30708.362443] xHCI xhci_add_endpoint called for root hub
>> [30708.362445] xHCI xhci_check_bandwidth called for root hub
>> [30708.362472] hub 6-0:1.0: USB hub found
>> [30708.362490] hub 6-0:1.0: 2 ports detected
>
> echo 1 /sys/.../remove
>
>> [30716.380693] xhci_hcd 0000:11:00.0: remove, state 4
>> [30716.380699] usb usb6: USB disconnect, device number 1
>> [30716.380752] xHCI xhci_drop_endpoint called for root hub
>> [30716.380754] xHCI xhci_check_bandwidth called for root hub
>> [30716.400795] xhci_hcd 0000:11:00.0: USB bus 6 deregistered
>> [30716.400803] xhci_hcd 0000:11:00.0: remove, state 4
>> [30716.400807] usb usb5: USB disconnect, device number 1
>> [30716.400846] xHCI xhci_drop_endpoint called for root hub
>> [30716.400848] xHCI xhci_check_bandwidth called for root hub
>> [30716.401134] xhci_hcd 0000:11:00.0: USB bus 5 deregistered
>> [30716.401207] pci 0000:11:00.0: freeing pci_dev info
>
> physically remove
>
>> [30720.175637] pciehp 0000:00:1c.7:pcie04: pcie_isr: intr_loc 108
>> [30720.175639] pciehp 0000:00:1c.7:pcie04: LinkState change
>> [30720.175643] pciehp 0000:00:1c.7:pcie04: lnk_status = 5011
>> [30720.175644] pciehp 0000:00:1c.7:pcie04: Presence/Notify input change
>> [30720.175648] pciehp 0000:00:1c.7:pcie04: Card not present on Slot(7)
>> [30720.175687] pciehp 0000:00:1c.7:pcie04: Surprise Removal
>> [30720.175718] pciehp 0000:00:1c.7:pcie04: Disabling domain:bus:device=0000:11:00
>> [30720.175721] pciehp 0000:00:1c.7:pcie04: pciehp_unconfigure_device: domain:bus:dev = 0000:11:00
>>
>
> So the USB host control driver xhci put that 11:00.0 in strange power state.
>
> please try to boot the system with pcie_aspm=off
>
> and don't use echo 1 before physically removing the expresscard.
inserting
Apr 21 01:38:03 vostro kernel: [ 166.843165] pci 0000:11:00.0: BAR 0: assigned [mem 0xf6c00000-0xf6c01fff 64bit]
Apr 21 01:38:03 vostro kernel: [ 166.843272] xhci_hcd 0000:11:00.0: enabling device (0100 -> 0102)
Apr 21 01:38:03 vostro kernel: [ 166.843329] xhci_hcd 0000:11:00.0: xHCI Host Controller
Apr 21 01:38:03 vostro kernel: [ 166.843335] xhci_hcd 0000:11:00.0: new USB bus registered, assigned bus number 5
Apr 21 01:38:03 vostro kernel: [ 166.843637] xhci_hcd 0000:11:00.0: irq 19, io mem 0xf6c00000
Apr 21 01:38:03 vostro kernel: [ 166.843923] usb usb5: New USB device found, idVendor=1d6b, idProduct=0002
Apr 21 01:38:03 vostro kernel: [ 166.843925] usb usb5: New USB device strings: Mfr=3, Product=2, SerialNumber=1
Apr 21 01:38:03 vostro kernel: [ 166.843926] usb usb5: Product: xHCI Host Controller
Apr 21 01:38:03 vostro kernel: [ 166.843927] usb usb5: Manufacturer: Linux 3.4.0-rc3-default xhci_hcd
Apr 21 01:38:03 vostro kernel: [ 166.843928] usb usb5: SerialNumber: 0000:11:00.0
Apr 21 01:38:03 vostro kernel: [ 166.844076] hub 5-0:1.0: USB hub found
Apr 21 01:38:03 vostro kernel: [ 166.844088] hub 5-0:1.0: 2 ports detected
Apr 21 01:38:03 vostro kernel: [ 166.844162] xhci_hcd 0000:11:00.0: xHCI Host Controller
Apr 21 01:38:03 vostro kernel: [ 166.844164] xhci_hcd 0000:11:00.0: new USB bus registered, assigned bus number 6
Apr 21 01:38:03 vostro kernel: [ 166.846869] usb usb6: New USB device found, idVendor=1d6b, idProduct=0003
Apr 21 01:38:03 vostro kernel: [ 166.846872] usb usb6: New USB device strings: Mfr=3, Product=2, SerialNumber=1
Apr 21 01:38:03 vostro kernel: [ 166.846874] usb usb6: Product: xHCI Host Controller
Apr 21 01:38:03 vostro kernel: [ 166.846876] usb usb6: Manufacturer: Linux 3.4.0-rc3-default xhci_hcd
Apr 21 01:38:03 vostro kernel: [ 166.846878] usb usb6: SerialNumber: 0000:11:00.0
Apr 21 01:38:03 vostro kernel: [ 166.847205] hub 6-0:1.0: USB hub found
Apr 21 01:38:03 vostro kernel: [ 166.847224] hub 6-0:1.0: 2 ports detected
removed
re-inserting
removing
Apr 21 01:40:22 vostro kernel: [ 305.286902] xhci_hcd 0000:11:00.0: remove, state 4
Apr 21 01:40:22 vostro kernel: [ 305.286909] usb usb6: USB disconnect, device number 1
Apr 21 01:40:22 vostro kernel: [ 305.287036] xhci_hcd 0000:11:00.0: Host not halted after 16000 microseconds.
Apr 21 01:40:22 vostro kernel: [ 305.287040] xhci_hcd 0000:11:00.0: USB bus 6 deregistered
Apr 21 01:40:22 vostro kernel: [ 305.287044] xhci_hcd 0000:11:00.0: remove, state 4
Apr 21 01:40:22 vostro kernel: [ 305.287047] usb usb5: USB disconnect, device number 1
Apr 21 01:40:22 vostro kernel: [ 305.287206] xhci_hcd 0000:11:00.0: Host not halted after 16000 microseconds.
Apr 21 01:40:22 vostro kernel: [ 305.287308] xhci_hcd 0000:11:00.0: USB bus 5 deregistered
re-inserting
Apr 21 01:42:05 vostro kernel: [ 408.103695] pci 0000:11:00.0: BAR 0: assigned [mem 0xf6c00000-0xf6c01fff 64bit]
Apr 21 01:42:05 vostro kernel: [ 408.103825] xhci_hcd 0000:11:00.0: enabling device (0100 -> 0102)
Apr 21 01:42:05 vostro kernel: [ 408.103875] xhci_hcd 0000:11:00.0: xHCI Host Controller
Apr 21 01:42:05 vostro kernel: [ 408.103880] xhci_hcd 0000:11:00.0: new USB bus registered, assigned bus number 5
Apr 21 01:42:05 vostro kernel: [ 408.104183] xhci_hcd 0000:11:00.0: irq 19, io mem 0xf6c00000
Apr 21 01:42:05 vostro kernel: [ 408.104474] usb usb5: New USB device found, idVendor=1d6b, idProduct=0002
Apr 21 01:42:05 vostro kernel: [ 408.104475] usb usb5: New USB device strings: Mfr=3, Product=2, SerialNumber=1
Apr 21 01:42:05 vostro kernel: [ 408.104477] usb usb5: Product: xHCI Host Controller
Apr 21 01:42:05 vostro kernel: [ 408.104478] usb usb5: Manufacturer: Linux 3.4.0-rc3-default xhci_hcd
Apr 21 01:42:05 vostro kernel: [ 408.104479] usb usb5: SerialNumber: 0000:11:00.0
Apr 21 01:42:05 vostro kernel: [ 408.104566] hub 5-0:1.0: USB hub found
Apr 21 01:42:05 vostro kernel: [ 408.104577] hub 5-0:1.0: 2 ports detected
Apr 21 01:42:05 vostro kernel: [ 408.104639] xhci_hcd 0000:11:00.0: xHCI Host Controller
Apr 21 01:42:05 vostro kernel: [ 408.104641] xhci_hcd 0000:11:00.0: new USB bus registered, assigned bus number 6
Apr 21 01:42:05 vostro kernel: [ 408.107411] usb usb6: New USB device found, idVendor=1d6b, idProduct=0003
Apr 21 01:42:05 vostro kernel: [ 408.107413] usb usb6: New USB device strings: Mfr=3, Product=2, SerialNumber=1
Apr 21 01:42:05 vostro kernel: [ 408.107415] usb usb6: Product: xHCI Host Controller
Apr 21 01:42:05 vostro kernel: [ 408.107417] usb usb6: Manufacturer: Linux 3.4.0-rc3-default xhci_hcd
Apr 21 01:42:05 vostro kernel: [ 408.107418] usb usb6: SerialNumber: 0000:11:00.0
Apr 21 01:42:05 vostro kernel: [ 408.107560] hub 6-0:1.0: USB hub found
Apr 21 01:42:05 vostro kernel: [ 408.107578] hub 6-0:1.0: 2 ports detected
removing
re-inserting
removing
Apr 21 01:49:06 vostro kernel: [ 828.978080] xhci_hcd 0000:11:00.0: remove, state 4
Apr 21 01:49:06 vostro kernel: [ 828.978094] usb usb6: USB disconnect, device number 1
Apr 21 01:49:06 vostro kernel: [ 828.978249] xhci_hcd 0000:11:00.0: Host not halted after 16000 microseconds.
Apr 21 01:49:06 vostro kernel: [ 828.978253] xhci_hcd 0000:11:00.0: USB bus 6 deregistered
Apr 21 01:49:06 vostro kernel: [ 828.978257] xhci_hcd 0000:11:00.0: remove, state 4
Apr 21 01:49:06 vostro kernel: [ 828.978260] usb usb5: USB disconnect, device number 1
Apr 21 01:49:06 vostro kernel: [ 828.978432] xhci_hcd 0000:11:00.0: Host not halted after 16000 microseconds.
Apr 21 01:49:06 vostro kernel: [ 828.978520] xhci_hcd 0000:11:00.0: USB bus 5 deregistered
Martin
View attachment "dmesg.txt" of type "text/plain" (67335 bytes)
Powered by blists - more mailing lists