ACPICA: Debug output: Add option to display method/object evaluation

Adds entry/exit messages for all objects that are evaluated.
Works for the kernel-level code as well as acpiexec. The "-eo"
flag enables acpiexec to display these messages.

The messages are very useful when debugging the flow of table
initialization.

Signed-off-by: Bob Moore <robert.moore@intel.com>
Signed-off-by: Erik Schmauss <erik.schmauss@intel.com>
Signed-off-by: Rafael J. Wysocki <rafael.j.wysocki@intel.com>

drivers/acpi/acpica/acstruct.h

@@ -60,6 +60,8 @@ struct acpi_walk_state {
 	struct acpi_parse_state parser_state;	/* Current state of parser */
 	u32 prev_arg_types;
 	u32 arg_count;		/* push for fixed or var args */
+	u16 method_nesting_depth;
+	u8 method_is_nested;
 
 	struct acpi_namespace_node arguments[ACPI_METHOD_NUM_ARGS];	/* Control method arguments */
 	struct acpi_namespace_node local_variables[ACPI_METHOD_NUM_LOCALS];	/* Control method locals */
@@ -74,7 +76,8 @@ struct acpi_walk_state {
 	struct acpi_namespace_node *method_call_node;	/* Called method Node */
 	union acpi_parse_object *method_call_op;	/* method_call Op if running a method */
 	union acpi_operand_object *method_desc;	/* Method descriptor if running a method */
-	struct acpi_namespace_node *method_node;	/* Method node if running a method. */
+	struct acpi_namespace_node *method_node;	/* Method node if running a method */
+	char *method_pathname;	/* Full pathname of running method */
 	union acpi_parse_object *op;	/* Current parser op */
 	const struct acpi_opcode_info *op_info;	/* Info on current opcode */
 	union acpi_parse_object *origin;	/* Start of walk [Obsolete] */

drivers/acpi/acpica/dsmethod.c

@@ -532,6 +532,9 @@ acpi_ds_call_control_method(struct acpi_thread_state *thread,
 		goto cleanup;
 	}
 
+	next_walk_state->method_nesting_depth =
+	    this_walk_state->method_nesting_depth + 1;
+
 	/*
 	 * Delete the operands on the previous walkstate operand stack
 	 * (they were copied to new objects)
@@ -549,6 +552,17 @@ acpi_ds_call_control_method(struct acpi_thread_state *thread,
 			  "**** Begin nested execution of [%4.4s] **** WalkState=%p\n",
 			  method_node->name.ascii, next_walk_state));
 
+	this_walk_state->method_pathname =
+	    acpi_ns_get_normalized_pathname(method_node, TRUE);
+	this_walk_state->method_is_nested = TRUE;
+
+	/* Optional object evaluation log */
+
+	ACPI_DEBUG_PRINT_RAW((ACPI_DB_EVALUATION,
+			      "%-26s:  %*s%s\n", "   Nested method call",
+			      next_walk_state->method_nesting_depth * 3, " ",
+			      &this_walk_state->method_pathname[1]));
+
 	/* Invoke an internal method if necessary */
 
 	if (obj_desc->method.info_flags & ACPI_METHOD_INTERNAL_ONLY) {

drivers/acpi/acpica/nseval.c

@@ -104,6 +104,13 @@ acpi_status acpi_ns_evaluate(struct acpi_evaluate_info *info)
 		return_ACPI_STATUS(AE_NO_MEMORY);
 	}
 
+	/* Optional object evaluation log */
+
+	ACPI_DEBUG_PRINT_RAW((ACPI_DB_EVALUATION,
+			      "%-26s:  %s (%s)\n", "   Enter evaluation",
+			      &info->full_pathname[1],
+			      acpi_ut_get_type_name(info->node->type)));
+
 	/* Count the number of arguments being passed in */
 
 	info->param_count = 0;
@@ -289,6 +296,12 @@ acpi_status acpi_ns_evaluate(struct acpi_evaluate_info *info)
 			  info->relative_pathname));
 
 cleanup:
+	/* Optional object evaluation log */
+
+	ACPI_DEBUG_PRINT_RAW((ACPI_DB_EVALUATION,
+			      "%-26s:  %s\n", "   Exit evaluation",
+			      &info->full_pathname[1]));
+
 	/*
 	 * Namespace was unlocked by the handling acpi_ns* function, so we
 	 * just free the pathname and return

drivers/acpi/acpica/nsparse.c

@@ -107,8 +107,20 @@ acpi_ns_execute_table(u32 table_index, struct acpi_namespace_node *start_node)
 		goto cleanup;
 	}
 
+	/* Optional object evaluation log */
+
+	ACPI_DEBUG_PRINT_RAW((ACPI_DB_EVALUATION,
+			      "%-26s:  (Definition Block level)\n",
+			      "Module-level evaluation"));
+
 	status = acpi_ps_execute_table(info);
 
+	/* Optional object evaluation log */
+
+	ACPI_DEBUG_PRINT_RAW((ACPI_DB_EVALUATION,
+			      "%-26s:  (Definition Block level)\n",
+			      "Module-level complete"));
+
 cleanup:
 	if (info) {
 		ACPI_FREE(info->full_pathname);

drivers/acpi/acpica/psparse.c

@@ -479,6 +479,21 @@ acpi_status acpi_ps_parse_aml(struct acpi_walk_state *walk_state)
 				  "Completed one call to walk loop, %s State=%p\n",
 				  acpi_format_exception(status), walk_state));
 
+		if (walk_state->method_pathname && walk_state->method_is_nested) {
+
+			/* Optional object evaluation log */
+
+			ACPI_DEBUG_PRINT_RAW((ACPI_DB_EVALUATION,
+					      "%-26s:  %*s%s\n",
+					      "   Exit nested method",
+					      (walk_state->
+					       method_nesting_depth + 1) * 3,
+					      " ",
+					      &walk_state->method_pathname[1]));
+
+			ACPI_FREE(walk_state->method_pathname);
+			walk_state->method_is_nested = FALSE;
+		}
 		if (status == AE_CTRL_TRANSFER) {
 			/*
 			 * A method call was detected.

drivers/acpi/acpica/psxface.c

@@ -147,6 +147,9 @@ acpi_status acpi_ps_execute_method(struct acpi_evaluate_info *info)
 		goto cleanup;
 	}
 
+	walk_state->method_pathname = info->full_pathname;
+	walk_state->method_is_nested = FALSE;
+
 	if (info->obj_desc->method.info_flags & ACPI_METHOD_MODULE_LEVEL) {
 		walk_state->parse_flags |= ACPI_PARSE_MODULE_LEVEL;
 	}
@@ -267,6 +270,9 @@ acpi_status acpi_ps_execute_table(struct acpi_evaluate_info *info)
 		goto cleanup;
 	}
 
+	walk_state->method_pathname = info->full_pathname;
+	walk_state->method_is_nested = FALSE;
+
 	if (info->obj_desc->method.info_flags & ACPI_METHOD_MODULE_LEVEL) {
 		walk_state->parse_flags |= ACPI_PARSE_MODULE_LEVEL;
 	}

include/acpi/acoutput.h

@@ -73,7 +73,8 @@
 #define ACPI_LV_RESOURCES           0x00010000
 #define ACPI_LV_USER_REQUESTS       0x00020000
 #define ACPI_LV_PACKAGE             0x00040000
-#define ACPI_LV_VERBOSITY1          0x0007FF40 | ACPI_LV_ALL_EXCEPTIONS
+#define ACPI_LV_EVALUATION          0x00080000
+#define ACPI_LV_VERBOSITY1          0x000FFF40 | ACPI_LV_ALL_EXCEPTIONS
 
 /* Trace verbosity level 2 [Function tracing and memory allocation] */
 
@@ -141,6 +142,7 @@
 #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_EVALUATION          ACPI_DEBUG_LEVEL (ACPI_LV_EVALUATION)
 #define ACPI_DB_MUTEX               ACPI_DEBUG_LEVEL (ACPI_LV_MUTEX)
 #define ACPI_DB_EVENTS              ACPI_DEBUG_LEVEL (ACPI_LV_EVENTS)
 
@@ -148,7 +150,7 @@
 
 /* Defaults for debug_level, debug and normal */
 
-#define ACPI_DEBUG_DEFAULT          (ACPI_LV_INFO | ACPI_LV_REPAIR)
+#define ACPI_DEBUG_DEFAULT          (ACPI_LV_INIT | ACPI_LV_DEBUG_OBJECT | ACPI_LV_EVALUATION | 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)