2022-08-18 13:30:34

by Cristian Marussi

Subject: [PATCH 0/1] Harmonize SCMI traces formats

Hi,

after having recently added new scmi_msg_dump traces I realized the
general format of the various other SCMI traces is not consistent.

As an example the full traces of a simple PERF_LEVEL_SET is now:

cpufreq-set-276 [000] ..... 139.905639: scmi_xfer_begin: transfer_id=145 msg_id=7 protocol_id=19 seq=145 poll=0
cpufreq-set-276 [000] ..... 139.905724: scmi_msg_dump: pt=13 t=CMND msg_id=07 seq=0091 s=0 pyld=000000008066ab13
cpufreq-set-276 [000] ..... 139.905725: scmi_xfer_response_wait: transfer_id=145 msg_id=7 protocol_id=19 seq=145 tmo_ms=5000 poll=0
<idle>-0 [000] d.h2. 139.906493: scmi_msg_dump: pt=13 t=RESP msg_id=07 seq=0091 s=0 pyld=
<idle>-0 [000] d.h2. 139.906521: scmi_rx_done: transfer_id=145 msg_id=7 protocol_id=19 seq=145 msg_type=0
cpufreq-set-276 [000] ..... 139.906651: scmi_xfer_end: transfer_id=145 msg_id=7 protocol_id=19 seq=145 status=0

... where same information is reported using different names (protocol_id= vs pt=)
and even worst different bases, which is hard to read and to parse.

So this tiny patch aims to unify this, using the same naming and ordering
of the fields (wherever possible) and moving all the protocol related
fields to base-16 while keeping in base-10 timeouts, res_id and values, so
that the new traces would be like:

cpufreq-set-274 [001] ..... 100.242894: scmi_xfer_begin: pt=13 msg_id=07 seq=0092 transfer_id=92 poll=0
cpufreq-set-274 [001] ..... 100.242906: scmi_msg_dump: pt=13 t=CMND msg_id=07 seq=0092 s=0 pyld=000000008066ab13
cpufreq-set-274 [001] ..... 100.242907: scmi_xfer_response_wait: pt=13 msg_id=07 seq=0092 transfer_id=92 tmo_ms=5000 poll=0
cat-256 [000] d.h1. 100.243084: scmi_msg_dump: pt=13 t=RESP msg_id=07 seq=0092 s=0 pyld=
cat-256 [000] d.h1. 100.243094: scmi_rx_done: pt=13 msg_id=07 seq=0092 transfer_id=92 msg_type=0
cpufreq-set-274 [002] ..... 100.243120: scmi_xfer_end: pt=13 msg_id=07 seq=0092 transfer_id=92 s=0

Being just a proposal I'm open to any variation of this that could help
improving realiability and parsing, any feedback welcome !

Thanks,
Cristian

Cristian Marussi (1):
include: trace: Harmonize SCMI tracing message format

include/trace/events/scmi.h | 30 +++++++++++++++---------------
1 file changed, 15 insertions(+), 15 deletions(-)

--
2.37.2

2022-08-31 13:38:57

by Sudeep Holla

Subject: Re: [PATCH 0/1] Harmonize SCMI traces formats

On Thu, 18 Aug 2022 14:23:08 +0100, Cristian Marussi wrote:
> after having recently added new scmi_msg_dump traces I realized the
> general format of the various other SCMI traces is not consistent.
>
> As an example the full traces of a simple PERF_LEVEL_SET is now:
>
> cpufreq-set-276 [000] ..... 139.905639: scmi_xfer_begin: transfer_id=145 msg_id=7 protocol_id=19 seq=145 poll=0
> cpufreq-set-276 [000] ..... 139.905724: scmi_msg_dump: pt=13 t=CMND msg_id=07 seq=0091 s=0 pyld=000000008066ab13
> cpufreq-set-276 [000] ..... 139.905725: scmi_xfer_response_wait: transfer_id=145 msg_id=7 protocol_id=19 seq=145 tmo_ms=5000 poll=0
> <idle>-0 [000] d.h2. 139.906493: scmi_msg_dump: pt=13 t=RESP msg_id=07 seq=0091 s=0 pyld=
> <idle>-0 [000] d.h2. 139.906521: scmi_rx_done: transfer_id=145 msg_id=7 protocol_id=19 seq=145 msg_type=0
> cpufreq-set-276 [000] ..... 139.906651: scmi_xfer_end: transfer_id=145 msg_id=7 protocol_id=19 seq=145 status=0
>
> [...]

Applied to sudeep.holla/linux (for-next/scmi), thanks!

[1/1] include: trace: Harmonize SCMI tracing message format
https://git.kernel.org/sudeep.holla/c/40d30cf680cb

--
Regards,
Sudeep