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@xxxxxxxxxxxxxxx
> More majordomo info at  http://vger.kernel.org/majordomo-info.html


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