devfreq: devfreq_spdm: Add IPC logging for hypervisor calls

Use IPC logging to log calls made to hypervisor for the SPDM driver.
The continuous logging is useful when debugging stability issues and also
to profile code execution.

Change-Id: Ib32fcc998319f4477dc8c1df383ed89b4a9e9214
Signed-off-by: Girish Mahadevan <girishm@codeaurora.org>

3 files changed, 53 insertions, 19 deletions

diff --git a/drivers/devfreq/devfreq_spdm.c b/drivers/devfreq/devfreq_spdm.c
index 1217ddea2929..2216094c675a 100644
--- a/drivers/devfreq/devfreq_spdm.c
+++ b/drivers/devfreq/devfreq_spdm.c
@@ -14,6 +14,7 @@
 #include <linux/device.h>
 #include <linux/devfreq.h>
 #include <linux/init.h>
+#include <linux/ipc_logging.h>
 #include <linux/gfp.h>
 #include <linux/list.h>
 #include <linux/module.h>
@@ -26,7 +27,15 @@
 #include "governor.h"
 #include "devfreq_spdm.h"
 
+static void *spdm_ipc_log_ctxt;
 #define DEVFREQ_SPDM_DEFAULT_WINDOW_MS 100
+#define SPDM_IPC_LOG_PAGES	5
+
+#define SPDM_IPC_LOG(x...)	do { \
+	pr_debug(x); \
+	if (spdm_ipc_log_ctxt) \
+		ipc_log_string(spdm_ipc_log_ctxt, x); \
+} while (0)
 
 static int change_bw(struct device *dev, unsigned long *freq, u32 flags)
 {
@@ -61,7 +70,7 @@ update_thresholds:
 	desc.arg[0] = SPDM_CMD_ENABLE;
 	desc.arg[1] = data->spdm_client;
 	desc.arg[2] = clk_get_rate(data->cci_clk);
-	hvc_status = hvc(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
+	hvc_status = spdm_ext_call(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
 	if (hvc_status)
 		pr_err("HVC command %u failed with error %u", (int)desc.arg[0],
 			hvc_status);
@@ -232,6 +241,17 @@ no_pdata:
 	return ret;
 }
 
+int __spdm_hyp_call(u64 func_id, struct hvc_desc *desc)
+{
+	int ret = 0;
+
+	SPDM_IPC_LOG("hvc call fn:0x%llx, cmd:%llu\n", func_id, desc->arg[0]);
+	ret = hvc(func_id, desc);
+	SPDM_IPC_LOG("hvc return fn:0x%llx cmd:%llu Ret[0]:%llu Ret[1]:%llu\n",
+			func_id, desc->arg[0], desc->ret[0], desc->ret[1]);
+	return ret;
+}
+
 static int probe(struct platform_device *pdev)
 {
 	struct spdm_data *data = 0;
@@ -280,6 +300,14 @@ static int probe(struct platform_device *pdev)
 	}
 
 	spdm_init_debugfs(&pdev->dev);
+	spdm_ipc_log_ctxt = ipc_log_context_create(SPDM_IPC_LOG_PAGES,
+							"devfreq_spdm", 0);
+
+	if (IS_ERR_OR_NULL(spdm_ipc_log_ctxt)) {
+		pr_err("%s: Failed to create IPC log context\n", __func__);
+		spdm_ipc_log_ctxt = NULL;
+	}
+
 
 	return 0;
 
@@ -315,6 +343,9 @@ static int remove(struct platform_device *pdev)
 
 	devm_kfree(&pdev->dev, data);
 
+	if (spdm_ipc_log_ctxt)
+		ipc_log_context_destroy(spdm_ipc_log_ctxt);
+
 	return 0;
 }
 
diff --git a/drivers/devfreq/devfreq_spdm.h b/drivers/devfreq/devfreq_spdm.h
index cdb45c88bc57..f08e63fd10e5 100644
--- a/drivers/devfreq/devfreq_spdm.h
+++ b/drivers/devfreq/devfreq_spdm.h
@@ -103,4 +103,7 @@ extern void spdm_remove_debugfs(struct spdm_data *data);
 #define SPDM_CMD_CFG_MAXCCI 17
 #define SPDM_CMD_CFG_VOTES 18
 
+extern int __spdm_hyp_call(u64 func_id, struct hvc_desc *desc);
+#define spdm_ext_call	__spdm_hyp_call
+
 #endif
diff --git a/drivers/devfreq/governor_spdm_bw_hyp.c b/drivers/devfreq/governor_spdm_bw_hyp.c
index 0dfe8ecee09e..319fb847e920 100644
--- a/drivers/devfreq/governor_spdm_bw_hyp.c
+++ b/drivers/devfreq/governor_spdm_bw_hyp.c
@@ -79,7 +79,7 @@ static irqreturn_t threaded_isr(int irq, void *dev_id)
 
 	/* call hyp to get bw_vote */
 	desc.arg[0] = SPDM_CMD_GET_BW_ALL;
-	hvc_status = hvc(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
+	hvc_status = spdm_ext_call(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
 	if (hvc_status)
 		pr_err("HVC command %u failed with error %u", (int)desc.arg[0],
 			hvc_status);
@@ -131,7 +131,7 @@ static int gov_spdm_hyp_target_bw(struct devfreq *devfreq, unsigned long *freq,
 	} else {
 		desc.arg[0] = SPDM_CMD_GET_BW_SPECIFIC;
 		desc.arg[1] = ((struct spdm_data *)devfreq->data)->spdm_client;
-		hvc_status = hvc(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
+		hvc_status = spdm_ext_call(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
 		if (hvc_status)
 			pr_err("HVC command %u failed with error %u",
 				(int)desc.arg[0], hvc_status);
@@ -160,7 +160,7 @@ static int gov_spdm_hyp_eh(struct devfreq *devfreq, unsigned int event,
 		desc.arg[2] = spdm_data->config_data.num_ports;
 		for (i = 0; i < spdm_data->config_data.num_ports; i++)
 			desc.arg[i+3] = spdm_data->config_data.ports[i];
-		hvc_status = hvc(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
+		hvc_status = spdm_ext_call(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
 		if (hvc_status)
 			pr_err("HVC command %u failed with error %u",
 				(int)desc.arg[0], hvc_status);
@@ -170,7 +170,7 @@ static int gov_spdm_hyp_eh(struct devfreq *devfreq, unsigned int event,
 		desc.arg[2] = spdm_data->config_data.aup;
 		desc.arg[3] = spdm_data->config_data.adown;
 		desc.arg[4] = spdm_data->config_data.bucket_size;
-		hvc_status = hvc(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
+		hvc_status = spdm_ext_call(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
 		if (hvc_status)
 			pr_err("HVC command %u failed with error %u",
 				(int)desc.arg[0], hvc_status);
@@ -179,7 +179,7 @@ static int gov_spdm_hyp_eh(struct devfreq *devfreq, unsigned int event,
 		desc.arg[1] = spdm_data->spdm_client;
 		for (i = 0; i < SPDM_PL_COUNT - 1; i++)
 			desc.arg[i+2] = spdm_data->config_data.pl_freqs[i];
-		hvc_status = hvc(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
+		hvc_status = spdm_ext_call(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
 		if (hvc_status)
 			pr_err("HVC command %u failed with error %u",
 				(int)desc.arg[0], hvc_status);
@@ -188,7 +188,7 @@ static int gov_spdm_hyp_eh(struct devfreq *devfreq, unsigned int event,
 		desc.arg[1] = spdm_data->spdm_client;
 		desc.arg[2] = spdm_data->config_data.reject_rate[0];
 		desc.arg[3] = spdm_data->config_data.reject_rate[1];
-		hvc_status = hvc(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
+		hvc_status = spdm_ext_call(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
 		if (hvc_status)
 			pr_err("HVC command %u failed with error %u",
 				(int)desc.arg[0], hvc_status);
@@ -196,7 +196,7 @@ static int gov_spdm_hyp_eh(struct devfreq *devfreq, unsigned int event,
 		desc.arg[1] = spdm_data->spdm_client;
 		desc.arg[2] = spdm_data->config_data.reject_rate[2];
 		desc.arg[3] = spdm_data->config_data.reject_rate[3];
-		hvc_status = hvc(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
+		hvc_status = spdm_ext_call(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
 		if (hvc_status)
 			pr_err("HVC command %u failed with error %u",
 				(int)desc.arg[0], hvc_status);
@@ -204,7 +204,7 @@ static int gov_spdm_hyp_eh(struct devfreq *devfreq, unsigned int event,
 		desc.arg[1] = spdm_data->spdm_client;
 		desc.arg[2] = spdm_data->config_data.reject_rate[4];
 		desc.arg[3] = spdm_data->config_data.reject_rate[5];
-		hvc_status = hvc(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
+		hvc_status = spdm_ext_call(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
 		if (hvc_status)
 			pr_err("HVC command %u failed with error %u",
 				(int)desc.arg[0], hvc_status);
@@ -213,7 +213,7 @@ static int gov_spdm_hyp_eh(struct devfreq *devfreq, unsigned int event,
 		desc.arg[1] = spdm_data->spdm_client;
 		desc.arg[2] = spdm_data->config_data.response_time_us[0];
 		desc.arg[3] = spdm_data->config_data.response_time_us[1];
-		hvc_status = hvc(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
+		hvc_status = spdm_ext_call(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
 		if (hvc_status)
 			pr_err("HVC command %u failed with error %u",
 				(int)desc.arg[0], hvc_status);
@@ -221,7 +221,7 @@ static int gov_spdm_hyp_eh(struct devfreq *devfreq, unsigned int event,
 		desc.arg[1] = spdm_data->spdm_client;
 		desc.arg[2] = spdm_data->config_data.response_time_us[2];
 		desc.arg[3] = spdm_data->config_data.response_time_us[3];
-		hvc_status = hvc(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
+		hvc_status = spdm_ext_call(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
 		if (hvc_status)
 			pr_err("HVC command %u failed with error %u",
 				(int)desc.arg[0], hvc_status);
@@ -229,7 +229,7 @@ static int gov_spdm_hyp_eh(struct devfreq *devfreq, unsigned int event,
 		desc.arg[1] = spdm_data->spdm_client;
 		desc.arg[2] = spdm_data->config_data.response_time_us[4];
 		desc.arg[3] = spdm_data->config_data.response_time_us[5];
-		hvc_status = hvc(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
+		hvc_status = spdm_ext_call(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
 		if (hvc_status)
 			pr_err("HVC command %u failed with error %u",
 				(int)desc.arg[0], hvc_status);
@@ -238,7 +238,7 @@ static int gov_spdm_hyp_eh(struct devfreq *devfreq, unsigned int event,
 		desc.arg[1] = spdm_data->spdm_client;
 		desc.arg[2] = spdm_data->config_data.cci_response_time_us[0];
 		desc.arg[3] = spdm_data->config_data.cci_response_time_us[1];
-		hvc_status = hvc(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
+		hvc_status = spdm_ext_call(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
 		if (hvc_status)
 			pr_err("HVC command %u failed with error %u",
 				(int)desc.arg[0], hvc_status);
@@ -246,7 +246,7 @@ static int gov_spdm_hyp_eh(struct devfreq *devfreq, unsigned int event,
 		desc.arg[1] = spdm_data->spdm_client;
 		desc.arg[2] = spdm_data->config_data.cci_response_time_us[2];
 		desc.arg[3] = spdm_data->config_data.cci_response_time_us[3];
-		hvc_status = hvc(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
+		hvc_status = spdm_ext_call(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
 		if (hvc_status)
 			pr_err("HVC command %u failed with error %u",
 				(int)desc.arg[0], hvc_status);
@@ -254,7 +254,7 @@ static int gov_spdm_hyp_eh(struct devfreq *devfreq, unsigned int event,
 		desc.arg[1] = spdm_data->spdm_client;
 		desc.arg[2] = spdm_data->config_data.cci_response_time_us[4];
 		desc.arg[3] = spdm_data->config_data.cci_response_time_us[5];
-		hvc_status = hvc(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
+		hvc_status = spdm_ext_call(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
 		if (hvc_status)
 			pr_err("HVC command %u failed with error %u",
 				(int)desc.arg[0], hvc_status);
@@ -262,7 +262,7 @@ static int gov_spdm_hyp_eh(struct devfreq *devfreq, unsigned int event,
 		desc.arg[0] = SPDM_CMD_CFG_MAXCCI;
 		desc.arg[1] = spdm_data->spdm_client;
 		desc.arg[2] = spdm_data->config_data.max_cci_freq;
-		hvc_status = hvc(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
+		hvc_status = spdm_ext_call(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
 		if (hvc_status)
 			pr_err("HVC command %u failed with error %u",
 				(int)desc.arg[0], hvc_status);
@@ -273,7 +273,7 @@ static int gov_spdm_hyp_eh(struct devfreq *devfreq, unsigned int event,
 		desc.arg[3] = spdm_data->config_data.downstep;
 		desc.arg[4] = spdm_data->config_data.max_vote;
 		desc.arg[5] = spdm_data->config_data.up_step_multp;
-		hvc_status = hvc(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
+		hvc_status = spdm_ext_call(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
 		if (hvc_status)
 			pr_err("HVC command %u failed with error %u",
 				(int)desc.arg[0], hvc_status);
@@ -282,7 +282,7 @@ static int gov_spdm_hyp_eh(struct devfreq *devfreq, unsigned int event,
 		desc.arg[0] = SPDM_CMD_ENABLE;
 		desc.arg[1] = spdm_data->spdm_client;
 		desc.arg[2] = 0;
-		hvc_status = hvc(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
+		hvc_status = spdm_ext_call(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
 		if (hvc_status) {
 			pr_err("HVC command %u failed with error %u",
 				(int)desc.arg[0], hvc_status);
@@ -309,7 +309,7 @@ static int gov_spdm_hyp_eh(struct devfreq *devfreq, unsigned int event,
 		/* call hypvervisor to disable */
 		desc.arg[0] = SPDM_CMD_DISABLE;
 		desc.arg[1] = spdm_data->spdm_client;
-		hvc_status = hvc(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
+		hvc_status = spdm_ext_call(HVC_FN_SIP(SPDM_HYP_FNID), &desc);
 		if (hvc_status)
 			pr_err("HVC command %u failed with error %u",
 				(int)desc.arg[0], hvc_status);