On Wed, Sep 11, 2024 at 3:36 PM Heikki Krogerus
<heikki.krogerus@xxxxxxxxxxxxxxx> wrote:
>
> On Tue, Sep 10, 2024 at 10:15:24AM +0000, Łukasz Bartosik wrote:
> > Add trace events to ChromeOS UCSI driver to enable debugging.
> >
> > Signed-off-by: Łukasz Bartosik <ukaszb@xxxxxxxxxxxx>
> > ---
> > MAINTAINERS | 1 +
> > drivers/usb/typec/ucsi/cros_ec_ucsi.c | 8 ++
> > drivers/usb/typec/ucsi/cros_ec_ucsi_trace.h | 92 +++++++++++++++++++++
> > 3 files changed, 101 insertions(+)
> > create mode 100644 drivers/usb/typec/ucsi/cros_ec_ucsi_trace.h
> >
> > diff --git a/MAINTAINERS b/MAINTAINERS
> > index 8c030ea0b503..d084f32208f0 100644
> > --- a/MAINTAINERS
> > +++ b/MAINTAINERS
> > @@ -5306,6 +5306,7 @@ M: Łukasz Bartosik <ukaszb@xxxxxxxxxxxx>
> > L: chrome-platform@xxxxxxxxxxxxxxx
> > S: Maintained
> > F: drivers/usb/typec/ucsi/cros_ec_ucsi.c
> > +F: drivers/usb/typec/ucsi/cros_ec_ucsi_trace.h
> >
> > CHRONTEL CH7322 CEC DRIVER
> > M: Joe Tessler <jrt@xxxxxxxxxx>
> > diff --git a/drivers/usb/typec/ucsi/cros_ec_ucsi.c b/drivers/usb/typec/ucsi/cros_ec_ucsi.c
> > index 422b3b14028c..70185616ec86 100644
> > --- a/drivers/usb/typec/ucsi/cros_ec_ucsi.c
> > +++ b/drivers/usb/typec/ucsi/cros_ec_ucsi.c
> > @@ -16,7 +16,9 @@
> > #include <linux/slab.h>
> > #include <linux/wait.h>
> >
> > +#define CREATE_TRACE_POINTS
> > #include "ucsi.h"
> > +#include "cros_ec_ucsi_trace.h"
> >
> > /*
> > * Maximum size in bytes of a UCSI message between AP and EC
> > @@ -62,6 +64,8 @@ static int cros_ucsi_read(struct ucsi *ucsi, unsigned int offset, void *val,
> > dev_warn(udata->dev, "Failed to send EC message UCSI_PPM_GET: error=%d", ret);
> > return ret;
> > }
> > +
> > + trace_cros_ec_opm_to_ppm_rd(offset, val, val_len);
> > return 0;
> > }
> >
> > @@ -96,6 +100,8 @@ static int cros_ucsi_async_control(struct ucsi *ucsi, u64 cmd)
> > dev_warn(udata->dev, "Failed to send EC message UCSI_PPM_SET: error=%d", ret);
> > return ret;
> > }
> > +
> > + trace_cros_ec_opm_to_ppm_wr(req->offset, &cmd, sizeof(cmd));
> > return 0;
> > }
> >
> > @@ -138,6 +144,8 @@ static void cros_ucsi_work(struct work_struct *work)
> > struct cros_ucsi_data *udata = container_of(work, struct cros_ucsi_data, work);
> > u32 cci;
> >
> > + trace_cros_ec_ppm_to_opm(0);
> > +
> > if (cros_ucsi_read_cci(udata->ucsi, &cci))
> > return;
> >
> > diff --git a/drivers/usb/typec/ucsi/cros_ec_ucsi_trace.h b/drivers/usb/typec/ucsi/cros_ec_ucsi_trace.h
> > new file mode 100644
> > index 000000000000..b765ef5c8236
> > --- /dev/null
> > +++ b/drivers/usb/typec/ucsi/cros_ec_ucsi_trace.h
> > @@ -0,0 +1,92 @@
> > +/* SPDX-License-Identifier: GPL-2.0 */
> > +
> > +#undef TRACE_SYSTEM
> > +#define TRACE_SYSTEM cros_ec_ucsi
> > +
> > +#if !defined(__CROS_EC_UCSI_TRACE_H) || defined(TRACE_HEADER_MULTI_READ)
> > +#define __CROS_EC_UCSI_TRACE_H
> > +
> > +#include <linux/tracepoint.h>
> > +
> > +#define decode_cmd(cmd) \
> > + __print_symbolic(cmd, \
> > + { 0, "Unknown command" }, \
> > + { UCSI_PPM_RESET, "PPM_RESET" }, \
> > + { UCSI_CONNECTOR_RESET, "CONNECTOR_RESET," }, \
> > + { UCSI_ACK_CC_CI, "ACK_CC_CI" }, \
> > + { UCSI_SET_NOTIFICATION_ENABLE, "SET_NOTIFICATION_ENABLE" }, \
> > + { UCSI_GET_CAPABILITY, "GET_CAPABILITY" }, \
> > + { UCSI_GET_CONNECTOR_CAPABILITY, "GET_CONNECTOR_CAPABILITY" }, \
> > + { UCSI_SET_UOM, "SET_UOM" }, \
> > + { UCSI_SET_UOR, "SET_UOR" }, \
> > + { UCSI_SET_PDM, "SET_PDM" }, \
> > + { UCSI_SET_PDR, "SET_PDR" }, \
> > + { UCSI_GET_ALTERNATE_MODES, "GET_ALTERNATE_MODES" }, \
> > + { UCSI_GET_CAM_SUPPORTED, "GET_CAM_SUPPORTED" }, \
> > + { UCSI_GET_CURRENT_CAM, "GET_CURRENT_CAM" }, \
> > + { UCSI_SET_NEW_CAM, "SET_NEW_CAM" }, \
> > + { UCSI_GET_PDOS, "GET_PDOS" }, \
> > + { UCSI_GET_CABLE_PROPERTY, "GET_CABLE_PROPERTY" }, \
> > + { UCSI_GET_CONNECTOR_STATUS, "GET_CONNECTOR_STATUS" }, \
> > + { UCSI_GET_ERROR_STATUS, "GET_ERROR_STATUS" })
>
> Couldn't you just export ucsi_cmd_str() ?
>
I ran into an issue when using exported ucsi_cmd_str(). Trace-cmd
report reports [FAILED TO PARSE].
For example
trace-cmd record -e cros_ec_ucsi
...
trace-cmd report
kworker/0:3-1891 [000] 59.432234: cros_ec_ppm_to_opm: notification
kworker/0:3-1891 [000] 59.432971: cros_ec_opm_to_ppm_rd:
[FAILED TO PARSE] cmd=4 offset=4 length=4 msg=ARRAY[04, 00, 00, 20]
I believe this issue applies also to some UCSI trace events.
With decode_cmd from the above it works fine
For example
trace-cmd record -e cros_ec_ucsi
...
trace-cmd report
kworker/0:1-10 [000] 49.248920: cros_ec_ppm_to_opm: notification
kworker/0:1-10 [000] 49.249857: cros_ec_opm_to_ppm_rd:
(CCI) : 04 00 00 20
kworker/0:1-10 [000] 49.253230: cros_ec_opm_to_ppm_wr:
(CTRL) GET_CONNECTOR_STATUS: 12 00 02 00 00 00 00 00
> > +#define decode_offset(offset) \
> > + __print_symbolic(offset, \
> > + { UCSI_VERSION, "VER" }, \
> > + { UCSI_CCI, "CCI" }, \
> > + { UCSI_CONTROL, "CTRL" }, \
> > + { UCSI_MESSAGE_IN, "MSG_IN" }, \
> > + { UCSI_MESSAGE_OUT, "MSG_OUT" }, \
> > + { UCSIv2_MESSAGE_OUT, "MSG_OUTv2" })
> > +
> > +DECLARE_EVENT_CLASS(cros_ec_opm_to_ppm,
> > + TP_PROTO(u16 offset, const void *value, size_t length),
> > + TP_ARGS(offset, value, length),
> > + TP_STRUCT__entry(
> > + __field(u8, cmd)
> > + __field(u16, offset)
> > + __field(size_t, length)
> > + __dynamic_array(char, msg, length)
> > + ),
> > + TP_fast_assign(
> > + __entry->cmd = *((u64 *) value + 3);
> > + __entry->offset = offset;
> > + __entry->length = length;
> > + memcpy(__get_dynamic_array(msg), value, length);
> > + ),
> > + TP_printk("(%s) %s: %s",
> > + decode_offset(__entry->offset),
> > + __entry->offset == UCSI_CONTROL ?
> > + decode_cmd(__entry->cmd) : "",
> > + __print_hex(__get_dynamic_array(msg), __entry->length))
> > +);
> > +
> > +DEFINE_EVENT(cros_ec_opm_to_ppm, cros_ec_opm_to_ppm_rd,
> > + TP_PROTO(u16 offset, const void *value, size_t length),
> > + TP_ARGS(offset, value, length)
> > +);
> > +
> > +DEFINE_EVENT(cros_ec_opm_to_ppm, cros_ec_opm_to_ppm_wr,
> > + TP_PROTO(u16 offset, const void *value, size_t length),
> > + TP_ARGS(offset, value, length)
> > +);
> > +
> > +TRACE_EVENT(cros_ec_ppm_to_opm,
> > + TP_PROTO(int x),
> > + TP_ARGS(x),
> > + TP_STRUCT__entry(__array(char, x, 0)),
> > + TP_fast_assign((void)x),
> > + TP_printk("notification%s", "")
> > +);
>
> This does not look cros_ec specific. Could you check if this could be
> made part of the ucsi core tracepoints?
>
Good point. I will look into it.
> I can also look into this more carefully, and throw ideas if you like.
> Let me know.
>
I would definitely like to hear your ideas on the topic :).
Thanks,
Lukasz
> Br,
>
> --
> heikki
