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 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(&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] [] 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/
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] [] fput+0xe/
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, 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] [] ? sys_getppid+0x5/
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: