[PATCH] perf, script: Fix crash with printing mixed trace point and other events

[PATCH] perf, script: Fix crash with printing mixed trace point and other events

[Andi Kleen]

From: Andi Kleen <ak@linux.intel.com>

perf script crashes currently when printing mixed trace points and other
events because the trace format does not handle events without trace
meta data. Add a simple check to avoid that.

% cat > test.c
main()
{
    printf("Hello world\n");
}
^D
% gcc -g -o test test.c
% sudo perf probe -x test 'test.c:3'
% perf record -e '{cpu/cpu-cycles,period=10000/,probe_test:main}:S' ./test
% perf script
<segfault>

Signed-off-by: Andi Kleen <ak@linux.intel.com>
---
 tools/perf/builtin-script.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/tools/perf/builtin-script.c b/tools/perf/builtin-script.c
index 3728b50e52e2..ea2396b33a57 100644
--- a/tools/perf/builtin-script.c
+++ b/tools/perf/builtin-script.c
@@ -1779,7 +1779,7 @@ static void process_event(struct perf_script *script,
 		return;
 	}
 
-	if (PRINT_FIELD(TRACE)) {
+	if (PRINT_FIELD(TRACE) && sample->raw_data) {
 		event_format__fprintf(evsel->tp_format, sample->cpu,
 				      sample->raw_data, sample->raw_size, fp);
 	}
-- 
2.17.2

Re: [PATCH] perf, script: Fix crash with printing mixed trace point and other events

[Jiri Olsa]

On Thu, Jan 17, 2019 at 11:48:34AM -0800, Andi Kleen wrote:
> From: Andi Kleen <ak@linux.intel.com>
> 
> perf script crashes currently when printing mixed trace points and other
> events because the trace format does not handle events without trace
> meta data. Add a simple check to avoid that.
> 
> % cat > test.c
> main()
> {
>     printf("Hello world\n");
> }
> ^D
> % gcc -g -o test test.c
> % sudo perf probe -x test 'test.c:3'
> % perf record -e '{cpu/cpu-cycles,period=10000/,probe_test:main}:S' ./test
> % perf script
> <segfault>
> 
> Signed-off-by: Andi Kleen <ak@linux.intel.com>

Acked-by: Jiri Olsa <jolsa@kernel.org>

thanks,
jirka

> ---
>  tools/perf/builtin-script.c | 2 +-
>  1 file changed, 1 insertion(+), 1 deletion(-)
> 
> diff --git a/tools/perf/builtin-script.c b/tools/perf/builtin-script.c
> index 3728b50e52e2..ea2396b33a57 100644
> --- a/tools/perf/builtin-script.c
> +++ b/tools/perf/builtin-script.c
> @@ -1779,7 +1779,7 @@ static void process_event(struct perf_script *script,
>  		return;
>  	}
>  
> -	if (PRINT_FIELD(TRACE)) {
> +	if (PRINT_FIELD(TRACE) && sample->raw_data) {
>  		event_format__fprintf(evsel->tp_format, sample->cpu,
>  				      sample->raw_data, sample->raw_size, fp);
>  	}
> -- 
> 2.17.2
> 

Re: [PATCH] perf, script: Fix crash with printing mixed trace point and other events

[Arnaldo Carvalho de Melo]

Em Fri, Jan 18, 2019 at 10:49:19AM +0100, Jiri Olsa escreveu:
> On Thu, Jan 17, 2019 at 11:48:34AM -0800, Andi Kleen wrote:
> > From: Andi Kleen <ak@linux.intel.com>

> > perf script crashes currently when printing mixed trace points and other
> > events because the trace format does not handle events without trace
> > meta data. Add a simple check to avoid that.

> > % cat > test.c
> > main()
> > {
> >     printf("Hello world\n");
> > }
> > ^D
> > % gcc -g -o test test.c
> > % sudo perf probe -x test 'test.c:3'
> > % perf record -e '{cpu/cpu-cycles,period=10000/,probe_test:main}:S' ./test
> > % perf script
> > <segfault>

> > Signed-off-by: Andi Kleen <ak@linux.intel.com>
 
> Acked-by: Jiri Olsa <jolsa@kernel.org>

Thanks, tested and applied.

While testing I found something odd, the cycles events are not showing
the CPU and the probe events shows a "negative" CPU column,
investigating.

- Arnaldo

Re: [PATCH] perf, script: Fix crash with printing mixed trace point and other events

[Arnaldo Carvalho de Melo]

Em Fri, Jan 18, 2019 at 09:59:20AM -0300, Arnaldo Carvalho de Melo escreveu:
> Em Fri, Jan 18, 2019 at 10:49:19AM +0100, Jiri Olsa escreveu:
> > On Thu, Jan 17, 2019 at 11:48:34AM -0800, Andi Kleen wrote:
> > > From: Andi Kleen <ak@linux.intel.com>
> 
> > > perf script crashes currently when printing mixed trace points and other
> > > events because the trace format does not handle events without trace
> > > meta data. Add a simple check to avoid that.
> 
> > > % cat > test.c
> > > main()
> > > {
> > >     printf("Hello world\n");
> > > }
> > > ^D
> > > % gcc -g -o test test.c
> > > % sudo perf probe -x test 'test.c:3'
> > > % perf record -e '{cpu/cpu-cycles,period=10000/,probe_test:main}:S' ./test
> > > % perf script
> > > <segfault>
> 
> > > Signed-off-by: Andi Kleen <ak@linux.intel.com>
>  
> > Acked-by: Jiri Olsa <jolsa@kernel.org>
> 
> Thanks, tested and applied.
> 
> While testing I found something odd, the cycles events are not showing
> the CPU and the probe events shows a "negative" CPU column,
> investigating.

The sample_type for those two events:

[root@quaco wb]# perf evlist -v
cpu/cpu-cycles,period=10000/: type: 4, size: 112, config: 0x3c, { sample_period, sample_freq }: 10000, sample_type: IP|TID|TIME|READ|IDENTIFIER, read_format: ID|GROUP, disabled: 1, mmap: 1, comm: 1, enable_on_exec: 1, task: 1, sample_id_all: 1, exclude_guest: 1, mmap2: 1, comm_exec: 1
probe_libc:malloc: type: 2, size: 112, config: 0x790, sample_type: IP|TID|TIME|READ|CPU|PERIOD|RAW|IDENTIFIER, read_format: ID|GROUP, sample_id_all: 1, exclude_guest: 1
# Tip: use 'perf evlist --trace-fields' to show fields for tracepoint events
[root@quaco wb]#

- Arnaldo

[RFC] Don't print sample_type bits in non-group events not set in the group's was Re: [PATCH] perf, script: Fix crash with printing mixed trace point and other events

[Arnaldo Carvalho de Melo]

Em Fri, Jan 18, 2019 at 10:01:06AM -0300, Arnaldo Carvalho de Melo escreveu:
> Em Fri, Jan 18, 2019 at 09:59:20AM -0300, Arnaldo Carvalho de Melo escreveu:
> > Thanks, tested and applied.

> > While testing I found something odd, the cycles events are not showing
> > the CPU and the probe events shows a "negative" CPU column,
> > investigating.
 
> The sample_type for those two events:
 
> [root@quaco wb]# perf evlist -v
> cpu/cpu-cycles,period=10000/: type: 4, size: 112, config: 0x3c, { sample_period, sample_freq }: 10000, sample_type: IP|TID|TIME|READ|IDENTIFIER, read_format: ID|GROUP, disabled: 1, mmap: 1, comm: 1, enable_on_exec: 1, task: 1, sample_id_all: 1, exclude_guest: 1, mmap2: 1, comm_exec: 1
> probe_libc:malloc: type: 2, size: 112, config: 0x790, sample_type: IP|TID|TIME|READ|CPU|PERIOD|RAW|IDENTIFIER, read_format: ID|GROUP, sample_id_all: 1, exclude_guest: 1
> # Tip: use 'perf evlist --trace-fields' to show fields for tracepoint events
> [root@quaco wb]#

The output:

  # perf probe -l
   probe_libc:malloc    (on __libc_malloc@malloc/malloc.c in /usr/lib64/libc-2.28.so)
   # perf record -e '{cpu/cpu-cycles,period=10000/,probe_libc:*}:S' sleep 1
   [ perf record: Woken up 1 times to write data ]
   [ perf record: Captured and wrote 0.023 MB perf.data (40 samples) ]
   # perf script
   Segmentation fault (core dumped)
   ^C
   #
 
 After:
 
   # perf script | head -6
      sleep 2888 94796.944981: 16198 cpu/cpu-cycles,period=10000/: ffffffff925dc04f get_random_u32+0x1f (/lib/modules/5.0.0-rc2+/build/vmlinux)
      sleep 2888 [-01] 94796.944981: probe_libc:malloc:
      sleep 2888 94796.944983:  4713 cpu/cpu-cycles,period=10000/: ffffffff922763af change_protection+0xcf (/lib/modules/5.0.0-rc2+/build/vmlinux)
      sleep 2888 [-01] 94796.944983: probe_libc:malloc:
      sleep 2888 94796.944986:  9934 cpu/cpu-cycles,period=10000/: ffffffff922777e0 move_page_tables+0x0 (/lib/modules/5.0.0-rc2+/build/vmlinux)
      sleep 2888 [-01] 94796.944986: probe_libc:malloc:
   #

For perf_sample->cpu to come out as -1 from perf_evsen__parse_sample() we would
have to have evsel->attr.sample_type not having PERF_SAMPLE_CPU set, which,
according to the 'perf evlist' output above, is not the case for
probe_libc:malloc...

So, this is because in this case we have it in a group so we end up never calling
perf_evsel__parse_sample for that probe_libc:malloc event, using the perf_sample
parsed for the cpu/cpu-cycles/ event that indeed doesn't have CPU set.

So we need to auto-deselect the CPU printing for non group events if the group
event doesn't have PERF_SAMPLE_CPU set, right Jiri?

See the details:

(gdb) b deliver_sample_value
Breakpoint 1 at 0x539a81: file util/session.c, line 1177.
(gdb) run script
Starting program: /root/bin/perf script
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
[Detaching after fork from child process 20014]

Breakpoint 1, deliver_sample_value (evlist=0xab2ce0, tool=0x7fffffffc3e0, event=0x7ffff7fcd408, sample=0x7fffffffbd50, v=0x7ffff7fcd438,
    machine=0xaaca60) at util/session.c:1177
1177	{
(gdb) bt
#0  deliver_sample_value (evlist=0xab2ce0, tool=0x7fffffffc3e0, event=0x7ffff7fcd408, sample=0x7fffffffbd50, v=0x7ffff7fcd438, machine=0xaaca60)
    at util/session.c:1177
#1  0x0000000000539bc6 in deliver_sample_group (evlist=0xab2ce0, tool=0x7fffffffc3e0, event=0x7ffff7fcd408, sample=0x7fffffffbd50,
    machine=0xaaca60) at util/session.c:1205
#2  0x0000000000539c9e in perf_evlist__deliver_sample (evlist=0xab2ce0, tool=0x7fffffffc3e0, event=0x7ffff7fcd408, sample=0x7fffffffbd50,
    evsel=0xab3730, machine=0xaaca60) at util/session.c:1233
#3  0x0000000000539e05 in machines__deliver_event (machines=0xaaca60, evlist=0xab2ce0, event=0x7ffff7fcd408, sample=0x7fffffffbd50,
    tool=0x7fffffffc3e0, file_offset=21512) at util/session.c:1266
#4  0x000000000053a219 in perf_session__deliver_event (session=0xaac960, event=0x7ffff7fcd408, tool=0x7fffffffc3e0, file_offset=21512)
    at util/session.c:1335
#5  0x0000000000536d22 in ordered_events__deliver_event (oe=0xab2bf0, event=0xad1da8) at util/session.c:113
#6  0x000000000053da1c in do_flush (oe=0xab2bf0, show_progress=true) at util/ordered-events.c:243
#7  0x000000000053dd4b in __ordered_events__flush (oe=0xab2bf0, how=OE_FLUSH__FINAL, timestamp=0) at util/ordered-events.c:320
#8  0x000000000053de20 in ordered_events__flush (oe=0xab2bf0, how=OE_FLUSH__FINAL) at util/ordered-events.c:338
#9  0x000000000053bb5c in __perf_session__process_events (session=0xaac960, data_offset=488, data_size=23424, file_size=23912)
    at util/session.c:1925
#10 0x000000000053bca5 in perf_session__process_events (session=0xaac960) at util/session.c:1955
#11 0x0000000000463d3e in __cmd_script (script=0x7fffffffc3e0) at builtin-script.c:2388
#12 0x0000000000468140 in cmd_script (argc=0, argv=0x7fffffffdb40) at builtin-script.c:3727
#13 0x00000000004d4a1a in run_builtin (p=0x92ab18 <commands+408>, argc=1, argv=0x7fffffffdb40) at perf.c:302
#14 0x00000000004d4c87 in handle_internal_command (argc=1, argv=0x7fffffffdb40) at perf.c:354
#15 0x00000000004d4dd6 in run_argv (argcp=0x7fffffffd99c, argv=0x7fffffffd990) at perf.c:398
#16 0x00000000004d5142 in main (argc=1, argv=0x7fffffffdb40) at perf.c:520
(gdb) p (int)sample->cpu
$1 = -1
(gdb) info b
Num     Type           Disp Enb Address            What
1       breakpoint     keep y   0x0000000000539a81 in deliver_sample_value at util/session.c:1177
	breakpoint already hit 1 time
(gdb) condition 1 (int)sample->cpu != -1
(gdb) c
Continuing.
    sleep  2888 94796.944981:      16198 cpu/cpu-cycles,period=10000/:  ffffffff925dc04f get_random_u32+0x1f (/lib/modules/5.0.0-rc2+/buil>
    sleep  2888 [-01] 94796.944981:            probe_libc:malloc:
    sleep  2888 94796.944983:       4713 cpu/cpu-cycles,period=10000/:  ffffffff922763af change_protection+0xcf (/lib/modules/5.0.0-rc2+/b>
    sleep  2888 [-01] 94796.944983:            probe_libc:malloc:
<SNIP>
[Inferior 1 (process 20003) exited normally]
(gdb)


See? None of the perf_sample parsed have perf_sample->cpu set, its all -1, which
is set in perf_evsel__parse_sample() to indicate that PERF_SAMPLE_TYPE wasn't found
in evsel->attr.sample_type for the evsel being used to parse the perf_event payload.

- Arnaldo

Re: [RFC] Don't print sample_type bits in non-group events not set in the group's was Re: [PATCH] perf, script: Fix crash with printing mixed trace point and other events

[Jiri Olsa]

On Fri, Jan 18, 2019 at 10:42:05AM -0300, Arnaldo Carvalho de Melo wrote:
> Em Fri, Jan 18, 2019 at 10:01:06AM -0300, Arnaldo Carvalho de Melo escreveu:
> > Em Fri, Jan 18, 2019 at 09:59:20AM -0300, Arnaldo Carvalho de Melo escreveu:
> > > Thanks, tested and applied.
> 
> > > While testing I found something odd, the cycles events are not showing
> > > the CPU and the probe events shows a "negative" CPU column,
> > > investigating.
>  
> > The sample_type for those two events:
>  
> > [root@quaco wb]# perf evlist -v
> > cpu/cpu-cycles,period=10000/: type: 4, size: 112, config: 0x3c, { sample_period, sample_freq }: 10000, sample_type: IP|TID|TIME|READ|IDENTIFIER, read_format: ID|GROUP, disabled: 1, mmap: 1, comm: 1, enable_on_exec: 1, task: 1, sample_id_all: 1, exclude_guest: 1, mmap2: 1, comm_exec: 1
> > probe_libc:malloc: type: 2, size: 112, config: 0x790, sample_type: IP|TID|TIME|READ|CPU|PERIOD|RAW|IDENTIFIER, read_format: ID|GROUP, sample_id_all: 1, exclude_guest: 1
> > # Tip: use 'perf evlist --trace-fields' to show fields for tracepoint events
> > [root@quaco wb]#
> 
> The output:
> 
>   # perf probe -l
>    probe_libc:malloc    (on __libc_malloc@malloc/malloc.c in /usr/lib64/libc-2.28.so)
>    # perf record -e '{cpu/cpu-cycles,period=10000/,probe_libc:*}:S' sleep 1
>    [ perf record: Woken up 1 times to write data ]
>    [ perf record: Captured and wrote 0.023 MB perf.data (40 samples) ]
>    # perf script
>    Segmentation fault (core dumped)
>    ^C
>    #
>  
>  After:
>  
>    # perf script | head -6
>       sleep 2888 94796.944981: 16198 cpu/cpu-cycles,period=10000/: ffffffff925dc04f get_random_u32+0x1f (/lib/modules/5.0.0-rc2+/build/vmlinux)
>       sleep 2888 [-01] 94796.944981: probe_libc:malloc:
>       sleep 2888 94796.944983:  4713 cpu/cpu-cycles,period=10000/: ffffffff922763af change_protection+0xcf (/lib/modules/5.0.0-rc2+/build/vmlinux)
>       sleep 2888 [-01] 94796.944983: probe_libc:malloc:
>       sleep 2888 94796.944986:  9934 cpu/cpu-cycles,period=10000/: ffffffff922777e0 move_page_tables+0x0 (/lib/modules/5.0.0-rc2+/build/vmlinux)
>       sleep 2888 [-01] 94796.944986: probe_libc:malloc:
>    #
> 
> For perf_sample->cpu to come out as -1 from perf_evsen__parse_sample() we would
> have to have evsel->attr.sample_type not having PERF_SAMPLE_CPU set, which,
> according to the 'perf evlist' output above, is not the case for
> probe_libc:malloc...
> 
> So, this is because in this case we have it in a group so we end up never calling
> perf_evsel__parse_sample for that probe_libc:malloc event, using the perf_sample
> parsed for the cpu/cpu-cycles/ event that indeed doesn't have CPU set.
> 
> So we need to auto-deselect the CPU printing for non group events if the group
> event doesn't have PERF_SAMPLE_CPU set, right Jiri?
> 
> See the details:
> 
> (gdb) b deliver_sample_value
> Breakpoint 1 at 0x539a81: file util/session.c, line 1177.
> (gdb) run script
> Starting program: /root/bin/perf script
> [Thread debugging using libthread_db enabled]
> Using host libthread_db library "/lib64/libthread_db.so.1".
> [Detaching after fork from child process 20014]
> 
> Breakpoint 1, deliver_sample_value (evlist=0xab2ce0, tool=0x7fffffffc3e0, event=0x7ffff7fcd408, sample=0x7fffffffbd50, v=0x7ffff7fcd438,
>     machine=0xaaca60) at util/session.c:1177
> 1177	{
> (gdb) bt
> #0  deliver_sample_value (evlist=0xab2ce0, tool=0x7fffffffc3e0, event=0x7ffff7fcd408, sample=0x7fffffffbd50, v=0x7ffff7fcd438, machine=0xaaca60)
>     at util/session.c:1177
> #1  0x0000000000539bc6 in deliver_sample_group (evlist=0xab2ce0, tool=0x7fffffffc3e0, event=0x7ffff7fcd408, sample=0x7fffffffbd50,
>     machine=0xaaca60) at util/session.c:1205
> #2  0x0000000000539c9e in perf_evlist__deliver_sample (evlist=0xab2ce0, tool=0x7fffffffc3e0, event=0x7ffff7fcd408, sample=0x7fffffffbd50,
>     evsel=0xab3730, machine=0xaaca60) at util/session.c:1233
> #3  0x0000000000539e05 in machines__deliver_event (machines=0xaaca60, evlist=0xab2ce0, event=0x7ffff7fcd408, sample=0x7fffffffbd50,
>     tool=0x7fffffffc3e0, file_offset=21512) at util/session.c:1266
> #4  0x000000000053a219 in perf_session__deliver_event (session=0xaac960, event=0x7ffff7fcd408, tool=0x7fffffffc3e0, file_offset=21512)
>     at util/session.c:1335
> #5  0x0000000000536d22 in ordered_events__deliver_event (oe=0xab2bf0, event=0xad1da8) at util/session.c:113
> #6  0x000000000053da1c in do_flush (oe=0xab2bf0, show_progress=true) at util/ordered-events.c:243
> #7  0x000000000053dd4b in __ordered_events__flush (oe=0xab2bf0, how=OE_FLUSH__FINAL, timestamp=0) at util/ordered-events.c:320
> #8  0x000000000053de20 in ordered_events__flush (oe=0xab2bf0, how=OE_FLUSH__FINAL) at util/ordered-events.c:338
> #9  0x000000000053bb5c in __perf_session__process_events (session=0xaac960, data_offset=488, data_size=23424, file_size=23912)
>     at util/session.c:1925
> #10 0x000000000053bca5 in perf_session__process_events (session=0xaac960) at util/session.c:1955
> #11 0x0000000000463d3e in __cmd_script (script=0x7fffffffc3e0) at builtin-script.c:2388
> #12 0x0000000000468140 in cmd_script (argc=0, argv=0x7fffffffdb40) at builtin-script.c:3727
> #13 0x00000000004d4a1a in run_builtin (p=0x92ab18 <commands+408>, argc=1, argv=0x7fffffffdb40) at perf.c:302
> #14 0x00000000004d4c87 in handle_internal_command (argc=1, argv=0x7fffffffdb40) at perf.c:354
> #15 0x00000000004d4dd6 in run_argv (argcp=0x7fffffffd99c, argv=0x7fffffffd990) at perf.c:398
> #16 0x00000000004d5142 in main (argc=1, argv=0x7fffffffdb40) at perf.c:520
> (gdb) p (int)sample->cpu
> $1 = -1
> (gdb) info b
> Num     Type           Disp Enb Address            What
> 1       breakpoint     keep y   0x0000000000539a81 in deliver_sample_value at util/session.c:1177
> 	breakpoint already hit 1 time
> (gdb) condition 1 (int)sample->cpu != -1
> (gdb) c
> Continuing.
>     sleep  2888 94796.944981:      16198 cpu/cpu-cycles,period=10000/:  ffffffff925dc04f get_random_u32+0x1f (/lib/modules/5.0.0-rc2+/buil>
>     sleep  2888 [-01] 94796.944981:            probe_libc:malloc:
>     sleep  2888 94796.944983:       4713 cpu/cpu-cycles,period=10000/:  ffffffff922763af change_protection+0xcf (/lib/modules/5.0.0-rc2+/b>
>     sleep  2888 [-01] 94796.944983:            probe_libc:malloc:
> <SNIP>
> [Inferior 1 (process 20003) exited normally]
> (gdb)
> 
> 
> See? None of the perf_sample parsed have perf_sample->cpu set, its all -1, which
> is set in perf_evsel__parse_sample() to indicate that PERF_SAMPLE_TYPE wasn't found
> in evsel->attr.sample_type for the evsel being used to parse the perf_event payload.

well the probe_test::main is never sampled, we just read its value
and attach it to the sampling leader - cycles

I wonder if there's a point to actualy display it in perf script
output.. we should probably skip (something like below) that and
add script field that would output the sample_read values for the
leader

jirka


---
diff --git a/tools/perf/builtin-script.c b/tools/perf/builtin-script.c
index f494f9aa0d06..85e76cec8a98 100644
--- a/tools/perf/builtin-script.c
+++ b/tools/perf/builtin-script.c
@@ -1925,6 +1925,14 @@ static int cleanup_scripting(void)
 	return scripting_ops ? scripting_ops->stop_script() : 0;
 }
 
+static bool perf_evsel__should_skip(struct perf_evsel *evsel)
+{
+	struct perf_event_attr *attr = &evsel->attr;
+	struct perf_evsel *leader = evsel->leader;
+
+	return (leader != evsel) && !attr->freq && !attr->sample_freq;
+}
+
 static int process_sample_event(struct perf_tool *tool,
 				union perf_event *event,
 				struct perf_sample *sample,
@@ -1934,6 +1942,9 @@ static int process_sample_event(struct perf_tool *tool,
 	struct perf_script *scr = container_of(tool, struct perf_script, tool);
 	struct addr_location al;
 
+	if (perf_evsel__should_skip(evsel))
+		return 0;
+
 	if (perf_time__ranges_skip_sample(scr->ptime_range, scr->range_num,
 					  sample->time)) {
 		return 0;

Re: [RFC] Don't print sample_type bits in non-group events not set in the group's was Re: [PATCH] perf, script: Fix crash with printing mixed trace point and other events

[Andi Kleen]

> +static bool perf_evsel__should_skip(struct perf_evsel *evsel)
> +{
> +	struct perf_event_attr *attr = &evsel->attr;
> +	struct perf_evsel *leader = evsel->leader;
> +
> +	return (leader != evsel) && !attr->freq && !attr->sample_freq;
> +}
> +
>  static int process_sample_event(struct perf_tool *tool,
>  				union perf_event *event,
>  				struct perf_sample *sample,
> @@ -1934,6 +1942,9 @@ static int process_sample_event(struct perf_tool *tool,
>  	struct perf_script *scr = container_of(tool, struct perf_script, tool);
>  	struct addr_location al;
>  
> +	if (perf_evsel__should_skip(evsel))
> +		return 0;

That just skips, but surely it has to be displayed somewhere?

-Andi

Re: [RFC] Don't print sample_type bits in non-group events not set in the group's was Re: [PATCH] perf, script: Fix crash with printing mixed trace point and other events

[Jiri Olsa]

On Fri, Jan 18, 2019 at 08:11:42AM -0800, Andi Kleen wrote:
> > +static bool perf_evsel__should_skip(struct perf_evsel *evsel)
> > +{
> > +	struct perf_event_attr *attr = &evsel->attr;
> > +	struct perf_evsel *leader = evsel->leader;
> > +
> > +	return (leader != evsel) && !attr->freq && !attr->sample_freq;
> > +}
> > +
> >  static int process_sample_event(struct perf_tool *tool,
> >  				union perf_event *event,
> >  				struct perf_sample *sample,
> > @@ -1934,6 +1942,9 @@ static int process_sample_event(struct perf_tool *tool,
> >  	struct perf_script *scr = container_of(tool, struct perf_script, tool);
> >  	struct addr_location al;
> >  
> > +	if (perf_evsel__should_skip(evsel))
> > +		return 0;
> 
> That just skips, but surely it has to be displayed somewhere?
>

yea as I wrote in that email:

.......   we should probably skip (something like below) that and
add script field that would output the sample_read values for the
leader

jirka

Re: [RFC] Don't print sample_type bits in non-group events not set in the group's was Re: [PATCH] perf, script: Fix crash with printing mixed trace point and other events

[Jiri Olsa]

On Fri, Jan 18, 2019 at 08:11:42AM -0800, Andi Kleen wrote:
> > +static bool perf_evsel__should_skip(struct perf_evsel *evsel)
> > +{
> > +	struct perf_event_attr *attr = &evsel->attr;
> > +	struct perf_evsel *leader = evsel->leader;
> > +
> > +	return (leader != evsel) && !attr->freq && !attr->sample_freq;
> > +}
> > +
> >  static int process_sample_event(struct perf_tool *tool,
> >  				union perf_event *event,
> >  				struct perf_sample *sample,
> > @@ -1934,6 +1942,9 @@ static int process_sample_event(struct perf_tool *tool,
> >  	struct perf_script *scr = container_of(tool, struct perf_script, tool);
> >  	struct addr_location al;
> >  
> > +	if (perf_evsel__should_skip(evsel))
> > +		return 0;
> 
> That just skips, but surely it has to be displayed somewhere?

actually maybe it's better to keep the current output,
and sort out the output for those slave events

with attached patch I can do:

  # ./perf script -Ftrace:+period,-cpu
              ex  5535 546813.189028:      11069 cpu/cpu-cycles,period=10000/:  ffffffffa492ad90 _raw_spin_lock+0x10 ([kernel.kallsyms])
              ex  5535 546813.189028:        101                probe_ex:main: 
              ex  5535 546813.189034:       9074 cpu/cpu-cycles,period=10000/:  ffffffffa4928066 down_read+0x6 ([kernel.kallsyms])
              ex  5535 546813.189041:      10102 cpu/cpu-cycles,period=10000/:  ffffffffa492af22 _raw_spin_lock_irqsave+0x22 ([kernel.kallsyms])
              ex  5535 546813.189041:          1                probe_ex:main: 

also now it won't make sample for slave events
with zero value/period read

note the patch needs to be split into more patches,
sending it all together for discussion over the solution

thanks,
jirka


---
diff --git a/tools/perf/builtin-script.c b/tools/perf/builtin-script.c
index 0c5dc4a52fc0..c8791d6bdf8e 100644
--- a/tools/perf/builtin-script.c
+++ b/tools/perf/builtin-script.c
@@ -2726,6 +2726,10 @@ static int parse_output_fields(const struct option *opt __maybe_unused,
 			pr_warning("Overriding previous field request for %s events.\n",
 				   event_type(type));
 
+		/* Don't override defaults for +- */
+		if (strchr(tok, '+') || strchr(tok, '-'))
+			goto parse;
+
 		output[type].fields = 0;
 		output[type].user_set = true;
 		output[type].wildcard_set = false;
@@ -2810,6 +2814,10 @@ static int parse_output_fields(const struct option *opt __maybe_unused,
 				rc = -EINVAL;
 				goto out;
 			}
+			if (change == REMOVE)
+				output[type].fields &= ~all_output_options[i].field;
+			else
+				output[type].fields |= all_output_options[i].field;
 			output[type].user_set = true;
 			output[type].wildcard_set = true;
 		}
diff --git a/tools/perf/util/evsel.c b/tools/perf/util/evsel.c
index dbc0466db368..7487b8f7ff96 100644
--- a/tools/perf/util/evsel.c
+++ b/tools/perf/util/evsel.c
@@ -956,6 +956,15 @@ void perf_evsel__config(struct perf_evsel *evsel, struct record_opts *opts,
 		attr->sample_freq    = 0;
 		attr->sample_period  = 0;
 		attr->write_backward = 0;
+
+		/*
+		 * We don't get sample for slave events, so let's
+		 * have them following the master sample_type to
+		 * make it easy during report.
+		 */
+		attr->sample_type |= leader->attr.sample_type;
+		perf_evsel__set_sample_bit(evsel, PERIOD);
+		perf_evsel__reset_sample_bit(evsel, READ);
 	}
 
 	if (opts->no_samples)
diff --git a/tools/perf/util/session.c b/tools/perf/util/session.c
index d6f41611f504..0cbb2a2fb942 100644
--- a/tools/perf/util/session.c
+++ b/tools/perf/util/session.c
@@ -1188,6 +1188,13 @@ static int deliver_sample_value(struct perf_evlist *evlist,
 		return 0;
 	}
 
+	/*
+	 * There's no reason to deliver sample
+	 * for zero period, bail out.
+	 */
+	if (!sample->period)
+		return 0;
+
 	return tool->sample(tool, event, sample, sid->evsel, machine);
 }
 

[tip:perf/urgent] perf script: Fix crash with printing mixed trace point and other events

[tip-bot for Andi Kleen]

Commit-ID:  96167167b6e17b25c0e05ecc31119b73baeab094
Gitweb:     https://git.kernel.org/tip/96167167b6e17b25c0e05ecc31119b73baeab094
Author:     Andi Kleen <ak@linux.intel.com>
AuthorDate: Thu, 17 Jan 2019 11:48:34 -0800
Committer:  Arnaldo Carvalho de Melo <acme@redhat.com>
CommitDate: Fri, 18 Jan 2019 09:53:07 -0300

perf script: Fix crash with printing mixed trace point and other events

'perf script' crashes currently when printing mixed trace points and
other events because the trace format does not handle events without
trace meta data. Add a simple check to avoid that.

  % cat > test.c
  main()
  {
      printf("Hello world\n");
  }
  ^D
  % gcc -g -o test test.c
  % sudo perf probe -x test 'test.c:3'
  % perf record -e '{cpu/cpu-cycles,period=10000/,probe_test:main}:S' ./test
  % perf script
  <segfault>

Committer testing:

Before:

  # perf probe -x /lib64/libc-2.28.so malloc
  Added new event:
    probe_libc:malloc    (on malloc in /usr/lib64/libc-2.28.so)

  You can now use it in all perf tools, such as:

	perf record -e probe_libc:malloc -aR sleep 1

  # perf probe -l
  probe_libc:malloc    (on __libc_malloc@malloc/malloc.c in /usr/lib64/libc-2.28.so)
  # perf record -e '{cpu/cpu-cycles,period=10000/,probe_libc:*}:S' sleep 1
  [ perf record: Woken up 1 times to write data ]
  [ perf record: Captured and wrote 0.023 MB perf.data (40 samples) ]
  # perf script
  Segmentation fault (core dumped)
  ^C
  #

After:

  # perf script | head -6
     sleep 2888 94796.944981: 16198 cpu/cpu-cycles,period=10000/: ffffffff925dc04f get_random_u32+0x1f (/lib/modules/5.0.0-rc2+/build/vmlinux)
     sleep 2888 [-01] 94796.944981: probe_libc:malloc:
     sleep 2888 94796.944983:  4713 cpu/cpu-cycles,period=10000/: ffffffff922763af change_protection+0xcf (/lib/modules/5.0.0-rc2+/build/vmlinux)
     sleep 2888 [-01] 94796.944983: probe_libc:malloc:
     sleep 2888 94796.944986:  9934 cpu/cpu-cycles,period=10000/: ffffffff922777e0 move_page_tables+0x0 (/lib/modules/5.0.0-rc2+/build/vmlinux)
     sleep 2888 [-01] 94796.944986: probe_libc:malloc:
  #

Signed-off-by: Andi Kleen <ak@linux.intel.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Acked-by: Jiri Olsa <jolsa@kernel.org>
Link: http://lkml.kernel.org/r/20190117194834.21940-1-andi@firstfloor.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
 tools/perf/builtin-script.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/tools/perf/builtin-script.c b/tools/perf/builtin-script.c
index d079f36d342d..357906ed1898 100644
--- a/tools/perf/builtin-script.c
+++ b/tools/perf/builtin-script.c
@@ -1794,7 +1794,7 @@ static void process_event(struct perf_script *script,
 		return;
 	}
 
-	if (PRINT_FIELD(TRACE)) {
+	if (PRINT_FIELD(TRACE) && sample->raw_data) {
 		event_format__fprintf(evsel->tp_format, sample->cpu,
 				      sample->raw_data, sample->raw_size, fp);
 	}

Re: [RFC] Don't print sample_type bits in non-group events not set in the group's was Re: [PATCH] perf, script: Fix crash with printing mixed trace point and other events

[Jiri Olsa]

On Sat, Jan 19, 2019 at 04:37:45PM +0100, Jiri Olsa wrote:
> On Fri, Jan 18, 2019 at 08:11:42AM -0800, Andi Kleen wrote:
> > > +static bool perf_evsel__should_skip(struct perf_evsel *evsel)
> > > +{
> > > +	struct perf_event_attr *attr = &evsel->attr;
> > > +	struct perf_evsel *leader = evsel->leader;
> > > +
> > > +	return (leader != evsel) && !attr->freq && !attr->sample_freq;
> > > +}
> > > +
> > >  static int process_sample_event(struct perf_tool *tool,
> > >  				union perf_event *event,
> > >  				struct perf_sample *sample,
> > > @@ -1934,6 +1942,9 @@ static int process_sample_event(struct perf_tool *tool,
> > >  	struct perf_script *scr = container_of(tool, struct perf_script, tool);
> > >  	struct addr_location al;
> > >  
> > > +	if (perf_evsel__should_skip(evsel))
> > > +		return 0;
> > 
> > That just skips, but surely it has to be displayed somewhere?
> 
> actually maybe it's better to keep the current output,
> and sort out the output for those slave events
> 
> with attached patch I can do:
> 
>   # ./perf script -Ftrace:+period,-cpu
>               ex  5535 546813.189028:      11069 cpu/cpu-cycles,period=10000/:  ffffffffa492ad90 _raw_spin_lock+0x10 ([kernel.kallsyms])
>               ex  5535 546813.189028:        101                probe_ex:main: 
>               ex  5535 546813.189034:       9074 cpu/cpu-cycles,period=10000/:  ffffffffa4928066 down_read+0x6 ([kernel.kallsyms])
>               ex  5535 546813.189041:      10102 cpu/cpu-cycles,period=10000/:  ffffffffa492af22 _raw_spin_lock_irqsave+0x22 ([kernel.kallsyms])
>               ex  5535 546813.189041:          1                probe_ex:main: 
> 
> also now it won't make sample for slave events
> with zero value/period read
> 
> note the patch needs to be split into more patches,
> sending it all together for discussion over the solution

any feedback on this one?

jirka

> 
> thanks,
> jirka
> 
> 
> ---
> diff --git a/tools/perf/builtin-script.c b/tools/perf/builtin-script.c
> index 0c5dc4a52fc0..c8791d6bdf8e 100644
> --- a/tools/perf/builtin-script.c
> +++ b/tools/perf/builtin-script.c
> @@ -2726,6 +2726,10 @@ static int parse_output_fields(const struct option *opt __maybe_unused,
>  			pr_warning("Overriding previous field request for %s events.\n",
>  				   event_type(type));
>  
> +		/* Don't override defaults for +- */
> +		if (strchr(tok, '+') || strchr(tok, '-'))
> +			goto parse;
> +
>  		output[type].fields = 0;
>  		output[type].user_set = true;
>  		output[type].wildcard_set = false;
> @@ -2810,6 +2814,10 @@ static int parse_output_fields(const struct option *opt __maybe_unused,
>  				rc = -EINVAL;
>  				goto out;
>  			}
> +			if (change == REMOVE)
> +				output[type].fields &= ~all_output_options[i].field;
> +			else
> +				output[type].fields |= all_output_options[i].field;
>  			output[type].user_set = true;
>  			output[type].wildcard_set = true;
>  		}
> diff --git a/tools/perf/util/evsel.c b/tools/perf/util/evsel.c
> index dbc0466db368..7487b8f7ff96 100644
> --- a/tools/perf/util/evsel.c
> +++ b/tools/perf/util/evsel.c
> @@ -956,6 +956,15 @@ void perf_evsel__config(struct perf_evsel *evsel, struct record_opts *opts,
>  		attr->sample_freq    = 0;
>  		attr->sample_period  = 0;
>  		attr->write_backward = 0;
> +
> +		/*
> +		 * We don't get sample for slave events, so let's
> +		 * have them following the master sample_type to
> +		 * make it easy during report.
> +		 */
> +		attr->sample_type |= leader->attr.sample_type;
> +		perf_evsel__set_sample_bit(evsel, PERIOD);
> +		perf_evsel__reset_sample_bit(evsel, READ);
>  	}
>  
>  	if (opts->no_samples)
> diff --git a/tools/perf/util/session.c b/tools/perf/util/session.c
> index d6f41611f504..0cbb2a2fb942 100644
> --- a/tools/perf/util/session.c
> +++ b/tools/perf/util/session.c
> @@ -1188,6 +1188,13 @@ static int deliver_sample_value(struct perf_evlist *evlist,
>  		return 0;
>  	}
>  
> +	/*
> +	 * There's no reason to deliver sample
> +	 * for zero period, bail out.
> +	 */
> +	if (!sample->period)
> +		return 0;
> +
>  	return tool->sample(tool, event, sample, sid->evsel, machine);
>  }
>  

Re: [RFC] Don't print sample_type bits in non-group events not set in the group's was Re: [PATCH] perf, script: Fix crash with printing mixed trace point and other events

[Andi Kleen]

> > also now it won't make sample for slave events
> > with zero value/period read
> > 
> > note the patch needs to be split into more patches,
> > sending it all together for discussion over the solution
> 
> any feedback on this one?

Looks good to me.

Reviewed-by: Andi Kleen <ak@linux.intel.com>
-Andi

Re: [RFC] Don't print sample_type bits in non-group events not set in the group's was Re: [PATCH] perf, script: Fix crash with printing mixed trace point and other events

[Arnaldo Carvalho de Melo]

Em Mon, Jan 28, 2019 at 09:00:37AM -0800, Andi Kleen escreveu:
> > > also now it won't make sample for slave events
> > > with zero value/period read
> > > 
> > > note the patch needs to be split into more patches,
> > > sending it all together for discussion over the solution
> > 
> > any feedback on this one?
> 
> Looks good to me.
> 
> Reviewed-by: Andi Kleen <ak@linux.intel.com>
> -Andi

Jiri, can you repost with a proper Subject line, Andi's reviewed-by,
etc?

- Arnaldo

Re: [RFC] Don't print sample_type bits in non-group events not set in the group's was Re: [PATCH] perf, script: Fix crash with printing mixed trace point and other events

[Jiri Olsa]

On Tue, Jan 29, 2019 at 09:48:51AM +0100, Arnaldo Carvalho de Melo wrote:
> Em Mon, Jan 28, 2019 at 09:00:37AM -0800, Andi Kleen escreveu:
> > > > also now it won't make sample for slave events
> > > > with zero value/period read
> > > > 
> > > > note the patch needs to be split into more patches,
> > > > sending it all together for discussion over the solution
> > > 
> > > any feedback on this one?
> > 
> > Looks good to me.
> > 
> > Reviewed-by: Andi Kleen <ak@linux.intel.com>
> > -Andi
> 
> Jiri, can you repost with a proper Subject line, Andi's reviewed-by,
> etc?

yes, I need to separate that change also.. just wanted
some ack on the output ;-)

jirka