subject:"\[PATCH\] perf session\: Dump PERF_RECORD_TIME

Re: [PATCH] perf session: Dump PERF_RECORD_TIME_CONV event

2021-04-10 Thread Leo Yan

Hi Adrian,

On Sat, Apr 10, 2021 at 11:46:10AM +0300, Adrian Hunter wrote:

[...]

> Hi Leo
> 
> I think there might be some more work related to this.
> 
> Pedantically, shouldn't you cater for backward compatibility and
> not assume the following were in the perf.data file:
>   
>  
>__u64time_cycles;  
>   
>  
>__u64time_mask;
>   
>  
>bool cap_user_time_zero;   
>   
>  
>bool cap_user_time_short;   
> 
> That means checking the event size.
> 
> Also PERF_RECORD_TIME_CONV should have its own byte-swapper instead of  
> perf_event__all64_swap() - also checking event size.
> 
> i.e. fixes for:
> 
>   commit d110162cafc80dad0622cfd40f3113aebb77e1bb
>   Author: Leo Yan 
>   Date:   Mon Sep 14 19:53:09 2020 +0800
> 
> perf tsc: Support cap_user_time_short for event TIME_CONV

Indeed!  IIUC, should have three fixes with event size checking:

- One fix for dumping TIME_CONV event;
- One fix for byte-swapper (especially for bool values);
- One fix for commit d110162cafc80dad0622cfd40f3113aebb77e1bb;

Will follow up for the suggestions.  Thanks a lot for your insight
review.

Leo

Re: [PATCH] perf session: Dump PERF_RECORD_TIME_CONV event

2021-04-10 Thread Adrian Hunter

On 10/04/21 6:19 am, Leo Yan wrote:
> Now perf tool uses the common stub function process_event_op2_stub() for
> dumping TIME_CONV event, thus it doesn't output the clock parameters
> contained in the event.
> 
> This patch adds the callback function for dumping the hardware clock
> parameters in TIME_CONV event.
> 
> Before:
> 
>   # perf report -D
> 
>   0x978 [0x38]: event: 79
>   .
>   . ... raw event: size 56 bytes
>   .  :  4f 00 00 00 00 00 38 00 15 00 00 00 00 00 00 00  O.8.
>   .  0010:  00 00 40 01 00 00 00 00 86 89 0b bf df ff ff ff  
> ..@
>   .  0020:  d1 c1 b2 39 03 00 00 00 ff ff ff ff ff ff ff 00  
> 9.
>   .  0030:  01 01 00 00 00 00 00 00  
> 
>   0 0 0x978 [0x38]: PERF_RECORD_TIME_CONV
>   : unhandled!
> 
>   [...]
> 
> After:
> 
>   # perf report -D
> 
>   0x978 [0x38]: event: 79
>   .
>   . ... raw event: size 56 bytes
>   .  :  4f 00 00 00 00 00 38 00 15 00 00 00 00 00 00 00  O.8.
>   .  0010:  00 00 40 01 00 00 00 00 86 89 0b bf df ff ff ff  
> ..@
>   .  0020:  d1 c1 b2 39 03 00 00 00 ff ff ff ff ff ff ff 00  
> 9.
>   .  0030:  01 01 00 00 00 00 00 00  
> 
>   0 0 0x978 [0x38]: PERF_RECORD_TIME_CONV
>   ... Time Shift  21
>   ... Time Muliplier  20971520
>   ... Time Zero   18446743935180835206
>   ... Time Cycles 13852918225
>   ... Time Mask   0xff
>   ... Cap Time Zero   1
>   ... Cap Time Short  1
>   : unhandled!
> 
>   [...]
> 
> Signed-off-by: Leo Yan 
> ---
>  tools/perf/util/session.c | 13 -
>  tools/perf/util/tsc.c | 18 ++
>  tools/perf/util/tsc.h |  4 
>  3 files changed, 34 insertions(+), 1 deletion(-)
> 
> diff --git a/tools/perf/util/session.c b/tools/perf/util/session.c
> index 9a8808507bd9..75931c8054aa 100644
> --- a/tools/perf/util/session.c
> +++ b/tools/perf/util/session.c
> @@ -29,6 +29,7 @@
>  #include "thread-stack.h"
>  #include "sample-raw.h"
>  #include "stat.h"
> +#include "tsc.h"
>  #include "ui/progress.h"
>  #include "../perf.h"
>  #include "arch/common.h"
> @@ -451,6 +452,16 @@ static int process_stat_round_stub(struct perf_session 
> *perf_session __maybe_unu
>   return 0;
>  }
>  
> +static int process_event_time_conv_stub(struct perf_session *perf_session 
> __maybe_unused,
> + union perf_event *event)
> +{
> + if (dump_trace)
> + perf_event__fprintf_time_conv(event, stdout);
> +
> + dump_printf(": unhandled!\n");
> + return 0;
> +}
> +
>  static int perf_session__process_compressed_event_stub(struct perf_session 
> *session __maybe_unused,
>  union perf_event *event 
> __maybe_unused,
>  u64 file_offset 
> __maybe_unused)
> @@ -532,7 +543,7 @@ void perf_tool__fill_defaults(struct perf_tool *tool)
>   if (tool->stat_round == NULL)
>   tool->stat_round = process_stat_round_stub;
>   if (tool->time_conv == NULL)
> - tool->time_conv = process_event_op2_stub;
> + tool->time_conv = process_event_time_conv_stub;
>   if (tool->feature == NULL)
>   tool->feature = process_event_op2_stub;
>   if (tool->compressed == NULL)
> diff --git a/tools/perf/util/tsc.c b/tools/perf/util/tsc.c
> index 62b4c75c966c..4ac3cc72f3e1 100644
> --- a/tools/perf/util/tsc.c
> +++ b/tools/perf/util/tsc.c
> @@ -1,5 +1,7 @@
>  // SPDX-License-Identifier: GPL-2.0
>  #include 
> +#include 
> +#include 
>  
>  #include 
>  #include 
> @@ -110,3 +112,19 @@ u64 __weak rdtsc(void)
>  {
>   return 0;
>  }
> +
> +size_t perf_event__fprintf_time_conv(union perf_event *event, FILE *fp)
> +{
> + struct perf_record_time_conv *tc = (struct perf_record_time_conv 
> *)event;
> + size_t ret;
> +
> + ret  = fprintf(fp, "\n... Time Shift  %" PRI_lu64 "\n", 
> tc->time_shift);
> + ret += fprintf(fp, "... Time Muliplier  %" PRI_lu64 "\n", 
> tc->time_mult);
> + ret += fprintf(fp, "... Time Zero   %" PRI_lu64 "\n", 
> tc->time_zero);
> + ret += fprintf(fp, "... Time Cycles %" PRI_lu64 "\n", 
> tc->time_cycles);
> + ret += fprintf(fp, "... Time Mask   %#" PRI_lx64 "\n", 
> tc->time_mask);
> + ret += fprintf(fp, "... Cap Time Zero   %" PRId32 "\n", 
> tc->cap_user_time_zero);
> + ret += fprintf(fp, "... Cap Time Short  %" PRId32 "\n", 
> tc->cap_user_time_short);

Hi Leo

I think there might be some more work related to this.

Pedantically, shouldn't you cater for backward compatibility and
not assume the following were in the perf.data file:

   
   __u64time_cycles;

[PATCH] perf session: Dump PERF_RECORD_TIME_CONV event

2021-04-09 Thread Leo Yan

Now perf tool uses the common stub function process_event_op2_stub() for
dumping TIME_CONV event, thus it doesn't output the clock parameters
contained in the event.

This patch adds the callback function for dumping the hardware clock
parameters in TIME_CONV event.

Before:

  # perf report -D

  0x978 [0x38]: event: 79
  .
  . ... raw event: size 56 bytes
  .  :  4f 00 00 00 00 00 38 00 15 00 00 00 00 00 00 00  O.8.
  .  0010:  00 00 40 01 00 00 00 00 86 89 0b bf df ff ff ff  
..@
  .  0020:  d1 c1 b2 39 03 00 00 00 ff ff ff ff ff ff ff 00  
9.
  .  0030:  01 01 00 00 00 00 00 00  

  0 0 0x978 [0x38]: PERF_RECORD_TIME_CONV
  : unhandled!

  [...]

After:

  # perf report -D

  0x978 [0x38]: event: 79
  .
  . ... raw event: size 56 bytes
  .  :  4f 00 00 00 00 00 38 00 15 00 00 00 00 00 00 00  O.8.
  .  0010:  00 00 40 01 00 00 00 00 86 89 0b bf df ff ff ff  
..@
  .  0020:  d1 c1 b2 39 03 00 00 00 ff ff ff ff ff ff ff 00  
9.
  .  0030:  01 01 00 00 00 00 00 00  

  0 0 0x978 [0x38]: PERF_RECORD_TIME_CONV
  ... Time Shift  21
  ... Time Muliplier  20971520
  ... Time Zero   18446743935180835206
  ... Time Cycles 13852918225
  ... Time Mask   0xff
  ... Cap Time Zero   1
  ... Cap Time Short  1
  : unhandled!

  [...]

Signed-off-by: Leo Yan 
---
 tools/perf/util/session.c | 13 -
 tools/perf/util/tsc.c | 18 ++
 tools/perf/util/tsc.h |  4 
 3 files changed, 34 insertions(+), 1 deletion(-)

diff --git a/tools/perf/util/session.c b/tools/perf/util/session.c
index 9a8808507bd9..75931c8054aa 100644
--- a/tools/perf/util/session.c
+++ b/tools/perf/util/session.c
@@ -29,6 +29,7 @@
 #include "thread-stack.h"
 #include "sample-raw.h"
 #include "stat.h"
+#include "tsc.h"
 #include "ui/progress.h"
 #include "../perf.h"
 #include "arch/common.h"
@@ -451,6 +452,16 @@ static int process_stat_round_stub(struct perf_session 
*perf_session __maybe_unu
return 0;
 }
 
+static int process_event_time_conv_stub(struct perf_session *perf_session 
__maybe_unused,
+   union perf_event *event)
+{
+   if (dump_trace)
+   perf_event__fprintf_time_conv(event, stdout);
+
+   dump_printf(": unhandled!\n");
+   return 0;
+}
+
 static int perf_session__process_compressed_event_stub(struct perf_session 
*session __maybe_unused,
   union perf_event *event 
__maybe_unused,
   u64 file_offset 
__maybe_unused)
@@ -532,7 +543,7 @@ void perf_tool__fill_defaults(struct perf_tool *tool)
if (tool->stat_round == NULL)
tool->stat_round = process_stat_round_stub;
if (tool->time_conv == NULL)
-   tool->time_conv = process_event_op2_stub;
+   tool->time_conv = process_event_time_conv_stub;
if (tool->feature == NULL)
tool->feature = process_event_op2_stub;
if (tool->compressed == NULL)
diff --git a/tools/perf/util/tsc.c b/tools/perf/util/tsc.c
index 62b4c75c966c..4ac3cc72f3e1 100644
--- a/tools/perf/util/tsc.c
+++ b/tools/perf/util/tsc.c
@@ -1,5 +1,7 @@
 // SPDX-License-Identifier: GPL-2.0
 #include 
+#include 
+#include 
 
 #include 
 #include 
@@ -110,3 +112,19 @@ u64 __weak rdtsc(void)
 {
return 0;
 }
+
+size_t perf_event__fprintf_time_conv(union perf_event *event, FILE *fp)
+{
+   struct perf_record_time_conv *tc = (struct perf_record_time_conv 
*)event;
+   size_t ret;
+
+   ret  = fprintf(fp, "\n... Time Shift  %" PRI_lu64 "\n", 
tc->time_shift);
+   ret += fprintf(fp, "... Time Muliplier  %" PRI_lu64 "\n", 
tc->time_mult);
+   ret += fprintf(fp, "... Time Zero   %" PRI_lu64 "\n", 
tc->time_zero);
+   ret += fprintf(fp, "... Time Cycles %" PRI_lu64 "\n", 
tc->time_cycles);
+   ret += fprintf(fp, "... Time Mask   %#" PRI_lx64 "\n", 
tc->time_mask);
+   ret += fprintf(fp, "... Cap Time Zero   %" PRId32 "\n", 
tc->cap_user_time_zero);
+   ret += fprintf(fp, "... Cap Time Short  %" PRId32 "\n", 
tc->cap_user_time_short);
+
+   return ret;
+}
diff --git a/tools/perf/util/tsc.h b/tools/perf/util/tsc.h
index 72a15419f3b3..7d83a31732a7 100644
--- a/tools/perf/util/tsc.h
+++ b/tools/perf/util/tsc.h
@@ -4,6 +4,8 @@
 
 #include 
 
+#include "event.h"
+
 struct perf_tsc_conversion {
u16 time_shift;
u32 time_mult;
@@ -24,4 +26,6 @@ u64 perf_time_to_tsc(u64 ns, struct perf_tsc_conversion *tc);
 u64 tsc_to_perf_time(u64 cyc, struct perf_tsc_conversion *tc);
 u64 rdtsc(void);
 
+size_t perf_event__fprintf_time_conv(union perf_event *event, FILE *fp);
+
 #endif // __PERF_TSC_H
-- 
2.25.1

Re: [PATCH] perf session: Dump PERF_RECORD_TIME_CONV event

Re: [PATCH] perf session: Dump PERF_RECORD_TIME_CONV event

[PATCH] perf session: Dump PERF_RECORD_TIME_CONV event

3 matches

Site Navigation

Mail list logo

Footer information