LinuxLists.cc - [PATCH v1 0/1] Add trace events for remoteproc

2023-02-24 16:52:13

Subject: [PATCH v1 0/1] Add trace events for remoteproc

This patch attempts to add traces for important remoteproc events,
this will help in debugging errors with the subsystem restart and
also helps in getting an estimate on how long each event takes to run.

Gokul krishna Krishnakumar (1):
remoteproc: qcom: Add remoteproc tracing

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

base-commit: 7c855ef7137a67bcff0e039691b969428dd8ef6a
--
2.39.2

2023-02-24 16:52:16

by Gokul krishna Krishnakumar

[permalink] [raw]

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

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)

Signed-off-by: Gokul krishna Krishnakumar <[email protected]>
---
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");
+
glink->edge = qcom_glink_smem_register(glink->dev, glink->node);

return PTR_ERR_OR_ZERO(glink->edge);
@@ -198,6 +205,9 @@ static void glink_subdev_stop(struct rproc_subdev *subdev, bool crashed)
{
struct qcom_rproc_glink *glink = to_glink_subdev(subdev);

+ trace_rproc_qcom_event(dev_name(glink->dev->parent), GLINK_SUBDEV_NAME,
+ crashed ? "crash stop" : "stop");
+
qcom_glink_smem_unregister(glink->edge);
glink->edge = NULL;
}
@@ -206,6 +216,8 @@ static void glink_subdev_unprepare(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, "unprepare");
+
qcom_glink_ssr_notify(glink->ssr_name);
}

@@ -300,6 +312,8 @@ static int smd_subdev_start(struct rproc_subdev *subdev)
{
struct qcom_rproc_subdev *smd = to_smd_subdev(subdev);

+ trace_rproc_qcom_event(dev_name(smd->dev->parent), SMD_SUBDEV_NAME, "start");
+
smd->edge = qcom_smd_register_edge(smd->dev, smd->node);

return PTR_ERR_OR_ZERO(smd->edge);
@@ -309,6 +323,9 @@ static void smd_subdev_stop(struct rproc_subdev *subdev, bool crashed)
{
struct qcom_rproc_subdev *smd = to_smd_subdev(subdev);

+ trace_rproc_qcom_event(dev_name(smd->dev->parent), SMD_SUBDEV_NAME,
+ crashed ? "crash stop" : "stop");
+
qcom_smd_unregister_edge(smd->edge);
smd->edge = NULL;
}
@@ -425,6 +442,8 @@ static int ssr_notify_prepare(struct rproc_subdev *subdev)
.crashed = false,
};

+ trace_rproc_qcom_event(ssr->info->name, SSR_SUBDEV_NAME, "prepare");
+
srcu_notifier_call_chain(&ssr->info->notifier_list,
QCOM_SSR_BEFORE_POWERUP, &data);
return 0;
@@ -438,6 +457,8 @@ static int ssr_notify_start(struct rproc_subdev *subdev)
.crashed = false,
};

+ trace_rproc_qcom_event(ssr->info->name, SSR_SUBDEV_NAME, "start");
+
srcu_notifier_call_chain(&ssr->info->notifier_list,
QCOM_SSR_AFTER_POWERUP, &data);
return 0;
@@ -451,6 +472,8 @@ static void ssr_notify_stop(struct rproc_subdev *subdev, bool crashed)
.crashed = crashed,
};

+ trace_rproc_qcom_event(ssr->info->name, SSR_SUBDEV_NAME, crashed ? "crash stop" : "stop");
+
srcu_notifier_call_chain(&ssr->info->notifier_list,
QCOM_SSR_BEFORE_SHUTDOWN, &data);
}
@@ -463,6 +486,8 @@ static void ssr_notify_unprepare(struct rproc_subdev *subdev)
.crashed = false,
};

+ trace_rproc_qcom_event(ssr->info->name, SSR_SUBDEV_NAME, "unprepare");
+
srcu_notifier_call_chain(&ssr->info->notifier_list,
QCOM_SSR_AFTER_SHUTDOWN, &data);
}
diff --git a/drivers/remoteproc/qcom_q6v5.c b/drivers/remoteproc/qcom_q6v5.c
index 192c7aa0e39e..31bbbe16363e 100644
--- a/drivers/remoteproc/qcom_q6v5.c
+++ b/drivers/remoteproc/qcom_q6v5.c
@@ -14,6 +14,7 @@
#include <linux/soc/qcom/qcom_aoss.h>
#include <linux/soc/qcom/smem.h>
#include <linux/soc/qcom/smem_state.h>
+#include <trace/events/rproc_qcom.h>
#include <linux/remoteproc.h>
#include "qcom_common.h"
#include "qcom_q6v5.h"
@@ -113,6 +114,7 @@ static irqreturn_t q6v5_wdog_interrupt(int irq, void *data)
dev_err(q6v5->dev, "watchdog without message\n");

q6v5->running = false;
+ trace_rproc_qcom_event(dev_name(q6v5->dev), "q6v5_wdog", msg);
rproc_report_crash(q6v5->rproc, RPROC_WATCHDOG);

return IRQ_HANDLED;
@@ -134,6 +136,7 @@ static irqreturn_t q6v5_fatal_interrupt(int irq, void *data)
dev_err(q6v5->dev, "fatal error without message\n");

q6v5->running = false;
+ trace_rproc_qcom_event(dev_name(q6v5->dev), "q6v5_fatal", msg);
rproc_report_crash(q6v5->rproc, RPROC_FATAL_ERROR);

return IRQ_HANDLED;
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");
+
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");
+
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");

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");
+
return ret;
}

diff --git a/drivers/remoteproc/qcom_sysmon.c b/drivers/remoteproc/qcom_sysmon.c
index 746f56b4bafb..57b8a03d4a30 100644
--- a/drivers/remoteproc/qcom_sysmon.c
+++ b/drivers/remoteproc/qcom_sysmon.c
@@ -13,9 +13,12 @@
#include <linux/platform_device.h>
#include <linux/remoteproc/qcom_rproc.h>
#include <linux/rpmsg.h>
+#include <trace/events/rproc_qcom.h>

#include "qcom_common.h"

+#define SYSMON_SUBDEV_NAME "sysmon"
+
static BLOCKING_NOTIFIER_HEAD(sysmon_notifiers);

struct qcom_sysmon {
@@ -477,6 +480,8 @@ static int sysmon_prepare(struct rproc_subdev *subdev)
.ssr_event = SSCTL_SSR_EVENT_BEFORE_POWERUP
};

+ trace_rproc_qcom_event(dev_name(sysmon->rproc->dev.parent), SYSMON_SUBDEV_NAME, "prepare");
+
mutex_lock(&sysmon->state_lock);
sysmon->state = SSCTL_SSR_EVENT_BEFORE_POWERUP;
blocking_notifier_call_chain(&sysmon_notifiers, 0, (void *)&event);
@@ -504,6 +509,8 @@ static int sysmon_start(struct rproc_subdev *subdev)
.ssr_event = SSCTL_SSR_EVENT_AFTER_POWERUP
};

+ trace_rproc_qcom_event(dev_name(sysmon->rproc->dev.parent), SYSMON_SUBDEV_NAME, "start");
+
reinit_completion(&sysmon->ssctl_comp);
mutex_lock(&sysmon->state_lock);
sysmon->state = SSCTL_SSR_EVENT_AFTER_POWERUP;
@@ -540,6 +547,9 @@ static void sysmon_stop(struct rproc_subdev *subdev, bool crashed)
.ssr_event = SSCTL_SSR_EVENT_BEFORE_SHUTDOWN
};

+ trace_rproc_qcom_event(dev_name(sysmon->rproc->dev.parent), SYSMON_SUBDEV_NAME,
+ crashed ? "crash stop" : "stop");
+
sysmon->shutdown_acked = false;

mutex_lock(&sysmon->state_lock);
@@ -571,6 +581,9 @@ static void sysmon_unprepare(struct rproc_subdev *subdev)
.ssr_event = SSCTL_SSR_EVENT_AFTER_SHUTDOWN
};

+ trace_rproc_qcom_event(dev_name(sysmon->rproc->dev.parent), SYSMON_SUBDEV_NAME,
+ "unprepare");
+
mutex_lock(&sysmon->state_lock);
sysmon->state = SSCTL_SSR_EVENT_AFTER_SHUTDOWN;
blocking_notifier_call_chain(&sysmon_notifiers, 0, (void *)&event);
diff --git a/drivers/remoteproc/qcom_tracepoints.c b/drivers/remoteproc/qcom_tracepoints.c
new file mode 100644
index 000000000000..546ebe90f141
--- /dev/null
+++ b/drivers/remoteproc/qcom_tracepoints.c
@@ -0,0 +1,10 @@
+// SPDX-License-Identifier: GPL-2.0-only
+/*
+ * Qualcomm Technologies, Inc. Peripheral Image Loader helpers
+ *
+ * Copyright (c) 2021 The Linux Foundation. All rights reserved.
+ */
+
+#define CREATE_TRACE_POINTS
+#include <trace/events/rproc_qcom.h>
+EXPORT_TRACEPOINT_SYMBOL(rproc_qcom_event);
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)
+ ),
+
+ 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

2023-02-24 17:08:45

by Elliot Berman

[permalink] [raw]

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

On 2/24/2023 8:51 AM, 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)
>
> Signed-off-by: Gokul krishna Krishnakumar <[email protected]>
> ---
> 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");
> +
> glink->edge = qcom_glink_smem_register(glink->dev, glink->node);
>
> return PTR_ERR_OR_ZERO(glink->edge);
> @@ -198,6 +205,9 @@ static void glink_subdev_stop(struct rproc_subdev *subdev, bool crashed)
> {
> struct qcom_rproc_glink *glink = to_glink_subdev(subdev);
>
> + trace_rproc_qcom_event(dev_name(glink->dev->parent), GLINK_SUBDEV_NAME,
> + crashed ? "crash stop" : "stop");
> +
> qcom_glink_smem_unregister(glink->edge);
> glink->edge = NULL;
> }
> @@ -206,6 +216,8 @@ static void glink_subdev_unprepare(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, "unprepare");
> +
> qcom_glink_ssr_notify(glink->ssr_name);
> }
>
> @@ -300,6 +312,8 @@ static int smd_subdev_start(struct rproc_subdev *subdev)
> {
> struct qcom_rproc_subdev *smd = to_smd_subdev(subdev);
>
> + trace_rproc_qcom_event(dev_name(smd->dev->parent), SMD_SUBDEV_NAME, "start");
> +
> smd->edge = qcom_smd_register_edge(smd->dev, smd->node);
>
> return PTR_ERR_OR_ZERO(smd->edge);
> @@ -309,6 +323,9 @@ static void smd_subdev_stop(struct rproc_subdev *subdev, bool crashed)
> {
> struct qcom_rproc_subdev *smd = to_smd_subdev(subdev);
>
> + trace_rproc_qcom_event(dev_name(smd->dev->parent), SMD_SUBDEV_NAME,
> + crashed ? "crash stop" : "stop");
> +
> qcom_smd_unregister_edge(smd->edge);
> smd->edge = NULL;
> }
> @@ -425,6 +442,8 @@ static int ssr_notify_prepare(struct rproc_subdev *subdev)
> .crashed = false,
> };
>
> + trace_rproc_qcom_event(ssr->info->name, SSR_SUBDEV_NAME, "prepare");
> +
> srcu_notifier_call_chain(&ssr->info->notifier_list,
> QCOM_SSR_BEFORE_POWERUP, &data);
> return 0;
> @@ -438,6 +457,8 @@ static int ssr_notify_start(struct rproc_subdev *subdev)
> .crashed = false,
> };
>
> + trace_rproc_qcom_event(ssr->info->name, SSR_SUBDEV_NAME, "start");
> +
> srcu_notifier_call_chain(&ssr->info->notifier_list,
> QCOM_SSR_AFTER_POWERUP, &data);
> return 0;
> @@ -451,6 +472,8 @@ static void ssr_notify_stop(struct rproc_subdev *subdev, bool crashed)
> .crashed = crashed,
> };
>
> + trace_rproc_qcom_event(ssr->info->name, SSR_SUBDEV_NAME, crashed ? "crash stop" : "stop");
> +
> srcu_notifier_call_chain(&ssr->info->notifier_list,
> QCOM_SSR_BEFORE_SHUTDOWN, &data);
> }
> @@ -463,6 +486,8 @@ static void ssr_notify_unprepare(struct rproc_subdev *subdev)
> .crashed = false,
> };
>
> + trace_rproc_qcom_event(ssr->info->name, SSR_SUBDEV_NAME, "unprepare");
> +
> srcu_notifier_call_chain(&ssr->info->notifier_list,
> QCOM_SSR_AFTER_SHUTDOWN, &data);
> }
> diff --git a/drivers/remoteproc/qcom_q6v5.c b/drivers/remoteproc/qcom_q6v5.c
> index 192c7aa0e39e..31bbbe16363e 100644
> --- a/drivers/remoteproc/qcom_q6v5.c
> +++ b/drivers/remoteproc/qcom_q6v5.c
> @@ -14,6 +14,7 @@
> #include <linux/soc/qcom/qcom_aoss.h>
> #include <linux/soc/qcom/smem.h>
> #include <linux/soc/qcom/smem_state.h>
> +#include <trace/events/rproc_qcom.h>
> #include <linux/remoteproc.h>
> #include "qcom_common.h"
> #include "qcom_q6v5.h"
> @@ -113,6 +114,7 @@ static irqreturn_t q6v5_wdog_interrupt(int irq, void *data)
> dev_err(q6v5->dev, "watchdog without message\n");
>
> q6v5->running = false;
> + trace_rproc_qcom_event(dev_name(q6v5->dev), "q6v5_wdog", msg);
> rproc_report_crash(q6v5->rproc, RPROC_WATCHDOG);
>
> return IRQ_HANDLED;
> @@ -134,6 +136,7 @@ static irqreturn_t q6v5_fatal_interrupt(int irq, void *data)
> dev_err(q6v5->dev, "fatal error without message\n");
>
> q6v5->running = false;
> + trace_rproc_qcom_event(dev_name(q6v5->dev), "q6v5_fatal", msg);
> rproc_report_crash(q6v5->rproc, RPROC_FATAL_ERROR);
>
> return IRQ_HANDLED;
> 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");
> +
> 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");
> +
> 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");
>
> 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");
> +
> return ret;
> }
>
> diff --git a/drivers/remoteproc/qcom_sysmon.c b/drivers/remoteproc/qcom_sysmon.c
> index 746f56b4bafb..57b8a03d4a30 100644
> --- a/drivers/remoteproc/qcom_sysmon.c
> +++ b/drivers/remoteproc/qcom_sysmon.c
> @@ -13,9 +13,12 @@
> #include <linux/platform_device.h>
> #include <linux/remoteproc/qcom_rproc.h>
> #include <linux/rpmsg.h>
> +#include <trace/events/rproc_qcom.h>
>
> #include "qcom_common.h"
>
> +#define SYSMON_SUBDEV_NAME "sysmon"
> +
> static BLOCKING_NOTIFIER_HEAD(sysmon_notifiers);
>
> struct qcom_sysmon {
> @@ -477,6 +480,8 @@ static int sysmon_prepare(struct rproc_subdev *subdev)
> .ssr_event = SSCTL_SSR_EVENT_BEFORE_POWERUP
> };
>
> + trace_rproc_qcom_event(dev_name(sysmon->rproc->dev.parent), SYSMON_SUBDEV_NAME, "prepare");
> +
> mutex_lock(&sysmon->state_lock);
> sysmon->state = SSCTL_SSR_EVENT_BEFORE_POWERUP;
> blocking_notifier_call_chain(&sysmon_notifiers, 0, (void *)&event);
> @@ -504,6 +509,8 @@ static int sysmon_start(struct rproc_subdev *subdev)
> .ssr_event = SSCTL_SSR_EVENT_AFTER_POWERUP
> };
>
> + trace_rproc_qcom_event(dev_name(sysmon->rproc->dev.parent), SYSMON_SUBDEV_NAME, "start");
> +
> reinit_completion(&sysmon->ssctl_comp);
> mutex_lock(&sysmon->state_lock);
> sysmon->state = SSCTL_SSR_EVENT_AFTER_POWERUP;
> @@ -540,6 +547,9 @@ static void sysmon_stop(struct rproc_subdev *subdev, bool crashed)
> .ssr_event = SSCTL_SSR_EVENT_BEFORE_SHUTDOWN
> };
>
> + trace_rproc_qcom_event(dev_name(sysmon->rproc->dev.parent), SYSMON_SUBDEV_NAME,
> + crashed ? "crash stop" : "stop");
> +
> sysmon->shutdown_acked = false;
>
> mutex_lock(&sysmon->state_lock);
> @@ -571,6 +581,9 @@ static void sysmon_unprepare(struct rproc_subdev *subdev)
> .ssr_event = SSCTL_SSR_EVENT_AFTER_SHUTDOWN
> };
>
> + trace_rproc_qcom_event(dev_name(sysmon->rproc->dev.parent), SYSMON_SUBDEV_NAME,
> + "unprepare");
> +
> mutex_lock(&sysmon->state_lock);
> sysmon->state = SSCTL_SSR_EVENT_AFTER_SHUTDOWN;
> blocking_notifier_call_chain(&sysmon_notifiers, 0, (void *)&event);
> diff --git a/drivers/remoteproc/qcom_tracepoints.c b/drivers/remoteproc/qcom_tracepoints.c
> new file mode 100644
> index 000000000000..546ebe90f141
> --- /dev/null
> +++ b/drivers/remoteproc/qcom_tracepoints.c
> @@ -0,0 +1,10 @@
> +// SPDX-License-Identifier: GPL-2.0-only
> +/*
> + * Qualcomm Technologies, Inc. Peripheral Image Loader helpers
> + *
> + * Copyright (c) 2021 The Linux Foundation. All rights reserved.

2023 QuIC copyright?

> + */
> +
> +#define CREATE_TRACE_POINTS
> +#include <trace/events/rproc_qcom.h>
> +EXPORT_TRACEPOINT_SYMBOL(rproc_qcom_event);
> 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.

Ditto

> + */
> +
> +#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)
> + ),
> +
> + 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>

2023-02-24 17:17:21

by Trilok Soni

[permalink] [raw]

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

2023-02-27 19:33:12

by Bjorn Andersson

[permalink] [raw]

Subject: Re: [PATCH v1 0/1] Add trace events for remoteproc

On Fri, Feb 24, 2023 at 08:51:41AM -0800, Gokul krishna Krishnakumar wrote:
> This patch attempts to add traces for important remoteproc events,
> this will help in debugging errors with the subsystem restart and
> also helps in getting an estimate on how long each event takes to run.
>

Please skip sending cover-letters for single patches. Also, this is the
kind of motivation that should be included in the commit message.

Thanks,
Bjorn

> Gokul krishna Krishnakumar (1):
> remoteproc: qcom: Add remoteproc tracing
>
> 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
>
>
> base-commit: 7c855ef7137a67bcff0e039691b969428dd8ef6a
> --
> 2.39.2
>

2023-02-27 19:55:55

by Gokul krishna Krishnakumar

[permalink] [raw]

Subject: Re: [PATCH v1 0/1] Add trace events for remoteproc

On 2/27/2023 11:36 AM, Bjorn Andersson wrote:
> On Fri, Feb 24, 2023 at 08:51:41AM -0800, Gokul krishna Krishnakumar wrote:
>> This patch attempts to add traces for important remoteproc events,
>> this will help in debugging errors with the subsystem restart and
>> also helps in getting an estimate on how long each event takes to run.
>>
>
> Please skip sending cover-letters for single patches. Also, this is the
> kind of motivation that should be included in the commit message.
>
> Thanks,
> Bjorn
>
Thanks Bjorn, Moving this to the commit text.
>> Gokul krishna Krishnakumar (1):
>> remoteproc: qcom: Add remoteproc tracing
>>
>> 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
>>
>>
>> base-commit: 7c855ef7137a67bcff0e039691b969428dd8ef6a
>> --
>> 2.39.2
>>
Thanks,
Gokul

2023-02-27 20:03:28

by Bjorn Andersson

[permalink] [raw]

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

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.

> Signed-off-by: Gokul krishna Krishnakumar <[email protected]>
> ---
> 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.

> +
> 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.

> +
> 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...

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

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

> 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".

> +
> 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.

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
>

2023-03-03 03:27:53

by Gokul krishna Krishnakumar

[permalink] [raw]

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

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 <[email protected]>
>> ---
>> 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