From 93d988310bb2f5ed16ba075bbc4281aa06907e72 Mon Sep 17 00:00:00 2001 From: Lv Zheng Date: Wed, 5 Aug 2015 16:23:43 +0800 Subject: [PATCH 1/4] ACPI / sysfs: Add ACPI_LV_REPAIR debug level. This patch updates debug_level file, adding ACPI_LV_REPAIR. Signed-off-by: Lv Zheng Signed-off-by: Rafael J. Wysocki --- drivers/acpi/sysfs.c | 1 + 1 file changed, 1 insertion(+) diff --git a/drivers/acpi/sysfs.c b/drivers/acpi/sysfs.c index 0876d77b3206..7ab6ba46866f 100644 --- a/drivers/acpi/sysfs.c +++ b/drivers/acpi/sysfs.c @@ -69,6 +69,7 @@ static const struct acpi_dlevel acpi_debug_levels[] = { ACPI_DEBUG_INIT(ACPI_LV_INIT), ACPI_DEBUG_INIT(ACPI_LV_DEBUG_OBJECT), ACPI_DEBUG_INIT(ACPI_LV_INFO), + ACPI_DEBUG_INIT(ACPI_LV_REPAIR), ACPI_DEBUG_INIT(ACPI_LV_INIT_NAMES), ACPI_DEBUG_INIT(ACPI_LV_PARSE), From 7901a052a981691d18f4e8f91fc27e40849b7336 Mon Sep 17 00:00:00 2001 From: Lv Zheng Date: Wed, 5 Aug 2015 16:23:51 +0800 Subject: [PATCH 2/4] ACPI / sysfs: Update method tracing facility. This patch updates the method tracing facility as the acpi_debug_trace() API has been updated to allow it to trace AML interpreter execution, the meanings and the usages of the API parameters are changed due to the updates. The new API: 1. Uses ACPI_TRACE_ENABLED flag to indicate the enabling of the tracer; 2. Allows tracer still can be enabled when method name is not specified so that the AML interpreter execution can be traced without knowing the method name, which is useful for kernel boot tracing; 3. Supports arbitrary full path name, it doesn't need to be a name related to an entrance of acpi_evaluate_object(). Note that the sysfs parameters are also updated so that when reading the attribute files, ACPICA internal settings are returned. In order to make the sysfs parameters (acpi.trace_state) available during boot, this patch adds code to bypass ACPICA semaphore/mutex invocations when acpi mutex utilities haven't been initialized. This patch doesn't update documentation of method tracing facility, it will be updated by further patches. Signed-off-by: Lv Zheng Signed-off-by: Rafael J. Wysocki --- drivers/acpi/osl.c | 8 +++ drivers/acpi/sysfs.c | 136 +++++++++++++++++++++++++++++++------------ 2 files changed, 108 insertions(+), 36 deletions(-) diff --git a/drivers/acpi/osl.c b/drivers/acpi/osl.c index 3b8963f21b36..6341cb523dc4 100644 --- a/drivers/acpi/osl.c +++ b/drivers/acpi/osl.c @@ -83,6 +83,7 @@ static void *acpi_irq_context; static struct workqueue_struct *kacpid_wq; static struct workqueue_struct *kacpi_notify_wq; static struct workqueue_struct *kacpi_hotplug_wq; +static bool acpi_os_initialized; /* * This list of permanent mappings is for memory that may be accessed from @@ -1316,6 +1317,9 @@ acpi_status acpi_os_wait_semaphore(acpi_handle handle, u32 units, u16 timeout) long jiffies; int ret = 0; + if (!acpi_os_initialized) + return AE_OK; + if (!sem || (units < 1)) return AE_BAD_PARAMETER; @@ -1355,6 +1359,9 @@ acpi_status acpi_os_signal_semaphore(acpi_handle handle, u32 units) { struct semaphore *sem = (struct semaphore *)handle; + if (!acpi_os_initialized) + return AE_OK; + if (!sem || (units < 1)) return AE_BAD_PARAMETER; @@ -1863,6 +1870,7 @@ acpi_status __init acpi_os_initialize(void) rv = acpi_os_map_generic_address(&acpi_gbl_FADT.reset_register); pr_debug(PREFIX "%s: map reset_reg status %d\n", __func__, rv); } + acpi_os_initialized = true; return AE_OK; } diff --git a/drivers/acpi/sysfs.c b/drivers/acpi/sysfs.c index 7ab6ba46866f..8979e4a8d066 100644 --- a/drivers/acpi/sysfs.c +++ b/drivers/acpi/sysfs.c @@ -70,6 +70,7 @@ static const struct acpi_dlevel acpi_debug_levels[] = { ACPI_DEBUG_INIT(ACPI_LV_DEBUG_OBJECT), ACPI_DEBUG_INIT(ACPI_LV_INFO), ACPI_DEBUG_INIT(ACPI_LV_REPAIR), + ACPI_DEBUG_INIT(ACPI_LV_TRACE_POINT), ACPI_DEBUG_INIT(ACPI_LV_INIT_NAMES), ACPI_DEBUG_INIT(ACPI_LV_PARSE), @@ -163,55 +164,118 @@ static const struct kernel_param_ops param_ops_debug_level = { module_param_cb(debug_layer, ¶m_ops_debug_layer, &acpi_dbg_layer, 0644); module_param_cb(debug_level, ¶m_ops_debug_level, &acpi_dbg_level, 0644); -static char trace_method_name[6]; -module_param_string(trace_method_name, trace_method_name, 6, 0644); -static unsigned int trace_debug_layer; -module_param(trace_debug_layer, uint, 0644); -static unsigned int trace_debug_level; -module_param(trace_debug_level, uint, 0644); +static char* trace_method_name; +static bool trace_method_kmalloced; + +int param_set_trace_method_name(const char *val, const struct kernel_param *kp) +{ + u32 saved_flags = 0; + + if (strlen(val) > 1024) { + pr_err("%s: string parameter too long\n", kp->name); + return -ENOSPC; + } + + /* + * It's not safe to update acpi_gbl_trace_method_name without + * having the tracer stopped, so we save the original tracer + * state and disable it. + */ + saved_flags = acpi_gbl_trace_flags; + (void)acpi_debug_trace(NULL, + acpi_gbl_trace_dbg_level, + acpi_gbl_trace_dbg_layer, + 0); + + if (trace_method_kmalloced) + kfree(trace_method_name); + trace_method_name = NULL; + trace_method_kmalloced = false; + + /* This is a hack. We can't kmalloc in early boot. */ + if (slab_is_available()) { + trace_method_name = kstrdup(val, GFP_KERNEL); + if (!trace_method_name) + return -ENOMEM; + trace_method_kmalloced = true; + } else + trace_method_name = (char *)val; + + /* Restore the original tracer state */ + (void)acpi_debug_trace(trace_method_name, + acpi_gbl_trace_dbg_level, + acpi_gbl_trace_dbg_layer, + saved_flags); + + return 0; +} + +static int param_get_trace_method_name(char *buffer, const struct kernel_param *kp) +{ + return scnprintf(buffer, PAGE_SIZE, "%s", acpi_gbl_trace_method_name); +} + +static const struct kernel_param_ops param_ops_trace_method = { + .set = param_set_trace_method_name, + .get = param_get_trace_method_name, +}; + +static const struct kernel_param_ops param_ops_trace_attrib = { + .set = param_set_uint, + .get = param_get_uint, +}; + +module_param_cb(trace_method_name, ¶m_ops_trace_method, &trace_method_name, 0644); +module_param_cb(trace_debug_layer, ¶m_ops_trace_attrib, &acpi_gbl_trace_dbg_layer, 0644); +module_param_cb(trace_debug_level, ¶m_ops_trace_attrib, &acpi_gbl_trace_dbg_level, 0644); static int param_set_trace_state(const char *val, struct kernel_param *kp) { - int result = 0; + acpi_status status; + const char *method = trace_method_name; + u32 flags = 0; - if (!strncmp(val, "enable", sizeof("enable") - 1)) { - result = acpi_debug_trace(trace_method_name, trace_debug_level, - trace_debug_layer, 0); - if (result) - result = -EBUSY; - goto exit; - } +/* So "xxx-once" comparison should go prior than "xxx" comparison */ +#define acpi_compare_param(val, key) \ + strncmp((val), (key), sizeof(key) - 1) - if (!strncmp(val, "disable", sizeof("disable") - 1)) { - int name = 0; - result = acpi_debug_trace((char *)&name, trace_debug_level, - trace_debug_layer, 0); - if (result) - result = -EBUSY; - goto exit; - } + if (!acpi_compare_param(val, "enable")) { + method = NULL; + flags = ACPI_TRACE_ENABLED; + } else if (!acpi_compare_param(val, "disable")) + method = NULL; + else if (!acpi_compare_param(val, "method-once")) + flags = ACPI_TRACE_ENABLED | ACPI_TRACE_ONESHOT; + else if (!acpi_compare_param(val, "method")) + flags = ACPI_TRACE_ENABLED; + else if (!acpi_compare_param(val, "opcode-once")) + flags = ACPI_TRACE_ENABLED | ACPI_TRACE_ONESHOT | ACPI_TRACE_OPCODE; + else if (!acpi_compare_param(val, "opcode")) + flags = ACPI_TRACE_ENABLED | ACPI_TRACE_OPCODE; + else + return -EINVAL; - if (!strncmp(val, "1", 1)) { - result = acpi_debug_trace(trace_method_name, trace_debug_level, - trace_debug_layer, 1); - if (result) - result = -EBUSY; - goto exit; - } + status = acpi_debug_trace(method, + acpi_gbl_trace_dbg_level, + acpi_gbl_trace_dbg_layer, + flags); + if (ACPI_FAILURE(status)) + return -EBUSY; - result = -EINVAL; -exit: - return result; + return 0; } static int param_get_trace_state(char *buffer, struct kernel_param *kp) { - if (!acpi_gbl_trace_method_name) + if (!(acpi_gbl_trace_flags & ACPI_TRACE_ENABLED)) return sprintf(buffer, "disable"); else { - if (acpi_gbl_trace_flags & 1) - return sprintf(buffer, "1"); - else + if (acpi_gbl_trace_method_name) { + if (acpi_gbl_trace_flags & ACPI_TRACE_ONESHOT) + return sprintf(buffer, "method-once"); + else + return sprintf(buffer, "method"); + } else return sprintf(buffer, "enable"); } return 0; From a0186bcf7c21907c78ab2b4bc50f3fb2b5047806 Mon Sep 17 00:00:00 2001 From: Lv Zheng Date: Wed, 5 Aug 2015 16:23:57 +0800 Subject: [PATCH 3/4] ACPI / sysfs: Add support to allow leading "\" missing in trace_method_name. Since _SB.PCI0 can be used as relative path from root and can be easily converted into internal trace_method_name format, we allow users to specify trace_method_name using relative paths from root. Note this is useful for grub2 for which users failed to pass "\" from the grub configuration file. Signed-off-by: Lv Zheng Signed-off-by: Rafael J. Wysocki --- drivers/acpi/sysfs.c | 28 +++++++++++++--------------- 1 file changed, 13 insertions(+), 15 deletions(-) diff --git a/drivers/acpi/sysfs.c b/drivers/acpi/sysfs.c index 8979e4a8d066..40a42655227c 100644 --- a/drivers/acpi/sysfs.c +++ b/drivers/acpi/sysfs.c @@ -164,14 +164,18 @@ static const struct kernel_param_ops param_ops_debug_level = { module_param_cb(debug_layer, ¶m_ops_debug_layer, &acpi_dbg_layer, 0644); module_param_cb(debug_level, ¶m_ops_debug_level, &acpi_dbg_level, 0644); -static char* trace_method_name; -static bool trace_method_kmalloced; +static char trace_method_name[1024]; int param_set_trace_method_name(const char *val, const struct kernel_param *kp) { u32 saved_flags = 0; + bool is_abs_path = true; - if (strlen(val) > 1024) { + if (*val != '\\') + is_abs_path = false; + + if ((is_abs_path && strlen(val) > 1023) || + (!is_abs_path && strlen(val) > 1022)) { pr_err("%s: string parameter too long\n", kp->name); return -ENOSPC; } @@ -187,19 +191,13 @@ int param_set_trace_method_name(const char *val, const struct kernel_param *kp) acpi_gbl_trace_dbg_layer, 0); - if (trace_method_kmalloced) - kfree(trace_method_name); - trace_method_name = NULL; - trace_method_kmalloced = false; - /* This is a hack. We can't kmalloc in early boot. */ - if (slab_is_available()) { - trace_method_name = kstrdup(val, GFP_KERNEL); - if (!trace_method_name) - return -ENOMEM; - trace_method_kmalloced = true; - } else - trace_method_name = (char *)val; + if (is_abs_path) + strcpy(trace_method_name, val); + else { + trace_method_name[0] = '\\'; + strcpy(trace_method_name+1, val); + } /* Restore the original tracer state */ (void)acpi_debug_trace(trace_method_name, From cb4ff766c42f0511ead5488b8de77fd392677464 Mon Sep 17 00:00:00 2001 From: Lv Zheng Date: Wed, 5 Aug 2015 16:24:04 +0800 Subject: [PATCH 4/4] ACPI / Documentation: Update method tracing documentation. This patch updates method tracing documentation. Signed-off-by: Lv Zheng Signed-off-by: Rafael J. Wysocki --- Documentation/acpi/method-tracing.txt | 208 +++++++++++++++++++++++--- 1 file changed, 187 insertions(+), 21 deletions(-) diff --git a/Documentation/acpi/method-tracing.txt b/Documentation/acpi/method-tracing.txt index f6efb1ea559a..c2505eefc878 100644 --- a/Documentation/acpi/method-tracing.txt +++ b/Documentation/acpi/method-tracing.txt @@ -1,26 +1,192 @@ -/sys/module/acpi/parameters/: +ACPICA Trace Facility -trace_method_name - The AML method name that the user wants to trace +Copyright (C) 2015, Intel Corporation +Author: Lv Zheng -trace_debug_layer - The temporary debug_layer used when tracing the method. - Using 0xffffffff by default if it is 0. -trace_debug_level - The temporary debug_level used when tracing the method. - Using 0x00ffffff by default if it is 0. +Abstract: -trace_state +This document describes the functions and the interfaces of the method +tracing facility. + +1. Functionalities and usage examples: + + ACPICA provides method tracing capability. And two functions are + currently implemented using this capability. + + A. Log reducer + ACPICA subsystem provides debugging outputs when CONFIG_ACPI_DEBUG is + enabled. The debugging messages which are deployed via + ACPI_DEBUG_PRINT() macro can be reduced at 2 levels - per-component + level (known as debug layer, configured via + /sys/module/acpi/parameters/debug_layer) and per-type level (known as + debug level, configured via /sys/module/acpi/parameters/debug_level). + + But when the particular layer/level is applied to the control method + evaluations, the quantity of the debugging outputs may still be too + large to be put into the kernel log buffer. The idea thus is worked out + to only enable the particular debug layer/level (normally more detailed) + logs when the control method evaluation is started, and disable the + detailed logging when the control method evaluation is stopped. + + The following command examples illustrate the usage of the "log reducer" + functionality: + a. Filter out the debug layer/level matched logs when control methods + are being evaluated: + # cd /sys/module/acpi/parameters + # echo "0xXXXXXXXX" > trace_debug_layer + # echo "0xYYYYYYYY" > trace_debug_level + # echo "enable" > trace_state + b. Filter out the debug layer/level matched logs when the specified + control method is being evaluated: + # cd /sys/module/acpi/parameters + # echo "0xXXXXXXXX" > trace_debug_layer + # echo "0xYYYYYYYY" > trace_debug_level + # echo "\PPPP.AAAA.TTTT.HHHH" > trace_method_name + # echo "method" > /sys/module/acpi/parameters/trace_state + c. Filter out the debug layer/level matched logs when the specified + control method is being evaluated for the first time: + # cd /sys/module/acpi/parameters + # echo "0xXXXXXXXX" > trace_debug_layer + # echo "0xYYYYYYYY" > trace_debug_level + # echo "\PPPP.AAAA.TTTT.HHHH" > trace_method_name + # echo "method-once" > /sys/module/acpi/parameters/trace_state + Where: + 0xXXXXXXXX/0xYYYYYYYY: Refer to Documentation/acpi/debug.txt for + possible debug layer/level masking values. + \PPPP.AAAA.TTTT.HHHH: Full path of a control method that can be found + in the ACPI namespace. It needn't be an entry + of a control method evaluation. + + B. AML tracer + + There are special log entries added by the method tracing facility at + the "trace points" the AML interpreter starts/stops to execute a control + method, or an AML opcode. Note that the format of the log entries are + subject to change: + [ 0.186427] exdebug-0398 ex_trace_point : Method Begin [0xf58394d8:\_SB.PCI0.LPCB.ECOK] execution. + [ 0.186630] exdebug-0398 ex_trace_point : Opcode Begin [0xf5905c88:If] execution. + [ 0.186820] exdebug-0398 ex_trace_point : Opcode Begin [0xf5905cc0:LEqual] execution. + [ 0.187010] exdebug-0398 ex_trace_point : Opcode Begin [0xf5905a20:-NamePath-] execution. + [ 0.187214] exdebug-0398 ex_trace_point : Opcode End [0xf5905a20:-NamePath-] execution. + [ 0.187407] exdebug-0398 ex_trace_point : Opcode Begin [0xf5905f60:One] execution. + [ 0.187594] exdebug-0398 ex_trace_point : Opcode End [0xf5905f60:One] execution. + [ 0.187789] exdebug-0398 ex_trace_point : Opcode End [0xf5905cc0:LEqual] execution. + [ 0.187980] exdebug-0398 ex_trace_point : Opcode Begin [0xf5905cc0:Return] execution. + [ 0.188146] exdebug-0398 ex_trace_point : Opcode Begin [0xf5905f60:One] execution. + [ 0.188334] exdebug-0398 ex_trace_point : Opcode End [0xf5905f60:One] execution. + [ 0.188524] exdebug-0398 ex_trace_point : Opcode End [0xf5905cc0:Return] execution. + [ 0.188712] exdebug-0398 ex_trace_point : Opcode End [0xf5905c88:If] execution. + [ 0.188903] exdebug-0398 ex_trace_point : Method End [0xf58394d8:\_SB.PCI0.LPCB.ECOK] execution. + + Developers can utilize these special log entries to track the AML + interpretion, thus can aid issue debugging and performance tuning. Note + that, as the "AML tracer" logs are implemented via ACPI_DEBUG_PRINT() + macro, CONFIG_ACPI_DEBUG is also required to be enabled for enabling + "AML tracer" logs. + + The following command examples illustrate the usage of the "AML tracer" + functionality: + a. Filter out the method start/stop "AML tracer" logs when control + methods are being evaluated: + # cd /sys/module/acpi/parameters + # echo "0x80" > trace_debug_layer + # echo "0x10" > trace_debug_level + # echo "enable" > trace_state + b. Filter out the method start/stop "AML tracer" when the specified + control method is being evaluated: + # cd /sys/module/acpi/parameters + # echo "0x80" > trace_debug_layer + # echo "0x10" > trace_debug_level + # echo "\PPPP.AAAA.TTTT.HHHH" > trace_method_name + # echo "method" > trace_state + c. Filter out the method start/stop "AML tracer" logs when the specified + control method is being evaluated for the first time: + # cd /sys/module/acpi/parameters + # echo "0x80" > trace_debug_layer + # echo "0x10" > trace_debug_level + # echo "\PPPP.AAAA.TTTT.HHHH" > trace_method_name + # echo "method-once" > trace_state + d. Filter out the method/opcode start/stop "AML tracer" when the + specified control method is being evaluated: + # cd /sys/module/acpi/parameters + # echo "0x80" > trace_debug_layer + # echo "0x10" > trace_debug_level + # echo "\PPPP.AAAA.TTTT.HHHH" > trace_method_name + # echo "opcode" > trace_state + e. Filter out the method/opcode start/stop "AML tracer" when the + specified control method is being evaluated for the first time: + # cd /sys/module/acpi/parameters + # echo "0x80" > trace_debug_layer + # echo "0x10" > trace_debug_level + # echo "\PPPP.AAAA.TTTT.HHHH" > trace_method_name + # echo "opcode-opcode" > trace_state + + Note that all above method tracing facility related module parameters can + be used as the boot parameters, for example: + acpi.trace_debug_layer=0x80 acpi.trace_debug_level=0x10 \ + acpi.trace_method_name=\_SB.LID0._LID acpi.trace_state=opcode-once + +2. Interface descriptions: + + All method tracing functions can be configured via ACPI module + parameters that are accessible at /sys/module/acpi/parameters/: + + trace_method_name + The full path of the AML method that the user wants to trace. + Note that the full path shouldn't contain the trailing "_"s in its + name segments but may contain "\" to form an absolute path. + + trace_debug_layer + The temporary debug_layer used when the tracing feature is enabled. + Using ACPI_EXECUTER (0x80) by default, which is the debug_layer + used to match all "AML tracer" logs. + + trace_debug_level + The temporary debug_level used when the tracing feature is enabled. + Using ACPI_LV_TRACE_POINT (0x10) by default, which is the + debug_level used to match all "AML tracer" logs. + + trace_state The status of the tracing feature. - - "enabled" means this feature is enabled - and the AML method is traced every time it's executed. - - "1" means this feature is enabled and the AML method - will only be traced during the next execution. - - "disabled" means this feature is disabled. - Users can enable/disable this debug tracing feature by - "echo string > /sys/module/acpi/parameters/trace_state". - "string" should be one of "enable", "disable" and "1". + Users can enable/disable this debug tracing feature by executing + the following command: + # echo string > /sys/module/acpi/parameters/trace_state + Where "string" should be one of the followings: + "disable" + Disable the method tracing feature. + "enable" + Enable the method tracing feature. + ACPICA debugging messages matching + "trace_debug_layer/trace_debug_level" during any method + execution will be logged. + "method" + Enable the method tracing feature. + ACPICA debugging messages matching + "trace_debug_layer/trace_debug_level" during method execution + of "trace_method_name" will be logged. + "method-once" + Enable the method tracing feature. + ACPICA debugging messages matching + "trace_debug_layer/trace_debug_level" during method execution + of "trace_method_name" will be logged only once. + "opcode" + Enable the method tracing feature. + ACPICA debugging messages matching + "trace_debug_layer/trace_debug_level" during method/opcode + execution of "trace_method_name" will be logged. + "opcode-once" + Enable the method tracing feature. + ACPICA debugging messages matching + "trace_debug_layer/trace_debug_level" during method/opcode + execution of "trace_method_name" will be logged only once. + Note that, the difference between the "enable" and other feature + enabling options are: + 1. When "enable" is specified, since + "trace_debug_layer/trace_debug_level" shall apply to all control + method evaluations, after configuring "trace_state" to "enable", + "trace_method_name" will be reset to NULL. + 2. When "method/opcode" is specified, if + "trace_method_name" is NULL when "trace_state" is configured to + these options, the "trace_debug_layer/trace_debug_level" will + apply to all control method evaluations.