Hi,
we only make use of a small subset of current ACPI tables.
ACPI spreads more and more over different parts of the kernel and it's
likely that this will hold on.
ACPI_DEBUG=y is a powerful debug facility, that can ease up bug
communication with less (ACPI) experienced bug submitters and can shed
some light behind ACPI magic.
I've done some measurements and found out that most of the performance
costs are due the function tracing support in the ACPICA debug
subsystem.
This patch offers the possibility to compile out ACPI function tracing
support which is of none use for ordinary kernel debugging (is only used
for Intel internal debugging AFAIK), but takes most of the performance
costs.
(This should efficiently be the same as the proposed big patch a year
ago from Pekka Enberg, just a bit smaller and should make ACPICA and
kernel/linux people happy:
http://marc.info/?l=linux-kernel&m=113699535303722&w=2
)
Kernel image size (compiled on x86_64):
Full acpi debug:
1618277 bytes (+3.1%, +48k)
acpi debug function trace compiled out:
1605359 bytes (+2.3%, +35k)
acpi debug not compiled in at all
1569803 bytes (100%)
Speed measures on one specific machine (x86_64, laptop):
A) ACPI_DEBUG compiled in
B) ACPI_DEBUG compiled in, but Function trace compiled out
C) ACPI_DEBUG compiled out
D) ACPI_DEBUG compiled out (control run)
The time has been taken at following functions:
1) drivers/acpi/bus.c:acpi_early_init (load tables and initialize
ACPI namespace)
2) drivers/acpi/bus.c:acpi_init (some more initialisation
-> enable ACPI HW mode
-> read PIC/APIC table, ...)
3) drivers/acpi/scan.c:scan_init (Enumerate devices in the
ACPI namespace)
register driver for acpi drivers:
4) ec
5) pci_root
6) pci_link
-----------------------------------------------------------------------
| A | B | C | D |
-----------------------------------------------------------------------
1 | 434711 (+1.0%) | 432652 (+0.4%) | 430522 (100%) | 430512 (-0.00%)
-----------------------------------------------------------------------
2 | 69156 (+3.7%) | 67007 (+0.4%) | 66696 (100%) | 66703 (+0.01%)
-----------------------------------------------------------------------
3 | 8769(+63.3%) | 7363(+37.1%) | 5369 (100%) | 5369 ( 0.00%)
-----------------------------------------------------------------------
4 | 15999 (+0.7%) | 15950 (+0.4%) | 15879 (100%) | 15878 (-0.01%)
-----------------------------------------------------------------------
5 | 9492(+75.4%) | 7657(+41.5%) | 5411 (100%) | 5405 (-0.11%)
-----------------------------------------------------------------------
6 | 1717(+64.0%) | 1494(+42.6%) | 1047 (100%) | 1046 (-0.10%)
-----------------------------------------------------------------------
All measured values are in us. TSC was used to obtain the values.
do_gettimeofday did only provide valid values after hpet got setup
(after pci_link).
I wonder why only the short time taking measures show that extreme
performance loss, maybe someone has an idea. However if you summarize
all additional time with ACPI_DEBUG without function trace, you get
about +5 ms boot time (which may vary from machine to machine...).
This should be acceptable for test and develop kernels.
If nothing bad happens in Beta phase I'd like to include this one into
the final OpenSUSE kernel to get detailed bug reports.
It would be great if others with their latest test/devel kernels follow,
so that even ordinary users can easily provide essential, detailed debug
information easily(e.g. Linus' Compaq and Andrew's Vaio are well known
on the acpi list, others do not have the luck to get that much of
support and they do not have the knowledge to compile kernel and so
on...).
I can also add a file "Documentation/acpi_debug" and add some debug
hints if this one gets accepted...
This one should not be really dangerous. If the patch is ok, can Len
still merge this in .22 time?
If not, can you take it for some testing, Andrew?
Thanks,
Thomas
Split ACPI_DEBUG into function trace enabled and not enabled.
Function trace is most of the ACPI_DEBUG costs, but is
not much of use for kernel ACPI debugging.
Size of kernel image increased on test compile:
+ 48k (Full ACPI_DEBUG)
+ 35k (ACPI_DEBUG with function trace compiled out)
Performance without function trace is also much better.
Also remove ACPI_LV_DEBUG_OBJECT from default debug level as
a lot vendors let Store (value, debug) in their code and this
might confuse users when it pops up in syslog.
---
drivers/acpi/Kconfig | 8 ++++++++
include/acpi/acmacros.h | 23 +++++++++++++++++++++++
include/acpi/acoutput.h | 4 ++--
3 files changed, 33 insertions(+), 2 deletions(-)
Index: linux-2.6.22-rc3/drivers/acpi/Kconfig
===================================================================
--- linux-2.6.22-rc3.orig/drivers/acpi/Kconfig
+++ linux-2.6.22-rc3/drivers/acpi/Kconfig
@@ -280,6 +280,14 @@ config ACPI_DEBUG
of verbosity. Saying Y enables these statements. This will increase
your kernel size by around 50K.
+config ACPI_DEBUG_FUNC_TRACE
+ bool "Additionally enable ACPI function tracing"
+ default n
+ depends on ACPI_DEBUG
+ help
+ ACPI Debug Statements slow down ACPI processing. Function trace
+ is about half of the penalty and is rarely useful.
+
config ACPI_EC
bool
default y
Index: linux-2.6.22-rc3/include/acpi/acmacros.h
===================================================================
--- linux-2.6.22-rc3.orig/include/acpi/acmacros.h
+++ linux-2.6.22-rc3/include/acpi/acmacros.h
@@ -486,6 +486,8 @@
#define ACPI_FUNCTION_NAME(name)
#endif
+#ifdef DEBUG_FUNC_TRACE
+
#define ACPI_FUNCTION_TRACE(a) ACPI_FUNCTION_NAME(a) \
acpi_ut_trace(ACPI_DEBUG_PARAMETERS)
#define ACPI_FUNCTION_TRACE_PTR(a,b) ACPI_FUNCTION_NAME(a) \
@@ -563,6 +565,27 @@
#endif /* ACPI_SIMPLE_RETURN_MACROS */
+#else /* !DEBUG_FUNC_TRACE */
+
+#define ACPI_FUNCTION_TRACE(a)
+#define ACPI_FUNCTION_TRACE_PTR(a,b)
+#define ACPI_FUNCTION_TRACE_U32(a,b)
+#define ACPI_FUNCTION_TRACE_STR(a,b)
+#define ACPI_FUNCTION_EXIT
+#define ACPI_FUNCTION_STATUS_EXIT(s)
+#define ACPI_FUNCTION_VALUE_EXIT(s)
+#define ACPI_FUNCTION_TRACE(a)
+#define ACPI_FUNCTION_ENTRY()
+
+#define return_VOID return
+#define return_ACPI_STATUS(s) return(s)
+#define return_VALUE(s) return(s)
+#define return_UINT8(s) return(s)
+#define return_UINT32(s) return(s)
+#define return_PTR(s) return(s)
+
+#endif /* DEBUG_FUNC_TRACE */
+
/* Conditional execution */
#define ACPI_DEBUG_EXEC(a) a
Index: linux-2.6.22-rc3/include/acpi/acoutput.h
===================================================================
--- linux-2.6.22-rc3.orig/include/acpi/acoutput.h
+++ linux-2.6.22-rc3/include/acpi/acoutput.h
@@ -178,8 +178,8 @@
/* Defaults for debug_level, debug and normal */
-#define ACPI_DEBUG_DEFAULT (ACPI_LV_INIT | ACPI_LV_WARN | ACPI_LV_ERROR | ACPI_LV_DEBUG_OBJECT)
-#define ACPI_NORMAL_DEFAULT (ACPI_LV_INIT | ACPI_LV_WARN | ACPI_LV_ERROR | ACPI_LV_DEBUG_OBJECT)
+#define ACPI_DEBUG_DEFAULT (ACPI_LV_INIT | ACPI_LV_WARN | ACPI_LV_ERROR)
+#define ACPI_NORMAL_DEFAULT (ACPI_LV_INIT | ACPI_LV_WARN | ACPI_LV_ERROR)
#define ACPI_DEBUG_ALL (ACPI_LV_AML_DISASSEMBLE | ACPI_LV_ALL_EXCEPTIONS | ACPI_LV_ALL)
#endif /* __ACOUTPUT_H__ */
The name of this patch is really "split ACPI function tracing
out of CONFIG_ACPI_DEBUG to a new Kconfig build option"
I agree that tracing should be its own build option.
I don't agree that enabling CONFIG_ACPI_DEBUG by default
is what you want to do in a production kernel, but that
isn't what this patch does, and I'm not going to stand
in your way if you want to ship debug kernels by default.
> we only make use of a small subset of current ACPI tables.
> ACPI spreads more and more over different parts of the kernel and it's
> likely that this will hold on.
There are two types of "ACPI tables", those with contents defined by
the ACPI spec, and those where ACPI is just acting as the "envelope"
to deliver a table from another spec to the OS.
We already use all the tables defined by the ACPI spec.
It is unlikely that this patch will have any effect on the "envelope" tables.
So I don't think you're going to see growing utility of CONFIG_ACPI_DEBUG
over time, you're going to see what it does immediately.
> ACPI_DEBUG=y is a powerful debug facility, that can ease up bug
> communication with less (ACPI) experienced bug submitters and can shed
> some light behind ACPI magic.
>
> I've done some measurements and found out that most of the performance
> costs are due the function tracing support in the ACPICA debug
> subsystem.
>
> This patch offers the possibility to compile out ACPI function tracing
> support which is of none use for ordinary kernel debugging (is only used
> for Intel internal debugging AFAIK), but takes most of the performance
> costs.
I agree that function tracing is never used by people who can't build a kernel --
and so it is fine to make it an additional build option.
> (This should efficiently be the same as the proposed big patch a year
> ago from Pekka Enberg, just a bit smaller and should make ACPICA and
> kernel/linux people happy:
> http://marc.info/?l=linux-kernel&m=113699535303722&w=2
> )
>
>
> Kernel image size (compiled on x86_64):
> Full acpi debug:
> 1618277 bytes (+3.1%, +48k)
> acpi debug function trace compiled out:
> 1605359 bytes (+2.3%, +35k)
> acpi debug not compiled in at all
> 1569803 bytes (100%)
>
>
> Speed measures on one specific machine (x86_64, laptop):
>
> A) ACPI_DEBUG compiled in
> B) ACPI_DEBUG compiled in, but Function trace compiled out
> C) ACPI_DEBUG compiled out
> D) ACPI_DEBUG compiled out (control run)
>
> The time has been taken at following functions:
>
> 1) drivers/acpi/bus.c:acpi_early_init (load tables and initialize
> ACPI namespace)
> 2) drivers/acpi/bus.c:acpi_init (some more initialisation
> -> enable ACPI HW mode
> -> read PIC/APIC table, ...)
> 3) drivers/acpi/scan.c:scan_init (Enumerate devices in the
> ACPI namespace)
>
> register driver for acpi drivers:
> 4) ec
> 5) pci_root
> 6) pci_link
>
> -----------------------------------------------------------------------
> | A | B | C | D |
> -----------------------------------------------------------------------
> 1 | 434711 (+1.0%) | 432652 (+0.4%) | 430522 (100%) | 430512 (-0.00%)
> -----------------------------------------------------------------------
> 2 | 69156 (+3.7%) | 67007 (+0.4%) | 66696 (100%) | 66703 (+0.01%)
> -----------------------------------------------------------------------
> 3 | 8769(+63.3%) | 7363(+37.1%) | 5369 (100%) | 5369 ( 0.00%)
> -----------------------------------------------------------------------
37% sounds like a lot.
The ACPI interpreter is not supposed to be in performace critical sections,
but at the same time, it isn't supposed to be a pig either.
> 4 | 15999 (+0.7%) | 15950 (+0.4%) | 15879 (100%) | 15878 (-0.01%)
> -----------------------------------------------------------------------
> 5 | 9492(+75.4%) | 7657(+41.5%) | 5411 (100%) | 5405 (-0.11%)
> -----------------------------------------------------------------------
> 6 | 1717(+64.0%) | 1494(+42.6%) | 1047 (100%) | 1046 (-0.10%)
> -----------------------------------------------------------------------
> All measured values are in us. TSC was used to obtain the values.
> do_gettimeofday did only provide valid values after hpet got setup
> (after pci_link).
>
> I wonder why only the short time taking measures show that extreme
> performance loss, maybe someone has an idea. However if you summarize
> all additional time with ACPI_DEBUG without function trace, you get
> about +5 ms boot time (which may vary from machine to machine...).
> This should be acceptable for test and develop kernels.
> If nothing bad happens in Beta phase I'd like to include this one into
> the final OpenSUSE kernel to get detailed bug reports.
> It would be great if others with their latest test/devel kernels follow,
> so that even ordinary users can easily provide essential, detailed debug
> information easily(e.g. Linus' Compaq and Andrew's Vaio are well known
> on the acpi list, others do not have the luck to get that much of
> support and they do not have the knowledge to compile kernel and so
> on...).
>
> I can also add a file "Documentation/acpi_debug" and add some debug
> hints if this one gets accepted...
>
> This one should not be really dangerous. If the patch is ok, can Len
> still merge this in .22 time?
.22 after -rc3? No. I don't see a problem with a final version
shipping in .23, however.
> If not, can you take it for some testing, Andrew?
It would be better for andrew to get it through acpi-test.
I'll be happy to include an updated version of this patch there.
Note that the testing that it is going to get will be small:
1. people who don't enable CONFIG_ACPI_DEBUG
no change
2. people who enable CONFIG_ACPI_DEBUG
will lose function tracing if they don't ask for it
will lose AML Debug-object messages unless they
set the flag to get them back.
> Thanks,
>
> Thomas
>
>
>
> Split ACPI_DEBUG into function trace enabled and not enabled.
>
> Function trace is most of the ACPI_DEBUG costs, but is
> not much of use for kernel ACPI debugging.
>
> Size of kernel image increased on test compile:
> + 48k (Full ACPI_DEBUG)
> + 35k (ACPI_DEBUG with function trace compiled out)
>
> Performance without function trace is also much better.
>
> Also remove ACPI_LV_DEBUG_OBJECT from default debug level as
> a lot vendors let Store (value, debug) in their code and this
> might confuse users when it pops up in syslog.
This, is an incompatible change, as one of the benefits of
CONFIG_ACPI_DEBUG is to get the AML debug-object messages.
After this patch, those will silently go away.
The patch needs to document the boot-time flag to make
those messages come back.
> ---
> drivers/acpi/Kconfig | 8 ++++++++
> include/acpi/acmacros.h | 23 +++++++++++++++++++++++
> include/acpi/acoutput.h | 4 ++--
> 3 files changed, 33 insertions(+), 2 deletions(-)
>
> Index: linux-2.6.22-rc3/drivers/acpi/Kconfig
> ===================================================================
> --- linux-2.6.22-rc3.orig/drivers/acpi/Kconfig
> +++ linux-2.6.22-rc3/drivers/acpi/Kconfig
> @@ -280,6 +280,14 @@ config ACPI_DEBUG
> of verbosity. Saying Y enables these statements. This will increase
> your kernel size by around 50K.
>
> +config ACPI_DEBUG_FUNC_TRACE
> + bool "Additionally enable ACPI function tracing"
> + default n
> + depends on ACPI_DEBUG
> + help
> + ACPI Debug Statements slow down ACPI processing. Function trace
> + is about half of the penalty and is rarely useful.
help text needs update -- it should say what tracing does,
not if SuSE customers frequently use it or not...
> config ACPI_EC
> bool
> default y
> Index: linux-2.6.22-rc3/include/acpi/acmacros.h
> ===================================================================
> --- linux-2.6.22-rc3.orig/include/acpi/acmacros.h
> +++ linux-2.6.22-rc3/include/acpi/acmacros.h
> @@ -486,6 +486,8 @@
> #define ACPI_FUNCTION_NAME(name)
> #endif
>
> +#ifdef DEBUG_FUNC_TRACE
> +
> #define ACPI_FUNCTION_TRACE(a) ACPI_FUNCTION_NAME(a) \
> acpi_ut_trace(ACPI_DEBUG_PARAMETERS)
> #define ACPI_FUNCTION_TRACE_PTR(a,b) ACPI_FUNCTION_NAME(a) \
> @@ -563,6 +565,27 @@
>
> #endif /* ACPI_SIMPLE_RETURN_MACROS */
>
> +#else /* !DEBUG_FUNC_TRACE */
> +
> +#define ACPI_FUNCTION_TRACE(a)
> +#define ACPI_FUNCTION_TRACE_PTR(a,b)
> +#define ACPI_FUNCTION_TRACE_U32(a,b)
> +#define ACPI_FUNCTION_TRACE_STR(a,b)
> +#define ACPI_FUNCTION_EXIT
> +#define ACPI_FUNCTION_STATUS_EXIT(s)
> +#define ACPI_FUNCTION_VALUE_EXIT(s)
> +#define ACPI_FUNCTION_TRACE(a)
> +#define ACPI_FUNCTION_ENTRY()
> +
> +#define return_VOID return
> +#define return_ACPI_STATUS(s) return(s)
> +#define return_VALUE(s) return(s)
> +#define return_UINT8(s) return(s)
> +#define return_UINT32(s) return(s)
> +#define return_PTR(s) return(s)
> +
> +#endif /* DEBUG_FUNC_TRACE */
These non-defines already appear later in the file.
Perhaps you can use an expression to make them appear just once instead of twice?
> /* Conditional execution */
>
> #define ACPI_DEBUG_EXEC(a) a
> Index: linux-2.6.22-rc3/include/acpi/acoutput.h
> ===================================================================
> --- linux-2.6.22-rc3.orig/include/acpi/acoutput.h
> +++ linux-2.6.22-rc3/include/acpi/acoutput.h
> @@ -178,8 +178,8 @@
>
> /* Defaults for debug_level, debug and normal */
>
> -#define ACPI_DEBUG_DEFAULT (ACPI_LV_INIT | ACPI_LV_WARN | ACPI_LV_ERROR | ACPI_LV_DEBUG_OBJECT)
> -#define ACPI_NORMAL_DEFAULT (ACPI_LV_INIT | ACPI_LV_WARN | ACPI_LV_ERROR | ACPI_LV_DEBUG_OBJECT)
> +#define ACPI_DEBUG_DEFAULT (ACPI_LV_INIT | ACPI_LV_WARN | ACPI_LV_ERROR)
> +#define ACPI_NORMAL_DEFAULT (ACPI_LV_INIT | ACPI_LV_WARN | ACPI_LV_ERROR)
> #define ACPI_DEBUG_ALL (ACPI_LV_AML_DISASSEMBLE | ACPI_LV_ALL_EXCEPTIONS | ACPI_LV_ALL)
>
> #endif /* __ACOUTPUT_H__ */
>
>
On 5/31/07, Thomas Renninger <[email protected]> wrote:
> (This should efficiently be the same as the proposed big patch a year
> ago from Pekka Enberg, just a bit smaller and should make ACPICA and
> kernel/linux people happy:
> http://marc.info/?l=linux-kernel&m=113699535303722&w=2)
No, you're keeping these obfuscating macros around:
+#define return_VOID return
+#define return_ACPI_STATUS(s) return(s)
+#define return_VALUE(s) return(s)
+#define return_UINT8(s) return(s)
Making the ACPI code look like regular Linux kernel code (or even
regular C for that matter) was the whole point of my patch. Your patch
doesn't change that.
On Thursday 31 May 2007 14:57, Pekka Enberg wrote:
> On 5/31/07, Thomas Renninger <[email protected]> wrote:
> > (This should efficiently be the same as the proposed big patch a year
> > ago from Pekka Enberg, just a bit smaller and should make ACPICA and
> > kernel/linux people happy:
> > http://marc.info/?l=linux-kernel&m=113699535303722&w=2)
>
> No, you're keeping these obfuscating macros around:
>
> +#define return_VOID return
> +#define return_ACPI_STATUS(s) return(s)
> +#define return_VALUE(s) return(s)
> +#define return_UINT8(s) return(s)
>
> Making the ACPI code look like regular Linux kernel code (or even
> regular C for that matter) was the whole point of my patch. Your patch
> doesn't change that.
I think that Thomas's point is that he is optimally removing
function tracing via #ifdef.
Your 600KB patch, on the other hand, permanently removed the feature
and touched every file in ACPICA.
The net effect to the user is the same, the ability to enable
ACPI_DEBUG and not enable ACPICA function tracing.
As I probably wrote a year ago, it isn't viable to completely
remove the tracing code --
until Linux reaches a point where vendors certify that their
BIOS is compatible with Linux before they ship, rather than the Linux
community having to debug some Windows-compatible systems into
Linux-compatibility well after they have shipped into the field.
-Len
On Thu, 2007-05-31 at 12:49 -0400, Len Brown wrote:
> The name of this patch is really "split ACPI function tracing
> out of CONFIG_ACPI_DEBUG to a new Kconfig build option"
>
> I agree that tracing should be its own build option.
Thanks.
> I don't agree that enabling CONFIG_ACPI_DEBUG by default
> is what you want to do in a production kernel, but that
> isn't what this patch does, and I'm not going to stand
> in your way if you want to ship debug kernels by default.
I don't see significant negative impact.
I consider it much worse that on several HP models fan control is messed
up (to at least kernel .21, after suspend fan is gone for sure, possibly
already before), there are also fan breakage reports for FSCs.
These are only the worst, really sever kind of bugs...
I hope that bugs like e.g.:
http://bugzilla.kernel.org/show_bug.cgi?id=7122
99 comments, already takes over half a year (still no working fan?)
http://bugzilla.kernel.org/show_bug.cgi?id=5534
211 comments, opened in Nov, final patches submitted in Feb 2007 - (ok
that was a tricky one with several patch approaches, still...)
end up with less question-answer posts and can be processed/solved much
faster.
Second point is to get more people on the boot, starting to work on
ACPI. People can identify bugs (kernel or BIOS misbehavior) by simply
understanding a bit ASL and by examining the debug output, no deep
kernel knowledge is really needed (unfortunately some people with deep
kernel knowledge don't want to touch ACPI parts at all, maybe some of
these guys then see that the interpreter itself isn't working that
bad...).
If we get bug reports like: My battery is not working, and I found out
that in line 42 of my DSDT a ACPI func returns a real strange value,
that's much more worth than 5, 10 or (IMO) even 100 ms of boot time.
> > we only make use of a small subset of current ACPI tables.
> > ACPI spreads more and more over different parts of the kernel and it's
> > likely that this will hold on.
>
> There are two types of "ACPI tables", those with contents defined by
> the ACPI spec, and those where ACPI is just acting as the "envelope"
> to deliver a table from another spec to the OS.
>
> We already use all the tables defined by the ACPI spec.
> It is unlikely that this patch will have any effect on the "envelope" tables.
I mean the ASL tables DSDT and SSDTs (not the enveloped, static once).
Vendor (or laptop model/series) specific ACPI devices are flying around.
Fortunately we got some support by the merged asus, thinkpad, toshiba
and sony ACPI drivers. But there is still a lot to improve and new
models come out every week... A big challenge could also be the move
from the proprietary ACPI to the video ACPI spec funcs...
Some define extra fan/temp control (these breaking with hwmon tools and
legacy i2c/smbus drivers) ACPI functions which we do not use. There are
WMI ACPI funcs and so on.
It's just a very rough guess, but I expect we make use of about 30-70
percent of the ACPI (AML) code provided by the BIOS (hard to guess which
are used or unused helper functions..). It's appreciated that Intel
helps to implement the spec stuff, but for full support more work and
more people working on it are needed...
> So I don't think you're going to see growing utility of CONFIG_ACPI_DEBUG
> over time, you're going to see what it does immediately.
> > ACPI_DEBUG=y is a powerful debug facility, that can ease up bug
> > communication with less (ACPI) experienced bug submitters and can shed
> > some light behind ACPI magic.
> >
> > I've done some measurements and found out that most of the performance
> > costs are due the function tracing support in the ACPICA debug
> > subsystem.
> >
> > This patch offers the possibility to compile out ACPI function tracing
> > support which is of none use for ordinary kernel debugging (is only used
> > for Intel internal debugging AFAIK), but takes most of the performance
> > costs.
>
> I agree that function tracing is never used by people who can't build a kernel --
> and so it is fine to make it an additional build option.
>
> > (This should efficiently be the same as the proposed big patch a year
> > ago from Pekka Enberg, just a bit smaller and should make ACPICA and
> > kernel/linux people happy:
> > http://marc.info/?l=linux-kernel&m=113699535303722&w=2
> > )
> >
> >
> > Kernel image size (compiled on x86_64):
> > Full acpi debug:
> > 1618277 bytes (+3.1%, +48k)
> > acpi debug function trace compiled out:
> > 1605359 bytes (+2.3%, +35k)
> > acpi debug not compiled in at all
> > 1569803 bytes (100%)
> >
> >
> > Speed measures on one specific machine (x86_64, laptop):
> >
> > A) ACPI_DEBUG compiled in
> > B) ACPI_DEBUG compiled in, but Function trace compiled out
> > C) ACPI_DEBUG compiled out
> > D) ACPI_DEBUG compiled out (control run)
> >
> > The time has been taken at following functions:
> >
> > 1) drivers/acpi/bus.c:acpi_early_init (load tables and initialize
> > ACPI namespace)
> > 2) drivers/acpi/bus.c:acpi_init (some more initialisation
> > -> enable ACPI HW mode
> > -> read PIC/APIC table, ...)
> > 3) drivers/acpi/scan.c:scan_init (Enumerate devices in the
> > ACPI namespace)
> >
> > register driver for acpi drivers:
> > 4) ec
> > 5) pci_root
> > 6) pci_link
> >
> > -----------------------------------------------------------------------
> > | A | B | C | D |
> > -----------------------------------------------------------------------
> > 1 | 434711 (+1.0%) | 432652 (+0.4%) | 430522 (100%) | 430512 (-0.00%)
> > -----------------------------------------------------------------------
> > 2 | 69156 (+3.7%) | 67007 (+0.4%) | 66696 (100%) | 66703 (+0.01%)
> > -----------------------------------------------------------------------
> > 3 | 8769(+63.3%) | 7363(+37.1%) | 5369 (100%) | 5369 ( 0.00%)
> > -----------------------------------------------------------------------
>
> 37% sounds like a lot.
Yes, it looks like a side effect, that on very short taking
measurements, the debug time increase is that much, but I don't know for
sure.
I'd have expected more time increase for the whole namespace parsing
where millions of function trace or other debug statements could get
checked, but this came out to be not that much (even much better without
function trace). So I doubt the time increase for the short time taking
measurements are true or it's for some reason only for short taking
functions. If I find some time I check that again on a bigger Itanium
with some ten thousand lines of ASL, if it's fast enough it should be
fine...
> The ACPI interpreter is not supposed to be in performace critical sections,
> but at the same time, it isn't supposed to be a pig either.
>
> > 4 | 15999 (+0.7%) | 15950 (+0.4%) | 15879 (100%) | 15878 (-0.01%)
> > -----------------------------------------------------------------------
> > 5 | 9492(+75.4%) | 7657(+41.5%) | 5411 (100%) | 5405 (-0.11%)
> > -----------------------------------------------------------------------
> > 6 | 1717(+64.0%) | 1494(+42.6%) | 1047 (100%) | 1046 (-0.10%)
> > -----------------------------------------------------------------------
> > All measured values are in us. TSC was used to obtain the values.
> > do_gettimeofday did only provide valid values after hpet got setup
> > (after pci_link).
> >
> > I wonder why only the short time taking measures show that extreme
> > performance loss, maybe someone has an idea. However if you summarize
> > all additional time with ACPI_DEBUG without function trace, you get
> > about +5 ms boot time (which may vary from machine to machine...).
> > This should be acceptable for test and develop kernels.
> > If nothing bad happens in Beta phase I'd like to include this one into
> > the final OpenSUSE kernel to get detailed bug reports.
> > It would be great if others with their latest test/devel kernels follow,
> > so that even ordinary users can easily provide essential, detailed debug
> > information easily(e.g. Linus' Compaq and Andrew's Vaio are well known
> > on the acpi list, others do not have the luck to get that much of
> > support and they do not have the knowledge to compile kernel and so
> > on...).
> >
> > I can also add a file "Documentation/acpi_debug" and add some debug
> > hints if this one gets accepted...
> >
> > This one should not be really dangerous. If the patch is ok, can Len
> > still merge this in .22 time?
>
> .22 after -rc3? No. I don't see a problem with a final version
> shipping in .23, however.
The only wanted changes are comments, right?
This could already be in your tree for three weeks.
Ok, may just have gone under,
looking forward to see this in your test tree then.
> > If not, can you take it for some testing, Andrew?
>
> It would be better for andrew to get it through acpi-test.
>
> I'll be happy to include an updated version of this patch there.
>
> Note that the testing that it is going to get will be small:
>
> 1. people who don't enable CONFIG_ACPI_DEBUG
> no change
> 2. people who enable CONFIG_ACPI_DEBUG
> will lose function tracing if they don't ask for it
> will lose AML Debug-object messages unless they
> set the flag to get them back.
>
> > Thanks,
> >
> > Thomas
> >
> >
> >
> > Split ACPI_DEBUG into function trace enabled and not enabled.
> >
> > Function trace is most of the ACPI_DEBUG costs, but is
> > not much of use for kernel ACPI debugging.
> >
> > Size of kernel image increased on test compile:
> > + 48k (Full ACPI_DEBUG)
> > + 35k (ACPI_DEBUG with function trace compiled out)
> >
> > Performance without function trace is also much better.
> >
> > Also remove ACPI_LV_DEBUG_OBJECT from default debug level as
> > a lot vendors let Store (value, debug) in their code and this
> > might confuse users when it pops up in syslog.
>
> This, is an incompatible change, as one of the benefits of
> CONFIG_ACPI_DEBUG is to get the AML debug-object messages.
> After this patch, those will silently go away.
>
> The patch needs to document the boot-time flag to make
> those messages come back.
Hm, who makes use of the store(xy, debug) functionality knows what he's
doing and should know where to enable it?
-> Mentioned the option in the patch.
>
> > ---
> > drivers/acpi/Kconfig | 8 ++++++++
> > include/acpi/acmacros.h | 23 +++++++++++++++++++++++
> > include/acpi/acoutput.h | 4 ++--
> > 3 files changed, 33 insertions(+), 2 deletions(-)
> >
> > Index: linux-2.6.22-rc3/drivers/acpi/Kconfig
> > ===================================================================
> > --- linux-2.6.22-rc3.orig/drivers/acpi/Kconfig
> > +++ linux-2.6.22-rc3/drivers/acpi/Kconfig
> > @@ -280,6 +280,14 @@ config ACPI_DEBUG
> > of verbosity. Saying Y enables these statements. This will increase
> > your kernel size by around 50K.
> >
> > +config ACPI_DEBUG_FUNC_TRACE
> > + bool "Additionally enable ACPI function tracing"
> > + default n
> > + depends on ACPI_DEBUG
> > + help
> > + ACPI Debug Statements slow down ACPI processing. Function trace
> > + is about half of the penalty and is rarely useful.
>
> help text needs update -- it should say what tracing does,
> not if SuSE customers frequently use it or not...
The text is not perfect... -> corrected.
>
> > config ACPI_EC
> > bool
> > default y
> > Index: linux-2.6.22-rc3/include/acpi/acmacros.h
> > ===================================================================
> > --- linux-2.6.22-rc3.orig/include/acpi/acmacros.h
> > +++ linux-2.6.22-rc3/include/acpi/acmacros.h
> > @@ -486,6 +486,8 @@
> > #define ACPI_FUNCTION_NAME(name)
> > #endif
> >
> > +#ifdef DEBUG_FUNC_TRACE
> > +
> > #define ACPI_FUNCTION_TRACE(a) ACPI_FUNCTION_NAME(a) \
> > acpi_ut_trace(ACPI_DEBUG_PARAMETERS)
> > #define ACPI_FUNCTION_TRACE_PTR(a,b) ACPI_FUNCTION_NAME(a) \
> > @@ -563,6 +565,27 @@
> >
> > #endif /* ACPI_SIMPLE_RETURN_MACROS */
> >
> > +#else /* !DEBUG_FUNC_TRACE */
> > +
> > +#define ACPI_FUNCTION_TRACE(a)
> > +#define ACPI_FUNCTION_TRACE_PTR(a,b)
> > +#define ACPI_FUNCTION_TRACE_U32(a,b)
> > +#define ACPI_FUNCTION_TRACE_STR(a,b)
> > +#define ACPI_FUNCTION_EXIT
> > +#define ACPI_FUNCTION_STATUS_EXIT(s)
> > +#define ACPI_FUNCTION_VALUE_EXIT(s)
> > +#define ACPI_FUNCTION_TRACE(a)
> > +#define ACPI_FUNCTION_ENTRY()
> > +
> > +#define return_VOID return
> > +#define return_ACPI_STATUS(s) return(s)
> > +#define return_VALUE(s) return(s)
> > +#define return_UINT8(s) return(s)
> > +#define return_UINT32(s) return(s)
> > +#define return_PTR(s) return(s)
> > +
> > +#endif /* DEBUG_FUNC_TRACE */
>
> These non-defines already appear later in the file.
> Perhaps you can use an expression to make them appear just once instead of twice?
Good idea. But this does not work because you'd need a kind of curly
braces functionality for pre-processor conditionals.
>
> > /* Conditional execution */
> >
> > #define ACPI_DEBUG_EXEC(a) a
> > Index: linux-2.6.22-rc3/include/acpi/acoutput.h
> > ===================================================================
> > --- linux-2.6.22-rc3.orig/include/acpi/acoutput.h
> > +++ linux-2.6.22-rc3/include/acpi/acoutput.h
> > @@ -178,8 +178,8 @@
> >
> > /* Defaults for debug_level, debug and normal */
> >
> > -#define ACPI_DEBUG_DEFAULT (ACPI_LV_INIT | ACPI_LV_WARN | ACPI_LV_ERROR | ACPI_LV_DEBUG_OBJECT)
> > -#define ACPI_NORMAL_DEFAULT (ACPI_LV_INIT | ACPI_LV_WARN | ACPI_LV_ERROR | ACPI_LV_DEBUG_OBJECT)
> > +#define ACPI_DEBUG_DEFAULT (ACPI_LV_INIT | ACPI_LV_WARN | ACPI_LV_ERROR)
> > +#define ACPI_NORMAL_DEFAULT (ACPI_LV_INIT | ACPI_LV_WARN | ACPI_LV_ERROR)
> > #define ACPI_DEBUG_ALL (ACPI_LV_AML_DISASSEMBLE | ACPI_LV_ALL_EXCEPTIONS | ACPI_LV_ALL)
> >
> > #endif /* __ACOUTPUT_H__ */
> >
Thanks,
Thomas
Split ACPI_DEBUG function trace into its own compile option.
Function trace is most of the ACPI_DEBUG costs, but is
not much of use for kernel ACPI debugging.
Size of kernel image increased on test compile:
+ 48k (Full ACPI_DEBUG)
+ 35k (ACPI_DEBUG with function trace compiled out)
Performance without function trace is also much better.
Also remove ACPI_LV_DEBUG_OBJECT from default debug level as
a lot vendors let Store (value, debug) in their code and this
might confuse users when it pops up in syslog.
That means, if you make use of your own, overridden DSDT and
store things to the debug object, you need to explicitly add the
debug_object flag to the boot param acpi.debug_level=
or enable it at runtime in the corresponding /sys/ file.
Signed-off-by: Thomas Renninger <[email protected]>
---
drivers/acpi/Kconfig | 13 ++++++++++++-
include/acpi/acmacros.h | 23 +++++++++++++++++++++++
include/acpi/acoutput.h | 4 ++--
3 files changed, 37 insertions(+), 3 deletions(-)
Index: linux-2.6.22-rc3/drivers/acpi/Kconfig
===================================================================
--- linux-2.6.22-rc3.orig/drivers/acpi/Kconfig
+++ linux-2.6.22-rc3/drivers/acpi/Kconfig
@@ -278,7 +278,18 @@ config ACPI_DEBUG
help
The ACPI driver can optionally report errors with a great deal
of verbosity. Saying Y enables these statements. This will increase
- your kernel size by around 50K.
+ your kernel size by around 35K.
+
+config ACPI_DEBUG_FUNC_TRACE
+ bool "Additionally enable ACPI function tracing"
+ default n
+ depends on ACPI_DEBUG
+ help
+ This will increase your kernel size by another 15K.
+ ACPI function tracing log the invoked ACPICA subsystem functions
+ in syslog (still needs to be enabled via acpi.debug_level= mask).
+ This significantly slows down ACPI code processing, only enable it
+ if you know what you are doing.
config ACPI_EC
bool
Index: linux-2.6.22-rc3/include/acpi/acmacros.h
===================================================================
--- linux-2.6.22-rc3.orig/include/acpi/acmacros.h
+++ linux-2.6.22-rc3/include/acpi/acmacros.h
@@ -486,6 +486,8 @@
#define ACPI_FUNCTION_NAME(name)
#endif
+#ifdef DEBUG_FUNC_TRACE
+
#define ACPI_FUNCTION_TRACE(a) ACPI_FUNCTION_NAME(a) \
acpi_ut_trace(ACPI_DEBUG_PARAMETERS)
#define ACPI_FUNCTION_TRACE_PTR(a,b) ACPI_FUNCTION_NAME(a) \
@@ -563,6 +565,27 @@
#endif /* ACPI_SIMPLE_RETURN_MACROS */
+#else /* !DEBUG_FUNC_TRACE */
+
+#define ACPI_FUNCTION_TRACE(a)
+#define ACPI_FUNCTION_TRACE_PTR(a,b)
+#define ACPI_FUNCTION_TRACE_U32(a,b)
+#define ACPI_FUNCTION_TRACE_STR(a,b)
+#define ACPI_FUNCTION_EXIT
+#define ACPI_FUNCTION_STATUS_EXIT(s)
+#define ACPI_FUNCTION_VALUE_EXIT(s)
+#define ACPI_FUNCTION_TRACE(a)
+#define ACPI_FUNCTION_ENTRY()
+
+#define return_VOID return
+#define return_ACPI_STATUS(s) return(s)
+#define return_VALUE(s) return(s)
+#define return_UINT8(s) return(s)
+#define return_UINT32(s) return(s)
+#define return_PTR(s) return(s)
+
+#endif /* DEBUG_FUNC_TRACE */
+
/* Conditional execution */
#define ACPI_DEBUG_EXEC(a) a
Index: linux-2.6.22-rc3/include/acpi/acoutput.h
===================================================================
--- linux-2.6.22-rc3.orig/include/acpi/acoutput.h
+++ linux-2.6.22-rc3/include/acpi/acoutput.h
@@ -178,8 +178,8 @@
/* Defaults for debug_level, debug and normal */
-#define ACPI_DEBUG_DEFAULT (ACPI_LV_INIT | ACPI_LV_WARN | ACPI_LV_ERROR | ACPI_LV_DEBUG_OBJECT)
-#define ACPI_NORMAL_DEFAULT (ACPI_LV_INIT | ACPI_LV_WARN | ACPI_LV_ERROR | ACPI_LV_DEBUG_OBJECT)
+#define ACPI_DEBUG_DEFAULT (ACPI_LV_INIT | ACPI_LV_WARN | ACPI_LV_ERROR)
+#define ACPI_NORMAL_DEFAULT (ACPI_LV_INIT | ACPI_LV_WARN | ACPI_LV_ERROR)
#define ACPI_DEBUG_ALL (ACPI_LV_AML_DISASSEMBLE | ACPI_LV_ALL_EXCEPTIONS | ACPI_LV_ALL)
#endif /* __ACOUTPUT_H__ */
Also remove ACPI_LV_DEBUG_OBJECT from default debug level as
a lot vendors let Store (value, debug) in their code and this
might confuse users when it pops up in syslog.
---
drivers/acpi/Kconfig | 8 ++++++++
include/acpi/acmacros.h | 23 +++++++++++++++++++++++
include/acpi/acoutput.h | 4 ++--
3 files changed, 33 insertions(+), 2 deletions(-)
Index: linux-2.6.21/drivers/acpi/Kconfig
===================================================================
--- linux-2.6.21.orig/drivers/acpi/Kconfig
+++ linux-2.6.21/drivers/acpi/Kconfig
@@ -346,6 +346,14 @@ config ACPI_DEBUG
of verbosity. Saying Y enables these statements. This will increase
your kernel size by around 50K.
+config ACPI_DEBUG_FUNC_TRACE
+ bool "Additionally enable ACPI function tracing"
+ default n
+ depends on ACPI_DEBUG
+ help
+ ACPI Debug Statements slow down ACPI processing. Function trace
+ is about half of the penalty and is rarely useful.
+
config ACPI_EC
bool
default y
Index: linux-2.6.21/include/acpi/acmacros.h
===================================================================
--- linux-2.6.21.orig/include/acpi/acmacros.h
+++ linux-2.6.21/include/acpi/acmacros.h
@@ -486,6 +486,8 @@
#define ACPI_FUNCTION_NAME(name)
#endif
+#ifdef DEBUG_FUNC_TRACE
+
#define ACPI_FUNCTION_TRACE(a) ACPI_FUNCTION_NAME(a) \
acpi_ut_trace(ACPI_DEBUG_PARAMETERS)
#define ACPI_FUNCTION_TRACE_PTR(a,b) ACPI_FUNCTION_NAME(a) \
@@ -563,6 +565,27 @@
#endif /* ACPI_SIMPLE_RETURN_MACROS */
+#else /* !DEBUG_FUNC_TRACE */
+
+#define ACPI_FUNCTION_TRACE(a)
+#define ACPI_FUNCTION_TRACE_PTR(a,b)
+#define ACPI_FUNCTION_TRACE_U32(a,b)
+#define ACPI_FUNCTION_TRACE_STR(a,b)
+#define ACPI_FUNCTION_EXIT
+#define ACPI_FUNCTION_STATUS_EXIT(s)
+#define ACPI_FUNCTION_VALUE_EXIT(s)
+#define ACPI_FUNCTION_TRACE(a)
+#define ACPI_FUNCTION_ENTRY()
+
+#define return_VOID return
+#define return_ACPI_STATUS(s) return(s)
+#define return_VALUE(s) return(s)
+#define return_UINT8(s) return(s)
+#define return_UINT32(s) return(s)
+#define return_PTR(s) return(s)
+
+#endif /* DEBUG_FUNC_TRACE */
+
/* Conditional execution */
#define ACPI_DEBUG_EXEC(a) a
Index: linux-2.6.21/include/acpi/acoutput.h
===================================================================
--- linux-2.6.21.orig/include/acpi/acoutput.h
+++ linux-2.6.21/include/acpi/acoutput.h
@@ -178,8 +178,8 @@
/* Defaults for debug_level, debug and normal */
-#define ACPI_DEBUG_DEFAULT (ACPI_LV_INIT | ACPI_LV_WARN | ACPI_LV_ERROR | ACPI_LV_DEBUG_OBJECT)
-#define ACPI_NORMAL_DEFAULT (ACPI_LV_INIT | ACPI_LV_WARN | ACPI_LV_ERROR | ACPI_LV_DEBUG_OBJECT)
+#define ACPI_DEBUG_DEFAULT (ACPI_LV_INIT | ACPI_LV_WARN | ACPI_LV_ERROR)
+#define ACPI_NORMAL_DEFAULT (ACPI_LV_INIT | ACPI_LV_WARN | ACPI_LV_ERROR)
#define ACPI_DEBUG_ALL (ACPI_LV_AML_DISASSEMBLE | ACPI_LV_ALL_EXCEPTIONS | ACPI_LV_ALL)
#endif /* __ACOUTPUT_H__ */
Hello Thomas,
I'm delighted that you feel that the ACPI debug code is worthy
of being enabled by default in SuSE Linux. While that certainly
wasn't the intent of the code, I'm open to your suggestions should
you find any issues with it where it doesn't suite your needs.
However, I have no plans to enable CONFIG_ACPI_DEBUG upstream by default.
For I don't expect it to increase the quality of bug reports we receive,
or to foster more participation and support in the community for debugging Linux/ACPI.
Indeed, I believe that end-users want fewer ACPI messages, not more.
I believe that there is a small group of people who are simultaneously
capable and willing to debug the Linux Kernel and AML.
These people already run custom built kernels and can enable CONFIG_ACPI_DEBUG
at will. I don't believe that enabling it by default in a distribution
kernel has measurable utility for the users and customers outside this
(already served) small group.
Re: bugzilla 7122 and 5534
I do not believe that these are valid examples of where enabling
CONFIG_ACPI_DEBUG by default would have resulted in solution sooner.
While it is true that my team has more ready access to Intel hardware,
I became so alarmed at these failures that I purchased an HP nx2125
and an HP nx6325 to figure out what the HP BIOS developers were thinking.
The nx6325 is now working perfectly -- I test kernels on it almost every day.
The nx6125 is for Alexy, but unfortunately, it seems to be mired
in Russian red tape at the moment.
Regarding the % of AML that Linux is currently taking advantage of.
With a few notable exceptions, Linux is actually ahead of Microsoft
in support for the very latest version of the ACPI specification.
This, of course, is a hollow victory, as vendors don't ship features
that can't be handled by Windows. But the point is that Linux is leading
here, not following, in support of AML.
Regarding platform specific drivers that use AML.
Everybody appreciates the efforts of the guys that are doing
these drivers -- they make our Linux laptops more useful.
But without vendor support, this requires a heroic effort.
The strategy of SuSE as a Linux distributor should not be
to escalate this heroic effort -- but to make it unnecessary.
Ie. If Brand-X wants to be certified on SuSE, then Brand-X
should provide the appropriate platform specific driver for
Linux - or support the community with documentation so we can
do it methodically and reliably.
BTW, you mentioned WMI..
I've prototyped a Linux WMI driver, and will release it as soon as
it is in a form where people in addition to just me will find it useful --
probably in July.
Re: timing
I'd love to be able to check stuff in upstream at any point in the release cycle,
but the reality is that Linus has ACPI on a pretty short leash.
He makes the rules, and I do my best to follow them.
After -rc1 closes, the focus is really on fixing regressions,
and patches which are worthy enough that they'd qualify
for the .stable criteria. So in this case, we are firmly
past 2.6.22 and into 2.6.23. Like you, I hope that happens
sooner rather than later.
Note that your earlier version of this patch is already in acpi-test.
I'll try out your update as soon as I return from watching the
Boston Red Sox clobber the New York Yankees at Fenway Park tonight.
thanks,
-Len
Hi!
> > > (This should efficiently be the same as the proposed big patch a year
> > > ago from Pekka Enberg, just a bit smaller and should make ACPICA and
> > > kernel/linux people happy:
> > > http://marc.info/?l=linux-kernel&m=113699535303722&w=2)
> >
> > No, you're keeping these obfuscating macros around:
> >
> > +#define return_VOID return
> > +#define return_ACPI_STATUS(s) return(s)
> > +#define return_VALUE(s) return(s)
> > +#define return_UINT8(s) return(s)
> >
> > Making the ACPI code look like regular Linux kernel code (or even
> > regular C for that matter) was the whole point of my patch. Your patch
> > doesn't change that.
>
> I think that Thomas's point is that he is optimally removing
> function tracing via #ifdef.
> Your 600KB patch, on the other hand, permanently removed the feature
> and touched every file in ACPICA.
>
> The net effect to the user is the same, the ability to enable
> ACPI_DEBUG and not enable ACPICA function tracing.
>
> As I probably wrote a year ago, it isn't viable to completely
> remove the tracing code --
> until Linux reaches a point where vendors certify that their
> BIOS is compatible with Linux before they ship, rather than the Linux
> community having to debug some Windows-compatible systems into
> Linux-compatibility well after they have shipped into the field.
Well, those obfuscating macros pretty much make acpi code unreadable
:-(. If function-level tracing is desired, perhaps it can be done via
linker magic?
Pavel
--
(english) http://www.livejournal.com/~pavelmachek
(cesky, pictures) http://atrey.karlin.mff.cuni.cz/~pavel/picture/horses/blog.html