rpmsg: glink: Introduce packet tracepoints

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 <[email protected]>
Reviewed-by: Chris Lew <[email protected]>
Link: https://lore.kernel.org/r/[email protected]
Signed-off-by: Bjorn Andersson <[email protected]>

Author: quic-bjorande

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

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);