[PATCH] soc: qcom: smd-rpm: Add trace events for SMD-RPM messages

[PATCH] soc: qcom: smd-rpm: Add trace events for SMD-RPM messages

[Maulik Shah]

There is no visibility on what resource votes are placed via SMD RPM making
it difficult to identify clients that do either under voting via active set
impacting the device functions or fail to send sleep set votes and thereby
prevent the SoC from reaching low power modes such as vmin or vlow.

Add trace events for SMD RPM requests and acknowledgment to make RPM votes
for various resources visible through ftrace.

Signed-off-by: Maulik Shah <maulik.shah@oss.qualcomm.com>
---
Output from newly added ftrace on shikra SoC,
rpm_smd_send_msg: msg_id:807 ctx:active rsc_type:ldoa rsc_id:0xe key:swen nbytes:4 value:1
rpm_smd_ack_recvd: msg_id:807 errno:00000000
..
..
rpm_smd_send_msg: msg_id:1106 ctx:active rsc_type:clk2 rsc_id:0x0 key:KHz nbytes:4 value:19200
rpm_smd_ack_recvd: msg_id:1106 errno:00000000
rpm_smd_send_msg: msg_id:1107 ctx:sleep rsc_type:clk2 rsc_id:0x0 key:KHz nbytes:4 value:0
rpm_smd_ack_recvd: msg_id:1107 errno:00000000
---
 drivers/soc/qcom/Makefile        |  1 +
 drivers/soc/qcom/smd-rpm.c       | 10 +++++
 drivers/soc/qcom/trace-smd-rpm.h | 83 ++++++++++++++++++++++++++++++++++++++++
 3 files changed, 94 insertions(+)

diff --git a/drivers/soc/qcom/Makefile b/drivers/soc/qcom/Makefile
index 798643be3590..839e7875ec1b 100644
--- a/drivers/soc/qcom/Makefile
+++ b/drivers/soc/qcom/Makefile
@@ -1,5 +1,6 @@
 # SPDX-License-Identifier: GPL-2.0
 CFLAGS_rpmh-rsc.o := -I$(src)
+CFLAGS_smd-rpm.o := -I$(src)
 CFLAGS_qcom_aoss.o := -I$(src)
 obj-$(CONFIG_QCOM_AOSS_QMP) +=	qcom_aoss.o
 obj-$(CONFIG_QCOM_GENI_SE) +=	qcom-geni-se.o
diff --git a/drivers/soc/qcom/smd-rpm.c b/drivers/soc/qcom/smd-rpm.c
index f2b3e02abdf1..04b3f7789ab7 100644
--- a/drivers/soc/qcom/smd-rpm.c
+++ b/drivers/soc/qcom/smd-rpm.c
@@ -14,6 +14,9 @@
 #include <linux/rpmsg.h>
 #include <linux/soc/qcom/smd-rpm.h>
 
+#define CREATE_TRACE_POINTS
+#include "trace-smd-rpm.h"
+
 #define RPM_REQUEST_TIMEOUT     (5 * HZ)
 
 /**
@@ -106,6 +109,7 @@ int qcom_rpm_smd_write(struct qcom_smd_rpm *rpm,
 		u8 payload[];
 	} *pkt;
 	size_t size = sizeof(*pkt) + count;
+	const struct clk_smd_rpm_req *req = buf;
 
 	/* SMD packets to the RPM may not exceed 256 bytes */
 	if (WARN_ON(size >= 256))
@@ -131,6 +135,8 @@ int qcom_rpm_smd_write(struct qcom_smd_rpm *rpm,
 	if (ret)
 		goto out;
 
+	trace_rpm_smd_send_msg(pkt->req.msg_id, state, type, id, req);
+
 	left = wait_for_completion_timeout(&rpm->ack, RPM_REQUEST_TIMEOUT);
 	if (!left)
 		ret = -ETIMEDOUT;
@@ -158,6 +164,7 @@ static int qcom_smd_rpm_callback(struct rpmsg_device *rpdev,
 	const u8 *end = buf + hdr_length;
 	char msgbuf[32];
 	int status = 0;
+	__le32 msg_id = 0;
 	u32 len, msg_length;
 
 	if (le32_to_cpu(hdr->service_type) != RPM_SERVICE_TYPE_REQUEST ||
@@ -171,6 +178,7 @@ static int qcom_smd_rpm_callback(struct rpmsg_device *rpdev,
 		msg_length = le32_to_cpu(msg->length);
 		switch (le32_to_cpu(msg->msg_type)) {
 		case RPM_MSG_TYPE_MSG_ID:
+			msg_id = msg->msg_id;
 			break;
 		case RPM_MSG_TYPE_ERR:
 			len = min_t(u32, ALIGN(msg_length, 4), sizeof(msgbuf));
@@ -187,6 +195,8 @@ static int qcom_smd_rpm_callback(struct rpmsg_device *rpdev,
 		buf = PTR_ALIGN(buf + 2 * sizeof(u32) + msg_length, 4);
 	}
 
+	trace_rpm_smd_ack_recvd(msg_id, status);
+
 	rpm->ack_status = status;
 	complete(&rpm->ack);
 	return 0;
diff --git a/drivers/soc/qcom/trace-smd-rpm.h b/drivers/soc/qcom/trace-smd-rpm.h
new file mode 100644
index 000000000000..b17fe5d5e306
--- /dev/null
+++ b/drivers/soc/qcom/trace-smd-rpm.h
@@ -0,0 +1,83 @@
+/* SPDX-License-Identifier: GPL-2.0 */
+/*
+ * Copyright (c) Qualcomm Technologies, Inc. and/or its subsidiaries.
+ */
+
+#if !defined(_TRACE_SMD_RPM_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_SMD_RPM_H
+
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM rpm_smd
+
+#include <linux/tracepoint.h>
+#include <linux/soc/qcom/smd-rpm.h>
+
+TRACE_EVENT(rpm_smd_ack_recvd,
+
+	TP_PROTO(__le32 msg_id, int errno),
+
+	TP_ARGS(msg_id, errno),
+
+	TP_STRUCT__entry(
+		__field(u32, msg_id)
+		__field(int, errno)
+	),
+
+	TP_fast_assign(
+		__entry->msg_id = le32_to_cpu(msg_id);
+		__entry->errno = errno;
+	),
+
+	TP_printk("msg_id:%u errno:%08x",
+		__entry->msg_id,
+		__entry->errno)
+);
+
+TRACE_EVENT(rpm_smd_send_msg,
+
+	TP_PROTO(__le32 msg_id, u32 state, u32 rsc_type, u32 rsc_id,
+		 const struct clk_smd_rpm_req *req),
+
+	TP_ARGS(msg_id, state, rsc_type, rsc_id, req),
+
+	TP_STRUCT__entry(
+		__field(u32, msg_id)
+		__field(u32, state)
+		__field(u32, rsc_type)
+		__field(u32, rsc_id)
+		__field(u32, key)
+		__field(u32, nbytes)
+		__field(u32, value)
+	),
+
+	TP_fast_assign(
+		__entry->msg_id = le32_to_cpu(msg_id);
+		__entry->state = state;
+		__entry->rsc_type = rsc_type;
+		__entry->rsc_id = rsc_id;
+		__entry->key = le32_to_cpu(req->key);
+		__entry->nbytes = le32_to_cpu(req->nbytes);
+		__entry->value = le32_to_cpu(req->value);
+	),
+
+	TP_printk("msg_id:%u ctx:%s rsc_type:%.4s rsc_id:0x%x key:%.4s nbytes:%u value:%u",
+		  __entry->msg_id,
+		  __print_symbolic(__entry->state,
+				   { QCOM_SMD_RPM_ACTIVE_STATE, "active" },
+				   { QCOM_SMD_RPM_SLEEP_STATE, "sleep" }),
+		  (const char *)&__entry->rsc_type,
+		  __entry->rsc_id,
+		  (const char *)&__entry->key,
+		  __entry->nbytes,
+		  __entry->value)
+);
+
+#endif /* _TRACE_SMD_RPM_H */
+
+#undef TRACE_INCLUDE_PATH
+#define TRACE_INCLUDE_PATH .
+
+#undef TRACE_INCLUDE_FILE
+#define TRACE_INCLUDE_FILE trace-smd-rpm
+
+#include <trace/define_trace.h>

---
base-commit: 89c07d98716a13454ec3fd9f97689e812cc71bd4
change-id: 20260901-smd-rpm-trace-8d112ca11840

Best regards,
--  
Maulik Shah <maulik.shah@oss.qualcomm.com>

Re: [PATCH] soc: qcom: smd-rpm: Add trace events for SMD-RPM messages

[Konrad Dybcio]

On 9/4/26 4:23 PM, Maulik Shah wrote:
> There is no visibility on what resource votes are placed via SMD RPM making
> it difficult to identify clients that do either under voting via active set
> impacting the device functions or fail to send sleep set votes and thereby
> prevent the SoC from reaching low power modes such as vmin or vlow.

[...]

> @@ -106,6 +109,7 @@ int qcom_rpm_smd_write(struct qcom_smd_rpm *rpm,
>  		u8 payload[];
>  	} *pkt;
>  	size_t size = sizeof(*pkt) + count;
> +	const struct clk_smd_rpm_req *req = buf;

This struct is called clk_smd_rpm_req, but it seems like at least for
the current in-kernel users, everything that's passed to
qcom_rpm_smd_write() (rpmpd, regulator) is a renamed version of this
one. We should probably rename it.

Or are there requests that differ in structure that we should be
mindful of?

>  	if (le32_to_cpu(hdr->service_type) != RPM_SERVICE_TYPE_REQUEST ||
> @@ -171,6 +178,7 @@ static int qcom_smd_rpm_callback(struct rpmsg_device *rpdev,
>  		msg_length = le32_to_cpu(msg->length);
>  		switch (le32_to_cpu(msg->msg_type)) {
>  		case RPM_MSG_TYPE_MSG_ID:
> +			msg_id = msg->msg_id;
>  			break;
>  		case RPM_MSG_TYPE_ERR:
>  			len = min_t(u32, ALIGN(msg_length, 4), sizeof(msgbuf));
> @@ -187,6 +195,8 @@ static int qcom_smd_rpm_callback(struct rpmsg_device *rpdev,
>  		buf = PTR_ALIGN(buf + 2 * sizeof(u32) + msg_length, 4);
>  	}
>  
> +	trace_rpm_smd_ack_recvd(msg_id, status);

This way only the last ack/err will be traced, is that the desired behavior?

[...]

> +TRACE_EVENT(rpm_smd_send_msg,
> +
> +	TP_PROTO(__le32 msg_id, u32 state, u32 rsc_type, u32 rsc_id,
> +		 const struct clk_smd_rpm_req *req),
> +
> +	TP_ARGS(msg_id, state, rsc_type, rsc_id, req),
> +
> +	TP_STRUCT__entry(
> +		__field(u32, msg_id)
> +		__field(u32, state)
> +		__field(u32, rsc_type)
> +		__field(u32, rsc_id)
> +		__field(u32, key)
> +		__field(u32, nbytes)
> +		__field(u32, value)
> +	),
> +
> +	TP_fast_assign(
> +		__entry->msg_id = le32_to_cpu(msg_id);
> +		__entry->state = state;
> +		__entry->rsc_type = rsc_type;
> +		__entry->rsc_id = rsc_id;
> +		__entry->key = le32_to_cpu(req->key);
> +		__entry->nbytes = le32_to_cpu(req->nbytes);
> +		__entry->value = le32_to_cpu(req->value);

GPT points out `value` can be more than just a single u32
(via nbytes)

Konrad