Merge branch 'acpi-trace'

* acpi-trace:
  ACPI / Documentation: Update method tracing documentation.
  ACPI / sysfs: Add support to allow leading "\" missing in trace_method_name.
  ACPI / sysfs: Update method tracing facility.
  ACPI / sysfs: Add ACPI_LV_REPAIR debug level.

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 <lv.zheng@intel.com>
 
-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
-	The status of the tracing feature.
+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.
 
-	"enabled" means this feature is enabled
-	and the AML method is traced every time it's executed.
+   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.
 
-	"1" means this feature is enabled and the AML method
-	will only be traced during the next execution.
+   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
 
-	"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".
+  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.
+	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.

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;
 }

drivers/acpi/sysfs.c

@@ -69,6 +69,8 @@ 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_TRACE_POINT),
 
 	ACPI_DEBUG_INIT(ACPI_LV_INIT_NAMES),
 	ACPI_DEBUG_INIT(ACPI_LV_PARSE),
@@ -162,55 +164,116 @@ static const struct kernel_param_ops param_ops_debug_level = {
 module_param_cb(debug_layer, &param_ops_debug_layer, &acpi_dbg_layer, 0644);
 module_param_cb(debug_level, &param_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[1024];
 
-static int param_set_trace_state(const char *val, struct kernel_param *kp)
+int param_set_trace_method_name(const char *val, const struct kernel_param *kp)
 {
-	int result = 0;
+	u32 saved_flags = 0;
+	bool is_abs_path = true;
 
-	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;
-	}
+	if (*val != '\\')
+		is_abs_path = false;
 
-	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 ((is_abs_path && strlen(val) > 1023) ||
+	    (!is_abs_path && strlen(val) > 1022)) {
+		pr_err("%s: string parameter too long\n", kp->name);
+		return -ENOSPC;
 	}
 
-	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;
+	/*
+	 * 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);
+
+	/* This is a hack.  We can't kmalloc in early boot. */
+	if (is_abs_path)
+		strcpy(trace_method_name, val);
+	else {
+		trace_method_name[0] = '\\';
+		strcpy(trace_method_name+1, val);
 	}
 
-	result = -EINVAL;
-exit:
-	return result;
+	/* 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, &param_ops_trace_method, &trace_method_name, 0644);
+module_param_cb(trace_debug_layer, &param_ops_trace_attrib, &acpi_gbl_trace_dbg_layer, 0644);
+module_param_cb(trace_debug_level, &param_ops_trace_attrib, &acpi_gbl_trace_dbg_level, 0644);
+
+static int param_set_trace_state(const char *val, struct kernel_param *kp)
+{
+	acpi_status status;
+	const char *method = trace_method_name;
+	u32 flags = 0;
+
+/* So "xxx-once" comparison should go prior than "xxx" comparison */
+#define acpi_compare_param(val, key)	\
+	strncmp((val), (key), sizeof(key) - 1)
+
+	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;
+
+	status = acpi_debug_trace(method,
+				  acpi_gbl_trace_dbg_level,
+				  acpi_gbl_trace_dbg_layer,
+				  flags);
+	if (ACPI_FAILURE(status))
+		return -EBUSY;
+
+	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;