All of lore.kernel.org
 help / color / mirror / Atom feed
* [PATCH 0/1] Harmonize SCMI traces formats
@ 2022-08-18 13:23 ` Cristian Marussi
  0 siblings, 0 replies; 6+ messages in thread
From: Cristian Marussi @ 2022-08-18 13:23 UTC (permalink / raw)
  To: linux-kernel, linux-arm-kernel
  Cc: sudeep.holla, james.quinlan, f.fainelli, vincent.guittot,
	lukasz.luba, Cristian Marussi

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


^ permalink raw reply	[flat|nested] 6+ messages in thread
* [PATCH 0/1] Harmonize SCMI traces formats
@ 2022-08-18 13:23 ` Cristian Marussi
  0 siblings, 0 replies; 6+ messages in thread
From: Cristian Marussi @ 2022-08-18 13:23 UTC (permalink / raw)
  To: linux-kernel, linux-arm-kernel
  Cc: sudeep.holla, james.quinlan, f.fainelli, vincent.guittot,
	lukasz.luba, Cristian Marussi

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


_______________________________________________
linux-arm-kernel mailing list
linux-arm-kernel@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-arm-kernel

^ permalink raw reply	[flat|nested] 6+ messages in thread
* [PATCH 1/1] include: trace: Harmonize SCMI tracing message format
  2022-08-18 13:23 ` Cristian Marussi
@ 2022-08-18 13:23   ` Cristian Marussi
  -1 siblings, 0 replies; 6+ messages in thread
From: Cristian Marussi @ 2022-08-18 13:23 UTC (permalink / raw)
  To: linux-kernel, linux-arm-kernel
  Cc: sudeep.holla, james.quinlan, f.fainelli, vincent.guittot,
	lukasz.luba, Cristian Marussi

Use the same format and across all SCMI traces.

Signed-off-by: Cristian Marussi <cristian.marussi@arm.com>
---
 include/trace/events/scmi.h | 30 +++++++++++++++---------------
 1 file changed, 15 insertions(+), 15 deletions(-)

diff --git a/include/trace/events/scmi.h b/include/trace/events/scmi.h
index 65016a767b7a..f160d68f961d 100644
--- a/include/trace/events/scmi.h
+++ b/include/trace/events/scmi.h
@@ -27,9 +27,9 @@ TRACE_EVENT(scmi_fc_call,
 		__entry->val2 = val2;
 	),
 
-	TP_printk("[0x%02X]:[0x%02X]:[%08X]:%u:%u",
-		  __entry->protocol_id, __entry->msg_id,
-		  __entry->res_id, __entry->val1, __entry->val2)
+	TP_printk("pt=%02X msg_id=%02X res_id:%u vals=%u:%u",
+		__entry->protocol_id, __entry->msg_id,
+		__entry->res_id, __entry->val1, __entry->val2)
 );
 
 TRACE_EVENT(scmi_xfer_begin,
@@ -53,9 +53,9 @@ TRACE_EVENT(scmi_xfer_begin,
 		__entry->poll = poll;
 	),
 
-	TP_printk("transfer_id=%d msg_id=%u protocol_id=%u seq=%u poll=%u",
-		__entry->transfer_id, __entry->msg_id, __entry->protocol_id,
-		__entry->seq, __entry->poll)
+	TP_printk("pt=%02X msg_id=%02X seq=%04X transfer_id=%X poll=%u",
+		__entry->protocol_id, __entry->msg_id, __entry->seq,
+		__entry->transfer_id, __entry->poll)
 );
 
 TRACE_EVENT(scmi_xfer_response_wait,
@@ -81,9 +81,9 @@ TRACE_EVENT(scmi_xfer_response_wait,
 		__entry->poll = poll;
 	),
 
-	TP_printk("transfer_id=%d msg_id=%u protocol_id=%u seq=%u tmo_ms=%u poll=%u",
-		__entry->transfer_id, __entry->msg_id, __entry->protocol_id,
-		__entry->seq, __entry->timeout, __entry->poll)
+	TP_printk("pt=%02X msg_id=%02X seq=%04X transfer_id=%X tmo_ms=%u poll=%u",
+		__entry->protocol_id, __entry->msg_id, __entry->seq,
+		__entry->transfer_id, __entry->timeout, __entry->poll)
 );
 
 TRACE_EVENT(scmi_xfer_end,
@@ -107,9 +107,9 @@ TRACE_EVENT(scmi_xfer_end,
 		__entry->status = status;
 	),
 
-	TP_printk("transfer_id=%d msg_id=%u protocol_id=%u seq=%u status=%d",
-		__entry->transfer_id, __entry->msg_id, __entry->protocol_id,
-		__entry->seq, __entry->status)
+	TP_printk("pt=%02X msg_id=%02X seq=%04X transfer_id=%X s=%d",
+		__entry->protocol_id, __entry->msg_id, __entry->seq,
+		__entry->transfer_id, __entry->status)
 );
 
 TRACE_EVENT(scmi_rx_done,
@@ -133,9 +133,9 @@ TRACE_EVENT(scmi_rx_done,
 		__entry->msg_type = msg_type;
 	),
 
-	TP_printk("transfer_id=%d msg_id=%u protocol_id=%u seq=%u msg_type=%u",
-		__entry->transfer_id, __entry->msg_id, __entry->protocol_id,
-		__entry->seq, __entry->msg_type)
+	TP_printk("pt=%02X msg_id=%02X seq=%04X transfer_id=%X msg_type=%u",
+		__entry->protocol_id, __entry->msg_id, __entry->seq,
+		__entry->transfer_id, __entry->msg_type)
 );
 
 TRACE_EVENT(scmi_msg_dump,
-- 
2.37.2


^ permalink raw reply related	[flat|nested] 6+ messages in thread
* [PATCH 1/1] include: trace: Harmonize SCMI tracing message format
@ 2022-08-18 13:23   ` Cristian Marussi
  0 siblings, 0 replies; 6+ messages in thread
From: Cristian Marussi @ 2022-08-18 13:23 UTC (permalink / raw)
  To: linux-kernel, linux-arm-kernel
  Cc: sudeep.holla, james.quinlan, f.fainelli, vincent.guittot,
	lukasz.luba, Cristian Marussi

Use the same format and across all SCMI traces.

Signed-off-by: Cristian Marussi <cristian.marussi@arm.com>
---
 include/trace/events/scmi.h | 30 +++++++++++++++---------------
 1 file changed, 15 insertions(+), 15 deletions(-)

diff --git a/include/trace/events/scmi.h b/include/trace/events/scmi.h
index 65016a767b7a..f160d68f961d 100644
--- a/include/trace/events/scmi.h
+++ b/include/trace/events/scmi.h
@@ -27,9 +27,9 @@ TRACE_EVENT(scmi_fc_call,
 		__entry->val2 = val2;
 	),
 
-	TP_printk("[0x%02X]:[0x%02X]:[%08X]:%u:%u",
-		  __entry->protocol_id, __entry->msg_id,
-		  __entry->res_id, __entry->val1, __entry->val2)
+	TP_printk("pt=%02X msg_id=%02X res_id:%u vals=%u:%u",
+		__entry->protocol_id, __entry->msg_id,
+		__entry->res_id, __entry->val1, __entry->val2)
 );
 
 TRACE_EVENT(scmi_xfer_begin,
@@ -53,9 +53,9 @@ TRACE_EVENT(scmi_xfer_begin,
 		__entry->poll = poll;
 	),
 
-	TP_printk("transfer_id=%d msg_id=%u protocol_id=%u seq=%u poll=%u",
-		__entry->transfer_id, __entry->msg_id, __entry->protocol_id,
-		__entry->seq, __entry->poll)
+	TP_printk("pt=%02X msg_id=%02X seq=%04X transfer_id=%X poll=%u",
+		__entry->protocol_id, __entry->msg_id, __entry->seq,
+		__entry->transfer_id, __entry->poll)
 );
 
 TRACE_EVENT(scmi_xfer_response_wait,
@@ -81,9 +81,9 @@ TRACE_EVENT(scmi_xfer_response_wait,
 		__entry->poll = poll;
 	),
 
-	TP_printk("transfer_id=%d msg_id=%u protocol_id=%u seq=%u tmo_ms=%u poll=%u",
-		__entry->transfer_id, __entry->msg_id, __entry->protocol_id,
-		__entry->seq, __entry->timeout, __entry->poll)
+	TP_printk("pt=%02X msg_id=%02X seq=%04X transfer_id=%X tmo_ms=%u poll=%u",
+		__entry->protocol_id, __entry->msg_id, __entry->seq,
+		__entry->transfer_id, __entry->timeout, __entry->poll)
 );
 
 TRACE_EVENT(scmi_xfer_end,
@@ -107,9 +107,9 @@ TRACE_EVENT(scmi_xfer_end,
 		__entry->status = status;
 	),
 
-	TP_printk("transfer_id=%d msg_id=%u protocol_id=%u seq=%u status=%d",
-		__entry->transfer_id, __entry->msg_id, __entry->protocol_id,
-		__entry->seq, __entry->status)
+	TP_printk("pt=%02X msg_id=%02X seq=%04X transfer_id=%X s=%d",
+		__entry->protocol_id, __entry->msg_id, __entry->seq,
+		__entry->transfer_id, __entry->status)
 );
 
 TRACE_EVENT(scmi_rx_done,
@@ -133,9 +133,9 @@ TRACE_EVENT(scmi_rx_done,
 		__entry->msg_type = msg_type;
 	),
 
-	TP_printk("transfer_id=%d msg_id=%u protocol_id=%u seq=%u msg_type=%u",
-		__entry->transfer_id, __entry->msg_id, __entry->protocol_id,
-		__entry->seq, __entry->msg_type)
+	TP_printk("pt=%02X msg_id=%02X seq=%04X transfer_id=%X msg_type=%u",
+		__entry->protocol_id, __entry->msg_id, __entry->seq,
+		__entry->transfer_id, __entry->msg_type)
 );
 
 TRACE_EVENT(scmi_msg_dump,
-- 
2.37.2


_______________________________________________
linux-arm-kernel mailing list
linux-arm-kernel@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-arm-kernel

^ permalink raw reply related	[flat|nested] 6+ messages in thread
* Re: [PATCH 0/1] Harmonize SCMI traces formats
  2022-08-18 13:23 ` Cristian Marussi
@ 2022-08-31 13:25   ` Sudeep Holla
  -1 siblings, 0 replies; 6+ messages in thread
From: Sudeep Holla @ 2022-08-31 13:25 UTC (permalink / raw)
  To: linux-arm-kernel, linux-kernel, cristian.marussi
  Cc: Sudeep Holla, james.quinlan, f.fainelli, vincent.guittot, lukasz.luba

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


^ permalink raw reply	[flat|nested] 6+ messages in thread
* Re: [PATCH 0/1] Harmonize SCMI traces formats
@ 2022-08-31 13:25   ` Sudeep Holla
  0 siblings, 0 replies; 6+ messages in thread
From: Sudeep Holla @ 2022-08-31 13:25 UTC (permalink / raw)
  To: linux-arm-kernel, linux-kernel, cristian.marussi
  Cc: Sudeep Holla, james.quinlan, f.fainelli, vincent.guittot, lukasz.luba

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


_______________________________________________
linux-arm-kernel mailing list
linux-arm-kernel@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-arm-kernel

^ permalink raw reply	[flat|nested] 6+ messages in thread
end of thread, other threads:[~2022-08-31 13:26 UTC | newest]

Thread overview: 6+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2022-08-18 13:23 [PATCH 0/1] Harmonize SCMI traces formats Cristian Marussi
2022-08-18 13:23 ` Cristian Marussi
2022-08-18 13:23 ` [PATCH 1/1] include: trace: Harmonize SCMI tracing message format Cristian Marussi
2022-08-18 13:23   ` Cristian Marussi
2022-08-31 13:25 ` [PATCH 0/1] Harmonize SCMI traces formats Sudeep Holla
2022-08-31 13:25   ` Sudeep Holla

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.