Re: Re: perf, kprobes: fuzzer generates huge number of WARNings
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
Re: Re: perf, kprobes: fuzzer generates huge number of WARNings
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:
Re: Re: perf, kprobes: fuzzer generates huge number of WARNings
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...@hitachi.com -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: Re: perf, kprobes: fuzzer generates huge number of WARNings
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...@hitachi.com -- To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: perf, kprobes: fuzzer generates huge number of WARNings
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 81196670 (-19)
The corresponding code is
ret = ftrace_set_filter_ip(_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: GW
> 4.2.0-rc1+ #169
> [ 5447.732454] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS
> 01/26/2014
> [ 5447.740897] 81a2894e 8801161b3bf8 816a0fd3
>
> [ 5447.749426] 8801161b3c48 8801161b3c38 8106ec8a
> aed0
> [ 5447.757931] 88011847b810 8800cd8b8000
> 81d25640
> [ 5447.766463] Call Trace:
> [ 5447.769567] [] dump_stack+0x45/0x57
> [ 5447.775569] [] warn_slowpath_common+0x8a/0xc0
> [ 5447.782504] [] warn_slowpath_fmt+0x46/0x50
> [ 5447.789111] [] ? pcpu_alloc+0x36a/0x630
> [ 5447.795466] [] ? vm_insert_mixed+0x40/0x40
> [ 5447.802098] [] arm_kprobe+0xe3/0xf0
> [ 5447.808095] [] enable_kprobe+0x78/0x80
> [ 5447.814353] [] kprobe_register+0x59/0xe0
> [ 5447.820805] [] perf_trace_init+0x1b5/0x2c0
> [ 5447.827471] [] perf_tp_event_init+0x2a/0x50
> [ 5447.834197] [] perf_try_init_event+0x8b/0xa0
> [ 5447.841012] [] perf_init_event+0x133/0x160
> [ 5447.847658] [] ? perf_bp_event+0x90/0x90
> [ 5447.854101] [] perf_event_alloc+0x42a/0x680
> [ 5447.860840] [] SYSC_perf_event_open+0x3c7/0xd20
> [ 5447.867949] [] SyS_perf_event_open+0x9/0x10
> [ 5447.874702] [] 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: GW
> 4.2.0-rc1+ #169
> [ 5447.994611] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS
> 01/26/2014
> [ 5448.003174] 81a2894e 8801161b3bf8 816a0fd3
>
> [ 5448.011805] 8801161b3c48 8801161b3c38 8106ec8a
> 81125c1a
> [ 5448.020424] 88011847b810 8800cd8b8000
> 81d25640
> [ 5448.029074] Call Trace:
> [ 5448.032265] [] dump_stack+0x45/0x57
> [ 5448.038342] [] warn_slowpath_common+0x8a/0xc0
> [ 5448.045376] [] ? register_ftrace_function+0x4a/0x70
> [ 5448.052930] [] warn_slowpath_fmt+0x46/0x50
> [ 5448.059617] [] ? mutex_unlock+0xe/0x10
> [ 5448.065951] [] arm_kprobe+0xae/0xf0
> [ 5448.072003] [] enable_kprobe+0x78/0x80
> [ 5448.078341] [] kprobe_register+0x59/0xe0
> [ 5448.084823] [] perf_trace_init+0x1b5/0x2c0
> [ 5448.091484] [] perf_tp_event_init+0x2a/0x50
> [ 5448.098212] [] perf_try_init_event+0x8b/0xa0
> [ 5448.105068] [] perf_init_event+0x133/0x160
> [ 5448.111689] [] ? perf_bp_event+0x90/0x90
> [ 5448.118116] [] perf_event_alloc+0x42a/0x680
> [ 5448.124825] [] SYSC_perf_event_open+0x3c7/0xd20
> [ 5448.131946] [] SyS_perf_event_open+0x9/0x10
> [ 5448.138640] [] 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: GW
> 4.2.0-rc1+ #169
> [ 5448.336416] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS
> 01/26/2014
>
Re: perf, kprobes: fuzzer generates huge number of WARNings
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. -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: perf, kprobes: fuzzer generates huge number of WARNings
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 -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: perf, kprobes: fuzzer generates huge number of WARNings
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? -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: perf, kprobes: fuzzer generates huge number of WARNings
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 81196670 (-19) [ 5447.723237] CPU: 1 PID: 4158 Comm: perf_fuzzer Tainted: GW 4.2.0-rc1+ #169 [ 5447.732454] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS 01/26/2014 [ 5447.740897] 81a2894e 8801161b3bf8 816a0fd3 [ 5447.749426] 8801161b3c48 8801161b3c38 8106ec8a aed0 [ 5447.757931] 88011847b810 8800cd8b8000 81d25640 [ 5447.766463] Call Trace: [ 5447.769567] [] dump_stack+0x45/0x57 [ 5447.775569] [] warn_slowpath_common+0x8a/0xc0 [ 5447.782504] [] warn_slowpath_fmt+0x46/0x50 [ 5447.789111] [] ? pcpu_alloc+0x36a/0x630 [ 5447.795466] [] ? vm_insert_mixed+0x40/0x40 [ 5447.802098] [] arm_kprobe+0xe3/0xf0 [ 5447.808095] [] enable_kprobe+0x78/0x80 [ 5447.814353] [] kprobe_register+0x59/0xe0 [ 5447.820805] [] perf_trace_init+0x1b5/0x2c0 [ 5447.827471] [] perf_tp_event_init+0x2a/0x50 [ 5447.834197] [] perf_try_init_event+0x8b/0xa0 [ 5447.841012] [] perf_init_event+0x133/0x160 [ 5447.847658] [] ? perf_bp_event+0x90/0x90 [ 5447.854101] [] perf_event_alloc+0x42a/0x680 [ 5447.860840] [] SYSC_perf_event_open+0x3c7/0xd20 [ 5447.867949] [] SyS_perf_event_open+0x9/0x10 [ 5447.874702] [] 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: GW 4.2.0-rc1+ #169 [ 5447.994611] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS 01/26/2014 [ 5448.003174] 81a2894e 8801161b3bf8 816a0fd3 [ 5448.011805] 8801161b3c48 8801161b3c38 8106ec8a 81125c1a [ 5448.020424] 88011847b810 8800cd8b8000 81d25640 [ 5448.029074] Call Trace: [ 5448.032265] [] dump_stack+0x45/0x57 [ 5448.038342] [] warn_slowpath_common+0x8a/0xc0 [ 5448.045376] [] ? register_ftrace_function+0x4a/0x70 [ 5448.052930] [] warn_slowpath_fmt+0x46/0x50 [ 5448.059617] [] ? mutex_unlock+0xe/0x10 [ 5448.065951] [] arm_kprobe+0xae/0xf0 [ 5448.072003] [] enable_kprobe+0x78/0x80 [ 5448.078341] [] kprobe_register+0x59/0xe0 [ 5448.084823] [] perf_trace_init+0x1b5/0x2c0 [ 5448.091484] [] perf_tp_event_init+0x2a/0x50 [ 5448.098212] [] perf_try_init_event+0x8b/0xa0 [ 5448.105068] [] perf_init_event+0x133/0x160 [ 5448.111689] [] ? perf_bp_event+0x90/0x90 [ 5448.118116] [] perf_event_alloc+0x42a/0x680 [ 5448.124825] [] SYSC_perf_event_open+0x3c7/0xd20 [ 5448.131946] [] SyS_perf_event_open+0x9/0x10 [ 5448.138640] [] 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: GW 4.2.0-rc1+ #169 [ 5448.336416] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS 01/26/2014 [ 5448.344935] 81a2894e 8801187a79e8 816a0fd3 [ 5448.353549] 8801187a7a38 8801187a7a28 8106ec8a 81124f6a [ 5448.362177] 88011847b810 88011847b810 88011847b800 8801160c02a8 [ 5448.370824] Call Trace: [ 5448.374033] [] dump_stack+0x45/0x57 [ 5448.380146] [] warn_slowpath_common+0x8a/0xc0 [ 5448.387148] [] ? unregister_ftrace_function+0x1a/0x50 [ 5448.394880] [] warn_slowpath_fmt+0x46/0x50 [ 5448.401603] [] ? mutex_unlock+0xe/0x10 [ 5448.407920] [] disarm_kprobe+0xf8/0x100 [ 5448.414326] [] __disable_kprobe+0x99/0xc0 [ 5448.420874] [] disable_kprobe+0x27/0x50 [ 5448.427222] [] disable_trace_kprobe+0xc3/0xf0 [ 5448.434140] [] kprobe_register+0x2d/0xe0 [ 5448.440586] [] perf_trace_event_unreg.isra.1+0x33/0x90 [ 5448.448349] [] perf_trace_destroy+0x3c/0x50 [ 5448.455058] [] tp_perf_event_destroy+0x9/0x10 [ 5448.461945] [] _free_event+0xc1/0x250 [ 5448.468093] [] put_event+0x10a/0x150 [ 5448.474167] [] ? put_event+0x2b/0x150 [ 5448.480313] [] ? perf_fasync+0x55/0x70 [ 5448.486552] [] perf_release+0x10/0x20 [ 5448.492735] [] __fput+0xdc/0x1e0 [ 5448.498420] []
Re: perf, kprobes: fuzzer generates huge number of WARNings
On Tue, 7 Jul 2015 11:06:55 -0400 (EDT)
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
>
> 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(0x81196730) is not an instruction
> boundary.
> [ 290.131191] Could not insert probe at _text+1664816: -84
> [ 290.137555] Probing address(0x81196730) is not an instruction
> boundary.
> [ 290.170513] Could not insert probe at _text+1664816: -84
> [ 290.176877] Probing address(0x81196730) is not an instruction
> boundary.
> [ 290.298940] Could not insert probe at _text+1664816: -84
> [ 290.305224] Probing address(0x81196730) is not an instruction
> boundary.
> [ 290.349272] Could not insert probe at _text+1664816: -84
> [ 290.355585] Probing address(0x81196730) is not an instruction
> boundary.
> [ 290.365738] Could not insert probe at _text+1664816: -84
> [ 290.371992] Probing address(0x81196730) 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 task0 1736 1
> 0x0008
> [ 311.439865] 0286 00010005 0096
> 0002
> [ 311.448549] 0286 81c4b2e0 81c4b2e0
> 828da234
> [ 311.457173] 1f2f 7fa62335fe11 0071
> 828da234
> [ 311.465865] Call Trace:
> [ 311.469098] [] ? do_syslog+0x456/0x500
> [ 311.475518] [] ? wait_woken+0x90/0x90
> [ 311.481830] [] ? kmsg_read+0x44/0x60
> [ 311.488040] [] ? mutex_unlock+0xe/0x10
> [ 311.494433] [] ? calibrate_delay+0x8f0/0x8f0
> [ 311.501356] [] ? retint_check+0x6/0x12
> [ 313.873152] hrtimer: interrupt took 14075878236 ns
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majord...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: perf, kprobes: fuzzer generates huge number of WARNings
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 -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: perf, kprobes: fuzzer generates huge number of WARNings
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(0x81196730) is not an instruction
boundary.
[ 290.131191] Could not insert probe at _text+1664816: -84
[ 290.137555] Probing address(0x81196730) is not an instruction
boundary.
[ 290.170513] Could not insert probe at _text+1664816: -84
[ 290.176877] Probing address(0x81196730) is not an instruction
boundary.
[ 290.298940] Could not insert probe at _text+1664816: -84
[ 290.305224] Probing address(0x81196730) is not an instruction
boundary.
[ 290.349272] Could not insert probe at _text+1664816: -84
[ 290.355585] Probing address(0x81196730) is not an instruction
boundary.
[ 290.365738] Could not insert probe at _text+1664816: -84
[ 290.371992] Probing address(0x81196730) 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 task0 1736 1 0x0008
[ 311.439865] 0286 00010005 0096
0002
[ 311.448549] 0286 81c4b2e0 81c4b2e0
828da234
[ 311.457173] 1f2f 7fa62335fe11 0071
828da234
[ 311.465865] Call Trace:
[ 311.469098] [] ? do_syslog+0x456/0x500
[ 311.475518] [] ? wait_woken+0x90/0x90
[ 311.481830] [] ? kmsg_read+0x44/0x60
[ 311.488040] [] ? mutex_unlock+0xe/0x10
[ 311.494433] [] ? calibrate_delay+0x8f0/0x8f0
[ 311.501356] [] ? retint_check+0x6/0x12
[ 313.873152] hrtimer: interrupt took 14075878236 ns
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majord...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: perf, kprobes: fuzzer generates huge number of WARNings
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...@hitachi.com -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: perf, kprobes: fuzzer generates huge number of WARNings
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? -- To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: perf, kprobes: fuzzer generates huge number of WARNings
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 81196670 (-19) [ 5447.723237] CPU: 1 PID: 4158 Comm: perf_fuzzer Tainted: GW 4.2.0-rc1+ #169 [ 5447.732454] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS 01/26/2014 [ 5447.740897] 81a2894e 8801161b3bf8 816a0fd3 [ 5447.749426] 8801161b3c48 8801161b3c38 8106ec8a aed0 [ 5447.757931] 88011847b810 8800cd8b8000 81d25640 [ 5447.766463] Call Trace: [ 5447.769567] [816a0fd3] dump_stack+0x45/0x57 [ 5447.775569] [8106ec8a] warn_slowpath_common+0x8a/0xc0 [ 5447.782504] [8106ed06] warn_slowpath_fmt+0x46/0x50 [ 5447.789111] [8118996a] ? pcpu_alloc+0x36a/0x630 [ 5447.795466] [81196670] ? vm_insert_mixed+0x40/0x40 [ 5447.802098] [81119083] arm_kprobe+0xe3/0xf0 [ 5447.808095] [81119108] enable_kprobe+0x78/0x80 [ 5447.814353] [81143489] kprobe_register+0x59/0xe0 [ 5447.820805] [8113dc95] perf_trace_init+0x1b5/0x2c0 [ 5447.827471] [81152e2a] perf_tp_event_init+0x2a/0x50 [ 5447.834197] [8115442b] perf_try_init_event+0x8b/0xa0 [ 5447.841012] [8115bec3] perf_init_event+0x133/0x160 [ 5447.847658] [8115bd90] ? perf_bp_event+0x90/0x90 [ 5447.854101] [8115c31a] perf_event_alloc+0x42a/0x680 [ 5447.860840] [8115c937] SYSC_perf_event_open+0x3c7/0xd20 [ 5447.867949] [8115d709] SyS_perf_event_open+0x9/0x10 [ 5447.874702] [816a8d32] 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: GW 4.2.0-rc1+ #169 [ 5447.994611] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS 01/26/2014 [ 5448.003174] 81a2894e 8801161b3bf8 816a0fd3 [ 5448.011805] 8801161b3c48 8801161b3c38 8106ec8a 81125c1a [ 5448.020424] 88011847b810 8800cd8b8000 81d25640 [ 5448.029074] Call Trace: [ 5448.032265] [816a0fd3] dump_stack+0x45/0x57 [ 5448.038342] [8106ec8a] warn_slowpath_common+0x8a/0xc0 [ 5448.045376] [81125c1a] ? register_ftrace_function+0x4a/0x70 [ 5448.052930] [8106ed06] warn_slowpath_fmt+0x46/0x50 [ 5448.059617] [816a686e] ? mutex_unlock+0xe/0x10 [ 5448.065951] [8111904e] arm_kprobe+0xae/0xf0 [ 5448.072003] [81119108] enable_kprobe+0x78/0x80 [ 5448.078341] [81143489] kprobe_register+0x59/0xe0 [ 5448.084823] [8113dc95] perf_trace_init+0x1b5/0x2c0 [ 5448.091484] [81152e2a] perf_tp_event_init+0x2a/0x50 [ 5448.098212] [8115442b] perf_try_init_event+0x8b/0xa0 [ 5448.105068] [8115bec3] perf_init_event+0x133/0x160 [ 5448.111689] [8115bd90] ? perf_bp_event+0x90/0x90 [ 5448.118116] [8115c31a] perf_event_alloc+0x42a/0x680 [ 5448.124825] [8115c937] SYSC_perf_event_open+0x3c7/0xd20 [ 5448.131946] [8115d709] SyS_perf_event_open+0x9/0x10 [ 5448.138640] [816a8d32] 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: GW 4.2.0-rc1+ #169 [ 5448.336416] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS 01/26/2014 [ 5448.344935] 81a2894e 8801187a79e8 816a0fd3 [ 5448.353549] 8801187a7a38 8801187a7a28 8106ec8a 81124f6a [ 5448.362177] 88011847b810 88011847b810 88011847b800 8801160c02a8 [ 5448.370824] Call Trace: [ 5448.374033] [816a0fd3] dump_stack+0x45/0x57 [ 5448.380146] [8106ec8a] warn_slowpath_common+0x8a/0xc0 [ 5448.387148] [81124f6a] ? unregister_ftrace_function+0x1a/0x50 [ 5448.394880] [8106ed06] warn_slowpath_fmt+0x46/0x50 [ 5448.401603] [816a686e] ? mutex_unlock+0xe/0x10 [ 5448.407920] [81119208]
Re: perf, kprobes: fuzzer generates huge number of WARNings
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 -- To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: perf, kprobes: fuzzer generates huge number of WARNings
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. -- To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: perf, kprobes: fuzzer generates huge number of WARNings
On Tue, 7 Jul 2015 11:06:55 -0400 (EDT)
Vince Weaver vincent.wea...@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(0x81196730) is not an instruction
boundary.
[ 290.131191] Could not insert probe at _text+1664816: -84
[ 290.137555] Probing address(0x81196730) is not an instruction
boundary.
[ 290.170513] Could not insert probe at _text+1664816: -84
[ 290.176877] Probing address(0x81196730) is not an instruction
boundary.
[ 290.298940] Could not insert probe at _text+1664816: -84
[ 290.305224] Probing address(0x81196730) is not an instruction
boundary.
[ 290.349272] Could not insert probe at _text+1664816: -84
[ 290.355585] Probing address(0x81196730) is not an instruction
boundary.
[ 290.365738] Could not insert probe at _text+1664816: -84
[ 290.371992] Probing address(0x81196730) 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 task0 1736 1
0x0008
[ 311.439865] 0286 00010005 0096
0002
[ 311.448549] 0286 81c4b2e0 81c4b2e0
828da234
[ 311.457173] 1f2f 7fa62335fe11 0071
828da234
[ 311.465865] Call Trace:
[ 311.469098] [810c8886] ? do_syslog+0x456/0x500
[ 311.475518] [810b02a0] ? wait_woken+0x90/0x90
[ 311.481830] [81255bb4] ? kmsg_read+0x44/0x60
[ 311.488040] [816a686e] ? mutex_unlock+0xe/0x10
[ 311.494433] [81003000] ? calibrate_delay+0x8f0/0x8f0
[ 311.501356] [816a98e5] ? retint_check+0x6/0x12
[ 313.873152] hrtimer: interrupt took 14075878236 ns
--
To unsubscribe from this list: send the line unsubscribe linux-kernel in
the body of a message to majord...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: perf, kprobes: fuzzer generates huge number of WARNings
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...@hitachi.com -- To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: perf, kprobes: fuzzer generates huge number of WARNings
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 81196670 (-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: GW
4.2.0-rc1+ #169
[ 5447.732454] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS
01/26/2014
[ 5447.740897] 81a2894e 8801161b3bf8 816a0fd3
[ 5447.749426] 8801161b3c48 8801161b3c38 8106ec8a
aed0
[ 5447.757931] 88011847b810 8800cd8b8000
81d25640
[ 5447.766463] Call Trace:
[ 5447.769567] [816a0fd3] dump_stack+0x45/0x57
[ 5447.775569] [8106ec8a] warn_slowpath_common+0x8a/0xc0
[ 5447.782504] [8106ed06] warn_slowpath_fmt+0x46/0x50
[ 5447.789111] [8118996a] ? pcpu_alloc+0x36a/0x630
[ 5447.795466] [81196670] ? vm_insert_mixed+0x40/0x40
[ 5447.802098] [81119083] arm_kprobe+0xe3/0xf0
[ 5447.808095] [81119108] enable_kprobe+0x78/0x80
[ 5447.814353] [81143489] kprobe_register+0x59/0xe0
[ 5447.820805] [8113dc95] perf_trace_init+0x1b5/0x2c0
[ 5447.827471] [81152e2a] perf_tp_event_init+0x2a/0x50
[ 5447.834197] [8115442b] perf_try_init_event+0x8b/0xa0
[ 5447.841012] [8115bec3] perf_init_event+0x133/0x160
[ 5447.847658] [8115bd90] ? perf_bp_event+0x90/0x90
[ 5447.854101] [8115c31a] perf_event_alloc+0x42a/0x680
[ 5447.860840] [8115c937] SYSC_perf_event_open+0x3c7/0xd20
[ 5447.867949] [8115d709] SyS_perf_event_open+0x9/0x10
[ 5447.874702] [816a8d32] 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: GW
4.2.0-rc1+ #169
[ 5447.994611] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS
01/26/2014
[ 5448.003174] 81a2894e 8801161b3bf8 816a0fd3
[ 5448.011805] 8801161b3c48 8801161b3c38 8106ec8a
81125c1a
[ 5448.020424] 88011847b810 8800cd8b8000
81d25640
[ 5448.029074] Call Trace:
[ 5448.032265] [816a0fd3] dump_stack+0x45/0x57
[ 5448.038342] [8106ec8a] warn_slowpath_common+0x8a/0xc0
[ 5448.045376] [81125c1a] ? register_ftrace_function+0x4a/0x70
[ 5448.052930] [8106ed06] warn_slowpath_fmt+0x46/0x50
[ 5448.059617] [816a686e] ? mutex_unlock+0xe/0x10
[ 5448.065951] [8111904e] arm_kprobe+0xae/0xf0
[ 5448.072003] [81119108] enable_kprobe+0x78/0x80
[ 5448.078341] [81143489] kprobe_register+0x59/0xe0
[ 5448.084823] [8113dc95] perf_trace_init+0x1b5/0x2c0
[ 5448.091484] [81152e2a] perf_tp_event_init+0x2a/0x50
[ 5448.098212] [8115442b] perf_try_init_event+0x8b/0xa0
[ 5448.105068] [8115bec3] perf_init_event+0x133/0x160
[ 5448.111689] [8115bd90] ? perf_bp_event+0x90/0x90
[ 5448.118116] [8115c31a] perf_event_alloc+0x42a/0x680
[ 5448.124825] [8115c937] SYSC_perf_event_open+0x3c7/0xd20
[ 5448.131946] [8115d709] SyS_perf_event_open+0x9/0x10
[ 5448.138640] [816a8d32]
Re: perf, kprobes: fuzzer generates huge number of WARNings
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(0x81196730) is not an instruction
boundary.
[ 290.131191] Could not insert probe at _text+1664816: -84
[ 290.137555] Probing address(0x81196730) is not an instruction
boundary.
[ 290.170513] Could not insert probe at _text+1664816: -84
[ 290.176877] Probing address(0x81196730) is not an instruction
boundary.
[ 290.298940] Could not insert probe at _text+1664816: -84
[ 290.305224] Probing address(0x81196730) is not an instruction
boundary.
[ 290.349272] Could not insert probe at _text+1664816: -84
[ 290.355585] Probing address(0x81196730) is not an instruction
boundary.
[ 290.365738] Could not insert probe at _text+1664816: -84
[ 290.371992] Probing address(0x81196730) 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 task0 1736 1 0x0008
[ 311.439865] 0286 00010005 0096
0002
[ 311.448549] 0286 81c4b2e0 81c4b2e0
828da234
[ 311.457173] 1f2f 7fa62335fe11 0071
828da234
[ 311.465865] Call Trace:
[ 311.469098] [810c8886] ? do_syslog+0x456/0x500
[ 311.475518] [810b02a0] ? wait_woken+0x90/0x90
[ 311.481830] [81255bb4] ? kmsg_read+0x44/0x60
[ 311.488040] [816a686e] ? mutex_unlock+0xe/0x10
[ 311.494433] [81003000] ? calibrate_delay+0x8f0/0x8f0
[ 311.501356] [816a98e5] ? retint_check+0x6/0x12
[ 313.873152] hrtimer: interrupt took 14075878236 ns
--
To unsubscribe from this list: send the line unsubscribe linux-kernel in
the body of a message to majord...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: perf, kprobes: fuzzer generates huge number of WARNings
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 -- To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: perf, kprobes: fuzzer generates huge number of WARNings
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 -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: perf, kprobes: fuzzer generates huge number of WARNings
On Mon, 6 Jul 2015, Steven Rostedt wrote: > On Mon, 6 Jul 2015 17:27:04 -0400 (EDT) > Vince Weaver wrote: > > [ 3521.650521] ---[ end trace a413501925547ed5 ]--- > > [ 3521.655960] ftrace failed to modify [] > > 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 -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: perf, kprobes: fuzzer generates huge number of WARNings
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] 81a28cf6 8800cd9f7b48 816a10a3 > > [ 3521.474274] 8800cd9f7b88 8106ec8a > 8800cd9f7b68 > [ 3521.482680] 880119bd7a80 81196730 880119bd7a80 > 17a8 > [ 3521.491143] Call Trace: > [ 3521.494128] [] dump_stack+0x45/0x57 > [ 3521.500016] [] warn_slowpath_common+0x8a/0xc0 > [ 3521.506810] [] ? vm_insert_mixed+0x40/0x40 > [ 3521.513389] [] warn_slowpath_null+0x1a/0x20 > [ 3521.520025] [] ftrace_bug+0x245/0x320 > [ 3521.526147] [] ftrace_replace_code+0x24c/0x360 > [ 3521.533102] [] ftrace_modify_all_code+0x9c/0x120 > [ 3521.540241] [] arch_ftrace_update_code+0x10/0x20 > [ 3521.547396] [] ftrace_run_update_code+0x20/0x80 > [ 3521.554425] [] ftrace_startup_enable+0x2f/0x40 > [ 3521.561376] [] ftrace_startup+0xd6/0x230 > [ 3521.567772] [] register_ftrace_function+0x54/0x70 > [ 3521.575025] [] perf_ftrace_event_register+0x47/0x140 > [ 3521.582537] [] perf_trace_init+0xc4/0x2c0 > [ 3521.589050] [] perf_tp_event_init+0x2a/0x50 > [ 3521.595771] [] perf_try_init_event+0x8b/0xa0 > [ 3521.602572] [] perf_init_event+0x133/0x160 > [ 3521.609181] [] ? perf_bp_event+0x90/0x90 > [ 3521.615647] [] perf_event_alloc+0x42a/0x680 > [ 3521.622388] [] SYSC_perf_event_open+0x3c7/0xd20 > [ 3521.629487] [] ? __do_page_fault+0x1ab/0x3f0 > [ 3521.636320] [] SyS_perf_event_open+0x9/0x10 > [ 3521.643087] [] entry_SYSCALL_64_fastpath+0x16/0x7a > [ 3521.650521] ---[ end trace a413501925547ed5 ]--- > [ 3521.655960] ftrace failed to modify [] > 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: ec02 > [ 3521.673993] (2) R tramp: 0xa009 expected tramp: > a009 > > > [ 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: GW > 4.2.0-rc1+ #168 > [ 3521.940498] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS > 01/26/2014 > [ 3521.948854] 81a28976 8800bf6d7a48 816a10a3 > > [ 3521.957335] 8800bf6d7a98 8800bf6d7a88 8106ec8a > 81124f6a > [ 3521.965839] 8800cd4e2010 8800cd4e2010 8800cd4e2000 > 8800cd28a000 > [ 3521.974275] Call Trace: > [ 3521.977335] [] dump_stack+0x45/0x57 > [ 3521.983302] [] warn_slowpath_common+0x8a/0xc0 > [ 3521.990170] [] ? unregister_ftrace_function+0x1a/0x50 > [ 3521.997784] [] warn_slowpath_fmt+0x46/0x50 > [ 3522.004418] [] ? mutex_unlock+0xe/0x10 > [ 3522.010640] [] disarm_kprobe+0xf8/0x100 > [ 3522.016972] [] __disable_kprobe+0x99/0xc0 > [ 3522.023491] [] disable_kprobe+0x27/0x50 > [ 3522.029827] [] disable_trace_kprobe+0xc3/0xf0 > [ 3522.036708] [] kprobe_register+0x2d/0xe0 > [ 3522.043102] [] perf_trace_event_unreg.isra.1+0x33/0x90 > [ 3522.050808] [] perf_trace_destroy+0x3c/0x50 > [ 3522.057482] [] tp_perf_event_destroy+0x9/0x10 > [ 3522.064354] [] _free_event+0xc1/0x250 > [ 3522.070474] [] ? put_event+0x2b/0x150 > [ 3522.076625] [] free_event+0x1f/0x50 > [ 3522.082531] [] perf_event_exit_task+0x245/0x300 > [ 3522.089575] [] do_exit+0x3b2/0xa90 > [ 3522.095444] [] ? get_signal+0xe2/0x720 > [ 3522.101659] [] do_group_exit+0x54/0xe0 > [ 3522.107892] [] get_signal+0x280/0x720 > [ 3522.114046] [] do_signal+0x28/0xb50 > [ 3522.119984] [] ? __lock_acquire.isra.31+0x3a6/0xf90 > [ 3522.127411] [] ?
Re: perf, kprobes: fuzzer generates huge number of WARNings
On Mon, 6 Jul 2015 17:27:04 -0400 (EDT) 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? > > 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] 81a28cf6 8800cd9f7b48 816a10a3 > > [ 3521.474274] 8800cd9f7b88 8106ec8a > 8800cd9f7b68 > [ 3521.482680] 880119bd7a80 81196730 880119bd7a80 > 17a8 > [ 3521.491143] Call Trace: > [ 3521.494128] [] dump_stack+0x45/0x57 > [ 3521.500016] [] warn_slowpath_common+0x8a/0xc0 > [ 3521.506810] [] ? vm_insert_mixed+0x40/0x40 > [ 3521.513389] [] warn_slowpath_null+0x1a/0x20 > [ 3521.520025] [] ftrace_bug+0x245/0x320 > [ 3521.526147] [] ftrace_replace_code+0x24c/0x360 > [ 3521.533102] [] ftrace_modify_all_code+0x9c/0x120 > [ 3521.540241] [] arch_ftrace_update_code+0x10/0x20 > [ 3521.547396] [] ftrace_run_update_code+0x20/0x80 > [ 3521.554425] [] ftrace_startup_enable+0x2f/0x40 > [ 3521.561376] [] ftrace_startup+0xd6/0x230 > [ 3521.567772] [] register_ftrace_function+0x54/0x70 > [ 3521.575025] [] perf_ftrace_event_register+0x47/0x140 > [ 3521.582537] [] perf_trace_init+0xc4/0x2c0 > [ 3521.589050] [] perf_tp_event_init+0x2a/0x50 > [ 3521.595771] [] perf_try_init_event+0x8b/0xa0 > [ 3521.602572] [] perf_init_event+0x133/0x160 > [ 3521.609181] [] ? perf_bp_event+0x90/0x90 > [ 3521.615647] [] perf_event_alloc+0x42a/0x680 > [ 3521.622388] [] SYSC_perf_event_open+0x3c7/0xd20 > [ 3521.629487] [] ? __do_page_fault+0x1ab/0x3f0 > [ 3521.636320] [] SyS_perf_event_open+0x9/0x10 > [ 3521.643087] [] entry_SYSCALL_64_fastpath+0x16/0x7a > [ 3521.650521] ---[ end trace a413501925547ed5 ]--- > [ 3521.655960] ftrace failed to modify [] > 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: ec02 > [ 3521.673993] (2) R tramp: 0xa009 expected tramp: > a009 > > > [ 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: GW > 4.2.0-rc1+ #168 > [ 3521.940498] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS > 01/26/2014 > [ 3521.948854] 81a28976 8800bf6d7a48 816a10a3 > > [ 3521.957335] 8800bf6d7a98 8800bf6d7a88 8106ec8a > 81124f6a > [ 3521.965839] 8800cd4e2010 8800cd4e2010 8800cd4e2000 > 8800cd28a000 > [ 3521.974275] Call Trace: > [ 3521.977335] [] dump_stack+0x45/0x57 > [ 3521.983302] [] warn_slowpath_common+0x8a/0xc0 > [ 3521.990170] [] ? unregister_ftrace_function+0x1a/0x50 > [ 3521.997784] [] warn_slowpath_fmt+0x46/0x50 > [ 3522.004418] [] ? mutex_unlock+0xe/0x10 > [ 3522.010640] [] disarm_kprobe+0xf8/0x100 > [ 3522.016972] [] __disable_kprobe+0x99/0xc0 > [ 3522.023491] [] disable_kprobe+0x27/0x50 > [ 3522.029827] [] disable_trace_kprobe+0xc3/0xf0 > [ 3522.036708] [] kprobe_register+0x2d/0xe0 > [ 3522.043102] [] perf_trace_event_unreg.isra.1+0x33/0x90 > [ 3522.050808] [] perf_trace_destroy+0x3c/0x50 > [ 3522.057482] [] tp_perf_event_destroy+0x9/0x10 > [ 3522.064354] [] _free_event+0xc1/0x250 > [ 3522.070474] [] ? put_event+0x2b/0x150 > [ 3522.076625] [] free_event+0x1f/0x50 > [ 3522.082531] [] perf_event_exit_task+0x245/0x300 > [ 3522.089575] [] do_exit+0x3b2/0xa90 > [ 3522.095444] [] ? get_signal+0xe2/0x720 > [ 3522.101659] [] do_group_exit+0x54/0xe0 > [ 3522.107892] [] get_signal+0x280/0x720 > [ 3522.114046] [] do_signal+0x28/0xb50 > [ 3522.119984] [] ? __lock_acquire.isra.31+0x3a6/0xf90 > [ 3522.127411] [] ? sys_getppid+0x5/0x80 > [ 3522.133563] [] do_notify_resume+0x62/0x70 > [ 3522.140084] [] 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 81196730 (-19) > [ 3522.251364] CPU:
perf, kprobes: fuzzer generates huge number of WARNings
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] 81a28cf6 8800cd9f7b48 816a10a3 [ 3521.474274] 8800cd9f7b88 8106ec8a 8800cd9f7b68 [ 3521.482680] 880119bd7a80 81196730 880119bd7a80 17a8 [ 3521.491143] Call Trace: [ 3521.494128] [] dump_stack+0x45/0x57 [ 3521.500016] [] warn_slowpath_common+0x8a/0xc0 [ 3521.506810] [] ? vm_insert_mixed+0x40/0x40 [ 3521.513389] [] warn_slowpath_null+0x1a/0x20 [ 3521.520025] [] ftrace_bug+0x245/0x320 [ 3521.526147] [] ftrace_replace_code+0x24c/0x360 [ 3521.533102] [] ftrace_modify_all_code+0x9c/0x120 [ 3521.540241] [] arch_ftrace_update_code+0x10/0x20 [ 3521.547396] [] ftrace_run_update_code+0x20/0x80 [ 3521.554425] [] ftrace_startup_enable+0x2f/0x40 [ 3521.561376] [] ftrace_startup+0xd6/0x230 [ 3521.567772] [] register_ftrace_function+0x54/0x70 [ 3521.575025] [] perf_ftrace_event_register+0x47/0x140 [ 3521.582537] [] perf_trace_init+0xc4/0x2c0 [ 3521.589050] [] perf_tp_event_init+0x2a/0x50 [ 3521.595771] [] perf_try_init_event+0x8b/0xa0 [ 3521.602572] [] perf_init_event+0x133/0x160 [ 3521.609181] [] ? perf_bp_event+0x90/0x90 [ 3521.615647] [] perf_event_alloc+0x42a/0x680 [ 3521.622388] [] SYSC_perf_event_open+0x3c7/0xd20 [ 3521.629487] [] ? __do_page_fault+0x1ab/0x3f0 [ 3521.636320] [] SyS_perf_event_open+0x9/0x10 [ 3521.643087] [] entry_SYSCALL_64_fastpath+0x16/0x7a [ 3521.650521] ---[ end trace a413501925547ed5 ]--- [ 3521.655960] ftrace failed to modify [] handle_mm_fault+0x0/0x1750 [ 3521.664767] actual: e8:cb:18:ef:1e [ 3521.669202] ftrace record flags: ec02 [ 3521.673993] (2) R tramp: 0xa009 expected tramp: a009 [ 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: GW 4.2.0-rc1+ #168 [ 3521.940498] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS 01/26/2014 [ 3521.948854] 81a28976 8800bf6d7a48 816a10a3 [ 3521.957335] 8800bf6d7a98 8800bf6d7a88 8106ec8a 81124f6a [ 3521.965839] 8800cd4e2010 8800cd4e2010 8800cd4e2000 8800cd28a000 [ 3521.974275] Call Trace: [ 3521.977335] [] dump_stack+0x45/0x57 [ 3521.983302] [] warn_slowpath_common+0x8a/0xc0 [ 3521.990170] [] ? unregister_ftrace_function+0x1a/0x50 [ 3521.997784] [] warn_slowpath_fmt+0x46/0x50 [ 3522.004418] [] ? mutex_unlock+0xe/0x10 [ 3522.010640] [] disarm_kprobe+0xf8/0x100 [ 3522.016972] [] __disable_kprobe+0x99/0xc0 [ 3522.023491] [] disable_kprobe+0x27/0x50 [ 3522.029827] [] disable_trace_kprobe+0xc3/0xf0 [ 3522.036708] [] kprobe_register+0x2d/0xe0 [ 3522.043102] [] perf_trace_event_unreg.isra.1+0x33/0x90 [ 3522.050808] [] perf_trace_destroy+0x3c/0x50 [ 3522.057482] [] tp_perf_event_destroy+0x9/0x10 [ 3522.064354] [] _free_event+0xc1/0x250 [ 3522.070474] [] ? put_event+0x2b/0x150 [ 3522.076625] [] free_event+0x1f/0x50 [ 3522.082531] [] perf_event_exit_task+0x245/0x300 [ 3522.089575] [] do_exit+0x3b2/0xa90 [ 3522.095444] [] ? get_signal+0xe2/0x720 [ 3522.101659] [] do_group_exit+0x54/0xe0 [ 3522.107892] [] get_signal+0x280/0x720 [ 3522.114046] [] do_signal+0x28/0xb50 [ 3522.119984] [] ? __lock_acquire.isra.31+0x3a6/0xf90 [ 3522.127411] [] ? sys_getppid+0x5/0x80 [ 3522.133563] [] do_notify_resume+0x62/0x70 [ 3522.140084] [] 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 81196730 (-19) [ 3522.251364] CPU: 2 PID: 5177 Comm: perf_fuzzer Tainted: GW 4.2.0-rc1+ #168 [ 3522.260488] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS 01/26/2014 [ 3522.268953] 81a28976 8800bf6d7a48 816a10a3 [ 3522.277482] 8800bf6d7a98 8800bf6d7a88 8106ec8a 81124f6a [ 3522.285993] 8800cd4e2010 8800cd4e2010 8800cd4e2000 8800cd28a000 [ 3522.294520] Call Trace: [
Re: perf, kprobes: fuzzer generates huge number of WARNings
On Mon, 6 Jul 2015 17:27:04 -0400 (EDT) Vince Weaver vincent.wea...@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] 81a28cf6 8800cd9f7b48 816a10a3 [ 3521.474274] 8800cd9f7b88 8106ec8a 8800cd9f7b68 [ 3521.482680] 880119bd7a80 81196730 880119bd7a80 17a8 [ 3521.491143] Call Trace: [ 3521.494128] [816a10a3] dump_stack+0x45/0x57 [ 3521.500016] [8106ec8a] warn_slowpath_common+0x8a/0xc0 [ 3521.506810] [81196730] ? vm_insert_mixed+0x40/0x40 [ 3521.513389] [8106ed7a] warn_slowpath_null+0x1a/0x20 [ 3521.520025] [81123425] ftrace_bug+0x245/0x320 [ 3521.526147] [81052d5c] ftrace_replace_code+0x24c/0x360 [ 3521.533102] [81123d3c] ftrace_modify_all_code+0x9c/0x120 [ 3521.540241] [81052e80] arch_ftrace_update_code+0x10/0x20 [ 3521.547396] [81123e30] ftrace_run_update_code+0x20/0x80 [ 3521.554425] [811244df] ftrace_startup_enable+0x2f/0x40 [ 3521.561376] [811256e6] ftrace_startup+0xd6/0x230 [ 3521.567772] [81125c24] register_ftrace_function+0x54/0x70 [ 3521.575025] [8113df07] perf_ftrace_event_register+0x47/0x140 [ 3521.582537] [8113dba4] perf_trace_init+0xc4/0x2c0 [ 3521.589050] [81152e8a] perf_tp_event_init+0x2a/0x50 [ 3521.595771] [8115448b] perf_try_init_event+0x8b/0xa0 [ 3521.602572] [8115bf63] perf_init_event+0x133/0x160 [ 3521.609181] [8115be30] ? perf_bp_event+0x90/0x90 [ 3521.615647] [8115c3ba] perf_event_alloc+0x42a/0x680 [ 3521.622388] [8115c9d7] SYSC_perf_event_open+0x3c7/0xd20 [ 3521.629487] [8105f86b] ? __do_page_fault+0x1ab/0x3f0 [ 3521.636320] [8115d7a9] SyS_perf_event_open+0x9/0x10 [ 3521.643087] [816a8df2] entry_SYSCALL_64_fastpath+0x16/0x7a [ 3521.650521] ---[ end trace a413501925547ed5 ]--- [ 3521.655960] ftrace failed to modify [81196730] 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: ec02 [ 3521.673993] (2) R tramp: 0xa009 expected tramp: a009 [ 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: GW 4.2.0-rc1+ #168 [ 3521.940498] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS 01/26/2014 [ 3521.948854] 81a28976 8800bf6d7a48 816a10a3 [ 3521.957335] 8800bf6d7a98 8800bf6d7a88 8106ec8a 81124f6a [ 3521.965839] 8800cd4e2010 8800cd4e2010 8800cd4e2000 8800cd28a000 [ 3521.974275] Call Trace: [ 3521.977335] [816a10a3] dump_stack+0x45/0x57 [ 3521.983302] [8106ec8a] warn_slowpath_common+0x8a/0xc0 [ 3521.990170] [81124f6a] ? unregister_ftrace_function+0x1a/0x50 [ 3521.997784] [8106ed06] warn_slowpath_fmt+0x46/0x50 [ 3522.004418] [816a693e] ? mutex_unlock+0xe/0x10 [ 3522.010640] [81119208] disarm_kprobe+0xf8/0x100 [ 3522.016972] [811192a9] __disable_kprobe+0x99/0xc0 [ 3522.023491] [811192f7] disable_kprobe+0x27/0x50 [ 3522.029827] [81142863] disable_trace_kprobe+0xc3/0xf0 [ 3522.036708] [8114345d] kprobe_register+0x2d/0xe0 [ 3522.043102] [8113da83] perf_trace_event_unreg.isra.1+0x33/0x90 [ 3522.050808] [8113dddc] perf_trace_destroy+0x3c/0x50 [ 3522.057482] [81152eb9] tp_perf_event_destroy+0x9/0x10 [ 3522.064354] [81158fc1] _free_event+0xc1/0x250 [ 3522.070474] [8115917b] ? put_event+0x2b/0x150 [ 3522.076625] [811592ef] free_event+0x1f/0x50 [ 3522.082531] [8115d9f5] perf_event_exit_task+0x245/0x300 [ 3522.089575] [81071622] do_exit+0x3b2/0xa90 [ 3522.095444]
perf, kprobes: fuzzer generates huge number of WARNings
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] 81a28cf6 8800cd9f7b48 816a10a3 [ 3521.474274] 8800cd9f7b88 8106ec8a 8800cd9f7b68 [ 3521.482680] 880119bd7a80 81196730 880119bd7a80 17a8 [ 3521.491143] Call Trace: [ 3521.494128] [816a10a3] dump_stack+0x45/0x57 [ 3521.500016] [8106ec8a] warn_slowpath_common+0x8a/0xc0 [ 3521.506810] [81196730] ? vm_insert_mixed+0x40/0x40 [ 3521.513389] [8106ed7a] warn_slowpath_null+0x1a/0x20 [ 3521.520025] [81123425] ftrace_bug+0x245/0x320 [ 3521.526147] [81052d5c] ftrace_replace_code+0x24c/0x360 [ 3521.533102] [81123d3c] ftrace_modify_all_code+0x9c/0x120 [ 3521.540241] [81052e80] arch_ftrace_update_code+0x10/0x20 [ 3521.547396] [81123e30] ftrace_run_update_code+0x20/0x80 [ 3521.554425] [811244df] ftrace_startup_enable+0x2f/0x40 [ 3521.561376] [811256e6] ftrace_startup+0xd6/0x230 [ 3521.567772] [81125c24] register_ftrace_function+0x54/0x70 [ 3521.575025] [8113df07] perf_ftrace_event_register+0x47/0x140 [ 3521.582537] [8113dba4] perf_trace_init+0xc4/0x2c0 [ 3521.589050] [81152e8a] perf_tp_event_init+0x2a/0x50 [ 3521.595771] [8115448b] perf_try_init_event+0x8b/0xa0 [ 3521.602572] [8115bf63] perf_init_event+0x133/0x160 [ 3521.609181] [8115be30] ? perf_bp_event+0x90/0x90 [ 3521.615647] [8115c3ba] perf_event_alloc+0x42a/0x680 [ 3521.622388] [8115c9d7] SYSC_perf_event_open+0x3c7/0xd20 [ 3521.629487] [8105f86b] ? __do_page_fault+0x1ab/0x3f0 [ 3521.636320] [8115d7a9] SyS_perf_event_open+0x9/0x10 [ 3521.643087] [816a8df2] entry_SYSCALL_64_fastpath+0x16/0x7a [ 3521.650521] ---[ end trace a413501925547ed5 ]--- [ 3521.655960] ftrace failed to modify [81196730] handle_mm_fault+0x0/0x1750 [ 3521.664767] actual: e8:cb:18:ef:1e [ 3521.669202] ftrace record flags: ec02 [ 3521.673993] (2) R tramp: 0xa009 expected tramp: a009 [ 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: GW 4.2.0-rc1+ #168 [ 3521.940498] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS 01/26/2014 [ 3521.948854] 81a28976 8800bf6d7a48 816a10a3 [ 3521.957335] 8800bf6d7a98 8800bf6d7a88 8106ec8a 81124f6a [ 3521.965839] 8800cd4e2010 8800cd4e2010 8800cd4e2000 8800cd28a000 [ 3521.974275] Call Trace: [ 3521.977335] [816a10a3] dump_stack+0x45/0x57 [ 3521.983302] [8106ec8a] warn_slowpath_common+0x8a/0xc0 [ 3521.990170] [81124f6a] ? unregister_ftrace_function+0x1a/0x50 [ 3521.997784] [8106ed06] warn_slowpath_fmt+0x46/0x50 [ 3522.004418] [816a693e] ? mutex_unlock+0xe/0x10 [ 3522.010640] [81119208] disarm_kprobe+0xf8/0x100 [ 3522.016972] [811192a9] __disable_kprobe+0x99/0xc0 [ 3522.023491] [811192f7] disable_kprobe+0x27/0x50 [ 3522.029827] [81142863] disable_trace_kprobe+0xc3/0xf0 [ 3522.036708] [8114345d] kprobe_register+0x2d/0xe0 [ 3522.043102] [8113da83] perf_trace_event_unreg.isra.1+0x33/0x90 [ 3522.050808] [8113dddc] perf_trace_destroy+0x3c/0x50 [ 3522.057482] [81152eb9] tp_perf_event_destroy+0x9/0x10 [ 3522.064354] [81158fc1] _free_event+0xc1/0x250 [ 3522.070474] [8115917b] ? put_event+0x2b/0x150 [ 3522.076625] [811592ef] free_event+0x1f/0x50 [ 3522.082531] [8115d9f5] perf_event_exit_task+0x245/0x300 [ 3522.089575] [81071622] do_exit+0x3b2/0xa90 [ 3522.095444] [8107d182] ? get_signal+0xe2/0x720 [ 3522.101659] [81071da4] do_group_exit+0x54/0xe0 [ 3522.107892] [8107d320] get_signal+0x280/0x720 [ 3522.114046] [81013478] do_signal+0x28/0xb50 [ 3522.119984] [810b78f6] ? __lock_acquire.isra.31+0x3a6/0xf90 [ 3522.127411] [810815a5] ? sys_getppid+0x5/0x80 [
Re: perf, kprobes: fuzzer generates huge number of WARNings
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] 81a28cf6 8800cd9f7b48 816a10a3 [ 3521.474274] 8800cd9f7b88 8106ec8a 8800cd9f7b68 [ 3521.482680] 880119bd7a80 81196730 880119bd7a80 17a8 [ 3521.491143] Call Trace: [ 3521.494128] [816a10a3] dump_stack+0x45/0x57 [ 3521.500016] [8106ec8a] warn_slowpath_common+0x8a/0xc0 [ 3521.506810] [81196730] ? vm_insert_mixed+0x40/0x40 [ 3521.513389] [8106ed7a] warn_slowpath_null+0x1a/0x20 [ 3521.520025] [81123425] ftrace_bug+0x245/0x320 [ 3521.526147] [81052d5c] ftrace_replace_code+0x24c/0x360 [ 3521.533102] [81123d3c] ftrace_modify_all_code+0x9c/0x120 [ 3521.540241] [81052e80] arch_ftrace_update_code+0x10/0x20 [ 3521.547396] [81123e30] ftrace_run_update_code+0x20/0x80 [ 3521.554425] [811244df] ftrace_startup_enable+0x2f/0x40 [ 3521.561376] [811256e6] ftrace_startup+0xd6/0x230 [ 3521.567772] [81125c24] register_ftrace_function+0x54/0x70 [ 3521.575025] [8113df07] perf_ftrace_event_register+0x47/0x140 [ 3521.582537] [8113dba4] perf_trace_init+0xc4/0x2c0 [ 3521.589050] [81152e8a] perf_tp_event_init+0x2a/0x50 [ 3521.595771] [8115448b] perf_try_init_event+0x8b/0xa0 [ 3521.602572] [8115bf63] perf_init_event+0x133/0x160 [ 3521.609181] [8115be30] ? perf_bp_event+0x90/0x90 [ 3521.615647] [8115c3ba] perf_event_alloc+0x42a/0x680 [ 3521.622388] [8115c9d7] SYSC_perf_event_open+0x3c7/0xd20 [ 3521.629487] [8105f86b] ? __do_page_fault+0x1ab/0x3f0 [ 3521.636320] [8115d7a9] SyS_perf_event_open+0x9/0x10 [ 3521.643087] [816a8df2] entry_SYSCALL_64_fastpath+0x16/0x7a [ 3521.650521] ---[ end trace a413501925547ed5 ]--- [ 3521.655960] ftrace failed to modify [81196730] 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: ec02 [ 3521.673993] (2) R tramp: 0xa009 expected tramp: a009 [ 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: GW 4.2.0-rc1+ #168 [ 3521.940498] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS 01/26/2014 [ 3521.948854] 81a28976 8800bf6d7a48 816a10a3 [ 3521.957335] 8800bf6d7a98 8800bf6d7a88 8106ec8a 81124f6a [ 3521.965839] 8800cd4e2010 8800cd4e2010 8800cd4e2000 8800cd28a000 [ 3521.974275] Call Trace: [ 3521.977335] [816a10a3] dump_stack+0x45/0x57 [ 3521.983302] [8106ec8a] warn_slowpath_common+0x8a/0xc0 [ 3521.990170] [81124f6a] ? unregister_ftrace_function+0x1a/0x50 [ 3521.997784] [8106ed06] warn_slowpath_fmt+0x46/0x50 [ 3522.004418] [816a693e] ? mutex_unlock+0xe/0x10 [ 3522.010640] [81119208] disarm_kprobe+0xf8/0x100 [ 3522.016972] [811192a9] __disable_kprobe+0x99/0xc0 [ 3522.023491] [811192f7] disable_kprobe+0x27/0x50 [ 3522.029827] [81142863] disable_trace_kprobe+0xc3/0xf0 [ 3522.036708] [8114345d] kprobe_register+0x2d/0xe0 [ 3522.043102] [8113da83] perf_trace_event_unreg.isra.1+0x33/0x90 [ 3522.050808] [8113dddc] perf_trace_destroy+0x3c/0x50 [ 3522.057482] [81152eb9]
Re: perf, kprobes: fuzzer generates huge number of WARNings
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 -- To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: perf, kprobes: fuzzer generates huge number of WARNings
On Mon, 6 Jul 2015, Steven Rostedt wrote: On Mon, 6 Jul 2015 17:27:04 -0400 (EDT) Vince Weaver vincent.wea...@maine.edu wrote: [ 3521.650521] ---[ end trace a413501925547ed5 ]--- [ 3521.655960] ftrace failed to modify [81196730] 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 -- To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
