Re: [PATCH] platform/chrome: cros_ec_proto: Add response tracing

From: Enric Balletbo i Serra
Date: Mon Nov 25 2019 - 12:02:39 EST


Hi Raul,

On 25/11/19 17:49, Raul Rangel wrote:
> On Mon, Nov 25, 2019 at 8:45 AM Enric Balletbo i Serra
> <enric.balletbo@xxxxxxxxxxxxx> wrote:
>>
>> Hi Raul,
>>
>> Many tanks for sending this patch upstream, some few comments below.
>>
>> On 21/11/19 19:55, Raul E Rangel wrote:
>>> Add the ability to view response codes as well.
>>>
>>> I renamed the trace event from cros_ec_cmd to cros_ec_request and added
>>> a cros_ec_response.
>>>
>>> Example:
>>> $ echo 1 > /sys/kernel/debug/tracing/events/cros_ec/enable
>>> $ cat /sys/kernel/debug/tracing/trace
>>>
>>> cros_ec_request: version: 1, command: EC_CMD_CONSOLE_READ
>>> cros_ec_response: version: 1, command: EC_CMD_CONSOLE_READ, result: EC_RES_SUCCESS, rc: 0
>>
>> I don't see the advantage of have two traces, one for the request and another
>> one for the response. Do you expect get stuck between them?
>
> It might if there is a bug in xfer_fxn, we miss an interrupt, or some
> kind of communication problem on the bus (early bring up issues). It's
> also possible to compute the latency of a transaction by having both.
> The mmc subsystem has both mmc_request_start and mmc_request_done. If
> you feel strongly, I can record just the response.

That's a good reason, I am fine with having both. Can we follow the same naming
as used in mmc though?

trace_cros_ec_request_start
trace_cros_ec_request_done


>>
>> What about just move the trace_cros_ec_cmd after the xfer_fnx call and add the
>> results?
>>
>> Thanks,
>> Enric
>>
>>> cros_ec_request: version: 0, command: EC_CMD_USB_PD_POWER_INFO
>>> cros_ec_response: version: 0, command: EC_CMD_USB_PD_POWER_INFO, result: EC_RES_SUCCESS, rc: 16

Could I suggest the following changes?

s/result/ec result/
s/rc/retval/

>>>
>>> Signed-off-by: Raul E Rangel <rrangel@xxxxxxxxxxxx>
>>> ---
>>>
>>> drivers/platform/chrome/cros_ec_proto.c | 7 +++++-
>>> drivers/platform/chrome/cros_ec_trace.c | 24 +++++++++++++++++++
>>> drivers/platform/chrome/cros_ec_trace.h | 32 +++++++++++++++++++++++--
>>> 3 files changed, 60 insertions(+), 3 deletions(-)
>>>
>>> diff --git a/drivers/platform/chrome/cros_ec_proto.c b/drivers/platform/chrome/cros_ec_proto.c
>>> index bd485ce98a42..ef2229047e0f 100644
>>> --- a/drivers/platform/chrome/cros_ec_proto.c
>>> +++ b/drivers/platform/chrome/cros_ec_proto.c
>>> @@ -54,7 +54,7 @@ static int send_command(struct cros_ec_device *ec_dev,
>>> int ret;
>>> int (*xfer_fxn)(struct cros_ec_device *ec, struct cros_ec_command *msg);
>>>
>>> - trace_cros_ec_cmd(msg);
>>> + trace_cros_ec_request(msg);
>>>
>>> if (ec_dev->proto_version > 2)
>>> xfer_fxn = ec_dev->pkt_xfer;
>>> @@ -73,6 +73,8 @@ static int send_command(struct cros_ec_device *ec_dev,
>>> }
>>>
>>> ret = (*xfer_fxn)(ec_dev, msg);
>>> +
>>> + trace_cros_ec_response(msg, ret);
>>> if (msg->result == EC_RES_IN_PROGRESS) {
>>> int i;
>>> struct cros_ec_command *status_msg;
>>> @@ -95,7 +97,10 @@ static int send_command(struct cros_ec_device *ec_dev,
>>> for (i = 0; i < EC_COMMAND_RETRIES; i++) {
>>> usleep_range(10000, 11000);
>>>
>>> + trace_cros_ec_request(status_msg);
>>> ret = (*xfer_fxn)(ec_dev, status_msg);
>>> + trace_cros_ec_response(status_msg, ret);
>>> +
>>> if (ret == -EAGAIN)
>>> continue;
>>> if (ret < 0)
>>> diff --git a/drivers/platform/chrome/cros_ec_trace.c b/drivers/platform/chrome/cros_ec_trace.c
>>> index 6f80ff4532ae..28eb94d99ba2 100644
>>> --- a/drivers/platform/chrome/cros_ec_trace.c
>>> +++ b/drivers/platform/chrome/cros_ec_trace.c
>>> @@ -120,5 +120,29 @@
>>> TRACE_SYMBOL(EC_CMD_PD_GET_LOG_ENTRY), \
>>> TRACE_SYMBOL(EC_CMD_USB_PD_MUX_INFO)
>>>
>>> +// See enum ec_status
>>
>> Use the C comment style, please.
> I used // because that was the comment format used above `#define
> EC_CMDS`. Do you want me to change that as well?
>

Yes, use C-style by default. The reason why it is used the C++ style above is
because contains '*/' in the script that broke the C comment.

Thanks,
Enric

> Thanks
>