Re: [PATCH] spmi: add command tracepoints for SPMI

From: Ankit Gupta
Date: Wed May 20 2015 - 11:08:38 EST

On Tue, 19 May 2015 17:36:41 -0700
Stephen Boyd <sboyd@xxxxxxxxxxxxxx> wrote:

> +Steven Rostedt
>
> On 05/18/15 14:51, Ankit Gupta wrote:
> > Add tracepoints to retrieve information about read, write
> > and non-data commands. For performance measurement support
> > tracepoints are added at the beginning and at the end of
> > transfers. Following is a list showing the new tracepoint
> > events. The "cmd" parameter here represents the opcode, SID,
> > and full 16-bit address.
> >
> > spmi_write_begin: cmd and data buffer.
> > spmi_write_end : cmd and return value.
> > spmi_read_begin : cmd.
> > spmi_read_end : cmd, return value and data buffer.
> > spmi_cmd : cmd.
> >
> > The reason that cmd appears at both the beginning and at
> > the end event is that SPMI drivers can request commands
> > concurrently. cmd helps in matching the corresponding
> > events.
> >
> > SPMI tracepoints can be enabled like:
> >
> > echo 1 >/sys/kernel/debug/tracing/events/spmi/enable
> >
> > and will dump messages that can be viewed in
> > /sys/kernel/debug/tracing/trace that look like:
> >
> > ... spmi_read_begin: opc=56 sid=00 addr=0x0000
> > ... spmi_read_end: opc=56 sid=00 addr=0x0000 ret=0 len=02
> > buf=0x[01-40] ... spmi_write_begin: opc=48 sid=00 addr=0x0000 len=3
> > buf=0x[ff-ff-ff]
> >
> > Signed-off-by: Ankit Gupta <ankgupta@xxxxxxxxxxxxxx>
> > Signed-off-by: Gilad Avidov <gavidov@xxxxxxxxxxxxxx>
> > Suggested-by: Sagar Dharia <sdharia@xxxxxxxxxxxxxx>
> > ---
>
> Your Signed-off-by should be last.
Will change that.
>
> > drivers/spmi/spmi.c | 22 ++++++-
> > include/trace/events/spmi.h | 136
> > ++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 155
> > insertions(+), 3 deletions(-) create mode 100644
> > include/trace/events/spmi.h
> >
> > diff --git a/drivers/spmi/spmi.c b/drivers/spmi/spmi.c
> > index 1d92f51..36fe010 100644
> > --- a/drivers/spmi/spmi.c
> > +++ b/drivers/spmi/spmi.c
> > @@ -21,6 +21,8 @@
> > #include <linux/pm_runtime.h>
> >
> > #include <dt-bindings/spmi/spmi.h>
> > +#define CREATE_TRACE_POINTS
> > +#include <trace/events/spmi.h>
> >
> > static DEFINE_IDA(ctrl_ida);
> >
> > @@ -95,28 +97,42 @@ EXPORT_SYMBOL_GPL(spmi_device_remove);
> > static inline int
> > spmi_cmd(struct spmi_controller *ctrl, u8 opcode, u8 sid)
> > {
> > + int ret;
> > +
> > if (!ctrl || !ctrl->cmd || ctrl->dev.type !=
> > &spmi_ctrl_type) return -EINVAL;
> >
> > - return ctrl->cmd(ctrl, opcode, sid);
> > + ret = ctrl->cmd(ctrl, opcode, sid);
> > + trace_spmi_cmd(opcode, sid, ret);
> > + return ret;
> > }
> >
> > static inline int spmi_read_cmd(struct spmi_controller *ctrl, u8
> > opcode, u8 sid, u16 addr, u8 *buf, size_t len)
> > {
> > + int ret;
> > +
> > if (!ctrl || !ctrl->read_cmd || ctrl->dev.type !=
> > &spmi_ctrl_type) return -EINVAL;
> >
> > - return ctrl->read_cmd(ctrl, opcode, sid, addr, buf, len);
> > + trace_spmi_read_begin(opcode, sid, addr);
> > + ret = ctrl->read_cmd(ctrl, opcode, sid, addr, buf, len);
> > + trace_spmi_read_end(opcode, sid, addr, ret, len, buf);
> > + return ret;
> > }
> >
> > static inline int spmi_write_cmd(struct spmi_controller *ctrl, u8
> > opcode, u8 sid, u16 addr, const u8 *buf, size_t len)
> > {
> > + int ret;
> > +
> > if (!ctrl || !ctrl->write_cmd || ctrl->dev.type !=
> > &spmi_ctrl_type) return -EINVAL;
> >
> > - return ctrl->write_cmd(ctrl, opcode, sid, addr, buf, len);
> > + trace_spmi_write_begin(opcode, sid, addr, len, buf);
> > + ret = ctrl->write_cmd(ctrl, opcode, sid, addr, buf, len);
> > + trace_spmi_write_end(opcode, sid, addr, ret);
> > + return ret;
> > }
> >
> > /**
> > diff --git a/include/trace/events/spmi.h
> > b/include/trace/events/spmi.h new file mode 100644
> > index 0000000..241fd1e
> > --- /dev/null
> > +++ b/include/trace/events/spmi.h
> > @@ -0,0 +1,136 @@
> > +#undef TRACE_SYSTEM
> > +#define TRACE_SYSTEM spmi
> > +
> > +#if !defined(_TRACE_SPMI_H) || defined(TRACE_HEADER_MULTI_READ)
> > +#define _TRACE_SPMI_H
> > +
> > +#include <linux/spmi.h>
> > +#include <linux/tracepoint.h>
> > +
> > +/*
> > + * drivers/spmi/spmi.c
> > + */
> > +
> > +TRACE_EVENT(spmi_write_begin,
> > + TP_PROTO(u8 opcode, u8 sid, u16 addr, u8 len, const u8
> > *buf),
> > + TP_ARGS(opcode, sid, addr, len, buf),
> > +
> > + TP_STRUCT__entry(
> > + __field ( u8, opcode )
> > + __field ( u8, sid )
> > + __field ( u16, addr )
> > + __field ( u8, len )
> > + __dynamic_array ( u8, buf, len + 1 )
> > + ),
> > +
> > + TP_fast_assign(
> > + __entry->opcode = opcode;
> > + __entry->sid = sid;
> > + __entry->addr = addr;
> > + __entry->len = len + 1;
> > + memcpy(__get_dynamic_array(buf), buf, len + 1);
> > + ),
> > +
> > + TP_printk("opc=%d sid=%02d addr=0x%04x len=%d
> > buf=0x[%*phD]",
> > + (int)__entry->opcode, (int)__entry->sid,
> > + (int)__entry->addr, (int)__entry->len,
> > + (int)__entry->len, __get_dynamic_array(buf))
> > +);
> > +
> > +TRACE_EVENT(spmi_write_end,
> > + TP_PROTO(u8 opcode, u8 sid, u16 addr, int ret),
> > + TP_ARGS(opcode, sid, addr, ret),
> > +
> > + TP_STRUCT__entry(
> > + __field ( u8, opcode )
> > + __field ( u8, sid )
> > + __field ( u16, addr )
> > + __field ( int, ret )
> > + ),
> > +
> > + TP_fast_assign(
> > + __entry->opcode = opcode;
> > + __entry->sid = sid;
> > + __entry->addr = addr;
> > + __entry->ret = ret;
> > + ),
> > +
> > + TP_printk("opc=%d sid=%02d addr=0x%04x ret=%d",
> > + (int)__entry->opcode, (int)__entry->sid,
> > + (int)__entry->addr, __entry->ret)
> > +);
> > +
> > +TRACE_EVENT(spmi_read_begin,
> > + TP_PROTO(u8 opcode, u8 sid, u16 addr),
> > + TP_ARGS(opcode, sid, addr),
> > +
> > + TP_STRUCT__entry(
> > + __field ( u8, opcode )
> > + __field ( u8, sid )
> > + __field ( u16, addr )
> > + ),
> > +
> > + TP_fast_assign(
> > + __entry->opcode = opcode;
> > + __entry->sid = sid;
> > + __entry->addr = addr;
> > + ),
> > +
> > + TP_printk("opc=%d sid=%02d addr=0x%04x",
> > + (int)__entry->opcode, (int)__entry->sid,
> > + (int)__entry->addr)
> > +);
> > +
> > +TRACE_EVENT(spmi_read_end,
> > + TP_PROTO(u8 opcode, u8 sid, u16 addr, int ret, u8 len,
>
> Should "len" be size_t instead of u8? It would at least match the
> implementation of spmi_controller::read_cmd(). Same comment for the
> write side.
>
> -Stephen

I see no reason to spend to 4-8 bytes when spmi spec allows for maximum
buffer size of 16. Do you suggest changing the API of read_cmd()?
>
> > + const u8 *buf),
> > + TP_ARGS(opcode, sid, addr, ret, len, buf),
> > +
> > + TP_STRUCT__entry(
> > + __field ( u8, opcode )
> > + __field ( u8, sid )
> > + __field ( u16, addr )
> > + __field ( int, ret )
> > + __field ( u8, len )
> > + __dynamic_array ( u8, buf, len + 1 )
> > + ),
> > +
> > + TP_fast_assign(
> > + __entry->opcode = opcode;
> > + __entry->sid = sid;
> > + __entry->addr = addr;
> > + __entry->ret = ret;
> > + __entry->len = len + 1;
> > + memcpy(__get_dynamic_array(buf), buf, len + 1);
> > + ),
> > +
> > + TP_printk("opc=%d sid=%02d addr=0x%04x ret=%d len=%02d
> > buf=0x[%*phD]",
> > + (int)__entry->opcode, (int)__entry->sid,
> > + (int)__entry->addr, __entry->ret,
> > (int)__entry->len,
> > + (int)__entry->len, __get_dynamic_array(buf))
> > +);
> > +
> > +TRACE_EVENT(spmi_cmd,
> > + TP_PROTO(u8 opcode, u8 sid, int ret),
> > + TP_ARGS(opcode, sid, ret),
> > +
> > + TP_STRUCT__entry(
> > + __field ( u8, opcode )
> > + __field ( u8, sid )
> > + __field ( int, ret )
> > + ),
> > +
> > + TP_fast_assign(
> > + __entry->opcode = opcode;
> > + __entry->sid = sid;
> > + __entry->ret = ret;
> > + ),
> > +
> > + TP_printk("opc=%d sid=%02d ret=%d", (int)__entry->opcode,
> > + (int)__entry->sid, ret)
> > +);
> > +
> > +#endif /* _TRACE_SPMI_H */
> > +
> > +/* This part must be outside protection */
> > +#include <trace/define_trace.h>
>
>
Thanks,
Ankit

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/