一、使用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
Logo

更多推荐