* perf, kprobes: fuzzer generates huge number of WARNings
@ 2015-07-06 21:27 Vince Weaver
2015-07-06 21:29 ` Steven Rostedt
2015-07-07 2:25 ` Masami Hiramatsu
0 siblings, 2 replies; 16+ messages in thread
From: Vince Weaver @ 2015-07-06 21:27 UTC (permalink / raw)
To: linux-kernel
Cc: Ananth N Mavinakayanahalli, Anil S Keshavamurthy,
David S. Miller, Masami Hiramatsu, Peter Zijlstra, Ingo Molnar,
Arnaldo Carvalho de Melo, Steven Rostedt
Hello
I've been working on trying to get the perf_fuzzer to start fuzzing the
PERF_EVENT_IOC_SET_BPF so I've added some really hackish kprobe support.
However before I can get to the BPF testing the kprobe code generates a
constant stream of WARNINGS which make the machine more or less useless
until I stop it. I've included a small selection here.
Is this expected?
Vince
[ 3521.350839] ftrace: Failed on adding breakpoints (6056):
[ 3521.357877] ------------[ cut here ]------------
[ 3521.363007] WARNING: CPU: 1 PID: 5080 at kernel/trace/ftrace.c:1951 ftrace_bug+0x245/0x320()
[ 3521.449830] CPU: 1 PID: 5080 Comm: perf_fuzzer Not tainted 4.2.0-rc1+ #168
[ 3521.457543] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS 01/26/2014
[ 3521.465820] ffffffff81a28cf6 ffff8800cd9f7b48 ffffffff816a10a3 0000000000000000
[ 3521.474274] 0000000000000000 ffff8800cd9f7b88 ffffffff8106ec8a ffff8800cd9f7b68
[ 3521.482680] ffff880119bd7a80 ffffffff81196730 ffff880119bd7a80 00000000000017a8
[ 3521.491143] Call Trace:
[ 3521.494128] [<ffffffff816a10a3>] dump_stack+0x45/0x57
[ 3521.500016] [<ffffffff8106ec8a>] warn_slowpath_common+0x8a/0xc0
[ 3521.506810] [<ffffffff81196730>] ? vm_insert_mixed+0x40/0x40
[ 3521.513389] [<ffffffff8106ed7a>] warn_slowpath_null+0x1a/0x20
[ 3521.520025] [<ffffffff81123425>] ftrace_bug+0x245/0x320
[ 3521.526147] [<ffffffff81052d5c>] ftrace_replace_code+0x24c/0x360
[ 3521.533102] [<ffffffff81123d3c>] ftrace_modify_all_code+0x9c/0x120
[ 3521.540241] [<ffffffff81052e80>] arch_ftrace_update_code+0x10/0x20
[ 3521.547396] [<ffffffff81123e30>] ftrace_run_update_code+0x20/0x80
[ 3521.554425] [<ffffffff811244df>] ftrace_startup_enable+0x2f/0x40
[ 3521.561376] [<ffffffff811256e6>] ftrace_startup+0xd6/0x230
[ 3521.567772] [<ffffffff81125c24>] register_ftrace_function+0x54/0x70
[ 3521.575025] [<ffffffff8113df07>] perf_ftrace_event_register+0x47/0x140
[ 3521.582537] [<ffffffff8113dba4>] perf_trace_init+0xc4/0x2c0
[ 3521.589050] [<ffffffff81152e8a>] perf_tp_event_init+0x2a/0x50
[ 3521.595771] [<ffffffff8115448b>] perf_try_init_event+0x8b/0xa0
[ 3521.602572] [<ffffffff8115bf63>] perf_init_event+0x133/0x160
[ 3521.609181] [<ffffffff8115be30>] ? perf_bp_event+0x90/0x90
[ 3521.615647] [<ffffffff8115c3ba>] perf_event_alloc+0x42a/0x680
[ 3521.622388] [<ffffffff8115c9d7>] SYSC_perf_event_open+0x3c7/0xd20
[ 3521.629487] [<ffffffff8105f86b>] ? __do_page_fault+0x1ab/0x3f0
[ 3521.636320] [<ffffffff8115d7a9>] SyS_perf_event_open+0x9/0x10
[ 3521.643087] [<ffffffff816a8df2>] entry_SYSCALL_64_fastpath+0x16/0x7a
[ 3521.650521] ---[ end trace a413501925547ed5 ]---
[ 3521.655960] ftrace failed to modify [<ffffffff81196730>] handle_mm_fault+0x0/0x1750
[ 3521.664767] actual: e8:cb:18:ef:1e
[ 3521.669202] ftrace record flags: ec000002
[ 3521.673993] (2) R tramp: 0xffffffffa0090000 expected tramp: ffffffffa0090000
[ 3521.834024] ------------[ cut here ]------------
[ 3521.839442] WARNING: CPU: 2 PID: 5177 at kernel/kprobes.c:955 disarm_kprobe+0xf8/0x100()
[ 3521.848577] Failed to init kprobe-ftrace (-19)
[ 3521.931384] CPU: 2 PID: 5177 Comm: perf_fuzzer Tainted: G W 4.2.0-rc1+ #168
[ 3521.940498] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS 01/26/2014
[ 3521.948854] ffffffff81a28976 ffff8800bf6d7a48 ffffffff816a10a3 0000000000000000
[ 3521.957335] ffff8800bf6d7a98 ffff8800bf6d7a88 ffffffff8106ec8a ffffffff81124f6a
[ 3521.965839] ffff8800cd4e2010 ffff8800cd4e2010 ffff8800cd4e2000 ffff8800cd28a000
[ 3521.974275] Call Trace:
[ 3521.977335] [<ffffffff816a10a3>] dump_stack+0x45/0x57
[ 3521.983302] [<ffffffff8106ec8a>] warn_slowpath_common+0x8a/0xc0
[ 3521.990170] [<ffffffff81124f6a>] ? unregister_ftrace_function+0x1a/0x50
[ 3521.997784] [<ffffffff8106ed06>] warn_slowpath_fmt+0x46/0x50
[ 3522.004418] [<ffffffff816a693e>] ? mutex_unlock+0xe/0x10
[ 3522.010640] [<ffffffff81119208>] disarm_kprobe+0xf8/0x100
[ 3522.016972] [<ffffffff811192a9>] __disable_kprobe+0x99/0xc0
[ 3522.023491] [<ffffffff811192f7>] disable_kprobe+0x27/0x50
[ 3522.029827] [<ffffffff81142863>] disable_trace_kprobe+0xc3/0xf0
[ 3522.036708] [<ffffffff8114345d>] kprobe_register+0x2d/0xe0
[ 3522.043102] [<ffffffff8113da83>] perf_trace_event_unreg.isra.1+0x33/0x90
[ 3522.050808] [<ffffffff8113dddc>] perf_trace_destroy+0x3c/0x50
[ 3522.057482] [<ffffffff81152eb9>] tp_perf_event_destroy+0x9/0x10
[ 3522.064354] [<ffffffff81158fc1>] _free_event+0xc1/0x250
[ 3522.070474] [<ffffffff8115917b>] ? put_event+0x2b/0x150
[ 3522.076625] [<ffffffff811592ef>] free_event+0x1f/0x50
[ 3522.082531] [<ffffffff8115d9f5>] perf_event_exit_task+0x245/0x300
[ 3522.089575] [<ffffffff81071622>] do_exit+0x3b2/0xa90
[ 3522.095444] [<ffffffff8107d182>] ? get_signal+0xe2/0x720
[ 3522.101659] [<ffffffff81071da4>] do_group_exit+0x54/0xe0
[ 3522.107892] [<ffffffff8107d320>] get_signal+0x280/0x720
[ 3522.114046] [<ffffffff81013478>] do_signal+0x28/0xb50
[ 3522.119984] [<ffffffff810b78f6>] ? __lock_acquire.isra.31+0x3a6/0xf90
[ 3522.127411] [<ffffffff810815a5>] ? sys_getppid+0x5/0x80
[ 3522.133563] [<ffffffff81014002>] do_notify_resume+0x62/0x70
[ 3522.140084] [<ffffffff816a9ade>] retint_signal+0x44/0x86
[ 3522.146349] ---[ end trace a413501925547ed6 ]---
[ 3522.157157] WARNING: CPU: 2 PID: 5177 at kernel/kprobes.c:959 disarm_kprobe+0xca/0x100()
[ 3522.166266] Failed to disarm kprobe-ftrace at ffffffff81196730 (-19)
[ 3522.251364] CPU: 2 PID: 5177 Comm: perf_fuzzer Tainted: G W 4.2.0-rc1+ #168
[ 3522.260488] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS 01/26/2014
[ 3522.268953] ffffffff81a28976 ffff8800bf6d7a48 ffffffff816a10a3 0000000000000000
[ 3522.277482] ffff8800bf6d7a98 ffff8800bf6d7a88 ffffffff8106ec8a ffffffff81124f6a
[ 3522.285993] ffff8800cd4e2010 ffff8800cd4e2010 ffff8800cd4e2000 ffff8800cd28a000
[ 3522.294520] Call Trace:
[ 3522.297594] [<ffffffff816a10a3>] dump_stack+0x45/0x57
[ 3522.303535] [<ffffffff8106ec8a>] warn_slowpath_common+0x8a/0xc0
[ 3522.310379] [<ffffffff81124f6a>] ? unregister_ftrace_function+0x1a/0x50
[ 3522.318026] [<ffffffff8106ed06>] warn_slowpath_fmt+0x46/0x50
[ 3522.324637] [<ffffffff816a693e>] ? mutex_unlock+0xe/0x10
[ 3522.330859] [<ffffffff81196730>] ? vm_insert_mixed+0x40/0x40
[ 3522.337459] [<ffffffff811191da>] disarm_kprobe+0xca/0x100
[ 3522.343792] [<ffffffff811192a9>] __disable_kprobe+0x99/0xc0
[ 3522.350304] [<ffffffff811192f7>] disable_kprobe+0x27/0x50
[ 3522.356692] [<ffffffff81142863>] disable_trace_kprobe+0xc3/0xf0
[ 3522.363510] [<ffffffff8114345d>] kprobe_register+0x2d/0xe0
[ 3522.369907] [<ffffffff8113da83>] perf_trace_event_unreg.isra.1+0x33/0x90
[ 3522.377620] [<ffffffff8113dddc>] perf_trace_destroy+0x3c/0x50
[ 3522.384337] [<ffffffff81152eb9>] tp_perf_event_destroy+0x9/0x10
[ 3522.391215] [<ffffffff81158fc1>] _free_event+0xc1/0x250
[ 3522.397348] [<ffffffff8115917b>] ? put_event+0x2b/0x150
[ 3522.403478] [<ffffffff811592ef>] free_event+0x1f/0x50
[ 3522.409443] [<ffffffff8115d9f5>] perf_event_exit_task+0x245/0x300
[ 3522.416466] [<ffffffff81071622>] do_exit+0x3b2/0xa90
[ 3522.422351] [<ffffffff8107d182>] ? get_signal+0xe2/0x720
[ 3522.428555] [<ffffffff81071da4>] do_group_exit+0x54/0xe0
[ 3522.434803] [<ffffffff8107d320>] get_signal+0x280/0x720
[ 3522.440974] [<ffffffff81013478>] do_signal+0x28/0xb50
[ 3522.446949] [<ffffffff810b78f6>] ? __lock_acquire.isra.31+0x3a6/0xf90
[ 3522.454420] [<ffffffff810815a5>] ? sys_getppid+0x5/0x80
[ 3522.460592] [<ffffffff81014002>] do_notify_resume+0x62/0x70
[ 3522.467079] [<ffffffff816a9ade>] retint_signal+0x44/0x86
[ 3522.473343] ---[ end trace a413501925547ed7 ]---
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: perf, kprobes: fuzzer generates huge number of WARNings
2015-07-06 21:27 perf, kprobes: fuzzer generates huge number of WARNings Vince Weaver
@ 2015-07-06 21:29 ` Steven Rostedt
2015-07-07 3:53 ` Vince Weaver
2015-07-07 2:25 ` Masami Hiramatsu
1 sibling, 1 reply; 16+ messages in thread
From: Steven Rostedt @ 2015-07-06 21:29 UTC (permalink / raw)
To: Vince Weaver
Cc: linux-kernel, Ananth N Mavinakayanahalli, Anil S Keshavamurthy,
David S. Miller, Masami Hiramatsu, Peter Zijlstra, Ingo Molnar,
Arnaldo Carvalho de Melo
On Mon, 6 Jul 2015 17:27:04 -0400 (EDT)
Vince Weaver <vincent.weaver@maine.edu> wrote:
> Hello
>
> I've been working on trying to get the perf_fuzzer to start fuzzing the
> PERF_EVENT_IOC_SET_BPF so I've added some really hackish kprobe support.
>
> However before I can get to the BPF testing the kprobe code generates a
> constant stream of WARNINGS which make the machine more or less useless
> until I stop it. I've included a small selection here.
>
> Is this expected?
>
> Vince
>
>
> [ 3521.350839] ftrace: Failed on adding breakpoints (6056):
> [ 3521.357877] ------------[ cut here ]------------
> [ 3521.363007] WARNING: CPU: 1 PID: 5080 at kernel/trace/ftrace.c:1951 ftrace_bug+0x245/0x320()
> [ 3521.449830] CPU: 1 PID: 5080 Comm: perf_fuzzer Not tainted 4.2.0-rc1+ #168
> [ 3521.457543] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS 01/26/2014
> [ 3521.465820] ffffffff81a28cf6 ffff8800cd9f7b48 ffffffff816a10a3 0000000000000000
> [ 3521.474274] 0000000000000000 ffff8800cd9f7b88 ffffffff8106ec8a ffff8800cd9f7b68
> [ 3521.482680] ffff880119bd7a80 ffffffff81196730 ffff880119bd7a80 00000000000017a8
> [ 3521.491143] Call Trace:
> [ 3521.494128] [<ffffffff816a10a3>] dump_stack+0x45/0x57
> [ 3521.500016] [<ffffffff8106ec8a>] warn_slowpath_common+0x8a/0xc0
> [ 3521.506810] [<ffffffff81196730>] ? vm_insert_mixed+0x40/0x40
> [ 3521.513389] [<ffffffff8106ed7a>] warn_slowpath_null+0x1a/0x20
> [ 3521.520025] [<ffffffff81123425>] ftrace_bug+0x245/0x320
> [ 3521.526147] [<ffffffff81052d5c>] ftrace_replace_code+0x24c/0x360
> [ 3521.533102] [<ffffffff81123d3c>] ftrace_modify_all_code+0x9c/0x120
> [ 3521.540241] [<ffffffff81052e80>] arch_ftrace_update_code+0x10/0x20
> [ 3521.547396] [<ffffffff81123e30>] ftrace_run_update_code+0x20/0x80
> [ 3521.554425] [<ffffffff811244df>] ftrace_startup_enable+0x2f/0x40
> [ 3521.561376] [<ffffffff811256e6>] ftrace_startup+0xd6/0x230
> [ 3521.567772] [<ffffffff81125c24>] register_ftrace_function+0x54/0x70
> [ 3521.575025] [<ffffffff8113df07>] perf_ftrace_event_register+0x47/0x140
> [ 3521.582537] [<ffffffff8113dba4>] perf_trace_init+0xc4/0x2c0
> [ 3521.589050] [<ffffffff81152e8a>] perf_tp_event_init+0x2a/0x50
> [ 3521.595771] [<ffffffff8115448b>] perf_try_init_event+0x8b/0xa0
> [ 3521.602572] [<ffffffff8115bf63>] perf_init_event+0x133/0x160
> [ 3521.609181] [<ffffffff8115be30>] ? perf_bp_event+0x90/0x90
> [ 3521.615647] [<ffffffff8115c3ba>] perf_event_alloc+0x42a/0x680
> [ 3521.622388] [<ffffffff8115c9d7>] SYSC_perf_event_open+0x3c7/0xd20
> [ 3521.629487] [<ffffffff8105f86b>] ? __do_page_fault+0x1ab/0x3f0
> [ 3521.636320] [<ffffffff8115d7a9>] SyS_perf_event_open+0x9/0x10
> [ 3521.643087] [<ffffffff816a8df2>] entry_SYSCALL_64_fastpath+0x16/0x7a
> [ 3521.650521] ---[ end trace a413501925547ed5 ]---
> [ 3521.655960] ftrace failed to modify [<ffffffff81196730>] handle_mm_fault+0x0/0x1750
> [ 3521.664767] actual: e8:cb:18:ef:1e
Hmm, it was not expecting to see this address above in the mcount slot.
Did you have other tracing going on, or did you add a kprobe to
handle_mm_fault too?
-- Steve
> [ 3521.669202] ftrace record flags: ec000002
> [ 3521.673993] (2) R tramp: 0xffffffffa0090000 expected tramp: ffffffffa0090000
>
>
> [ 3521.834024] ------------[ cut here ]------------
> [ 3521.839442] WARNING: CPU: 2 PID: 5177 at kernel/kprobes.c:955 disarm_kprobe+0xf8/0x100()
> [ 3521.848577] Failed to init kprobe-ftrace (-19)
> [ 3521.931384] CPU: 2 PID: 5177 Comm: perf_fuzzer Tainted: G W 4.2.0-rc1+ #168
> [ 3521.940498] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS 01/26/2014
> [ 3521.948854] ffffffff81a28976 ffff8800bf6d7a48 ffffffff816a10a3 0000000000000000
> [ 3521.957335] ffff8800bf6d7a98 ffff8800bf6d7a88 ffffffff8106ec8a ffffffff81124f6a
> [ 3521.965839] ffff8800cd4e2010 ffff8800cd4e2010 ffff8800cd4e2000 ffff8800cd28a000
> [ 3521.974275] Call Trace:
> [ 3521.977335] [<ffffffff816a10a3>] dump_stack+0x45/0x57
> [ 3521.983302] [<ffffffff8106ec8a>] warn_slowpath_common+0x8a/0xc0
> [ 3521.990170] [<ffffffff81124f6a>] ? unregister_ftrace_function+0x1a/0x50
> [ 3521.997784] [<ffffffff8106ed06>] warn_slowpath_fmt+0x46/0x50
> [ 3522.004418] [<ffffffff816a693e>] ? mutex_unlock+0xe/0x10
> [ 3522.010640] [<ffffffff81119208>] disarm_kprobe+0xf8/0x100
> [ 3522.016972] [<ffffffff811192a9>] __disable_kprobe+0x99/0xc0
> [ 3522.023491] [<ffffffff811192f7>] disable_kprobe+0x27/0x50
> [ 3522.029827] [<ffffffff81142863>] disable_trace_kprobe+0xc3/0xf0
> [ 3522.036708] [<ffffffff8114345d>] kprobe_register+0x2d/0xe0
> [ 3522.043102] [<ffffffff8113da83>] perf_trace_event_unreg.isra.1+0x33/0x90
> [ 3522.050808] [<ffffffff8113dddc>] perf_trace_destroy+0x3c/0x50
> [ 3522.057482] [<ffffffff81152eb9>] tp_perf_event_destroy+0x9/0x10
> [ 3522.064354] [<ffffffff81158fc1>] _free_event+0xc1/0x250
> [ 3522.070474] [<ffffffff8115917b>] ? put_event+0x2b/0x150
> [ 3522.076625] [<ffffffff811592ef>] free_event+0x1f/0x50
> [ 3522.082531] [<ffffffff8115d9f5>] perf_event_exit_task+0x245/0x300
> [ 3522.089575] [<ffffffff81071622>] do_exit+0x3b2/0xa90
> [ 3522.095444] [<ffffffff8107d182>] ? get_signal+0xe2/0x720
> [ 3522.101659] [<ffffffff81071da4>] do_group_exit+0x54/0xe0
> [ 3522.107892] [<ffffffff8107d320>] get_signal+0x280/0x720
> [ 3522.114046] [<ffffffff81013478>] do_signal+0x28/0xb50
> [ 3522.119984] [<ffffffff810b78f6>] ? __lock_acquire.isra.31+0x3a6/0xf90
> [ 3522.127411] [<ffffffff810815a5>] ? sys_getppid+0x5/0x80
> [ 3522.133563] [<ffffffff81014002>] do_notify_resume+0x62/0x70
> [ 3522.140084] [<ffffffff816a9ade>] retint_signal+0x44/0x86
> [ 3522.146349] ---[ end trace a413501925547ed6 ]---
>
>
>
> [ 3522.157157] WARNING: CPU: 2 PID: 5177 at kernel/kprobes.c:959 disarm_kprobe+0xca/0x100()
> [ 3522.166266] Failed to disarm kprobe-ftrace at ffffffff81196730 (-19)
> [ 3522.251364] CPU: 2 PID: 5177 Comm: perf_fuzzer Tainted: G W 4.2.0-rc1+ #168
> [ 3522.260488] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS 01/26/2014
> [ 3522.268953] ffffffff81a28976 ffff8800bf6d7a48 ffffffff816a10a3 0000000000000000
> [ 3522.277482] ffff8800bf6d7a98 ffff8800bf6d7a88 ffffffff8106ec8a ffffffff81124f6a
> [ 3522.285993] ffff8800cd4e2010 ffff8800cd4e2010 ffff8800cd4e2000 ffff8800cd28a000
> [ 3522.294520] Call Trace:
> [ 3522.297594] [<ffffffff816a10a3>] dump_stack+0x45/0x57
> [ 3522.303535] [<ffffffff8106ec8a>] warn_slowpath_common+0x8a/0xc0
> [ 3522.310379] [<ffffffff81124f6a>] ? unregister_ftrace_function+0x1a/0x50
> [ 3522.318026] [<ffffffff8106ed06>] warn_slowpath_fmt+0x46/0x50
> [ 3522.324637] [<ffffffff816a693e>] ? mutex_unlock+0xe/0x10
> [ 3522.330859] [<ffffffff81196730>] ? vm_insert_mixed+0x40/0x40
> [ 3522.337459] [<ffffffff811191da>] disarm_kprobe+0xca/0x100
> [ 3522.343792] [<ffffffff811192a9>] __disable_kprobe+0x99/0xc0
> [ 3522.350304] [<ffffffff811192f7>] disable_kprobe+0x27/0x50
> [ 3522.356692] [<ffffffff81142863>] disable_trace_kprobe+0xc3/0xf0
> [ 3522.363510] [<ffffffff8114345d>] kprobe_register+0x2d/0xe0
> [ 3522.369907] [<ffffffff8113da83>] perf_trace_event_unreg.isra.1+0x33/0x90
> [ 3522.377620] [<ffffffff8113dddc>] perf_trace_destroy+0x3c/0x50
> [ 3522.384337] [<ffffffff81152eb9>] tp_perf_event_destroy+0x9/0x10
> [ 3522.391215] [<ffffffff81158fc1>] _free_event+0xc1/0x250
> [ 3522.397348] [<ffffffff8115917b>] ? put_event+0x2b/0x150
> [ 3522.403478] [<ffffffff811592ef>] free_event+0x1f/0x50
> [ 3522.409443] [<ffffffff8115d9f5>] perf_event_exit_task+0x245/0x300
> [ 3522.416466] [<ffffffff81071622>] do_exit+0x3b2/0xa90
> [ 3522.422351] [<ffffffff8107d182>] ? get_signal+0xe2/0x720
> [ 3522.428555] [<ffffffff81071da4>] do_group_exit+0x54/0xe0
> [ 3522.434803] [<ffffffff8107d320>] get_signal+0x280/0x720
> [ 3522.440974] [<ffffffff81013478>] do_signal+0x28/0xb50
> [ 3522.446949] [<ffffffff810b78f6>] ? __lock_acquire.isra.31+0x3a6/0xf90
> [ 3522.454420] [<ffffffff810815a5>] ? sys_getppid+0x5/0x80
> [ 3522.460592] [<ffffffff81014002>] do_notify_resume+0x62/0x70
> [ 3522.467079] [<ffffffff816a9ade>] retint_signal+0x44/0x86
> [ 3522.473343] ---[ end trace a413501925547ed7 ]---
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: perf, kprobes: fuzzer generates huge number of WARNings
2015-07-06 21:27 perf, kprobes: fuzzer generates huge number of WARNings Vince Weaver
2015-07-06 21:29 ` Steven Rostedt
@ 2015-07-07 2:25 ` Masami Hiramatsu
2015-07-07 4:00 ` Vince Weaver
1 sibling, 1 reply; 16+ messages in thread
From: Masami Hiramatsu @ 2015-07-07 2:25 UTC (permalink / raw)
To: Vince Weaver, linux-kernel
Cc: Ananth N Mavinakayanahalli, Anil S Keshavamurthy,
David S. Miller, Peter Zijlstra, Ingo Molnar,
Arnaldo Carvalho de Melo, Steven Rostedt
On 2015/07/07 6:27, Vince Weaver wrote:
> Hello
>
> I've been working on trying to get the perf_fuzzer to start fuzzing the
> PERF_EVENT_IOC_SET_BPF so I've added some really hackish kprobe support.
>
> However before I can get to the BPF testing the kprobe code generates a
> constant stream of WARNINGS which make the machine more or less useless
> until I stop it. I've included a small selection here.
>
> Is this expected?
Did you get same message without BPF hack? And also, could you tell us
your kernel version and configuration?
>
> Vince
>
>
> [ 3521.350839] ftrace: Failed on adding breakpoints (6056):
> [ 3521.357877] ------------[ cut here ]------------
> [ 3521.363007] WARNING: CPU: 1 PID: 5080 at kernel/trace/ftrace.c:1951 ftrace_bug+0x245/0x320()
> [ 3521.449830] CPU: 1 PID: 5080 Comm: perf_fuzzer Not tainted 4.2.0-rc1+ #168
> [ 3521.457543] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS 01/26/2014
> [ 3521.465820] ffffffff81a28cf6 ffff8800cd9f7b48 ffffffff816a10a3 0000000000000000
> [ 3521.474274] 0000000000000000 ffff8800cd9f7b88 ffffffff8106ec8a ffff8800cd9f7b68
> [ 3521.482680] ffff880119bd7a80 ffffffff81196730 ffff880119bd7a80 00000000000017a8
> [ 3521.491143] Call Trace:
> [ 3521.494128] [<ffffffff816a10a3>] dump_stack+0x45/0x57
> [ 3521.500016] [<ffffffff8106ec8a>] warn_slowpath_common+0x8a/0xc0
> [ 3521.506810] [<ffffffff81196730>] ? vm_insert_mixed+0x40/0x40
> [ 3521.513389] [<ffffffff8106ed7a>] warn_slowpath_null+0x1a/0x20
> [ 3521.520025] [<ffffffff81123425>] ftrace_bug+0x245/0x320
> [ 3521.526147] [<ffffffff81052d5c>] ftrace_replace_code+0x24c/0x360
> [ 3521.533102] [<ffffffff81123d3c>] ftrace_modify_all_code+0x9c/0x120
> [ 3521.540241] [<ffffffff81052e80>] arch_ftrace_update_code+0x10/0x20
> [ 3521.547396] [<ffffffff81123e30>] ftrace_run_update_code+0x20/0x80
> [ 3521.554425] [<ffffffff811244df>] ftrace_startup_enable+0x2f/0x40
> [ 3521.561376] [<ffffffff811256e6>] ftrace_startup+0xd6/0x230
> [ 3521.567772] [<ffffffff81125c24>] register_ftrace_function+0x54/0x70
> [ 3521.575025] [<ffffffff8113df07>] perf_ftrace_event_register+0x47/0x140
> [ 3521.582537] [<ffffffff8113dba4>] perf_trace_init+0xc4/0x2c0
> [ 3521.589050] [<ffffffff81152e8a>] perf_tp_event_init+0x2a/0x50
> [ 3521.595771] [<ffffffff8115448b>] perf_try_init_event+0x8b/0xa0
> [ 3521.602572] [<ffffffff8115bf63>] perf_init_event+0x133/0x160
> [ 3521.609181] [<ffffffff8115be30>] ? perf_bp_event+0x90/0x90
> [ 3521.615647] [<ffffffff8115c3ba>] perf_event_alloc+0x42a/0x680
> [ 3521.622388] [<ffffffff8115c9d7>] SYSC_perf_event_open+0x3c7/0xd20
> [ 3521.629487] [<ffffffff8105f86b>] ? __do_page_fault+0x1ab/0x3f0
> [ 3521.636320] [<ffffffff8115d7a9>] SyS_perf_event_open+0x9/0x10
> [ 3521.643087] [<ffffffff816a8df2>] entry_SYSCALL_64_fastpath+0x16/0x7a
> [ 3521.650521] ---[ end trace a413501925547ed5 ]---
> [ 3521.655960] ftrace failed to modify [<ffffffff81196730>] handle_mm_fault+0x0/0x1750
> [ 3521.664767] actual: e8:cb:18:ef:1e
Hmm, this seems to happen when disarming kprobes from handle_mm_fault+0.
However, with this easy test, I couldn't reproduce it on the latest tip/master.
[root@localhost tracing]# echo p handle_mm_fault > kprobe_events
[root@localhost tracing]# echo 1 > events/kprobes/p_handle_mm_fault_0/enable
[root@localhost tracing]# echo 0 > events/kprobes/p_handle_mm_fault_0/enable
We'd better know how to reproduce this issue.
Thank you,
> [ 3521.669202] ftrace record flags: ec000002
> [ 3521.673993] (2) R tramp: 0xffffffffa0090000 expected tramp: ffffffffa0090000
>
>
> [ 3521.834024] ------------[ cut here ]------------
> [ 3521.839442] WARNING: CPU: 2 PID: 5177 at kernel/kprobes.c:955 disarm_kprobe+0xf8/0x100()
> [ 3521.848577] Failed to init kprobe-ftrace (-19)
> [ 3521.931384] CPU: 2 PID: 5177 Comm: perf_fuzzer Tainted: G W 4.2.0-rc1+ #168
> [ 3521.940498] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS 01/26/2014
> [ 3521.948854] ffffffff81a28976 ffff8800bf6d7a48 ffffffff816a10a3 0000000000000000
> [ 3521.957335] ffff8800bf6d7a98 ffff8800bf6d7a88 ffffffff8106ec8a ffffffff81124f6a
> [ 3521.965839] ffff8800cd4e2010 ffff8800cd4e2010 ffff8800cd4e2000 ffff8800cd28a000
> [ 3521.974275] Call Trace:
> [ 3521.977335] [<ffffffff816a10a3>] dump_stack+0x45/0x57
> [ 3521.983302] [<ffffffff8106ec8a>] warn_slowpath_common+0x8a/0xc0
> [ 3521.990170] [<ffffffff81124f6a>] ? unregister_ftrace_function+0x1a/0x50
> [ 3521.997784] [<ffffffff8106ed06>] warn_slowpath_fmt+0x46/0x50
> [ 3522.004418] [<ffffffff816a693e>] ? mutex_unlock+0xe/0x10
> [ 3522.010640] [<ffffffff81119208>] disarm_kprobe+0xf8/0x100
> [ 3522.016972] [<ffffffff811192a9>] __disable_kprobe+0x99/0xc0
> [ 3522.023491] [<ffffffff811192f7>] disable_kprobe+0x27/0x50
> [ 3522.029827] [<ffffffff81142863>] disable_trace_kprobe+0xc3/0xf0
> [ 3522.036708] [<ffffffff8114345d>] kprobe_register+0x2d/0xe0
> [ 3522.043102] [<ffffffff8113da83>] perf_trace_event_unreg.isra.1+0x33/0x90
> [ 3522.050808] [<ffffffff8113dddc>] perf_trace_destroy+0x3c/0x50
> [ 3522.057482] [<ffffffff81152eb9>] tp_perf_event_destroy+0x9/0x10
> [ 3522.064354] [<ffffffff81158fc1>] _free_event+0xc1/0x250
> [ 3522.070474] [<ffffffff8115917b>] ? put_event+0x2b/0x150
> [ 3522.076625] [<ffffffff811592ef>] free_event+0x1f/0x50
> [ 3522.082531] [<ffffffff8115d9f5>] perf_event_exit_task+0x245/0x300
> [ 3522.089575] [<ffffffff81071622>] do_exit+0x3b2/0xa90
> [ 3522.095444] [<ffffffff8107d182>] ? get_signal+0xe2/0x720
> [ 3522.101659] [<ffffffff81071da4>] do_group_exit+0x54/0xe0
> [ 3522.107892] [<ffffffff8107d320>] get_signal+0x280/0x720
> [ 3522.114046] [<ffffffff81013478>] do_signal+0x28/0xb50
> [ 3522.119984] [<ffffffff810b78f6>] ? __lock_acquire.isra.31+0x3a6/0xf90
> [ 3522.127411] [<ffffffff810815a5>] ? sys_getppid+0x5/0x80
> [ 3522.133563] [<ffffffff81014002>] do_notify_resume+0x62/0x70
> [ 3522.140084] [<ffffffff816a9ade>] retint_signal+0x44/0x86
> [ 3522.146349] ---[ end trace a413501925547ed6 ]---
>
>
>
> [ 3522.157157] WARNING: CPU: 2 PID: 5177 at kernel/kprobes.c:959 disarm_kprobe+0xca/0x100()
> [ 3522.166266] Failed to disarm kprobe-ftrace at ffffffff81196730 (-19)
> [ 3522.251364] CPU: 2 PID: 5177 Comm: perf_fuzzer Tainted: G W 4.2.0-rc1+ #168
> [ 3522.260488] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS 01/26/2014
> [ 3522.268953] ffffffff81a28976 ffff8800bf6d7a48 ffffffff816a10a3 0000000000000000
> [ 3522.277482] ffff8800bf6d7a98 ffff8800bf6d7a88 ffffffff8106ec8a ffffffff81124f6a
> [ 3522.285993] ffff8800cd4e2010 ffff8800cd4e2010 ffff8800cd4e2000 ffff8800cd28a000
> [ 3522.294520] Call Trace:
> [ 3522.297594] [<ffffffff816a10a3>] dump_stack+0x45/0x57
> [ 3522.303535] [<ffffffff8106ec8a>] warn_slowpath_common+0x8a/0xc0
> [ 3522.310379] [<ffffffff81124f6a>] ? unregister_ftrace_function+0x1a/0x50
> [ 3522.318026] [<ffffffff8106ed06>] warn_slowpath_fmt+0x46/0x50
> [ 3522.324637] [<ffffffff816a693e>] ? mutex_unlock+0xe/0x10
> [ 3522.330859] [<ffffffff81196730>] ? vm_insert_mixed+0x40/0x40
> [ 3522.337459] [<ffffffff811191da>] disarm_kprobe+0xca/0x100
> [ 3522.343792] [<ffffffff811192a9>] __disable_kprobe+0x99/0xc0
> [ 3522.350304] [<ffffffff811192f7>] disable_kprobe+0x27/0x50
> [ 3522.356692] [<ffffffff81142863>] disable_trace_kprobe+0xc3/0xf0
> [ 3522.363510] [<ffffffff8114345d>] kprobe_register+0x2d/0xe0
> [ 3522.369907] [<ffffffff8113da83>] perf_trace_event_unreg.isra.1+0x33/0x90
> [ 3522.377620] [<ffffffff8113dddc>] perf_trace_destroy+0x3c/0x50
> [ 3522.384337] [<ffffffff81152eb9>] tp_perf_event_destroy+0x9/0x10
> [ 3522.391215] [<ffffffff81158fc1>] _free_event+0xc1/0x250
> [ 3522.397348] [<ffffffff8115917b>] ? put_event+0x2b/0x150
> [ 3522.403478] [<ffffffff811592ef>] free_event+0x1f/0x50
> [ 3522.409443] [<ffffffff8115d9f5>] perf_event_exit_task+0x245/0x300
> [ 3522.416466] [<ffffffff81071622>] do_exit+0x3b2/0xa90
> [ 3522.422351] [<ffffffff8107d182>] ? get_signal+0xe2/0x720
> [ 3522.428555] [<ffffffff81071da4>] do_group_exit+0x54/0xe0
> [ 3522.434803] [<ffffffff8107d320>] get_signal+0x280/0x720
> [ 3522.440974] [<ffffffff81013478>] do_signal+0x28/0xb50
> [ 3522.446949] [<ffffffff810b78f6>] ? __lock_acquire.isra.31+0x3a6/0xf90
> [ 3522.454420] [<ffffffff810815a5>] ? sys_getppid+0x5/0x80
> [ 3522.460592] [<ffffffff81014002>] do_notify_resume+0x62/0x70
> [ 3522.467079] [<ffffffff816a9ade>] retint_signal+0x44/0x86
> [ 3522.473343] ---[ end trace a413501925547ed7 ]---
>
> --
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at http://www.tux.org/lkml/
>
--
Masami HIRAMATSU
Linux Technology Research Center, System Productivity Research Dept.
Center for Technology Innovation - Systems Engineering
Hitachi, Ltd., Research & Development Group
E-mail: masami.hiramatsu.pt@hitachi.com
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: perf, kprobes: fuzzer generates huge number of WARNings
2015-07-06 21:29 ` Steven Rostedt
@ 2015-07-07 3:53 ` Vince Weaver
0 siblings, 0 replies; 16+ messages in thread
From: Vince Weaver @ 2015-07-07 3:53 UTC (permalink / raw)
To: Steven Rostedt
Cc: Vince Weaver, linux-kernel, Ananth N Mavinakayanahalli,
Anil S Keshavamurthy, David S. Miller, Masami Hiramatsu,
Peter Zijlstra, Ingo Molnar, Arnaldo Carvalho de Melo
On Mon, 6 Jul 2015, Steven Rostedt wrote:
> On Mon, 6 Jul 2015 17:27:04 -0400 (EDT)
> Vince Weaver <vincent.weaver@maine.edu> wrote:
> > [ 3521.650521] ---[ end trace a413501925547ed5 ]---
> > [ 3521.655960] ftrace failed to modify [<ffffffff81196730>] handle_mm_fault+0x0/0x1750
> > [ 3521.664767] actual: e8:cb:18:ef:1e
>
> Hmm, it was not expecting to see this address above in the mcount slot.
> Did you have other tracing going on, or did you add a kprobe to
> handle_mm_fault too?
it's fuzzing so there were potentially a large number of tracepoint events
active at the time. Only one kprobe event,
p:probe/VMW _text+1664816
and I forget what that actually mapped to originally.
Vince
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: perf, kprobes: fuzzer generates huge number of WARNings
2015-07-07 2:25 ` Masami Hiramatsu
@ 2015-07-07 4:00 ` Vince Weaver
2015-07-07 10:35 ` Masami Hiramatsu
2015-07-07 19:18 ` Alexei Starovoitov
0 siblings, 2 replies; 16+ messages in thread
From: Vince Weaver @ 2015-07-07 4:00 UTC (permalink / raw)
To: Masami Hiramatsu
Cc: Vince Weaver, linux-kernel, Ananth N Mavinakayanahalli,
Anil S Keshavamurthy, David S. Miller, Peter Zijlstra,
Ingo Molnar, Arnaldo Carvalho de Melo, Steven Rostedt
On Tue, 7 Jul 2015, Masami Hiramatsu wrote:
> On 2015/07/07 6:27, Vince Weaver wrote:
> > Hello
> >
> > I've been working on trying to get the perf_fuzzer to start fuzzing the
> > PERF_EVENT_IOC_SET_BPF so I've added some really hackish kprobe support.
> >
> > However before I can get to the BPF testing the kprobe code generates a
> > constant stream of WARNINGS which make the machine more or less useless
> > until I stop it. I've included a small selection here.
> >
> > Is this expected?
>
> Did you get same message without BPF hack? And also, could you tell us
> your kernel version and configuration?
It's a Hawell machine running 4.2-rc1. I can post the .config if it's of
interest.
Well the BPF hack is in the fuzzer, not the kernel. And it's not really a
hack, it just turned out to be a huge pain to figure out how to
manually create a valid BPF program in conjunction with a valid kprobe
event.
I did have to sprinkle printks in the kprobe and bpf code to find out
where various EINVAL returns were coming from, so potentially this is just
a problem of printks happening where they shouldn't. I'll remove those
changes and try to reproduce this tomorrow.
This is possibly a long standing issue, until now I never ran the fuzzer
as root so these particular code paths weren't tested.
Vince
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: perf, kprobes: fuzzer generates huge number of WARNings
2015-07-07 4:00 ` Vince Weaver
@ 2015-07-07 10:35 ` Masami Hiramatsu
2015-07-07 15:06 ` Vince Weaver
2015-07-07 19:18 ` Alexei Starovoitov
1 sibling, 1 reply; 16+ messages in thread
From: Masami Hiramatsu @ 2015-07-07 10:35 UTC (permalink / raw)
To: Vince Weaver
Cc: linux-kernel, Ananth N Mavinakayanahalli, Anil S Keshavamurthy,
David S. Miller, Peter Zijlstra, Ingo Molnar,
Arnaldo Carvalho de Melo, Steven Rostedt
On 2015/07/07 13:00, Vince Weaver wrote:
> On Tue, 7 Jul 2015, Masami Hiramatsu wrote:
>
>> On 2015/07/07 6:27, Vince Weaver wrote:
>>> Hello
>>>
>>> I've been working on trying to get the perf_fuzzer to start fuzzing the
>>> PERF_EVENT_IOC_SET_BPF so I've added some really hackish kprobe support.
>>>
>>> However before I can get to the BPF testing the kprobe code generates a
>>> constant stream of WARNINGS which make the machine more or less useless
>>> until I stop it. I've included a small selection here.
>>>
>>> Is this expected?
>>
>> Did you get same message without BPF hack? And also, could you tell us
>> your kernel version and configuration?
>
> It's a Hawell machine running 4.2-rc1. I can post the .config if it's of
> interest.
Yes, I'm interested in.
> Well the BPF hack is in the fuzzer, not the kernel. And it's not really a
> hack, it just turned out to be a huge pain to figure out how to
> manually create a valid BPF program in conjunction with a valid kprobe
> event.
>
> I did have to sprinkle printks in the kprobe and bpf code to find out
> where various EINVAL returns were coming from, so potentially this is just
> a problem of printks happening where they shouldn't. I'll remove those
> changes and try to reproduce this tomorrow.
OK, and also, if you have a chance, please run the ftracetest as below.
$ cd tools/testing/selftest/ftrace/
$ sudo ./ftracetest
This will do a series of basic tests on ftrace and report it.
> This is possibly a long standing issue, until now I never ran the fuzzer
> as root so these particular code paths weren't tested.
Thanks,
--
Masami HIRAMATSU
Linux Technology Research Center, System Productivity Research Dept.
Center for Technology Innovation - Systems Engineering
Hitachi, Ltd., Research & Development Group
E-mail: masami.hiramatsu.pt@hitachi.com
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: perf, kprobes: fuzzer generates huge number of WARNings
2015-07-07 10:35 ` Masami Hiramatsu
@ 2015-07-07 15:06 ` Vince Weaver
2015-07-07 15:10 ` Steven Rostedt
2015-07-07 15:11 ` Vince Weaver
0 siblings, 2 replies; 16+ messages in thread
From: Vince Weaver @ 2015-07-07 15:06 UTC (permalink / raw)
To: Masami Hiramatsu
Cc: Vince Weaver, linux-kernel, Ananth N Mavinakayanahalli,
Anil S Keshavamurthy, David S. Miller, Peter Zijlstra,
Ingo Molnar, Arnaldo Carvalho de Melo, Steven Rostedt
On Tue, 7 Jul 2015, Masami Hiramatsu wrote:
> > It's a Hawell machine running 4.2-rc1. I can post the .config if it's of
> > interest.
>
> Yes, I'm interested in.
I've put it here:
http://web.eece.maine.edu/~vweaver/junk/haswell-config
> OK, and also, if you have a chance, please run the ftracetest as below.
>
> $ cd tools/testing/selftest/ftrace/
> $ sudo ./ftracetest
>
> This will do a series of basic tests on ftrace and report it.
It won't run:
sudo ./ftracetest
Error: No ftrace directory found
probably because I am running 4.2-rc1 and have tracefs mounted under
/sys/kernel/tracing.
I guess the tester needs to be updated?
I'll see if I can get debugfs mounted too, but I had changed the setup so
perf would run.
When I recompiled my kernel to remove the extra debug messages and run my
fuzzer test I get a lot of these, probably because I have the kprobe
address hard-coded into the tester.
[ 290.067450] Could not insert probe at _text+1664816: -84
[ 290.074976] Probing address(0xffffffff81196730) is not an instruction boundary.
[ 290.131191] Could not insert probe at _text+1664816: -84
[ 290.137555] Probing address(0xffffffff81196730) is not an instruction boundary.
[ 290.170513] Could not insert probe at _text+1664816: -84
[ 290.176877] Probing address(0xffffffff81196730) is not an instruction boundary.
[ 290.298940] Could not insert probe at _text+1664816: -84
[ 290.305224] Probing address(0xffffffff81196730) is not an instruction boundary.
[ 290.349272] Could not insert probe at _text+1664816: -84
[ 290.355585] Probing address(0xffffffff81196730) is not an instruction boundary.
[ 290.365738] Could not insert probe at _text+1664816: -84
[ 290.371992] Probing address(0xffffffff81196730) is not an instruction boundary.
[ 290.383820] perf interrupt took too long (448 > 266), lowering kernel.perf_event_max_sample_rate to 468250
[ 295.088511] perf interrupt took too long (485 > 0), lowering kernel.perf_event_max_sample_rate to 1639281051
[ 311.415309] INFO: rcu_sched detected stalls on CPUs/tasks: { 5} (detected by 6, t=5253 jiffies, g=1818, c=1817, q=534)
[ 311.427531] Task dump for CPU 5:
[ 311.431631] in:imklog R running task 0 1736 1 0x00000008
[ 311.439865] 0000000000000286 0000000100000005 0000000000000096 0000000200000000
[ 311.448549] 0000000000000286 ffffffff81c4b2e0 ffffffff81c4b2e0 ffffffff828da234
[ 311.457173] 0000000000001f2f 00007fa62335fe11 0000000000000071 ffffffff828da234
[ 311.465865] Call Trace:
[ 311.469098] [<ffffffff810c8886>] ? do_syslog+0x456/0x500
[ 311.475518] [<ffffffff810b02a0>] ? wait_woken+0x90/0x90
[ 311.481830] [<ffffffff81255bb4>] ? kmsg_read+0x44/0x60
[ 311.488040] [<ffffffff816a686e>] ? mutex_unlock+0xe/0x10
[ 311.494433] [<ffffffff81003000>] ? calibrate_delay+0x8f0/0x8f0
[ 311.501356] [<ffffffff816a98e5>] ? retint_check+0x6/0x12
[ 313.873152] hrtimer: interrupt took 14075878236 ns
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: perf, kprobes: fuzzer generates huge number of WARNings
2015-07-07 15:06 ` Vince Weaver
@ 2015-07-07 15:10 ` Steven Rostedt
2015-07-07 18:06 ` Vince Weaver
2015-07-07 15:11 ` Vince Weaver
1 sibling, 1 reply; 16+ messages in thread
From: Steven Rostedt @ 2015-07-07 15:10 UTC (permalink / raw)
To: Vince Weaver
Cc: Masami Hiramatsu, linux-kernel, Ananth N Mavinakayanahalli,
Anil S Keshavamurthy, David S. Miller, Peter Zijlstra,
Ingo Molnar, Arnaldo Carvalho de Melo
On Tue, 7 Jul 2015 11:06:55 -0400 (EDT)
Vince Weaver <vincent.weaver@maine.edu> wrote:
> On Tue, 7 Jul 2015, Masami Hiramatsu wrote:
>
> > > It's a Hawell machine running 4.2-rc1. I can post the .config if it's of
> > > interest.
> >
> > Yes, I'm interested in.
>
> I've put it here:
> http://web.eece.maine.edu/~vweaver/junk/haswell-config
>
> > OK, and also, if you have a chance, please run the ftracetest as below.
> >
> > $ cd tools/testing/selftest/ftrace/
> > $ sudo ./ftracetest
> >
> > This will do a series of basic tests on ftrace and report it.
>
> It won't run:
> sudo ./ftracetest
> Error: No ftrace directory found
>
> probably because I am running 4.2-rc1 and have tracefs mounted under
> /sys/kernel/tracing.
You could also just mount debugfs.
> I guess the tester needs to be updated?
Yes, it probably should be.
> I'll see if I can get debugfs mounted too, but I had changed the setup so
> perf would run.
>
>
> When I recompiled my kernel to remove the extra debug messages and run my
> fuzzer test I get a lot of these, probably because I have the kprobe
> address hard-coded into the tester.
Probably. If you recompiled the kernel, you need to find the new
address points.
-- Steve
>
> [ 290.067450] Could not insert probe at _text+1664816: -84
> [ 290.074976] Probing address(0xffffffff81196730) is not an instruction boundary.
> [ 290.131191] Could not insert probe at _text+1664816: -84
> [ 290.137555] Probing address(0xffffffff81196730) is not an instruction boundary.
> [ 290.170513] Could not insert probe at _text+1664816: -84
> [ 290.176877] Probing address(0xffffffff81196730) is not an instruction boundary.
> [ 290.298940] Could not insert probe at _text+1664816: -84
> [ 290.305224] Probing address(0xffffffff81196730) is not an instruction boundary.
> [ 290.349272] Could not insert probe at _text+1664816: -84
> [ 290.355585] Probing address(0xffffffff81196730) is not an instruction boundary.
> [ 290.365738] Could not insert probe at _text+1664816: -84
> [ 290.371992] Probing address(0xffffffff81196730) is not an instruction boundary.
> [ 290.383820] perf interrupt took too long (448 > 266), lowering kernel.perf_event_max_sample_rate to 468250
> [ 295.088511] perf interrupt took too long (485 > 0), lowering kernel.perf_event_max_sample_rate to 1639281051
> [ 311.415309] INFO: rcu_sched detected stalls on CPUs/tasks: { 5} (detected by 6, t=5253 jiffies, g=1818, c=1817, q=534)
> [ 311.427531] Task dump for CPU 5:
> [ 311.431631] in:imklog R running task 0 1736 1 0x00000008
> [ 311.439865] 0000000000000286 0000000100000005 0000000000000096 0000000200000000
> [ 311.448549] 0000000000000286 ffffffff81c4b2e0 ffffffff81c4b2e0 ffffffff828da234
> [ 311.457173] 0000000000001f2f 00007fa62335fe11 0000000000000071 ffffffff828da234
> [ 311.465865] Call Trace:
> [ 311.469098] [<ffffffff810c8886>] ? do_syslog+0x456/0x500
> [ 311.475518] [<ffffffff810b02a0>] ? wait_woken+0x90/0x90
> [ 311.481830] [<ffffffff81255bb4>] ? kmsg_read+0x44/0x60
> [ 311.488040] [<ffffffff816a686e>] ? mutex_unlock+0xe/0x10
> [ 311.494433] [<ffffffff81003000>] ? calibrate_delay+0x8f0/0x8f0
> [ 311.501356] [<ffffffff816a98e5>] ? retint_check+0x6/0x12
> [ 313.873152] hrtimer: interrupt took 14075878236 ns
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: perf, kprobes: fuzzer generates huge number of WARNings
2015-07-07 15:06 ` Vince Weaver
2015-07-07 15:10 ` Steven Rostedt
@ 2015-07-07 15:11 ` Vince Weaver
2015-07-09 9:58 ` Masami Hiramatsu
1 sibling, 1 reply; 16+ messages in thread
From: Vince Weaver @ 2015-07-07 15:11 UTC (permalink / raw)
To: Vince Weaver
Cc: Masami Hiramatsu, linux-kernel, Ananth N Mavinakayanahalli,
Anil S Keshavamurthy, David S. Miller, Peter Zijlstra,
Ingo Molnar, Arnaldo Carvalho de Melo, Steven Rostedt
On Tue, 7 Jul 2015, Vince Weaver wrote:
> On Tue, 7 Jul 2015, Masami Hiramatsu wrote:
>
> > > It's a Hawell machine running 4.2-rc1. I can post the .config if it's of
> > > interest.
> >
> > Yes, I'm interested in.
>
> I've put it here:
> http://web.eece.maine.edu/~vweaver/junk/haswell-config
>
> > OK, and also, if you have a chance, please run the ftracetest as below.
> >
> > $ cd tools/testing/selftest/ftrace/
> > $ sudo ./ftracetest
> >
> > This will do a series of basic tests on ftrace and report it.
>
> It won't run:
> sudo ./ftracetest
> Error: No ftrace directory found
>
OK here are the results when I mounted debugfs in the right place.
sudo ./ftracetest
=== Ftrace unit tests ===
[1] Basic trace file check [PASS]
[2] Basic test for tracers [PASS]
[3] Basic trace clock test [PASS]
[4] Basic event tracing check [PASS]
[5] event tracing - enable/disable with event level files [PASS]
[6] event tracing - enable/disable with subsystem level files [PASS]
[7] event tracing - enable/disable with top level files [PASS]
[8] ftrace - function graph filters with stack tracer [UNSUPPORTED]
execute:
/home/vince/research/linux-kernel/linux-git/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter-stack.tc
+ .
/home/vince/research/linux-kernel/linux-git/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter-stack.tc
+ grep -q function_graph available_tracers
+ [ ! -f set_ftrace_filter ]
+ disable_tracing
+ echo 0
+ clear_trace
+ echo
+ echo schedule
+ echo function_graph
+ [ ! -f stack_trace ]
+ echo Stack tracer not configured
Stack tracer not configured
+ do_reset
+ reset_tracer
+ echo nop
+ [ -e /proc/sys/kernel/stack_tracer_enabled ]
+ enable_tracing
+ echo 1
+ clear_trace
+ echo
+ echo
+ exit_unsupported
+ kill -s 40 2725
+ exit 0
[9] ftrace - function graph filters [PASS]
[10] ftrace - function profiler with function tracing [UNSUPPORTED]
execute:
/home/vince/research/linux-kernel/linux-git/tools/testing/selftests/ftrace/test.d/ftrace/func_profiler.tc
+ .
/home/vince/research/linux-kernel/linux-git/tools/testing/selftests/ftrace/test.d/ftrace/func_profiler.tc
+ grep -q function_graph available_tracers
+ [ ! -f set_ftrace_filter ]
+ [ ! -f function_profile_enabled ]
+ echo function_profile_enabled not found, function profiling enabled?
function_profile_enabled not found, function profiling enabled?
+ exit_unsupported
+ kill -s 40 2725
+ exit 0
[11] Kprobe dynamic event - adding and removing [FAIL]
execute:
/home/vince/research/linux-kernel/linux-git/tools/testing/selftests/ftrace/test.d/kprobe/add_and_remove.tc
+ .
/home/vince/research/linux-kernel/linux-git/tools/testing/selftests/ftrace/test.d/kprobe/add_and_remove.tc
+ [ -f kprobe_events ]
+ echo 0
+ echo
+ echo p:myevent do_fork
sh: echo: I/O error
[12] Kprobe dynamic event - busy event check [FAIL]
execute:
/home/vince/research/linux-kernel/linux-git/tools/testing/selftests/ftrace/test.d/kprobe/busy_check.tc
+ .
/home/vince/research/linux-kernel/linux-git/tools/testing/selftests/ftrace/test.d/kprobe/busy_check.tc
+ [ -f kprobe_events ]
+ echo 0
+ echo
+ echo p:myevent do_fork
sh: echo: I/O error
[13] Kprobe dynamic event with arguments [FAIL]
execute:
/home/vince/research/linux-kernel/linux-git/tools/testing/selftests/ftrace/test.d/kprobe/kprobe_args.tc
+ .
/home/vince/research/linux-kernel/linux-git/tools/testing/selftests/ftrace/test.d/kprobe/kprobe_args.tc
+ [ -f kprobe_events ]
+ echo 0
+ echo
+ echo p:testprobe do_fork $stack $stack0 +0($stack)
sh: echo: I/O error
[14] Kprobe dynamic event with function tracer [FAIL]
execute:
/home/vince/research/linux-kernel/linux-git/tools/testing/selftests/ftrace/test.d/kprobe/kprobe_ftrace.tc
+ .
/home/vince/research/linux-kernel/linux-git/tools/testing/selftests/ftrace/test.d/kprobe/kprobe_ftrace.tc
+ [ -f kprobe_events ]
+ grep function available_tracers
blk function_graph function nop
+ echo nop
+ echo do_fork
sh: echo: I/O error
[15] Kretprobe dynamic event with arguments [FAIL]
execute:
/home/vince/research/linux-kernel/linux-git/tools/testing/selftests/ftrace/test.d/kprobe/kretprobe_args.tc
+ .
/home/vince/research/linux-kernel/linux-git/tools/testing/selftests/ftrace/test.d/kprobe/kretprobe_args.tc
+ [ -f kprobe_events ]
+ echo 0
+ echo
+ echo r:testprobe2 do_fork $retval
sh: echo: I/O error
# of passed: 8
# of failed: 5
# of unresolved: 0
# of untested: 0
# of unsupported: 2
# of xfailed: 0
# of undefined(test bug): 0
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: perf, kprobes: fuzzer generates huge number of WARNings
2015-07-07 15:10 ` Steven Rostedt
@ 2015-07-07 18:06 ` Vince Weaver
2015-07-08 3:13 ` Masami Hiramatsu
0 siblings, 1 reply; 16+ messages in thread
From: Vince Weaver @ 2015-07-07 18:06 UTC (permalink / raw)
To: Steven Rostedt
Cc: Vince Weaver, Masami Hiramatsu, linux-kernel,
Ananth N Mavinakayanahalli, Anil S Keshavamurthy,
David S. Miller, Peter Zijlstra, Ingo Molnar,
Arnaldo Carvalho de Melo
On Tue, 7 Jul 2015, Steven Rostedt wrote:
> On Tue, 7 Jul 2015 11:06:55 -0400 (EDT)
> Probably. If you recompiled the kernel, you need to find the new
> address points.
should these messages really be spamming the syslog?
I updated the kprobe to point to the right location again
(this is
and the fuzzer just generates infinite of these warnings. Maybe they
should be WARN_ONCE rather than plain WARN?
[ 5447.623713] ------------[ cut here ]------------
[ 5447.629160] WARNING: CPU: 1 PID: 4158 at kernel/kprobes.c:939 arm_kprobe+0xe3/0xf0()
[ 5447.637944] Failed to arm kprobe-ftrace at ffffffff81196670 (-19)
[ 5447.723237] CPU: 1 PID: 4158 Comm: perf_fuzzer Tainted: G W 4.2.0-rc1+ #169
[ 5447.732454] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS 01/26/2014
[ 5447.740897] ffffffff81a2894e ffff8801161b3bf8 ffffffff816a0fd3 0000000000000000
[ 5447.749426] ffff8801161b3c48 ffff8801161b3c38 ffffffff8106ec8a 000000000000aed0
[ 5447.757931] ffff88011847b810 0000000000000000 ffff8800cd8b8000 ffffffff81d25640
[ 5447.766463] Call Trace:
[ 5447.769567] [<ffffffff816a0fd3>] dump_stack+0x45/0x57
[ 5447.775569] [<ffffffff8106ec8a>] warn_slowpath_common+0x8a/0xc0
[ 5447.782504] [<ffffffff8106ed06>] warn_slowpath_fmt+0x46/0x50
[ 5447.789111] [<ffffffff8118996a>] ? pcpu_alloc+0x36a/0x630
[ 5447.795466] [<ffffffff81196670>] ? vm_insert_mixed+0x40/0x40
[ 5447.802098] [<ffffffff81119083>] arm_kprobe+0xe3/0xf0
[ 5447.808095] [<ffffffff81119108>] enable_kprobe+0x78/0x80
[ 5447.814353] [<ffffffff81143489>] kprobe_register+0x59/0xe0
[ 5447.820805] [<ffffffff8113dc95>] perf_trace_init+0x1b5/0x2c0
[ 5447.827471] [<ffffffff81152e2a>] perf_tp_event_init+0x2a/0x50
[ 5447.834197] [<ffffffff8115442b>] perf_try_init_event+0x8b/0xa0
[ 5447.841012] [<ffffffff8115bec3>] perf_init_event+0x133/0x160
[ 5447.847658] [<ffffffff8115bd90>] ? perf_bp_event+0x90/0x90
[ 5447.854101] [<ffffffff8115c31a>] perf_event_alloc+0x42a/0x680
[ 5447.860840] [<ffffffff8115c937>] SYSC_perf_event_open+0x3c7/0xd20
[ 5447.867949] [<ffffffff8115d709>] SyS_perf_event_open+0x9/0x10
[ 5447.874702] [<ffffffff816a8d32>] entry_SYSCALL_64_fastpath+0x16/0x7a
[ 5447.882093] ---[ end trace 5d38212a775ec3f3 ]---
[ 5447.887538] ------------[ cut here ]------------
[ 5447.892984] WARNING: CPU: 1 PID: 4158 at kernel/kprobes.c:943 arm_kprobe+0xae/0xf0()
[ 5447.901755] Failed to init kprobe-ftrace (-19)
[ 5447.985337] CPU: 1 PID: 4158 Comm: perf_fuzzer Tainted: G W 4.2.0-rc1+ #169
[ 5447.994611] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS 01/26/2014
[ 5448.003174] ffffffff81a2894e ffff8801161b3bf8 ffffffff816a0fd3 0000000000000000
[ 5448.011805] ffff8801161b3c48 ffff8801161b3c38 ffffffff8106ec8a ffffffff81125c1a
[ 5448.020424] ffff88011847b810 0000000000000000 ffff8800cd8b8000 ffffffff81d25640
[ 5448.029074] Call Trace:
[ 5448.032265] [<ffffffff816a0fd3>] dump_stack+0x45/0x57
[ 5448.038342] [<ffffffff8106ec8a>] warn_slowpath_common+0x8a/0xc0
[ 5448.045376] [<ffffffff81125c1a>] ? register_ftrace_function+0x4a/0x70
[ 5448.052930] [<ffffffff8106ed06>] warn_slowpath_fmt+0x46/0x50
[ 5448.059617] [<ffffffff816a686e>] ? mutex_unlock+0xe/0x10
[ 5448.065951] [<ffffffff8111904e>] arm_kprobe+0xae/0xf0
[ 5448.072003] [<ffffffff81119108>] enable_kprobe+0x78/0x80
[ 5448.078341] [<ffffffff81143489>] kprobe_register+0x59/0xe0
[ 5448.084823] [<ffffffff8113dc95>] perf_trace_init+0x1b5/0x2c0
[ 5448.091484] [<ffffffff81152e2a>] perf_tp_event_init+0x2a/0x50
[ 5448.098212] [<ffffffff8115442b>] perf_try_init_event+0x8b/0xa0
[ 5448.105068] [<ffffffff8115bec3>] perf_init_event+0x133/0x160
[ 5448.111689] [<ffffffff8115bd90>] ? perf_bp_event+0x90/0x90
[ 5448.118116] [<ffffffff8115c31a>] perf_event_alloc+0x42a/0x680
[ 5448.124825] [<ffffffff8115c937>] SYSC_perf_event_open+0x3c7/0xd20
[ 5448.131946] [<ffffffff8115d709>] SyS_perf_event_open+0x9/0x10
[ 5448.138640] [<ffffffff816a8d32>] entry_SYSCALL_64_fastpath+0x16/0x7a
[ 5448.146065] ---[ end trace 5d38212a775ec3f4 ]---
[ 5448.228748] ------------[ cut here ]------------
[ 5448.234201] WARNING: CPU: 2 PID: 4247 at kernel/kprobes.c:955 disarm_kprobe+0xf8/0x100()
[ 5448.243366] Failed to init kprobe-ftrace (-19)
[ 5448.327114] CPU: 2 PID: 4247 Comm: perf_fuzzer Tainted: G W 4.2.0-rc1+ #169
[ 5448.336416] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS 01/26/2014
[ 5448.344935] ffffffff81a2894e ffff8801187a79e8 ffffffff816a0fd3 0000000000000000
[ 5448.353549] ffff8801187a7a38 ffff8801187a7a28 ffffffff8106ec8a ffffffff81124f6a
[ 5448.362177] ffff88011847b810 ffff88011847b810 ffff88011847b800 ffff8801160c02a8
[ 5448.370824] Call Trace:
[ 5448.374033] [<ffffffff816a0fd3>] dump_stack+0x45/0x57
[ 5448.380146] [<ffffffff8106ec8a>] warn_slowpath_common+0x8a/0xc0
[ 5448.387148] [<ffffffff81124f6a>] ? unregister_ftrace_function+0x1a/0x50
[ 5448.394880] [<ffffffff8106ed06>] warn_slowpath_fmt+0x46/0x50
[ 5448.401603] [<ffffffff816a686e>] ? mutex_unlock+0xe/0x10
[ 5448.407920] [<ffffffff81119208>] disarm_kprobe+0xf8/0x100
[ 5448.414326] [<ffffffff811192a9>] __disable_kprobe+0x99/0xc0
[ 5448.420874] [<ffffffff811192f7>] disable_kprobe+0x27/0x50
[ 5448.427222] [<ffffffff81142863>] disable_trace_kprobe+0xc3/0xf0
[ 5448.434140] [<ffffffff8114345d>] kprobe_register+0x2d/0xe0
[ 5448.440586] [<ffffffff8113da83>] perf_trace_event_unreg.isra.1+0x33/0x90
[ 5448.448349] [<ffffffff8113dddc>] perf_trace_destroy+0x3c/0x50
[ 5448.455058] [<ffffffff81152e59>] tp_perf_event_destroy+0x9/0x10
[ 5448.461945] [<ffffffff81158f61>] _free_event+0xc1/0x250
[ 5448.468093] [<ffffffff811591fa>] put_event+0x10a/0x150
[ 5448.474167] [<ffffffff8115911b>] ? put_event+0x2b/0x150
[ 5448.480313] [<ffffffff81152db5>] ? perf_fasync+0x55/0x70
[ 5448.486552] [<ffffffff81159260>] perf_release+0x10/0x20
[ 5448.492735] [<ffffffff811df3ec>] __fput+0xdc/0x1e0
[ 5448.498420] [<ffffffff811df53e>] ____fput+0xe/0x10
[ 5448.504110] [<ffffffff8108c27b>] task_work_run+0x9b/0xb0
[ 5448.510315] [<ffffffff81071615>] do_exit+0x3a5/0xa90
[ 5448.516184] [<ffffffff8107d182>] ? get_signal+0xe2/0x720
[ 5448.522407] [<ffffffff81071da4>] do_group_exit+0x54/0xe0
[ 5448.528671] [<ffffffff8107d320>] get_signal+0x280/0x720
[ 5448.534830] [<ffffffff81013478>] do_signal+0x28/0xb50
[ 5448.540792] [<ffffffff810b78f6>] ? __lock_acquire.isra.31+0x3a6/0xf90
[ 5448.548277] [<ffffffff810815a5>] ? sys_getppid+0x5/0x80
[ 5448.554413] [<ffffffff81014002>] do_notify_resume+0x62/0x70
[ 5448.560950] [<ffffffff816a9a1e>] retint_signal+0x44/0x86
[ 5448.567208] ---[ end trace 5d38212a775ec3f5 ]---
[ 5448.572624] ------------[ cut here ]------------
[ 5448.578045] WARNING: CPU: 2 PID: 4247 at kernel/kprobes.c:959 disarm_kprobe+0xca/0x100()
[ 5448.587194] Failed to disarm kprobe-ftrace at ffffffff81196670 (-19)
[ 5448.672321] CPU: 2 PID: 4247 Comm: perf_fuzzer Tainted: G W 4.2.0-rc1+ #169
[ 5448.681431] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS 01/26/2014
[ 5448.689813] ffffffff81a2894e ffff8801187a79e8 ffffffff816a0fd3 0000000000000000
[ 5448.698271] ffff8801187a7a38 ffff8801187a7a28 ffffffff8106ec8a ffffffff81124f6a
[ 5448.706783] ffff88011847b810 ffff88011847b810 ffff88011847b800 ffff8801160c02a8
[ 5448.715255] Call Trace:
[ 5448.718342] [<ffffffff816a0fd3>] dump_stack+0x45/0x57
[ 5448.724346] [<ffffffff8106ec8a>] warn_slowpath_common+0x8a/0xc0
[ 5448.731233] [<ffffffff81124f6a>] ? unregister_ftrace_function+0x1a/0x50
[ 5448.738872] [<ffffffff8106ed06>] warn_slowpath_fmt+0x46/0x50
[ 5448.745467] [<ffffffff816a686e>] ? mutex_unlock+0xe/0x10
[ 5448.751708] [<ffffffff81196670>] ? vm_insert_mixed+0x40/0x40
[ 5448.758336] [<ffffffff811191da>] disarm_kprobe+0xca/0x100
[ 5448.764683] [<ffffffff811192a9>] __disable_kprobe+0x99/0xc0
[ 5448.771186] [<ffffffff811192f7>] disable_kprobe+0x27/0x50
[ 5448.777504] [<ffffffff81142863>] disable_trace_kprobe+0xc3/0xf0
[ 5448.784424] [<ffffffff8114345d>] kprobe_register+0x2d/0xe0
[ 5448.790863] [<ffffffff8113da83>] perf_trace_event_unreg.isra.1+0x33/0x90
[ 5448.798558] [<ffffffff8113dddc>] perf_trace_destroy+0x3c/0x50
[ 5448.805285] [<ffffffff81152e59>] tp_perf_event_destroy+0x9/0x10
[ 5448.812218] [<ffffffff81158f61>] _free_event+0xc1/0x250
[ 5448.818384] [<ffffffff811591fa>] put_event+0x10a/0x150
[ 5448.824422] [<ffffffff8115911b>] ? put_event+0x2b/0x150
[ 5448.830593] [<ffffffff81152db5>] ? perf_fasync+0x55/0x70
[ 5448.836862] [<ffffffff81159260>] perf_release+0x10/0x20
[ 5448.843023] [<ffffffff811df3ec>] __fput+0xdc/0x1e0
[ 5448.848709] [<ffffffff811df53e>] ____fput+0xe/0x10
[ 5448.854382] [<ffffffff8108c27b>] task_work_run+0x9b/0xb0
[ 5448.860620] [<ffffffff81071615>] do_exit+0x3a5/0xa90
[ 5448.866469] [<ffffffff8107d182>] ? get_signal+0xe2/0x720
[ 5448.872714] [<ffffffff81071da4>] do_group_exit+0x54/0xe0
[ 5448.878990] [<ffffffff8107d320>] get_signal+0x280/0x720
[ 5448.885163] [<ffffffff81013478>] do_signal+0x28/0xb50
[ 5448.891117] [<ffffffff810b78f6>] ? __lock_acquire.isra.31+0x3a6/0xf90
[ 5448.898586] [<ffffffff810815a5>] ? sys_getppid+0x5/0x80
[ 5448.904712] [<ffffffff81014002>] do_notify_resume+0x62/0x70
[ 5448.911245] [<ffffffff816a9a1e>] retint_signal+0x44/0x86
[ 5448.917526] ---[ end trace 5d38212a775ec3f6 ]---
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: perf, kprobes: fuzzer generates huge number of WARNings
2015-07-07 4:00 ` Vince Weaver
2015-07-07 10:35 ` Masami Hiramatsu
@ 2015-07-07 19:18 ` Alexei Starovoitov
2015-07-07 21:08 ` Vince Weaver
1 sibling, 1 reply; 16+ messages in thread
From: Alexei Starovoitov @ 2015-07-07 19:18 UTC (permalink / raw)
To: Vince Weaver
Cc: Masami Hiramatsu, linux-kernel, Ananth N Mavinakayanahalli,
Anil S Keshavamurthy, David S. Miller, Peter Zijlstra,
Ingo Molnar, Arnaldo Carvalho de Melo, Steven Rostedt
On Tue, Jul 07, 2015 at 12:00:12AM -0400, Vince Weaver wrote:
>
> Well the BPF hack is in the fuzzer, not the kernel. And it's not really a
> hack, it just turned out to be a huge pain to figure out how to
> manually create a valid BPF program in conjunction with a valid kprobe
> event.
You mean automatically generating valid bpf program? That's definitely hard.
If you mean just few hardcoded programs then take them from samples or
from test_bpf ?
> I did have to sprinkle printks in the kprobe and bpf code to find out
> where various EINVAL returns were coming from, so potentially this is just
> a problem of printks happening where they shouldn't. I'll remove those
> changes and try to reproduce this tomorrow.
could you please elaborate on this further. Which EINVALs you talking about?
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: perf, kprobes: fuzzer generates huge number of WARNings
2015-07-07 19:18 ` Alexei Starovoitov
@ 2015-07-07 21:08 ` Vince Weaver
2015-07-07 21:21 ` Alexei Starovoitov
0 siblings, 1 reply; 16+ messages in thread
From: Vince Weaver @ 2015-07-07 21:08 UTC (permalink / raw)
To: Alexei Starovoitov
Cc: Vince Weaver, Masami Hiramatsu, linux-kernel,
Ananth N Mavinakayanahalli, Anil S Keshavamurthy,
David S. Miller, Peter Zijlstra, Ingo Molnar,
Arnaldo Carvalho de Melo, Steven Rostedt
On Tue, 7 Jul 2015, Alexei Starovoitov wrote:
> On Tue, Jul 07, 2015 at 12:00:12AM -0400, Vince Weaver wrote:
> >
> > Well the BPF hack is in the fuzzer, not the kernel. And it's not really a
> > hack, it just turned out to be a huge pain to figure out how to
> > manually create a valid BPF program in conjunction with a valid kprobe
> > event.
>
> You mean automatically generating valid bpf program? That's definitely hard.
> If you mean just few hardcoded programs then take them from samples or
> from test_bpf ?
there's already code in trinity that in theory autogenerates bpf programs,
but for now I was just trying to hook up a short known valid one.
it might not be possible to really test things though, as you need to be
root to create a kprobe and attach a BPF program, but my fuzzer when run
as root often does all kinds of other stuff that will crash a machine.
Is it ever planned to allow using bpf/kprobes without requiring full
CAP_ADMIN privledges?
> > I did have to sprinkle printks in the kprobe and bpf code to find out
> > where various EINVAL returns were coming from, so potentially this is just
> > a problem of printks happening where they shouldn't. I'll remove those
> > changes and try to reproduce this tomorrow.
>
> could you please elaborate on this further. Which EINVALs you talking about?
When you are trying to create a kprobe and bpf file there's about 10
different ways to get EINVAL as a return value and no way of knowing which
one you are hitting. I added printks so I could know what issue was
causing the einval. (from memory, the problems I hit were not zeroing out
the attr structure, having a wrong instruction count, and a few others).
Vince
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: perf, kprobes: fuzzer generates huge number of WARNings
2015-07-07 21:08 ` Vince Weaver
@ 2015-07-07 21:21 ` Alexei Starovoitov
2015-07-08 13:11 ` Masami Hiramatsu
0 siblings, 1 reply; 16+ messages in thread
From: Alexei Starovoitov @ 2015-07-07 21:21 UTC (permalink / raw)
To: Vince Weaver
Cc: Masami Hiramatsu, linux-kernel, Ananth N Mavinakayanahalli,
Anil S Keshavamurthy, David S. Miller, Peter Zijlstra,
Ingo Molnar, Arnaldo Carvalho de Melo, Steven Rostedt
On Tue, Jul 07, 2015 at 05:08:51PM -0400, Vince Weaver wrote:
> On Tue, 7 Jul 2015, Alexei Starovoitov wrote:
>
> > On Tue, Jul 07, 2015 at 12:00:12AM -0400, Vince Weaver wrote:
> > >
> > > Well the BPF hack is in the fuzzer, not the kernel. And it's not really a
> > > hack, it just turned out to be a huge pain to figure out how to
> > > manually create a valid BPF program in conjunction with a valid kprobe
> > > event.
> >
> > You mean automatically generating valid bpf program? That's definitely hard.
> > If you mean just few hardcoded programs then take them from samples or
> > from test_bpf ?
>
> there's already code in trinity that in theory autogenerates bpf programs,
> but for now I was just trying to hook up a short known valid one.
>
> it might not be possible to really test things though, as you need to be
> root to create a kprobe and attach a BPF program, but my fuzzer when run
> as root often does all kinds of other stuff that will crash a machine.
> Is it ever planned to allow using bpf/kprobes without requiring full
> CAP_ADMIN privledges?
I suspect kprobes will forever be root only, whereas for bpf I'm thinking
to introduce CAP_BPF, but before that we need to finish constant blinding
and add address leak prevention. So not soon.
> > > I did have to sprinkle printks in the kprobe and bpf code to find out
> > > where various EINVAL returns were coming from, so potentially this is just
> > > a problem of printks happening where they shouldn't. I'll remove those
> > > changes and try to reproduce this tomorrow.
> >
> > could you please elaborate on this further. Which EINVALs you talking about?
>
> When you are trying to create a kprobe and bpf file there's about 10
> different ways to get EINVAL as a return value and no way of knowing which
> one you are hitting. I added printks so I could know what issue was
> causing the einval. (from memory, the problems I hit were not zeroing out
> the attr structure, having a wrong instruction count, and a few others).
I see. I guess anyone trying to use syscall directly will be facing such
issues, but libbpf that is being developed to be used by perf and others
should solve these problems.
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: perf, kprobes: fuzzer generates huge number of WARNings
2015-07-07 18:06 ` Vince Weaver
@ 2015-07-08 3:13 ` Masami Hiramatsu
0 siblings, 0 replies; 16+ messages in thread
From: Masami Hiramatsu @ 2015-07-08 3:13 UTC (permalink / raw)
To: Vince Weaver, Steven Rostedt
Cc: linux-kernel, Ananth N Mavinakayanahalli, Anil S Keshavamurthy,
David S. Miller, Peter Zijlstra, Ingo Molnar,
Arnaldo Carvalho de Melo
Hi Vince,
On 2015/07/08 3:06, Vince Weaver wrote:
> On Tue, 7 Jul 2015, Steven Rostedt wrote:
>
>> On Tue, 7 Jul 2015 11:06:55 -0400 (EDT)
>> Probably. If you recompiled the kernel, you need to find the new
>> address points.
>
> should these messages really be spamming the syslog?
>
> I updated the kprobe to point to the right location again
> (this is
>
> and the fuzzer just generates infinite of these warnings. Maybe they
> should be WARN_ONCE rather than plain WARN?
>
> [ 5447.623713] ------------[ cut here ]------------
> [ 5447.629160] WARNING: CPU: 1 PID: 4158 at kernel/kprobes.c:939 arm_kprobe+0xe3/0xf0()
> [ 5447.637944] Failed to arm kprobe-ftrace at ffffffff81196670 (-19)
The corresponding code is
----
ret = ftrace_set_filter_ip(&kprobe_ftrace_ops,
(unsigned long)p->addr, 0, 0);
WARN(ret < 0, "Failed to arm kprobe-ftrace at %p (%d)\n", p->addr, ret);
----
-19 is -ENODEV, and it may be returned from ftrace_set_hash
(ftrace_set_filter_ip -> ftrace_set_addr -> ftrace_set_hash)
----
static int
ftrace_set_hash(struct ftrace_ops *ops, unsigned char *buf, int len,
unsigned long ip, int remove, int reset, int enable)
{
struct ftrace_hash **orig_hash;
struct ftrace_ops_hash old_hash_ops;
struct ftrace_hash *old_hash;
struct ftrace_hash *hash;
int ret;
if (unlikely(ftrace_disabled))
return -ENODEV;
----
the ftrace_disabled (I think it would better be renamed to ftrace_died...) is
set only if an unrecoverable error happened. So before this message you'll
see some other error messages.
Thank you,
> [ 5447.723237] CPU: 1 PID: 4158 Comm: perf_fuzzer Tainted: G W 4.2.0-rc1+ #169
> [ 5447.732454] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS 01/26/2014
> [ 5447.740897] ffffffff81a2894e ffff8801161b3bf8 ffffffff816a0fd3 0000000000000000
> [ 5447.749426] ffff8801161b3c48 ffff8801161b3c38 ffffffff8106ec8a 000000000000aed0
> [ 5447.757931] ffff88011847b810 0000000000000000 ffff8800cd8b8000 ffffffff81d25640
> [ 5447.766463] Call Trace:
> [ 5447.769567] [<ffffffff816a0fd3>] dump_stack+0x45/0x57
> [ 5447.775569] [<ffffffff8106ec8a>] warn_slowpath_common+0x8a/0xc0
> [ 5447.782504] [<ffffffff8106ed06>] warn_slowpath_fmt+0x46/0x50
> [ 5447.789111] [<ffffffff8118996a>] ? pcpu_alloc+0x36a/0x630
> [ 5447.795466] [<ffffffff81196670>] ? vm_insert_mixed+0x40/0x40
> [ 5447.802098] [<ffffffff81119083>] arm_kprobe+0xe3/0xf0
> [ 5447.808095] [<ffffffff81119108>] enable_kprobe+0x78/0x80
> [ 5447.814353] [<ffffffff81143489>] kprobe_register+0x59/0xe0
> [ 5447.820805] [<ffffffff8113dc95>] perf_trace_init+0x1b5/0x2c0
> [ 5447.827471] [<ffffffff81152e2a>] perf_tp_event_init+0x2a/0x50
> [ 5447.834197] [<ffffffff8115442b>] perf_try_init_event+0x8b/0xa0
> [ 5447.841012] [<ffffffff8115bec3>] perf_init_event+0x133/0x160
> [ 5447.847658] [<ffffffff8115bd90>] ? perf_bp_event+0x90/0x90
> [ 5447.854101] [<ffffffff8115c31a>] perf_event_alloc+0x42a/0x680
> [ 5447.860840] [<ffffffff8115c937>] SYSC_perf_event_open+0x3c7/0xd20
> [ 5447.867949] [<ffffffff8115d709>] SyS_perf_event_open+0x9/0x10
> [ 5447.874702] [<ffffffff816a8d32>] entry_SYSCALL_64_fastpath+0x16/0x7a
> [ 5447.882093] ---[ end trace 5d38212a775ec3f3 ]---
> [ 5447.887538] ------------[ cut here ]------------
> [ 5447.892984] WARNING: CPU: 1 PID: 4158 at kernel/kprobes.c:943 arm_kprobe+0xae/0xf0()
> [ 5447.901755] Failed to init kprobe-ftrace (-19)
> [ 5447.985337] CPU: 1 PID: 4158 Comm: perf_fuzzer Tainted: G W 4.2.0-rc1+ #169
> [ 5447.994611] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS 01/26/2014
> [ 5448.003174] ffffffff81a2894e ffff8801161b3bf8 ffffffff816a0fd3 0000000000000000
> [ 5448.011805] ffff8801161b3c48 ffff8801161b3c38 ffffffff8106ec8a ffffffff81125c1a
> [ 5448.020424] ffff88011847b810 0000000000000000 ffff8800cd8b8000 ffffffff81d25640
> [ 5448.029074] Call Trace:
> [ 5448.032265] [<ffffffff816a0fd3>] dump_stack+0x45/0x57
> [ 5448.038342] [<ffffffff8106ec8a>] warn_slowpath_common+0x8a/0xc0
> [ 5448.045376] [<ffffffff81125c1a>] ? register_ftrace_function+0x4a/0x70
> [ 5448.052930] [<ffffffff8106ed06>] warn_slowpath_fmt+0x46/0x50
> [ 5448.059617] [<ffffffff816a686e>] ? mutex_unlock+0xe/0x10
> [ 5448.065951] [<ffffffff8111904e>] arm_kprobe+0xae/0xf0
> [ 5448.072003] [<ffffffff81119108>] enable_kprobe+0x78/0x80
> [ 5448.078341] [<ffffffff81143489>] kprobe_register+0x59/0xe0
> [ 5448.084823] [<ffffffff8113dc95>] perf_trace_init+0x1b5/0x2c0
> [ 5448.091484] [<ffffffff81152e2a>] perf_tp_event_init+0x2a/0x50
> [ 5448.098212] [<ffffffff8115442b>] perf_try_init_event+0x8b/0xa0
> [ 5448.105068] [<ffffffff8115bec3>] perf_init_event+0x133/0x160
> [ 5448.111689] [<ffffffff8115bd90>] ? perf_bp_event+0x90/0x90
> [ 5448.118116] [<ffffffff8115c31a>] perf_event_alloc+0x42a/0x680
> [ 5448.124825] [<ffffffff8115c937>] SYSC_perf_event_open+0x3c7/0xd20
> [ 5448.131946] [<ffffffff8115d709>] SyS_perf_event_open+0x9/0x10
> [ 5448.138640] [<ffffffff816a8d32>] entry_SYSCALL_64_fastpath+0x16/0x7a
> [ 5448.146065] ---[ end trace 5d38212a775ec3f4 ]---
> [ 5448.228748] ------------[ cut here ]------------
> [ 5448.234201] WARNING: CPU: 2 PID: 4247 at kernel/kprobes.c:955 disarm_kprobe+0xf8/0x100()
> [ 5448.243366] Failed to init kprobe-ftrace (-19)
> [ 5448.327114] CPU: 2 PID: 4247 Comm: perf_fuzzer Tainted: G W 4.2.0-rc1+ #169
> [ 5448.336416] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS 01/26/2014
> [ 5448.344935] ffffffff81a2894e ffff8801187a79e8 ffffffff816a0fd3 0000000000000000
> [ 5448.353549] ffff8801187a7a38 ffff8801187a7a28 ffffffff8106ec8a ffffffff81124f6a
> [ 5448.362177] ffff88011847b810 ffff88011847b810 ffff88011847b800 ffff8801160c02a8
> [ 5448.370824] Call Trace:
> [ 5448.374033] [<ffffffff816a0fd3>] dump_stack+0x45/0x57
> [ 5448.380146] [<ffffffff8106ec8a>] warn_slowpath_common+0x8a/0xc0
> [ 5448.387148] [<ffffffff81124f6a>] ? unregister_ftrace_function+0x1a/0x50
> [ 5448.394880] [<ffffffff8106ed06>] warn_slowpath_fmt+0x46/0x50
> [ 5448.401603] [<ffffffff816a686e>] ? mutex_unlock+0xe/0x10
> [ 5448.407920] [<ffffffff81119208>] disarm_kprobe+0xf8/0x100
> [ 5448.414326] [<ffffffff811192a9>] __disable_kprobe+0x99/0xc0
> [ 5448.420874] [<ffffffff811192f7>] disable_kprobe+0x27/0x50
> [ 5448.427222] [<ffffffff81142863>] disable_trace_kprobe+0xc3/0xf0
> [ 5448.434140] [<ffffffff8114345d>] kprobe_register+0x2d/0xe0
> [ 5448.440586] [<ffffffff8113da83>] perf_trace_event_unreg.isra.1+0x33/0x90
> [ 5448.448349] [<ffffffff8113dddc>] perf_trace_destroy+0x3c/0x50
> [ 5448.455058] [<ffffffff81152e59>] tp_perf_event_destroy+0x9/0x10
> [ 5448.461945] [<ffffffff81158f61>] _free_event+0xc1/0x250
> [ 5448.468093] [<ffffffff811591fa>] put_event+0x10a/0x150
> [ 5448.474167] [<ffffffff8115911b>] ? put_event+0x2b/0x150
> [ 5448.480313] [<ffffffff81152db5>] ? perf_fasync+0x55/0x70
> [ 5448.486552] [<ffffffff81159260>] perf_release+0x10/0x20
> [ 5448.492735] [<ffffffff811df3ec>] __fput+0xdc/0x1e0
> [ 5448.498420] [<ffffffff811df53e>] ____fput+0xe/0x10
> [ 5448.504110] [<ffffffff8108c27b>] task_work_run+0x9b/0xb0
> [ 5448.510315] [<ffffffff81071615>] do_exit+0x3a5/0xa90
> [ 5448.516184] [<ffffffff8107d182>] ? get_signal+0xe2/0x720
> [ 5448.522407] [<ffffffff81071da4>] do_group_exit+0x54/0xe0
> [ 5448.528671] [<ffffffff8107d320>] get_signal+0x280/0x720
> [ 5448.534830] [<ffffffff81013478>] do_signal+0x28/0xb50
> [ 5448.540792] [<ffffffff810b78f6>] ? __lock_acquire.isra.31+0x3a6/0xf90
> [ 5448.548277] [<ffffffff810815a5>] ? sys_getppid+0x5/0x80
> [ 5448.554413] [<ffffffff81014002>] do_notify_resume+0x62/0x70
> [ 5448.560950] [<ffffffff816a9a1e>] retint_signal+0x44/0x86
> [ 5448.567208] ---[ end trace 5d38212a775ec3f5 ]---
> [ 5448.572624] ------------[ cut here ]------------
> [ 5448.578045] WARNING: CPU: 2 PID: 4247 at kernel/kprobes.c:959 disarm_kprobe+0xca/0x100()
> [ 5448.587194] Failed to disarm kprobe-ftrace at ffffffff81196670 (-19)
> [ 5448.672321] CPU: 2 PID: 4247 Comm: perf_fuzzer Tainted: G W 4.2.0-rc1+ #169
> [ 5448.681431] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS 01/26/2014
> [ 5448.689813] ffffffff81a2894e ffff8801187a79e8 ffffffff816a0fd3 0000000000000000
> [ 5448.698271] ffff8801187a7a38 ffff8801187a7a28 ffffffff8106ec8a ffffffff81124f6a
> [ 5448.706783] ffff88011847b810 ffff88011847b810 ffff88011847b800 ffff8801160c02a8
> [ 5448.715255] Call Trace:
> [ 5448.718342] [<ffffffff816a0fd3>] dump_stack+0x45/0x57
> [ 5448.724346] [<ffffffff8106ec8a>] warn_slowpath_common+0x8a/0xc0
> [ 5448.731233] [<ffffffff81124f6a>] ? unregister_ftrace_function+0x1a/0x50
> [ 5448.738872] [<ffffffff8106ed06>] warn_slowpath_fmt+0x46/0x50
> [ 5448.745467] [<ffffffff816a686e>] ? mutex_unlock+0xe/0x10
> [ 5448.751708] [<ffffffff81196670>] ? vm_insert_mixed+0x40/0x40
> [ 5448.758336] [<ffffffff811191da>] disarm_kprobe+0xca/0x100
> [ 5448.764683] [<ffffffff811192a9>] __disable_kprobe+0x99/0xc0
> [ 5448.771186] [<ffffffff811192f7>] disable_kprobe+0x27/0x50
> [ 5448.777504] [<ffffffff81142863>] disable_trace_kprobe+0xc3/0xf0
> [ 5448.784424] [<ffffffff8114345d>] kprobe_register+0x2d/0xe0
> [ 5448.790863] [<ffffffff8113da83>] perf_trace_event_unreg.isra.1+0x33/0x90
> [ 5448.798558] [<ffffffff8113dddc>] perf_trace_destroy+0x3c/0x50
> [ 5448.805285] [<ffffffff81152e59>] tp_perf_event_destroy+0x9/0x10
> [ 5448.812218] [<ffffffff81158f61>] _free_event+0xc1/0x250
> [ 5448.818384] [<ffffffff811591fa>] put_event+0x10a/0x150
> [ 5448.824422] [<ffffffff8115911b>] ? put_event+0x2b/0x150
> [ 5448.830593] [<ffffffff81152db5>] ? perf_fasync+0x55/0x70
> [ 5448.836862] [<ffffffff81159260>] perf_release+0x10/0x20
> [ 5448.843023] [<ffffffff811df3ec>] __fput+0xdc/0x1e0
> [ 5448.848709] [<ffffffff811df53e>] ____fput+0xe/0x10
> [ 5448.854382] [<ffffffff8108c27b>] task_work_run+0x9b/0xb0
> [ 5448.860620] [<ffffffff81071615>] do_exit+0x3a5/0xa90
> [ 5448.866469] [<ffffffff8107d182>] ? get_signal+0xe2/0x720
> [ 5448.872714] [<ffffffff81071da4>] do_group_exit+0x54/0xe0
> [ 5448.878990] [<ffffffff8107d320>] get_signal+0x280/0x720
> [ 5448.885163] [<ffffffff81013478>] do_signal+0x28/0xb50
> [ 5448.891117] [<ffffffff810b78f6>] ? __lock_acquire.isra.31+0x3a6/0xf90
> [ 5448.898586] [<ffffffff810815a5>] ? sys_getppid+0x5/0x80
> [ 5448.904712] [<ffffffff81014002>] do_notify_resume+0x62/0x70
> [ 5448.911245] [<ffffffff816a9a1e>] retint_signal+0x44/0x86
> [ 5448.917526] ---[ end trace 5d38212a775ec3f6 ]---
>
>
--
Masami HIRAMATSU
Linux Technology Research Center, System Productivity Research Dept.
Center for Technology Innovation - Systems Engineering
Hitachi, Ltd., Research & Development Group
E-mail: masami.hiramatsu.pt@hitachi.com
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: Re: perf, kprobes: fuzzer generates huge number of WARNings
2015-07-07 21:21 ` Alexei Starovoitov
@ 2015-07-08 13:11 ` Masami Hiramatsu
0 siblings, 0 replies; 16+ messages in thread
From: Masami Hiramatsu @ 2015-07-08 13:11 UTC (permalink / raw)
To: Alexei Starovoitov, Vince Weaver
Cc: linux-kernel, Ananth N Mavinakayanahalli, Anil S Keshavamurthy,
David S. Miller, Peter Zijlstra, Ingo Molnar,
Arnaldo Carvalho de Melo, Steven Rostedt
On 2015/07/08 6:21, Alexei Starovoitov wrote:
> On Tue, Jul 07, 2015 at 05:08:51PM -0400, Vince Weaver wrote:
>> On Tue, 7 Jul 2015, Alexei Starovoitov wrote:
>>
>>> On Tue, Jul 07, 2015 at 12:00:12AM -0400, Vince Weaver wrote:
>>>>
>>>> Well the BPF hack is in the fuzzer, not the kernel. And it's not really a
>>>> hack, it just turned out to be a huge pain to figure out how to
>>>> manually create a valid BPF program in conjunction with a valid kprobe
>>>> event.
>>>
>>> You mean automatically generating valid bpf program? That's definitely hard.
>>> If you mean just few hardcoded programs then take them from samples or
>>> from test_bpf ?
>>
>> there's already code in trinity that in theory autogenerates bpf programs,
>> but for now I was just trying to hook up a short known valid one.
>>
>> it might not be possible to really test things though, as you need to be
>> root to create a kprobe and attach a BPF program, but my fuzzer when run
>> as root often does all kinds of other stuff that will crash a machine.
>> Is it ever planned to allow using bpf/kprobes without requiring full
>> CAP_ADMIN privledges?
>
> I suspect kprobes will forever be root only, whereas for bpf I'm thinking
> to introduce CAP_BPF, but before that we need to finish constant blinding
> and add address leak prevention. So not soon.
Currently I don't plan to do that. Actually systemtap allows that, but
with much bigger blacklist. I think we can make a tool which also
allows user to add new events on the limited functions (white-list).
But anyway, since these can expose kernel function addresses to users,
it is highly recommended to limit users by some capabilities.
>>>> I did have to sprinkle printks in the kprobe and bpf code to find out
>>>> where various EINVAL returns were coming from, so potentially this is just
>>>> a problem of printks happening where they shouldn't. I'll remove those
>>>> changes and try to reproduce this tomorrow.
>>>
>>> could you please elaborate on this further. Which EINVALs you talking about?
>>
>> When you are trying to create a kprobe and bpf file there's about 10
>> different ways to get EINVAL as a return value and no way of knowing which
>> one you are hitting. I added printks so I could know what issue was
>> causing the einval. (from memory, the problems I hit were not zeroing out
>> the attr structure, having a wrong instruction count, and a few others).
Hmm I must fix some parts of kprobes by changing retval or showing more
precise messages.
Thanks!
> I see. I guess anyone trying to use syscall directly will be facing such
> issues, but libbpf that is being developed to be used by perf and others
> should solve these problems.
--
Masami HIRAMATSU
Linux Technology Research Center, System Productivity Research Dept.
Center for Technology Innovation - Systems Engineering
Hitachi, Ltd., Research & Development Group
E-mail: masami.hiramatsu.pt@hitachi.com
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: Re: perf, kprobes: fuzzer generates huge number of WARNings
2015-07-07 15:11 ` Vince Weaver
@ 2015-07-09 9:58 ` Masami Hiramatsu
0 siblings, 0 replies; 16+ messages in thread
From: Masami Hiramatsu @ 2015-07-09 9:58 UTC (permalink / raw)
To: Vince Weaver
Cc: linux-kernel, Ananth N Mavinakayanahalli, Anil S Keshavamurthy,
David S. Miller, Peter Zijlstra, Ingo Molnar,
Arnaldo Carvalho de Melo, Steven Rostedt
On 2015/07/08 0:11, Vince Weaver wrote:
> On Tue, 7 Jul 2015, Vince Weaver wrote:
>
>> On Tue, 7 Jul 2015, Masami Hiramatsu wrote:
>>
>>>> It's a Hawell machine running 4.2-rc1. I can post the .config if it's of
>>>> interest.
>>>
>>> Yes, I'm interested in.
>>
>> I've put it here:
>> http://web.eece.maine.edu/~vweaver/junk/haswell-config
>>
>>> OK, and also, if you have a chance, please run the ftracetest as below.
>>>
>>> $ cd tools/testing/selftest/ftrace/
>>> $ sudo ./ftracetest
>>>
>>> This will do a series of basic tests on ftrace and report it.
>>
>> It won't run:
>> sudo ./ftracetest
>> Error: No ftrace directory found
>>
>
> OK here are the results when I mounted debugfs in the right place.
Thanks, I've found do_fork does not exist anymore... that caused the
failure.
Unsupported results are just because of the lack of function profiler
from kconfig.
Thank you for reporting!
>
> sudo ./ftracetest
> === Ftrace unit tests ===
> [1] Basic trace file check [PASS]
> [2] Basic test for tracers [PASS]
> [3] Basic trace clock test [PASS]
> [4] Basic event tracing check [PASS]
> [5] event tracing - enable/disable with event level files [PASS]
> [6] event tracing - enable/disable with subsystem level files [PASS]
> [7] event tracing - enable/disable with top level files [PASS]
> [8] ftrace - function graph filters with stack tracer [UNSUPPORTED]
> execute:
> /home/vince/research/linux-kernel/linux-git/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter-stack.tc
> + .
> /home/vince/research/linux-kernel/linux-git/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter-stack.tc
> + grep -q function_graph available_tracers
> + [ ! -f set_ftrace_filter ]
> + disable_tracing
> + echo 0
> + clear_trace
> + echo
> + echo schedule
> + echo function_graph
> + [ ! -f stack_trace ]
> + echo Stack tracer not configured
> Stack tracer not configured
> + do_reset
> + reset_tracer
> + echo nop
> + [ -e /proc/sys/kernel/stack_tracer_enabled ]
> + enable_tracing
> + echo 1
> + clear_trace
> + echo
> + echo
> + exit_unsupported
> + kill -s 40 2725
> + exit 0
> [9] ftrace - function graph filters [PASS]
> [10] ftrace - function profiler with function tracing [UNSUPPORTED]
> execute:
> /home/vince/research/linux-kernel/linux-git/tools/testing/selftests/ftrace/test.d/ftrace/func_profiler.tc
> + .
> /home/vince/research/linux-kernel/linux-git/tools/testing/selftests/ftrace/test.d/ftrace/func_profiler.tc
> + grep -q function_graph available_tracers
> + [ ! -f set_ftrace_filter ]
> + [ ! -f function_profile_enabled ]
> + echo function_profile_enabled not found, function profiling enabled?
> function_profile_enabled not found, function profiling enabled?
> + exit_unsupported
> + kill -s 40 2725
> + exit 0
> [11] Kprobe dynamic event - adding and removing [FAIL]
> execute:
> /home/vince/research/linux-kernel/linux-git/tools/testing/selftests/ftrace/test.d/kprobe/add_and_remove.tc
> + .
> /home/vince/research/linux-kernel/linux-git/tools/testing/selftests/ftrace/test.d/kprobe/add_and_remove.tc
> + [ -f kprobe_events ]
> + echo 0
> + echo
> + echo p:myevent do_fork
> sh: echo: I/O error
> [12] Kprobe dynamic event - busy event check [FAIL]
> execute:
> /home/vince/research/linux-kernel/linux-git/tools/testing/selftests/ftrace/test.d/kprobe/busy_check.tc
> + .
> /home/vince/research/linux-kernel/linux-git/tools/testing/selftests/ftrace/test.d/kprobe/busy_check.tc
> + [ -f kprobe_events ]
> + echo 0
> + echo
> + echo p:myevent do_fork
> sh: echo: I/O error
> [13] Kprobe dynamic event with arguments [FAIL]
> execute:
> /home/vince/research/linux-kernel/linux-git/tools/testing/selftests/ftrace/test.d/kprobe/kprobe_args.tc
> + .
> /home/vince/research/linux-kernel/linux-git/tools/testing/selftests/ftrace/test.d/kprobe/kprobe_args.tc
> + [ -f kprobe_events ]
> + echo 0
> + echo
> + echo p:testprobe do_fork $stack $stack0 +0($stack)
> sh: echo: I/O error
> [14] Kprobe dynamic event with function tracer [FAIL]
> execute:
> /home/vince/research/linux-kernel/linux-git/tools/testing/selftests/ftrace/test.d/kprobe/kprobe_ftrace.tc
> + .
> /home/vince/research/linux-kernel/linux-git/tools/testing/selftests/ftrace/test.d/kprobe/kprobe_ftrace.tc
> + [ -f kprobe_events ]
> + grep function available_tracers
> blk function_graph function nop
> + echo nop
> + echo do_fork
> sh: echo: I/O error
> [15] Kretprobe dynamic event with arguments [FAIL]
> execute:
> /home/vince/research/linux-kernel/linux-git/tools/testing/selftests/ftrace/test.d/kprobe/kretprobe_args.tc
> + .
> /home/vince/research/linux-kernel/linux-git/tools/testing/selftests/ftrace/test.d/kprobe/kretprobe_args.tc
> + [ -f kprobe_events ]
> + echo 0
> + echo
> + echo r:testprobe2 do_fork $retval
> sh: echo: I/O error
>
> # of passed: 8
> # of failed: 5
> # of unresolved: 0
> # of untested: 0
> # of unsupported: 2
> # of xfailed: 0
> # of undefined(test bug): 0
>
>
--
Masami HIRAMATSU
Linux Technology Research Center, System Productivity Research Dept.
Center for Technology Innovation - Systems Engineering
Hitachi, Ltd., Research & Development Group
E-mail: masami.hiramatsu.pt@hitachi.com
^ permalink raw reply [flat|nested] 16+ messages in thread
end of thread, other threads:[~2015-07-09 9:58 UTC | newest]
Thread overview: 16+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2015-07-06 21:27 perf, kprobes: fuzzer generates huge number of WARNings Vince Weaver
2015-07-06 21:29 ` Steven Rostedt
2015-07-07 3:53 ` Vince Weaver
2015-07-07 2:25 ` Masami Hiramatsu
2015-07-07 4:00 ` Vince Weaver
2015-07-07 10:35 ` Masami Hiramatsu
2015-07-07 15:06 ` Vince Weaver
2015-07-07 15:10 ` Steven Rostedt
2015-07-07 18:06 ` Vince Weaver
2015-07-08 3:13 ` Masami Hiramatsu
2015-07-07 15:11 ` Vince Weaver
2015-07-09 9:58 ` Masami Hiramatsu
2015-07-07 19:18 ` Alexei Starovoitov
2015-07-07 21:08 ` Vince Weaver
2015-07-07 21:21 ` Alexei Starovoitov
2015-07-08 13:11 ` Masami Hiramatsu
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).