[PATCH bpf v2 0/2] rethook: Reject getting a rethook if RCU is not watching

[PATCH bpf v2 0/2] rethook: Reject getting a rethook if RCU is not watching

[Masami Hiramatsu (Google)]

Hi,

Here is the 2nd version of the patches to reject rethook if RCU is
not watching. The 1st version is here;

https://lore.kernel.org/all/165189881197.175864.14757002789194211860.stgit@devnote2/

This is actually related to the idle function tracing issue
reported by Jiri on LKML (*)

(*) https://lore.kernel.org/bpf/20220515203653.4039075-1-jolsa@kernel.org/

Jiri reported that fprobe (and rethook) based kprobe-multi bpf
trace kicks "suspicious RCU usage" warning. This is because the
RCU operation is used in the kprobe-multi handler. However, I
also found that the similar issue exists in the rethook because
the rethook uses RCU operation.

I added a new patch [1/2] to test this issue by fprobe_example.ko.
(with this patch, it can avoid using printk() which also involves
the RCU operation.)

 ------
 # insmod fprobe_example.ko symbol=arch_cpu_idle use_trace=1 stackdump=0 
 fprobe_init: Planted fprobe at arch_cpu_idle
 # rmmod fprobe_example.ko 
 
 =============================
 WARNING: suspicious RCU usage
 5.18.0-rc5-00019-gcae4ec21e87a-dirty #30 Not tainted
 -----------------------------
 include/trace/events/lock.h:37 suspicious rcu_dereference_check() usage!
 
 other info that might help us debug this:
 
 rcu_scheduler_active = 2, debug_locks = 1
 
 
 RCU used illegally from extended quiescent state!
 no locks held by swapper/0/0.
 
 stack backtrace:
 CPU: 0 PID: 0 Comm: swapper/0 Not tainted 5.18.0-rc5-00019-gcae4ec21e87a-dirty #30
 ------
 
After applying [2/2] fix (which avoid initializing rethook on
function entry if !rcu_watching()), this warning was gone.

 ------
 # insmod fprobe_example.ko symbol=arch_cpu_idle use_trace=1 stackdump=0
 fprobe_init: Planted fprobe at arch_cpu_idle
 # rmmod fprobe_example.ko 
 fprobe_exit: fprobe at arch_cpu_idle unregistered. 225 times hit, 230 times missed
 ------

Note that you can test this program until the arch_cpu_idle()
is marked as noinstr. After that, the function can not be
traced.

Thank you,

---

Masami Hiramatsu (Google) (2):
      fprobe: samples: Add use_trace option and show hit/missed counter
      rethook: Reject getting a rethook if RCU is not watching


 kernel/trace/rethook.c          |    9 +++++++++
 samples/fprobe/fprobe_example.c |   21 +++++++++++++++++----
 2 files changed, 26 insertions(+), 4 deletions(-)

--
Signature

[PATCH bpf v2 1/2] fprobe: samples: Add use_trace option and show hit/missed counter

[Masami Hiramatsu (Google)]

From: Masami Hiramatsu (Google) <mhiramat@kernel.org>

Add use_trace option to use trace_printk() instead of pr_info()
so that the handler doesn't involve the RCU operations.
And show the hit and missed counter so that the user can check
how many times the probe handler hit and missed.

Signed-off-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
---
 samples/fprobe/fprobe_example.c |   21 +++++++++++++++++----
 1 file changed, 17 insertions(+), 4 deletions(-)

diff --git a/samples/fprobe/fprobe_example.c b/samples/fprobe/fprobe_example.c
index 24d3cf109140..aad5af0278f4 100644
--- a/samples/fprobe/fprobe_example.c
+++ b/samples/fprobe/fprobe_example.c
@@ -21,6 +21,7 @@
 #define BACKTRACE_DEPTH 16
 #define MAX_SYMBOL_LEN 4096
 struct fprobe sample_probe;
+static unsigned long nhit;
 
 static char symbol[MAX_SYMBOL_LEN] = "kernel_clone";
 module_param_string(symbol, symbol, sizeof(symbol), 0644);
@@ -28,6 +29,8 @@ static char nosymbol[MAX_SYMBOL_LEN] = "";
 module_param_string(nosymbol, nosymbol, sizeof(nosymbol), 0644);
 static bool stackdump = true;
 module_param(stackdump, bool, 0644);
+static bool use_trace = false;
+module_param(use_trace, bool, 0644);
 
 static void show_backtrace(void)
 {
@@ -40,7 +43,11 @@ static void show_backtrace(void)
 
 static void sample_entry_handler(struct fprobe *fp, unsigned long ip, struct pt_regs *regs)
 {
-	pr_info("Enter <%pS> ip = 0x%p\n", (void *)ip, (void *)ip);
+	if (use_trace)
+		trace_printk("Enter <%pS> ip = 0x%p\n", (void *)ip, (void *)ip);
+	else
+		pr_info("Enter <%pS> ip = 0x%p\n", (void *)ip, (void *)ip);
+	nhit++;
 	if (stackdump)
 		show_backtrace();
 }
@@ -49,8 +56,13 @@ static void sample_exit_handler(struct fprobe *fp, unsigned long ip, struct pt_r
 {
 	unsigned long rip = instruction_pointer(regs);
 
-	pr_info("Return from <%pS> ip = 0x%p to rip = 0x%p (%pS)\n",
-		(void *)ip, (void *)ip, (void *)rip, (void *)rip);
+	if (use_trace)
+		trace_printk("Return from <%pS> ip = 0x%p to rip = 0x%p (%pS)\n",
+			(void *)ip, (void *)ip, (void *)rip, (void *)rip);
+	else
+		pr_info("Return from <%pS> ip = 0x%p to rip = 0x%p (%pS)\n",
+			(void *)ip, (void *)ip, (void *)rip, (void *)rip);
+	nhit++;
 	if (stackdump)
 		show_backtrace();
 }
@@ -112,7 +124,8 @@ static void __exit fprobe_exit(void)
 {
 	unregister_fprobe(&sample_probe);
 
-	pr_info("fprobe at %s unregistered\n", symbol);
+	pr_info("fprobe at %s unregistered. %ld times hit, %ld times missed\n",
+		symbol, nhit, sample_probe.nmissed);
 }
 
 module_init(fprobe_init)

[PATCH bpf v2 2/2] rethook: Reject getting a rethook if RCU is not watching

[Masami Hiramatsu (Google)]

From: Masami Hiramatsu (Google) <mhiramat@kernel.org>

Since the rethook_recycle() will involve the call_rcu() for reclaiming
the rethook_instance, the rethook must be set up at the RCU available
context (non idle). This rethook_recycle() in the rethook trampoline
handler is inevitable, thus the RCU available check must be done before
setting the rethook trampoline.

This adds a rcu_is_watching() check in the rethook_try_get() so that
it will return NULL if it is called when !rcu_is_watching().

Fixes: 54ecbe6f1ed5 ("rethook: Add a generic return hook")
Signed-off-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
---
 kernel/trace/rethook.c |    9 +++++++++
 1 file changed, 9 insertions(+)

diff --git a/kernel/trace/rethook.c b/kernel/trace/rethook.c
index b56833700d23..c69d82273ce7 100644
--- a/kernel/trace/rethook.c
+++ b/kernel/trace/rethook.c
@@ -154,6 +154,15 @@ struct rethook_node *rethook_try_get(struct rethook *rh)
 	if (unlikely(!handler))
 		return NULL;
 
+	/*
+	 * This expects the caller will set up a rethook on a function entry.
+	 * When the function returns, the rethook will eventually be reclaimed
+	 * or released in the rethook_recycle() with call_rcu().
+	 * This means the caller must be run in the RCU-availabe context.
+	 */
+	if (unlikely(!rcu_is_watching()))
+		return NULL;
+
 	fn = freelist_try_get(&rh->pool);
 	if (!fn)
 		return NULL;

Re: [PATCH bpf v2 0/2] rethook: Reject getting a rethook if RCU is not watching

[Jiri Olsa]

On Wed, Jun 08, 2022 at 01:10:52AM +0900, Masami Hiramatsu (Google) wrote:
> Hi,
> 
> Here is the 2nd version of the patches to reject rethook if RCU is
> not watching. The 1st version is here;
> 
> https://lore.kernel.org/all/165189881197.175864.14757002789194211860.stgit@devnote2/
> 
> This is actually related to the idle function tracing issue
> reported by Jiri on LKML (*)
> 
> (*) https://lore.kernel.org/bpf/20220515203653.4039075-1-jolsa@kernel.org/
> 
> Jiri reported that fprobe (and rethook) based kprobe-multi bpf
> trace kicks "suspicious RCU usage" warning. This is because the
> RCU operation is used in the kprobe-multi handler. However, I
> also found that the similar issue exists in the rethook because
> the rethook uses RCU operation.
> 
> I added a new patch [1/2] to test this issue by fprobe_example.ko.
> (with this patch, it can avoid using printk() which also involves
> the RCU operation.)
> 
>  ------
>  # insmod fprobe_example.ko symbol=arch_cpu_idle use_trace=1 stackdump=0 
>  fprobe_init: Planted fprobe at arch_cpu_idle
>  # rmmod fprobe_example.ko 
>  
>  =============================
>  WARNING: suspicious RCU usage
>  5.18.0-rc5-00019-gcae4ec21e87a-dirty #30 Not tainted
>  -----------------------------
>  include/trace/events/lock.h:37 suspicious rcu_dereference_check() usage!
>  
>  other info that might help us debug this:
>  
>  rcu_scheduler_active = 2, debug_locks = 1
>  
>  
>  RCU used illegally from extended quiescent state!
>  no locks held by swapper/0/0.
>  
>  stack backtrace:
>  CPU: 0 PID: 0 Comm: swapper/0 Not tainted 5.18.0-rc5-00019-gcae4ec21e87a-dirty #30
>  ------
>  
> After applying [2/2] fix (which avoid initializing rethook on
> function entry if !rcu_watching()), this warning was gone.
> 
>  ------
>  # insmod fprobe_example.ko symbol=arch_cpu_idle use_trace=1 stackdump=0
>  fprobe_init: Planted fprobe at arch_cpu_idle
>  # rmmod fprobe_example.ko 
>  fprobe_exit: fprobe at arch_cpu_idle unregistered. 225 times hit, 230 times missed
>  ------
> 
> Note that you can test this program until the arch_cpu_idle()
> is marked as noinstr. After that, the function can not be
> traced.
> 
> Thank you,
> 
> ---
> 
> Masami Hiramatsu (Google) (2):
>       fprobe: samples: Add use_trace option and show hit/missed counter
>       rethook: Reject getting a rethook if RCU is not watching

LGTM

Acked-by: Jiri Olsa <jolsa@kernel.org>

jirka

> 
> 
>  kernel/trace/rethook.c          |    9 +++++++++
>  samples/fprobe/fprobe_example.c |   21 +++++++++++++++++----
>  2 files changed, 26 insertions(+), 4 deletions(-)
> 
> --
> Signature

Re: [PATCH bpf v2 1/2] fprobe: samples: Add use_trace option and show hit/missed counter

[Steven Rostedt]

On Wed,  8 Jun 2022 01:11:02 +0900
"Masami Hiramatsu (Google)" <mhiramat@kernel.org> wrote:

>  
>  static void sample_entry_handler(struct fprobe *fp, unsigned long ip, struct pt_regs *regs)
>  {
> -	pr_info("Enter <%pS> ip = 0x%p\n", (void *)ip, (void *)ip);
> +	if (use_trace)
> +		trace_printk("Enter <%pS> ip = 0x%p\n", (void *)ip, (void *)ip);

Could we add a comment stating something like "this is just an example, no
kernel code should call trace_printk() except when actively debugging".

-- Steve


> +	else
> +		pr_info("Enter <%pS> ip = 0x%p\n", (void *)ip, (void *)ip);
> +	nhit++;
>  	if (stackdump)
>  		show_backtrace();
>  }
> @@ -49,8 +56,13 @@ static void sample_exit_handler(struct fprobe *fp, unsigned long ip, struct pt_r
>  {
>  	unsigned long rip = instruction_pointer(regs);
>  
> -	pr_info("Return from <%pS> ip = 0x%p to rip = 0x%p (%pS)\n",
> -		(void *)ip, (void *)ip, (void *)rip, (void *)rip);
> +	if (use_trace)
> +		trace_printk("Return from <%pS> ip = 0x%p to rip = 0x%p (%pS)\n",
> +			(void *)ip, (void *)ip, (void *)rip, (void *)rip);
> +	else
> +		pr_info("Return from <%pS> ip = 0x%p to rip = 0x%p (%pS)\n",
> +			(void *)ip, (void *)ip, (void *)rip, (void *)rip);
> +	nhit++;
>  	if (stackdump)
>  		show_backtrace();

Re: [PATCH bpf v2 2/2] rethook: Reject getting a rethook if RCU is not watching

[Steven Rostedt]

On Wed,  8 Jun 2022 01:11:12 +0900
"Masami Hiramatsu (Google)" <mhiramat@kernel.org> wrote:

> From: Masami Hiramatsu (Google) <mhiramat@kernel.org>
> 
> Since the rethook_recycle() will involve the call_rcu() for reclaiming
> the rethook_instance, the rethook must be set up at the RCU available
> context (non idle). This rethook_recycle() in the rethook trampoline
> handler is inevitable, thus the RCU available check must be done before
> setting the rethook trampoline.
> 
> This adds a rcu_is_watching() check in the rethook_try_get() so that
> it will return NULL if it is called when !rcu_is_watching().
> 
> Fixes: 54ecbe6f1ed5 ("rethook: Add a generic return hook")
> Signed-off-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
> ---
>  kernel/trace/rethook.c |    9 +++++++++
>  1 file changed, 9 insertions(+)
> 
> diff --git a/kernel/trace/rethook.c b/kernel/trace/rethook.c
> index b56833700d23..c69d82273ce7 100644
> --- a/kernel/trace/rethook.c
> +++ b/kernel/trace/rethook.c
> @@ -154,6 +154,15 @@ struct rethook_node *rethook_try_get(struct rethook *rh)
>  	if (unlikely(!handler))
>  		return NULL;
>  
> +	/*
> +	 * This expects the caller will set up a rethook on a function entry.
> +	 * When the function returns, the rethook will eventually be reclaimed
> +	 * or released in the rethook_recycle() with call_rcu().
> +	 * This means the caller must be run in the RCU-availabe context.
> +	 */
> +	if (unlikely(!rcu_is_watching()))
> +		return NULL;

Acked-by: Steven Rostedt (Google) <rostedt@goodmis.org>

-- Steve

> +
>  	fn = freelist_try_get(&rh->pool);
>  	if (!fn)
>  		return NULL;

Re: [PATCH bpf v2 1/2] fprobe: samples: Add use_trace option and show hit/missed counter

[Masami Hiramatsu]

On Fri, 17 Jun 2022 12:06:51 -0400
Steven Rostedt <rostedt@goodmis.org> wrote:

> On Wed,  8 Jun 2022 01:11:02 +0900
> "Masami Hiramatsu (Google)" <mhiramat@kernel.org> wrote:
> 
> >  
> >  static void sample_entry_handler(struct fprobe *fp, unsigned long ip, struct pt_regs *regs)
> >  {
> > -	pr_info("Enter <%pS> ip = 0x%p\n", (void *)ip, (void *)ip);
> > +	if (use_trace)
> > +		trace_printk("Enter <%pS> ip = 0x%p\n", (void *)ip, (void *)ip);
> 
> Could we add a comment stating something like "this is just an example, no
> kernel code should call trace_printk() except when actively debugging".

Indeed. I also add a description for this option so that user can
understand this is just a debug option.

Thank you,


-- 
Masami Hiramatsu (Google) <mhiramat@kernel.org>