[Bug report] Warning when hot-add an ACPI0004 device.

[Bug report] Warning when hot-add an ACPI0004 device.

[Tang Chen]

Hi Rafael, Toshi,

When we hot-add an ACPI0004 device, we got the following warning:

	acpi ACPI0004:01: Attempt to re-insert

The ACPI0004 device is a System Board in Fujitsu server, which has two
numa nodes (processors and memory).

It seems that we reserved the ACPI_NOTIFY_DEVICE_CHECK event twice in
acpi_hotplug_notify_cb().


According to bisect, this happens after the following commit:

 From 68a67f6c78b80525d9b3c6672e7782de95e56a83 Mon Sep 17 00:00:00 2001
From: "Rafael J. Wysocki" <rafael.j.wysocki@intel.com>
Date: Sun, 3 Mar 2013 23:05:55 +0100
Subject: [PATCH 1/1] ACPI / container: Use common hotplug code

Switch the ACPI container driver to using common device hotplug code
introduced previously.  This reduces the driver down to a trivial
definition and registration of a struct acpi_scan_handler object.

Signed-off-by: Rafael J. Wysocki <rafael.j.wysocki@intel.com>
Acked-by: Toshi Kani <toshi.kani@hp.com>
Tested-by: Toshi Kani <toshi.kani@hp.com>
---
  drivers/acpi/container.c | 146 
++++-------------------------------------------
  1 file changed, 10 insertions(+), 136 deletions(-)


I'm now investigating this problem. If you have any idea about why this
happens, please let me know.

Thanks. :)

Re: [Bug report] Warning when hot-add an ACPI0004 device.

[Toshi Kani]

On Thu, 2013-09-12 at 13:00 +0800, Tang Chen wrote:
> Hi Rafael, Toshi,
> 
> When we hot-add an ACPI0004 device, we got the following warning:
> 
> 	acpi ACPI0004:01: Attempt to re-insert
> 
> The ACPI0004 device is a System Board in Fujitsu server, which has two
> numa nodes (processors and memory).
> 
> It seems that we reserved the ACPI_NOTIFY_DEVICE_CHECK event twice in
> acpi_hotplug_notify_cb().
> 
> 
> According to bisect, this happens after the following commit:
> 
>  From 68a67f6c78b80525d9b3c6672e7782de95e56a83 Mon Sep 17 00:00:00 2001
> From: "Rafael J. Wysocki" <rafael.j.wysocki@intel.com>
> Date: Sun, 3 Mar 2013 23:05:55 +0100
> Subject: [PATCH 1/1] ACPI / container: Use common hotplug code
> 
> Switch the ACPI container driver to using common device hotplug code
> introduced previously.  This reduces the driver down to a trivial
> definition and registration of a struct acpi_scan_handler object.
> 
> Signed-off-by: Rafael J. Wysocki <rafael.j.wysocki@intel.com>
> Acked-by: Toshi Kani <toshi.kani@hp.com>
> Tested-by: Toshi Kani <toshi.kani@hp.com>
> ---
>   drivers/acpi/container.c | 146 
> ++++-------------------------------------------
>   1 file changed, 10 insertions(+), 136 deletions(-)
> 
> 
> I'm now investigating this problem. If you have any idea about why this
> happens, please let me know.

With the above change, container devices use the common notify handler,
which logs the warning message in question when it receives device check
twice on a same device.  Before the change, the container-specific
notify handler did not log this message in the same case (but considered
it as an eject request).

So, I suspect that you are getting device check twice regardless of the
kernel change.  Can you check KERN_DEBUG messages to see if that is the
case?  The notify handler logs all events with KERN_DEBUG.

Thanks,
-Toshi

Re: [Bug report] Warning when hot-add an ACPI0004 device.

[Gu Zheng]

Hi Toshi,

On 09/12/2013 11:11 PM, Toshi Kani wrote:

> On Thu, 2013-09-12 at 13:00 +0800, Tang Chen wrote:
>> Hi Rafael, Toshi,
>>
>> When we hot-add an ACPI0004 device, we got the following warning:
>>
>> 	acpi ACPI0004:01: Attempt to re-insert
>>
>> The ACPI0004 device is a System Board in Fujitsu server, which has two
>> numa nodes (processors and memory).
>>
>> It seems that we reserved the ACPI_NOTIFY_DEVICE_CHECK event twice in
>> acpi_hotplug_notify_cb().
>>
>>
>> According to bisect, this happens after the following commit:
>>
>>  From 68a67f6c78b80525d9b3c6672e7782de95e56a83 Mon Sep 17 00:00:00 2001
>> From: "Rafael J. Wysocki" <rafael.j.wysocki@intel.com>
>> Date: Sun, 3 Mar 2013 23:05:55 +0100
>> Subject: [PATCH 1/1] ACPI / container: Use common hotplug code
>>
>> Switch the ACPI container driver to using common device hotplug code
>> introduced previously.  This reduces the driver down to a trivial
>> definition and registration of a struct acpi_scan_handler object.
>>
>> Signed-off-by: Rafael J. Wysocki <rafael.j.wysocki@intel.com>
>> Acked-by: Toshi Kani <toshi.kani@hp.com>
>> Tested-by: Toshi Kani <toshi.kani@hp.com>
>> ---
>>   drivers/acpi/container.c | 146 
>> ++++-------------------------------------------
>>   1 file changed, 10 insertions(+), 136 deletions(-)
>>
>>
>> I'm now investigating this problem. If you have any idea about why this
>> happens, please let me know.
> 
> With the above change, container devices use the common notify handler,
> which logs the warning message in question when it receives device check
> twice on a same device.  Before the change, the container-specific
> notify handler did not log this message in the same case (but considered
> it as an eject request).
> 
> So, I suspect that you are getting device check twice regardless of the
> kernel change.  Can you check KERN_DEBUG messages to see if that is the
> case?  The notify handler logs all events with KERN_DEBUG.

Follow your suggestion, we confirm that it really received ACPI_NOTIFY_
DEVICE_CHECK event*twice*, but the original ACPI container driver only
received once, does the common device hotplug code introduce another device
check? any idea?

Container uses common device hotplug code:
[  142.937724] IPv6: ADDRCONF(NETDEV_CHANGE): eth8: link becomes ready
[  674.975575] ACPI: \_SB_.LSB1: ACPI_NOTIFY_DEVICE_CHECK event          <<<<
[  674.991604] ACPI: \_SB_.LSB1: ACPI_NOTIFY_DEVICE_CHECK event		 <<<<	
[  675.613990] ACPI: PCI Root Bridge [UNC2] (domain 0000 [bus fd])
[  675.684970] acpi PNP0A03:01: ACPI _OSC support notification failed, disabling PCIe ASPM
[  675.780957] acpi PNP0A03:01: Unable to request _OSC control (_OSC support mask: 0x08)
[  675.874806] ACPI _OSC control for PCIe not granted, disabling ASPM
[  675.949005] pci_bus 0000:fd: Allocating resources
[  675.960145] ACPI: PCI Root Bridge [UNC3] (domain 0000 [bus fc])
[  676.031176] acpi PNP0A03:02: ACPI _OSC support notification failed, disabling PCIe ASPM
[  676.127129] acpi PNP0A03:02: Unable to request _OSC control (_OSC support mask: 0x08)
[  676.220943] ACPI _OSC control for PCIe not granted, disabling ASPM
[  676.295019] pci_bus 0000:fc: Allocating resources

Original ACPI container driver:
[ 1526.122933] Container driver received ACPI_NOTIFY_DEVICE_CHECK event <<<<
[ 1526.800646] ACPI: PCI Root Bridge [UNC2] (domain 0000 [bus fd])
[ 1526.871682] acpi PNP0A03:01: ACPI _OSC support notification failed, disabling PCIe ASPM
[ 1526.967878] acpi PNP0A03:01: Unable to request _OSC control (_OSC support mask: 0x08)
[ 1527.061891] ACPI _OSC control for PCIe not granted, disabling ASPM
[ 1527.136036] pci_bus 0000:fd: Allocating resources
[ 1527.150747] ACPI: PCI Root Bridge [UNC3] (domain 0000 [bus fc])
[ 1527.221821] acpi PNP0A03:02: ACPI _OSC support notification failed, disabling PCIe ASPM
[ 1527.317738] acpi PNP0A03:02: Unable to request _OSC control (_OSC support mask: 0x08)
[ 1527.411795] ACPI _OSC control for PCIe not granted, disabling ASPM
[ 1527.485917] pci_bus 0000:fc: Allocating resources


Thanks,
Gu

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

Re: [Bug report] Warning when hot-add an ACPI0004 device.

[Rafael J. Wysocki]

On Wednesday, September 25, 2013 06:31:09 PM Gu Zheng wrote:
> Hi Toshi,
> 
> On 09/12/2013 11:11 PM, Toshi Kani wrote:
> 
> > On Thu, 2013-09-12 at 13:00 +0800, Tang Chen wrote:
> >> Hi Rafael, Toshi,
> >>
> >> When we hot-add an ACPI0004 device, we got the following warning:
> >>
> >> 	acpi ACPI0004:01: Attempt to re-insert
> >>
> >> The ACPI0004 device is a System Board in Fujitsu server, which has two
> >> numa nodes (processors and memory).
> >>
> >> It seems that we reserved the ACPI_NOTIFY_DEVICE_CHECK event twice in
> >> acpi_hotplug_notify_cb().
> >>
> >>
> >> According to bisect, this happens after the following commit:
> >>
> >>  From 68a67f6c78b80525d9b3c6672e7782de95e56a83 Mon Sep 17 00:00:00 2001
> >> From: "Rafael J. Wysocki" <rafael.j.wysocki@intel.com>
> >> Date: Sun, 3 Mar 2013 23:05:55 +0100
> >> Subject: [PATCH 1/1] ACPI / container: Use common hotplug code
> >>
> >> Switch the ACPI container driver to using common device hotplug code
> >> introduced previously.  This reduces the driver down to a trivial
> >> definition and registration of a struct acpi_scan_handler object.
> >>
> >> Signed-off-by: Rafael J. Wysocki <rafael.j.wysocki@intel.com>
> >> Acked-by: Toshi Kani <toshi.kani@hp.com>
> >> Tested-by: Toshi Kani <toshi.kani@hp.com>
> >> ---
> >>   drivers/acpi/container.c | 146 
> >> ++++-------------------------------------------
> >>   1 file changed, 10 insertions(+), 136 deletions(-)
> >>
> >>
> >> I'm now investigating this problem. If you have any idea about why this
> >> happens, please let me know.
> > 
> > With the above change, container devices use the common notify handler,
> > which logs the warning message in question when it receives device check
> > twice on a same device.  Before the change, the container-specific
> > notify handler did not log this message in the same case (but considered
> > it as an eject request).
> > 
> > So, I suspect that you are getting device check twice regardless of the
> > kernel change.  Can you check KERN_DEBUG messages to see if that is the
> > case?  The notify handler logs all events with KERN_DEBUG.
> 
> Follow your suggestion, we confirm that it really received ACPI_NOTIFY_
> DEVICE_CHECK event*twice*, but the original ACPI container driver only
> received once, does the common device hotplug code introduce another device
> check? any idea?

Well, we couldn't possibly make the BIOS generate the event twice unless
there's an _OST response missing somewhere or similar.

In any case the second event should be harmless.

> Container uses common device hotplug code:
> [  142.937724] IPv6: ADDRCONF(NETDEV_CHANGE): eth8: link becomes ready
> [  674.975575] ACPI: \_SB_.LSB1: ACPI_NOTIFY_DEVICE_CHECK event          <<<<
> [  674.991604] ACPI: \_SB_.LSB1: ACPI_NOTIFY_DEVICE_CHECK event		 <<<<	

Where exactly did you put that printk()?

> [  675.613990] ACPI: PCI Root Bridge [UNC2] (domain 0000 [bus fd])
> [  675.684970] acpi PNP0A03:01: ACPI _OSC support notification failed, disabling PCIe ASPM
> [  675.780957] acpi PNP0A03:01: Unable to request _OSC control (_OSC support mask: 0x08)
> [  675.874806] ACPI _OSC control for PCIe not granted, disabling ASPM
> [  675.949005] pci_bus 0000:fd: Allocating resources
> [  675.960145] ACPI: PCI Root Bridge [UNC3] (domain 0000 [bus fc])
> [  676.031176] acpi PNP0A03:02: ACPI _OSC support notification failed, disabling PCIe ASPM
> [  676.127129] acpi PNP0A03:02: Unable to request _OSC control (_OSC support mask: 0x08)
> [  676.220943] ACPI _OSC control for PCIe not granted, disabling ASPM
> [  676.295019] pci_bus 0000:fc: Allocating resources
> 
> Original ACPI container driver:
> [ 1526.122933] Container driver received ACPI_NOTIFY_DEVICE_CHECK event <<<<

And that?

> [ 1526.800646] ACPI: PCI Root Bridge [UNC2] (domain 0000 [bus fd])
> [ 1526.871682] acpi PNP0A03:01: ACPI _OSC support notification failed, disabling PCIe ASPM
> [ 1526.967878] acpi PNP0A03:01: Unable to request _OSC control (_OSC support mask: 0x08)
> [ 1527.061891] ACPI _OSC control for PCIe not granted, disabling ASPM
> [ 1527.136036] pci_bus 0000:fd: Allocating resources
> [ 1527.150747] ACPI: PCI Root Bridge [UNC3] (domain 0000 [bus fc])
> [ 1527.221821] acpi PNP0A03:02: ACPI _OSC support notification failed, disabling PCIe ASPM
> [ 1527.317738] acpi PNP0A03:02: Unable to request _OSC control (_OSC support mask: 0x08)
> [ 1527.411795] ACPI _OSC control for PCIe not granted, disabling ASPM
> [ 1527.485917] pci_bus 0000:fc: Allocating resources

Thanks,
Rafael

Re: [Bug report] Warning when hot-add an ACPI0004 device.

[Toshi Kani]

On Wed, 2013-09-25 at 10:31 +0000, Gu Zheng wrote:
> Hi Toshi,
> 
> On 09/12/2013 11:11 PM, Toshi Kani wrote:
> 
> > On Thu, 2013-09-12 at 13:00 +0800, Tang Chen wrote:
> >> Hi Rafael, Toshi,
> >>
> >> When we hot-add an ACPI0004 device, we got the following warning:
> >>
> >> 	acpi ACPI0004:01: Attempt to re-insert
> >>
> >> The ACPI0004 device is a System Board in Fujitsu server, which has two
> >> numa nodes (processors and memory).
> >>
> >> It seems that we reserved the ACPI_NOTIFY_DEVICE_CHECK event twice in
> >> acpi_hotplug_notify_cb().
> >>
> >>
> >> According to bisect, this happens after the following commit:
> >>
> >>  From 68a67f6c78b80525d9b3c6672e7782de95e56a83 Mon Sep 17 00:00:00 2001
> >> From: "Rafael J. Wysocki" <rafael.j.wysocki@intel.com>
> >> Date: Sun, 3 Mar 2013 23:05:55 +0100
> >> Subject: [PATCH 1/1] ACPI / container: Use common hotplug code
> >>
> >> Switch the ACPI container driver to using common device hotplug code
> >> introduced previously.  This reduces the driver down to a trivial
> >> definition and registration of a struct acpi_scan_handler object.
> >>
> >> Signed-off-by: Rafael J. Wysocki <rafael.j.wysocki@intel.com>
> >> Acked-by: Toshi Kani <toshi.kani@hp.com>
> >> Tested-by: Toshi Kani <toshi.kani@hp.com>
> >> ---
> >>   drivers/acpi/container.c | 146 
> >> ++++-------------------------------------------
> >>   1 file changed, 10 insertions(+), 136 deletions(-)
> >>
> >>
> >> I'm now investigating this problem. If you have any idea about why this
> >> happens, please let me know.
> > 
> > With the above change, container devices use the common notify handler,
> > which logs the warning message in question when it receives device check
> > twice on a same device.  Before the change, the container-specific
> > notify handler did not log this message in the same case (but considered
> > it as an eject request).
> > 
> > So, I suspect that you are getting device check twice regardless of the
> > kernel change.  Can you check KERN_DEBUG messages to see if that is the
> > case?  The notify handler logs all events with KERN_DEBUG.
> 
> Follow your suggestion, we confirm that it really received ACPI_NOTIFY_
> DEVICE_CHECK event*twice*, but the original ACPI container driver only
> received once, does the common device hotplug code introduce another device
> check? any idea?
> 
> Container uses common device hotplug code:
> [  142.937724] IPv6: ADDRCONF(NETDEV_CHANGE): eth8: link becomes ready
> [  674.975575] ACPI: \_SB_.LSB1: ACPI_NOTIFY_DEVICE_CHECK event          <<<<

acpi_hotplug_notify_cb() calls acpi_os_hotplug_execute() to schedule to
run acpi_scan_device_check() asynchronously and returns immediately.
This leads acpi_ev_asynch_enable_gpe() to run next, which clears this
GPE (if level triggered) and re-enable GPE.

> [  674.991604] ACPI: \_SB_.LSB1: ACPI_NOTIFY_DEVICE_CHECK event		 <<<<	

It appears that re-enabling GPE caused this GPE to show up again as a
spurious interrupt. 

> [  675.613990] ACPI: PCI Root Bridge [UNC2] (domain 0000 [bus fd])
> [  675.684970] acpi PNP0A03:01: ACPI _OSC support notification failed, disabling PCIe ASPM
> [  675.780957] acpi PNP0A03:01: Unable to request _OSC control (_OSC support mask: 0x08)
> [  675.874806] ACPI _OSC control for PCIe not granted, disabling ASPM
> [  675.949005] pci_bus 0000:fd: Allocating resources
> [  675.960145] ACPI: PCI Root Bridge [UNC3] (domain 0000 [bus fc])
> [  676.031176] acpi PNP0A03:02: ACPI _OSC support notification failed, disabling PCIe ASPM
> [  676.127129] acpi PNP0A03:02: Unable to request _OSC control (_OSC support mask: 0x08)
> [  676.220943] ACPI _OSC control for PCIe not granted, disabling ASPM
> [  676.295019] pci_bus 0000:fc: Allocating resources
> 
> Original ACPI container driver:
> [ 1526.122933] Container driver received ACPI_NOTIFY_DEVICE_CHECK event <<<<

In the original code, container_notify_cb() proceeds the device check
handling and then calls _OST on the same thread.  It then re-enable GPE.
This ordering seems to avoid the spurious interrupt on your platform.

> [ 1526.800646] ACPI: PCI Root Bridge [UNC2] (domain 0000 [bus fd])
> [ 1526.871682] acpi PNP0A03:01: ACPI _OSC support notification failed, disabling PCIe ASPM
> [ 1526.967878] acpi PNP0A03:01: Unable to request _OSC control (_OSC support mask: 0x08)
> [ 1527.061891] ACPI _OSC control for PCIe not granted, disabling ASPM
> [ 1527.136036] pci_bus 0000:fd: Allocating resources
> [ 1527.150747] ACPI: PCI Root Bridge [UNC3] (domain 0000 [bus fc])
> [ 1527.221821] acpi PNP0A03:02: ACPI _OSC support notification failed, disabling PCIe ASPM
> [ 1527.317738] acpi PNP0A03:02: Unable to request _OSC control (_OSC support mask: 0x08)
> [ 1527.411795] ACPI _OSC control for PCIe not granted, disabling ASPM
> [ 1527.485917] pci_bus 0000:fc: Allocating resources

The GPE handler code in ACPICA is the same.  So, the issue could be due
to either;
 - The firmware expects _OST before re-enabling GPE, or
 - The timing of re-enabling GPE was too soon on your platform.

Can you check with your firmware team to see if this might be the case?

Thanks,
-Toshi

Re: [Bug report] Warning when hot-add an ACPI0004 device.

[Gu Zheng]

Hi Rafael,

On 09/25/2013 10:36 PM, Rafael J. Wysocki wrote:

> On Wednesday, September 25, 2013 06:31:09 PM Gu Zheng wrote:
>> Hi Toshi,
>>
>> On 09/12/2013 11:11 PM, Toshi Kani wrote:
>>
>>> On Thu, 2013-09-12 at 13:00 +0800, Tang Chen wrote:
>>>> Hi Rafael, Toshi,
>>>>
>>>> When we hot-add an ACPI0004 device, we got the following warning:
>>>>
>>>> 	acpi ACPI0004:01: Attempt to re-insert
<...>
>>>>
>>>>
>>>> I'm now investigating this problem. If you have any idea about why this
>>>> happens, please let me know.
>>>
>>> With the above change, container devices use the common notify handler,
>>> which logs the warning message in question when it receives device check
>>> twice on a same device.  Before the change, the container-specific
>>> notify handler did not log this message in the same case (but considered
>>> it as an eject request).
>>>
>>> So, I suspect that you are getting device check twice regardless of the
>>> kernel change.  Can you check KERN_DEBUG messages to see if that is the
>>> case?  The notify handler logs all events with KERN_DEBUG.
>>
>> Follow your suggestion, we confirm that it really received ACPI_NOTIFY_
>> DEVICE_CHECK event*twice*, but the original ACPI container driver only
>> received once, does the common device hotplug code introduce another device
>> check? any idea?
> 
> Well, we couldn't possibly make the BIOS generate the event twice unless
> there's an _OST response missing somewhere or similar.
> 
> In any case the second event should be harmless.

Yes, though it's harmless, but this message is not very friendly. 

> 
>> Container uses common device hotplug code:
>> [  142.937724] IPv6: ADDRCONF(NETDEV_CHANGE): eth8: link becomes ready
>> [  674.975575] ACPI: \_SB_.LSB1: ACPI_NOTIFY_DEVICE_CHECK event          <<<<
>> [  674.991604] ACPI: \_SB_.LSB1: ACPI_NOTIFY_DEVICE_CHECK event		 <<<<	
> 
> Where exactly did you put that printk()?

It's the acpi_handle_debug in acpi_hotplug_notify_cb():
 410         case ACPI_NOTIFY_DEVICE_CHECK:                                          
 411                 acpi_handle_debug(handle, "ACPI_NOTIFY_DEVICE_CHECK event\n");  
 412                 callback = acpi_scan_device_check;                              
 413                 break;  

> 
>> [  675.613990] ACPI: PCI Root Bridge [UNC2] (domain 0000 [bus fd])
>> [  675.684970] acpi PNP0A03:01: ACPI _OSC support notification failed, disabling PCIe ASPM
>> [  675.780957] acpi PNP0A03:01: Unable to request _OSC control (_OSC support mask: 0x08)
>> [  675.874806] ACPI _OSC control for PCIe not granted, disabling ASPM
>> [  675.949005] pci_bus 0000:fd: Allocating resources
>> [  675.960145] ACPI: PCI Root Bridge [UNC3] (domain 0000 [bus fc])
>> [  676.031176] acpi PNP0A03:02: ACPI _OSC support notification failed, disabling PCIe ASPM
>> [  676.127129] acpi PNP0A03:02: Unable to request _OSC control (_OSC support mask: 0x08)
>> [  676.220943] ACPI _OSC control for PCIe not granted, disabling ASPM
>> [  676.295019] pci_bus 0000:fc: Allocating resources
>>
>> Original ACPI container driver:
>> [ 1526.122933] Container driver received ACPI_NOTIFY_DEVICE_CHECK event <<<<
> 
> And that?

It seems that the original ACPI container driver can avoid the second event.

The debug printk is added in original container_notify_cb():
 96         case ACPI_NOTIFY_DEVICE_CHECK:
 97                 printk("Container driver received %s event\n",
 98                        (type == ACPI_NOTIFY_BUS_CHECK) ?
 99                        "ACPI_NOTIFY_BUS_CHECK" : "ACPI_NOTIFY_DEVICE_CHECK");
100 
101                 present = is_device_present(handle);
102                 status = acpi_bus_get_device(handle, &device);
103                 if (device)
104                         printk("=======attemp to reinsert!\n");
105                 if (!present) {

Best regards,
Gu

> 
>> [ 1526.800646] ACPI: PCI Root Bridge [UNC2] (domain 0000 [bus fd])
>> [ 1526.871682] acpi PNP0A03:01: ACPI _OSC support notification failed, disabling PCIe ASPM
>> [ 1526.967878] acpi PNP0A03:01: Unable to request _OSC control (_OSC support mask: 0x08)
>> [ 1527.061891] ACPI _OSC control for PCIe not granted, disabling ASPM
>> [ 1527.136036] pci_bus 0000:fd: Allocating resources
>> [ 1527.150747] ACPI: PCI Root Bridge [UNC3] (domain 0000 [bus fc])
>> [ 1527.221821] acpi PNP0A03:02: ACPI _OSC support notification failed, disabling PCIe ASPM
>> [ 1527.317738] acpi PNP0A03:02: Unable to request _OSC control (_OSC support mask: 0x08)
>> [ 1527.411795] ACPI _OSC control for PCIe not granted, disabling ASPM
>> [ 1527.485917] pci_bus 0000:fc: Allocating resources
> 
> Thanks,
> Rafael
> 
> 

Re: [Bug report] Warning when hot-add an ACPI0004 device.

[Gu Zheng]

Hi Toshi,

On 09/26/2013 06:24 AM, Toshi Kani wrote:

> On Wed, 2013-09-25 at 10:31 +0000, Gu Zheng wrote:
>> Hi Toshi,
>>
>> On 09/12/2013 11:11 PM, Toshi Kani wrote:
>>
>>> On Thu, 2013-09-12 at 13:00 +0800, Tang Chen wrote:
>>>> Hi Rafael, Toshi,
>>>>
>>>> When we hot-add an ACPI0004 device, we got the following warning:
>>>>
>>>> 	acpi ACPI0004:01: Attempt to re-insert
>>>>
>>>> The ACPI0004 device is a System Board in Fujitsu server, which has two
>>>> numa nodes (processors and memory).
>>>>
>>>> It seems that we reserved the ACPI_NOTIFY_DEVICE_CHECK event twice in
>>>> acpi_hotplug_notify_cb().
>>>>
>>>>
>>>> According to bisect, this happens after the following commit:
>>>>
>>>>  From 68a67f6c78b80525d9b3c6672e7782de95e56a83 Mon Sep 17 00:00:00 2001
>>>> From: "Rafael J. Wysocki" <rafael.j.wysocki@intel.com>
>>>> Date: Sun, 3 Mar 2013 23:05:55 +0100
>>>> Subject: [PATCH 1/1] ACPI / container: Use common hotplug code
>>>>
>>>> Switch the ACPI container driver to using common device hotplug code
>>>> introduced previously.  This reduces the driver down to a trivial
>>>> definition and registration of a struct acpi_scan_handler object.
>>>>
>>>> Signed-off-by: Rafael J. Wysocki <rafael.j.wysocki@intel.com>
>>>> Acked-by: Toshi Kani <toshi.kani@hp.com>
>>>> Tested-by: Toshi Kani <toshi.kani@hp.com>
>>>> ---
>>>>   drivers/acpi/container.c | 146 
>>>> ++++-------------------------------------------
>>>>   1 file changed, 10 insertions(+), 136 deletions(-)
>>>>
>>>>
>>>> I'm now investigating this problem. If you have any idea about why this
>>>> happens, please let me know.
>>>
>>> With the above change, container devices use the common notify handler,
>>> which logs the warning message in question when it receives device check
>>> twice on a same device.  Before the change, the container-specific
>>> notify handler did not log this message in the same case (but considered
>>> it as an eject request).
>>>
>>> So, I suspect that you are getting device check twice regardless of the
>>> kernel change.  Can you check KERN_DEBUG messages to see if that is the
>>> case?  The notify handler logs all events with KERN_DEBUG.
>>
>> Follow your suggestion, we confirm that it really received ACPI_NOTIFY_
>> DEVICE_CHECK event*twice*, but the original ACPI container driver only
>> received once, does the common device hotplug code introduce another device
>> check? any idea?
>>
>> Container uses common device hotplug code:
>> [  142.937724] IPv6: ADDRCONF(NETDEV_CHANGE): eth8: link becomes ready
>> [  674.975575] ACPI: \_SB_.LSB1: ACPI_NOTIFY_DEVICE_CHECK event          <<<<
> 
> acpi_hotplug_notify_cb() calls acpi_os_hotplug_execute() to schedule to
> run acpi_scan_device_check() asynchronously and returns immediately.
> This leads acpi_ev_asynch_enable_gpe() to run next, which clears this
> GPE (if level triggered) and re-enable GPE.

Thanks for your explanation, it's really the routine you mentioned above.

> 
>> [  674.991604] ACPI: \_SB_.LSB1: ACPI_NOTIFY_DEVICE_CHECK event		 <<<<	
> 
> It appears that re-enabling GPE caused this GPE to show up again as a
> spurious interrupt.

Yes, it is.

> 
>> [  675.613990] ACPI: PCI Root Bridge [UNC2] (domain 0000 [bus fd])
>> [  675.684970] acpi PNP0A03:01: ACPI _OSC support notification failed, disabling PCIe ASPM
>> [  675.780957] acpi PNP0A03:01: Unable to request _OSC control (_OSC support mask: 0x08)
>> [  675.874806] ACPI _OSC control for PCIe not granted, disabling ASPM
>> [  675.949005] pci_bus 0000:fd: Allocating resources
>> [  675.960145] ACPI: PCI Root Bridge [UNC3] (domain 0000 [bus fc])
>> [  676.031176] acpi PNP0A03:02: ACPI _OSC support notification failed, disabling PCIe ASPM
>> [  676.127129] acpi PNP0A03:02: Unable to request _OSC control (_OSC support mask: 0x08)
>> [  676.220943] ACPI _OSC control for PCIe not granted, disabling ASPM
>> [  676.295019] pci_bus 0000:fc: Allocating resources
>>
>> Original ACPI container driver:
>> [ 1526.122933] Container driver received ACPI_NOTIFY_DEVICE_CHECK event <<<<
> 
> In the original code, container_notify_cb() proceeds the device check
> handling and then calls _OST on the same thread.  It then re-enable GPE.

According to our debug, the whole routine was executed on the same thread.

> This ordering seems to avoid the spurious interrupt on your platform.

It seems that, but it is very strange.

> 
>> [ 1526.800646] ACPI: PCI Root Bridge [UNC2] (domain 0000 [bus fd])
>> [ 1526.871682] acpi PNP0A03:01: ACPI _OSC support notification failed, disabling PCIe ASPM
>> [ 1526.967878] acpi PNP0A03:01: Unable to request _OSC control (_OSC support mask: 0x08)
>> [ 1527.061891] ACPI _OSC control for PCIe not granted, disabling ASPM
>> [ 1527.136036] pci_bus 0000:fd: Allocating resources
>> [ 1527.150747] ACPI: PCI Root Bridge [UNC3] (domain 0000 [bus fc])
>> [ 1527.221821] acpi PNP0A03:02: ACPI _OSC support notification failed, disabling PCIe ASPM
>> [ 1527.317738] acpi PNP0A03:02: Unable to request _OSC control (_OSC support mask: 0x08)
>> [ 1527.411795] ACPI _OSC control for PCIe not granted, disabling ASPM
>> [ 1527.485917] pci_bus 0000:fc: Allocating resources
> 
> The GPE handler code in ACPICA is the same.  So, the issue could be due
> to either;
>  - The firmware expects _OST before re-enabling GPE, or
>  - The timing of re-enabling GPE was too soon on your platform.

Thanks for your directions.

> 
> Can you check with your firmware team to see if this might be the case?

I'll confirm this.

Best regards,
Gu

> 
> Thanks,
> -Toshi
> 
>