Re: [RFC 00/13] kprobe/bpf: Add support to attach multiple kprobes

[Jiri Olsa <jolsa@redhat.com>]

On Tue, Jan 04, 2022 at 10:53:19AM -0800, Alexei Starovoitov wrote:
> On Tue, Jan 4, 2022 at 12:09 AM Jiri Olsa <jolsa@redhat.com> wrote:
> >
> > hi,
> > adding support to attach multiple kprobes within single syscall
> > and speed up attachment of many kprobes.
> >
> > The previous attempt [1] wasn't fast enough, so coming with new
> > approach that adds new kprobe interface.
> >
> > The attachment speed of of this approach (tested in bpftrace)
> > is now comparable to ftrace tracer attachment speed.. fast ;-)
> 
> What are the absolute numbers?
> How quickly a single bpf prog can attach to 1k kprobes?
> 

I'd need to write special tool for 1k kprobes exactly,
we could do some benchmark selftest for that

I tested following counts with current bpftrace interface for now
(note it includes both attach and detach)


2 seconds for 673 kprobes:

	# perf stat -e cycles:u,cycles:k ./src/bpftrace  -e 'kprobe:kvm* {  } i:ms:10 { printf("KRAVA\n"); exit() }' 
	Attaching 2 probes...
	Attaching 673 functions
	KRAVA


	 Performance counter stats for './src/bpftrace -e kprobe:kvm* {  } i:ms:10 { printf("KRAVA\n"); exit() }':

	     1,695,142,901      cycles:u                                                    
	     1,909,616,944      cycles:k                                                    

	       1.990434019 seconds time elapsed

	       0.767746000 seconds user
	       0.921166000 seconds sys


5 seconds for 3337 kprobes:

	# perf stat -e cycles:u,cycles:k ./src/bpftrace  -e 'kprobe:x* {  } i:ms:10 { printf("KRAVA\n"); exit() }' 
	Attaching 2 probes...
	Attaching 3337 functions
	KRAVA


	 Performance counter stats for './src/bpftrace -e kprobe:x* {  } i:ms:10 { printf("KRAVA\n"); exit() }':

	     1,731,646,061      cycles:u                                                    
	     9,815,306,940      cycles:k                                                    

	       5.196176904 seconds time elapsed

	       0.780508000 seconds user
	       4.078170000 seconds sys


lot of the time above is spent in kallsyms:

	    42.70%  bpftrace  [kernel.kallsyms]     [k] kallsyms_expand_symbol.constprop.0
	     5.11%  bpftrace  [kernel.kallsyms]     [k] insn_get_prefixes.part.0
	     3.91%  bpftrace  [kernel.kallsyms]     [k] insn_decode
	     3.09%  bpftrace  [kernel.kallsyms]     [k] arch_jump_entry_size
	     1.98%  bpftrace  [kernel.kallsyms]     [k] __lock_acquire
	     1.51%  bpftrace  [kernel.kallsyms]     [k] static_call_text_reserved


by checking if the address is on the kprobe blacklist:

	    42.70%  bpftrace  [kernel.kallsyms]     [k] kallsyms_expand_symbol.constprop.0
		    |
		    ---kallsyms_expand_symbol.constprop.0
		       |          
			--42.22%--kallsyms_lookup_name
				  within_kprobe_blacklist.part.0
				  check_kprobe_address
				  register_kprobe
				  bpf_kprobe_link_attach
				  __sys_bpf
				  __x64_sys_bpf
				  do_syscall_64
				  entry_SYSCALL_64_after_hwframe
				  syscall
				  bpftrace::AttachedProbe::attach_kprobe


I could revive that patch that did bsearch on kallsyms or we could
add 'do-not-check-kprobe-blacklist' unsafe mode to get more speed

jirka