firmware: arm_scmi: Track basic SCMI communication debug metrics

Add the support for counting some of the SCMI communication debug metrics
like how many were sent successfully or with some errors, responses
received, notifications and delayed responses, transfer timeouts and
errors from the firmware/platform.

In many cases, the traces exists. But the traces are not always necessarily
enabled and getting such cumulative SCMI communication debug metrics helps
in understanding if there are any possible improvements that can be made
on either side of SCMI communication.

Signed-off-by: Luke Parkin <luke.parkin@arm.com>
Reviewed-by: Cristian Marussi <cristian.marussi@arm.com>
Tested-by: Cristian Marussi <cristian.marussi@arm.com>
Message-Id: <20240805131013.587016-4-sudeep.holla@arm.com>
Signed-off-by: Sudeep Holla <sudeep.holla@arm.com>

diff --git a/drivers/firmware/arm_scmi/common.h b/drivers/firmware/arm_scmi/common.h
index d414b0a43b3bda71be268212435779218072d276..21c94deaf6147c854dfeefa131fb2e6143290ae5 100644 (file)
--- a/drivers/firmware/arm_scmi/common.h
+++ b/drivers/firmware/arm_scmi/common.h
@@ -302,6 +302,20 @@ extern const struct scmi_desc scmi_optee_desc;
 void scmi_rx_callback(struct scmi_chan_info *cinfo, u32 msg_hdr, void *priv);
 
 enum debug_counters {
+       SENT_OK,
+       SENT_FAIL,
+       SENT_FAIL_POLLING_UNSUPPORTED,
+       SENT_FAIL_CHANNEL_NOT_FOUND,
+       RESPONSE_OK,
+       NOTIFICATION_OK,
+       DELAYED_RESPONSE_OK,
+       XFERS_RESPONSE_TIMEOUT,
+       XFERS_RESPONSE_POLLED_TIMEOUT,
+       RESPONSE_POLLED_OK,
+       ERR_MSG_UNEXPECTED,
+       ERR_MSG_INVALID,
+       ERR_MSG_NOMEM,
+       ERR_PROTOCOL,
        SCMI_DEBUG_COUNTERS_LAST
 };
 

diff --git a/drivers/firmware/arm_scmi/driver.c b/drivers/firmware/arm_scmi/driver.c
index 958b2ac92050b7ceaafd5398a0db8e70aa5700f8..943ba03315de90de3dbae750198f81a46d8c5c51 100644 (file)
--- a/drivers/firmware/arm_scmi/driver.c
+++ b/drivers/firmware/arm_scmi/driver.c
@@ -990,6 +990,7 @@ scmi_xfer_command_acquire(struct scmi_chan_info *cinfo, u32 msg_hdr)
                spin_unlock_irqrestore(&minfo->xfer_lock, flags);
 
                scmi_bad_message_trace(cinfo, msg_hdr, MSG_UNEXPECTED);
+               scmi_inc_count(info->dbg->counters, ERR_MSG_UNEXPECTED);
 
                return xfer;
        }
@@ -1017,6 +1018,8 @@ scmi_xfer_command_acquire(struct scmi_chan_info *cinfo, u32 msg_hdr)
                        msg_type, xfer_id, msg_hdr, xfer->state);
 
                scmi_bad_message_trace(cinfo, msg_hdr, MSG_INVALID);
+               scmi_inc_count(info->dbg->counters, ERR_MSG_INVALID);
+
 
                /* On error the refcount incremented above has to be dropped */
                __scmi_xfer_put(minfo, xfer);
@@ -1056,6 +1059,7 @@ static void scmi_handle_notification(struct scmi_chan_info *cinfo,
                        PTR_ERR(xfer));
 
                scmi_bad_message_trace(cinfo, msg_hdr, MSG_NOMEM);
+               scmi_inc_count(info->dbg->counters, ERR_MSG_NOMEM);
 
                scmi_clear_channel(info, cinfo);
                return;
@@ -1071,6 +1075,7 @@ static void scmi_handle_notification(struct scmi_chan_info *cinfo,
        trace_scmi_msg_dump(info->id, cinfo->id, xfer->hdr.protocol_id,
                            xfer->hdr.id, "NOTI", xfer->hdr.seq,
                            xfer->hdr.status, xfer->rx.buf, xfer->rx.len);
+       scmi_inc_count(info->dbg->counters, NOTIFICATION_OK);
 
        scmi_notify(cinfo->handle, xfer->hdr.protocol_id,
                    xfer->hdr.id, xfer->rx.buf, xfer->rx.len, ts);
@@ -1130,8 +1135,10 @@ static void scmi_handle_response(struct scmi_chan_info *cinfo,
        if (xfer->hdr.type == MSG_TYPE_DELAYED_RESP) {
                scmi_clear_channel(info, cinfo);
                complete(xfer->async_done);
+               scmi_inc_count(info->dbg->counters, DELAYED_RESPONSE_OK);
        } else {
                complete(&xfer->done);
+               scmi_inc_count(info->dbg->counters, RESPONSE_OK);
        }
 
        if (IS_ENABLED(CONFIG_ARM_SCMI_RAW_MODE_SUPPORT)) {
@@ -1215,6 +1222,7 @@ static int scmi_wait_for_reply(struct device *dev, const struct scmi_desc *desc,
                               struct scmi_xfer *xfer, unsigned int timeout_ms)
 {
        int ret = 0;
+       struct scmi_info *info = handle_to_scmi_info(cinfo->handle);
 
        if (xfer->hdr.poll_completion) {
                /*
@@ -1235,13 +1243,12 @@ static int scmi_wait_for_reply(struct device *dev, const struct scmi_desc *desc,
                                        "timed out in resp(caller: %pS) - polling\n",
                                        (void *)_RET_IP_);
                                ret = -ETIMEDOUT;
+                               scmi_inc_count(info->dbg->counters, XFERS_RESPONSE_POLLED_TIMEOUT);
                        }
                }
 
                if (!ret) {
                        unsigned long flags;
-                       struct scmi_info *info =
-                               handle_to_scmi_info(cinfo->handle);
 
                        /*
                         * Do not fetch_response if an out-of-order delayed
@@ -1261,6 +1268,7 @@ static int scmi_wait_for_reply(struct device *dev, const struct scmi_desc *desc,
                                            "RESP" : "resp",
                                            xfer->hdr.seq, xfer->hdr.status,
                                            xfer->rx.buf, xfer->rx.len);
+                       scmi_inc_count(info->dbg->counters, RESPONSE_POLLED_OK);
 
                        if (IS_ENABLED(CONFIG_ARM_SCMI_RAW_MODE_SUPPORT)) {
                                scmi_raw_message_report(info->raw, xfer,
@@ -1275,6 +1283,7 @@ static int scmi_wait_for_reply(struct device *dev, const struct scmi_desc *desc,
                        dev_err(dev, "timed out in resp(caller: %pS)\n",
                                (void *)_RET_IP_);
                        ret = -ETIMEDOUT;
+                       scmi_inc_count(info->dbg->counters, XFERS_RESPONSE_TIMEOUT);
                }
        }
 
@@ -1358,13 +1367,15 @@ static int do_xfer(const struct scmi_protocol_handle *ph,
            !is_transport_polling_capable(info->desc)) {
                dev_warn_once(dev,
                              "Polling mode is not supported by transport.\n");
+               scmi_inc_count(info->dbg->counters, SENT_FAIL_POLLING_UNSUPPORTED);
                return -EINVAL;
        }
 
        cinfo = idr_find(&info->tx_idr, pi->proto->id);
-       if (unlikely(!cinfo))
+       if (unlikely(!cinfo)) {
+               scmi_inc_count(info->dbg->counters, SENT_FAIL_CHANNEL_NOT_FOUND);
                return -EINVAL;
-
+       }
        /* True ONLY if also supported by transport. */
        if (is_polling_enabled(cinfo, info->desc))
                xfer->hdr.poll_completion = true;
@@ -1396,16 +1407,20 @@ static int do_xfer(const struct scmi_protocol_handle *ph,
        ret = info->desc->ops->send_message(cinfo, xfer);
        if (ret < 0) {
                dev_dbg(dev, "Failed to send message %d\n", ret);
+               scmi_inc_count(info->dbg->counters, SENT_FAIL);
                return ret;
        }
 
        trace_scmi_msg_dump(info->id, cinfo->id, xfer->hdr.protocol_id,
                            xfer->hdr.id, "CMND", xfer->hdr.seq,
                            xfer->hdr.status, xfer->tx.buf, xfer->tx.len);
+       scmi_inc_count(info->dbg->counters, SENT_OK);
 
        ret = scmi_wait_for_message_response(cinfo, xfer);
-       if (!ret && xfer->hdr.status)
+       if (!ret && xfer->hdr.status) {
                ret = scmi_to_linux_errno(xfer->hdr.status);
+               scmi_inc_count(info->dbg->counters, ERR_PROTOCOL);
+       }
 
        if (info->desc->ops->mark_txdone)
                info->desc->ops->mark_txdone(cinfo, ret, xfer);