Re: [PATCH v2 3/3] remoteproc: Add ftrace events to trace lifecycle of remoteprocs

From: Bjorn Andersson
Date: Thu Dec 10 2020 - 13:18:32 EST

Next message: Geva, Erez: "Re: [PATCH 1/3] Add TX sending hardware timestamp."
Previous message: Mark Brown: "Re: Re: [PATCH] spi: Limit the spi device max speed to controller's max speed"
In reply to: Bjorn Andersson: "Re: [PATCH v2 3/3] remoteproc: Add ftrace events to trace lifecycle of remoteprocs"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

On Wed 18 Nov 16:26 CST 2020, Mathieu Poirier wrote:

> On Mon, Nov 16, 2020 at 01:44:44PM -0800, Rishabh Bhatnagar wrote:
> > Add trace events to trace bootup/shutdown/recovery of remote
> > processors. These events are useful in analyzing the time
> > spent in each step in the life cycle and can be used for
> > performace analysis. Also these serve as standard checkpoints
> > in debugging.
> >
> > Signed-off-by: Rishabh Bhatnagar <rishabhb@xxxxxxxxxxxxxx>
> > ---
> > drivers/remoteproc/remoteproc_core.c | 19 +++++++-
> > include/trace/events/remoteproc.h | 91 ++++++++++++++++++++++++++++++++++++
> > 2 files changed, 109 insertions(+), 1 deletion(-)
> > create mode 100644 include/trace/events/remoteproc.h
> >
> > diff --git a/drivers/remoteproc/remoteproc_core.c b/drivers/remoteproc/remoteproc_core.c
> > index dab2c0f..39da409 100644
> > --- a/drivers/remoteproc/remoteproc_core.c
> > +++ b/drivers/remoteproc/remoteproc_core.c
> > @@ -42,6 +42,9 @@
> >
> > #include "remoteproc_internal.h"
> >
> > +#define CREATE_TRACE_POINTS
> > +#include <trace/events/remoteproc.h>
> > +
> > #define HIGH_BITS_MASK 0xFFFFFFFF00000000ULL
> >
> > static DEFINE_MUTEX(rproc_list_mutex);
> > @@ -1164,6 +1167,7 @@ static int rproc_prepare_subdevices(struct rproc *rproc)
> > struct rproc_subdev *subdev;
> > int ret;
> >
> > + trace_rproc_subdevices("Prepare subdevices", rproc->name);
>
> I wouldn't add this to the core - after a while they become part of the ABI and
> we can't move things around. I suppose they can stay in platform drivers but
> even that is going against the general trend in the kernel community to avoid them at
> all. To me this should remain out of tree code but Bjorn will make the call.
>

I need to update my understanding of traces being ABI or not. But I
think the general start/stop traces would be useful and I expect that we
will continue to do those.

For the subdevices we need to conclude what we want to trace, e.g.
is this big trace adding anything beyond the trace_rproc_boot()?
Shouldn't we trace the individual subdevs, and if so we're definitely in
the area you're worrying about.

Regards,
Bjorn

> Thanks,
> Mathieu
>
> > list_for_each_entry(subdev, &rproc->subdevs, node) {
> > if (subdev->prepare) {
> > ret = subdev->prepare(subdev);
> > @@ -1188,6 +1192,7 @@ static int rproc_start_subdevices(struct rproc *rproc)
> > struct rproc_subdev *subdev;
> > int ret;
> >
> > + trace_rproc_subdevices("Start subdevices", rproc->name);
> > list_for_each_entry(subdev, &rproc->subdevs, node) {
> > if (subdev->start) {
> > ret = subdev->start(subdev);
> > @@ -1211,6 +1216,7 @@ static void rproc_stop_subdevices(struct rproc *rproc, bool crashed)
> > {
> > struct rproc_subdev *subdev;
> >
> > + trace_rproc_subdevices("Stop subdevices", rproc->name);
> > list_for_each_entry_reverse(subdev, &rproc->subdevs, node) {
> > if (subdev->stop)
> > subdev->stop(subdev, crashed);
> > @@ -1221,6 +1227,7 @@ static void rproc_unprepare_subdevices(struct rproc *rproc)
> > {
> > struct rproc_subdev *subdev;
> >
> > + trace_rproc_subdevices("Unprepare subdevices", rproc->name);
> > list_for_each_entry_reverse(subdev, &rproc->subdevs, node) {
> > if (subdev->unprepare)
> > subdev->unprepare(subdev);
> > @@ -1357,6 +1364,7 @@ static int rproc_start(struct rproc *rproc, const struct firmware *fw)
> > struct device *dev = &rproc->dev;
> > int ret;
> >
> > + trace_rproc_boot("loading firmware segments into memory", rproc->name);
> > /* load the ELF segments to memory */
> > ret = rproc_load_segments(rproc, fw);
> > if (ret) {
> > @@ -1385,6 +1393,7 @@ static int rproc_start(struct rproc *rproc, const struct firmware *fw)
> > goto reset_table_ptr;
> > }
> >
> > + trace_rproc_boot("starting remoteproc", rproc->name);
> > /* power up the remote processor */
> > ret = rproc->ops->start(rproc);
> > if (ret) {
> > @@ -1402,6 +1411,7 @@ static int rproc_start(struct rproc *rproc, const struct firmware *fw)
> >
> > rproc->state = RPROC_RUNNING;
> >
> > + trace_rproc_boot("remoteproc is up", rproc->name);
> > dev_info(dev, "remote processor %s is now up\n", rproc->name);
> >
> > return 0;
> > @@ -1648,6 +1658,7 @@ static int rproc_stop(struct rproc *rproc, bool crashed)
> > /* the installed resource table is no longer accessible */
> > rproc->table_ptr = rproc->cached_table;
> >
> > + trace_rproc_shutdown("Stopping the remoteproc", rproc->name);
> > /* power off the remote processor */
> > ret = rproc->ops->stop(rproc);
> > if (ret) {
> > @@ -1697,6 +1708,7 @@ int rproc_trigger_recovery(struct rproc *rproc)
> > if (rproc->state != RPROC_CRASHED)
> > goto unlock_mutex;
> >
> > + trace_rproc_recovery("Recover remoteproc", rproc->name);
> > dev_err(dev, "recovering %s\n", rproc->name);
> >
> > ret = rproc_stop(rproc, true);
> > @@ -1716,6 +1728,7 @@ int rproc_trigger_recovery(struct rproc *rproc)
> > /* boot the remote processor up again */
> > ret = rproc_start(rproc, firmware_p);
> >
> > + trace_rproc_recovery("Recovery completed", rproc->name);
> > release_firmware(firmware_p);
> >
> > unlock_mutex:
> > @@ -1796,6 +1809,7 @@ int rproc_boot(struct rproc *rproc)
> > /* skip the boot or attach process if rproc is already powered up */
> > if (atomic_inc_return(&rproc->power) > 1) {
> > ret = 0;
> > + trace_rproc_boot("Incrementing ref count and exiting", rproc->name);
> > goto unlock_mutex;
> > }
> >
> > @@ -1804,6 +1818,7 @@ int rproc_boot(struct rproc *rproc)
> >
> > ret = rproc_actuate(rproc);
> > } else {
> > + trace_rproc_boot("requesting firmware", rproc->name);
> > dev_info(dev, "powering up %s\n", rproc->name);
> >
> > /* load firmware */
> > @@ -1858,8 +1873,10 @@ void rproc_shutdown(struct rproc *rproc)
> > }
> >
> > /* if the remote proc is still needed, bail out */
> > - if (!atomic_dec_and_test(&rproc->power))
> > + if (!atomic_dec_and_test(&rproc->power)) {
> > + trace_rproc_shutdown("Decrementing ref count and exiting", rproc->name);
> > goto out;
> > + }
> >
> > ret = rproc_stop(rproc, false);
> > if (ret) {
> > diff --git a/include/trace/events/remoteproc.h b/include/trace/events/remoteproc.h
> > new file mode 100644
> > index 0000000..341bf4b
> > --- /dev/null
> > +++ b/include/trace/events/remoteproc.h
> > @@ -0,0 +1,91 @@
> > +/* SPDX-License-Identifier: GPL-2.0-only */
> > +/*
> > + * Copyright (c) 2020, The Linux Foundation. All rights reserved.
> > + */
> > +
> > +#undef TRACE_SYSTEM
> > +#define TRACE_SYSTEM remoteproc
> > +
> > +#if !defined(_TRACE_REMOTEPROC_H) || defined(TRACE_HEADER_MULTI_READ)
> > +#define _TRACE_REMOTEPROC_H
> > +
> > +#include <linux/tracepoint.h>
> > +
> > +TRACE_EVENT(rproc_boot,
> > +
> > + TP_PROTO(const char *event, const char *rproc_name),
> > +
> > + TP_ARGS(event, rproc_name),
> > +
> > + TP_STRUCT__entry(
> > + __string(event, event)
> > + __string(rproc_name, rproc_name)
> > + ),
> > +
> > + TP_fast_assign(
> > + __assign_str(event, event);
> > + __assign_str(rproc_name, rproc_name);
> > + ),
> > +
> > + TP_printk("rproc_boot: %s: %s", __get_str(rproc_name), __get_str(event))
> > +);
> > +
> > +TRACE_EVENT(rproc_shutdown,
> > +
> > + TP_PROTO(const char *event, const char *rproc_name),
> > +
> > + TP_ARGS(event, rproc_name),
> > +
> > + TP_STRUCT__entry(
> > + __string(event, event)
> > + __string(rproc_name, rproc_name)
> > + ),
> > +
> > + TP_fast_assign(
> > + __assign_str(event, event);
> > + __assign_str(rproc_name, rproc_name);
> > + ),
> > +
> > + TP_printk("rproc_shutdown: %s: %s", __get_str(rproc_name), __get_str(event))
> > +);
> > +
> > +TRACE_EVENT(rproc_recovery,
> > +
> > + TP_PROTO(const char *event, const char *rproc_name),
> > +
> > + TP_ARGS(event, rproc_name),
> > +
> > + TP_STRUCT__entry(
> > + __string(event, event)
> > + __string(rproc_name, rproc_name)
> > + ),
> > +
> > + TP_fast_assign(
> > + __assign_str(event, event);
> > + __assign_str(rproc_name, rproc_name);
> > + ),
> > +
> > + TP_printk("rproc_recovery: %s: %s", __get_str(rproc_name), __get_str(event))
> > +);
> > +
> > +TRACE_EVENT(rproc_subdevices,
> > +
> > + TP_PROTO(const char *event, const char *rproc_name),
> > +
> > + TP_ARGS(event, rproc_name),
> > +
> > + TP_STRUCT__entry(
> > + __string(event, event)
> > + __string(rproc_name, rproc_name)
> > + ),
> > +
> > + TP_fast_assign(
> > + __assign_str(event, event);
> > + __assign_str(rproc_name, rproc_name);
> > + ),
> > +
> > + TP_printk("rproc_subdevices: %s: %s", __get_str(rproc_name), __get_str(event))
> > +);
> > +#endif
> > +#include <trace/define_trace.h>
> > +
> > --
> > The Qualcomm Innovation Center, Inc. is a member of the Code Aurora Forum,
> > a Linux Foundation Collaborative Project
> >

Next message: Geva, Erez: "Re: [PATCH 1/3] Add TX sending hardware timestamp."
Previous message: Mark Brown: "Re: Re: [PATCH] spi: Limit the spi device max speed to controller's max speed"
In reply to: Bjorn Andersson: "Re: [PATCH v2 3/3] remoteproc: Add ftrace events to trace lifecycle of remoteprocs"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]