Re: [PATCH v1 1/1] remoteproc: qcom: Add remoteproc tracing

From: Gokul Krishna Krishnakumar
Date: Thu Mar 02 2023 - 22:27:54 EST

Next message: Roxana Bradescu: "Re: [PATCH] x86: enable Data Operand Independent Timing Mode"
Previous message: Rodrigo Vivi: "Re: [PATCH v9 15/15] drm/i915: Add deadline based boost support"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

Hi Bjorn,
Thanks for the review comments.

On 2/27/2023 12:06 PM, Bjorn Andersson wrote:

On Fri, Feb 24, 2023 at 08:51:42AM -0800, Gokul krishna Krishnakumar wrote:

This change adds traces to the following rproc events:
1. subdevices events - (STRAT/STOP/CRASH)
2. subsystem events - (START/STOP/CRASH)
3. RPROC framework events - (Firmware Load/Authentication)

Thanks for proposing the introduction of tracepoints, this is something
we have talked about for years, but no one has shown enough
need/interest to do the work.

Most of the proposed tracepoints would however be very useful if you
move them one step up (or down...) in the stack.

I.e. please move them into the common code.

Moving the traces to one step up in the stack.

Signed-off-by: Gokul krishna Krishnakumar <quic_gokukris@xxxxxxxxxxx>
---
drivers/remoteproc/Makefile | 3 ++-
drivers/remoteproc/qcom_common.c | 25 +++++++++++++++++++
drivers/remoteproc/qcom_q6v5.c | 3 +++
drivers/remoteproc/qcom_q6v5_pas.c | 17 +++++++++++++
drivers/remoteproc/qcom_sysmon.c | 13 ++++++++++
drivers/remoteproc/qcom_tracepoints.c | 10 ++++++++
include/trace/events/rproc_qcom.h | 36 +++++++++++++++++++++++++++
7 files changed, 106 insertions(+), 1 deletion(-)
create mode 100644 drivers/remoteproc/qcom_tracepoints.c
create mode 100644 include/trace/events/rproc_qcom.h

diff --git a/drivers/remoteproc/Makefile b/drivers/remoteproc/Makefile
index 91314a9b43ce..e52fa815ddc0 100644
--- a/drivers/remoteproc/Makefile
+++ b/drivers/remoteproc/Makefile
@@ -22,7 +22,8 @@ obj-$(CONFIG_KEYSTONE_REMOTEPROC) += keystone_remoteproc.o
obj-$(CONFIG_MESON_MX_AO_ARC_REMOTEPROC)+= meson_mx_ao_arc.o
obj-$(CONFIG_PRU_REMOTEPROC) += pru_rproc.o
obj-$(CONFIG_QCOM_PIL_INFO) += qcom_pil_info.o
-obj-$(CONFIG_QCOM_RPROC_COMMON) += qcom_common.o
+obj-$(CONFIG_QCOM_RPROC_COMMON) += rproc_qcom_common.o
+rproc_qcom_common-y := qcom_common.o qcom_tracepoints.o
obj-$(CONFIG_QCOM_Q6V5_COMMON) += qcom_q6v5.o
obj-$(CONFIG_QCOM_Q6V5_ADSP) += qcom_q6v5_adsp.o
obj-$(CONFIG_QCOM_Q6V5_MSS) += qcom_q6v5_mss.o
diff --git a/drivers/remoteproc/qcom_common.c b/drivers/remoteproc/qcom_common.c
index a0d4238492e9..7da3259be14a 100644
--- a/drivers/remoteproc/qcom_common.c
+++ b/drivers/remoteproc/qcom_common.c
@@ -18,6 +18,7 @@
#include <linux/slab.h>
#include <linux/soc/qcom/mdt_loader.h>
#include <linux/soc/qcom/smem.h>
+#include <trace/events/rproc_qcom.h>
#include "remoteproc_internal.h"
#include "qcom_common.h"
@@ -26,6 +27,10 @@
#define to_smd_subdev(d) container_of(d, struct qcom_rproc_subdev, subdev)
#define to_ssr_subdev(d) container_of(d, struct qcom_rproc_ssr, subdev)
+#define GLINK_SUBDEV_NAME "glink"
+#define SMD_SUBDEV_NAME "smd"
+#define SSR_SUBDEV_NAME "ssr"
+
#define MAX_NUM_OF_SS 10
#define MAX_REGION_NAME_LENGTH 16
#define SBL_MINIDUMP_SMEM_ID 602
@@ -189,6 +194,8 @@ static int glink_subdev_start(struct rproc_subdev *subdev)
{
struct qcom_rproc_glink *glink = to_glink_subdev(subdev);
+ trace_rproc_qcom_event(dev_name(glink->dev->parent), GLINK_SUBDEV_NAME, "start");

Please do add individual events, rather than adding a single
trace_printk()-like event. That allows the user to selectively enable
events, and it becomes convenient to use the events in debugging.

Adding spearate trace events for load/start/stop/interrupts/subdevices.

+
glink->edge = qcom_glink_smem_register(glink->dev, glink->node);
return PTR_ERR_OR_ZERO(glink->edge);
[..]

diff --git a/drivers/remoteproc/qcom_q6v5_pas.c b/drivers/remoteproc/qcom_q6v5_pas.c
index 6cc4e13c5d36..27d3a6f8c92f 100644
--- a/drivers/remoteproc/qcom_q6v5_pas.c
+++ b/drivers/remoteproc/qcom_q6v5_pas.c
@@ -24,6 +24,7 @@
#include <linux/soc/qcom/mdt_loader.h>
#include <linux/soc/qcom/smem.h>
#include <linux/soc/qcom/smem_state.h>
+#include <trace/events/rproc_qcom.h>
#include "qcom_common.h"
#include "qcom_pil_info.h"
@@ -206,10 +207,13 @@ static int adsp_load(struct rproc *rproc, const struct firmware *fw)
struct qcom_adsp *adsp = (struct qcom_adsp *)rproc->priv;
int ret;
+ trace_rproc_qcom_event(dev_name(adsp->dev), "adsp_load", "enter");
+
/* Store firmware handle to be used in adsp_start() */
adsp->firmware = fw;
if (adsp->dtb_pas_id) {
+ trace_rproc_qcom_event(dev_name(adsp->dev), "dtb_firmware_loading", "enter");
ret = request_firmware(&adsp->dtb_firmware, adsp->dtb_firmware_name, adsp->dev);
if (ret) {
dev_err(adsp->dev, "request_firmware failed for %s: %d\n",
@@ -231,6 +235,8 @@ static int adsp_load(struct rproc *rproc, const struct firmware *fw)
goto release_dtb_metadata;
}
+ trace_rproc_qcom_event(dev_name(adsp->dev), "adsp_load", "exit");

I believe it would be more useful to capture the error path as well.

Done.

+
return 0;
release_dtb_metadata:
@@ -247,6 +253,8 @@ static int adsp_start(struct rproc *rproc)
struct qcom_adsp *adsp = (struct qcom_adsp *)rproc->priv;
int ret;
+ trace_rproc_qcom_event(dev_name(adsp->dev), "adsp_start", "enter");
+
ret = qcom_q6v5_prepare(&adsp->q6v5);
if (ret)
return ret;
@@ -276,6 +284,7 @@ static int adsp_start(struct rproc *rproc)
}
if (adsp->dtb_pas_id) {
+ trace_rproc_qcom_event(dev_name(adsp->dev), "dtb_auth_reset", "enter");
ret = qcom_scm_pas_auth_and_reset(adsp->dtb_pas_id);
if (ret) {
dev_err(adsp->dev,
@@ -289,6 +298,8 @@ static int adsp_start(struct rproc *rproc)
if (ret)
goto disable_px_supply;
+ trace_rproc_qcom_event(dev_name(adsp->dev), "Q6_firmware_loading", "enter");

I would like this to contain move useful information, e.g. what file is
it that we're trying to load?

And you only put "enter" here because you have a single tracepoint, it
doesn't add any value...

Adding firmware name field in the remoteproc load function.

+
ret = qcom_mdt_load_no_init(adsp->dev, adsp->firmware, rproc->firmware, adsp->pas_id,
adsp->mem_region, adsp->mem_phys, adsp->mem_size,
&adsp->mem_reloc);
@@ -296,6 +307,7 @@ static int adsp_start(struct rproc *rproc)
goto release_pas_metadata;
qcom_pil_info_store(adsp->info_name, adsp->mem_phys, adsp->mem_size);
+ trace_rproc_qcom_event(dev_name(adsp->dev), "Q6_auth_reset", "enter");

When is this tracepoint useful to you? (Same with the mdt loader above)

To see where the boot failed- if it failed in the dtb authentication or it got timed out in the Q6 boot.

Should mdt-loader and scm drivers have their own tracepoints defined?
They are after all called from a variety of other drivers...

Yes I think it would be better to move these trace points to the mdt_loader driver.

ret = qcom_scm_pas_auth_and_reset(adsp->pas_id);
if (ret) {
@@ -303,6 +315,7 @@ static int adsp_start(struct rproc *rproc)
"failed to authenticate image and release reset\n");
goto release_pas_metadata;
}
+ trace_rproc_qcom_event(dev_name(adsp->dev), "Q6_auth_reset", "exit");
ret = qcom_q6v5_wait_for_start(&adsp->q6v5, msecs_to_jiffies(5000));
if (ret == -ETIMEDOUT) {
@@ -364,6 +377,8 @@ static int adsp_stop(struct rproc *rproc)
int handover;
int ret;
+ trace_rproc_qcom_event(dev_name(adsp->dev), "adsp_stop", "enter");
+
ret = qcom_q6v5_request_stop(&adsp->q6v5, adsp->sysmon);
if (ret == -ETIMEDOUT)
dev_err(adsp->dev, "timed out on wait\n");
@@ -385,6 +400,8 @@ static int adsp_stop(struct rproc *rproc)
if (handover)
qcom_pas_handover(&adsp->q6v5);
+ trace_rproc_qcom_event(dev_name(adsp->dev), "adsp_stop", "exit");

You're missing an opportunity to convey the success/failure by not using
"ret".

Adding more information in the trace events.

+
return ret;
}

[..]

diff --git a/include/trace/events/rproc_qcom.h b/include/trace/events/rproc_qcom.h
new file mode 100644
index 000000000000..b8748873ab25
--- /dev/null
+++ b/include/trace/events/rproc_qcom.h
@@ -0,0 +1,36 @@
+/* SPDX-License-Identifier: GPL-2.0-only */
+/*
+ * Copyright (c) 2021 The Linux Foundation. All rights reserved.
+ */
+
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM rproc_qcom
+
+#if !defined(_TRACE_RPROC_QCOM_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_RPROC_QCOM_H
+#include <linux/tracepoint.h>
+
+TRACE_EVENT(rproc_qcom_event,
+
+ TP_PROTO(const char *name, const char *event, const char *subevent),
+
+ TP_ARGS(name, event, subevent),
+
+ TP_STRUCT__entry(
+ __string(name, name)
+ __string(event, event)
+ __string(subevent, subevent)

Please ensure that your trace events are carrying useful information;
as seen above, subevent is not useful in all cases, and in several other
cases you're missing useful information.

Please think beyond printk, and please consider that these buffers could
be consumed by a machine.

Please review the V2 patchset where the events are seperated and more information is passed.

Regards,
Bjorn

+ ),
+
+ TP_fast_assign(
+ __assign_str(name, name);
+ __assign_str(event, event);
+ __assign_str(subevent, subevent);
+ ),
+
+ TP_printk("%s: %s: %s", __get_str(name), __get_str(event), __get_str(subevent))
+);
+#endif /* _TRACE_RPROC_QCOM_H */
+
+/* This part must be outside protection */
+#include <trace/define_trace.h>
--
2.39.2

Thanks,
Gokul

Next message: Roxana Bradescu: "Re: [PATCH] x86: enable Data Operand Independent Timing Mode"
Previous message: Rodrigo Vivi: "Re: [PATCH v9 15/15] drm/i915: Add deadline based boost support"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]