diff mbox

3.8.2: stale pci device info for a previously inserted express card

Message ID 51B1C1F3.3070804@fold.natur.cuni.cz (mailing list archive)
State New, archived
Delegated to: Bjorn Helgaas
Headers show

Commit Message

Martin Mokrejs June 7, 2013, 11:20 a.m. UTC
Hi everybody,

Bjorn Helgaas wrote:
> [+cc linux-pci, Sarah, Alan]
> 
> On Mon, Mar 11, 2013 at 10:02 AM, Martin Mokrejs
> <mmokrejs@fold.natur.cuni.cz> wrote:
>> [re-sending to you all three directly, looks the original email did not make it into linux-pci
>> through some filters]
>>
>>   I use for my daily work acpiphp to manage express cards in Dell Vostro 3550.
>> I have never seen something like this before and believe this is some new regression
>> in 3.8 series. I had in teh a USB3 card and ejected it. Then I inserted a
>> SATA Sil3132 card but it is not detected and dmesg still ends with last lines
>> added when the USB card was being removed. The funny thing is that lspci reports
>> a mixture of USB-card properties with NEC chips along with Silicon Image eSATA card.
> 
> I don't know anything about the kmemleaks mentioned elsewhere in this
> thread, but the idea of "stale PCI device info" seems possibly related
> to some acpiphp issues we've been working on recently.
> 
> Starting with v3.9, we don't handle ACPI Bus Check notifications to
> host bridges correctly, and the result is that when we're using
> acpiphp, we don't notice when PCI devices are added or removed. There
> are more details in https://bugzilla.kernel.org/show_bug.cgi?id=57961

Looks to me it is already in 3.10-rc4 which I tested now. No, I still do see
same problem like before: a hotremoval of NEC-based xHCI express card is detected
on every second eject. But, sometimes it seems it is only delayed by some 25-30
seconds. Would have to do more testing. However, there are some *new* kmemleaks
reported by kernel related to acpiphpp bu xhci_hcd. That could a hint why
the hotremoval sometimes proceeds delayed but sometimes maybe not at all or at
least not *immediately* like for any other device?

However, the stale sysfs entries for partially removed device SiI3132 (sata_sil24
driver) are NOT appearing anymore, good. That used to be associated with
'sata_sil24: IRQ status == 0xffffffff, PCI fault or device removal?' line.
Now, I see under 3.10-rc4 the extra message about 'ACPI: Device does not support D3cold'.
would be nice if it said what device is it talking about? About upstream root port
or about my end device (express card)? Is it related by pcie_aspm= kernel
commandline option? If yes, please include the relevant info the message text.
referring to this being affected by the particular value. At the moment I used:
pcie_aspm=off



So, in my eyes the "stale pci info" issue is fixed in 3.10-rc4 at least under acpiphp and pcie_aspm=off.



> 
> It looks like your Vostro 3550 uses acpiphp, so maybe there's a
> connection.  Can you try a current Linus upstream kernel (v3.10-rc1
> should be released in the next day or two) and apply the v3.10 patch
> from the bugzilla, and collect a complete dmesg log after you try a
> couple hotplug events?

I opened a bug https://bugzilla.kernel.org/show_bug.cgi?id=59411 .
I wanted to report individual tests but as overnight kernel reported
kmemleaks with interesting stacktraces I took the lazy approach and
uploaded the kmemleaks file and dmesg from the morning without further
splitting the stuff. However, I have step-by-step collected data for
everything in the dmesg since bootup, sadly except the very last
hotremoval. But hope that is not a big loss.
;-)


The SiI3132 card handled by sata_sil24 is treated differently:

# prev='/dev/null'; ls -latr dmesg* | awk '{print $9}' | while read cur; do diff -u -w $prev $cur; echo ""; echo ""; prev=$cur; done | grep "enabling device"
+[   87.551260] firewire_ohci 0000:11:00.0: enabling device (0100 -> 0103)
+[  110.223677] firewire_ohci 0000:11:00.0: enabling device (0100 -> 0103)
+[  143.649295] sata_sil24 0000:11:00.0: enabling device (0100 -> 0103)
+[  172.391223] sata_sil24 0000:11:00.0: enabling device (0100 -> 0103)
+[  208.367596] firewire_ohci 0000:11:00.0: enabling device (0100 -> 0103)
+[  242.299044] firewire_ohci 0000:11:00.0: enabling device (0100 -> 0103)
+[  277.412231] pci 0000:11:00.0: enabling device (0100 -> 0102)
+[  400.101571] pci 0000:11:00.0: enabling device (0100 -> 0102)
+[  458.763955] pci 0000:11:00.0: enabling device (0100 -> 0102)
#

I think the eSATA card hotremoval leaves acpiphp in a broken state.
That breaks in turn the NEC-based xHCI card hotplug removal detection while
NOT VIA-based FireWire card which can somehow overcome that.
What one can see in logs that xhci_hcd started to complain:


Hotinsert+removal of a firewire card, note "PME# disabled" line.

[  110.222507] pci 0000:11:00.0: [1106:3403] type 00 class 0x0c0010
[  110.222550] pci 0000:11:00.0: reg 10: [mem 0x00000000-0x000007ff 64bit]
[  110.222569] pci 0000:11:00.0: reg 18: [io  0x0000-0x00ff]
[  110.222746] pci 0000:11:00.0: supports D2
[  110.222747] pci 0000:11:00.0: PME# supported from D2 D3hot D3cold
[  110.222755] pci 0000:11:00.0: PME# disabled
[  110.223273] pci 0000:11:00.0: BAR 0: assigned [mem 0xf6c00000-0xf6c007ff 64bit]
[  110.223294] pci 0000:11:00.0: BAR 0: set to [mem 0xf6c00000-0xf6c007ff 64bit] (PCI address [0xf6c00000-0xf6c007ff])
[  110.223296] pci 0000:11:00.0: BAR 2: assigned [io  0xc000-0xc0ff]
[  110.223302] pci 0000:11:00.0: BAR 2: set to [io  0xc000-0xc0ff] (PCI address [0xc000-0xc0ff])
[  110.223677] firewire_ohci 0000:11:00.0: enabling device (0100 -> 0103)
[  110.224296] firewire_ohci 0000:11:00.0: calling quirk_via_vlink+0x0/0xae
[  110.224301] firewire_ohci 0000:11:00.0: enabling bus mastering
[  110.319376] firewire_ohci 0000:11:00.0: added OHCI v1.10 device as card 1, 4 IR + 8 IT contexts, quirks 0x11
[  110.820445] firewire_core 0000:11:00.0: created device fw0: GUID 0011066600000003, S400
[  120.739684] firewire_ohci 0000:11:00.0: PME# disabled
[  120.741121] firewire_ohci 0000:11:00.0: removed fw-ohci device
[  120.741349] ACPI: Device does not support D3cold


A following hotinsert+removal of a SiI3132 card, note "nothing about PME# logged" by pci core. Why?
Is this related to my pcie_aspm=off?

[  143.558781] pci 0000:11:00.0: [1095:3132] type 00 class 0x018000
[  143.558827] pci 0000:11:00.0: reg 10: [mem 0x00000000-0x0000007f 64bit]
[  143.558859] pci 0000:11:00.0: reg 18: [mem 0x00000000-0x00003fff 64bit]
[  143.558880] pci 0000:11:00.0: reg 20: [io  0x0000-0x007f]
[  143.558922] pci 0000:11:00.0: reg 30: [mem 0x00000000-0x0007ffff pref]
[  143.559037] pci 0000:11:00.0: supports D1 D2
[  143.559503] pci 0000:11:00.0: BAR 6: assigned [mem 0xf0000000-0xf007ffff pref]
[  143.559506] pci 0000:11:00.0: BAR 2: assigned [mem 0xf6c00000-0xf6c03fff 64bit]
[  143.559527] pci 0000:11:00.0: BAR 2: set to [mem 0xf6c00000-0xf6c03fff 64bit] (PCI address [0xf6c00000-0xf6c03fff])
[  143.559529] pci 0000:11:00.0: BAR 0: assigned [mem 0xf6c04000-0xf6c0407f 64bit]
[  143.559551] pci 0000:11:00.0: BAR 0: set to [mem 0xf6c04000-0xf6c0407f 64bit] (PCI address [0xf6c04000-0xf6c0407f])
[  143.559552] pci 0000:11:00.0: BAR 4: assigned [io  0xc000-0xc07f]
[  143.559560] pci 0000:11:00.0: BAR 4: set to [io  0xc000-0xc07f] (PCI address [0xc000-0xc07f])
[  143.649276] sata_sil24 0000:11:00.0: version 1.1
[  143.649295] sata_sil24 0000:11:00.0: enabling device (0100 -> 0103)
[  143.650045] sata_sil24 0000:11:00.0: enabling bus mastering
[  143.652840] scsi6 : sata_sil24
[  143.653497] scsi7 : sata_sil24
[  143.654042] ata7: SATA max UDMA/100 host m128@0xf6c04000 port 0xf6c00000 irq 19
[  143.654045] ata8: SATA max UDMA/100 host m128@0xf6c04000 port 0xf6c02000 irq 19
[  145.737258] ata7: SATA link down (SStatus 0 SControl 0)
[  147.828753] ata8: SATA link down (SStatus 0 SControl 0)
[  163.534474] sata_sil24: IRQ status == 0xffffffff, PCI fault or device removal?
[  163.535550] ACPI: Device does not support D3cold


Finally, a third one to compare to, a hotinsert+hotremoval of NEC-based USB3 card.
Note, no line saying "pci 0000:11:00.0: supports ...":

[  277.411123] pci 0000:11:00.0: [1033:0194] type 00 class 0x0c0330
[  277.411178] pci 0000:11:00.0: reg 10: [mem 0x00000000-0x00001fff 64bit]
[  277.411439] pci 0000:11:00.0: PME# supported from D0 D3hot
[  277.411450] pci 0000:11:00.0: PME# disabled
[  277.412021] pci 0000:11:00.0: BAR 0: assigned [mem 0xf6c00000-0xf6c01fff 64bit]
[  277.412049] pci 0000:11:00.0: BAR 0: set to [mem 0xf6c00000-0xf6c01fff 64bit] (PCI address [0xf6c00000-0xf6c01fff])
[  277.412218] pci 0000:11:00.0: calling quirk_usb_early_handoff+0x0/0x65a
[  277.412231] pci 0000:11:00.0: enabling device (0100 -> 0102)
[  277.414428] xhci_hcd 0000:11:00.0: enabling bus mastering
[  277.414452] xhci_hcd 0000:11:00.0: xHCI Host Controller
[  277.414501] xhci_hcd 0000:11:00.0: new USB bus registered, assigned bus number 5
[  277.414925] xhci_hcd 0000:11:00.0: enabling Mem-Wr-Inval
[  277.414931] xhci_hcd 0000:11:00.0: supports USB remote wakeup
[  277.415073] xhci_hcd 0000:11:00.0: irq 48 for MSI/MSI-X
[  277.415121] xhci_hcd 0000:11:00.0: irq 49 for MSI/MSI-X
[  277.415168] xhci_hcd 0000:11:00.0: irq 50 for MSI/MSI-X
[  277.417049] xHCI xhci_add_endpoint called for root hub
[  277.417050] xHCI xhci_check_bandwidth called for root hub
[  277.418987] xhci_hcd 0000:11:00.0: xHCI Host Controller
[  277.419028] xhci_hcd 0000:11:00.0: new USB bus registered, assigned bus number 6
[  277.419051] xhci_hcd 0000:11:00.0: supports USB remote wakeup
[  277.420411] xHCI xhci_add_endpoint called for root hub
[  277.420412] xHCI xhci_check_bandwidth called for root hub
[  293.398490] xhci_hcd 0000:11:00.0: PME# disabled
[  293.398765] xhci_hcd 0000:11:00.0: remove, state 4
[  293.398833] xhci_hcd 0000:11:00.0: roothub graceful disconnect
[  293.400107] xHCI xhci_drop_endpoint called for root hub
[  293.400108] xHCI xhci_check_bandwidth called for root hub
[  293.401695] xhci_hcd 0000:11:00.0: Host not halted after 16000 microseconds.
[  293.401735] xhci_hcd 0000:11:00.0: USB bus 6 deregistered
[  293.401754] xhci_hcd 0000:11:00.0: remove, state 4
[  293.401766] xhci_hcd 0000:11:00.0: roothub graceful disconnect
[  293.402479] xHCI xhci_drop_endpoint called for root hub
[  293.402480] xHCI xhci_check_bandwidth called for root hub
[  293.403302] xhci_hcd 0000:11:00.0: Host not halted after 16000 microseconds.
[  293.403707] xhci_hcd 0000:11:00.0: USB bus 5 deregistered
[  293.448715] ACPI: Device does not support D3cold



Martin
To attract Google search engine and your eyes I am attaching the kmemleak
file to this email. ;-)
unreferenced object 0xffff88040b2ef690 (size 256):
  comm "swapper/0", pid 1, jiffies 4294937684 (age 28068.730s)
  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 f8 89 6d 82 ff ff ff ff  ..........m.....
  backtrace:
    [<ffffffff816b46ae>] kmemleak_alloc+0x21/0x3e
    [<ffffffff81162847>] slab_post_alloc_hook+0x28/0x2a
    [<ffffffff811648c9>] kmem_cache_alloc+0xb0/0xc0
    [<ffffffff813e7f6e>] device_private_init+0x1b/0x68
    [<ffffffff813ea120>] dev_set_drvdata+0x28/0x31
    [<ffffffff814975fb>] i801_probe+0x4d/0x40a
    [<ffffffff812df27e>] local_pci_probe+0x39/0x61
    [<ffffffff812df4a6>] pci_device_probe+0xba/0xe0
    [<ffffffff813ea752>] driver_probe_device+0x99/0x1c7
    [<ffffffff813ea8ce>] __driver_attach+0x4e/0x6f
    [<ffffffff813e8e02>] bus_for_each_dev+0x57/0x89
    [<ffffffff813ea24e>] driver_attach+0x19/0x1b
    [<ffffffff813e9eef>] bus_add_driver+0xe7/0x20c
    [<ffffffff813eae53>] driver_register+0x8e/0x114
    [<ffffffff812de8f2>] __pci_register_driver+0x5d/0x62
    [<ffffffff81b4527a>] i2c_i801_init+0xaa/0xc9
unreferenced object 0xffff8804095e6090 (size 4096):
  comm "kworker/0:0", pid 4, jiffies 4294946028 (age 27985.300s)
  hex dump (first 32 bytes):
    00 01 10 00 00 00 ad de 00 02 20 00 00 00 ad de  .......... .....
    38 69 f5 0c 04 88 ff ff 00 00 00 00 00 00 00 00  8i..............
  backtrace:
    [<ffffffff816b46ae>] kmemleak_alloc+0x21/0x3e
    [<ffffffff81162847>] slab_post_alloc_hook+0x28/0x2a
    [<ffffffff811648c9>] kmem_cache_alloc+0xb0/0xc0
    [<ffffffff812d8baa>] alloc_pci_dev+0x15/0x2e
    [<ffffffff816b4714>] pci_scan_single_device+0x49/0x99
    [<ffffffff812d9972>] pci_scan_slot+0x52/0xf6
    [<ffffffff816b5523>] enable_device+0xdb/0x393
    [<ffffffff812ed278>] acpiphp_enable_slot+0xcb/0x130
    [<ffffffff812ed454>] acpiphp_check_bridge+0x6e/0xd4
    [<ffffffff812ed812>] _handle_hotplug_event_bridge+0xc8/0x218
    [<ffffffff810d8463>] process_one_work+0x1cb/0x2dd
    [<ffffffff810d8936>] worker_thread+0x12f/0x1fc
    [<ffffffff810dd519>] kthread+0xac/0xb4
    [<ffffffff816cbd2c>] ret_from_fork+0x7c/0xb0
    [<ffffffffffffffff>] 0xffffffffffffffff
unreferenced object 0xffff880407f59a28 (size 16):
  comm "kworker/0:0", pid 4, jiffies 4294946028 (age 27985.300s)
  hex dump (first 16 bytes):
    30 30 30 30 3a 31 31 3a 30 30 2e 30 00 6b 6b a5  0000:11:00.0.kk.
  backtrace:
    [<ffffffff816b46ae>] kmemleak_alloc+0x21/0x3e
    [<ffffffff81162847>] slab_post_alloc_hook+0x28/0x2a
    [<ffffffff81165ccf>] __kmalloc_track_caller+0xdd/0x118
    [<ffffffff812c2727>] kvasprintf+0x4b/0x74
    [<ffffffff812b916d>] kobject_set_name_vargs+0x21/0x56
    [<ffffffff813e6e44>] dev_set_name+0x3c/0x3e
    [<ffffffff812d951b>] pci_setup_device+0xfc/0x3b5
    [<ffffffff816b473a>] pci_scan_single_device+0x6f/0x99
    [<ffffffff812d9972>] pci_scan_slot+0x52/0xf6
    [<ffffffff816b5523>] enable_device+0xdb/0x393
    [<ffffffff812ed278>] acpiphp_enable_slot+0xcb/0x130
    [<ffffffff812ed454>] acpiphp_check_bridge+0x6e/0xd4
    [<ffffffff812ed812>] _handle_hotplug_event_bridge+0xc8/0x218
    [<ffffffff810d8463>] process_one_work+0x1cb/0x2dd
    [<ffffffff810d8936>] worker_thread+0x12f/0x1fc
    [<ffffffff810dd519>] kthread+0xac/0xb4
unreferenced object 0xffff88040a1925d8 (size 64):
  comm "kworker/0:0", pid 4, jiffies 4294946028 (age 27985.310s)
  hex dump (first 32 bytes):
    00 00 00 00 00 00 00 00 08 69 5e 09 04 88 ff ff  .........i^.....
    10 00 00 00 0e 00 00 00 00 00 00 00 00 00 00 00  ................
  backtrace:
    [<ffffffff816b46ae>] kmemleak_alloc+0x21/0x3e
    [<ffffffff81162847>] slab_post_alloc_hook+0x28/0x2a
    [<ffffffff81164702>] __kmalloc+0xde/0x118
    [<ffffffff812dbc16>] kzalloc.constprop.32+0xe/0x10
    [<ffffffff812dbcb4>] pci_add_cap_save_buffer.part.16+0x1f/0x62
    [<ffffffff812dd825>] pci_allocate_cap_save_buffers+0x29/0x82
    [<ffffffff812d9877>] pci_device_add+0xa3/0x14c
    [<ffffffff816b4756>] pci_scan_single_device+0x8b/0x99
    [<ffffffff812d9972>] pci_scan_slot+0x52/0xf6
    [<ffffffff816b5523>] enable_device+0xdb/0x393
    [<ffffffff812ed278>] acpiphp_enable_slot+0xcb/0x130
    [<ffffffff812ed454>] acpiphp_check_bridge+0x6e/0xd4
    [<ffffffff812ed812>] _handle_hotplug_event_bridge+0xc8/0x218
    [<ffffffff810d8463>] process_one_work+0x1cb/0x2dd
    [<ffffffff810d8936>] worker_thread+0x12f/0x1fc
    [<ffffffff810dd519>] kthread+0xac/0xb4
unreferenced object 0xffff880408619578 (size 256):
  comm "kworker/0:0", pid 4, jiffies 4294946028 (age 27985.310s)
  hex dump (first 32 bytes):
    05 05 00 00 ad 4e ad de ff ff ff ff 00 00 00 00  .....N..........
    ff ff ff ff ff ff ff ff f8 89 6d 82 ff ff ff ff  ..........m.....
  backtrace:
    [<ffffffff816b46ae>] kmemleak_alloc+0x21/0x3e
    [<ffffffff81162847>] slab_post_alloc_hook+0x28/0x2a
    [<ffffffff811648c9>] kmem_cache_alloc+0xb0/0xc0
    [<ffffffff813e7f6e>] device_private_init+0x1b/0x68
    [<ffffffff813e8006>] device_add+0x4b/0x5d2
    [<ffffffff812d98fb>] pci_device_add+0x127/0x14c
    [<ffffffff816b4756>] pci_scan_single_device+0x8b/0x99
    [<ffffffff812d9972>] pci_scan_slot+0x52/0xf6
    [<ffffffff816b5523>] enable_device+0xdb/0x393
    [<ffffffff812ed278>] acpiphp_enable_slot+0xcb/0x130
    [<ffffffff812ed454>] acpiphp_check_bridge+0x6e/0xd4
    [<ffffffff812ed812>] _handle_hotplug_event_bridge+0xc8/0x218
    [<ffffffff810d8463>] process_one_work+0x1cb/0x2dd
    [<ffffffff810d8936>] worker_thread+0x12f/0x1fc
    [<ffffffff810dd519>] kthread+0xac/0xb4
    [<ffffffff816cbd2c>] ret_from_fork+0x7c/0xb0
unreferenced object 0xffff8804095e2030 (size 4096):
  comm "kworker/0:0", pid 4, jiffies 4294948304 (age 27962.550s)
  hex dump (first 32 bytes):
    00 01 10 00 00 00 ad de 00 02 20 00 00 00 ad de  .......... .....
    38 69 f5 0c 04 88 ff ff 00 00 00 00 00 00 00 00  8i..............
  backtrace:
    [<ffffffff816b46ae>] kmemleak_alloc+0x21/0x3e
    [<ffffffff81162847>] slab_post_alloc_hook+0x28/0x2a
    [<ffffffff811648c9>] kmem_cache_alloc+0xb0/0xc0
    [<ffffffff812d8baa>] alloc_pci_dev+0x15/0x2e
    [<ffffffff816b4714>] pci_scan_single_device+0x49/0x99
    [<ffffffff812d9972>] pci_scan_slot+0x52/0xf6
    [<ffffffff816b5523>] enable_device+0xdb/0x393
    [<ffffffff812ed278>] acpiphp_enable_slot+0xcb/0x130
    [<ffffffff812ed454>] acpiphp_check_bridge+0x6e/0xd4
    [<ffffffff812ed812>] _handle_hotplug_event_bridge+0xc8/0x218
    [<ffffffff810d8463>] process_one_work+0x1cb/0x2dd
    [<ffffffff810d8936>] worker_thread+0x12f/0x1fc
    [<ffffffff810dd519>] kthread+0xac/0xb4
    [<ffffffff816cbd2c>] ret_from_fork+0x7c/0xb0
    [<ffffffffffffffff>] 0xffffffffffffffff
unreferenced object 0xffff880407f59d20 (size 16):
  comm "kworker/0:0", pid 4, jiffies 4294948304 (age 27962.550s)
  hex dump (first 16 bytes):
    30 30 30 30 3a 31 31 3a 30 30 2e 30 00 6b 6b a5  0000:11:00.0.kk.
  backtrace:
    [<ffffffff816b46ae>] kmemleak_alloc+0x21/0x3e
    [<ffffffff81162847>] slab_post_alloc_hook+0x28/0x2a
    [<ffffffff81165ccf>] __kmalloc_track_caller+0xdd/0x118
    [<ffffffff812c2727>] kvasprintf+0x4b/0x74
    [<ffffffff812b916d>] kobject_set_name_vargs+0x21/0x56
    [<ffffffff813e6e44>] dev_set_name+0x3c/0x3e
    [<ffffffff812d951b>] pci_setup_device+0xfc/0x3b5
    [<ffffffff816b473a>] pci_scan_single_device+0x6f/0x99
    [<ffffffff812d9972>] pci_scan_slot+0x52/0xf6
    [<ffffffff816b5523>] enable_device+0xdb/0x393
    [<ffffffff812ed278>] acpiphp_enable_slot+0xcb/0x130
    [<ffffffff812ed454>] acpiphp_check_bridge+0x6e/0xd4
    [<ffffffff812ed812>] _handle_hotplug_event_bridge+0xc8/0x218
    [<ffffffff810d8463>] process_one_work+0x1cb/0x2dd
    [<ffffffff810d8936>] worker_thread+0x12f/0x1fc
    [<ffffffff810dd519>] kthread+0xac/0xb4
unreferenced object 0xffff8804077bef78 (size 64):
  comm "kworker/0:0", pid 4, jiffies 4294948304 (age 27962.550s)
  hex dump (first 32 bytes):
    00 00 00 00 00 00 00 00 a8 28 5e 09 04 88 ff ff  .........(^.....
    10 00 00 00 0e 00 00 00 00 00 00 00 00 00 00 00  ................
  backtrace:
    [<ffffffff816b46ae>] kmemleak_alloc+0x21/0x3e
    [<ffffffff81162847>] slab_post_alloc_hook+0x28/0x2a
    [<ffffffff81164702>] __kmalloc+0xde/0x118
    [<ffffffff812dbc16>] kzalloc.constprop.32+0xe/0x10
    [<ffffffff812dbcb4>] pci_add_cap_save_buffer.part.16+0x1f/0x62
    [<ffffffff812dd825>] pci_allocate_cap_save_buffers+0x29/0x82
    [<ffffffff812d9877>] pci_device_add+0xa3/0x14c
    [<ffffffff816b4756>] pci_scan_single_device+0x8b/0x99
    [<ffffffff812d9972>] pci_scan_slot+0x52/0xf6
    [<ffffffff816b5523>] enable_device+0xdb/0x393
    [<ffffffff812ed278>] acpiphp_enable_slot+0xcb/0x130
    [<ffffffff812ed454>] acpiphp_check_bridge+0x6e/0xd4
    [<ffffffff812ed812>] _handle_hotplug_event_bridge+0xc8/0x218
    [<ffffffff810d8463>] process_one_work+0x1cb/0x2dd
    [<ffffffff810d8936>] worker_thread+0x12f/0x1fc
    [<ffffffff810dd519>] kthread+0xac/0xb4
unreferenced object 0xffff88040749b690 (size 256):
  comm "kworker/0:0", pid 4, jiffies 4294948304 (age 27962.550s)
  hex dump (first 32 bytes):
    05 05 00 00 ad 4e ad de ff ff ff ff 00 00 00 00  .....N..........
    ff ff ff ff ff ff ff ff f8 89 6d 82 ff ff ff ff  ..........m.....
  backtrace:
    [<ffffffff816b46ae>] kmemleak_alloc+0x21/0x3e
    [<ffffffff81162847>] slab_post_alloc_hook+0x28/0x2a
    [<ffffffff811648c9>] kmem_cache_alloc+0xb0/0xc0
    [<ffffffff813e7f6e>] device_private_init+0x1b/0x68
    [<ffffffff813e8006>] device_add+0x4b/0x5d2
    [<ffffffff812d98fb>] pci_device_add+0x127/0x14c
    [<ffffffff816b4756>] pci_scan_single_device+0x8b/0x99
    [<ffffffff812d9972>] pci_scan_slot+0x52/0xf6
    [<ffffffff816b5523>] enable_device+0xdb/0x393
    [<ffffffff812ed278>] acpiphp_enable_slot+0xcb/0x130
    [<ffffffff812ed454>] acpiphp_check_bridge+0x6e/0xd4
    [<ffffffff812ed812>] _handle_hotplug_event_bridge+0xc8/0x218
    [<ffffffff810d8463>] process_one_work+0x1cb/0x2dd
    [<ffffffff810d8936>] worker_thread+0x12f/0x1fc
    [<ffffffff810dd519>] kthread+0xac/0xb4
    [<ffffffff816cbd2c>] ret_from_fork+0x7c/0xb0
unreferenced object 0xffff8804095e4060 (size 4096):
  comm "kworker/0:0", pid 4, jiffies 4294951635 (age 27929.250s)
  hex dump (first 32 bytes):
    00 01 10 00 00 00 ad de 00 02 20 00 00 00 ad de  .......... .....
    38 69 f5 0c 04 88 ff ff 00 00 00 00 00 00 00 00  8i..............
  backtrace:
    [<ffffffff816b46ae>] kmemleak_alloc+0x21/0x3e
    [<ffffffff81162847>] slab_post_alloc_hook+0x28/0x2a
    [<ffffffff811648c9>] kmem_cache_alloc+0xb0/0xc0
    [<ffffffff812d8baa>] alloc_pci_dev+0x15/0x2e
    [<ffffffff816b4714>] pci_scan_single_device+0x49/0x99
    [<ffffffff812d9972>] pci_scan_slot+0x52/0xf6
    [<ffffffff816b5523>] enable_device+0xdb/0x393
    [<ffffffff812ed278>] acpiphp_enable_slot+0xcb/0x130
    [<ffffffff812ed454>] acpiphp_check_bridge+0x6e/0xd4
    [<ffffffff812ed812>] _handle_hotplug_event_bridge+0xc8/0x218
    [<ffffffff810d8463>] process_one_work+0x1cb/0x2dd
    [<ffffffff810d8936>] worker_thread+0x12f/0x1fc
    [<ffffffff810dd519>] kthread+0xac/0xb4
    [<ffffffff816cbd2c>] ret_from_fork+0x7c/0xb0
    [<ffffffffffffffff>] 0xffffffffffffffff
unreferenced object 0xffff880407f59960 (size 16):
  comm "kworker/0:0", pid 4, jiffies 4294951635 (age 27929.250s)
  hex dump (first 16 bytes):
    30 30 30 30 3a 31 31 3a 30 30 2e 30 00 6b 6b a5  0000:11:00.0.kk.
  backtrace:
    [<ffffffff816b46ae>] kmemleak_alloc+0x21/0x3e
    [<ffffffff81162847>] slab_post_alloc_hook+0x28/0x2a
    [<ffffffff81165ccf>] __kmalloc_track_caller+0xdd/0x118
    [<ffffffff812c2727>] kvasprintf+0x4b/0x74
    [<ffffffff812b916d>] kobject_set_name_vargs+0x21/0x56
    [<ffffffff813e6e44>] dev_set_name+0x3c/0x3e
    [<ffffffff812d951b>] pci_setup_device+0xfc/0x3b5
    [<ffffffff816b473a>] pci_scan_single_device+0x6f/0x99
    [<ffffffff812d9972>] pci_scan_slot+0x52/0xf6
    [<ffffffff816b5523>] enable_device+0xdb/0x393
    [<ffffffff812ed278>] acpiphp_enable_slot+0xcb/0x130
    [<ffffffff812ed454>] acpiphp_check_bridge+0x6e/0xd4
    [<ffffffff812ed812>] _handle_hotplug_event_bridge+0xc8/0x218
    [<ffffffff810d8463>] process_one_work+0x1cb/0x2dd
    [<ffffffff810d8936>] worker_thread+0x12f/0x1fc
    [<ffffffff810dd519>] kthread+0xac/0xb4
unreferenced object 0xffff8804077bee18 (size 64):
  comm "kworker/0:0", pid 4, jiffies 4294951635 (age 27929.250s)
  hex dump (first 32 bytes):
    00 00 00 00 00 00 00 00 d8 48 5e 09 04 88 ff ff  .........H^.....
    10 00 00 00 0e 00 00 00 00 00 00 00 00 00 00 00  ................
  backtrace:
    [<ffffffff816b46ae>] kmemleak_alloc+0x21/0x3e
    [<ffffffff81162847>] slab_post_alloc_hook+0x28/0x2a
    [<ffffffff81164702>] __kmalloc+0xde/0x118
    [<ffffffff812dbc16>] kzalloc.constprop.32+0xe/0x10
    [<ffffffff812dbcb4>] pci_add_cap_save_buffer.part.16+0x1f/0x62
    [<ffffffff812dd825>] pci_allocate_cap_save_buffers+0x29/0x82
    [<ffffffff812d9877>] pci_device_add+0xa3/0x14c
    [<ffffffff816b4756>] pci_scan_single_device+0x8b/0x99
    [<ffffffff812d9972>] pci_scan_slot+0x52/0xf6
    [<ffffffff816b5523>] enable_device+0xdb/0x393
    [<ffffffff812ed278>] acpiphp_enable_slot+0xcb/0x130
    [<ffffffff812ed454>] acpiphp_check_bridge+0x6e/0xd4
    [<ffffffff812ed812>] _handle_hotplug_event_bridge+0xc8/0x218
    [<ffffffff810d8463>] process_one_work+0x1cb/0x2dd
    [<ffffffff810d8936>] worker_thread+0x12f/0x1fc
    [<ffffffff810dd519>] kthread+0xac/0xb4
unreferenced object 0xffff880408619460 (size 256):
  comm "kworker/0:0", pid 4, jiffies 4294951635 (age 27929.260s)
  hex dump (first 32 bytes):
    04 04 00 00 ad 4e ad de ff ff ff ff 00 00 00 00  .....N..........
    ff ff ff ff ff ff ff ff f8 89 6d 82 ff ff ff ff  ..........m.....
  backtrace:
    [<ffffffff816b46ae>] kmemleak_alloc+0x21/0x3e
    [<ffffffff81162847>] slab_post_alloc_hook+0x28/0x2a
    [<ffffffff811648c9>] kmem_cache_alloc+0xb0/0xc0
    [<ffffffff813e7f6e>] device_private_init+0x1b/0x68
    [<ffffffff813e8006>] device_add+0x4b/0x5d2
    [<ffffffff812d98fb>] pci_device_add+0x127/0x14c
    [<ffffffff816b4756>] pci_scan_single_device+0x8b/0x99
    [<ffffffff812d9972>] pci_scan_slot+0x52/0xf6
    [<ffffffff816b5523>] enable_device+0xdb/0x393
    [<ffffffff812ed278>] acpiphp_enable_slot+0xcb/0x130
    [<ffffffff812ed454>] acpiphp_check_bridge+0x6e/0xd4
    [<ffffffff812ed812>] _handle_hotplug_event_bridge+0xc8/0x218
    [<ffffffff810d8463>] process_one_work+0x1cb/0x2dd
    [<ffffffff810d8936>] worker_thread+0x12f/0x1fc
    [<ffffffff810dd519>] kthread+0xac/0xb4
    [<ffffffff816cbd2c>] ret_from_fork+0x7c/0xb0
unreferenced object 0xffff880409246090 (size 4096):
  comm "kworker/0:0", pid 4, jiffies 4294954516 (age 27900.450s)
  hex dump (first 32 bytes):
    00 01 10 00 00 00 ad de 00 02 20 00 00 00 ad de  .......... .....
    38 69 f5 0c 04 88 ff ff 00 00 00 00 00 00 00 00  8i..............
  backtrace:
    [<ffffffff816b46ae>] kmemleak_alloc+0x21/0x3e
    [<ffffffff81162847>] slab_post_alloc_hook+0x28/0x2a
    [<ffffffff811648c9>] kmem_cache_alloc+0xb0/0xc0
    [<ffffffff812d8baa>] alloc_pci_dev+0x15/0x2e
    [<ffffffff816b4714>] pci_scan_single_device+0x49/0x99
    [<ffffffff812d9972>] pci_scan_slot+0x52/0xf6
    [<ffffffff816b5523>] enable_device+0xdb/0x393
    [<ffffffff812ed278>] acpiphp_enable_slot+0xcb/0x130
    [<ffffffff812ed454>] acpiphp_check_bridge+0x6e/0xd4
    [<ffffffff812ed812>] _handle_hotplug_event_bridge+0xc8/0x218
    [<ffffffff810d8463>] process_one_work+0x1cb/0x2dd
    [<ffffffff810d8936>] worker_thread+0x12f/0x1fc
    [<ffffffff810dd519>] kthread+0xac/0xb4
    [<ffffffff816cbd2c>] ret_from_fork+0x7c/0xb0
    [<ffffffffffffffff>] 0xffffffffffffffff
unreferenced object 0xffff8804077e8fc8 (size 16):
  comm "kworker/0:0", pid 4, jiffies 4294954516 (age 27900.450s)
  hex dump (first 16 bytes):
    30 30 30 30 3a 31 31 3a 30 30 2e 30 00 6b 6b a5  0000:11:00.0.kk.
  backtrace:
    [<ffffffff816b46ae>] kmemleak_alloc+0x21/0x3e
    [<ffffffff81162847>] slab_post_alloc_hook+0x28/0x2a
    [<ffffffff81165ccf>] __kmalloc_track_caller+0xdd/0x118
    [<ffffffff812c2727>] kvasprintf+0x4b/0x74
    [<ffffffff812b916d>] kobject_set_name_vargs+0x21/0x56
    [<ffffffff813e6e44>] dev_set_name+0x3c/0x3e
    [<ffffffff812d951b>] pci_setup_device+0xfc/0x3b5
    [<ffffffff816b473a>] pci_scan_single_device+0x6f/0x99
    [<ffffffff812d9972>] pci_scan_slot+0x52/0xf6
    [<ffffffff816b5523>] enable_device+0xdb/0x393
    [<ffffffff812ed278>] acpiphp_enable_slot+0xcb/0x130
    [<ffffffff812ed454>] acpiphp_check_bridge+0x6e/0xd4
    [<ffffffff812ed812>] _handle_hotplug_event_bridge+0xc8/0x218
    [<ffffffff810d8463>] process_one_work+0x1cb/0x2dd
    [<ffffffff810d8936>] worker_thread+0x12f/0x1fc
    [<ffffffff810dd519>] kthread+0xac/0xb4
unreferenced object 0xffff880404403000 (size 64):
  comm "kworker/0:0", pid 4, jiffies 4294954516 (age 27900.450s)
  hex dump (first 32 bytes):
    00 00 00 00 00 00 00 00 08 69 24 09 04 88 ff ff  .........i$.....
    10 00 00 00 0e 00 00 00 00 00 00 00 00 00 00 00  ................
  backtrace:
    [<ffffffff816b46ae>] kmemleak_alloc+0x21/0x3e
    [<ffffffff81162847>] slab_post_alloc_hook+0x28/0x2a
    [<ffffffff81164702>] __kmalloc+0xde/0x118
    [<ffffffff812dbc16>] kzalloc.constprop.32+0xe/0x10
    [<ffffffff812dbcb4>] pci_add_cap_save_buffer.part.16+0x1f/0x62
    [<ffffffff812dd825>] pci_allocate_cap_save_buffers+0x29/0x82
    [<ffffffff812d9877>] pci_device_add+0xa3/0x14c
    [<ffffffff816b4756>] pci_scan_single_device+0x8b/0x99
    [<ffffffff812d9972>] pci_scan_slot+0x52/0xf6
    [<ffffffff816b5523>] enable_device+0xdb/0x393
    [<ffffffff812ed278>] acpiphp_enable_slot+0xcb/0x130
    [<ffffffff812ed454>] acpiphp_check_bridge+0x6e/0xd4
    [<ffffffff812ed812>] _handle_hotplug_event_bridge+0xc8/0x218
    [<ffffffff810d8463>] process_one_work+0x1cb/0x2dd
    [<ffffffff810d8936>] worker_thread+0x12f/0x1fc
    [<ffffffff810dd519>] kthread+0xac/0xb4
unreferenced object 0xffff880404574118 (size 256):
  comm "kworker/0:0", pid 4, jiffies 4294954516 (age 27900.450s)
  hex dump (first 32 bytes):
    04 04 00 00 ad 4e ad de ff ff ff ff 00 00 00 00  .....N..........
    ff ff ff ff ff ff ff ff f8 89 6d 82 ff ff ff ff  ..........m.....
  backtrace:
    [<ffffffff816b46ae>] kmemleak_alloc+0x21/0x3e
    [<ffffffff81162847>] slab_post_alloc_hook+0x28/0x2a
    [<ffffffff811648c9>] kmem_cache_alloc+0xb0/0xc0
    [<ffffffff813e7f6e>] device_private_init+0x1b/0x68
    [<ffffffff813e8006>] device_add+0x4b/0x5d2
    [<ffffffff812d98fb>] pci_device_add+0x127/0x14c
    [<ffffffff816b4756>] pci_scan_single_device+0x8b/0x99
    [<ffffffff812d9972>] pci_scan_slot+0x52/0xf6
    [<ffffffff816b5523>] enable_device+0xdb/0x393
    [<ffffffff812ed278>] acpiphp_enable_slot+0xcb/0x130
    [<ffffffff812ed454>] acpiphp_check_bridge+0x6e/0xd4
    [<ffffffff812ed812>] _handle_hotplug_event_bridge+0xc8/0x218
    [<ffffffff810d8463>] process_one_work+0x1cb/0x2dd
    [<ffffffff810d8936>] worker_thread+0x12f/0x1fc
    [<ffffffff810dd519>] kthread+0xac/0xb4
    [<ffffffff816cbd2c>] ret_from_fork+0x7c/0xb0
unreferenced object 0xffff880409241018 (size 4096):
  comm "kworker/0:0", pid 4, jiffies 4294958111 (age 27864.500s)
  hex dump (first 32 bytes):
    00 01 10 00 00 00 ad de 00 02 20 00 00 00 ad de  .......... .....
    38 69 f5 0c 04 88 ff ff 00 00 00 00 00 00 00 00  8i..............
  backtrace:
    [<ffffffff816b46ae>] kmemleak_alloc+0x21/0x3e
    [<ffffffff81162847>] slab_post_alloc_hook+0x28/0x2a
    [<ffffffff811648c9>] kmem_cache_alloc+0xb0/0xc0
    [<ffffffff812d8baa>] alloc_pci_dev+0x15/0x2e
    [<ffffffff816b4714>] pci_scan_single_device+0x49/0x99
    [<ffffffff812d9972>] pci_scan_slot+0x52/0xf6
    [<ffffffff816b5523>] enable_device+0xdb/0x393
    [<ffffffff812ed278>] acpiphp_enable_slot+0xcb/0x130
    [<ffffffff812ed454>] acpiphp_check_bridge+0x6e/0xd4
    [<ffffffff812ed812>] _handle_hotplug_event_bridge+0xc8/0x218
    [<ffffffff810d8463>] process_one_work+0x1cb/0x2dd
    [<ffffffff810d8936>] worker_thread+0x12f/0x1fc
    [<ffffffff810dd519>] kthread+0xac/0xb4
    [<ffffffff816cbd2c>] ret_from_fork+0x7c/0xb0
    [<ffffffffffffffff>] 0xffffffffffffffff
unreferenced object 0xffff880407f59988 (size 16):
  comm "kworker/0:0", pid 4, jiffies 4294958111 (age 27864.510s)
  hex dump (first 16 bytes):
    30 30 30 30 3a 31 31 3a 30 30 2e 30 00 6b 6b a5  0000:11:00.0.kk.
  backtrace:
    [<ffffffff816b46ae>] kmemleak_alloc+0x21/0x3e
    [<ffffffff81162847>] slab_post_alloc_hook+0x28/0x2a
    [<ffffffff81165ccf>] __kmalloc_track_caller+0xdd/0x118
    [<ffffffff812c2727>] kvasprintf+0x4b/0x74
    [<ffffffff812b916d>] kobject_set_name_vargs+0x21/0x56
    [<ffffffff813e6e44>] dev_set_name+0x3c/0x3e
    [<ffffffff812d951b>] pci_setup_device+0xfc/0x3b5
    [<ffffffff816b473a>] pci_scan_single_device+0x6f/0x99
    [<ffffffff812d9972>] pci_scan_slot+0x52/0xf6
    [<ffffffff816b5523>] enable_device+0xdb/0x393
    [<ffffffff812ed278>] acpiphp_enable_slot+0xcb/0x130
    [<ffffffff812ed454>] acpiphp_check_bridge+0x6e/0xd4
    [<ffffffff812ed812>] _handle_hotplug_event_bridge+0xc8/0x218
    [<ffffffff810d8463>] process_one_work+0x1cb/0x2dd
    [<ffffffff810d8936>] worker_thread+0x12f/0x1fc
    [<ffffffff810dd519>] kthread+0xac/0xb4
unreferenced object 0xffff880404403370 (size 64):
  comm "kworker/0:0", pid 4, jiffies 4294958111 (age 27864.510s)
  hex dump (first 32 bytes):
    00 00 00 00 00 00 00 00 90 18 24 09 04 88 ff ff  ..........$.....
    10 00 00 00 0e 00 00 00 00 00 00 00 00 00 00 00  ................
  backtrace:
    [<ffffffff816b46ae>] kmemleak_alloc+0x21/0x3e
    [<ffffffff81162847>] slab_post_alloc_hook+0x28/0x2a
    [<ffffffff81164702>] __kmalloc+0xde/0x118
    [<ffffffff812dbc16>] kzalloc.constprop.32+0xe/0x10
    [<ffffffff812dbcb4>] pci_add_cap_save_buffer.part.16+0x1f/0x62
    [<ffffffff812dd825>] pci_allocate_cap_save_buffers+0x29/0x82
    [<ffffffff812d9877>] pci_device_add+0xa3/0x14c
    [<ffffffff816b4756>] pci_scan_single_device+0x8b/0x99
    [<ffffffff812d9972>] pci_scan_slot+0x52/0xf6
    [<ffffffff816b5523>] enable_device+0xdb/0x393
    [<ffffffff812ed278>] acpiphp_enable_slot+0xcb/0x130
    [<ffffffff812ed454>] acpiphp_check_bridge+0x6e/0xd4
    [<ffffffff812ed812>] _handle_hotplug_event_bridge+0xc8/0x218
    [<ffffffff810d8463>] process_one_work+0x1cb/0x2dd
    [<ffffffff810d8936>] worker_thread+0x12f/0x1fc
    [<ffffffff810dd519>] kthread+0xac/0xb4
unreferenced object 0xffff8804044008c0 (size 256):
  comm "kworker/0:0", pid 4, jiffies 4294958111 (age 27864.510s)
  hex dump (first 32 bytes):
    05 05 00 00 ad 4e ad de ff ff ff ff 00 00 00 00  .....N..........
    ff ff ff ff ff ff ff ff f8 89 6d 82 ff ff ff ff  ..........m.....
  backtrace:
    [<ffffffff816b46ae>] kmemleak_alloc+0x21/0x3e
    [<ffffffff81162847>] slab_post_alloc_hook+0x28/0x2a
    [<ffffffff811648c9>] kmem_cache_alloc+0xb0/0xc0
    [<ffffffff813e7f6e>] device_private_init+0x1b/0x68
    [<ffffffff813e8006>] device_add+0x4b/0x5d2
    [<ffffffff812d98fb>] pci_device_add+0x127/0x14c
    [<ffffffff816b4756>] pci_scan_single_device+0x8b/0x99
    [<ffffffff812d9972>] pci_scan_slot+0x52/0xf6
    [<ffffffff816b5523>] enable_device+0xdb/0x393
    [<ffffffff812ed278>] acpiphp_enable_slot+0xcb/0x130
    [<ffffffff812ed454>] acpiphp_check_bridge+0x6e/0xd4
    [<ffffffff812ed812>] _handle_hotplug_event_bridge+0xc8/0x218
    [<ffffffff810d8463>] process_one_work+0x1cb/0x2dd
    [<ffffffff810d8936>] worker_thread+0x12f/0x1fc
    [<ffffffff810dd519>] kthread+0xac/0xb4
    [<ffffffff816cbd2c>] ret_from_fork+0x7c/0xb0
unreferenced object 0xffff880409243048 (size 4096):
  comm "kworker/0:0", pid 4, jiffies 4294961501 (age 27830.610s)
  hex dump (first 32 bytes):
    00 01 10 00 00 00 ad de 00 02 20 00 00 00 ad de  .......... .....
    38 69 f5 0c 04 88 ff ff 00 00 00 00 00 00 00 00  8i..............
  backtrace:
    [<ffffffff816b46ae>] kmemleak_alloc+0x21/0x3e
    [<ffffffff81162847>] slab_post_alloc_hook+0x28/0x2a
    [<ffffffff811648c9>] kmem_cache_alloc+0xb0/0xc0
    [<ffffffff812d8baa>] alloc_pci_dev+0x15/0x2e
    [<ffffffff816b4714>] pci_scan_single_device+0x49/0x99
    [<ffffffff812d9972>] pci_scan_slot+0x52/0xf6
    [<ffffffff816b5523>] enable_device+0xdb/0x393
    [<ffffffff812ed278>] acpiphp_enable_slot+0xcb/0x130
    [<ffffffff812ed454>] acpiphp_check_bridge+0x6e/0xd4
    [<ffffffff812ed812>] _handle_hotplug_event_bridge+0xc8/0x218
    [<ffffffff810d8463>] process_one_work+0x1cb/0x2dd
    [<ffffffff810d8936>] worker_thread+0x12f/0x1fc
    [<ffffffff810dd519>] kthread+0xac/0xb4
    [<ffffffff816cbd2c>] ret_from_fork+0x7c/0xb0
    [<ffffffffffffffff>] 0xffffffffffffffff
unreferenced object 0xffff880407f594d8 (size 16):
  comm "kworker/0:0", pid 4, jiffies 4294961501 (age 27830.610s)
  hex dump (first 16 bytes):
    30 30 30 30 3a 31 31 3a 30 30 2e 30 00 6b 6b a5  0000:11:00.0.kk.
  backtrace:
    [<ffffffff816b46ae>] kmemleak_alloc+0x21/0x3e
    [<ffffffff81162847>] slab_post_alloc_hook+0x28/0x2a
    [<ffffffff81165ccf>] __kmalloc_track_caller+0xdd/0x118
    [<ffffffff812c2727>] kvasprintf+0x4b/0x74
    [<ffffffff812b916d>] kobject_set_name_vargs+0x21/0x56
    [<ffffffff813e6e44>] dev_set_name+0x3c/0x3e
    [<ffffffff812d951b>] pci_setup_device+0xfc/0x3b5
    [<ffffffff816b473a>] pci_scan_single_device+0x6f/0x99
    [<ffffffff812d9972>] pci_scan_slot+0x52/0xf6
    [<ffffffff816b5523>] enable_device+0xdb/0x393
    [<ffffffff812ed278>] acpiphp_enable_slot+0xcb/0x130
    [<ffffffff812ed454>] acpiphp_check_bridge+0x6e/0xd4
    [<ffffffff812ed812>] _handle_hotplug_event_bridge+0xc8/0x218
    [<ffffffff810d8463>] process_one_work+0x1cb/0x2dd
    [<ffffffff810d8936>] worker_thread+0x12f/0x1fc
    [<ffffffff810dd519>] kthread+0xac/0xb4
unreferenced object 0xffff8804095f1f78 (size 64):
  comm "kworker/0:0", pid 4, jiffies 4294961501 (age 27830.610s)
  hex dump (first 32 bytes):
    00 00 00 00 00 00 00 00 c0 38 24 09 04 88 ff ff  .........8$.....
    10 00 00 00 0e 00 00 00 00 00 00 00 00 00 00 00  ................
  backtrace:
    [<ffffffff816b46ae>] kmemleak_alloc+0x21/0x3e
    [<ffffffff81162847>] slab_post_alloc_hook+0x28/0x2a
    [<ffffffff81164702>] __kmalloc+0xde/0x118
    [<ffffffff812dbc16>] kzalloc.constprop.32+0xe/0x10
    [<ffffffff812dbcb4>] pci_add_cap_save_buffer.part.16+0x1f/0x62
    [<ffffffff812dd825>] pci_allocate_cap_save_buffers+0x29/0x82
    [<ffffffff812d9877>] pci_device_add+0xa3/0x14c
    [<ffffffff816b4756>] pci_scan_single_device+0x8b/0x99
    [<ffffffff812d9972>] pci_scan_slot+0x52/0xf6
    [<ffffffff816b5523>] enable_device+0xdb/0x393
    [<ffffffff812ed278>] acpiphp_enable_slot+0xcb/0x130
    [<ffffffff812ed454>] acpiphp_check_bridge+0x6e/0xd4
    [<ffffffff812ed812>] _handle_hotplug_event_bridge+0xc8/0x218
    [<ffffffff810d8463>] process_one_work+0x1cb/0x2dd
    [<ffffffff810d8936>] worker_thread+0x12f/0x1fc
    [<ffffffff810dd519>] kthread+0xac/0xb4
unreferenced object 0xffff8804044009d8 (size 256):
  comm "kworker/0:0", pid 4, jiffies 4294961501 (age 27830.620s)
  hex dump (first 32 bytes):
    05 05 00 00 ad 4e ad de ff ff ff ff 00 00 00 00  .....N..........
    ff ff ff ff ff ff ff ff f8 89 6d 82 ff ff ff ff  ..........m.....
  backtrace:
    [<ffffffff816b46ae>] kmemleak_alloc+0x21/0x3e
    [<ffffffff81162847>] slab_post_alloc_hook+0x28/0x2a
    [<ffffffff811648c9>] kmem_cache_alloc+0xb0/0xc0
    [<ffffffff813e7f6e>] device_private_init+0x1b/0x68
    [<ffffffff813e8006>] device_add+0x4b/0x5d2
    [<ffffffff812d98fb>] pci_device_add+0x127/0x14c
    [<ffffffff816b4756>] pci_scan_single_device+0x8b/0x99
    [<ffffffff812d9972>] pci_scan_slot+0x52/0xf6
    [<ffffffff816b5523>] enable_device+0xdb/0x393
    [<ffffffff812ed278>] acpiphp_enable_slot+0xcb/0x130
    [<ffffffff812ed454>] acpiphp_check_bridge+0x6e/0xd4
    [<ffffffff812ed812>] _handle_hotplug_event_bridge+0xc8/0x218
    [<ffffffff810d8463>] process_one_work+0x1cb/0x2dd
    [<ffffffff810d8936>] worker_thread+0x12f/0x1fc
    [<ffffffff810dd519>] kthread+0xac/0xb4
    [<ffffffff816cbd2c>] ret_from_fork+0x7c/0xb0
unreferenced object 0xffff880409245078 (size 4096):
  comm "kworker/0:0", pid 4, jiffies 4294965008 (age 27795.550s)
  hex dump (first 32 bytes):
    00 01 10 00 00 00 ad de 00 02 20 00 00 00 ad de  .......... .....
    38 69 f5 0c 04 88 ff ff 00 00 00 00 00 00 00 00  8i..............
  backtrace:
    [<ffffffff816b46ae>] kmemleak_alloc+0x21/0x3e
    [<ffffffff81162847>] slab_post_alloc_hook+0x28/0x2a
    [<ffffffff811648c9>] kmem_cache_alloc+0xb0/0xc0
    [<ffffffff812d8baa>] alloc_pci_dev+0x15/0x2e
    [<ffffffff816b4714>] pci_scan_single_device+0x49/0x99
    [<ffffffff812d9972>] pci_scan_slot+0x52/0xf6
    [<ffffffff816b5523>] enable_device+0xdb/0x393
    [<ffffffff812ed278>] acpiphp_enable_slot+0xcb/0x130
    [<ffffffff812ed454>] acpiphp_check_bridge+0x6e/0xd4
    [<ffffffff812ed812>] _handle_hotplug_event_bridge+0xc8/0x218
    [<ffffffff810d8463>] process_one_work+0x1cb/0x2dd
    [<ffffffff810d8936>] worker_thread+0x12f/0x1fc
    [<ffffffff810dd519>] kthread+0xac/0xb4
    [<ffffffff816cbd2c>] ret_from_fork+0x7c/0xb0
    [<ffffffffffffffff>] 0xffffffffffffffff
unreferenced object 0xffff880407f59500 (size 16):
  comm "kworker/0:0", pid 4, jiffies 4294965008 (age 27795.550s)
  hex dump (first 16 bytes):
    30 30 30 30 3a 31 31 3a 30 30 2e 30 00 6b 6b a5  0000:11:00.0.kk.
  backtrace:
    [<ffffffff816b46ae>] kmemleak_alloc+0x21/0x3e
    [<ffffffff81162847>] slab_post_alloc_hook+0x28/0x2a
    [<ffffffff81165ccf>] __kmalloc_track_caller+0xdd/0x118
    [<ffffffff812c2727>] kvasprintf+0x4b/0x74
    [<ffffffff812b916d>] kobject_set_name_vargs+0x21/0x56
    [<ffffffff813e6e44>] dev_set_name+0x3c/0x3e
    [<ffffffff812d951b>] pci_setup_device+0xfc/0x3b5
    [<ffffffff816b473a>] pci_scan_single_device+0x6f/0x99
    [<ffffffff812d9972>] pci_scan_slot+0x52/0xf6
    [<ffffffff816b5523>] enable_device+0xdb/0x393
    [<ffffffff812ed278>] acpiphp_enable_slot+0xcb/0x130
    [<ffffffff812ed454>] acpiphp_check_bridge+0x6e/0xd4
    [<ffffffff812ed812>] _handle_hotplug_event_bridge+0xc8/0x218
    [<ffffffff810d8463>] process_one_work+0x1cb/0x2dd
    [<ffffffff810d8936>] worker_thread+0x12f/0x1fc
    [<ffffffff810dd519>] kthread+0xac/0xb4
unreferenced object 0xffff8804095f19a0 (size 64):
  comm "kworker/0:0", pid 4, jiffies 4294965008 (age 27795.550s)
  hex dump (first 32 bytes):
    00 00 00 00 00 00 00 00 f0 58 24 09 04 88 ff ff  .........X$.....
    10 00 00 00 0e 00 00 00 00 00 00 00 00 00 00 00  ................
  backtrace:
    [<ffffffff816b46ae>] kmemleak_alloc+0x21/0x3e
    [<ffffffff81162847>] slab_post_alloc_hook+0x28/0x2a
    [<ffffffff81164702>] __kmalloc+0xde/0x118
    [<ffffffff812dbc16>] kzalloc.constprop.32+0xe/0x10
    [<ffffffff812dbcb4>] pci_add_cap_save_buffer.part.16+0x1f/0x62
    [<ffffffff812dd825>] pci_allocate_cap_save_buffers+0x29/0x82
    [<ffffffff812d9877>] pci_device_add+0xa3/0x14c
    [<ffffffff816b4756>] pci_scan_single_device+0x8b/0x99
    [<ffffffff812d9972>] pci_scan_slot+0x52/0xf6
    [<ffffffff816b5523>] enable_device+0xdb/0x393
    [<ffffffff812ed278>] acpiphp_enable_slot+0xcb/0x130
    [<ffffffff812ed454>] acpiphp_check_bridge+0x6e/0xd4
    [<ffffffff812ed812>] _handle_hotplug_event_bridge+0xc8/0x218
    [<ffffffff810d8463>] process_one_work+0x1cb/0x2dd
    [<ffffffff810d8936>] worker_thread+0x12f/0x1fc
    [<ffffffff810dd519>] kthread+0xac/0xb4
unreferenced object 0xffff880404400460 (size 256):
  comm "kworker/0:0", pid 4, jiffies 4294965008 (age 27795.550s)
  hex dump (first 32 bytes):
    04 04 00 00 ad 4e ad de ff ff ff ff 00 00 00 00  .....N..........
    ff ff ff ff ff ff ff ff f8 89 6d 82 ff ff ff ff  ..........m.....
  backtrace:
    [<ffffffff816b46ae>] kmemleak_alloc+0x21/0x3e
    [<ffffffff81162847>] slab_post_alloc_hook+0x28/0x2a
    [<ffffffff811648c9>] kmem_cache_alloc+0xb0/0xc0
    [<ffffffff813e7f6e>] device_private_init+0x1b/0x68
    [<ffffffff813e8006>] device_add+0x4b/0x5d2
    [<ffffffff812d98fb>] pci_device_add+0x127/0x14c
    [<ffffffff816b4756>] pci_scan_single_device+0x8b/0x99
    [<ffffffff812d9972>] pci_scan_slot+0x52/0xf6
    [<ffffffff816b5523>] enable_device+0xdb/0x393
    [<ffffffff812ed278>] acpiphp_enable_slot+0xcb/0x130
    [<ffffffff812ed454>] acpiphp_check_bridge+0x6e/0xd4
    [<ffffffff812ed812>] _handle_hotplug_event_bridge+0xc8/0x218
    [<ffffffff810d8463>] process_one_work+0x1cb/0x2dd
    [<ffffffff810d8936>] worker_thread+0x12f/0x1fc
    [<ffffffff810dd519>] kthread+0xac/0xb4
    [<ffffffff816cbd2c>] ret_from_fork+0x7c/0xb0
unreferenced object 0xffff88040af38860 (size 512):
  comm "kworker/0:0", pid 4, jiffies 4294965009 (age 27795.540s)
  hex dump (first 32 bytes):
    10 51 24 09 04 88 ff ff 06 00 00 00 00 00 00 00  .Q$.............
    00 95 f5 07 04 88 ff ff 01 00 00 04 ff ff ff ff  ................
  backtrace:
    [<ffffffff816b46ae>] kmemleak_alloc+0x21/0x3e
    [<ffffffff81162847>] slab_post_alloc_hook+0x28/0x2a
    [<ffffffff81164702>] __kmalloc+0xde/0x118
    [<ffffffff81449d90>] usb_create_shared_hcd+0x30/0x206
    [<ffffffff81474363>] xhci_pci_probe+0x5a/0xd1
    [<ffffffff812df27e>] local_pci_probe+0x39/0x61
    [<ffffffff812df4a6>] pci_device_probe+0xba/0xe0
    [<ffffffff813ea752>] driver_probe_device+0x99/0x1c7
    [<ffffffff813ea914>] __device_attach+0x25/0x38
    [<ffffffff813e8d6f>] bus_for_each_drv+0x4f/0x8b
    [<ffffffff813ea67c>] device_attach+0x66/0x87
    [<ffffffff812d828b>] pci_bus_add_device+0x32/0x54
    [<ffffffff812d83d6>] pci_bus_add_devices+0x29/0x7d
    [<ffffffff816b577c>] enable_device+0x334/0x393
    [<ffffffff812ed278>] acpiphp_enable_slot+0xcb/0x130
    [<ffffffff812ed454>] acpiphp_check_bridge+0x6e/0xd4
unreferenced object 0xffff8804095e0000 (size 4096):
  comm "kworker/0:0", pid 4, jiffies 4294977262 (age 27673.040s)
  hex dump (first 32 bytes):
    00 01 10 00 00 00 ad de 00 02 20 00 00 00 ad de  .......... .....
    38 69 f5 0c 04 88 ff ff 00 00 00 00 00 00 00 00  8i..............
  backtrace:
    [<ffffffff816b46ae>] kmemleak_alloc+0x21/0x3e
    [<ffffffff81162847>] slab_post_alloc_hook+0x28/0x2a
    [<ffffffff811648c9>] kmem_cache_alloc+0xb0/0xc0
    [<ffffffff812d8baa>] alloc_pci_dev+0x15/0x2e
    [<ffffffff816b4714>] pci_scan_single_device+0x49/0x99
    [<ffffffff812d9972>] pci_scan_slot+0x52/0xf6
    [<ffffffff816b5523>] enable_device+0xdb/0x393
    [<ffffffff812ed278>] acpiphp_enable_slot+0xcb/0x130
    [<ffffffff812ed454>] acpiphp_check_bridge+0x6e/0xd4
    [<ffffffff812ed812>] _handle_hotplug_event_bridge+0xc8/0x218
    [<ffffffff810d8463>] process_one_work+0x1cb/0x2dd
    [<ffffffff810d8936>] worker_thread+0x12f/0x1fc
    [<ffffffff810dd519>] kthread+0xac/0xb4
    [<ffffffff816cbd2c>] ret_from_fork+0x7c/0xb0
    [<ffffffffffffffff>] 0xffffffffffffffff
unreferenced object 0xffff8804077e8460 (size 16):
  comm "kworker/0:0", pid 4, jiffies 4294977262 (age 27673.040s)
  hex dump (first 16 bytes):
    30 30 30 30 3a 31 31 3a 30 30 2e 30 00 6b 6b a5  0000:11:00.0.kk.
  backtrace:
    [<ffffffff816b46ae>] kmemleak_alloc+0x21/0x3e
    [<ffffffff81162847>] slab_post_alloc_hook+0x28/0x2a
    [<ffffffff81165ccf>] __kmalloc_track_caller+0xdd/0x118
    [<ffffffff812c2727>] kvasprintf+0x4b/0x74
    [<ffffffff812b916d>] kobject_set_name_vargs+0x21/0x56
    [<ffffffff813e6e44>] dev_set_name+0x3c/0x3e
    [<ffffffff812d951b>] pci_setup_device+0xfc/0x3b5
    [<ffffffff816b473a>] pci_scan_single_device+0x6f/0x99
    [<ffffffff812d9972>] pci_scan_slot+0x52/0xf6
    [<ffffffff816b5523>] enable_device+0xdb/0x393
    [<ffffffff812ed278>] acpiphp_enable_slot+0xcb/0x130
    [<ffffffff812ed454>] acpiphp_check_bridge+0x6e/0xd4
    [<ffffffff812ed812>] _handle_hotplug_event_bridge+0xc8/0x218
    [<ffffffff810d8463>] process_one_work+0x1cb/0x2dd
    [<ffffffff810d8936>] worker_thread+0x12f/0x1fc
    [<ffffffff810dd519>] kthread+0xac/0xb4
unreferenced object 0xffff880401d98478 (size 64):
  comm "kworker/0:0", pid 4, jiffies 4294977262 (age 27673.040s)
  hex dump (first 32 bytes):
    00 00 00 00 00 00 00 00 78 08 5e 09 04 88 ff ff  ........x.^.....
    10 00 00 00 0e 00 00 00 00 00 00 00 00 00 00 00  ................
  backtrace:
    [<ffffffff816b46ae>] kmemleak_alloc+0x21/0x3e
    [<ffffffff81162847>] slab_post_alloc_hook+0x28/0x2a
    [<ffffffff81164702>] __kmalloc+0xde/0x118
    [<ffffffff812dbc16>] kzalloc.constprop.32+0xe/0x10
    [<ffffffff812dbcb4>] pci_add_cap_save_buffer.part.16+0x1f/0x62
    [<ffffffff812dd825>] pci_allocate_cap_save_buffers+0x29/0x82
    [<ffffffff812d9877>] pci_device_add+0xa3/0x14c
    [<ffffffff816b4756>] pci_scan_single_device+0x8b/0x99
    [<ffffffff812d9972>] pci_scan_slot+0x52/0xf6
    [<ffffffff816b5523>] enable_device+0xdb/0x393
    [<ffffffff812ed278>] acpiphp_enable_slot+0xcb/0x130
    [<ffffffff812ed454>] acpiphp_check_bridge+0x6e/0xd4
    [<ffffffff812ed812>] _handle_hotplug_event_bridge+0xc8/0x218
    [<ffffffff810d8463>] process_one_work+0x1cb/0x2dd
    [<ffffffff810d8936>] worker_thread+0x12f/0x1fc
    [<ffffffff810dd519>] kthread+0xac/0xb4
unreferenced object 0xffff880404574c08 (size 256):
  comm "kworker/0:0", pid 4, jiffies 4294977262 (age 27673.040s)
  hex dump (first 32 bytes):
    04 04 00 00 ad 4e ad de ff ff ff ff 00 00 00 00  .....N..........
    ff ff ff ff ff ff ff ff f8 89 6d 82 ff ff ff ff  ..........m.....
  backtrace:
    [<ffffffff816b46ae>] kmemleak_alloc+0x21/0x3e
    [<ffffffff81162847>] slab_post_alloc_hook+0x28/0x2a
    [<ffffffff811648c9>] kmem_cache_alloc+0xb0/0xc0
    [<ffffffff813e7f6e>] device_private_init+0x1b/0x68
    [<ffffffff813e8006>] device_add+0x4b/0x5d2
    [<ffffffff812d98fb>] pci_device_add+0x127/0x14c
    [<ffffffff816b4756>] pci_scan_single_device+0x8b/0x99
    [<ffffffff812d9972>] pci_scan_slot+0x52/0xf6
    [<ffffffff816b5523>] enable_device+0xdb/0x393
    [<ffffffff812ed278>] acpiphp_enable_slot+0xcb/0x130
    [<ffffffff812ed454>] acpiphp_check_bridge+0x6e/0xd4
    [<ffffffff812ed812>] _handle_hotplug_event_bridge+0xc8/0x218
    [<ffffffff810d8463>] process_one_work+0x1cb/0x2dd
    [<ffffffff810d8936>] worker_thread+0x12f/0x1fc
    [<ffffffff810dd519>] kthread+0xac/0xb4
    [<ffffffff816cbd2c>] ret_from_fork+0x7c/0xb0
unreferenced object 0xffff88040afd8218 (size 512):
  comm "kworker/0:0", pid 4, jiffies 4294977263 (age 27673.030s)
  hex dump (first 32 bytes):
    98 00 5e 09 04 88 ff ff 06 00 00 00 00 00 00 00  ..^.............
    60 84 7e 07 04 88 ff ff 01 00 00 04 ff ff ff ff  `.~.............
  backtrace:
    [<ffffffff816b46ae>] kmemleak_alloc+0x21/0x3e
    [<ffffffff81162847>] slab_post_alloc_hook+0x28/0x2a
    [<ffffffff81164702>] __kmalloc+0xde/0x118
    [<ffffffff81449d90>] usb_create_shared_hcd+0x30/0x206
    [<ffffffff81474363>] xhci_pci_probe+0x5a/0xd1
    [<ffffffff812df27e>] local_pci_probe+0x39/0x61
    [<ffffffff812df4a6>] pci_device_probe+0xba/0xe0
    [<ffffffff813ea752>] driver_probe_device+0x99/0x1c7
    [<ffffffff813ea914>] __device_attach+0x25/0x38
    [<ffffffff813e8d6f>] bus_for_each_drv+0x4f/0x8b
    [<ffffffff813ea67c>] device_attach+0x66/0x87
    [<ffffffff812d828b>] pci_bus_add_device+0x32/0x54
    [<ffffffff812d83d6>] pci_bus_add_devices+0x29/0x7d
    [<ffffffff816b577c>] enable_device+0x334/0x393
    [<ffffffff812ed278>] acpiphp_enable_slot+0xcb/0x130
    [<ffffffff812ed454>] acpiphp_check_bridge+0x6e/0xd4
unreferenced object 0xffff88040a19f4f0 (size 512):
  comm "kworker/0:1", pid 3682, jiffies 4294983122 (age 27614.440s)
  hex dump (first 32 bytes):
    c8 20 24 09 04 88 ff ff 06 00 00 00 00 00 00 00  . $.............
    a8 87 7e 07 04 88 ff ff 01 00 00 04 ff ff ff ff  ..~.............
  backtrace:
    [<ffffffff816b46ae>] kmemleak_alloc+0x21/0x3e
    [<ffffffff81162847>] slab_post_alloc_hook+0x28/0x2a
    [<ffffffff81164702>] __kmalloc+0xde/0x118
    [<ffffffff81449d90>] usb_create_shared_hcd+0x30/0x206
    [<ffffffff81474363>] xhci_pci_probe+0x5a/0xd1
    [<ffffffff812df27e>] local_pci_probe+0x39/0x61
    [<ffffffff812df4a6>] pci_device_probe+0xba/0xe0
    [<ffffffff813ea752>] driver_probe_device+0x99/0x1c7
    [<ffffffff813ea914>] __device_attach+0x25/0x38
    [<ffffffff813e8d6f>] bus_for_each_drv+0x4f/0x8b
    [<ffffffff813ea67c>] device_attach+0x66/0x87
    [<ffffffff812d828b>] pci_bus_add_device+0x32/0x54
    [<ffffffff812d83d6>] pci_bus_add_devices+0x29/0x7d
    [<ffffffff816b577c>] enable_device+0x334/0x393
    [<ffffffff812ed278>] acpiphp_enable_slot+0xcb/0x130
    [<ffffffff812ed454>] acpiphp_check_bridge+0x6e/0xd4

Comments

Martin Mokrejs June 7, 2013, 11:27 a.m. UTC | #1
Martin Mokrejs wrote:
> Hi everybody,
> 
> Bjorn Helgaas wrote:
>> [+cc linux-pci, Sarah, Alan]
>>
>> On Mon, Mar 11, 2013 at 10:02 AM, Martin Mokrejs
>> <mmokrejs@fold.natur.cuni.cz> wrote:
>>> [re-sending to you all three directly, looks the original email did not make it into linux-pci
>>> through some filters]
>>>
>>>   I use for my daily work acpiphp to manage express cards in Dell Vostro 3550.
>>> I have never seen something like this before and believe this is some new regression
>>> in 3.8 series. I had in teh a USB3 card and ejected it. Then I inserted a
>>> SATA Sil3132 card but it is not detected and dmesg still ends with last lines
>>> added when the USB card was being removed. The funny thing is that lspci reports
>>> a mixture of USB-card properties with NEC chips along with Silicon Image eSATA card.
>>
>> I don't know anything about the kmemleaks mentioned elsewhere in this
>> thread, but the idea of "stale PCI device info" seems possibly related
>> to some acpiphp issues we've been working on recently.
>>
>> Starting with v3.9, we don't handle ACPI Bus Check notifications to
>> host bridges correctly, and the result is that when we're using
>> acpiphp, we don't notice when PCI devices are added or removed. There
>> are more details in https://bugzilla.kernel.org/show_bug.cgi?id=57961
> 
> Looks to me it is already in 3.10-rc4 which I tested now. No, I still do see
> same problem like before: a hotremoval of NEC-based xHCI express card is detected
> on every second eject. But, sometimes it seems it is only delayed by some 25-30
> seconds. Would have to do more testing. However, there are some *new* kmemleaks
> reported by kernel related to acpiphpp bu xhci_hcd. That could a hint why
> the hotremoval sometimes proceeds delayed but sometimes maybe not at all or at
> least not *immediately* like for any other device?
> 
> However, the stale sysfs entries for partially removed device SiI3132 (sata_sil24
> driver) are NOT appearing anymore, good. That used to be associated with
> 'sata_sil24: IRQ status == 0xffffffff, PCI fault or device removal?' line.
> Now, I see under 3.10-rc4 the extra message about 'ACPI: Device does not support D3cold'.
> would be nice if it said what device is it talking about? About upstream root port
> or about my end device (express card)? Is it related by pcie_aspm= kernel
> commandline option? If yes, please include the relevant info the message text.
> referring to this being affected by the particular value. At the moment I used:
> pcie_aspm=off
> 
> --- dmesg_initial__inserted_eSATA__ejected__inserted__ejected__inserted.txt     2013-06-07 02:53:56.000000000 +0200
> +++ dmesg_initial__inserted_eSATA__ejected__inserted__ejected__inserted__ejected.txt    2013-06-07 02:54:09.000000000 +0200
> @@ -1439,3 +1439,5 @@
>  [  254.317365] ata12: SATA max UDMA/100 host m128@0xf6c04000 port 0xf6c02000 irq 19
>  [  256.400454] ata11: SATA link down (SStatus 0 SControl 0)
>  [  258.493027] ata12: SATA link down (SStatus 0 SControl 0)
> +[  267.116723] sata_sil24: IRQ status == 0xffffffff, PCI fault or device removal?
> +[  267.117779] ACPI: Device does not support D3cold
> 
> 
> So, in my eyes the "stale pci info" issue is fixed in 3.10-rc4 at least under acpiphp and pcie_aspm=off.

And to be even more exact, I had CONFIG_HOTPLUG_PCI_ACPI=y as I see now an updated
v2 patch from Yinghai:
[PATCH v3.9 stable] PCI: acpiphp: Re-enumerate devices when host bridge receives Bus Check

Please make sure that whatever I tested in plain 3.10-rc4 is what you had in those bugzilla patches
under https://bugzilla.kernel.org/show_bug.cgi?id=57961 or what Yinghai posted as an update.
Just in case are tested a different version.

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
Martin Mokrejs June 7, 2013, 3:55 p.m. UTC | #2
Martin Mokrejs wrote:
> Martin Mokrejs wrote:
>> Hi everybody,
>>
>> Bjorn Helgaas wrote:
>>> [+cc linux-pci, Sarah, Alan]
>>>
>>> On Mon, Mar 11, 2013 at 10:02 AM, Martin Mokrejs
>>> <mmokrejs@fold.natur.cuni.cz> wrote:
>>>> [re-sending to you all three directly, looks the original email did not make it into linux-pci
>>>> through some filters]
>>>>
>>>>   I use for my daily work acpiphp to manage express cards in Dell Vostro 3550.
>>>> I have never seen something like this before and believe this is some new regression
>>>> in 3.8 series. I had in teh a USB3 card and ejected it. Then I inserted a
>>>> SATA Sil3132 card but it is not detected and dmesg still ends with last lines
>>>> added when the USB card was being removed. The funny thing is that lspci reports
>>>> a mixture of USB-card properties with NEC chips along with Silicon Image eSATA card.
>>>
>>> I don't know anything about the kmemleaks mentioned elsewhere in this
>>> thread, but the idea of "stale PCI device info" seems possibly related
>>> to some acpiphp issues we've been working on recently.
>>>
>>> Starting with v3.9, we don't handle ACPI Bus Check notifications to
>>> host bridges correctly, and the result is that when we're using
>>> acpiphp, we don't notice when PCI devices are added or removed. There
>>> are more details in https://bugzilla.kernel.org/show_bug.cgi?id=57961
>>
>> Looks to me it is already in 3.10-rc4 which I tested now. No, I still do see
>> same problem like before: a hotremoval of NEC-based xHCI express card is detected
>> on every second eject. But, sometimes it seems it is only delayed by some 25-30
>> seconds. Would have to do more testing. However, there are some *new* kmemleaks
>> reported by kernel related to acpiphpp bu xhci_hcd. That could a hint why
>> the hotremoval sometimes proceeds delayed but sometimes maybe not at all or at
>> least not *immediately* like for any other device?
>>
>> However, the stale sysfs entries for partially removed device SiI3132 (sata_sil24
>> driver) are NOT appearing anymore, good. That used to be associated with
>> 'sata_sil24: IRQ status == 0xffffffff, PCI fault or device removal?' line.
>> Now, I see under 3.10-rc4 the extra message about 'ACPI: Device does not support D3cold'.
>> would be nice if it said what device is it talking about? About upstream root port
>> or about my end device (express card)? Is it related by pcie_aspm= kernel
>> commandline option? If yes, please include the relevant info the message text.
>> referring to this being affected by the particular value. At the moment I used:
>> pcie_aspm=off
>>
>> --- dmesg_initial__inserted_eSATA__ejected__inserted__ejected__inserted.txt     2013-06-07 02:53:56.000000000 +0200
>> +++ dmesg_initial__inserted_eSATA__ejected__inserted__ejected__inserted__ejected.txt    2013-06-07 02:54:09.000000000 +0200
>> @@ -1439,3 +1439,5 @@
>>  [  254.317365] ata12: SATA max UDMA/100 host m128@0xf6c04000 port 0xf6c02000 irq 19
>>  [  256.400454] ata11: SATA link down (SStatus 0 SControl 0)
>>  [  258.493027] ata12: SATA link down (SStatus 0 SControl 0)
>> +[  267.116723] sata_sil24: IRQ status == 0xffffffff, PCI fault or device removal?
>> +[  267.117779] ACPI: Device does not support D3cold
>>
>>
>> So, in my eyes the "stale pci info" issue is fixed in 3.10-rc4 at least under acpiphp and pcie_aspm=off.

No, it is not. :(

> 
> And to be even more exact, I had CONFIG_HOTPLUG_PCI_ACPI=y as I see now an updated
> v2 patch from Yinghai:
> [PATCH v3.9 stable] PCI: acpiphp: Re-enumerate devices when host bridge receives Bus Check
> 
> Please make sure that whatever I tested in plain 3.10-rc4 is what you had in those bugzilla patches
> under https://bugzilla.kernel.org/show_bug.cgi?id=57961 or what Yinghai posted as an update.
> Just in case are tested a different version.


Sorry, I was "able" to plugin a firewire card into express card slot faster
than xhci_hcd released resource of the to be yet hotremoved NEC-based xHCI
card. So, like in older kernels, lspci reports chimeric entry 11:00 of the
NEC card and of the VIA-based firewire card. Upon eject of the VIA card
xhci_hcd released resources with usual messages, including the complaint
that 'xhci_hcd 0000:11:00.0: Host not halted after 16000 microseconds.'
Nothing new in dmesg, I would just say that whatever makes xhci_hcd or pcieport
slow in turning PME# to disabled is efectively blocked if I plugin some card back
into the express slot. It seems to me the "conclusion" in the past in Jan-April
was that pcieport is to blame and not xhci_hcd, and it always seemed to proceed
smoothly once 'PME# disabled' appeared in dmesg.



> 
> 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
diff mbox

Patch

--- dmesg_initial__inserted_eSATA__ejected__inserted__ejected__inserted.txt     2013-06-07 02:53:56.000000000 +0200
+++ dmesg_initial__inserted_eSATA__ejected__inserted__ejected__inserted__ejected.txt    2013-06-07 02:54:09.000000000 +0200
@@ -1439,3 +1439,5 @@ 
 [  254.317365] ata12: SATA max UDMA/100 host m128@0xf6c04000 port 0xf6c02000 irq 19
 [  256.400454] ata11: SATA link down (SStatus 0 SControl 0)
 [  258.493027] ata12: SATA link down (SStatus 0 SControl 0)
+[  267.116723] sata_sil24: IRQ status == 0xffffffff, PCI fault or device removal?
+[  267.117779] ACPI: Device does not support D3cold