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

[Enric Balletbo i Serra]

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?

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

> +#define EC_RESULT \
> +	TRACE_SYMBOL(EC_RES_SUCCESS), \
> +	TRACE_SYMBOL(EC_RES_INVALID_COMMAND), \
> +	TRACE_SYMBOL(EC_RES_ERROR), \
> +	TRACE_SYMBOL(EC_RES_INVALID_PARAM), \
> +	TRACE_SYMBOL(EC_RES_ACCESS_DENIED), \
> +	TRACE_SYMBOL(EC_RES_INVALID_RESPONSE), \
> +	TRACE_SYMBOL(EC_RES_INVALID_VERSION), \
> +	TRACE_SYMBOL(EC_RES_INVALID_CHECKSUM), \
> +	TRACE_SYMBOL(EC_RES_IN_PROGRESS), \
> +	TRACE_SYMBOL(EC_RES_UNAVAILABLE), \
> +	TRACE_SYMBOL(EC_RES_TIMEOUT), \
> +	TRACE_SYMBOL(EC_RES_OVERFLOW), \
> +	TRACE_SYMBOL(EC_RES_INVALID_HEADER), \
> +	TRACE_SYMBOL(EC_RES_REQUEST_TRUNCATED), \
> +	TRACE_SYMBOL(EC_RES_RESPONSE_TOO_BIG), \
> +	TRACE_SYMBOL(EC_RES_BUS_ERROR), \
> +	TRACE_SYMBOL(EC_RES_BUSY), \
> +	TRACE_SYMBOL(EC_RES_INVALID_HEADER_VERSION), \
> +	TRACE_SYMBOL(EC_RES_INVALID_HEADER_CRC), \
> +	TRACE_SYMBOL(EC_RES_INVALID_DATA_CRC), \
> +	TRACE_SYMBOL(EC_RES_DUP_UNAVAILABLE)
> +
>  #define CREATE_TRACE_POINTS
>  #include "cros_ec_trace.h"
> diff --git a/drivers/platform/chrome/cros_ec_trace.h b/drivers/platform/chrome/cros_ec_trace.h
> index 0dd4df30fa89..853eeaaac9da 100644
> --- a/drivers/platform/chrome/cros_ec_trace.h
> +++ b/drivers/platform/chrome/cros_ec_trace.h
> @@ -18,7 +18,7 @@
>  
>  #include <linux/tracepoint.h>
>  
> -DECLARE_EVENT_CLASS(cros_ec_cmd_class,
> +DECLARE_EVENT_CLASS(cros_ec_request_class,
>  	TP_PROTO(struct cros_ec_command *cmd),
>  	TP_ARGS(cmd),
>  	TP_STRUCT__entry(
> @@ -34,11 +34,39 @@ DECLARE_EVENT_CLASS(cros_ec_cmd_class,
>  );
>  
>  
> -DEFINE_EVENT(cros_ec_cmd_class, cros_ec_cmd,
> +DEFINE_EVENT(cros_ec_request_class, cros_ec_request,
>  	TP_PROTO(struct cros_ec_command *cmd),
>  	TP_ARGS(cmd)
>  );
>  
> +DECLARE_EVENT_CLASS(cros_ec_response_class,
> +	TP_PROTO(struct cros_ec_command *cmd, int rc),
> +	TP_ARGS(cmd, rc),
> +	TP_STRUCT__entry(
> +		__field(uint32_t, version)
> +		__field(uint32_t, command)
> +		__field(uint32_t, result)
> +		__field(int, rc)
> +	),
> +	TP_fast_assign(
> +		__entry->version = cmd->version;
> +		__entry->command = cmd->command;
> +		__entry->result = cmd->result;
> +		__entry->rc = rc;
> +	),
> +	TP_printk("version: %u, command: %s, result: %s, rc: %d",
> +		  __entry->version,
> +		  __print_symbolic(__entry->command, EC_CMDS),
> +		  __print_symbolic(__entry->result, EC_RESULT),
> +		  __entry->rc)
> +);
> +
> +
> +DEFINE_EVENT(cros_ec_response_class, cros_ec_response,
> +	TP_PROTO(struct cros_ec_command *cmd, int rc),
> +	TP_ARGS(cmd, rc)
> +);
> +
>  
>  #endif /* _CROS_EC_TRACE_H_ */
>  
>