LinuxLists.cc - perf sched broken on tip, bisected

2010-02-22 18:10:25

Subject: perf sched broken on tip, bisected

While testing a patch series I'm working on I noticed that 'perf sched record ;
perf sched latency' is broken on tip, bisected it down to this cset, investigating...

[acme@mica linux-2.6-tip]$ git bisect good
86d8d29634de4464d568e7c335c0da6cba64e8ab is first bad commit
commit 86d8d29634de4464d568e7c335c0da6cba64e8ab
Author: Hitoshi Mitake <[email protected]>
Date: Sat Jan 30 20:43:23 2010 +0900

perf tools: Add __data_loc support

This patch is required to test the next patch for perf lock.

At 064739bc4b3d7f424b2f25547e6611bcf0132415 ,
support for the modifier "__data_loc" of format is added.

But, when I wanted to parse format of lock_acquired (or some
event else), raw_field_ptr() did not returned correct pointer.

So I modified raw_field_ptr() like this patch. Then
raw_field_ptr() works well.

Signed-off-by: Hitoshi Mitake <[email protected]>
Acked-by: Frederic Weisbecker <[email protected]>
Cc: Peter Zijlstra <[email protected]>
Cc: Paul Mackerras <[email protected]>
Cc: Tom Zanussi <[email protected]>
Cc: Steven Rostedt <[email protected]>
LKML-Reference: <[email protected]>
[ v3: fixed minor stylistic detail ]
Signed-off-by: Ingo Molnar <[email protected]>

:040000 040000 8650752c9d8295e3c0ae3999b237fb86eb269e5d eb3ecfba6bfbcc80ecde51e10307fefc4d43864e M tools
[acme@mica linux-2.6-tip]$

(gdb) run sched latency
Starting program: /root/bin/perf sched latency
[Thread debugging using libthread_db enabled]
[Detaching after fork from child process 30314. (Try `set detach-on-fork off'.)]
[New Thread 139670509008608 (LWP 30311)]

Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 139670509008608 (LWP 30311)]
0x000000000040df1b in process_sched_switch_event (data=0x7f079312f9fc, session=0xcaf780, event=0xcaff50, this_cpu=3, timestamp=3964393249899, thread=0xd21ea0) at builtin-sched.c:1489
1489 FILL_ARRAY(switch_event, prev_comm, event, data);
(gdb) bt
#0 0x000000000040df1b in process_sched_switch_event (data=0x7f079312f9fc, session=0xcaf780, event=0xcaff50, this_cpu=3, timestamp=3964393249899, thread=0xd21ea0) at builtin-sched.c:1489
#1 0x000000000040e508 in process_raw_event (raw_event=0x7f079312f9d0, session=0xcaf780, data=0x7f079312f9fc, cpu=3, timestamp=3964393249899, thread=0xd21ea0) at builtin-sched.c:1594
#2 0x000000000040e7ec in process_sample_event (event=0x7f079312f9d0, session=0xcaf780) at builtin-sched.c:1639
#3 0x000000000043be6f in perf_session__process_event (self=0xcaf780, event=0x7f079312f9d0, ops=0x6878e0, offset=0, head=117200) at util/session.c:298
#4 0x000000000043c5f0 in perf_session__process_events (self=0xcaf780, ops=0x6878e0) at util/session.c:464
#5 0x000000000040e8e0 in read_events () at builtin-sched.c:1667
#6 0x000000000040edb7 in __cmd_lat () at builtin-sched.c:1708
#7 0x000000000040f355 in cmd_sched (argc=1, argv=0x7fff2a064640, prefix=0x0) at builtin-sched.c:1911
#8 0x0000000000404fdd in run_builtin (p=0x682cd0, argc=2, argv=0x7fff2a064640) at perf.c:264
#9 0x00000000004051b3 in handle_internal_command (argc=2, argv=0x7fff2a064640) at perf.c:329
#10 0x00000000004052f2 in run_argv (argcp=0x7fff2a064534, argv=0x7fff2a064528) at perf.c:373
#11 0x00000000004054ce in main (argc=2, argv=0x7fff2a064640) at perf.c:457
(gdb)

2010-02-23 13:47:18

by Hitoshi Mitake

[permalink] [raw]

Subject: Re: perf sched broken on tip, bisected

On 2010年02月23日 04:09, Arnaldo Carvalho de Melo wrote:
> While testing a patch series I'm working on I noticed that 'perf sched record ;
> perf sched latency' is broken on tip, bisected it down to this cset, investigating...
>

Very sorry, Arnaldo...
I'll fix it later.

Hitoshi

2010-02-24 08:03:44

by Hitoshi Mitake

[permalink] [raw]

Subject: Re: perf sched broken on tip, bisected

On 02/23/10 04:09, Arnaldo Carvalho de Melo wrote:
> While testing a patch series I'm working on I noticed that 'perf sched record ;
> perf sched latency' is broken on tip, bisected it down to this cset, investigating...
>

I couldn't reproduce your problem on tip/master (
ae37d2288d22938bd48b552f83d3e01c41fd42f9 ),
could you give me a pointer to your testing patch series?

> [acme@mica linux-2.6-tip]$ git bisect good
> 86d8d29634de4464d568e7c335c0da6cba64e8ab is first bad commit
> commit 86d8d29634de4464d568e7c335c0da6cba64e8ab
> Author: Hitoshi Mitake<[email protected]>
> Date: Sat Jan 30 20:43:23 2010 +0900
>
> perf tools: Add __data_loc support
>
> This patch is required to test the next patch for perf lock.
>
> At 064739bc4b3d7f424b2f25547e6611bcf0132415 ,
> support for the modifier "__data_loc" of format is added.
>
> But, when I wanted to parse format of lock_acquired (or some
> event else), raw_field_ptr() did not returned correct pointer.
>
> So I modified raw_field_ptr() like this patch. Then
> raw_field_ptr() works well.
>
> Signed-off-by: Hitoshi Mitake<[email protected]>
> Acked-by: Frederic Weisbecker<[email protected]>
> Cc: Peter Zijlstra<[email protected]>
> Cc: Paul Mackerras<[email protected]>
> Cc: Tom Zanussi<[email protected]>
> Cc: Steven Rostedt<[email protected]>
> LKML-Reference:<[email protected]>
> [ v3: fixed minor stylistic detail ]
> Signed-off-by: Ingo Molnar<[email protected]>
>
> :040000 040000 8650752c9d8295e3c0ae3999b237fb86eb269e5d eb3ecfba6bfbcc80ecde51e10307fefc4d43864e M tools
> [acme@mica linux-2.6-tip]$
>
> (gdb) run sched latency
> Starting program: /root/bin/perf sched latency
> [Thread debugging using libthread_db enabled]
> [Detaching after fork from child process 30314. (Try `set detach-on-fork off'.)]
> [New Thread 139670509008608 (LWP 30311)]
>
> Program received signal SIGSEGV, Segmentation fault.
> [Switching to Thread 139670509008608 (LWP 30311)]
> 0x000000000040df1b in process_sched_switch_event (data=0x7f079312f9fc, session=0xcaf780, event=0xcaff50, this_cpu=3, timestamp=3964393249899, thread=0xd21ea0) at builtin-sched.c:1489
> 1489 FILL_ARRAY(switch_event, prev_comm, event, data);
> (gdb) bt
> #0 0x000000000040df1b in process_sched_switch_event (data=0x7f079312f9fc, session=0xcaf780, event=0xcaff50, this_cpu=3, timestamp=3964393249899, thread=0xd21ea0) at builtin-sched.c:1489
> #1 0x000000000040e508 in process_raw_event (raw_event=0x7f079312f9d0, session=0xcaf780, data=0x7f079312f9fc, cpu=3, timestamp=3964393249899, thread=0xd21ea0) at builtin-sched.c:1594
> #2 0x000000000040e7ec in process_sample_event (event=0x7f079312f9d0, session=0xcaf780) at builtin-sched.c:1639
> #3 0x000000000043be6f in perf_session__process_event (self=0xcaf780, event=0x7f079312f9d0, ops=0x6878e0, offset=0, head=117200) at util/session.c:298
> #4 0x000000000043c5f0 in perf_session__process_events (self=0xcaf780, ops=0x6878e0) at util/session.c:464
> #5 0x000000000040e8e0 in read_events () at builtin-sched.c:1667
> #6 0x000000000040edb7 in __cmd_lat () at builtin-sched.c:1708
> #7 0x000000000040f355 in cmd_sched (argc=1, argv=0x7fff2a064640, prefix=0x0) at builtin-sched.c:1911
> #8 0x0000000000404fdd in run_builtin (p=0x682cd0, argc=2, argv=0x7fff2a064640) at perf.c:264
> #9 0x00000000004051b3 in handle_internal_command (argc=2, argv=0x7fff2a064640) at perf.c:329
> #10 0x00000000004052f2 in run_argv (argcp=0x7fff2a064534, argv=0x7fff2a064528) at perf.c:373
> #11 0x00000000004054ce in main (argc=2, argv=0x7fff2a064640) at perf.c:457
> (gdb)
>

2010-02-24 08:04:46

by Hitoshi Mitake

[permalink] [raw]