一、使用ACPI_DEBUG_PRINT()输出 debug message

ACPICA、linux ACPI core和一些ACPI drivers都可以通过ACPI_DEBUG_PRINT()宏输出一些信息帮助我们完成调试和function tracing。
但是这些信息有很多，如果都打出来的话，会不停地刷屏，也给我们带来困扰，如果能够查看我们关心的一些模块或是阶段的信息就好了。
好在，Linux kernel提供了module parameter：debug_layer和debug_level，通过设置这两个参数，可以只输出指定模块、指定类型的信息。
参考文档：Documentations/acpi/debug.txt；

1.1 debug_layer

debug_layer用来控制ACPI_DEBUG_PRINT()的输出粒度，可以通过debug_layer选择只输出我们比较关心的模块，比如event handling、processor等；
当前系统支持的component定义在include/acpi/acoutput.h中；
系统runtime运行时，可以通过 $ cat /sys/module/acpi/parameters/debug_layer 查看支持&使能的component如下：

Description                    		 Hex        	    SET
ACPI_UTILITIES      0x00000001 [ ]
ACPI_HARDWARE		0x00000002 [ ]
ACPI_EVENTS			0x00000004 [ ]
ACPI_TABLES			0x00000008 [ ]
ACPI_NAMESPACE		0x00000010 [ ]
ACPI_PARSER			0x00000020 [ ]
ACPI_DISPATCHER		0x00000040 [ ]
ACPI_EXECUTER			0x00000080 [ ]
ACPI_RESOURCES		0x00000100 [ ]
ACPI_CA_DEBUGGER		0x00000200 [ ]
ACPI_OS_SERVICES		0x00000400 [ ]
ACPI_CA_DISASSEMBLER 0x00000800 [ ]
ACPI_COMPILER 			0x00001000 [ ]
ACPI_TOOLS				0x00002000 [ ]
ACPI_BUS_COMPONENT 	0x00010000 [ ]
ACPI_AC_COMPONENT	0x00020000 [ ]
ACPI_BATTERY_COMPONENT	0x00040000 [ ]
ACPI_BUTTON_COMPONENT	0x00080000 [ ]
ACPI_SBS_COMPONENT		0x00100000 [ ]
ACPI_FAN_COMPONENT		0x00200000 [ ]
ACPI_PCI_COMPONENT 		0x00400000 [ ]
ACPI_POWER_COMPONENT 	0x00800000 [ ]
ACPI_CONTAINER_COMPONENT	0x01000000 [ ]
ACPI_SYSTEM_COMPONENT		0x02000000 [ ]
ACPI_THERMAL_COMPONENT		0x04000000 [ ]
ACPI_MEMORY_DEVICE_COMPONENT	0x08000000 [ ]
ACPI_VIDEO_COMPONENT			0x10000000 [ ]
ACPI_PROCESSOR_COMPONENT		0x20000000 [*]
ACPI_ALL_DRIVERS					0xFFFF0000 [-]

debug_layer = 0x20000000 ( * = enabled)

如上，[*]表示对应的模块使能。
若是想要在source code中输出指定模块的debug info，需要通过
#define __COMPONENT 引入相应的模块。
比如，我们在ACPI table处理的相关code中引入ACPI_TABLES；在event处理的相关code中引入ACPI_EVENTS。
比如在processor_idle.c中使用processor module debug info，需要添加：
#define _COMPONENT ACPI_PROCESSOR_COMPONENT
之后，当debug_layer中设置了ACPI_PROCESSOR_COMPONENT时，就能在source code代码执行时输出相应的debug message。

1.2 debug_level

debug_level用来选择输出message的类型，比如initialization、method execution、informational message等。
每个模块都可以通过ACPI_DEBUG_PRINT()宏来控制选择输出debug message，一般地，ACPI interpreter模块中会使用不同level，但Linux ACPI core和ACPI driver通常只使用ACPI_LV_INFO。
各个debug level的定义在include/acpi/acoutput.h中
同样，也可以通过 $ cat /sys/module/acpi/parameters/debug_level查看系统支持&当前设置的debug_level如下：

Description                    			 Hex        SET
ACPI_LV_INIT                0x00000001 [ ]
ACPI_LV_DEBUG_OBJECT		0x00000002 [ ]
ACPI_LV_INFO				0x00000004 [*]
ACPI_LV_REPAIR				0x00000008 [ ]
ACPI_LV_TRACE_POINT			0x00000010 [ ]
ACPI_LV_INIT_NAMES 			0x00000020 [ ]
ACPI_LV_PARSE				0x00000040 [ ]
ACPI_LV_LOAD				0x00000080 [ ]
ACPI_LV_DISPATCH			0x00000100 [ ]
ACPI_LV_EXEC				0x00000200 [ ]
ACPI_LV_NAMES				0x00000400 [ ]
ACPI_LV_OPREGION			0x00000800 [ ]
ACPI_LV_BFIELD				0x00001000 [ ]
ACPI_LV_TABLES				0x00002000 [ ]
ACPI_LV_VALUES				0x00004000 [ ]
ACPI_LV_OBJECTS             0x00008000 [ ]
ACPI_LV_RESOURCES           0x00010000 [ ]
ACPI_LV_USER_REQUESTS 		0x00020000 [ ]
ACPI_LV_PACKAGE 			0x00040000 [ ]
ACPI_LV_ALLOCATIONS			0x00100000 [ ]
ACPI_LV_FUNCTIONS			0x00200000 [ ]
ACPI_LV_OPTIMIZATIONS 		0x00400000 [ ]
ACPI_LV_MUTEX				0x01000000 [ ]
ACPI_LV_THREADS				0x02000000 [ ]
ACPI_LV_IO					0x04000000 [ ]
ACPI_LV_INTERRUPTS			0x08000000 [ ]
ACPI_LV_AML_DISASSEMBLE 	0x10000000 [ ]
ACPI_LV_VERBOSE_INFO		0x20000000 [ ]
ACPI_LV_FULL_TABLES 		0x40000000 [ ]
ACPI_LV_EVENTS 				0x80000000 [ ]
--
debug_level = 0x00000004 (* = enabled)

如上，[* ]表示选中相应的debug message type。
虽然我们设置debug_level时，都是使用ACPI_LV_xxxx，但是ACPI_DEBUG_PRINT()宏不会直接使用这些宏，而是在ACPI_LV_xxxx的基础上，额外使用宏ACPI_DEBUG_LEVEL定义ACPI_DB_xxxx，方便输出格式化信息；

#define ACPI_DB_INIT				ACPI_DEBUG_LEVEL (ACPI_LV_INIT)
#define ACPI_DB_DEBUG_OBJECT		ACPI_DEBUG_LEVEL (ACPI_LV_DEBUG_OBJECT)
#define ACPI_DB_INFO 				ACPI_DEBUG_LEVEL (ACPI_LV_INFO)
#define ACPI_DB_REPAIR				ACPI_DEBUG_LEVEL (ACPI_LV_REPAIR)
#define ACPI_DB_TRACE_POINT 		ACPI_DEBUG_LEVEL (ACPI_LV_TRACE_POINT)
#define ACPI_DB_ALL_EXCEPTIONS		ACPI_DEBUG_LEVEL (ACPI_LV_ALL_EXCEPTIONS)
/* Trace level -- also used in the global "DebugLevel" */
#define ACPI_DB_INIT_NAMES			ACPI_DEBUG_LEVEL (ACPI_LV_INIT_NAMES)
#define ACPI_DB_THREADS 			ACPI_DEBUG_LEVEL (ACPI_LV_THREADS)
#define ACPI_DB_PARSE				ACPI_DEBUG_LEVEL (ACPI_LV_PARSE)
#define ACPI_DB_DISPATCH 			ACPI_DEBUG_LEVEL (ACPI_LV_DISPATCH)
#define ACPI_DB_LOAD				ACPI_DEBUG_LEVEL (ACPI_LV_LOAD)
#define ACPI_DB_EXEC 				ACPI_DEBUG_LEVEL (ACPI_LV_EXEC)
#define ACPI_DB_NAMES 				ACPI_DEBUG_LEVEL (ACPI_LV_NAMES)
#define ACPI_DB_OPREGION			ACPI_DEBUG_LEVEL (ACPI_LV_OPREGION)
#define ACPI_DB_BFIELD				ACPI_DEBUG_LEVEL (ACPI_LV_BFIELD)
#define ACPI_DB_TABLES 				ACPI_DEBUG_LEVEL (ACPI_LV_TABLES)
#define ACPI_DB_FUNCTIONS			ACPI_DEBUG_LEVEL (ACPI_LV_FUNCTIONS)
#define ACPI_DB_OPTIMIZATIONS		ACPI_DEBUG_LEVEL (ACPI_LV_OPTIMIZATIONS)
#define ACPI_DB_VALUES				ACPI_DEBUG_LEVEL (ACPI_LV_VALUES)
#define ACPI_DB_OBJECTS				ACPI_DEBUG_LEVEL (ACPI_LV_OBJECTS)
#define ACPI_DB_ALLOCATIONS 		ACPI_DEBUG_LEVEL (ACPI_LV_ALLOCATIONS)
#define ACPI_DB_RESOURCES			ACPI_DEBUG_LEVEL (ACPI_LV_RESOURCES)
#define ACPI_DB_IO					ACPI_DEBUG_LEVEL (ACPI_LV_IO)
#define ACPI_DB_INTERRUPTS			ACPI_DEBUG_LEVEL (ACPI_LV_INTERRUPTS)
#define ACPI_DB_USER_REQUESTS       ACPI_DEBUG_LEVEL (ACPI_LV_USER_REQUESTS)
#define ACPI_DB_PACKAGE				ACPI_DEBUG_LEVEL (ACPI_LV_PACKAGE)
#define ACPI_DB_MUTEX				ACPI_DEBUG_LEVEL (ACPI_LV_MUTEX)
#define ACPI_DB_EVENTS 				ACPI_DEBUG_LEVEL (ACPI_LV_EVENTS)
#define ACPI_DB_ALL                 ACPI_DEBUG_LEVEL (ACPI_LV_ALL)
/* Defaults for debug_level, debug and normal */
#define ACPI_DEBUG_DEFAULT		(ACPI_LV_INFO | ACPI_LV_REPAIR)
#define ACPI_NORMAL_DEFAULT		(ACPI_LV_INIT | ACPI_LV_DEBUG_OBJECT | ACPI_LV_REPAIR)
#define ACPI_DEBUG_ALL			(ACPI_LV_AML_DISASSEMBLE | ACPI_LV_ALL_EXCEPTIONS | 	
ACPI_LV_ALL)

其中ACPI_DEBUG_LEVEL()和ACPI_DEBUG_PARAMETERS()都在acoutput.h中定义

#define ACPI_DEBUG_LEVEL(dl)        	(u32) dl,ACPI_DEBUG_PARAMETERS
#define ACPI_DEBUG_PARAMETERS 	\
	__LINE__, ACPI_GET_FUNCTION_NAME, _acpi_module_name, _COMPONENT

通过这种方式，我们能够很方便地输出component、module、function以及line number信息。
比如：

ACPI_DEBUG_PRINT((ACPI_DB_INFO, "Found %d power states\n", current_count));
当debug_level中设置了ACPI_LV_INFO之后，输出的message如下：
processor_idle-0455 processor_get_power_in: Found 3 power states 

1.3 how to use debug_layer and debug_level

大致了解了debug_layer和debug_level之后，我们来看看如何使用
1）首先，kernel中必须设置CONFIG_ACPI_DEBUG=y，这样才能将debug message加入到kernel中；
2）boot-time setting
在boot时，通过kernel command line option设置debug_layer和debug_level

acpi.debug_layer=xxxx;
acpi.debug_level=xxxx;

3）run-time setting
系统运行时，可以通过module parameters来实时修改

echo  xxxx > /sys/module/acpi/parameters/debug_layer
echo  xxxx > /sys/module/acpi/parameters/debug_level

这个改动会覆盖boot-time时对debug_layer和debug_level的设定。

二、使用debug_layer和debug_level进行调试和tracing的实例

2.1 processor模块信息输出

我们以ACPI_PROCESSOR_COMPONENT为例，看看如何通过debug_layer和debug_level控制只输出processor相关的debug message。
在drivers/acpi/processor_idle.c中

#define _COMPONENT		ACPI_PROCESSOR_COMPONENT
ACPI_DEBUG_PRINT((ACPI_DB_INFO, "Found %d power states\n",  current_count));

想要输出这个message，我们需要设置：
1） 设置debug_layer，将ACPI_PROCESSOR_COMPONENT (0x20000000)使能
$ echo 0x20000000 > /sys/module/acpi/parameter/debug_layer
2） 设置debug_level，将ACPI_LV_INFO (0x04)使能
$ echo 0x04 > /sys/module/acpi/parameter/debug_level
3）我们将CPU1进行hotplug，测试debug message输出如下：

$ echo 0 > /sys/devices/system/cpu/cpu1/online
$ echo 1 > /sys/devices/system/cpu/cpu1/online
[ 3765.300338] processor_idle-0450 processor_get_power_in: Found 3 power states
[ 3765.300345] processor_idle-0506 processor_power_verify: C3 support without BM control；

2.2 使用acpi_debug_print进行function tracing

使用function tracing能够在函数的entry&exit point输出信息，帮助我们了解函数的调用流程。
function tracing主要用来tracing ACPICA code；通过ACPI_FUNCTION_TRACE()宏实现：
ACPI_FUNCTION_TRACE()宏也在include/acpi/acoutput.h文件中定义，其核心是acpi_ut_trace()函数，最终也是调用acpi_debug_print()实现log输出，因此开启function tracing也需要对debug_layer和debug_level进行设置。
其中debug_level必须设置为ACPI_LV_FUNCTIONS；
debug_layer设置为需要监控的module。
在相应的source code中，调用ACPI_FUNCTION_TRACE(function_name)即可，这样就会在函数的entry&exit point输出debug message。
比如，我们想要trace系统进入S-state过程中，对GPE event的操作，
在drivers/acpi/acpica/evxfgpe.c中

#define _COMPONENT          ACPI_EVENTS
ACPI_MODULE_NAME("evxfgpe")
在需要tracing的函数中加入 ACPI_FUNCTION_TRACE(acpi_update_all_gpes);

之后，设置debug_layer和debug_level

$ echo 0x04 > /sys/module/acpi/parameters/debug_layer
$ echo 0x00200000 > /sys/module/acpi/parameters/debug_level

之后，执行S3，suspend_to_mem，这个过程中，我们可以通过dmesg查看gpe相关函数的entry/exit log，截取一段如下：

[  501.573345] evxfgpe-0154 disable_gpe           : ----Entry
[  501.586273] evgpe-0204 ev_remove_gpe_referenc: ----Entry
[  501.592582] evgpe-0227 ev_remove_gpe_referenc: ----Exit- AE_OK
[  501.599438] evxfgpe-0166 disable_gpe           : ----Exit- AE_OK

2.3 method execution tracing

参考文档Documentations/acpi/method-tracing.txt
有童鞋可能又提出来了，使用debug_layer和debug_level之后，仍然会有很多log出来，有时候我可能只关心某个device object或是control method执行时的情况，能不能只在这些object执行时才输出debug message呢？
ACPICA为我们提供了method tracing方法，能够在control method执行时，才输出指定debug layer/level的debug message，control method evaluation结束之后，不再输出任何信息。
method tracing主要是通过/sys/modules/acpi/parameters/下的trace_state、trace_method_name、trace_debug_layer、trace_debug_level实现。
我们以processor0 的_CST method为例，介绍如何使用method tracing
1、当control method执行时，才输出debug message

# echo enable > /sys/module/acpi/parameters/trace_state
# echo 0x80 > /sys/module/acpi/parameters/trace_debug_layer		(ACPI_EXECUTER)
# echo 0x10 > /sys/module/acpi/parameters/trace_debug_level		(ACPI_LV_TRACE_POINT)
# dmesg -c > /dev/null
//将CPU1/2 hotplug offline & online，
# echo 0 > /sys/devices/system/cpu/cpu1/online
# echo 0 > /sys/devices/system/cpu/cpu2/online
# echo 1 > /sys/devices/system/cpu/cpu1/online
# echo 1 > /sys/devices/system/cpu/cpu2/online
# dmesg
[21205.688453] smpboot: Booting Node 0 Processor 1 APIC 0x2
[21205.688965] masked ExtINT on CPU#1
[21205.696423]   extrace-0141 ex_trace_point        : Method Begin [0x0000000011abe5bd:\_PR.CPU1._CST] execution.
[21205.696449]   extrace-0141 ex_trace_point        : Method Begin [0x000000006d1886ee:\_PR.CPU0._CST] execution.
[21205.696685]   extrace-0141 ex_trace_point        : Method End [0x000000006d1886ee:\_PR.CPU0._CST] execution.
[21205.696693]   extrace-0141 ex_trace_point        : Method End [0x0000000011abe5bd:\_PR.CPU1._CST] execution.
[21205.696891]   extrace-0141 ex_trace_point        : Method Begin [0x000000007eb9ddc6:\_PR.CPU1._PCT] execution.
[21205.696904]   extrace-0141 ex_trace_point        : Method Begin [0x00000000ad4a85eb:\_PR.CPU0._PCT] execution.
[21205.696970]   extrace-0141 ex_trace_point        : Method End [0x00000000ad4a85eb:\_PR.CPU0._PCT] execution.
[21205.696977]   extrace-0141 ex_trace_point        : Method End [0x000000007eb9ddc6:\_PR.CPU1._PCT] execution.
[21205.696990]   extrace-0141 ex_trace_point        : Method Begin [0x00000000ba48c4ce:\_PR.CPU1._PSS] execution.
[21205.697031]   extrace-0141 ex_trace_point        : Method End [0x00000000ba48c4ce:\_PR.CPU1._PSS] execution.
[21205.697074]   extrace-0141 ex_trace_point        : Method Begin [0x000000008f16c187:\_PR.CPU1._PPC] execution.
[21205.697087]   extrace-0141 ex_trace_point        : Method End [0x000000008f16c187:\_PR.CPU1._PPC] execution.
[21209.112448] smpboot: Booting Node 0 Processor 2 APIC 0x4
[21209.112903] masked ExtINT on CPU#2
[21209.121405]   extrace-0141 ex_trace_point        : Method Begin [0x0000000063ca3b73:\_PR.CPU2._CST] execution.
[21209.121432]   extrace-0141 ex_trace_point        : Method Begin [0x000000006d1886ee:\_PR.CPU0._CST] execution.
[21209.121672]   extrace-0141 ex_trace_point        : Method End [0x000000006d1886ee:\_PR.CPU0._CST] execution.
[21209.121681]   extrace-0141 ex_trace_point        : Method End [0x0000000063ca3b73:\_PR.CPU2._CST] execution.
[21209.121858]   extrace-0141 ex_trace_point        : Method Begin [0x000000006ffd2be6:\_PR.CPU2._PCT] execution.
[21209.121870]   extrace-0141 ex_trace_point        : Method Begin [0x00000000ad4a85eb:\_PR.CPU0._PCT] execution.
[21209.121935]   extrace-0141 ex_trace_point        : Method End [0x00000000ad4a85eb:\_PR.CPU0._PCT] execution.
[21209.121943]   extrace-0141 ex_trace_point        : Method End [0x000000006ffd2be6:\_PR.CPU2._PCT] execution.
[21209.121956]   extrace-0141 ex_trace_point        : Method Begin [0x000000007507a43c:\_PR.CPU2._PSS] execution.
[21209.121998]   extrace-0141 ex_trace_point        : Method End [0x000000007507a43c:\_PR.CPU2._PSS] execution.
[21209.122041]   extrace-0141 ex_trace_point        : Method Begin [0x000000008f05d9f2:\_PR.CPU2._PPC] execution.
[21209.122053]   extrace-0141 ex_trace_point        : Method End [0x000000008f05d9f2:\_PR.CPU2._PPC] execution.

我们看到，dmesg中只输出了processor online/offline过程中control method evaluation相关的log。

2、当指定的CPU0的_CST method执行时，才输出debug message
以上会输出processor online/offline过程中所有control method的信息，如果我们只关心CPU0的_CST method执行过程呢，可以通过trace_method_name进一步缩小范围；

# echo '\_PR.CPU0._CST' > /sys/module/acpi/parameters/trace_method_name
# echo 0x80 > /sys/module/acpi/parameters/trace_debug_layer		(ACPI_EXECUTER)
# echo 0x10 > /sys/module/acpi/parameters/trace_debug_level		(ACPI_LV_TRACE_POINT)
# dmesg -c > /dev/null
//将CPU1/2 hotplug offline & online，
# echo 0 > /sys/devices/system/cpu/cpu1/online
# echo 0 > /sys/devices/system/cpu/cpu2/online
# echo 1 > /sys/devices/system/cpu/cpu1/online
# echo 1 > /sys/devices/system/cpu/cpu2/online
# dmesg
[21205.688453] smpboot: Booting Node 0 Processor 1 APIC 0x2
[21205.688965] masked ExtINT on CPU#1
[21205.696449]   extrace-0141 ex_trace_point        : Method Begin [0x000000006d1886ee:\_PR.CPU0._CST] execution.
[21205.696685]   extrace-0141 ex_trace_point        : Method End [0x000000006d1886ee:\_PR.CPU0._CST] execution.
[21209.112448] smpboot: Booting Node 0 Processor 2 APIC 0x4
[21209.112903] masked ExtINT on CPU#2
[21209.121432]   extrace-0141 ex_trace_point        : Method Begin [0x000000006d1886ee:\_PR.CPU0._CST] execution.
[21209.121672]   extrace-0141 ex_trace_point        : Method End [0x000000006d1886ee:\_PR.CPU0._CST] execution.

3、当指定的CPU0的_CST method第一次执行时，才输出debug message
需要设置trace_state为"method_once"

# echo '\_PR.CPU0._CST' > /sys/module/acpi/parameters/trace_method_name
# echo 'method_once' > /sys/module/acpi/parameters/trace_state
# echo 0x80 > /sys/module/acpi/parameters/trace_debug_layer		(ACPI_EXECUTER)
# echo 0x10 > /sys/module/acpi/parameters/trace_debug_level		(ACPI_LV_TRACE_POINT)
# dmesg -c > /dev/null
//将CPU1/2 hotplug offline & online，
# echo 0 > /sys/devices/system/cpu/cpu1/online
# echo 0 > /sys/devices/system/cpu/cpu2/online
# echo 1 > /sys/devices/system/cpu/cpu1/online
# echo 1 > /sys/devices/system/cpu/cpu2/online
# dmesg
[21205.688453] smpboot: Booting Node 0 Processor 1 APIC 0x2
[21205.688965] masked ExtINT on CPU#1
[21205.696449]   extrace-0141 ex_trace_point        : Method Begin [0x000000006d1886ee:\_PR.CPU0._CST] execution.
[21205.696685]   extrace-0141 ex_trace_point        : Method End [0x000000006d1886ee:\_PR.CPU0._CST] execution.
[21209.112448] smpboot: Booting Node 0 Processor 2 APIC 0x4
[21209.112903] masked ExtINT on CPU#2