[PATCH 0/4] ACPI: hotplug messages improvement

[PATCH 0/4] ACPI: hotplug messages improvement

[Toshi Kani]

This patchset improves logging messages for ACPI CPU, Memory, and
Container hotplug notify handlers.  The patchset introduces a set of
new macro interfaces, acpi_pr_<level>(), and updates the notify
handlers to use them.  acpi_pr_<level>() appends "ACPI" prefix and
ACPI object path to the messages.  This improves diagnostics in
hotplug operations since it identifies an object that caused an
issue in a log file.

---
This patchset applies on top of the patch below.

[PATCH] ACPI: Add ACPI CPU hot-remove support
http://marc.info/?l=linux-acpi&m=134098193327362&w=2

---
Toshi Kani (4):
 ACPI: Add acpi_pr_<level>() interfaces
 ACPI: Update CPU hotplug messages
 ACPI: Update Memory hotplug messages
 ACPI: Update Container hotplug messages

---
 drivers/acpi/acpi_memhotplug.c  |   24 ++++++++++++------------
 drivers/acpi/container.c        |    6 +++---
 drivers/acpi/processor_driver.c |   36 +++++++++++++++++++++---------------
 drivers/acpi/utils.c            |   32 ++++++++++++++++++++++++++++++++
 include/acpi/acpi_bus.h         |   18 ++++++++++++++++++
 5 files changed, 86 insertions(+), 30 deletions(-)

[PATCH 1/4] ACPI: Add acpi_pr_<level>() interfaces

[Toshi Kani]

This patch introduces acpi_pr_<level>(), where <level> is a message
level such as err/warn/info, to support improved logging messages
for ACPI, esp. in hotplug operations.  acpi_pr_<level>() appends
"ACPI" prefix and ACPI object path to the messages.  This improves
diagnostics in hotplug operations since it identifies an object that
caused an issue in a log file.

acpi_pr_<level>() takes acpi_handle as an argument, which is passed
to ACPI hotplug notify handlers from the ACPI CA.  Therefore, it is
always available unlike other kernel objects, such as device.

For example, the statement below
  acpi_pr_err(handle, "Device don't exist, dropping EJECT\n");
logs an error message like this:
  ACPI: \_SB_.SCK4.CPU4: Device don't exist, dropping EJECT

Signed-off-by: Toshi Kani <toshi.kani@hp.com>
---
 drivers/acpi/utils.c    |   32 ++++++++++++++++++++++++++++++++
 include/acpi/acpi_bus.h |   18 ++++++++++++++++++
 2 files changed, 50 insertions(+), 0 deletions(-)

diff --git a/drivers/acpi/utils.c b/drivers/acpi/utils.c
index 3e87c9c..4097266 100644
--- a/drivers/acpi/utils.c
+++ b/drivers/acpi/utils.c
@@ -454,3 +454,35 @@ acpi_evaluate_hotplug_ost(acpi_handle handle, u32 source_event,
 #endif
 }
 EXPORT_SYMBOL(acpi_evaluate_hotplug_ost);
+
+/**
+ * acpi_printk: Print messages with ACPI prefix and object path
+ *
+ * This function is intended to be called through acpi_pr_<level> macros.
+ */
+void
+acpi_printk(const char *level, acpi_handle handle, const char *fmt, ...)
+{
+	struct va_format vaf;
+	va_list args;
+	struct acpi_buffer buffer = {ACPI_ALLOCATE_BUFFER};
+	char *path;
+	acpi_status ret;
+
+	va_start(args, fmt);
+
+	vaf.fmt = fmt;
+	vaf.va = &args;
+
+	ret = acpi_get_name(handle, ACPI_FULL_PATHNAME, &buffer);
+	if (ret == AE_OK)
+		path = buffer.pointer;
+	else
+		path = "<n/a>";
+
+	printk("%sACPI: %s: %pV", level, path, &vaf);
+
+	va_end(args);
+	kfree(buffer.pointer);
+}
+EXPORT_SYMBOL(acpi_printk);
diff --git a/include/acpi/acpi_bus.h b/include/acpi/acpi_bus.h
index b22b774..c3a175d 100644
--- a/include/acpi/acpi_bus.h
+++ b/include/acpi/acpi_bus.h
@@ -85,6 +85,24 @@ struct acpi_pld {
 
 acpi_status
 acpi_get_physical_device_location(acpi_handle handle, struct acpi_pld *pld);
+
+void acpi_printk(const char *level, acpi_handle handle, const char *fmt, ...);
+
+#define acpi_pr_emerg(handle, fmt, ...)				\
+	acpi_printk(KERN_EMERG, handle, fmt, ##__VA_ARGS__)
+#define acpi_pr_alert(handle, fmt, ...)				\
+	acpi_printk(KERN_ALERT, handle, fmt, ##__VA_ARGS__)
+#define acpi_pr_crit(handle, fmt, ...)				\
+	acpi_printk(KERN_CRIT, handle, fmt, ##__VA_ARGS__)
+#define acpi_pr_err(handle, fmt, ...)				\
+	acpi_printk(KERN_ERR, handle, fmt, ##__VA_ARGS__)
+#define acpi_pr_warn(handle, fmt, ...)				\
+	acpi_printk(KERN_WARNING, handle, fmt, ##__VA_ARGS__)
+#define acpi_pr_notice(handle, fmt, ...)			\
+	acpi_printk(KERN_NOTICE, handle, fmt, ##__VA_ARGS__)
+#define acpi_pr_info(handle, fmt, ...)				\
+	acpi_printk(KERN_INFO, handle, fmt, ##__VA_ARGS__)
+
 #ifdef CONFIG_ACPI
 
 #include <linux/proc_fs.h>
-- 
1.7.7.6

Re: [PATCH 1/4] ACPI: Add acpi_pr_<level>() interfaces

[Joe Perches]

On Wed, 2012-07-18 at 14:40 -0600, Toshi Kani wrote:
> This patch introduces acpi_pr_<level>(), where <level> is a message
> level such as err/warn/info, to support improved logging messages
> for ACPI, esp. in hotplug operations.  acpi_pr_<level>() appends
> "ACPI" prefix and ACPI object path to the messages.  This improves
> diagnostics in hotplug operations since it identifies an object that
> caused an issue in a log file.
> 
> acpi_pr_<level>() takes acpi_handle as an argument, which is passed
> to ACPI hotplug notify handlers from the ACPI CA.  Therefore, it is
> always available unlike other kernel objects, such as device.

Hi Toshi.

I'd be tempted to instead make the calls more like
other <subsystem>_<level> uses and rename these to
acpi_<level> and change the existing acpi_info to
another name.

Other than that, seems fine to me.

cheers, Joe

Re: [PATCH 1/4] ACPI: Add acpi_pr_<level>() interfaces

[Toshi Kani]

On Wed, 2012-07-18 at 14:21 -0700, Joe Perches wrote:
> On Wed, 2012-07-18 at 14:40 -0600, Toshi Kani wrote:
> > This patch introduces acpi_pr_<level>(), where <level> is a message
> > level such as err/warn/info, to support improved logging messages
> > for ACPI, esp. in hotplug operations.  acpi_pr_<level>() appends
> > "ACPI" prefix and ACPI object path to the messages.  This improves
> > diagnostics in hotplug operations since it identifies an object that
> > caused an issue in a log file.
> > 
> > acpi_pr_<level>() takes acpi_handle as an argument, which is passed
> > to ACPI hotplug notify handlers from the ACPI CA.  Therefore, it is
> > always available unlike other kernel objects, such as device.
> 
> Hi Toshi.
> 
> I'd be tempted to instead make the calls more like
> other <subsystem>_<level> uses and rename these to
> acpi_<level> and change the existing acpi_info to
> another name.

Hi Joe,

I agree with you.  Unfortunately, the ACPI CA (ACPI FW interpreter)
already uses them for its internal-use as follows, so I needed to come
up with some other name...  Hence, acpi_pr_<level>.

/*
 * Error reporting. Callers module and line number are inserted by
AE_INFO,
 * the plist contains a set of parens to allow variable-length lists.
 * These macros are used for both the debug and non-debug versions of
the code.
 */
#define ACPI_INFO(plist)                acpi_info plist
#define ACPI_WARNING(plist)             acpi_warning plist
#define ACPI_EXCEPTION(plist)           acpi_exception plist
#define ACPI_ERROR(plist)               acpi_error plist
#define ACPI_DEBUG_OBJECT(obj,l,i)      acpi_ex_do_debug_object(obj,l,i)


> Other than that, seems fine to me.

Great!  Can I consider it as Ack? :)


Thanks,
-Toshi


> cheers, Joe
> 

Re: [PATCH 1/4] ACPI: Add acpi_pr_<level>() interfaces

[Joe Perches]

On Wed, 2012-07-18 at 15:41 -0600, Toshi Kani wrote:
> On Wed, 2012-07-18 at 14:21 -0700, Joe Perches wrote:
> > On Wed, 2012-07-18 at 14:40 -0600, Toshi Kani wrote:
> > > This patch introduces acpi_pr_<level>(), where <level> is a message
> > > level such as err/warn/info, to support improved logging messages
> > > for ACPI, esp. in hotplug operations.  acpi_pr_<level>() appends
> > > "ACPI" prefix and ACPI object path to the messages.  This improves
> > > diagnostics in hotplug operations since it identifies an object that
> > > caused an issue in a log file.
[]
> > I'd be tempted to instead make the calls more like
> > other <subsystem>_<level> uses and rename these to
> > acpi_<level> and change the existing acpi_info to
> > another name.
[]
> I agree with you.  Unfortunately, the ACPI CA (ACPI FW interpreter)
> already uses them for its internal-use as follows, so I needed to come
> up with some other name...  Hence, acpi_pr_<level>.
> 
> /*
>  * Error reporting. Callers module and line number are inserted by AE_INFO,
>  * the plist contains a set of parens to allow variable-length lists.
>  * These macros are used for both the debug and non-debug versions of the code.
>  */
> #define ACPI_INFO(plist)                acpi_info plist
> #define ACPI_WARNING(plist)             acpi_warning plist
> #define ACPI_EXCEPTION(plist)           acpi_exception plist
> #define ACPI_ERROR(plist)               acpi_error plist
> #define ACPI_DEBUG_OBJECT(obj,l,i)      acpi_ex_do_debug_object(obj,l,i)

I wouldn't have a problem renaming a few of those to
something like:

#define ACPI_INFO(plist)	acpi_old_info plist
#define ACPI_WARNING(plist)	acpi_old_warning plist
#define ACPI_ERROR(plist)	acpi_old_error plist

The acpi folk might though.

> > Other than that, seems fine to me.
> Great!  Can I consider it as Ack? :)

Fix the kfree first.

I rarely ack stuff as other people generally have to
pick up the changes and I think acks are overrated.

cheers, Joe

Re: [PATCH 1/4] ACPI: Add acpi_pr_<level>() interfaces

[Toshi Kani]

On Wed, 2012-07-18 at 14:54 -0700, Joe Perches wrote:
> On Wed, 2012-07-18 at 15:41 -0600, Toshi Kani wrote:
> > On Wed, 2012-07-18 at 14:21 -0700, Joe Perches wrote:
> > > On Wed, 2012-07-18 at 14:40 -0600, Toshi Kani wrote:
> > > > This patch introduces acpi_pr_<level>(), where <level> is a message
> > > > level such as err/warn/info, to support improved logging messages
> > > > for ACPI, esp. in hotplug operations.  acpi_pr_<level>() appends
> > > > "ACPI" prefix and ACPI object path to the messages.  This improves
> > > > diagnostics in hotplug operations since it identifies an object that
> > > > caused an issue in a log file.
> []
> > > I'd be tempted to instead make the calls more like
> > > other <subsystem>_<level> uses and rename these to
> > > acpi_<level> and change the existing acpi_info to
> > > another name.
> []
> > I agree with you.  Unfortunately, the ACPI CA (ACPI FW interpreter)
> > already uses them for its internal-use as follows, so I needed to come
> > up with some other name...  Hence, acpi_pr_<level>.
> > 
> > /*
> >  * Error reporting. Callers module and line number are inserted by AE_INFO,
> >  * the plist contains a set of parens to allow variable-length lists.
> >  * These macros are used for both the debug and non-debug versions of the code.
> >  */
> > #define ACPI_INFO(plist)                acpi_info plist
> > #define ACPI_WARNING(plist)             acpi_warning plist
> > #define ACPI_EXCEPTION(plist)           acpi_exception plist
> > #define ACPI_ERROR(plist)               acpi_error plist
> > #define ACPI_DEBUG_OBJECT(obj,l,i)      acpi_ex_do_debug_object(obj,l,i)
> 
> I wouldn't have a problem renaming a few of those to
> something like:
> 
> #define ACPI_INFO(plist)	acpi_old_info plist
> #define ACPI_WARNING(plist)	acpi_old_warning plist
> #define ACPI_ERROR(plist)	acpi_old_error plist
> 
> The acpi folk might though.

Hi Joe,

ACPI CA is being developed by Intel as OS-neutral code, and is used by
multiple OSes including Linux.  So, I am not sure how easy to make such
changes.  I am copying to Lin Ming.


> > > Other than that, seems fine to me.
> > Great!  Can I consider it as Ack? :)
> 
> Fix the kfree first.

Please see my other email.  Do you think the check should be added
despite of the warning message?


> I rarely ack stuff as other people generally have to
> pick up the changes and I think acks are overrated.

That's fair enough.

Thanks!
-Toshi


> cheers, Joe
> 

RE: [PATCH 1/4] ACPI: Add acpi_pr_<level>() interfaces

[Moore, Robert]

>> I wouldn't have a problem renaming a few of those to
>> something like:
>>
>> #define ACPI_INFO(plist)	acpi_old_info plist
>> #define ACPI_WARNING(plist)	acpi_old_warning plist
>> #define ACPI_ERROR(plist)	acpi_old_error plist
>>
>> The acpi folk might though.
>
>Hi Joe,
>
>ACPI CA is being developed by Intel as OS-neutral code, and is used by
>multiple OSes including Linux.  So, I am not sure how easy to make such
>changes.  I am copying to Lin Ming.


Please don't even consider doing something like this. As we continue to develop and maintain the ACPICA code, these kinds of OS-specific divergences from the base ACPICA code cause us all kinds of grief, including the accidental creation of new bugs as it becomes more and more difficult to integrate the base ACPICA code back into Linux.

In fact, we have a major project this year (and probably far into next year) to continue to minimize (i.e., fix) this type of Linux/ACPICA divergence -- of which many have crept in over the years that ACPICA has been present in the Linux kernel.

Bob
















>-----Original Message-----
>From: linux-acpi-owner@vger.kernel.org [mailto:linux-acpi-
>owner@vger.kernel.org] On Behalf Of Toshi Kani
>Sent: Wednesday, July 18, 2012 3:08 PM
>To: Joe Perches; Lin, Ming M
>Cc: lenb@kernel.org; linux-acpi@vger.kernel.org; linux-
>kernel@vger.kernel.org; bhelgaas@google.com;
>isimatu.yasuaki@jp.fujitsu.com; liuj97@gmail.com;
>srivatsa.bhat@linux.vnet.ibm.com; prarit@redhat.com; imammedo@redhat.com;
>vijaymohan.pandarathil@hp.com
>Subject: Re: [PATCH 1/4] ACPI: Add acpi_pr_<level>() interfaces
>
>On Wed, 2012-07-18 at 14:54 -0700, Joe Perches wrote:
>> On Wed, 2012-07-18 at 15:41 -0600, Toshi Kani wrote:
>> > On Wed, 2012-07-18 at 14:21 -0700, Joe Perches wrote:
>> > > On Wed, 2012-07-18 at 14:40 -0600, Toshi Kani wrote:
>> > > > This patch introduces acpi_pr_<level>(), where <level> is a message
>> > > > level such as err/warn/info, to support improved logging messages
>> > > > for ACPI, esp. in hotplug operations.  acpi_pr_<level>() appends
>> > > > "ACPI" prefix and ACPI object path to the messages.  This improves
>> > > > diagnostics in hotplug operations since it identifies an object
>that
>> > > > caused an issue in a log file.
>> []
>> > > I'd be tempted to instead make the calls more like
>> > > other <subsystem>_<level> uses and rename these to
>> > > acpi_<level> and change the existing acpi_info to
>> > > another name.
>> []
>> > I agree with you.  Unfortunately, the ACPI CA (ACPI FW interpreter)
>> > already uses them for its internal-use as follows, so I needed to come
>> > up with some other name...  Hence, acpi_pr_<level>.
>> >
>> > /*
>> >  * Error reporting. Callers module and line number are inserted by
>AE_INFO,
>> >  * the plist contains a set of parens to allow variable-length lists.
>> >  * These macros are used for both the debug and non-debug versions of
>the code.
>> >  */
>> > #define ACPI_INFO(plist)                acpi_info plist
>> > #define ACPI_WARNING(plist)             acpi_warning plist
>> > #define ACPI_EXCEPTION(plist)           acpi_exception plist
>> > #define ACPI_ERROR(plist)               acpi_error plist
>> > #define ACPI_DEBUG_OBJECT(obj,l,i)
>acpi_ex_do_debug_object(obj,l,i)
>>
>> I wouldn't have a problem renaming a few of those to
>> something like:
>>
>> #define ACPI_INFO(plist)	acpi_old_info plist
>> #define ACPI_WARNING(plist)	acpi_old_warning plist
>> #define ACPI_ERROR(plist)	acpi_old_error plist
>>
>> The acpi folk might though.
>
>Hi Joe,
>
>ACPI CA is being developed by Intel as OS-neutral code, and is used by
>multiple OSes including Linux.  So, I am not sure how easy to make such
>changes.  I am copying to Lin Ming.
>
>
>> > > Other than that, seems fine to me.
>> > Great!  Can I consider it as Ack? :)
>>
>> Fix the kfree first.
>
>Please see my other email.  Do you think the check should be added
>despite of the warning message?
>
>
>> I rarely ack stuff as other people generally have to
>> pick up the changes and I think acks are overrated.
>
>That's fair enough.
>
>Thanks!
>-Toshi
>
>
>> cheers, Joe
>>
>
>
>--
>To unsubscribe from this list: send the line "unsubscribe linux-acpi" in
>the body of a message to majordomo@vger.kernel.org
>More majordomo info at  http://vger.kernel.org/majordomo-info.html

RE: [PATCH 1/4] ACPI: Add acpi_pr_<level>() interfaces

[Toshi Kani]

On Thu, 2012-07-19 at 05:35 +0000, Moore, Robert wrote:
> >> I wouldn't have a problem renaming a few of those to
> >> something like:
> >>
> >> #define ACPI_INFO(plist)	acpi_old_info plist
> >> #define ACPI_WARNING(plist)	acpi_old_warning plist
> >> #define ACPI_ERROR(plist)	acpi_old_error plist
> >>
> >> The acpi folk might though.
> >
> >Hi Joe,
> >
> >ACPI CA is being developed by Intel as OS-neutral code, and is used by
> >multiple OSes including Linux.  So, I am not sure how easy to make such
> >changes.  I am copying to Lin Ming.
> 
> 
> Please don't even consider doing something like this. As we continue to
> develop and maintain the ACPICA code, these kinds of OS-specific divergences
> from the base ACPICA code cause us all kinds of grief, including the accidental
> creation of new bugs as it becomes more and more difficult to integrate the base
> ACPICA code back into Linux.

Hi Bob,

Thanks for the clarification!  I agree with you.

> In fact, we have a major project this year (and probably far into next year) to
> continue to minimize (i.e., fix) this type of Linux/ACPICA divergence -- of which
> many have crept in over the years that ACPICA has been present in the Linux kernel.

Cool!  I think that's very good improvement.

Thanks again,
-Toshi


> Bob
> 
>
> >-----Original Message-----
> >From: linux-acpi-owner@vger.kernel.org [mailto:linux-acpi-
> >owner@vger.kernel.org] On Behalf Of Toshi Kani
> >Sent: Wednesday, July 18, 2012 3:08 PM
> >To: Joe Perches; Lin, Ming M
> >Cc: lenb@kernel.org; linux-acpi@vger.kernel.org; linux-
> >kernel@vger.kernel.org; bhelgaas@google.com;
> >isimatu.yasuaki@jp.fujitsu.com; liuj97@gmail.com;
> >srivatsa.bhat@linux.vnet.ibm.com; prarit@redhat.com; imammedo@redhat.com;
> >vijaymohan.pandarathil@hp.com
> >Subject: Re: [PATCH 1/4] ACPI: Add acpi_pr_<level>() interfaces
> >
> >On Wed, 2012-07-18 at 14:54 -0700, Joe Perches wrote:
> >> On Wed, 2012-07-18 at 15:41 -0600, Toshi Kani wrote:
> >> > On Wed, 2012-07-18 at 14:21 -0700, Joe Perches wrote:
> >> > > On Wed, 2012-07-18 at 14:40 -0600, Toshi Kani wrote:
> >> > > > This patch introduces acpi_pr_<level>(), where <level> is a message
> >> > > > level such as err/warn/info, to support improved logging messages
> >> > > > for ACPI, esp. in hotplug operations.  acpi_pr_<level>() appends
> >> > > > "ACPI" prefix and ACPI object path to the messages.  This improves
> >> > > > diagnostics in hotplug operations since it identifies an object
> >that
> >> > > > caused an issue in a log file.
> >> []
> >> > > I'd be tempted to instead make the calls more like
> >> > > other <subsystem>_<level> uses and rename these to
> >> > > acpi_<level> and change the existing acpi_info to
> >> > > another name.
> >> []
> >> > I agree with you.  Unfortunately, the ACPI CA (ACPI FW interpreter)
> >> > already uses them for its internal-use as follows, so I needed to come
> >> > up with some other name...  Hence, acpi_pr_<level>.
> >> >
> >> > /*
> >> >  * Error reporting. Callers module and line number are inserted by
> >AE_INFO,
> >> >  * the plist contains a set of parens to allow variable-length lists.
> >> >  * These macros are used for both the debug and non-debug versions of
> >the code.
> >> >  */
> >> > #define ACPI_INFO(plist)                acpi_info plist
> >> > #define ACPI_WARNING(plist)             acpi_warning plist
> >> > #define ACPI_EXCEPTION(plist)           acpi_exception plist
> >> > #define ACPI_ERROR(plist)               acpi_error plist
> >> > #define ACPI_DEBUG_OBJECT(obj,l,i)
> >acpi_ex_do_debug_object(obj,l,i)
> >>
> >> I wouldn't have a problem renaming a few of those to
> >> something like:
> >>
> >> #define ACPI_INFO(plist)	acpi_old_info plist
> >> #define ACPI_WARNING(plist)	acpi_old_warning plist
> >> #define ACPI_ERROR(plist)	acpi_old_error plist
> >>
> >> The acpi folk might though.
> >
> >Hi Joe,
> >
> >ACPI CA is being developed by Intel as OS-neutral code, and is used by
> >multiple OSes including Linux.  So, I am not sure how easy to make such
> >changes.  I am copying to Lin Ming.
> >
> >
> >> > > Other than that, seems fine to me.
> >> > Great!  Can I consider it as Ack? :)
> >>
> >> Fix the kfree first.
> >
> >Please see my other email.  Do you think the check should be added
> >despite of the warning message?
> >
> >
> >> I rarely ack stuff as other people generally have to
> >> pick up the changes and I think acks are overrated.
> >
> >That's fair enough.
> >
> >Thanks!
> >-Toshi
> >
> >
> >> cheers, Joe
> >>
> >
> >
> >--
> >To unsubscribe from this list: send the line "unsubscribe linux-acpi" in
> >the body of a message to majordomo@vger.kernel.org
> >More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [PATCH 1/4] ACPI: Add acpi_pr_<level>() interfaces

[Joe Perches]

On Wed, 2012-07-18 at 14:40 -0600, Toshi Kani wrote:
> This patch introduces acpi_pr_<level>(), where <level> is a message
> level such as err/warn/info, to support improved logging messages
> for ACPI, esp. in hotplug operations.

One more note:

> diff --git a/drivers/acpi/utils.c b/drivers/acpi/utils.c
[]
> @@ -454,3 +454,35 @@ acpi_evaluate_hotplug_ost(acpi_handle handle, u32 source_event,
[]
> +void
> +acpi_printk(const char *level, acpi_handle handle, const char *fmt, ...)
[]
> +	struct acpi_buffer buffer = {ACPI_ALLOCATE_BUFFER};
[]
> +	ret = acpi_get_name(handle, ACPI_FULL_PATHNAME, &buffer);
[]
> +	kfree(buffer.pointer);

There's a failure mode here because buffer.pointer
isn't guaranteed to be initialized or set to NULL.

Re: [PATCH 1/4] ACPI: Add acpi_pr_<level>() interfaces

[Toshi Kani]

On Wed, 2012-07-18 at 14:27 -0700, Joe Perches wrote:
> On Wed, 2012-07-18 at 14:40 -0600, Toshi Kani wrote:
> > This patch introduces acpi_pr_<level>(), where <level> is a message
> > level such as err/warn/info, to support improved logging messages
> > for ACPI, esp. in hotplug operations.
> 
> One more note:
> 
> > diff --git a/drivers/acpi/utils.c b/drivers/acpi/utils.c
> []
> > @@ -454,3 +454,35 @@ acpi_evaluate_hotplug_ost(acpi_handle handle, u32 source_event,
> []
> > +void
> > +acpi_printk(const char *level, acpi_handle handle, const char *fmt, ...)
> []
> > +	struct acpi_buffer buffer = {ACPI_ALLOCATE_BUFFER};
> []
> > +	ret = acpi_get_name(handle, ACPI_FULL_PATHNAME, &buffer);
> []
> > +	kfree(buffer.pointer);
> 
> There's a failure mode here because buffer.pointer
> isn't guaranteed to be initialized or set to NULL.

Hi Joe,

Yes, I thought that check was necessary as well.  However, to my
surprise, such check caused the following warning message from
patchcheck.pl.  So, I deleted the check...

# check for needless kfree() checks
                if ($prevline =~ /\bif\s*\(([^\)]*)\)/) {
                        my $expr = $1;
                        if ($line =~ /\bkfree\(\Q$expr\E\);/) {
                                WARN("NEEDLESS_KFREE",
                                     "kfree(NULL) is safe this check is
probably not required\n" . $hereprev);
                        }
                }

Thanks,
-Toshi

Re: [PATCH 1/4] ACPI: Add acpi_pr_<level>() interfaces

[Joe Perches]

On Wed, 2012-07-18 at 15:41 -0600, Toshi Kani wrote:
> On Wed, 2012-07-18 at 14:27 -0700, Joe Perches wrote:
> > On Wed, 2012-07-18 at 14:40 -0600, Toshi Kani wrote:
> > > This patch introduces acpi_pr_<level>(), where <level> is a message
> > > level such as err/warn/info, to support improved logging messages
> > > for ACPI, esp. in hotplug operations.
> > 
> > One more note:
> > 
> > > diff --git a/drivers/acpi/utils.c b/drivers/acpi/utils.c
> > []
> > > @@ -454,3 +454,35 @@ acpi_evaluate_hotplug_ost(acpi_handle handle, u32 source_event,
> > []
> > > +void
> > > +acpi_printk(const char *level, acpi_handle handle, const char *fmt, ...)
> > []
> > > +	struct acpi_buffer buffer = {ACPI_ALLOCATE_BUFFER};
> > []
> > > +	ret = acpi_get_name(handle, ACPI_FULL_PATHNAME, &buffer);
> > []
> > > +	kfree(buffer.pointer);
> > 
> > There's a failure mode here because buffer.pointer
> > isn't guaranteed to be initialized or set to NULL.
> 
> Hi Joe,
> 
> Yes, I thought that check was necessary as well.  However, to my
> surprise, such check caused the following warning message from
> patchcheck.pl.  So, I deleted the check...

checkpatch ain't very bright.

Because buffer is an automatic not a static,
buffer.pointer needs to be set to NULL.

	struct acpi_buffer buffer = {
		.length = ACPI_ALLOCATE_BUFFER,
		.pointer = NULL,
	};

then the kfree is fine.

Re: [PATCH 1/4] ACPI: Add acpi_pr_<level>() interfaces

[Toshi Kani]

On Wed, 2012-07-18 at 15:06 -0700, Joe Perches wrote:
> On Wed, 2012-07-18 at 15:41 -0600, Toshi Kani wrote:
> > On Wed, 2012-07-18 at 14:27 -0700, Joe Perches wrote:
> > > On Wed, 2012-07-18 at 14:40 -0600, Toshi Kani wrote:
> > > > This patch introduces acpi_pr_<level>(), where <level> is a message
> > > > level such as err/warn/info, to support improved logging messages
> > > > for ACPI, esp. in hotplug operations.
> > > 
> > > One more note:
> > > 
> > > > diff --git a/drivers/acpi/utils.c b/drivers/acpi/utils.c
> > > []
> > > > @@ -454,3 +454,35 @@ acpi_evaluate_hotplug_ost(acpi_handle handle, u32 source_event,
> > > []
> > > > +void
> > > > +acpi_printk(const char *level, acpi_handle handle, const char *fmt, ...)
> > > []
> > > > +	struct acpi_buffer buffer = {ACPI_ALLOCATE_BUFFER};
> > > []
> > > > +	ret = acpi_get_name(handle, ACPI_FULL_PATHNAME, &buffer);
> > > []
> > > > +	kfree(buffer.pointer);
> > > 
> > > There's a failure mode here because buffer.pointer
> > > isn't guaranteed to be initialized or set to NULL.
> > 
> > Hi Joe,
> > 
> > Yes, I thought that check was necessary as well.  However, to my
> > surprise, such check caused the following warning message from
> > patchcheck.pl.  So, I deleted the check...
> 
> checkpatch ain't very bright.
> 
> Because buffer is an automatic not a static,
> buffer.pointer needs to be set to NULL.
> 
> 	struct acpi_buffer buffer = {
> 		.length = ACPI_ALLOCATE_BUFFER,
> 		.pointer = NULL,
> 	};
> 
> then the kfree is fine.

Hi Joe,

Very good point!  I will update with the change.


Thanks,
-Toshi


> 
> --
> To unsubscribe from this list: send the line "unsubscribe linux-acpi" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [PATCH 1/4] ACPI: Add acpi_pr_<level>() interfaces

[Shuah Khan]

On Wed, 2012-07-18 at 14:40 -0600, Toshi Kani wrote:
> This patch introduces acpi_pr_<level>(), where <level> is a message
> level such as err/warn/info, to support improved logging messages
> for ACPI, esp. in hotplug operations.  acpi_pr_<level>() appends
> "ACPI" prefix and ACPI object path to the messages.  This improves
> diagnostics in hotplug operations since it identifies an object that
> caused an issue in a log file.
> 
> acpi_pr_<level>() takes acpi_handle as an argument, which is passed
> to ACPI hotplug notify handlers from the ACPI CA.  Therefore, it is
> always available unlike other kernel objects, such as device.
> 
> For example, the statement below
>   acpi_pr_err(handle, "Device don't exist, dropping EJECT\n");
> logs an error message like this:
>   ACPI: \_SB_.SCK4.CPU4: Device don't exist, dropping EJECT
> 
> Signed-off-by: Toshi Kani <toshi.kani@hp.com>
> ---
>  drivers/acpi/utils.c    |   32 ++++++++++++++++++++++++++++++++
>  include/acpi/acpi_bus.h |   18 ++++++++++++++++++
>  2 files changed, 50 insertions(+), 0 deletions(-)
> 
> diff --git a/drivers/acpi/utils.c b/drivers/acpi/utils.c
> index 3e87c9c..4097266 100644
> --- a/drivers/acpi/utils.c
> +++ b/drivers/acpi/utils.c
> @@ -454,3 +454,35 @@ acpi_evaluate_hotplug_ost(acpi_handle handle, u32 source_event,
>  #endif
>  }
>  EXPORT_SYMBOL(acpi_evaluate_hotplug_ost);
> +
> +/**
> + * acpi_printk: Print messages with ACPI prefix and object path
> + *
> + * This function is intended to be called through acpi_pr_<level> macros.
> + */
> +void
> +acpi_printk(const char *level, acpi_handle handle, const char *fmt, ...)
> +{
> +	struct va_format vaf;
> +	va_list args;
> +	struct acpi_buffer buffer = {ACPI_ALLOCATE_BUFFER};
> +	char *path;
> +	acpi_status ret;
> +
> +	va_start(args, fmt);
> +
> +	vaf.fmt = fmt;
> +	vaf.va = &args;
> +
> +	ret = acpi_get_name(handle, ACPI_FULL_PATHNAME, &buffer);

One big problem I see with this approach is now each acpi_printk() will
result in a call to acpi_get_name() which will invoke several ACPI
calls, including a call to acpi_ut_initialize_buffer() which allocates
buffer. Is this really warranted? What is the performance impact of this
change?

-- Shuah

Re: [PATCH 1/4] ACPI: Add acpi_pr_<level>() interfaces

[Toshi Kani]

On Wed, 2012-07-18 at 15:59 -0600, Shuah Khan wrote:
> On Wed, 2012-07-18 at 14:40 -0600, Toshi Kani wrote:
> > This patch introduces acpi_pr_<level>(), where <level> is a message
> > level such as err/warn/info, to support improved logging messages
> > for ACPI, esp. in hotplug operations.  acpi_pr_<level>() appends
> > "ACPI" prefix and ACPI object path to the messages.  This improves
> > diagnostics in hotplug operations since it identifies an object that
> > caused an issue in a log file.
> > 
> > acpi_pr_<level>() takes acpi_handle as an argument, which is passed
> > to ACPI hotplug notify handlers from the ACPI CA.  Therefore, it is
> > always available unlike other kernel objects, such as device.
> > 
> > For example, the statement below
> >   acpi_pr_err(handle, "Device don't exist, dropping EJECT\n");
> > logs an error message like this:
> >   ACPI: \_SB_.SCK4.CPU4: Device don't exist, dropping EJECT
> > 
> > Signed-off-by: Toshi Kani <toshi.kani@hp.com>
> > ---
> >  drivers/acpi/utils.c    |   32 ++++++++++++++++++++++++++++++++
> >  include/acpi/acpi_bus.h |   18 ++++++++++++++++++
> >  2 files changed, 50 insertions(+), 0 deletions(-)
> > 
> > diff --git a/drivers/acpi/utils.c b/drivers/acpi/utils.c
> > index 3e87c9c..4097266 100644
> > --- a/drivers/acpi/utils.c
> > +++ b/drivers/acpi/utils.c
> > @@ -454,3 +454,35 @@ acpi_evaluate_hotplug_ost(acpi_handle handle, u32 source_event,
> >  #endif
> >  }
> >  EXPORT_SYMBOL(acpi_evaluate_hotplug_ost);
> > +
> > +/**
> > + * acpi_printk: Print messages with ACPI prefix and object path
> > + *
> > + * This function is intended to be called through acpi_pr_<level> macros.
> > + */
> > +void
> > +acpi_printk(const char *level, acpi_handle handle, const char *fmt, ...)
> > +{
> > +	struct va_format vaf;
> > +	va_list args;
> > +	struct acpi_buffer buffer = {ACPI_ALLOCATE_BUFFER};
> > +	char *path;
> > +	acpi_status ret;
> > +
> > +	va_start(args, fmt);
> > +
> > +	vaf.fmt = fmt;
> > +	vaf.va = &args;
> > +
> > +	ret = acpi_get_name(handle, ACPI_FULL_PATHNAME, &buffer);
> 
> One big problem I see with this approach is now each acpi_printk() will
> result in a call to acpi_get_name() which will invoke several ACPI
> calls, including a call to acpi_ut_initialize_buffer() which allocates
> buffer. Is this really warranted? What is the performance impact of this
> change?

Hi Shuah,

This interface is intended to be used by acpi_pr_<level>(), which is
used for error, warning, debugging, etc.  It is not intended to be used
in any performance path.

Thanks,
-Toshi


> 
> -- Shuah
> 
> 

Re: [PATCH 1/4] ACPI: Add acpi_pr_<level>() interfaces

[Shuah Khan]

On Wed, 2012-07-18 at 16:26 -0600, Toshi Kani wrote:
> On Wed, 2012-07-18 at 15:59 -0600, Shuah Khan wrote:
> > On Wed, 2012-07-18 at 14:40 -0600, Toshi Kani wrote:
> > > This patch introduces acpi_pr_<level>(), where <level> is a message
> > > level such as err/warn/info, to support improved logging messages
> > > for ACPI, esp. in hotplug operations.  acpi_pr_<level>() appends
> > > "ACPI" prefix and ACPI object path to the messages.  This improves
> > > diagnostics in hotplug operations since it identifies an object that
> > > caused an issue in a log file.
> > > 
> > > acpi_pr_<level>() takes acpi_handle as an argument, which is passed
> > > to ACPI hotplug notify handlers from the ACPI CA.  Therefore, it is
> > > always available unlike other kernel objects, such as device.
> > > 
> > > For example, the statement below
> > >   acpi_pr_err(handle, "Device don't exist, dropping EJECT\n");
> > > logs an error message like this:
> > >   ACPI: \_SB_.SCK4.CPU4: Device don't exist, dropping EJECT
> > > 
> > > Signed-off-by: Toshi Kani <toshi.kani@hp.com>
> > > ---
> > >  drivers/acpi/utils.c    |   32 ++++++++++++++++++++++++++++++++
> > >  include/acpi/acpi_bus.h |   18 ++++++++++++++++++
> > >  2 files changed, 50 insertions(+), 0 deletions(-)
> > > 
> > > diff --git a/drivers/acpi/utils.c b/drivers/acpi/utils.c
> > > index 3e87c9c..4097266 100644
> > > --- a/drivers/acpi/utils.c
> > > +++ b/drivers/acpi/utils.c
> > > @@ -454,3 +454,35 @@ acpi_evaluate_hotplug_ost(acpi_handle handle, u32 source_event,
> > >  #endif
> > >  }
> > >  EXPORT_SYMBOL(acpi_evaluate_hotplug_ost);
> > > +
> > > +/**
> > > + * acpi_printk: Print messages with ACPI prefix and object path
> > > + *
> > > + * This function is intended to be called through acpi_pr_<level> macros.
> > > + */
> > > +void
> > > +acpi_printk(const char *level, acpi_handle handle, const char *fmt, ...)
> > > +{
> > > +	struct va_format vaf;
> > > +	va_list args;
> > > +	struct acpi_buffer buffer = {ACPI_ALLOCATE_BUFFER};
> > > +	char *path;
> > > +	acpi_status ret;
> > > +
> > > +	va_start(args, fmt);
> > > +
> > > +	vaf.fmt = fmt;
> > > +	vaf.va = &args;
> > > +
> > > +	ret = acpi_get_name(handle, ACPI_FULL_PATHNAME, &buffer);
> > 
> > One big problem I see with this approach is now each acpi_printk() will
> > result in a call to acpi_get_name() which will invoke several ACPI
> > calls, including a call to acpi_ut_initialize_buffer() which allocates
> > buffer. Is this really warranted? What is the performance impact of this
> > change?
> 
> Hi Shuah,
> 
> This interface is intended to be used by acpi_pr_<level>(), which is
> used for error, warning, debugging, etc.  It is not intended to be used
> in any performance path.
> 

How does one enable this interface to see errors, warns, debugging? Is
there a special mode kernel needs to run in? I am trying to understand
what you mean by "not intended to be used in any performance path". Does
one build a special kernel similar to CONFIG_VM_DEBUG (just happen to
the one I could think off) ?

-- Shuah

Re: [PATCH 1/4] ACPI: Add acpi_pr_<level>() interfaces

[Toshi Kani]

On Wed, 2012-07-18 at 16:40 -0600, Shuah Khan wrote:
> On Wed, 2012-07-18 at 16:26 -0600, Toshi Kani wrote:
> > On Wed, 2012-07-18 at 15:59 -0600, Shuah Khan wrote:
> > > On Wed, 2012-07-18 at 14:40 -0600, Toshi Kani wrote:
> > > > This patch introduces acpi_pr_<level>(), where <level> is a message
> > > > level such as err/warn/info, to support improved logging messages
> > > > for ACPI, esp. in hotplug operations.  acpi_pr_<level>() appends
> > > > "ACPI" prefix and ACPI object path to the messages.  This improves
> > > > diagnostics in hotplug operations since it identifies an object that
> > > > caused an issue in a log file.
> > > > 
> > > > acpi_pr_<level>() takes acpi_handle as an argument, which is passed
> > > > to ACPI hotplug notify handlers from the ACPI CA.  Therefore, it is
> > > > always available unlike other kernel objects, such as device.
> > > > 
> > > > For example, the statement below
> > > >   acpi_pr_err(handle, "Device don't exist, dropping EJECT\n");
> > > > logs an error message like this:
> > > >   ACPI: \_SB_.SCK4.CPU4: Device don't exist, dropping EJECT
> > > > 
> > > > Signed-off-by: Toshi Kani <toshi.kani@hp.com>
> > > > ---
> > > >  drivers/acpi/utils.c    |   32 ++++++++++++++++++++++++++++++++
> > > >  include/acpi/acpi_bus.h |   18 ++++++++++++++++++
> > > >  2 files changed, 50 insertions(+), 0 deletions(-)
> > > > 
> > > > diff --git a/drivers/acpi/utils.c b/drivers/acpi/utils.c
> > > > index 3e87c9c..4097266 100644
> > > > --- a/drivers/acpi/utils.c
> > > > +++ b/drivers/acpi/utils.c
> > > > @@ -454,3 +454,35 @@ acpi_evaluate_hotplug_ost(acpi_handle handle, u32 source_event,
> > > >  #endif
> > > >  }
> > > >  EXPORT_SYMBOL(acpi_evaluate_hotplug_ost);
> > > > +
> > > > +/**
> > > > + * acpi_printk: Print messages with ACPI prefix and object path
> > > > + *
> > > > + * This function is intended to be called through acpi_pr_<level> macros.
> > > > + */
> > > > +void
> > > > +acpi_printk(const char *level, acpi_handle handle, const char *fmt, ...)
> > > > +{
> > > > +	struct va_format vaf;
> > > > +	va_list args;
> > > > +	struct acpi_buffer buffer = {ACPI_ALLOCATE_BUFFER};
> > > > +	char *path;
> > > > +	acpi_status ret;
> > > > +
> > > > +	va_start(args, fmt);
> > > > +
> > > > +	vaf.fmt = fmt;
> > > > +	vaf.va = &args;
> > > > +
> > > > +	ret = acpi_get_name(handle, ACPI_FULL_PATHNAME, &buffer);
> > > 
> > > One big problem I see with this approach is now each acpi_printk() will
> > > result in a call to acpi_get_name() which will invoke several ACPI
> > > calls, including a call to acpi_ut_initialize_buffer() which allocates
> > > buffer. Is this really warranted? What is the performance impact of this
> > > change?
> > 
> > Hi Shuah,
> > 
> > This interface is intended to be used by acpi_pr_<level>(), which is
> > used for error, warning, debugging, etc.  It is not intended to be used
> > in any performance path.
> > 
> 
> How does one enable this interface to see errors, warns, debugging? Is
> there a special mode kernel needs to run in? I am trying to understand
> what you mean by "not intended to be used in any performance path". Does
> one build a special kernel similar to CONFIG_VM_DEBUG (just happen to
> the one I could think off) ?

acpi_pr_<level>() calls printk() with a corresponding message level,
such as KERN_ERR, KERN_WARNING and KERN_DEBUG, which is by definition
used for error, warning and debugging messages.  Let me know if the
change log was not clear about this.  Anyway, I think one should not use
a printk() in performance path in the first place...

BTW, I realized that I forgot to define acpi_pr_debug()! (duh)  I will
update the patch to define it.


Thanks,
-Toshi


> -- Shuah
> 

Re: [PATCH 1/4] ACPI: Add acpi_pr_<level>() interfaces

[Shuah Khan]

On Wed, 2012-07-18 at 16:52 -0600, Toshi Kani wrote:
> On Wed, 2012-07-18 at 16:40 -0600, Shuah Khan wrote:
> > On Wed, 2012-07-18 at 16:26 -0600, Toshi Kani wrote:
> > > On Wed, 2012-07-18 at 15:59 -0600, Shuah Khan wrote:
> > > > On Wed, 2012-07-18 at 14:40 -0600, Toshi Kani wrote:
> > > > > This patch introduces acpi_pr_<level>(), where <level> is a message
> > > > > level such as err/warn/info, to support improved logging messages
> > > > > for ACPI, esp. in hotplug operations.  acpi_pr_<level>() appends
> > > > > "ACPI" prefix and ACPI object path to the messages.  This improves
> > > > > diagnostics in hotplug operations since it identifies an object that
> > > > > caused an issue in a log file.
> > > > > 
> > > > > acpi_pr_<level>() takes acpi_handle as an argument, which is passed
> > > > > to ACPI hotplug notify handlers from the ACPI CA.  Therefore, it is
> > > > > always available unlike other kernel objects, such as device.
> > > > > 
> > > > > For example, the statement below
> > > > >   acpi_pr_err(handle, "Device don't exist, dropping EJECT\n");
> > > > > logs an error message like this:
> > > > >   ACPI: \_SB_.SCK4.CPU4: Device don't exist, dropping EJECT
> > > > > 
> > > > > Signed-off-by: Toshi Kani <toshi.kani@hp.com>
> > > > > ---
> > > > >  drivers/acpi/utils.c    |   32 ++++++++++++++++++++++++++++++++
> > > > >  include/acpi/acpi_bus.h |   18 ++++++++++++++++++
> > > > >  2 files changed, 50 insertions(+), 0 deletions(-)
> > > > > 
> > > > > diff --git a/drivers/acpi/utils.c b/drivers/acpi/utils.c
> > > > > index 3e87c9c..4097266 100644
> > > > > --- a/drivers/acpi/utils.c
> > > > > +++ b/drivers/acpi/utils.c
> > > > > @@ -454,3 +454,35 @@ acpi_evaluate_hotplug_ost(acpi_handle handle, u32 source_event,
> > > > >  #endif
> > > > >  }
> > > > >  EXPORT_SYMBOL(acpi_evaluate_hotplug_ost);
> > > > > +
> > > > > +/**
> > > > > + * acpi_printk: Print messages with ACPI prefix and object path
> > > > > + *
> > > > > + * This function is intended to be called through acpi_pr_<level> macros.
> > > > > + */
> > > > > +void
> > > > > +acpi_printk(const char *level, acpi_handle handle, const char *fmt, ...)
> > > > > +{
> > > > > +	struct va_format vaf;
> > > > > +	va_list args;
> > > > > +	struct acpi_buffer buffer = {ACPI_ALLOCATE_BUFFER};
> > > > > +	char *path;
> > > > > +	acpi_status ret;
> > > > > +
> > > > > +	va_start(args, fmt);
> > > > > +
> > > > > +	vaf.fmt = fmt;
> > > > > +	vaf.va = &args;
> > > > > +
> > > > > +	ret = acpi_get_name(handle, ACPI_FULL_PATHNAME, &buffer);
> > > > 
> > > > One big problem I see with this approach is now each acpi_printk() will
> > > > result in a call to acpi_get_name() which will invoke several ACPI
> > > > calls, including a call to acpi_ut_initialize_buffer() which allocates
> > > > buffer. Is this really warranted? What is the performance impact of this
> > > > change?
> > > 
> > > Hi Shuah,
> > > 
> > > This interface is intended to be used by acpi_pr_<level>(), which is
> > > used for error, warning, debugging, etc.  It is not intended to be used
> > > in any performance path.
> > > 
> > 
> > How does one enable this interface to see errors, warns, debugging? Is
> > there a special mode kernel needs to run in? I am trying to understand
> > what you mean by "not intended to be used in any performance path". Does
> > one build a special kernel similar to CONFIG_VM_DEBUG (just happen to
> > the one I could think off) ?
> 
> acpi_pr_<level>() calls printk() with a corresponding message level,
> such as KERN_ERR, KERN_WARNING and KERN_DEBUG, which is by definition
> used for error, warning and debugging messages.  Let me know if the
> change log was not clear about this.  Anyway, I think one should not use
> a printk() in performance path in the first place...

KERN_ERR, KERN_WARNING, and KERN_DEBUG are used at run-time. What
happens when these new interfaces start getting used widely during
run-time. In the case of a serious error, shouldn't the kernel do the
minimum to print the message out and not call several acpi routines?
This type of feature definitely makes sense for debug, but not for other
cases KERN_ERR, KERN_WARNING case.

My concern is all the extra work that is done whenever one of these
interfaces is called. Can we limit this to special debug cases only.

-- Shuah

Re: [PATCH 1/4] ACPI: Add acpi_pr_<level>() interfaces

[Toshi Kani]

On Wed, 2012-07-18 at 17:18 -0600, Shuah Khan wrote:
> On Wed, 2012-07-18 at 16:52 -0600, Toshi Kani wrote:
> > On Wed, 2012-07-18 at 16:40 -0600, Shuah Khan wrote:
> > > On Wed, 2012-07-18 at 16:26 -0600, Toshi Kani wrote:
> > > > On Wed, 2012-07-18 at 15:59 -0600, Shuah Khan wrote:
> > > > > On Wed, 2012-07-18 at 14:40 -0600, Toshi Kani wrote:
> > > > > > This patch introduces acpi_pr_<level>(), where <level> is a message
> > > > > > level such as err/warn/info, to support improved logging messages
> > > > > > for ACPI, esp. in hotplug operations.  acpi_pr_<level>() appends
> > > > > > "ACPI" prefix and ACPI object path to the messages.  This improves
> > > > > > diagnostics in hotplug operations since it identifies an object that
> > > > > > caused an issue in a log file.
> > > > > > 
> > > > > > acpi_pr_<level>() takes acpi_handle as an argument, which is passed
> > > > > > to ACPI hotplug notify handlers from the ACPI CA.  Therefore, it is
> > > > > > always available unlike other kernel objects, such as device.
> > > > > > 
> > > > > > For example, the statement below
> > > > > >   acpi_pr_err(handle, "Device don't exist, dropping EJECT\n");
> > > > > > logs an error message like this:
> > > > > >   ACPI: \_SB_.SCK4.CPU4: Device don't exist, dropping EJECT
> > > > > > 
> > > > > > Signed-off-by: Toshi Kani <toshi.kani@hp.com>
> > > > > > ---
> > > > > >  drivers/acpi/utils.c    |   32 ++++++++++++++++++++++++++++++++
> > > > > >  include/acpi/acpi_bus.h |   18 ++++++++++++++++++
> > > > > >  2 files changed, 50 insertions(+), 0 deletions(-)
> > > > > > 
> > > > > > diff --git a/drivers/acpi/utils.c b/drivers/acpi/utils.c
> > > > > > index 3e87c9c..4097266 100644
> > > > > > --- a/drivers/acpi/utils.c
> > > > > > +++ b/drivers/acpi/utils.c
> > > > > > @@ -454,3 +454,35 @@ acpi_evaluate_hotplug_ost(acpi_handle handle, u32 source_event,
> > > > > >  #endif
> > > > > >  }
> > > > > >  EXPORT_SYMBOL(acpi_evaluate_hotplug_ost);
> > > > > > +
> > > > > > +/**
> > > > > > + * acpi_printk: Print messages with ACPI prefix and object path
> > > > > > + *
> > > > > > + * This function is intended to be called through acpi_pr_<level> macros.
> > > > > > + */
> > > > > > +void
> > > > > > +acpi_printk(const char *level, acpi_handle handle, const char *fmt, ...)
> > > > > > +{
> > > > > > +	struct va_format vaf;
> > > > > > +	va_list args;
> > > > > > +	struct acpi_buffer buffer = {ACPI_ALLOCATE_BUFFER};
> > > > > > +	char *path;
> > > > > > +	acpi_status ret;
> > > > > > +
> > > > > > +	va_start(args, fmt);
> > > > > > +
> > > > > > +	vaf.fmt = fmt;
> > > > > > +	vaf.va = &args;
> > > > > > +
> > > > > > +	ret = acpi_get_name(handle, ACPI_FULL_PATHNAME, &buffer);
> > > > > 
> > > > > One big problem I see with this approach is now each acpi_printk() will
> > > > > result in a call to acpi_get_name() which will invoke several ACPI
> > > > > calls, including a call to acpi_ut_initialize_buffer() which allocates
> > > > > buffer. Is this really warranted? What is the performance impact of this
> > > > > change?
> > > > 
> > > > Hi Shuah,
> > > > 
> > > > This interface is intended to be used by acpi_pr_<level>(), which is
> > > > used for error, warning, debugging, etc.  It is not intended to be used
> > > > in any performance path.
> > > > 
> > > 
> > > How does one enable this interface to see errors, warns, debugging? Is
> > > there a special mode kernel needs to run in? I am trying to understand
> > > what you mean by "not intended to be used in any performance path". Does
> > > one build a special kernel similar to CONFIG_VM_DEBUG (just happen to
> > > the one I could think off) ?
> > 
> > acpi_pr_<level>() calls printk() with a corresponding message level,
> > such as KERN_ERR, KERN_WARNING and KERN_DEBUG, which is by definition
> > used for error, warning and debugging messages.  Let me know if the
> > change log was not clear about this.  Anyway, I think one should not use
> > a printk() in performance path in the first place...
> 
> KERN_ERR, KERN_WARNING, and KERN_DEBUG are used at run-time. What
> happens when these new interfaces start getting used widely during
> run-time. In the case of a serious error, shouldn't the kernel do the
> minimum to print the message out and not call several acpi routines?

acpi_pr_<level>() does not replace pr_<level>().  When the kernel needs
the minimum to print the message out, it can continue to use the regular
pr_<level>() interface.

> This type of feature definitely makes sense for debug, but not for other
> cases KERN_ERR, KERN_WARNING case.

Can you elaborate why you think this interface does not make sense for
KERN_ERR and KERN_WARNING?  As described in the change log, we need to
know which object caused an error in order to diagnose an issue.  This
is a critical piece of the information to start analyzing.

Without this interface, error paths in the hotplug handlers would have
to call acpi_get_name() by itself in order to log the same information.
This is much more complicated and is not saving any time.

> My concern is all the extra work that is done whenever one of these
> interfaces is called. Can we limit this to special debug cases only.

This interface is defined in acpi/acpi_bus.h, which is intended for ACPI
drivers which make many ACPI calls to proceed when they are called at
run-time today.  This interface does not change that, and I believe
acpi_get_name() is much faster compared to ACPI method calls these ACPI
drivers make in their normal code path.  The extra work to call
acpi_get_name() is simply a noise in this case (if you try to measure),
and the use of this interface is limited in error paths of such ACPI
drivers.

Thanks,
-Toshi


> -- Shuah
> 

Re: [PATCH 1/4] ACPI: Add acpi_pr_<level>() interfaces

[Shuah Khan]

On Wed, 2012-07-18 at 18:38 -0600, Toshi Kani wrote:

> 
> This interface is defined in acpi/acpi_bus.h, which is intended for ACPI
> drivers which make many ACPI calls to proceed when they are called at
> run-time today.  This interface does not change that, and I believe
> acpi_get_name() is much faster compared to ACPI method calls these ACPI
> drivers make in their normal code path.  The extra work to call
> acpi_get_name() is simply a noise in this case (if you try to measure),
> and the use of this interface is limited in error paths of such ACPI
> drivers.

I understand the scope of the usage of this new interface. I don't think
I am able to explain the problem I see with this interface as it gets
used more and more from acpi drivers. Let me try another way.

If understand the this patch set, if and when acpi drivers that
currently use pr_* interfaces switch to using acpi_pr_*, the execution
path goes from a what printk() does to the following:

acpi_pr_*
- setup static buffer
- calls acpi_get_name()
- acpi_get_name() calls acpi_ut_validate_buffer() and then calls
  acpi_ns_handle_to_pathname()
- acpi_ns_handle_to_pathname() calls acpi_ns_validate_handle() followed
  by acpi_ns_get_pathname_length() and so on.

I think this should give you a good idea of my concern. I think
acpi_pr_* full functionality should be enabled under special cases such
as some acpi_debug level setting or some other way, and not for default
case. I propose the following:

Make acpi_pr_* versions execute the full path to do acpi_get_name()
conditionally and not as a default case.

To illustrate my point further, I currently see the following ACPI
messages in my dmesg buffer on my laptop. I haven't taken the time to
evaluate how many of them originate from acpi drivers, however I would
not want to see all of these becoming acpi_pr_* versions that do more
than what pr_* does today. I hope this explains my concern clearly.

[    0.000000] ACPI: RSDP 00000000000fc600 00024 (v02 HPQOEM)
[    0.000000] ACPI: XSDT 00000000bb7fe120 00084 (v01 HPQOEM SLIC-MPC
0000000F      01000013)
[    0.000000] ACPI: FACP 00000000bb7fc000 000F4 (v03 HPQOEM 172A
0000000F HP   00000001)
[    0.000000] ACPI: DSDT 00000000bb7d6000 203A2 (v02 HPQOEM 172A
00000001 INTL 20060912)
[    0.000000] ACPI: FACS 00000000bb760000 00040
[    0.000000] ACPI: HPET 00000000bb7fb000 00038 (v01 HPQOEM 172A
00000001 HP   00000001)
[    0.000000] ACPI: APIC 00000000bb7fa000 000BC (v01 HPQOEM 172A
00000001 HP   00000001)
[    0.000000] ACPI: MCFG 00000000bb7f9000 0003C (v01 HPQOEM 172A
00000001 HP   00000001)
[    0.000000] ACPI: TCPA 00000000bb7f7000 00032 (v02 HPQOEM 172A
00000000 HP   00000001)
[    0.000000] ACPI: SSDT 00000000bb7d3000 00135 (v01 HPQOEM SataAhci
00001000 INTL 20060912)
[    0.000000] ACPI: SSDT 00000000bb7d2000 00314 (v01 HPQOEM PtidDevc
00001000 INTL 20060912)
[    0.000000] ACPI: SLIC 00000000bb7d1000 00176 (v01 HPQOEM SLIC-MPC
00000001 HP   00000001)
[    0.000000] ACPI: SSDT 00000000bb7d0000 00A10 (v01  PmRef    CpuPm
00003000 INTL 20060912)
[    0.000000] ACPI: SSDT 00000000bb7cf000 00288 (v01  PmRef  Cpu0Tst
00003000 INTL 20060912)
[    0.000000] ACPI: SSDT 00000000bb7ce000 00225 (v01  PmRef    ApTst
00003000 INTL 20060912)
[    0.000000] ACPI: ASF! 00000000bb7f8000 000A0 (v32 HPQOEM 172A
00000001 HP   00000001)
[    0.000000] ACPI: Local APIC address 0xfee00000
[    0.000000] ACPI: PM-Timer IO Port: 0x408
[    0.000000] ACPI: Local APIC address 0xfee00000
[    0.000000] ACPI: LAPIC (acpi_id[0x00] lapic_id[0x00] enabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x01] lapic_id[0x01] enabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x02] lapic_id[0x04] enabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x03] lapic_id[0x05] enabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x04] lapic_id[0x00] disabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x05] lapic_id[0x00] disabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x06] lapic_id[0x00] disabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x07] lapic_id[0x00] disabled)
[    0.000000] ACPI: LAPIC_NMI (acpi_id[0x00] high edge lint[0x1])
[    0.000000] ACPI: LAPIC_NMI (acpi_id[0x01] high edge lint[0x1])
[    0.000000] ACPI: LAPIC_NMI (acpi_id[0x02] high edge lint[0x1])
[    0.000000] ACPI: LAPIC_NMI (acpi_id[0x03] high edge lint[0x1])
[    0.000000] ACPI: LAPIC_NMI (acpi_id[0x04] high edge lint[0x1])
[    0.000000] ACPI: LAPIC_NMI (acpi_id[0x05] high edge lint[0x1])
[    0.000000] ACPI: LAPIC_NMI (acpi_id[0x06] high edge lint[0x1])
[    0.000000] ACPI: LAPIC_NMI (acpi_id[0x07] high edge lint[0x1])
[    0.000000] ACPI: IOAPIC (id[0x01] address[0xfec00000] gsi_base[0])
[    0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
[    0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high
level)
[    0.000000] ACPI: IRQ0 used by override.
[    0.000000] ACPI: IRQ2 used by override.
[    0.000000] ACPI: IRQ9 used by override.
[    0.000000] Using ACPI (MADT) for SMP configuration information
[    0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000
[    0.003827] ACPI: Core revision 20120320
[    0.229840] PM: Registering ACPI NVS region [mem
0xbb6c2000-0xbb7c1fff] (1048576 bytes)
[    0.230694] ACPI FADT declares the system doesn't support PCIe ASPM,
so disable it
[    0.230698] ACPI: bus type pci registered
[    0.246838] ACPI: Added _OSI(Module Device)
[    0.246841] ACPI: Added _OSI(Processor Device)
[    0.246843] ACPI: Added _OSI(3.0 _SCP Extensions)
[    0.246845] ACPI: Added _OSI(Processor Aggregator Device)
[    0.248464] ACPI: EC: Look up EC in DSDT
[    0.250886] ACPI: Executed 1 blocks of module-level executable AML
code
[    0.256201] [Firmware Bug]: ACPI: BIOS _OSI(Linux) query ignored
[    0.264485] ACPI: SSDT 00000000bb6bba18 0047D (v01  PmRef  Cpu0Ist
00003000 INTL 20060912)
[    0.264874] ACPI: Dynamic OEM Table Load:
[    0.264878] ACPI: SSDT           (null) 0047D (v01  PmRef  Cpu0Ist
00003000 INTL 20060912)
[    0.264995] ACPI: SSDT 00000000bb6b9018 008AA (v01  PmRef  Cpu0Cst
00003001 INTL 20060912)
[    0.265369] ACPI: Dynamic OEM Table Load:
[    0.265372] ACPI: SSDT           (null) 008AA (v01  PmRef  Cpu0Cst
00003001 INTL 20060912)
[    0.265589] ACPI: SSDT 00000000bb6baa98 00303 (v01  PmRef    ApIst
00003000 INTL 20060912)
[    0.266008] ACPI: Dynamic OEM Table Load:
[    0.266012] ACPI: SSDT           (null) 00303 (v01  PmRef    ApIst
00003000 INTL 20060912)
[    0.266113] ACPI: SSDT 00000000bb6b8d98 00119 (v01  PmRef    ApCst
00003000 INTL 20060912)
[    0.266506] ACPI: Dynamic OEM Table Load:
[    0.266510] ACPI: SSDT           (null) 00119 (v01  PmRef    ApCst
00003000 INTL 20060912)
[    0.698211] ACPI: Interpreter enabled
[    0.698230] ACPI: (supports S0 S3 S4 S5)
[    0.698235] ACPI: Using IOAPIC for interrupt routing
[    0.699577] ACPI: Power Resource [APPR] (off)
[    0.700772] ACPI: Power Resource [LPP] (on)
[    0.702856] ACPI: EC: GPE = 0x16, I/O: command/status = 0x66, data =
0x62
[    0.703023] ACPI: No dock devices found.
[    0.703027] PCI: Using host bridge windows from ACPI; if necessary,
use "pci=nocrs" and report a bug
[    0.703627] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-fe])
[    0.713983] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0._PRT]
[    0.714162] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.PCIB._PRT]
[    0.714203] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.RP01._PRT]
[    0.714228] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.RP02._PRT]
[    0.714269] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.RP04._PRT]
[    0.714608]  pci0000:00: Requesting ACPI _OSC control (0x1d)
[    0.715476]  pci0000:00: ACPI _OSC control (0x1d) granted
[    0.719729] ACPI: PCI Root Bridge [CPBG] (domain 0000 [bus ff])
[    0.719885]  pci0000:ff: Requesting ACPI _OSC control (0x1d)
[    0.719888]  pci0000:ff: ACPI _OSC request failed (AE_NOT_FOUND),
returned control mask: 0x1d
[    0.719891] ACPI _OSC control for PCIe not granted, disabling ASPM
[    0.720049] ACPI: PCI Interrupt Link [LNKA] (IRQs 1 3 4 5 6 7 *10 12
14 15)
[    0.720087] ACPI: PCI Interrupt Link [LNKB] (IRQs 1 3 4 5 6 7 *11 12
14 15)
[    0.720124] ACPI: PCI Interrupt Link [LNKC] (IRQs 1 3 4 5 6 7 *10 12
14 15)
[    0.720160] ACPI: PCI Interrupt Link [LNKD] (IRQs 1 3 4 *5 6 7 11 12
14 15)
[    0.720195] ACPI: PCI Interrupt Link [LNKE] (IRQs 1 3 4 5 6 7 *10 12
14 15)
[    0.720230] ACPI: PCI Interrupt Link [LNKF] (IRQs 1 3 4 5 6 7 11 12
14 15) *10
[    0.720266] ACPI: PCI Interrupt Link [LNKG] (IRQs 1 3 4 5 6 7 10 12
14 15) *0, disabled.
[    0.720301] ACPI: PCI Interrupt Link [LNKH] (IRQs 1 3 4 5 6 7 11 12
14 15) *0, disabled.
[    0.720559] ACPI: bus type usb registered
[    0.720658] PCI: Using ACPI for IRQ routing
[    0.737801] pnp: PnP ACPI init
[    0.737817] ACPI: bus type pnp registered
[    0.738257] pnp 00:00: Plug and Play ACPI device, IDs PNP0a08 PNP0a03
(active)
[    0.738500] system 00:01: Plug and Play ACPI device, IDs PNP0c02
(active)
[    0.738593] pnp 00:02: Plug and Play ACPI device, IDs PNP0200
(active)
[    0.738619] pnp 00:03: Plug and Play ACPI device, IDs INT0800
(active)
[    0.738685] pnp 00:04: Plug and Play ACPI device, IDs IFX0102 PNP0c31
(active)
[    0.738770] pnp 00:05: Plug and Play ACPI device, IDs PNP0103
(active)
[    0.738810] pnp 00:06: Plug and Play ACPI device, IDs PNP0c04
(active)
[    0.738895] system 00:07: Plug and Play ACPI device, IDs PNP0c02
(active)
[    0.738930] pnp 00:08: Plug and Play ACPI device, IDs PNP0b00
(active)
[    0.739325] pnp 00:09: Plug and Play ACPI device, IDs PNP0401
(active)
[    0.739361] pnp 00:0a: Plug and Play ACPI device, IDs PNP0303
(active)
[    0.739396] pnp 00:0b: Plug and Play ACPI device, IDs SYN0165 SYN0100
SYN0002 PNP0f13 (active)
[    0.739602] pnp 00:0c: Plug and Play ACPI device, IDs HPQ0004
(active)
[    0.739742] pnp 00:0d: Plug and Play ACPI device, IDs PNP0a03
(active)
[    0.739841] pnp: PnP ACPI: found 14 devices
[    0.739844] ACPI: ACPI bus type pnp unregistered
[    1.078598] ACPI: Deprecated procfs I/F for AC is loaded, please
retry with CONFIG_ACPI_PROCFS_POWER cleared
[    1.078674] ACPI: AC Adapter [AC] (on-line)
[    1.078843] ACPI: Sleep Button [SLPB]
[    1.078892] ACPI: Lid Switch [LID]
[    1.078923] ACPI: Power Button [PWRF]
[    1.078982] ACPI: Requesting acpi_cpufreq
[    1.093567] ACPI: Thermal Zone [EXTZ] (0 C)
[    1.095993] ACPI: Thermal Zone [EX2Z] (26 C)
[    1.097220] ACPI: Thermal Zone [PWMZ] (0 C)
[    1.099681] ACPI: Thermal Zone [LOCZ] (25 C)
[    1.100065] ACPI: Thermal Zone [GFXZ] (0 C)
[    1.110366] ACPI: Thermal Zone [BATZ] (27 C)
[    1.120051] ACPI: Thermal Zone [EGXZ] (0 C)
[    1.120219] ACPI: Thermal Zone [CPUZ] (38 C)
[    1.120350] ACPI: Thermal Zone [MCHZ] (35 C)
[    1.120475] ACPI: Thermal Zone [PCHZ] (59 C)
[    1.165755] ACPI: Deprecated procfs I/F for battery is loaded, please
retry with CONFIG_ACPI_PROCFS_POWER cleared
[    1.165764] ACPI: Battery Slot [BAT0] (battery present)
[    1.165807] ACPI: Deprecated procfs I/F for battery is loaded, please
retry with CONFIG_ACPI_PROCFS_POWER cleared
[    1.165813] ACPI: Battery Slot [BAT1] (battery absent)
[    5.465815] ACPI: Video Device [GFX0] (multi-head: yes  rom: no
post: no)
[   43.954919] parport_pc 00:09: reported by Plug and Play ACPI
[   45.027388] ACPI Warning: 0x0000000000000460-0x000000000000047f
SystemIO conflicts with Region \PMIO 1 (20120320/utaddress-251)
[   45.027390] ACPI: If an ACPI driver is available for this device, you
should use it instead of the native driver
[   45.027397] ACPI Warning: 0x0000000000000428-0x000000000000042f
SystemIO conflicts with Region \PMIO 1 (20120320/utaddress-251)
[   45.027398] ACPI: If an ACPI driver is available for this device, you
should use it instead of the native driver
[   45.027404] ACPI Warning: 0x0000000000000500-0x000000000000057f
SystemIO conflicts with Region \GPIO 1 (20120320/utaddress-251)
[   45.027405] ACPI: If an ACPI driver is available for this device, you
should use it instead of the native driver
[   47.432241] snd_hda_intel 0000:00:1b.0: power state changed by ACPI
to D0
[   47.432254] snd_hda_intel 0000:00:1b.0: power state changed by ACPI
to D0

-- Shuah

Re: [PATCH 1/4] ACPI: Add acpi_pr_<level>() interfaces

[Joe Perches]

On Thu, 2012-07-19 at 10:15 -0600, Shuah Khan wrote:
> On Wed, 2012-07-18 at 18:38 -0600, Toshi Kani wrote:
> 
> > 
> > This interface is defined in acpi/acpi_bus.h, which is intended for ACPI
> > drivers which make many ACPI calls to proceed when they are called at
> > run-time today.  This interface does not change that, and I believe
> > acpi_get_name() is much faster compared to ACPI method calls these ACPI
> > drivers make in their normal code path.  The extra work to call
> > acpi_get_name() is simply a noise in this case (if you try to measure),
> > and the use of this interface is limited in error paths of such ACPI
> > drivers.
> 
> I understand the scope of the usage of this new interface. I don't think
> I am able to explain the problem I see with this interface as it gets
> used more and more from acpi drivers. Let me try another way.
> 
> If understand the this patch set, if and when acpi drivers that
> currently use pr_* interfaces switch to using acpi_pr_*, the execution
> path goes from a what printk() does to the following:
> 
> acpi_pr_*
> - setup static buffer
> - calls acpi_get_name()
> - acpi_get_name() calls acpi_ut_validate_buffer() and then calls
>   acpi_ns_handle_to_pathname()
> - acpi_ns_handle_to_pathname() calls acpi_ns_validate_handle() followed
>   by acpi_ns_get_pathname_length() and so on.
> 
> I think this should give you a good idea of my concern. I think
> acpi_pr_* full functionality should be enabled under special cases such
> as some acpi_debug level setting or some other way, and not for default
> case. I propose the following:
> 
> Make acpi_pr_* versions execute the full path to do acpi_get_name()
> conditionally and not as a default case.

or maybe cache one or two.

> To illustrate my point further, I currently see the following ACPI
> messages in my dmesg buffer on my laptop. I haven't taken the time to
> evaluate how many of them originate from acpi drivers, however I would
> not want to see all of these becoming acpi_pr_* versions that do more
> than what pr_* does today. I hope this explains my concern clearly.
> 
> [    0.000000] ACPI: RSDP 00000000000fc600 00024 (v02 HPQOEM)
> [    0.000000] ACPI: XSDT 00000000bb7fe120 00084 (v01 HPQOEM SLIC-MPC
> 0000000F      01000013)

[120+ lines of ACPI stuff]

> [    0.739844] ACPI: ACPI bus type pnp unregistered

I think ACPI is the noisiest subsystem.

I'd rather see this logging made quieter by conversion to
KERN_DEBUG or another selective mechanism.

There just aren't many ACPI_INFO calls around and that why
I thought it reasonable to convert the macro to call a
different named function.

Re: [PATCH 1/4] ACPI: Add acpi_pr_<level>() interfaces

[Toshi Kani]

On Thu, 2012-07-19 at 09:34 -0700, Joe Perches wrote:
> On Thu, 2012-07-19 at 10:15 -0600, Shuah Khan wrote:
> > On Wed, 2012-07-18 at 18:38 -0600, Toshi Kani wrote:
> > 
> > > 
> > > This interface is defined in acpi/acpi_bus.h, which is intended for ACPI
> > > drivers which make many ACPI calls to proceed when they are called at
> > > run-time today.  This interface does not change that, and I believe
> > > acpi_get_name() is much faster compared to ACPI method calls these ACPI
> > > drivers make in their normal code path.  The extra work to call
> > > acpi_get_name() is simply a noise in this case (if you try to measure),
> > > and the use of this interface is limited in error paths of such ACPI
> > > drivers.
> > 
> > I understand the scope of the usage of this new interface. I don't think
> > I am able to explain the problem I see with this interface as it gets
> > used more and more from acpi drivers. Let me try another way.
> > 
> > If understand the this patch set, if and when acpi drivers that
> > currently use pr_* interfaces switch to using acpi_pr_*, the execution
> > path goes from a what printk() does to the following:
> > 
> > acpi_pr_*
> > - setup static buffer
> > - calls acpi_get_name()
> > - acpi_get_name() calls acpi_ut_validate_buffer() and then calls
> >   acpi_ns_handle_to_pathname()
> > - acpi_ns_handle_to_pathname() calls acpi_ns_validate_handle() followed
> >   by acpi_ns_get_pathname_length() and so on.
> > 
> > I think this should give you a good idea of my concern. I think
> > acpi_pr_* full functionality should be enabled under special cases such
> > as some acpi_debug level setting or some other way, and not for default
> > case. I propose the following:
> > 
> > Make acpi_pr_* versions execute the full path to do acpi_get_name()
> > conditionally and not as a default case.
> 
> or maybe cache one or two.

Hi Joe,

Sorry, I had overlooked this email yesterday...

I agree that caching one or two is a good idea when we expect to see
repeated calls to a same object.  I think there may be a few repeated
calls, such that callee fails and calls acpi_pr_<level>() with its error
message, and then caller sees this error return and calls
acpi_pr_<level>() with its own message.  That said, considering
additional complexity of locking cache data, etc., I'd prefer keeping
the code simple for now since I do not expect this interface be called
very often.

> > To illustrate my point further, I currently see the following ACPI
> > messages in my dmesg buffer on my laptop. I haven't taken the time to
> > evaluate how many of them originate from acpi drivers, however I would
> > not want to see all of these becoming acpi_pr_* versions that do more
> > than what pr_* does today. I hope this explains my concern clearly.
> > 
> > [    0.000000] ACPI: RSDP 00000000000fc600 00024 (v02 HPQOEM)
> > [    0.000000] ACPI: XSDT 00000000bb7fe120 00084 (v01 HPQOEM SLIC-MPC
> > 0000000F      01000013)
> 
> [120+ lines of ACPI stuff]
> 
> > [    0.739844] ACPI: ACPI bus type pnp unregistered
> 
> I think ACPI is the noisiest subsystem.

I agree for the boot time messages.  The use of ACPI is limited at
run-time, such as hotplug operations, though.

> I'd rather see this logging made quieter by conversion to
> KERN_DEBUG or another selective mechanism.
>
> There just aren't many ACPI_INFO calls around and that why
> I thought it reasonable to convert the macro to call a
> different named function.

I looked at the first two major cases as follows.  Looks like there are
some considerations to minimize them.

ACPI_INFO is suppressed when ACPI_NO_ERROR_MESSAGES is defined.

    ACPI_INFO((AE_INFO, "RSDP %p %05X (v%.2d %6.6s)",
           ACPI_CAST_PTR (void, address),
           (ACPI_CAST_PTR(struct acpi_table_rsdp, header)->
           revision >
           0) ? ACPI_CAST_PTR(struct acpi_table_rsdp,
                              header)->length : 20,
           ACPI_CAST_PTR(struct acpi_table_rsdp,
                         header)->revision,
                         local_header.oem_id));

LAPIC info is printed at KERN_INFO.

     printk(KERN_INFO PREFIX
          "LAPIC (acpi_id[0x%02x] lapic_id[0x%02x] %s)\n",
           p->processor_id, p->id,
           (p->lapic_flags & ACPI_MADT_ENABLED) ? "enabled"

Thanks,
-Toshi


> 
> --
> To unsubscribe from this list: send the line "unsubscribe linux-acpi" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [PATCH 1/4] ACPI: Add acpi_pr_<level>() interfaces

[Toshi Kani]

On Thu, 2012-07-19 at 10:15 -0600, Shuah Khan wrote:
> On Wed, 2012-07-18 at 18:38 -0600, Toshi Kani wrote:
> 
> > 
> > This interface is defined in acpi/acpi_bus.h, which is intended for ACPI
> > drivers which make many ACPI calls to proceed when they are called at
> > run-time today.  This interface does not change that, and I believe
> > acpi_get_name() is much faster compared to ACPI method calls these ACPI
> > drivers make in their normal code path.  The extra work to call
> > acpi_get_name() is simply a noise in this case (if you try to measure),
> > and the use of this interface is limited in error paths of such ACPI
> > drivers.
> 
> I understand the scope of the usage of this new interface. I don't think
> I am able to explain the problem I see with this interface as it gets
> used more and more from acpi drivers. Let me try another way.
> 
> If understand the this patch set, if and when acpi drivers that
> currently use pr_* interfaces switch to using acpi_pr_*, the execution
> path goes from a what printk() does to the following:
> 
> acpi_pr_*
> - setup static buffer
> - calls acpi_get_name()
> - acpi_get_name() calls acpi_ut_validate_buffer() and then calls
>   acpi_ns_handle_to_pathname()
> - acpi_ns_handle_to_pathname() calls acpi_ns_validate_handle() followed
>   by acpi_ns_get_pathname_length() and so on.
> 
> I think this should give you a good idea of my concern. I think
> acpi_pr_* full functionality should be enabled under special cases such
> as some acpi_debug level setting or some other way, and not for default
> case. I propose the following:
> 
> Make acpi_pr_* versions execute the full path to do acpi_get_name()
> conditionally and not as a default case.
> 
> To illustrate my point further, I currently see the following ACPI
> messages in my dmesg buffer on my laptop. I haven't taken the time to
> evaluate how many of them originate from acpi drivers, however I would
> not want to see all of these becoming acpi_pr_* versions that do more
> than what pr_* does today. I hope this explains my concern clearly.

I agree that there are many ACPI messages at boot, and I understand that
you concerned with them, but that is a different issue.  It requires a
different project to address them.  Changing my patchset won't make any
difference.

The issue I am trying to solve is well summarized in Bjorn's comment in
my earlier patch as follows: 
=== <quote> ===
>                result = acpi_processor_device_add(handle, &device);
>                if (result) {
>                        printk(KERN_ERR PREFIX "Unable to add the
device\n");

You didn't add this problem, but since you're touching the code, I'll
point it out.  This message will look to the user like:

    ACPI: Unable to add the device

which is useless.  The user has no idea what device we're talking
about or why we can't add it, so he can't *do* anything with the
message.
=== </quote> ===

This is very true.  And this issue is even worse when support teams need
to solve such customer issue from log files.  The current error messages
in ACPI hotplug handlers do not provide any information to identify a
device that cause an issue.

To address this issue, the ACPI drivers have to obtain an ACPI object
path information in their error handling code with acpi_get_name().

A possible alternative to acpi_pr_<level>() is to create a driver's
local printk function, just like acpi_print_osc_error().  However, I do
not think we should create such local functions in all ACPI drivers.

Performance is not an issue since the use of the interfaces is limited
to the error paths.  The boot messages you concerned with do not need to
any more extra-info to append ACPI device path, and therefore no need to
use acpi_pr_<level>().  dev_<level>() may be a good example of how this
type of interfaces is used in error paths today.


Thanks,
-Toshi





  

Re: [PATCH 1/4] ACPI: Add acpi_pr_<level>() interfaces

[Shuah Khan]

On Thu, 2012-07-19 at 11:28 -0600, Toshi Kani wrote:
> On Thu, 2012-07-19 at 10:15 -0600, Shuah Khan wrote:
> > On Wed, 2012-07-18 at 18:38 -0600, Toshi Kani wrote:
> > 
> > > 
> > > This interface is defined in acpi/acpi_bus.h, which is intended for ACPI
> > > drivers which make many ACPI calls to proceed when they are called at
> > > run-time today.  This interface does not change that, and I believe
> > > acpi_get_name() is much faster compared to ACPI method calls these ACPI
> > > drivers make in their normal code path.  The extra work to call
> > > acpi_get_name() is simply a noise in this case (if you try to measure),
> > > and the use of this interface is limited in error paths of such ACPI
> > > drivers.
> > 
> > I understand the scope of the usage of this new interface. I don't think
> > I am able to explain the problem I see with this interface as it gets
> > used more and more from acpi drivers. Let me try another way.
> > 
> > If understand the this patch set, if and when acpi drivers that
> > currently use pr_* interfaces switch to using acpi_pr_*, the execution
> > path goes from a what printk() does to the following:
> > 
> > acpi_pr_*
> > - setup static buffer
> > - calls acpi_get_name()
> > - acpi_get_name() calls acpi_ut_validate_buffer() and then calls
> >   acpi_ns_handle_to_pathname()
> > - acpi_ns_handle_to_pathname() calls acpi_ns_validate_handle() followed
> >   by acpi_ns_get_pathname_length() and so on.
> > 
> > I think this should give you a good idea of my concern. I think
> > acpi_pr_* full functionality should be enabled under special cases such
> > as some acpi_debug level setting or some other way, and not for default
> > case. I propose the following:
> > 
> > Make acpi_pr_* versions execute the full path to do acpi_get_name()
> > conditionally and not as a default case.
> > 
> > To illustrate my point further, I currently see the following ACPI
> > messages in my dmesg buffer on my laptop. I haven't taken the time to
> > evaluate how many of them originate from acpi drivers, however I would
> > not want to see all of these becoming acpi_pr_* versions that do more
> > than what pr_* does today. I hope this explains my concern clearly.
> 
> I agree that there are many ACPI messages at boot, and I understand that
> you concerned with them, but that is a different issue.  It requires a
> different project to address them.  Changing my patchset won't make any
> difference.

On the contrary, your patch set could make the existing problems worse
by introducing lot of complexity (makes the execution path very long for
each and every one these messages) in the path that prints messages. As
more and more acpi code paths start using the new interfaces, it will
keep getting worse.

I am not questioning the usefulness of the additional information, I am
questioning the complexity your patch set adds. The added complexity
isn't desirable.

The design in this patch set needs refinement so it doesn't add to the
execution path.

-- Shuah

Re: [PATCH 1/4] ACPI: Add acpi_pr_<level>() interfaces

[Toshi Kani]

On Thu, 2012-07-19 at 13:25 -0600, Shuah Khan wrote:
> On Thu, 2012-07-19 at 11:28 -0600, Toshi Kani wrote:
> > On Thu, 2012-07-19 at 10:15 -0600, Shuah Khan wrote:
> > > On Wed, 2012-07-18 at 18:38 -0600, Toshi Kani wrote:
> > > 
> > > > 
> > > > This interface is defined in acpi/acpi_bus.h, which is intended for ACPI
> > > > drivers which make many ACPI calls to proceed when they are called at
> > > > run-time today.  This interface does not change that, and I believe
> > > > acpi_get_name() is much faster compared to ACPI method calls these ACPI
> > > > drivers make in their normal code path.  The extra work to call
> > > > acpi_get_name() is simply a noise in this case (if you try to measure),
> > > > and the use of this interface is limited in error paths of such ACPI
> > > > drivers.
> > > 
> > > I understand the scope of the usage of this new interface. I don't think
> > > I am able to explain the problem I see with this interface as it gets
> > > used more and more from acpi drivers. Let me try another way.
> > > 
> > > If understand the this patch set, if and when acpi drivers that
> > > currently use pr_* interfaces switch to using acpi_pr_*, the execution
> > > path goes from a what printk() does to the following:
> > > 
> > > acpi_pr_*
> > > - setup static buffer
> > > - calls acpi_get_name()
> > > - acpi_get_name() calls acpi_ut_validate_buffer() and then calls
> > >   acpi_ns_handle_to_pathname()
> > > - acpi_ns_handle_to_pathname() calls acpi_ns_validate_handle() followed
> > >   by acpi_ns_get_pathname_length() and so on.
> > > 
> > > I think this should give you a good idea of my concern. I think
> > > acpi_pr_* full functionality should be enabled under special cases such
> > > as some acpi_debug level setting or some other way, and not for default
> > > case. I propose the following:
> > > 
> > > Make acpi_pr_* versions execute the full path to do acpi_get_name()
> > > conditionally and not as a default case.
> > > 
> > > To illustrate my point further, I currently see the following ACPI
> > > messages in my dmesg buffer on my laptop. I haven't taken the time to
> > > evaluate how many of them originate from acpi drivers, however I would
> > > not want to see all of these becoming acpi_pr_* versions that do more
> > > than what pr_* does today. I hope this explains my concern clearly.
> > 
> > I agree that there are many ACPI messages at boot, and I understand that
> > you concerned with them, but that is a different issue.  It requires a
> > different project to address them.  Changing my patchset won't make any
> > difference.
> 
> On the contrary, your patch set could make the existing problems worse
> by introducing lot of complexity (makes the execution path very long for
> each and every one these messages) in the path that prints messages. As
> more and more acpi code paths start using the new interfaces, it will
> keep getting worse.
> 
> I am not questioning the usefulness of the additional information, I am
> questioning the complexity your patch set adds. The added complexity
> isn't desirable.

That's good.  In the last email, you suggested to make the interface
debug-only, and make it non-default case.  This totally defeats the
purpose, which is why I explained it.  When someone reported an issue,
we do not want to tell him that he will need to reproduce it again with
debug kernel/option.  I am glad to know that you understand this point.

> The design in this patch set needs refinement so it doesn't add to the
> execution path.

I am not sure why you are so much concerned about the complexity.
Frankly, acpi_get_name() is one of the simplest and lightest interfaces
in the ACPI CA.  It does not execute AML at all.  The slowness or
complexity of ACPI comes when it executes AML due to the way ACPI is
defined.  acpi_get_name() simply builds a path info and copies it to an
allocated buffer.

One possible optimization is, like Joe suggested, to avoid a buffer
allocation.  I prefer not to use stack space as I explained to Joe.  We
could statically allocate per-CPU buffer for this, but I do not think it
is worth doing it.  After all, such optimization makes the code
complicated, and does not make any difference in performance.  At
run-time, ACPI is only used when GPE occurs (or accessed from sysfs),
which is infrequent event and has nothing to compare with the
performance paths like syscall and I/Os.  And acpi_pr_<level>() is used
in the error paths of such infrequent events.

If your concern is actually a performance bottleneck in acpi_get_name()
you found in the code, you should report it to the ACPI CA team.

Thanks,
-Toshi

> -- Shuah
> 
> 

Re: [PATCH 1/4] ACPI: Add acpi_pr_<level>() interfaces

[Shuah Khan]

On Thu, 2012-07-19 at 14:51 -0600, Toshi Kani wrote:

> If your concern is actually a performance bottleneck in acpi_get_name()
> you found in the code, you should report it to the ACPI CA team.

I have tried my best to get you to understand the problems in bigger
picture your patch set can exacerbate. Looking to somebody else to fix
the problems doesn't help. It doesn't look like we can come to an
agreement here, we just have to agree to disagree.

caio,
-- Shuah

Re: [PATCH 1/4] ACPI: Add acpi_pr_<level>() interfaces

[Toshi Kani]

On Thu, 2012-07-19 at 16:32 -0600, Shuah Khan wrote:
> On Thu, 2012-07-19 at 14:51 -0600, Toshi Kani wrote:
> 
> > If your concern is actually a performance bottleneck in acpi_get_name()
> > you found in the code, you should report it to the ACPI CA team.
> 
> I have tried my best to get you to understand the problems in bigger
> picture your patch set can exacerbate. Looking to somebody else to fix
> the problems doesn't help. It doesn't look like we can come to an
> agreement here, we just have to agree to disagree.

I am not asking someone to fix it.  I tried my best to explain that
acpi_get_name() does not lead any performance issue when it is called in
the error paths of ACPI drivers, and why we have to call it to obtain an
object path info for error analysis.  If you still believe there is a
performance issue in calling acpi_get_name() under this context, please
help us understand where the performance bottleneck is in the code.  (I
hope you just concerned it because it has "acpi_" prefix...) I will then
work on the issue with the ACPI CA team.

Thanks,
-Toshi



> caio,
> -- Shuah
> 

Re: [PATCH 1/4] ACPI: Add acpi_pr_<level>() interfaces

[Toshi Kani]

On Thu, 2012-07-19 at 17:43 -0600, Toshi Kani wrote:
> On Thu, 2012-07-19 at 16:32 -0600, Shuah Khan wrote:
> > On Thu, 2012-07-19 at 14:51 -0600, Toshi Kani wrote:
> > 
> > > If your concern is actually a performance bottleneck in acpi_get_name()
> > > you found in the code, you should report it to the ACPI CA team.
> > 
> > I have tried my best to get you to understand the problems in bigger
> > picture your patch set can exacerbate. Looking to somebody else to fix
> > the problems doesn't help. It doesn't look like we can come to an
> > agreement here, we just have to agree to disagree.
> 
> I am not asking someone to fix it.  I tried my best to explain that
> acpi_get_name() does not lead any performance issue when it is called in
> the error paths of ACPI drivers, and why we have to call it to obtain an
> object path info for error analysis.  If you still believe there is a
> performance issue in calling acpi_get_name() under this context, please
> help us understand where the performance bottleneck is in the code.  (I
> hope you just concerned it because it has "acpi_" prefix...) I will then
> work on the issue with the ACPI CA team.

I have measured acpi_pr_<level>() to make sure my statement is correct.
Here are the results:

Avg. acpi_get_name()		 587 ns
Avg. printk()			3420 ns
Avg. kfree()			 238 ns
Avg. acpi_get_time()+kfree()	 825 ns

The results indicate that acpi_pr_<level>() has 20% increase of the time
compared to the regular printk(), which is less than 1 us.  I believe
the results endorse my statement, and may not cause any performance
issue to the error paths of the ACPI drivers.

-Toshi


> Thanks,
> -Toshi
> 
> 
> 
> > caio,
> > -- Shuah
> > 
> 

Re: [PATCH 1/4] ACPI: Add acpi_pr_<level>() interfaces

[Toshi Kani]

On Tue, 2012-07-24 at 09:55 -0600, Toshi Kani wrote:
> On Thu, 2012-07-19 at 17:43 -0600, Toshi Kani wrote:
> > On Thu, 2012-07-19 at 16:32 -0600, Shuah Khan wrote:
> > > On Thu, 2012-07-19 at 14:51 -0600, Toshi Kani wrote:
> > > 
> > > > If your concern is actually a performance bottleneck in acpi_get_name()
> > > > you found in the code, you should report it to the ACPI CA team.
> > > 
> > > I have tried my best to get you to understand the problems in bigger
> > > picture your patch set can exacerbate. Looking to somebody else to fix
> > > the problems doesn't help. It doesn't look like we can come to an
> > > agreement here, we just have to agree to disagree.
> > 
> > I am not asking someone to fix it.  I tried my best to explain that
> > acpi_get_name() does not lead any performance issue when it is called in
> > the error paths of ACPI drivers, and why we have to call it to obtain an
> > object path info for error analysis.  If you still believe there is a
> > performance issue in calling acpi_get_name() under this context, please
> > help us understand where the performance bottleneck is in the code.  (I
> > hope you just concerned it because it has "acpi_" prefix...) I will then
> > work on the issue with the ACPI CA team.
> 
> I have measured acpi_pr_<level>() to make sure my statement is correct.
> Here are the results:
> 
> Avg. acpi_get_name()		 587 ns
> Avg. printk()			3420 ns
> Avg. kfree()			 238 ns
> Avg. acpi_get_time()+kfree()	 825 ns
> 
> The results indicate that acpi_pr_<level>() has 20% increase of the time

Oops, I should have stated that it is 24% increase to printk(), or 20%
of time in acpi_pr_<level>().

-Toshi


> compared to the regular printk(), which is less than 1 us.  I believe
> the results endorse my statement, and may not cause any performance
> issue to the error paths of the ACPI drivers.
> 
> -Toshi
> 
> 
> > Thanks,
> > -Toshi
> > 
> > 
> > 
> > > caio,
> > > -- Shuah
> > > 
> > 
> 

Re: [PATCH 1/4] ACPI: Add acpi_pr_<level>() interfaces

[Joe Perches]

On Wed, 2012-07-18 at 16:26 -0600, Toshi Kani wrote:
> On Wed, 2012-07-18 at 15:59 -0600, Shuah Khan wrote:
> > On Wed, 2012-07-18 at 14:40 -0600, Toshi Kani wrote:
> > > This patch introduces acpi_pr_<level>(), where <level> is a message
> > > level such as err/warn/info, to support improved logging messages
> > > for ACPI, esp. in hotplug operations.
[]
> > > diff --git a/drivers/acpi/utils.c b/drivers/acpi/utils.c
[]
> > > @@ -454,3 +454,35 @@ acpi_evaluate_hotplug_ost(acpi_handle handle, u32 source_event,
[]
> > > +	struct acpi_buffer buffer = {ACPI_ALLOCATE_BUFFER};
[]
> > > +	ret = acpi_get_name(handle, ACPI_FULL_PATHNAME, &buffer);
> > 
> > One big problem I see with this approach is now each acpi_printk() will
> > result in a call to acpi_get_name() which will invoke several ACPI
> > calls, including a call to acpi_ut_initialize_buffer() which allocates
> > buffer. Is this really warranted? What is the performance impact of this
> > change?
[]
> This interface is intended to be used by acpi_pr_<level>(), which is
> used for error, warning, debugging, etc.  It is not intended to be used
> in any performance path.

While it's not performance critical, perhaps the buffer
alloc/free could be avoided by using stack. Something like:

	char name[ACPI_PATH_SEGMENT_LENGTH * max_segments ? ];
	struct acpi_buffer buffer = {
		.length = ACPI_PATH_SEGMENT_LENGTH,
		.buffer = name,
	};

Re: [PATCH 1/4] ACPI: Add acpi_pr_<level>() interfaces

[Toshi Kani]

On Wed, 2012-07-18 at 15:49 -0700, Joe Perches wrote:
> On Wed, 2012-07-18 at 16:26 -0600, Toshi Kani wrote:
> > On Wed, 2012-07-18 at 15:59 -0600, Shuah Khan wrote:
> > > On Wed, 2012-07-18 at 14:40 -0600, Toshi Kani wrote:
> > > > This patch introduces acpi_pr_<level>(), where <level> is a message
> > > > level such as err/warn/info, to support improved logging messages
> > > > for ACPI, esp. in hotplug operations.
> []
> > > > diff --git a/drivers/acpi/utils.c b/drivers/acpi/utils.c
> []
> > > > @@ -454,3 +454,35 @@ acpi_evaluate_hotplug_ost(acpi_handle handle, u32 source_event,
> []
> > > > +	struct acpi_buffer buffer = {ACPI_ALLOCATE_BUFFER};
> []
> > > > +	ret = acpi_get_name(handle, ACPI_FULL_PATHNAME, &buffer);
> > > 
> > > One big problem I see with this approach is now each acpi_printk() will
> > > result in a call to acpi_get_name() which will invoke several ACPI
> > > calls, including a call to acpi_ut_initialize_buffer() which allocates
> > > buffer. Is this really warranted? What is the performance impact of this
> > > change?
> []
> > This interface is intended to be used by acpi_pr_<level>(), which is
> > used for error, warning, debugging, etc.  It is not intended to be used
> > in any performance path.
> 
> While it's not performance critical, perhaps the buffer
> alloc/free could be avoided by using stack. Something like:
> 
> 	char name[ACPI_PATH_SEGMENT_LENGTH * max_segments ? ];
> 	struct acpi_buffer buffer = {
> 		.length = ACPI_PATH_SEGMENT_LENGTH,
> 		.buffer = name,
> 	};
> 

Hi Joe,

I thought about using stack initially, but I too was not sure how big
the buffer size should be, and was a bit afraid of causing kernel stack
overflow potentially.  Since it is mainly used for error paths in ACPI
hotplug handlers, I do not think alloc/free can lead any performance
impact.

Thanks,
-Toshi

[PATCH 2/4] ACPI: Update CPU hotplug messages

[Toshi Kani]

Updated CPU hotplug log messages with acpi_pr_<level>(),
dev_<level>() and pr_<level>().  Some messages are also
changed for clarity.

Signed-off-by: Toshi Kani <toshi.kani@hp.com>
---
 drivers/acpi/processor_driver.c |   36 +++++++++++++++++++++---------------
 1 files changed, 21 insertions(+), 15 deletions(-)

diff --git a/drivers/acpi/processor_driver.c b/drivers/acpi/processor_driver.c
index a6f6bde..40727d9 100644
--- a/drivers/acpi/processor_driver.c
+++ b/drivers/acpi/processor_driver.c
@@ -280,7 +280,9 @@ static int acpi_processor_get_info(struct acpi_device *device)
 		/* Declared with "Processor" statement; match ProcessorID */
 		status = acpi_evaluate_object(pr->handle, NULL, NULL, &buffer);
 		if (ACPI_FAILURE(status)) {
-			printk(KERN_ERR PREFIX "Evaluating processor object\n");
+			acpi_pr_err(pr->handle,
+				"Failed to evaluate processor object (0x%x)\n",
+				status);
 			return -ENODEV;
 		}
 
@@ -299,8 +301,9 @@ static int acpi_processor_get_info(struct acpi_device *device)
 		status = acpi_evaluate_integer(pr->handle, METHOD_NAME__UID,
 						NULL, &value);
 		if (ACPI_FAILURE(status)) {
-			printk(KERN_ERR PREFIX
-			    "Evaluating processor _UID [%#x]\n", status);
+			acpi_pr_err(pr->handle,
+				"Failed to evaluate processor _UID (0x%x)\n",
+				status);
 			return -ENODEV;
 		}
 		device_declaration = 1;
@@ -343,7 +346,7 @@ static int acpi_processor_get_info(struct acpi_device *device)
 	if (!object.processor.pblk_address)
 		ACPI_DEBUG_PRINT((ACPI_DB_INFO, "No PBLK (NULL address)\n"));
 	else if (object.processor.pblk_length != 6)
-		printk(KERN_ERR PREFIX "Invalid PBLK length [%d]\n",
+		acpi_pr_err(pr->handle, "Invalid PBLK length [%d]\n",
 			    object.processor.pblk_length);
 	else {
 		pr->throttling.address = object.processor.pblk_address;
@@ -430,8 +433,8 @@ static int acpi_cpu_soft_notify(struct notifier_block *nfb,
 			struct cpuidle_driver *idle_driver =
 				cpuidle_get_driver();
 
-			printk(KERN_INFO "Will online and init hotplugged "
-			       "CPU: %d\n", pr->id);
+			pr_info("Will online and init hotplugged CPU: %d\n",
+				pr->id);
 			WARN(acpi_processor_start(pr), "Failed to start CPU:"
 				" %d\n", pr->id);
 			pr->flags.need_hotplug_init = 0;
@@ -496,14 +499,16 @@ static __ref int acpi_processor_start(struct acpi_processor *pr)
 				   &pr->cdev->device.kobj,
 				   "thermal_cooling");
 	if (result) {
-		printk(KERN_ERR PREFIX "Create sysfs link\n");
+		dev_err(&device->dev,
+			"Failed to create sysfs link 'thermal_cooling'\n");
 		goto err_thermal_unregister;
 	}
 	result = sysfs_create_link(&pr->cdev->device.kobj,
 				   &device->dev.kobj,
 				   "device");
 	if (result) {
-		printk(KERN_ERR PREFIX "Create sysfs link\n");
+		dev_err(&pr->cdev->device,
+			"Failed to create sysfs link 'device'\n");
 		goto err_remove_sysfs_thermal;
 	}
 
@@ -565,8 +570,7 @@ static int __cpuinit acpi_processor_add(struct acpi_device *device)
 	 */
 	if (per_cpu(processor_device_array, pr->id) != NULL &&
 	    per_cpu(processor_device_array, pr->id) != device) {
-		printk(KERN_WARNING "BIOS reported wrong ACPI id "
-			"for the processor\n");
+		pr_warn("BIOS reported wrong ACPI id for the processor\n");
 		result = -ENODEV;
 		goto err_free_cpumask;
 	}
@@ -720,7 +724,7 @@ static void acpi_processor_hotplug_notify(acpi_handle handle,
 
 		result = acpi_processor_device_add(handle, &device);
 		if (result) {
-			pr_err(PREFIX "Unable to add the device\n");
+			acpi_pr_err(handle, "Unable to add the device\n");
 			break;
 		}
 
@@ -732,17 +736,19 @@ static void acpi_processor_hotplug_notify(acpi_handle handle,
 				  "received ACPI_NOTIFY_EJECT_REQUEST\n"));
 
 		if (acpi_bus_get_device(handle, &device)) {
-			pr_err(PREFIX "Device don't exist, dropping EJECT\n");
+			acpi_pr_err(handle,
+				"Device don't exist, dropping EJECT\n");
 			break;
 		}
 		if (!acpi_driver_data(device)) {
-			pr_err(PREFIX "Driver data is NULL, dropping EJECT\n");
+			acpi_pr_err(handle,
+				"Driver data is NULL, dropping EJECT\n");
 			break;
 		}
 
 		ej_event = kmalloc(sizeof(*ej_event), GFP_KERNEL);
 		if (!ej_event) {
-			pr_err(PREFIX "No memory, dropping EJECT\n");
+			acpi_pr_err(handle, "No memory, dropping EJECT\n");
 			break;
 		}
 
@@ -852,7 +858,7 @@ static acpi_status acpi_processor_hotadd_init(struct acpi_processor *pr)
 	 * and do it when the CPU gets online the first time
 	 * TBD: Cleanup above functions and try to do this more elegant.
 	 */
-	printk(KERN_INFO "CPU %d got hotplugged\n", pr->id);
+	pr_info("CPU %d got hotplugged\n", pr->id);
 	pr->flags.need_hotplug_init = 1;
 
 	return AE_OK;
-- 
1.7.7.6

[PATCH 3/4] ACPI: Update Memory hotplug messages

[Toshi Kani]

Updated Memory hotplug log messages with acpi_pr_<level>()
and pr_<level>().

Signed-off-by: Toshi Kani <toshi.kani@hp.com>
---
 drivers/acpi/acpi_memhotplug.c |   24 ++++++++++++------------
 1 files changed, 12 insertions(+), 12 deletions(-)

diff --git a/drivers/acpi/acpi_memhotplug.c b/drivers/acpi/acpi_memhotplug.c
index 06c55cd..dcc8f4d 100644
--- a/drivers/acpi/acpi_memhotplug.c
+++ b/drivers/acpi/acpi_memhotplug.c
@@ -170,7 +170,7 @@ acpi_memory_get_device(acpi_handle handle,
 	/* Get the parent device */
 	result = acpi_bus_get_device(phandle, &pdevice);
 	if (result) {
-		printk(KERN_WARNING PREFIX "Cannot get acpi bus device");
+		acpi_pr_warn(phandle, "Cannot get acpi bus device\n");
 		return -EINVAL;
 	}
 
@@ -180,14 +180,14 @@ acpi_memory_get_device(acpi_handle handle,
 	 */
 	result = acpi_bus_add(&device, pdevice, handle, ACPI_BUS_TYPE_DEVICE);
 	if (result) {
-		printk(KERN_WARNING PREFIX "Cannot add acpi bus");
+		acpi_pr_warn(handle, "Cannot add acpi bus\n");
 		return -EINVAL;
 	}
 
       end:
 	*mem_device = acpi_driver_data(device);
 	if (!(*mem_device)) {
-		printk(KERN_ERR "\n driver data not found");
+		acpi_pr_err(handle, "driver data not found\n");
 		return -ENODEV;
 	}
 
@@ -224,7 +224,7 @@ static int acpi_memory_enable_device(struct acpi_memory_device *mem_device)
 	/* Get the range from the _CRS */
 	result = acpi_memory_get_device_resources(mem_device);
 	if (result) {
-		printk(KERN_ERR PREFIX "get_device_resources failed\n");
+		pr_err(PREFIX "get_device_resources failed\n");
 		mem_device->state = MEMORY_INVALID_STATE;
 		return result;
 	}
@@ -257,7 +257,7 @@ static int acpi_memory_enable_device(struct acpi_memory_device *mem_device)
 		num_enabled++;
 	}
 	if (!num_enabled) {
-		printk(KERN_ERR PREFIX "add_memory failed\n");
+		acpi_pr_err(mem_device->device->handle, "add_memory failed\n");
 		mem_device->state = MEMORY_INVALID_STATE;
 		return -EINVAL;
 	}
@@ -353,7 +353,7 @@ static void acpi_memory_device_notify(acpi_handle handle, u32 event, void *data)
 			ACPI_DEBUG_PRINT((ACPI_DB_INFO,
 					  "\nReceived DEVICE CHECK notification for device\n"));
 		if (acpi_memory_get_device(handle, &mem_device)) {
-			printk(KERN_ERR PREFIX "Cannot find driver data\n");
+			acpi_pr_err(handle, "Cannot find driver data\n");
 			break;
 		}
 
@@ -361,7 +361,7 @@ static void acpi_memory_device_notify(acpi_handle handle, u32 event, void *data)
 			break;
 
 		if (acpi_memory_enable_device(mem_device)) {
-			pr_err(PREFIX "Cannot enable memory device\n");
+			acpi_pr_err(handle, "Cannot enable memory device\n");
 			break;
 		}
 
@@ -373,12 +373,12 @@ static void acpi_memory_device_notify(acpi_handle handle, u32 event, void *data)
 				  "\nReceived EJECT REQUEST notification for device\n"));
 
 		if (acpi_bus_get_device(handle, &device)) {
-			printk(KERN_ERR PREFIX "Device doesn't exist\n");
+			acpi_pr_err(handle, "Device doesn't exist\n");
 			break;
 		}
 		mem_device = acpi_driver_data(device);
 		if (!mem_device) {
-			printk(KERN_ERR PREFIX "Driver Data is NULL\n");
+			acpi_pr_err(handle, "Driver Data is NULL\n");
 			break;
 		}
 
@@ -389,7 +389,7 @@ static void acpi_memory_device_notify(acpi_handle handle, u32 event, void *data)
 		 *      with generic sysfs driver
 		 */
 		if (acpi_memory_disable_device(mem_device)) {
-			pr_err(PREFIX "Disable memory device\n");
+			acpi_pr_err(handle, "Disable memory device\n");
 			/*
 			 * If _EJ0 was called but failed, _OST is not
 			 * necessary.
@@ -449,7 +449,7 @@ static int acpi_memory_device_add(struct acpi_device *device)
 	/* Set the device state */
 	mem_device->state = MEMORY_POWER_ON_STATE;
 
-	printk(KERN_DEBUG "%s \n", acpi_device_name(device));
+	pr_debug("%s\n", acpi_device_name(device));
 
 	/*
 	 * Early boot code has recognized memory area by EFI/E820.
@@ -464,7 +464,7 @@ static int acpi_memory_device_add(struct acpi_device *device)
 		/* call add_memory func */
 		result = acpi_memory_enable_device(mem_device);
 		if (result)
-			printk(KERN_ERR PREFIX
+			acpi_pr_err(device->handle,
 				"Error in acpi_memory_enable_device\n");
 	}
 	return result;
-- 
1.7.7.6

[PATCH 4/4] ACPI: Update Container hotplug messages

[Toshi Kani]

Updated Container hotplug log messages with acpi_pr_<level>()
and pr_<level>().

Signed-off-by: Toshi Kani <toshi.kani@hp.com>
---
 drivers/acpi/container.c |    6 +++---
 1 files changed, 3 insertions(+), 3 deletions(-)

diff --git a/drivers/acpi/container.c b/drivers/acpi/container.c
index 01a986d..6672386 100644
--- a/drivers/acpi/container.c
+++ b/drivers/acpi/container.c
@@ -99,7 +99,7 @@ static int acpi_container_add(struct acpi_device *device)
 
 
 	if (!device) {
-		printk(KERN_ERR PREFIX "device is NULL\n");
+		pr_err(PREFIX "device is NULL\n");
 		return -EINVAL;
 	}
 
@@ -164,7 +164,7 @@ static void container_notify_cb(acpi_handle handle, u32 type, void *context)
 	case ACPI_NOTIFY_BUS_CHECK:
 		/* Fall through */
 	case ACPI_NOTIFY_DEVICE_CHECK:
-		printk(KERN_WARNING "Container driver received %s event\n",
+		acpi_pr_warn(handle, "Container driver received %s event\n",
 		       (type == ACPI_NOTIFY_BUS_CHECK) ?
 		       "ACPI_NOTIFY_BUS_CHECK" : "ACPI_NOTIFY_DEVICE_CHECK");
 
@@ -185,7 +185,7 @@ static void container_notify_cb(acpi_handle handle, u32 type, void *context)
 
 		result = container_device_add(&device, handle);
 		if (result) {
-			pr_warn("Failed to add container\n");
+			acpi_pr_warn(handle, "Failed to add container\n");
 			break;
 		}
 
-- 
1.7.7.6

Re: [PATCH 0/4] ACPI: hotplug messages improvement

[Yasuaki Ishimatsu]

Hi Toshi,

2012/07/19 5:40, Toshi Kani wrote:
> This patchset improves logging messages for ACPI CPU, Memory, and
> Container hotplug notify handlers.  The patchset introduces a set of
> new macro interfaces, acpi_pr_<level>(), and updates the notify
> handlers to use them.  acpi_pr_<level>() appends "ACPI" prefix and
> ACPI object path to the messages.  This improves diagnostics in
> hotplug operations since it identifies an object that caused an
> issue in a log file.
>

The log message looks good to me.
But I could not understand when to use it instead of pr_{warn, info, ...}
or ACPI_{WARNING, INFO, ...}. Do you have the policy?

> ---
> This patchset applies on top of the patch below.
> 
> [PATCH] ACPI: Add ACPI CPU hot-remove support
> http://marc.info/?l=linux-acpi&m=134098193327362&w=2
> 
> ---
> Toshi Kani (4):
>   ACPI: Add acpi_pr_<level>() interfaces
>   ACPI: Update CPU hotplug messages
>   ACPI: Update Memory hotplug messages
>   ACPI: Update Container hotplug messages

I think you need update other component, which are driver/acpi/{acpi_pad.c,
battery.c, button.c}. Do you have the plan to update them?

Thanks,
Yasuaki Ishimatsu

> ---
>   drivers/acpi/acpi_memhotplug.c  |   24 ++++++++++++------------
>   drivers/acpi/container.c        |    6 +++---
>   drivers/acpi/processor_driver.c |   36 +++++++++++++++++++++---------------
>   drivers/acpi/utils.c            |   32 ++++++++++++++++++++++++++++++++
>   include/acpi/acpi_bus.h         |   18 ++++++++++++++++++
>   5 files changed, 86 insertions(+), 30 deletions(-)
> 

Re: [PATCH 0/4] ACPI: hotplug messages improvement

[Yasuaki Ishimatsu]

Hi Toshi,

2012/07/19 5:40, Toshi Kani wrote:
> This patchset improves logging messages for ACPI CPU, Memory, and
> Container hotplug notify handlers.  The patchset introduces a set of
> new macro interfaces, acpi_pr_<level>(), and updates the notify
> handlers to use them.  acpi_pr_<level>() appends "ACPI" prefix and
> ACPI object path to the messages.  This improves diagnostics in
> hotplug operations since it identifies an object that caused an
> issue in a log file.
>

The log message looks good to me.
But I could not understand when to use it instead of pr_{warn, info, ...}
or ACPI_{WARNING, INFO, ...}. Do you have the policy?

> ---
> This patchset applies on top of the patch below.
> 
> [PATCH] ACPI: Add ACPI CPU hot-remove support
> http://marc.info/?l=linux-acpi&m=134098193327362&w=2
> 
> ---
> Toshi Kani (4):
>   ACPI: Add acpi_pr_<level>() interfaces
>   ACPI: Update CPU hotplug messages
>   ACPI: Update Memory hotplug messages
>   ACPI: Update Container hotplug messages

I think you need update other component, which are driver/acpi/{acpi_pad.c,
battery.c, button.c}. Do you have the plan to update them?

Thanks,
Yasuaki Ishimatsu

> ---
>   drivers/acpi/acpi_memhotplug.c  |   24 ++++++++++++------------
>   drivers/acpi/container.c        |    6 +++---
>   drivers/acpi/processor_driver.c |   36 +++++++++++++++++++++---------------
>   drivers/acpi/utils.c            |   32 ++++++++++++++++++++++++++++++++
>   include/acpi/acpi_bus.h         |   18 ++++++++++++++++++
>   5 files changed, 86 insertions(+), 30 deletions(-)
> 

Re: [PATCH 0/4] ACPI: hotplug messages improvement

[Toshi Kani]

On Wed, 2012-07-25 at 12:45 +0900, Yasuaki Ishimatsu wrote:
> Hi Toshi,
> 
> 2012/07/19 5:40, Toshi Kani wrote:
> > This patchset improves logging messages for ACPI CPU, Memory, and
> > Container hotplug notify handlers.  The patchset introduces a set of
> > new macro interfaces, acpi_pr_<level>(), and updates the notify
> > handlers to use them.  acpi_pr_<level>() appends "ACPI" prefix and
> > ACPI object path to the messages.  This improves diagnostics in
> > hotplug operations since it identifies an object that caused an
> > issue in a log file.
> >
> 
> The log message looks good to me.

Hi Yasuaki,

Thanks for reviewing!

> But I could not understand when to use it instead of pr_{warn, info, ...}
> or ACPI_{WARNING, INFO, ...}. Do you have the policy?

acpi_pr_<level>() is used when ACPI device path is used to identify an
ACPI object for the message, such as error message to the object.  The
usage model is similar to dev_<level>(), which appends device object to
the message.  acpi_pr_<level>() is intended for ACPI drivers, and can be
used when device object is not created / valid, such as the case for
ACPI hotplug handlers.

pr_<level>() is the regular printk() interfaces with message level, and
continues to be used when ACPI device path does not have to be appended
to the message.  I expect non-error messages (such as boot-up messages)
continue to use pr_<level>().

ACPI_[WARNING|INFO|ERROR]() are ACPICA internal interfaces, and are not
intended for ACPI drivers.

Additionally, ACPI drivers can also use dev_<level>() when device object
is valid.  You find such examples in patch 2/4.

I will add more descriptions to the patchset.


> > ---
> > This patchset applies on top of the patch below.
> > 
> > [PATCH] ACPI: Add ACPI CPU hot-remove support
> > http://marc.info/?l=linux-acpi&m=134098193327362&w=2
> > 
> > ---
> > Toshi Kani (4):
> >   ACPI: Add acpi_pr_<level>() interfaces
> >   ACPI: Update CPU hotplug messages
> >   ACPI: Update Memory hotplug messages
> >   ACPI: Update Container hotplug messages
> 
> I think you need update other component, which are driver/acpi/{acpi_pad.c,
> battery.c, button.c}. Do you have the plan to update them?

I won't be ready to include them in this round, but will look at them
and change them later as necessary.  I need to make sure that I can test
these drivers when making such changes.

Thanks,
-Toshi


> 
> Thanks,
> Yasuaki Ishimatsu
> 
> > ---
> >   drivers/acpi/acpi_memhotplug.c  |   24 ++++++++++++------------
> >   drivers/acpi/container.c        |    6 +++---
> >   drivers/acpi/processor_driver.c |   36 +++++++++++++++++++++---------------
> >   drivers/acpi/utils.c            |   32 ++++++++++++++++++++++++++++++++
> >   include/acpi/acpi_bus.h         |   18 ++++++++++++++++++
> >   5 files changed, 86 insertions(+), 30 deletions(-)
> > 
> 
>