Re: [PATCH v7 00/10] fprobe: Introduce fprobe function entry/exit probe
From: Jiri Olsa <hidden>
Date: 2022-02-02 00:02:52
Also in:
bpf, lkml
On Mon, Jan 31, 2022 at 02:00:24PM +0900, Masami Hiramatsu wrote:
Hi, Here is the 7th version of fprobe. This version fixes unregister_fprobe() ensures that exit_handler is not called after returning from the unregister_fprobe(), and fixes some comments and documents. The previous version is here[1]; [1] https://lore.kernel.org/all/164338031590.2429999.6203979005944292576.stgit@devnote2/T/#u (local) This series introduces the fprobe, the function entry/exit probe with multiple probe point support. This also introduces the rethook for hooking function return as same as the kretprobe does. This abstraction will help us to generalize the fgraph tracer, because we can just switch to it from the rethook in fprobe, depending on the kernel configuration. The patch [1/10] is from Jiri's series[2]. [2] https://lore.kernel.org/all/20220104080943.113249-1-jolsa@kernel.org/T/#u (local) And the patch [9/10] adds the FPROBE_FL_KPROBE_SHARED flag for the case if user wants to share the same code (or share a same resource) on the fprobe and the kprobes.
hi,
it works fine for bpf selftests, but when I use it through bpftrace
to attach more probes with:
# ./src/bpftrace -e 'kprobe:ksys_* { }'
Attaching 27 probes
I'm getting stalls like:
krava33 login: [ 988.574069] INFO: task bpftrace:4137 blocked for more than 122 seconds.
[ 988.577577] Not tainted 5.16.0+ #89
[ 988.580173] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 988.585538] task:bpftrace state:D stack: 0 pid: 4137 ppid: 4123 flags:0x00004004
[ 988.589869] Call Trace:
[ 988.591312] <TASK>
[ 988.592577] __schedule+0x3a8/0xd30
[ 988.594469] ? wait_for_completion+0x84/0x110
[ 988.596753] schedule+0x4e/0xc0
[ 988.598480] schedule_timeout+0xed/0x130
[ 988.600524] ? rcu_read_lock_sched_held+0x12/0x70
[ 988.602901] ? lock_release+0x253/0x4a0
[ 988.604935] ? lock_acquired+0x1b7/0x410
[ 988.607041] ? trace_hardirqs_on+0x1b/0xe0
[ 988.609202] wait_for_completion+0xae/0x110
[ 988.613762] __wait_rcu_gp+0x127/0x130
[ 988.615787] synchronize_rcu_tasks_generic+0x46/0xa0
[ 988.618329] ? call_rcu_tasks+0x20/0x20
[ 988.620600] ? rcu_tasks_pregp_step+0x10/0x10
[ 988.623232] ftrace_shutdown.part.0+0x174/0x210
[ 988.625820] unregister_ftrace_function+0x37/0x60
[ 988.628480] unregister_fprobe+0x2d/0x50
[ 988.630928] bpf_link_free+0x4e/0x70
[ 988.633126] bpf_link_release+0x11/0x20
[ 988.635249] __fput+0xae/0x270
[ 988.637022] task_work_run+0x5c/0xa0
[ 988.639016] exit_to_user_mode_prepare+0x251/0x260
[ 988.641294] syscall_exit_to_user_mode+0x16/0x50
[ 988.646249] do_syscall_64+0x48/0x90
[ 988.648218] entry_SYSCALL_64_after_hwframe+0x44/0xae
[ 988.650787] RIP: 0033:0x7f9079e95fbb
[ 988.652761] RSP: 002b:00007ffd474fa3b0 EFLAGS: 00000293 ORIG_RAX: 0000000000000003
[ 988.656718] RAX: 0000000000000000 RBX: 00000000011bf8d0 RCX: 00007f9079e95fbb
[ 988.660110] RDX: 0000000000000000 RSI: 00007ffd474fa3b0 RDI: 0000000000000019
[ 988.663512] RBP: 00007ffd474faaf0 R08: 0000000000000000 R09: 000000000000001a
[ 988.666673] R10: 0000000000000064 R11: 0000000000000293 R12: 0000000000000001
[ 988.669770] R13: 00000000004a19a1 R14: 00007f9083428c00 R15: 00000000008c02d8
[ 988.672601] </TASK>
[ 988.675763] INFO: lockdep is turned off.
I have't investigated yet, any idea?
thanks,
jirka