Re: [PATCH v2 03/10] drivers: qcom: rpmh-rsc: log RPMH requests in FTRACE

[Lina Iyer]

On Thu, Feb 15 2018 at 19:57 +0000, Steven Rostedt wrote:
> On Thu, 15 Feb 2018 10:35:00 -0700
> Lina Iyer <ilina@xxxxxxxxxxxxxx> wrote:
>
> > @@ -298,6 +303,7 @@ static void __tcs_buffer_write(struct rsc_drv *drv, int m, int n,
> >  		write_tcs_reg(drv, RSC_DRV_CMD_MSGID, m, n + i, msgid);
> >  		write_tcs_reg(drv, RSC_DRV_CMD_ADDR, m, n + i, cmd->addr);
> >  		write_tcs_reg(drv, RSC_DRV_CMD_DATA, m, n + i, cmd->data);
> > +		trace_rpmh_send_msg(drv, m, n + i, msgid, cmd);
>
> No biggy, but I'm curious to why you didn't do something this:
>
> +static void __tcs_buffer_write(struct rsc_drv *drv, int m, int n,
> +                             struct tcs_request *msg)
> +{
> +       u32 msgid, cmd_msgid = 0;
> +       u32 cmd_enable = 0;
> +       u32 cmd_complete;
> +       struct tcs_cmd *cmd;
> +       int i;
> +
> +       cmd_msgid = CMD_MSGID_LEN;
> +       cmd_msgid |= (msg->is_complete) ? CMD_MSGID_RESP_REQ : 0;
> +       cmd_msgid |= CMD_MSGID_WRITE;
> +
> +       cmd_complete = read_tcs_reg(drv, RSC_DRV_CMD_WAIT_FOR_CMPL, m, 0);
> +
> +       for (i = 0; i < msg->num_payload; i++) {
>
> 		int bit = n + i;
>
> +               cmd = &msg->payload[i];
> +               cmd_enable |= BIT(bit);
> +               cmd_complete |= cmd->complete << (n + i);
> +               msgid = cmd_msgid;
> +               msgid |= (cmd->complete) ? CMD_MSGID_RESP_REQ : 0;
> +               write_tcs_reg(drv, RSC_DRV_CMD_MSGID, m, bit, msgid);
> +               write_tcs_reg(drv, RSC_DRV_CMD_ADDR, m, bit, cmd->addr);
> +               write_tcs_reg(drv, RSC_DRV_CMD_DATA, m, bit, cmd->data);
>
> 		trace_rpmh_send_msg(drv, m, bit, msgid, cmd);
>
> The compiler should optimize that, so this isn't really a big deal, but
> I was just curious.
No particular reason. Think I just went with the logic at that time and
didn't look back deeply again on the code to tidy it up. Thanks for the
suggestion.

> +       }
> +
> +       write_tcs_reg(drv, RSC_DRV_CMD_WAIT_FOR_CMPL, m, 0, cmd_complete);
> +       cmd_enable |= read_tcs_reg(drv, RSC_DRV_CMD_ENABLE, m, 0);
> +       write_tcs_reg(drv, RSC_DRV_CMD_ENABLE, m, 0, cmd_enable);
> +}
>
> >  	}
> >
> >  	write_tcs_reg(drv, RSC_DRV_CMD_WAIT_FOR_CMPL, m, 0, cmd_complete);
>
> [..]
>
> > +TRACE_EVENT(rpmh_send_msg,
> > +
> > +	TP_PROTO(struct rsc_drv *d, int m, int n, u32 h, struct tcs_cmd *c),
> > +
> > +	TP_ARGS(d, m, n, h, c),
> > +
> > +	TP_STRUCT__entry(
> > +		__field(const char*, d->name)
> > +		__field(int, m)
> > +		__field(int, n)
> > +		__field(u32, hdr)
> > +		__field(u32, addr)
> > +		__field(u32, data)
> > +		__field(bool, complete)
> > +	),
> > +
> > +	TP_fast_assign(
> > +		__entry->name = s;
> > +		__entry->m = m;
> > +		__entry->n = n;
> > +		__entry->hdr = h;
> > +		__entry->addr = c->addr;
> > +		__entry->data = c->data;
> > +		__entry->complete = c->complete;
> > +	),
> > +
> > +	TP_printk("%s: send-msg: tcs(m): %d cmd(n): %d msgid: 0x%08x addr: 0x%08x data: 0x%08x complete: %d",
> > +			__entry->name, __entry->m, __entry->n, __entry->hdr,
>
> I'm sorry I didn't catch this in my other reviews, but please don't use
> direct strings in TP_printk(). In trace-cmd and perf, it has no access
> to that information when reading this trace event. Not to mention, if
> drv is freed between the time it is recorded, and the time it is read
> in the trace buffer, you are now referencing random memory.
>
> The way to do this in a trace event is to use the string functionality:
>
> 	TP_STRUCT__entry(
> 		__string(name, d->name)
> 		[..]
> 	TP_fast_assign(
> 		__assign_string(name, d->name)
> 		[..]
> 	TP_printk("%s: ...",
> 		__get_str(name), ...
>
> Then the name is recorded in the ring buffer at the time of execution
> of the trace event, and trace-cmd and perf can read it, and there's no
> worries about it being freed between recording and reading the tracing
> buffer.
The drv would not be freed. But that said, I will use this in my
patches.

Thanks Steve.

-- Lina