[PATCH 0/3] rpmsg: glink: Introduce tracepoints

[PATCH 0/3] rpmsg: glink: Introduce tracepoints

[Bjorn Andersson]

When debugging interaction with remoteproc, do performance measurments
and fix client bugs, it turns out to be very useful to have tracepoints
throughout GLINK, so introduce this.

Signed-off-by: Bjorn Andersson <quic_bjorande@quicinc.com>
---
Bjorn Andersson (3):
      rpmsg: glink: Tidy up RX advance handling
      rpmsg: glink: Pass channel to qcom_glink_send_close_ack()
      rpmsg: glink: Introduce packet tracepoints

 drivers/rpmsg/Makefile            |   1 +
 drivers/rpmsg/qcom_glink_native.c | 124 ++++++++++--
 drivers/rpmsg/qcom_glink_trace.h  | 406 ++++++++++++++++++++++++++++++++++++++
 3 files changed, 519 insertions(+), 12 deletions(-)
---
base-commit: d6dbc9f56c3a70e915625b6f1887882c23dc5c91
change-id: 20240726-glink-tracepoints-0426bba64a0e

Best regards,
-- 
Bjorn Andersson <quic_bjorande@quicinc.com>

[PATCH 1/3] rpmsg: glink: Tidy up RX advance handling

[Bjorn Andersson]

The operation of advancing the FIFO receive pointer is sprinkled between
the interrupt handler itself, and functions being called from this.

Push all the RX advancement operations to the individual handlers, to
unify the style across the handling of the various messages.

Signed-off-by: Bjorn Andersson <quic_bjorande@quicinc.com>
---
 drivers/rpmsg/qcom_glink_native.c | 22 +++++++++++++++-------
 1 file changed, 15 insertions(+), 7 deletions(-)

diff --git a/drivers/rpmsg/qcom_glink_native.c b/drivers/rpmsg/qcom_glink_native.c
index 82d460ff4777..e764ea8a290c 100644
--- a/drivers/rpmsg/qcom_glink_native.c
+++ b/drivers/rpmsg/qcom_glink_native.c
@@ -424,6 +424,8 @@ static void qcom_glink_handle_intent_req_ack(struct qcom_glink *glink,
 	struct glink_channel *channel;
 	unsigned long flags;
 
+	qcom_glink_rx_advance(glink, ALIGN(sizeof(struct glink_msg), 8));
+
 	spin_lock_irqsave(&glink->idr_lock, flags);
 	channel = idr_find(&glink->rcids, cid);
 	spin_unlock_irqrestore(&glink->idr_lock, flags);
@@ -745,6 +747,8 @@ static void qcom_glink_handle_rx_done(struct qcom_glink *glink,
 	struct glink_channel *channel;
 	unsigned long flags;
 
+	qcom_glink_rx_advance(glink, ALIGN(sizeof(struct glink_msg), 8));
+
 	spin_lock_irqsave(&glink->idr_lock, flags);
 	channel = idr_find(&glink->rcids, cid);
 	spin_unlock_irqrestore(&glink->idr_lock, flags);
@@ -952,6 +956,12 @@ static int qcom_glink_rx_data(struct qcom_glink *glink, size_t avail)
 	return ret;
 }
 
+static void qcom_glink_rx_read_notif(struct qcom_glink *glink)
+{
+	qcom_glink_rx_advance(glink, ALIGN(sizeof(struct glink_msg), 8));
+	qcom_glink_tx_kick(glink);
+}
+
 static void qcom_glink_handle_intent(struct qcom_glink *glink,
 				     unsigned int cid,
 				     unsigned int count,
@@ -1022,6 +1032,8 @@ static int qcom_glink_rx_open_ack(struct qcom_glink *glink, unsigned int lcid)
 {
 	struct glink_channel *channel;
 
+	qcom_glink_rx_advance(glink, ALIGN(sizeof(struct glink_msg), 8));
+
 	spin_lock(&glink->idr_lock);
 	channel = idr_find(&glink->lcids, lcid);
 	spin_unlock(&glink->idr_lock);
@@ -1067,6 +1079,8 @@ static void qcom_glink_handle_signals(struct qcom_glink *glink,
 	unsigned long flags;
 	bool enable;
 
+	qcom_glink_rx_advance(glink, ALIGN(sizeof(struct glink_msg), 8));
+
 	spin_lock_irqsave(&glink->idr_lock, flags);
 	channel = idr_find(&glink->rcids, rcid);
 	spin_unlock_irqrestore(&glink->idr_lock, flags);
@@ -1114,7 +1128,6 @@ void qcom_glink_native_rx(struct qcom_glink *glink)
 			break;
 		case GLINK_CMD_OPEN_ACK:
 			ret = qcom_glink_rx_open_ack(glink, param1);
-			qcom_glink_rx_advance(glink, ALIGN(sizeof(msg), 8));
 			break;
 		case GLINK_CMD_OPEN:
 			ret = qcom_glink_rx_defer(glink, param2);
@@ -1124,27 +1137,22 @@ void qcom_glink_native_rx(struct qcom_glink *glink)
 			ret = qcom_glink_rx_data(glink, avail);
 			break;
 		case GLINK_CMD_READ_NOTIF:
-			qcom_glink_rx_advance(glink, ALIGN(sizeof(msg), 8));
-			qcom_glink_tx_kick(glink);
+			qcom_glink_rx_read_notif(glink);
 			break;
 		case GLINK_CMD_INTENT:
 			qcom_glink_handle_intent(glink, param1, param2, avail);
 			break;
 		case GLINK_CMD_RX_DONE:
 			qcom_glink_handle_rx_done(glink, param1, param2, false);
-			qcom_glink_rx_advance(glink, ALIGN(sizeof(msg), 8));
 			break;
 		case GLINK_CMD_RX_DONE_W_REUSE:
 			qcom_glink_handle_rx_done(glink, param1, param2, true);
-			qcom_glink_rx_advance(glink, ALIGN(sizeof(msg), 8));
 			break;
 		case GLINK_CMD_RX_INTENT_REQ_ACK:
 			qcom_glink_handle_intent_req_ack(glink, param1, param2);
-			qcom_glink_rx_advance(glink, ALIGN(sizeof(msg), 8));
 			break;
 		case GLINK_CMD_SIGNALS:
 			qcom_glink_handle_signals(glink, param1, param2);
-			qcom_glink_rx_advance(glink, ALIGN(sizeof(msg), 8));
 			break;
 		default:
 			dev_err(glink->dev, "unhandled rx cmd: %d\n", cmd);

-- 
2.34.1

[PATCH 2/3] rpmsg: glink: Pass channel to qcom_glink_send_close_ack()

[Bjorn Andersson]

Align the qcom_glink_send_close_ack() arguments with other functions to
take the struct glink_channel, so that the upcoming tracepoint patch can
access the channel attributes.

Signed-off-by: Bjorn Andersson <quic_bjorande@quicinc.com>
---
 drivers/rpmsg/qcom_glink_native.c | 6 +++---
 1 file changed, 3 insertions(+), 3 deletions(-)

diff --git a/drivers/rpmsg/qcom_glink_native.c b/drivers/rpmsg/qcom_glink_native.c
index e764ea8a290c..ba0ea28df821 100644
--- a/drivers/rpmsg/qcom_glink_native.c
+++ b/drivers/rpmsg/qcom_glink_native.c
@@ -511,12 +511,12 @@ static void qcom_glink_send_close_req(struct qcom_glink *glink,
 }
 
 static void qcom_glink_send_close_ack(struct qcom_glink *glink,
-				      unsigned int rcid)
+				      struct glink_channel *channel)
 {
 	struct glink_msg req;
 
 	req.cmd = cpu_to_le16(GLINK_CMD_CLOSE_ACK);
-	req.param1 = cpu_to_le16(rcid);
+	req.param1 = cpu_to_le16(channel->rcid);
 	req.param2 = 0;
 
 	qcom_glink_tx(glink, &req, sizeof(req), NULL, 0, true);
@@ -1628,7 +1628,7 @@ static void qcom_glink_rx_close(struct qcom_glink *glink, unsigned int rcid)
 	}
 	channel->rpdev = NULL;
 
-	qcom_glink_send_close_ack(glink, channel->rcid);
+	qcom_glink_send_close_ack(glink, channel);
 
 	spin_lock_irqsave(&glink->idr_lock, flags);
 	idr_remove(&glink->rcids, channel->rcid);

-- 
2.34.1

[PATCH 3/3] rpmsg: glink: Introduce packet tracepoints

[Bjorn Andersson]

Introduce tracepoints to allow tracing the GLINK packets being exchanged
with other subsystems. This is useful for debugging both interaction
with remote processors and client driver issues, as well as tracking
latency through the communication stack.

Channel events are traced with both local and remote channel ids, as
well as the textual representation when possible. The channel ids are
useful when matching traces with traces from the firmware side logs,
while the textual representation is necessary to identify channels when
we're starting to trace an already running system.

Signed-off-by: Bjorn Andersson <quic_bjorande@quicinc.com>
---
 drivers/rpmsg/Makefile            |   1 +
 drivers/rpmsg/qcom_glink_native.c |  96 ++++++++-
 drivers/rpmsg/qcom_glink_trace.h  | 406 ++++++++++++++++++++++++++++++++++++++
 3 files changed, 501 insertions(+), 2 deletions(-)

diff --git a/drivers/rpmsg/Makefile b/drivers/rpmsg/Makefile
index 58e3b382e316..1e02b58ff61f 100644
--- a/drivers/rpmsg/Makefile
+++ b/drivers/rpmsg/Makefile
@@ -4,6 +4,7 @@ obj-$(CONFIG_RPMSG_CHAR)	+= rpmsg_char.o
 obj-$(CONFIG_RPMSG_CTRL)	+= rpmsg_ctrl.o
 obj-$(CONFIG_RPMSG_NS)		+= rpmsg_ns.o
 obj-$(CONFIG_RPMSG_MTK_SCP)	+= mtk_rpmsg.o
+CFLAGS_qcom_glink_native.o	:= -I$(src)
 qcom_glink-objs			:= qcom_glink_native.o qcom_glink_ssr.o
 obj-$(CONFIG_RPMSG_QCOM_GLINK) += qcom_glink.o
 obj-$(CONFIG_RPMSG_QCOM_GLINK_RPM) += qcom_glink_rpm.o
diff --git a/drivers/rpmsg/qcom_glink_native.c b/drivers/rpmsg/qcom_glink_native.c
index ba0ea28df821..c7c3c21a7156 100644
--- a/drivers/rpmsg/qcom_glink_native.c
+++ b/drivers/rpmsg/qcom_glink_native.c
@@ -23,6 +23,9 @@
 #include "rpmsg_internal.h"
 #include "qcom_glink_native.h"
 
+#define CREATE_TRACE_POINTS
+#include "qcom_glink_trace.h"
+
 #define GLINK_NAME_SIZE		32
 #define GLINK_VERSION_1		1
 
@@ -78,6 +81,7 @@ struct glink_core_rx_intent {
 /**
  * struct qcom_glink - driver context, relates to one remote subsystem
  * @dev:	reference to the associated struct device
+ * @label:	identifier of the glink edge
  * @rx_pipe:	pipe object for receive FIFO
  * @tx_pipe:	pipe object for transmit FIFO
  * @rx_work:	worker for handling received control messages
@@ -96,6 +100,8 @@ struct glink_core_rx_intent {
 struct qcom_glink {
 	struct device *dev;
 
+	const char *label;
+
 	struct qcom_glink_pipe *rx_pipe;
 	struct qcom_glink_pipe *tx_pipe;
 
@@ -392,6 +398,8 @@ static int qcom_glink_send_version(struct qcom_glink *glink)
 	msg.param1 = cpu_to_le16(GLINK_VERSION_1);
 	msg.param2 = cpu_to_le32(glink->features);
 
+	trace_qcom_glink_cmd_version_tx(glink->label, GLINK_VERSION_1, glink->features);
+
 	return qcom_glink_tx(glink, &msg, sizeof(msg), NULL, 0, true);
 }
 
@@ -403,6 +411,8 @@ static void qcom_glink_send_version_ack(struct qcom_glink *glink)
 	msg.param1 = cpu_to_le16(GLINK_VERSION_1);
 	msg.param2 = cpu_to_le32(glink->features);
 
+	trace_qcom_glink_cmd_version_ack_tx(glink->label, msg.param1, msg.param2);
+
 	qcom_glink_tx(glink, &msg, sizeof(msg), NULL, 0, true);
 }
 
@@ -415,6 +425,9 @@ static void qcom_glink_send_open_ack(struct qcom_glink *glink,
 	msg.param1 = cpu_to_le16(channel->rcid);
 	msg.param2 = cpu_to_le32(0);
 
+	trace_qcom_glink_cmd_open_ack_tx(glink->label, channel->name,
+					 channel->lcid, channel->rcid);
+
 	qcom_glink_tx(glink, &msg, sizeof(msg), NULL, 0, true);
 }
 
@@ -429,6 +442,11 @@ static void qcom_glink_handle_intent_req_ack(struct qcom_glink *glink,
 	spin_lock_irqsave(&glink->idr_lock, flags);
 	channel = idr_find(&glink->rcids, cid);
 	spin_unlock_irqrestore(&glink->idr_lock, flags);
+
+	trace_qcom_glink_cmd_rx_intent_req_ack_rx(glink->label,
+						  channel ? channel->name : NULL,
+						  channel ? channel->lcid : 0,
+						  cid, granted);
 	if (!channel) {
 		dev_err(glink->dev, "unable to find channel\n");
 		return;
@@ -483,6 +501,9 @@ static int qcom_glink_send_open_req(struct qcom_glink *glink,
 	req.msg.param2 = cpu_to_le32(name_len);
 	strcpy(req.name, channel->name);
 
+	trace_qcom_glink_cmd_open_tx(glink->label, channel->name,
+				     channel->lcid, channel->rcid);
+
 	ret = qcom_glink_tx(glink, &req, req_len, NULL, 0, true);
 	if (ret)
 		goto remove_idr;
@@ -507,6 +528,9 @@ static void qcom_glink_send_close_req(struct qcom_glink *glink,
 	req.param1 = cpu_to_le16(channel->lcid);
 	req.param2 = 0;
 
+	trace_qcom_glink_cmd_close_tx(glink->label, channel->name,
+				      channel->lcid, channel->rcid);
+
 	qcom_glink_tx(glink, &req, sizeof(req), NULL, 0, true);
 }
 
@@ -519,6 +543,9 @@ static void qcom_glink_send_close_ack(struct qcom_glink *glink,
 	req.param1 = cpu_to_le16(channel->rcid);
 	req.param2 = 0;
 
+	trace_qcom_glink_cmd_close_ack_tx(glink->label, channel->name,
+					  channel->lcid, channel->rcid);
+
 	qcom_glink_tx(glink, &req, sizeof(req), NULL, 0, true);
 }
 
@@ -550,6 +577,9 @@ static void qcom_glink_rx_done_work(struct work_struct *work)
 		cmd.lcid = cid;
 		cmd.liid = iid;
 
+		trace_qcom_glink_cmd_rx_done_tx(glink->label, channel->name,
+						channel->lcid, channel->rcid, cmd.liid, reuse);
+
 		qcom_glink_tx(glink, &cmd, sizeof(cmd), NULL, 0, true);
 		if (!reuse) {
 			kfree(intent->data);
@@ -600,6 +630,8 @@ static void qcom_glink_receive_version(struct qcom_glink *glink,
 				       u32 version,
 				       u32 features)
 {
+	trace_qcom_glink_cmd_version_rx(glink->label, version, features);
+
 	switch (version) {
 	case 0:
 		break;
@@ -627,6 +659,8 @@ static void qcom_glink_receive_version_ack(struct qcom_glink *glink,
 					   u32 version,
 					   u32 features)
 {
+	trace_qcom_glink_cmd_version_ack_rx(glink->label, version, features);
+
 	switch (version) {
 	case 0:
 		/* Version negotiation failed */
@@ -658,6 +692,10 @@ static int qcom_glink_send_intent_req_ack(struct qcom_glink *glink,
 {
 	struct glink_msg msg;
 
+	trace_qcom_glink_cmd_rx_intent_req_ack_tx(glink->label, channel->name,
+						  channel->lcid, channel->rcid,
+						  granted);
+
 	msg.cmd = cpu_to_le16(GLINK_CMD_RX_INTENT_REQ_ACK);
 	msg.param1 = cpu_to_le16(channel->lcid);
 	msg.param2 = cpu_to_le32(granted);
@@ -695,6 +733,10 @@ static int qcom_glink_advertise_intent(struct qcom_glink *glink,
 	cmd.size = cpu_to_le32(intent->size);
 	cmd.liid = cpu_to_le32(intent->id);
 
+	trace_qcom_glink_cmd_intent_tx(glink->label, channel->name,
+				       channel->lcid, channel->rcid,
+				       cmd.count, cmd.size, cmd.liid);
+
 	qcom_glink_tx(glink, &cmd, sizeof(cmd), NULL, 0, true);
 
 	return 0;
@@ -752,6 +794,9 @@ static void qcom_glink_handle_rx_done(struct qcom_glink *glink,
 	spin_lock_irqsave(&glink->idr_lock, flags);
 	channel = idr_find(&glink->rcids, cid);
 	spin_unlock_irqrestore(&glink->idr_lock, flags);
+
+	trace_qcom_glink_cmd_rx_done_rx(glink->label, channel ? channel->name : NULL,
+					channel ? channel->lcid : 0, cid, iid, reuse);
 	if (!channel) {
 		dev_err(glink->dev, "invalid channel id received\n");
 		return;
@@ -801,6 +846,10 @@ static void qcom_glink_handle_intent_req(struct qcom_glink *glink,
 	channel = idr_find(&glink->rcids, cid);
 	spin_unlock_irqrestore(&glink->idr_lock, flags);
 
+	trace_qcom_glink_cmd_rx_intent_req_rx(glink->label,
+					      channel ? channel->name : NULL,
+					      channel ? channel->lcid : 0,
+					      cid, size);
 	if (!channel) {
 		pr_err("%s channel not found for cid %d\n", __func__, cid);
 		return;
@@ -873,9 +922,15 @@ static int qcom_glink_rx_data(struct qcom_glink *glink, size_t avail)
 	}
 
 	rcid = le16_to_cpu(hdr.msg.param1);
+	liid = le32_to_cpu(hdr.msg.param2);
 	spin_lock_irqsave(&glink->idr_lock, flags);
 	channel = idr_find(&glink->rcids, rcid);
 	spin_unlock_irqrestore(&glink->idr_lock, flags);
+
+	trace_qcom_glink_cmd_tx_data_rx(glink->label, channel ? channel->name : NULL,
+					channel ? channel->lcid : 0, rcid,
+					liid, chunk_size, left_size,
+					hdr.msg.cmd == GLINK_CMD_TX_DATA_CONT);
 	if (!channel) {
 		dev_dbg(glink->dev, "Data on non-existing channel\n");
 
@@ -906,8 +961,6 @@ static int qcom_glink_rx_data(struct qcom_glink *glink, size_t avail)
 			intent = channel->buf;
 		}
 	} else {
-		liid = le32_to_cpu(hdr.msg.param2);
-
 		spin_lock_irqsave(&channel->intent_lock, flags);
 		intent = idr_find(&channel->liids, liid);
 		spin_unlock_irqrestore(&channel->intent_lock, flags);
@@ -958,6 +1011,8 @@ static int qcom_glink_rx_data(struct qcom_glink *glink, size_t avail)
 
 static void qcom_glink_rx_read_notif(struct qcom_glink *glink)
 {
+	trace_qcom_glink_cmd_read_notif_rx(glink->label);
+
 	qcom_glink_rx_advance(glink, ALIGN(sizeof(struct glink_msg), 8));
 	qcom_glink_tx_kick(glink);
 }
@@ -993,6 +1048,7 @@ static void qcom_glink_handle_intent(struct qcom_glink *glink,
 	channel = idr_find(&glink->rcids, cid);
 	spin_unlock_irqrestore(&glink->idr_lock, flags);
 	if (!channel) {
+		trace_qcom_glink_cmd_intent_rx(glink->label, NULL, 0, cid, count, 0, 0);
 		dev_err(glink->dev, "intents for non-existing channel\n");
 		qcom_glink_rx_advance(glink, ALIGN(msglen, 8));
 		return;
@@ -1004,6 +1060,11 @@ static void qcom_glink_handle_intent(struct qcom_glink *glink,
 
 	qcom_glink_rx_peek(glink, msg, 0, msglen);
 
+	trace_qcom_glink_cmd_intent_rx(glink->label, channel->name,
+				       channel->lcid, cid, count,
+				       count > 0 ? msg->intents[0].size : 0,
+				       count > 0 ? msg->intents[0].iid : 0);
+
 	for (i = 0; i < count; ++i) {
 		intent = kzalloc(sizeof(*intent), GFP_ATOMIC);
 		if (!intent)
@@ -1037,6 +1098,9 @@ static int qcom_glink_rx_open_ack(struct qcom_glink *glink, unsigned int lcid)
 	spin_lock(&glink->idr_lock);
 	channel = idr_find(&glink->lcids, lcid);
 	spin_unlock(&glink->idr_lock);
+
+	trace_qcom_glink_cmd_open_ack_rx(glink->label, channel ? channel->name : NULL,
+					 lcid, channel ? channel->rcid : 0);
 	if (!channel) {
 		dev_err(glink->dev, "Invalid open ack packet\n");
 		return -EINVAL;
@@ -1069,6 +1133,9 @@ static int qcom_glink_set_flow_control(struct rpmsg_endpoint *ept, bool pause, u
 	msg.param1 = cpu_to_le16(channel->lcid);
 	msg.param2 = cpu_to_le32(sigs);
 
+	trace_qcom_glink_cmd_signal_tx(glink->label, channel->name,
+				       channel->lcid, channel->rcid, sigs);
+
 	return qcom_glink_tx(glink, &msg, sizeof(msg), NULL, 0, true);
 }
 
@@ -1084,6 +1151,9 @@ static void qcom_glink_handle_signals(struct qcom_glink *glink,
 	spin_lock_irqsave(&glink->idr_lock, flags);
 	channel = idr_find(&glink->rcids, rcid);
 	spin_unlock_irqrestore(&glink->idr_lock, flags);
+
+	trace_qcom_glink_cmd_signal_rx(glink->label, channel ? channel->name : NULL,
+				       channel ? channel->lcid : 0, rcid, sigs);
 	if (!channel) {
 		dev_err(glink->dev, "signal for non-existing channel\n");
 		return;
@@ -1357,6 +1427,10 @@ static int qcom_glink_request_intent(struct qcom_glink *glink,
 	cmd.cid = channel->lcid;
 	cmd.size = size;
 
+	trace_qcom_glink_cmd_rx_intent_req_tx(glink->label, channel->name,
+					      channel->lcid, channel->rcid,
+					      cmd.size);
+
 	ret = qcom_glink_tx(glink, &cmd, sizeof(cmd), NULL, 0, true);
 	if (ret)
 		goto unlock;
@@ -1437,6 +1511,12 @@ static int __qcom_glink_send(struct glink_channel *channel,
 		req.chunk_size = cpu_to_le32(chunk_size);
 		req.left_size = cpu_to_le32(len - offset - chunk_size);
 
+		trace_qcom_glink_cmd_tx_data_tx(glink->label, channel->name,
+						channel->lcid, channel->rcid,
+						iid, chunk_size,
+						len - offset - chunk_size,
+						offset > 0);
+
 		ret = qcom_glink_tx(glink, &req, sizeof(req), data + offset, chunk_size, wait);
 		if (ret) {
 			/* Mark intent available if we failed */
@@ -1552,6 +1632,8 @@ static int qcom_glink_rx_open(struct qcom_glink *glink, unsigned int rcid,
 		create_device = true;
 	}
 
+	trace_qcom_glink_cmd_open_rx(glink->label, name, channel->lcid, rcid);
+
 	spin_lock_irqsave(&glink->idr_lock, flags);
 	ret = idr_alloc(&glink->rcids, channel, rcid, rcid + 1, GFP_ATOMIC);
 	if (ret < 0) {
@@ -1613,6 +1695,9 @@ static void qcom_glink_rx_close(struct qcom_glink *glink, unsigned int rcid)
 	spin_lock_irqsave(&glink->idr_lock, flags);
 	channel = idr_find(&glink->rcids, rcid);
 	spin_unlock_irqrestore(&glink->idr_lock, flags);
+
+	trace_qcom_glink_cmd_close_rx(glink->label, channel ? channel->name : NULL,
+				      channel ? channel->lcid : 0, rcid);
 	if (WARN(!channel, "close request on unknown channel\n"))
 		return;
 
@@ -1649,6 +1734,9 @@ static void qcom_glink_rx_close_ack(struct qcom_glink *glink, unsigned int lcid)
 
 	spin_lock_irqsave(&glink->idr_lock, flags);
 	channel = idr_find(&glink->lcids, lcid);
+
+	trace_qcom_glink_cmd_close_ack_rx(glink->label, channel ? channel->name : NULL,
+					  lcid, channel ? channel->rcid : 0);
 	if (WARN(!channel, "close ack on unknown channel\n")) {
 		spin_unlock_irqrestore(&glink->idr_lock, flags);
 		return;
@@ -1823,6 +1911,10 @@ struct qcom_glink *qcom_glink_native_probe(struct device *dev,
 	idr_init(&glink->lcids);
 	idr_init(&glink->rcids);
 
+	ret = of_property_read_string(dev->of_node, "label", &glink->label);
+	if (ret < 0)
+		glink->label = dev->of_node->name;
+
 	glink->dev->groups = qcom_glink_groups;
 
 	ret = device_add_groups(dev, qcom_glink_groups);
diff --git a/drivers/rpmsg/qcom_glink_trace.h b/drivers/rpmsg/qcom_glink_trace.h
new file mode 100644
index 000000000000..668bdea1d78f
--- /dev/null
+++ b/drivers/rpmsg/qcom_glink_trace.h
@@ -0,0 +1,406 @@
+/* SPDX-License-Identifier: GPL-2.0 */
+
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM qcom_glink
+
+#if !defined(__QCOM_GLINK_TRACE_H__) || defined(TRACE_HEADER_MULTI_READ)
+#define __QCOM_GLINK_TRACE_H__
+
+#include <linux/tracepoint.h>
+#include "qcom_glink_native.h"
+
+
+TRACE_EVENT(qcom_glink_cmd_version,
+	TP_PROTO(const char *remote, unsigned int version, unsigned int features, bool tx),
+	TP_ARGS(remote, version, features, tx),
+	TP_STRUCT__entry(
+		__string(remote, remote)
+		__field(u32, version)
+		__field(u32, features)
+		__field(bool, tx)
+	),
+	TP_fast_assign(
+		__assign_str(remote);
+		__entry->version = version;
+		__entry->features = features;
+		__entry->tx = tx;
+	),
+	TP_printk("%s remote: %s version: %u features: %#x",
+		  __entry->tx ? "tx" : "rx",
+		  __get_str(remote),
+		  __entry->version,
+		  __entry->features
+	)
+);
+#define trace_qcom_glink_cmd_version_tx(...) trace_qcom_glink_cmd_version(__VA_ARGS__, true)
+#define trace_qcom_glink_cmd_version_rx(...) trace_qcom_glink_cmd_version(__VA_ARGS__, false)
+
+TRACE_EVENT(qcom_glink_cmd_version_ack,
+	TP_PROTO(const char *remote, unsigned int version, unsigned int features, bool tx),
+	TP_ARGS(remote, version, features, tx),
+	TP_STRUCT__entry(
+		__string(remote, remote)
+		__field(u32, version)
+		__field(u32, features)
+		__field(bool, tx)
+	),
+	TP_fast_assign(
+		__assign_str(remote);
+		__entry->version = version;
+		__entry->features = features;
+		__entry->tx = tx;
+	),
+	TP_printk("%s remote: %s version: %u features: %#x",
+		  __entry->tx ? "tx" : "rx",
+		  __get_str(remote),
+		  __entry->version,
+		  __entry->features
+	)
+);
+#define trace_qcom_glink_cmd_version_ack_tx(...) trace_qcom_glink_cmd_version_ack(__VA_ARGS__, true)
+#define trace_qcom_glink_cmd_version_ack_rx(...) trace_qcom_glink_cmd_version_ack(__VA_ARGS__, false)
+
+TRACE_EVENT(qcom_glink_cmd_open,
+	TP_PROTO(const char *remote, const char *channel, u16 lcid, u16 rcid, bool tx),
+	TP_ARGS(remote, channel, lcid, rcid, tx),
+	TP_STRUCT__entry(
+		__string(remote, remote)
+		__string(channel, channel)
+		__field(u16, lcid)
+		__field(u16, rcid)
+		__field(bool, tx)
+	),
+	TP_fast_assign(
+		__assign_str(remote);
+		__assign_str(channel);
+		__entry->lcid = lcid;
+		__entry->rcid = rcid;
+		__entry->tx = tx;
+	),
+	TP_printk("%s remote: %s channel: %s[%u/%u]",
+		  __entry->tx ? "tx" : "rx",
+		  __get_str(remote),
+		  __get_str(channel),
+		  __entry->lcid,
+		  __entry->rcid
+	)
+);
+#define trace_qcom_glink_cmd_open_tx(...) trace_qcom_glink_cmd_open(__VA_ARGS__, true)
+#define trace_qcom_glink_cmd_open_rx(...) trace_qcom_glink_cmd_open(__VA_ARGS__, false)
+
+TRACE_EVENT(qcom_glink_cmd_close,
+	TP_PROTO(const char *remote, const char *channel, u16 lcid, u16 rcid, bool tx),
+	TP_ARGS(remote, channel, lcid, rcid, tx),
+	TP_STRUCT__entry(
+		__string(remote, remote)
+		__string(channel, channel)
+		__field(u16, lcid)
+		__field(u16, rcid)
+		__field(bool, tx)
+	),
+	TP_fast_assign(
+		__assign_str(remote);
+		__assign_str(channel);
+		__entry->lcid = lcid;
+		__entry->rcid = rcid;
+		__entry->tx = tx;
+	),
+	TP_printk("%s remote: %s channel: %s[%u/%u]",
+		  __entry->tx ? "tx" : "rx",
+		  __get_str(remote),
+		  __get_str(channel),
+		  __entry->lcid,
+		  __entry->rcid
+	)
+);
+#define trace_qcom_glink_cmd_close_tx(...) trace_qcom_glink_cmd_close(__VA_ARGS__, true)
+#define trace_qcom_glink_cmd_close_rx(...) trace_qcom_glink_cmd_close(__VA_ARGS__, false)
+
+TRACE_EVENT(qcom_glink_cmd_open_ack,
+	TP_PROTO(const char *remote, const char *channel, u16 lcid, u16 rcid, bool tx),
+	TP_ARGS(remote, channel, lcid, rcid, tx),
+	TP_STRUCT__entry(
+		__string(remote, remote)
+		__string(channel, channel)
+		__field(u16, lcid)
+		__field(u16, rcid)
+		__field(bool, tx)
+	),
+	TP_fast_assign(
+		__assign_str(remote);
+		__assign_str(channel);
+		__entry->lcid = lcid;
+		__entry->rcid = rcid;
+		__entry->tx = tx;
+	),
+	TP_printk("%s remote: %s channel: %s[%u/%u]",
+		  __entry->tx ? "tx" : "rx",
+		  __get_str(remote),
+		  __get_str(channel),
+		  __entry->lcid,
+		  __entry->rcid
+	)
+);
+#define trace_qcom_glink_cmd_open_ack_tx(...) trace_qcom_glink_cmd_open_ack(__VA_ARGS__, true)
+#define trace_qcom_glink_cmd_open_ack_rx(...) trace_qcom_glink_cmd_open_ack(__VA_ARGS__, false)
+
+TRACE_EVENT(qcom_glink_cmd_intent,
+	TP_PROTO(const char *remote, const char *channel, u16 lcid, u16 rcid, size_t count, size_t size, u32 liid, bool tx),
+	TP_ARGS(remote, channel, lcid, rcid, count, size, liid, tx),
+	TP_STRUCT__entry(
+		__string(remote, remote)
+		__string(channel, channel)
+		__field(u16, lcid)
+		__field(u16, rcid)
+		__field(u32, count)
+		__field(u32, size)
+		__field(u32, liid)
+		__field(bool, tx)
+	),
+	TP_fast_assign(
+		__assign_str(remote);
+		__assign_str(channel);
+		__entry->lcid = lcid;
+		__entry->rcid = rcid;
+		__entry->count = count;
+		__entry->size = size;
+		__entry->liid = liid;
+		__entry->tx = tx;
+	),
+	TP_printk("%s remote: %s channel: %s[%u/%u] count: %d [size: %d liid: %d]",
+		  __entry->tx ? "tx" : "rx",
+		  __get_str(remote),
+		  __get_str(channel),
+		  __entry->lcid,
+		  __entry->rcid,
+		  __entry->count,
+		  __entry->size,
+		  __entry->liid
+	)
+);
+#define trace_qcom_glink_cmd_intent_tx(...) trace_qcom_glink_cmd_intent(__VA_ARGS__, true)
+#define trace_qcom_glink_cmd_intent_rx(...) trace_qcom_glink_cmd_intent(__VA_ARGS__, false)
+
+TRACE_EVENT(qcom_glink_cmd_rx_done,
+	TP_PROTO(const char *remote, const char *channel, u16 lcid, u16 rcid, u32 iid, bool reuse, bool tx),
+	TP_ARGS(remote, channel, lcid, rcid, iid, reuse, tx),
+	TP_STRUCT__entry(
+		__string(remote, remote)
+		__string(channel, channel)
+		__field(u16, lcid)
+		__field(u16, rcid)
+		__field(u32, iid)
+		__field(bool, reuse)
+		__field(bool, tx)
+	),
+	TP_fast_assign(
+		__assign_str(remote);
+		__assign_str(channel);
+		__entry->lcid = lcid;
+		__entry->rcid = rcid;
+		__entry->iid = iid;
+		__entry->reuse = reuse;
+		__entry->tx = tx;
+	),
+	TP_printk("%s remote: %s channel: %s[%u/%u] iid: %d reuse: %d",
+		  __entry->tx ? "tx" : "rx",
+		  __get_str(remote),
+		  __get_str(channel),
+		  __entry->lcid,
+		  __entry->rcid,
+		  __entry->iid,
+		  __entry->reuse
+	)
+);
+#define trace_qcom_glink_cmd_rx_done_tx(...) trace_qcom_glink_cmd_rx_done(__VA_ARGS__, true)
+#define trace_qcom_glink_cmd_rx_done_rx(...) trace_qcom_glink_cmd_rx_done(__VA_ARGS__, false)
+
+TRACE_EVENT(qcom_glink_cmd_rx_intent_req,
+	TP_PROTO(const char *remote, const char *channel, u16 lcid, u16 rcid, size_t size, bool tx),
+	TP_ARGS(remote, channel, lcid, rcid, size, tx),
+	TP_STRUCT__entry(
+		__string(remote, remote)
+		__string(channel, channel)
+		__field(u16, lcid)
+		__field(u16, rcid)
+		__field(u32, size)
+		__field(bool, tx)
+	),
+	TP_fast_assign(
+		__assign_str(remote);
+		__assign_str(channel);
+		__entry->lcid = lcid;
+		__entry->rcid = rcid;
+		__entry->size = size;
+		__entry->tx = tx;
+	),
+	TP_printk("%s remote: %s channel: %s[%u/%u] size: %d",
+		  __entry->tx ? "tx" : "rx",
+		  __get_str(remote),
+		  __get_str(channel),
+		  __entry->lcid,
+		  __entry->rcid,
+		  __entry->size
+	)
+);
+#define trace_qcom_glink_cmd_rx_intent_req_tx(...) trace_qcom_glink_cmd_rx_intent_req(__VA_ARGS__, true)
+#define trace_qcom_glink_cmd_rx_intent_req_rx(...) trace_qcom_glink_cmd_rx_intent_req(__VA_ARGS__, false)
+
+TRACE_EVENT(qcom_glink_cmd_rx_intent_req_ack,
+	TP_PROTO(const char *remote, const char *channel, u16 lcid, u16 rcid, bool granted, bool tx),
+	TP_ARGS(remote, channel, lcid, rcid, granted, tx),
+	TP_STRUCT__entry(
+		__string(remote, remote)
+		__string(channel, channel)
+		__field(u16, lcid)
+		__field(u16, rcid)
+		__field(bool, granted)
+		__field(bool, tx)
+	),
+	TP_fast_assign(
+		__assign_str(remote);
+		__assign_str(channel);
+		__entry->lcid = lcid;
+		__entry->rcid = rcid;
+		__entry->granted = granted;
+		__entry->tx = tx;
+	),
+	TP_printk("%s remote: %s channel: %s[%u/%u] granted: %d",
+		  __entry->tx ? "tx" : "rx",
+		  __get_str(remote),
+		  __get_str(channel),
+		  __entry->lcid,
+		  __entry->rcid,
+		  __entry->granted
+	)
+);
+#define trace_qcom_glink_cmd_rx_intent_req_ack_tx(...) trace_qcom_glink_cmd_rx_intent_req_ack(__VA_ARGS__, true)
+#define trace_qcom_glink_cmd_rx_intent_req_ack_rx(...) trace_qcom_glink_cmd_rx_intent_req_ack(__VA_ARGS__, false)
+
+TRACE_EVENT(qcom_glink_cmd_tx_data,
+	TP_PROTO(const char *remote, const char *channel, u16 lcid, u16 rcid, u32 iid, u32 chunk_size, u32 left_size, bool cont, bool tx),
+	TP_ARGS(remote, channel, lcid, rcid, iid, chunk_size, left_size, cont, tx),
+	TP_STRUCT__entry(
+		__string(remote, remote)
+		__string(channel, channel)
+		__field(u16, lcid)
+		__field(u16, rcid)
+		__field(u32, iid)
+		__field(u32, chunk_size)
+		__field(u32, left_size)
+		__field(bool, cont)
+		__field(bool, tx)
+	),
+	TP_fast_assign(
+		__assign_str(remote);
+		__assign_str(channel);
+		__entry->lcid = lcid;
+		__entry->rcid = rcid;
+		__entry->iid = iid;
+		__entry->chunk_size = chunk_size;
+		__entry->left_size = left_size;
+		__entry->cont = cont;
+		__entry->tx = tx;
+	),
+	TP_printk("%s remote: %s channel: %s[%u/%u] iid: %d chunk_size: %d left_size: %d cont: %d",
+		  __entry->tx ? "tx" : "rx",
+		  __get_str(remote),
+		  __get_str(channel),
+		  __entry->lcid,
+		  __entry->rcid,
+		  __entry->iid,
+		  __entry->chunk_size,
+		  __entry->left_size,
+		  __entry->cont
+	)
+);
+#define trace_qcom_glink_cmd_tx_data_tx(...) trace_qcom_glink_cmd_tx_data(__VA_ARGS__, true)
+#define trace_qcom_glink_cmd_tx_data_rx(...) trace_qcom_glink_cmd_tx_data(__VA_ARGS__, false)
+
+TRACE_EVENT(qcom_glink_cmd_close_ack,
+	TP_PROTO(const char *remote, const char *channel, u16 lcid, u16 rcid, bool tx),
+	TP_ARGS(remote, channel, lcid, rcid, tx),
+	TP_STRUCT__entry(
+		__string(remote, remote)
+		__string(channel, channel)
+		__field(u16, lcid)
+		__field(u16, rcid)
+		__field(bool, tx)
+	),
+	TP_fast_assign(
+		__assign_str(remote);
+		__assign_str(channel);
+		__entry->lcid = lcid;
+		__entry->rcid = rcid;
+		__entry->tx = tx;
+	),
+	TP_printk("%s remote: %s channel: %s[%u/%u]",
+		  __entry->tx ? "tx" : "rx",
+		  __get_str(remote),
+		  __get_str(channel),
+		  __entry->lcid,
+		  __entry->rcid
+	)
+);
+#define trace_qcom_glink_cmd_close_ack_tx(...) trace_qcom_glink_cmd_close_ack(__VA_ARGS__, true)
+#define trace_qcom_glink_cmd_close_ack_rx(...) trace_qcom_glink_cmd_close_ack(__VA_ARGS__, false)
+
+TRACE_EVENT(qcom_glink_cmd_read_notif,
+	TP_PROTO(const char *remote, bool tx),
+	TP_ARGS(remote, tx),
+	TP_STRUCT__entry(
+		__string(remote, remote)
+		__field(bool, tx)
+	),
+	TP_fast_assign(
+		__assign_str(remote);
+		__entry->tx = tx;
+	),
+	TP_printk("%s remote: %s",
+		  __entry->tx ? "tx" : "rx",
+		  __get_str(remote)
+	)
+);
+#define trace_qcom_glink_cmd_read_notif_tx(...) trace_qcom_glink_cmd_read_notif(__VA_ARGS__, true)
+#define trace_qcom_glink_cmd_read_notif_rx(...) trace_qcom_glink_cmd_read_notif(__VA_ARGS__, false)
+
+TRACE_EVENT(qcom_glink_cmd_signal,
+	TP_PROTO(const char *remote, const char *channel, u16 lcid, u16 rcid, unsigned int signals, bool tx),
+	TP_ARGS(remote, channel, lcid, rcid, signals, tx),
+	TP_STRUCT__entry(
+		__string(remote, remote)
+		__string(channel, channel)
+		__field(u16, lcid)
+		__field(u16, rcid)
+		__field(u32, signals)
+		__field(bool, tx)
+	),
+	TP_fast_assign(
+		__assign_str(remote);
+		__assign_str(channel);
+		__entry->lcid = lcid;
+		__entry->rcid = rcid;
+		__entry->signals = signals;
+		__entry->tx = tx;
+	),
+	TP_printk("%s remote: %s channel: %s[%u/%u] signals: %#x",
+		  __entry->tx ? "tx" : "rx",
+		  __get_str(remote),
+		  __get_str(channel),
+		  __entry->lcid,
+		  __entry->rcid,
+		  __entry->signals
+	)
+);
+#define trace_qcom_glink_cmd_signal_tx(...) trace_qcom_glink_cmd_signal(__VA_ARGS__, true)
+#define trace_qcom_glink_cmd_signal_rx(...) trace_qcom_glink_cmd_signal(__VA_ARGS__, false)
+
+#endif
+
+#undef TRACE_INCLUDE_PATH
+#define TRACE_INCLUDE_PATH .
+
+#undef TRACE_INCLUDE_FILE
+#define TRACE_INCLUDE_FILE qcom_glink_trace
+
+#include <trace/define_trace.h>

-- 
2.34.1

Re: [PATCH 1/3] rpmsg: glink: Tidy up RX advance handling

[Chris Lew]

On 8/5/2024 8:56 PM, Bjorn Andersson wrote:
> The operation of advancing the FIFO receive pointer is sprinkled between
> the interrupt handler itself, and functions being called from this.
> 
> Push all the RX advancement operations to the individual handlers, to
> unify the style across the handling of the various messages.
> 
> Signed-off-by: Bjorn Andersson <quic_bjorande@quicinc.com>
> ---
>   drivers/rpmsg/qcom_glink_native.c | 22 +++++++++++++++-------
>   1 file changed, 15 insertions(+), 7 deletions(-)
> 

Reviewed-by: Chris Lew <quic_clew@quicinc.com>

Re: [PATCH 2/3] rpmsg: glink: Pass channel to qcom_glink_send_close_ack()

[Chris Lew]

On 8/5/2024 8:56 PM, Bjorn Andersson wrote:
> Align the qcom_glink_send_close_ack() arguments with other functions to
> take the struct glink_channel, so that the upcoming tracepoint patch can
> access the channel attributes.
> 
> Signed-off-by: Bjorn Andersson <quic_bjorande@quicinc.com>
> ---
>   drivers/rpmsg/qcom_glink_native.c | 6 +++---
>   1 file changed, 3 insertions(+), 3 deletions(-)
> 

Reviewed-by: Chris Lew <quic_clew@quicinc.com>

Re: [PATCH 3/3] rpmsg: glink: Introduce packet tracepoints

[Chris Lew]

On 8/5/2024 8:56 PM, Bjorn Andersson wrote:
> Introduce tracepoints to allow tracing the GLINK packets being exchanged
> with other subsystems. This is useful for debugging both interaction
> with remote processors and client driver issues, as well as tracking
> latency through the communication stack.
> 
> Channel events are traced with both local and remote channel ids, as
> well as the textual representation when possible. The channel ids are
> useful when matching traces with traces from the firmware side logs,
> while the textual representation is necessary to identify channels when
> we're starting to trace an already running system.
> 
> Signed-off-by: Bjorn Andersson <quic_bjorande@quicinc.com>
> ---
>   drivers/rpmsg/Makefile            |   1 +
>   drivers/rpmsg/qcom_glink_native.c |  96 ++++++++-
>   drivers/rpmsg/qcom_glink_trace.h  | 406 ++++++++++++++++++++++++++++++++++++++
>   3 files changed, 501 insertions(+), 2 deletions(-)
> 

Reviewed-by: Chris Lew <quic_clew@quicinc.com>

Re: [PATCH 0/3] rpmsg: glink: Introduce tracepoints

[Bjorn Andersson]

On Mon, 05 Aug 2024 20:56:24 -0700, Bjorn Andersson wrote:
> When debugging interaction with remoteproc, do performance measurments
> and fix client bugs, it turns out to be very useful to have tracepoints
> throughout GLINK, so introduce this.
> 
> 

Applied, thanks!

[1/3] rpmsg: glink: Tidy up RX advance handling
      commit: 159c79764f37f081b79d577e71b62f0b1b2b1062
[2/3] rpmsg: glink: Pass channel to qcom_glink_send_close_ack()
      commit: 91adb340d1b8fed6507d0143da1f0d8ccb8aeca4
[3/3] rpmsg: glink: Introduce packet tracepoints
      commit: 34f79c11fb2f31ba05f13e42b936b3eae1783d40

Best regards,
-- 
Bjorn Andersson <andersson@kernel.org>