refactor(logging): modify RMI/RSI commands logging

Number of input arguments and output values is
now encoded in 'rmi_type' of the handler.
Logging of RMI & RSI commands is modified to only
print supported input arguments.
For RMI commands output values are logged only
in case of RMI_SUCCESS return status.
Added logging of output values for RSI and PSCI
commands.
Minor changes to comply with MISRA-C and coding
style.

Logging examples from FVP model running TFTF tests:

SMC_RMM_VERSION               > 380000
SMC_RMM_FEATURES              0 > RMI_SUCCESS 3fc00030
SMC_RMM_REALM_CREATE          88c00000 88c02000 > RMI_SUCCESS
SMC_RMM_REC_AUX_COUNT         88c00000 > RMI_SUCCESS 10
SMC_RMM_RTT_INIT_RIPAS        88c00000 88b00000 3 > RMI_ERROR_RTT 0
SMC_RMM_REC_CREATE            88c07000 88c00000 88c08000 > RMI_SUCCESS
SMC_RMM_REALM_ACTIVATE        88c00000 > RMI_SUCCESS
SMC_RSI_HOST_CALL             88b07000
SMC_RMM_REC_DESTROY           88c07000 > RMI_SUCCESS
SMC_RMM_REALM_DESTROY         88c00000 > RMI_SUCCESS
SMC_RMM_VERSION               > 380000
SMC_RMM_GRANULE_DELEGATE      8801a000 > RMI_ERROR_INPUT
SMC_RMM_GRANULE_UNDELEGATE    8801a001 > RMI_ERROR_INPUT
SMC_RMM_FEATURES              0 > RMI_SUCCESS 3fc00030
SMC_RMM_REALM_CREATE          88c00000 88c02000 > RMI_SUCCESS
SMC_RMM_REC_AUX_COUNT         88c00000 > RMI_SUCCESS 10
SMC_RMM_RTT_INIT_RIPAS        88c00000 88b00000 3 > RMI_ERROR_RTT 0
SMC_RMM_REC_CREATE            88c07000 88c00000 88c08000 > RMI_SUCCESS
SMC_RSI_ABI_VERSION           > c0000

Signed-off-by: AlexeiFedorov <Alexei.Fedorov@arm.com>
Change-Id: Ie53c6450495e49136f0a39752182363e7c93f09f
diff --git a/runtime/core/handler.c b/runtime/core/handler.c
index 93e9927..77c1517 100644
--- a/runtime/core/handler.c
+++ b/runtime/core/handler.c
@@ -15,28 +15,33 @@
 #include <status.h>
 #include <utils_def.h>
 
-#define STATUS_HANDLER(_id)[_id] = #_id
+/* Maximum number of supported arguments */
+#define MAX_NUM_ARGS		5
 
-const char *status_handler[] = {
-	STATUS_HANDLER(RMI_SUCCESS),
-	STATUS_HANDLER(RMI_ERROR_INPUT),
-	STATUS_HANDLER(RMI_ERROR_REALM),
-	STATUS_HANDLER(RMI_ERROR_REC),
-	STATUS_HANDLER(RMI_ERROR_RTT),
-	STATUS_HANDLER(RMI_ERROR_IN_USE)
+/* Maximum number of output values */
+#define MAX_NUM_OUTPUT_VALS	4
+
+#define RMI_STATUS_STRING(_id)[RMI_##_id] = #_id
+
+const char *rmi_status_string[] = {
+	RMI_STATUS_STRING(SUCCESS),
+	RMI_STATUS_STRING(ERROR_INPUT),
+	RMI_STATUS_STRING(ERROR_REALM),
+	RMI_STATUS_STRING(ERROR_REC),
+	RMI_STATUS_STRING(ERROR_RTT),
+	RMI_STATUS_STRING(ERROR_IN_USE)
 };
-COMPILER_ASSERT(ARRAY_LEN(status_handler) == RMI_ERROR_COUNT);
+COMPILER_ASSERT(ARRAY_LEN(rmi_status_string) == RMI_ERROR_COUNT);
 
 /*
  * At this level (in handle_ns_smc) we distinguish the RMI calls only on:
- * - The number of input arguments [0..4], and whether
+ * - The number of input arguments [0..5], and whether
  * - The function returns up to three output values in addition
  *   to the return status code.
  * Hence, the naming syntax is:
- * - `*_[0..4]` when no output values are returned, and
- * - `*_[0..4]_o` when the function returns some output values.
+ * - `*_[0..5]` when no output values are returned, and
+ * - `*_[0..3]_o` when the function returns some output values.
  */
-
 typedef unsigned long (*handler_0)(void);
 typedef unsigned long (*handler_1)(unsigned long arg0);
 typedef unsigned long (*handler_2)(unsigned long arg0, unsigned long arg1);
@@ -51,103 +56,85 @@
 typedef void (*handler_3_o)(unsigned long arg0, unsigned long arg1,
 			    unsigned long arg2, struct smc_result *ret);
 
+/*
+ * SMC RMI handler type encoding:
+ * [0:7]  - number of arguments
+ * [8:15] - number of output values
+ */
+#define RMI_TYPE(_in, _out)	(_in | (_out << 8))
+#define rmi_type(_in, _out)	rmi_type_##_in##_out = RMI_TYPE(_in, _out)
+
 enum rmi_type {
-	rmi_type_0,
-	rmi_type_1,
-	rmi_type_2,
-	rmi_type_3,
-	rmi_type_4,
-	rmi_type_5,
-	rmi_type_1_o,
-	rmi_type_3_o
+	rmi_type(0, 0),	/* 0 arguments, 0 output values */
+	rmi_type(1, 0),	/* 1 argument,  0 output values */
+	rmi_type(2, 0),	/* 2 arguments, 0 output values */
+	rmi_type(3, 0),	/* 3 arguments, 0 output values */
+	rmi_type(4, 0),	/* 4 arguments, 0 output values */
+	rmi_type(5, 0),	/* 5 arguments, 0 output values */
+	rmi_type(1, 1), /* 1 argument,  1 output value */
+	rmi_type(3, 4)	/* 3 arguments, 4 output values */
 };
 
 struct smc_handler {
 	const char	*fn_name;
 	enum rmi_type	type;
 	union {
-		handler_0	f0;
-		handler_1	f1;
-		handler_2	f2;
-		handler_3	f3;
-		handler_4	f4;
-		handler_5	f5;
-		handler_1_o	f1_o;
-		handler_3_o	f3_o;
+		handler_0	f_00;
+		handler_1	f_10;
+		handler_2	f_20;
+		handler_3	f_30;
+		handler_4	f_40;
+		handler_5	f_50;
+		handler_1_o	f_11;
+		handler_3_o	f_34;
 		void		*fn_dummy;
 	};
 	bool		log_exec;	/* print handler execution */
 	bool		log_error;	/* print in case of error status */
-	unsigned int	out_values;	/* number of output values */
 };
 
 /*
  * Get handler ID from FID
  * Precondition: FID is an RMI call
  */
-#define SMC_RMI_HANDLER_ID(_fid) SMC64_FID_OFFSET_FROM_RANGE_MIN(RMI, _fid)
+#define RMI_HANDLER_ID(_id)	SMC64_FID_OFFSET_FROM_RANGE_MIN(RMI, _id)
 
-#define HANDLER_0(_id, _fn, _exec, _error)[SMC_RMI_HANDLER_ID(_id)] = { \
-	.fn_name = #_id, \
-	.type = rmi_type_0, .f0 = _fn, .log_exec = _exec, .log_error = _error,	   \
-	.out_values = 0U }
-#define HANDLER_1(_id, _fn, _exec, _error)[SMC_RMI_HANDLER_ID(_id)] = { \
-	.fn_name = #_id, \
-	.type = rmi_type_1, .f1 = _fn, .log_exec = _exec, .log_error = _error,	   \
-	.out_values = 0U }
-#define HANDLER_2(_id, _fn, _exec, _error)[SMC_RMI_HANDLER_ID(_id)] = { \
-	.fn_name = #_id, \
-	.type = rmi_type_2, .f2 = _fn, .log_exec = _exec, .log_error = _error,     \
-	.out_values = 0U }
-#define HANDLER_3(_id, _fn, _exec, _error)[SMC_RMI_HANDLER_ID(_id)] = { \
-	.fn_name = #_id, \
-	.type = rmi_type_3, .f3 = _fn, .log_exec = _exec, .log_error = _error,	   \
-	.out_values = 0U }
-#define HANDLER_4(_id, _fn, _exec, _error)[SMC_RMI_HANDLER_ID(_id)] = { \
-	.fn_name = #_id, \
-	.type = rmi_type_4, .f4 = _fn, .log_exec = _exec, .log_error = _error,	   \
-	.out_values = 0U }
-#define HANDLER_5(_id, _fn, _exec, _error)[SMC_RMI_HANDLER_ID(_id)] = { \
-	.fn_name = #_id, \
-	.type = rmi_type_5, .f5 = _fn, .log_exec = _exec, .log_error = _error,	   \
-	.out_values = 0U }
-#define HANDLER_1_O(_id, _fn, _exec, _error, _values)[SMC_RMI_HANDLER_ID(_id)] = { \
-	.fn_name = #_id, \
-	.type = rmi_type_1_o, .f1_o = _fn, .log_exec = _exec, .log_error = _error, \
-	.out_values = _values }
-#define HANDLER_3_O(_id, _fn, _exec, _error, _values)[SMC_RMI_HANDLER_ID(_id)] = { \
-	.fn_name = #_id, \
-	.type = rmi_type_3_o, .f3_o = _fn, .log_exec = _exec, .log_error = _error, \
-	.out_values = _values }
+#define HANDLER(_id, _in, _out, _fn, _exec, _error)[RMI_HANDLER_ID(SMC_RMM_##_id)] = { \
+	.fn_name = #_id,		\
+	.type = RMI_TYPE(_in, _out),	\
+	.f_##_in##_out = _fn,		\
+	.log_exec = _exec,		\
+	.log_error = _error		\
+}
 
 /*
  * The 3rd value enables the execution log.
  * The 4th value enables the error log.
  */
 static const struct smc_handler smc_handlers[] = {
-	HANDLER_0(SMC_RMM_VERSION,		 smc_version,			true,  true),
-	HANDLER_1_O(SMC_RMM_FEATURES,		 smc_read_feature_register,	true,  true, 1U),
-	HANDLER_1(SMC_RMM_GRANULE_DELEGATE,	 smc_granule_delegate,		false, true),
-	HANDLER_1(SMC_RMM_GRANULE_UNDELEGATE,	 smc_granule_undelegate,	false, true),
-	HANDLER_2(SMC_RMM_REALM_CREATE,		 smc_realm_create,		true,  true),
-	HANDLER_1(SMC_RMM_REALM_DESTROY,	 smc_realm_destroy,		true,  true),
-	HANDLER_1(SMC_RMM_REALM_ACTIVATE,	 smc_realm_activate,		true,  true),
-	HANDLER_3(SMC_RMM_REC_CREATE,		 smc_rec_create,		true,  true),
-	HANDLER_1(SMC_RMM_REC_DESTROY,		 smc_rec_destroy,		true,  true),
-	HANDLER_2(SMC_RMM_REC_ENTER,		 smc_rec_enter,			false, true),
-	HANDLER_5(SMC_RMM_DATA_CREATE,		 smc_data_create,		false, false),
-	HANDLER_3(SMC_RMM_DATA_CREATE_UNKNOWN,	 smc_data_create_unknown,	false, false),
-	HANDLER_2(SMC_RMM_DATA_DESTROY,		 smc_data_destroy,		false, true),
-	HANDLER_4(SMC_RMM_RTT_CREATE,		 smc_rtt_create,		false, true),
-	HANDLER_4(SMC_RMM_RTT_DESTROY,		 smc_rtt_destroy,		false, true),
-	HANDLER_4(SMC_RMM_RTT_FOLD,		 smc_rtt_fold,			false, true),
-	HANDLER_4(SMC_RMM_RTT_MAP_UNPROTECTED,	 smc_rtt_map_unprotected,	false, false),
-	HANDLER_3(SMC_RMM_RTT_UNMAP_UNPROTECTED, smc_rtt_unmap_unprotected,	false, false),
-	HANDLER_3_O(SMC_RMM_RTT_READ_ENTRY,	 smc_rtt_read_entry,		false, true, 4U),
-	HANDLER_2(SMC_RMM_PSCI_COMPLETE,	 smc_psci_complete,		true,  true),
-	HANDLER_1_O(SMC_RMM_REC_AUX_COUNT,	 smc_rec_aux_count,		true,  true, 1U),
-	HANDLER_3(SMC_RMM_RTT_INIT_RIPAS,	 smc_rtt_init_ripas,		false, true),
-	HANDLER_5(SMC_RMM_RTT_SET_RIPAS,	 smc_rtt_set_ripas,		false, true)
+	HANDLER(VERSION,		0, 0, smc_version,		 true,  true),
+	HANDLER(FEATURES,		1, 1, smc_read_feature_register, true,  true),
+	HANDLER(GRANULE_DELEGATE,	1, 0, smc_granule_delegate,	 false, true),
+	HANDLER(GRANULE_UNDELEGATE,	1, 0, smc_granule_undelegate,	 false, true),
+	HANDLER(REALM_CREATE,		2, 0, smc_realm_create,		 true,  true),
+	HANDLER(REALM_DESTROY,		1, 0, smc_realm_destroy,	 true,  true),
+	HANDLER(REALM_ACTIVATE,		1, 0, smc_realm_activate,	 true,  true),
+	HANDLER(REC_CREATE,		3, 0, smc_rec_create,		 true,  true),
+	HANDLER(REC_DESTROY,		1, 0, smc_rec_destroy,		 true,  true),
+	HANDLER(REC_ENTER,		2, 0, smc_rec_enter,		 false, true),
+	HANDLER(DATA_CREATE,		5, 0, smc_data_create,		 false, false),
+	HANDLER(DATA_CREATE_UNKNOWN,	3, 0, smc_data_create_unknown,	 false, false),
+	HANDLER(DATA_DESTROY,		2, 0, smc_data_destroy,		 false, true),
+	HANDLER(RTT_CREATE,		4, 0, smc_rtt_create,		 false, true),
+	HANDLER(RTT_DESTROY,		4, 0, smc_rtt_destroy,		 false, true),
+	HANDLER(RTT_FOLD,		4, 0, smc_rtt_fold,		 false, true),
+	HANDLER(RTT_MAP_UNPROTECTED,	4, 0, smc_rtt_map_unprotected,	 false, false),
+	HANDLER(RTT_UNMAP_UNPROTECTED,	3, 0, smc_rtt_unmap_unprotected, false, false),
+	HANDLER(RTT_READ_ENTRY,		3, 4, smc_rtt_read_entry,	 false, true),
+	HANDLER(PSCI_COMPLETE,		2, 0, smc_psci_complete,	 true,  true),
+	HANDLER(REC_AUX_COUNT,		1, 1, smc_rec_aux_count,	 true,  true),
+	HANDLER(RTT_INIT_RIPAS,		3, 0, smc_rtt_init_ripas,	 false, true),
+	HANDLER(RTT_SET_RIPAS,		5, 0, smc_rtt_set_ripas,	 false, true)
 };
 
 COMPILER_ASSERT(ARRAY_LEN(smc_handlers) == SMC64_NUM_FIDS_IN_RANGE(RMI));
@@ -155,16 +142,13 @@
 static bool rmi_call_log_enabled = true;
 
 static void rmi_log_on_exit(unsigned long handler_id,
-			    unsigned long arg0,
-			    unsigned long arg1,
-			    unsigned long arg2,
-			    unsigned long arg3,
-			    unsigned long arg4,
+			    unsigned long args[],
 			    struct smc_result *ret)
 {
 	const struct smc_handler *handler = &smc_handlers[handler_id];
 	unsigned long function_id = SMC64_RMI_FID(handler_id);
 	return_code_t rc;
+	unsigned int num;
 
 	if (!handler->log_exec && !handler->log_error) {
 		return;
@@ -175,9 +159,7 @@
 		 * RMM_VERSION is special because it returns the
 		 * version number, not the error code.
 		 */
-		INFO("%-29s %8lx %8lx %8lx %8lx %8lx > %lx\n",
-		     handler->fn_name, arg0, arg1, arg2, arg3, arg4,
-		     ret->x[0]);
+		INFO("SMC_RMM_%-21s > %lx\n", handler->fn_name, ret->x[0]);
 		return;
 	}
 
@@ -185,12 +167,22 @@
 
 	if ((handler->log_exec) ||
 	    (handler->log_error && (rc.status != RMI_SUCCESS))) {
-		INFO("%-29s %8lx %8lx %8lx %8lx %8lx > ",
-			handler->fn_name, arg0, arg1, arg2, arg3, arg4);
+		/* Print function name */
+		INFO("SMC_RMM_%-21s", handler->fn_name);
+
+		/* Print arguments */
+		num = handler->type & 0xFF;
+		assert(num <= MAX_NUM_ARGS);
+
+		for (unsigned int i = 0U; i < num; i++) {
+			INFO(" %lx", args[i]);
+		}
+
+		/* Print status */
 		if (rc.status >= RMI_ERROR_COUNT) {
-			INFO("%lx", ret->x[0]);
+			INFO(" > %lx", ret->x[0]);
 		} else {
-			INFO("%s", status_handler[rc.status]);
+			INFO(" > RMI_%s", rmi_status_string[rc.status]);
 		}
 
 		/* Check for index */
@@ -198,13 +190,15 @@
 		     (rc.status == RMI_ERROR_REALM)) ||
 		     (rc.status == RMI_ERROR_RTT)) {
 			INFO(" %x", rc.index);
-		}
+		} else if (rc.status == RMI_SUCCESS) {
+			/* Print output values */
+			num = (handler->type >> 8) & 0xFF;
+			assert(num <= MAX_NUM_OUTPUT_VALS);
 
-		/* Print output values */
-		for (unsigned int i = 1U; i <= handler->out_values; i++) {
-			INFO(" %8lx", ret->x[i]);
+			for (unsigned int i = 1U; i <= num; i++) {
+				INFO(" %lx", ret->x[i]);
+			}
 		}
-
 		INFO("\n");
 	}
 }
@@ -225,7 +219,7 @@
 	function_id &= ~MASK(SMC_SVE_HINT);
 
 	if (IS_SMC64_RMI_FID(function_id)) {
-		handler_id = SMC_RMI_HANDLER_ID(function_id);
+		handler_id = RMI_HANDLER_ID(function_id);
 		if (handler_id < ARRAY_LEN(smc_handlers)) {
 			handler = &smc_handlers[handler_id];
 		}
@@ -245,36 +239,38 @@
 	assert_cpu_slots_empty();
 
 	switch (handler->type) {
-	case rmi_type_0:
-		ret->x[0] = handler->f0();
+	case rmi_type_00:
+		ret->x[0] = handler->f_00();
 		break;
-	case rmi_type_1:
-		ret->x[0] = handler->f1(arg0);
+	case rmi_type_10:
+		ret->x[0] = handler->f_10(arg0);
 		break;
-	case rmi_type_2:
-		ret->x[0] = handler->f2(arg0, arg1);
+	case rmi_type_20:
+		ret->x[0] = handler->f_20(arg0, arg1);
 		break;
-	case rmi_type_3:
-		ret->x[0] = handler->f3(arg0, arg1, arg2);
+	case rmi_type_30:
+		ret->x[0] = handler->f_30(arg0, arg1, arg2);
 		break;
-	case rmi_type_4:
-		ret->x[0] = handler->f4(arg0, arg1, arg2, arg3);
+	case rmi_type_40:
+		ret->x[0] = handler->f_40(arg0, arg1, arg2, arg3);
 		break;
-	case rmi_type_5:
-		ret->x[0] = handler->f5(arg0, arg1, arg2, arg3, arg4);
+	case rmi_type_50:
+		ret->x[0] = handler->f_50(arg0, arg1, arg2, arg3, arg4);
 		break;
-	case rmi_type_1_o:
-		handler->f1_o(arg0, ret);
+	case rmi_type_11:
+		handler->f_11(arg0, ret);
 		break;
-	case rmi_type_3_o:
-		handler->f3_o(arg0, arg1, arg2, ret);
+	case rmi_type_34:
+		handler->f_34(arg0, arg1, arg2, ret);
 		break;
 	default:
 		assert(false);
 	}
 
 	if (rmi_call_log_enabled) {
-		rmi_log_on_exit(handler_id, arg0, arg1, arg2, arg3, arg4, ret);
+		unsigned long args[] = {arg0, arg1, arg2, arg3, arg4};
+
+		rmi_log_on_exit(handler_id, args, ret);
 	}
 
 	assert_cpu_slots_empty();
@@ -294,14 +290,13 @@
 	INFO("ELR_EL2:  0x%016lx\n", elr);
 	INFO("FAR_EL2:  0x%016lx\n", far);
 	INFO("----\n");
-
 }
 
 unsigned long handle_realm_trap(unsigned long *regs)
 {
 	report_unexpected();
 
-	while (1) {
+	while (true) {
 		wfe();
 	}
 }
@@ -345,7 +340,7 @@
 {
 	report_unexpected();
 
-	while (1) {
+	while (true) {
 		wfe();
 	}
 }
@@ -353,8 +348,9 @@
 static bool is_el2_data_abort_gpf(unsigned long esr)
 {
 	if (((esr & MASK(ESR_EL2_EC)) == ESR_EL2_EC_DATA_ABORT_SEL) &&
-	    ((esr & MASK(ESR_EL2_ABORT_FSC)) == ESR_EL2_ABORT_FSC_GPF))
+	    ((esr & MASK(ESR_EL2_ABORT_FSC)) == ESR_EL2_ABORT_FSC_GPF)) {
 		return true;
+	}
 	return false;
 }
 
@@ -367,8 +363,6 @@
  */
 unsigned long handle_rmm_trap(void)
 {
-	int i;
-
 	unsigned long esr = read_esr_el2();
 	unsigned long elr = read_elr_el2();
 
@@ -379,12 +373,12 @@
 		fatal_abort();
 	}
 
-	for (i = 0; i < RMM_TRAP_LIST_SIZE; i++) {
+	for (unsigned int i = 0U; i < RMM_TRAP_LIST_SIZE; i++) {
 		if (rmm_trap_list[i].aborted_pc == elr) {
 			return rmm_trap_list[i].new_pc;
 		}
 	}
 
 	fatal_abort();
-	return 0;
+	return 0UL;
 }