[PATCH] tracing/kprobes: 'nmissed' not showed correctly for kretprobe

[PATCH] tracing/kprobes: 'nmissed' not showed correctly for kretprobe

[Xiangyang Zhang]

The 'nmissed' column of the 'kprobe_profile' file for kretprobe is
always zero, because 'nmissed' for kretprobe is maintained in
'tk->rp.nmissed' but not in 'tk->rp.kp.nmissed'

Fixes: c31ffb3ff633 ("tracing/kprobes: Factor out struct trace_probe")
Signed-off-by: Xiangyang Zhang <xyz.sun.ok@gmail.com>
---
 kernel/trace/trace_kprobe.c | 4 +++-
 1 file changed, 3 insertions(+), 1 deletion(-)

diff --git a/kernel/trace/trace_kprobe.c b/kernel/trace/trace_kprobe.c
index d10c01948e68..2b9de6826e94 100644
--- a/kernel/trace/trace_kprobe.c
+++ b/kernel/trace/trace_kprobe.c
@@ -1175,15 +1175,17 @@ static int probes_profile_seq_show(struct seq_file *m, void *v)
 {
 	struct dyn_event *ev = v;
 	struct trace_kprobe *tk;
+	unsigned long nmissed = 0;
 
 	if (!is_trace_kprobe(ev))
 		return 0;
 
 	tk = to_trace_kprobe(ev);
+	nmissed = tk->rp.handler ? tk->rp.nmissed : tk->rp.kp.nmissed;
 	seq_printf(m, "  %-44s %15lu %15lu\n",
 		   trace_probe_name(&tk->tp),
 		   trace_kprobe_nhit(tk),
-		   tk->rp.kp.nmissed);
+		   nmissed);
 
 	return 0;
 }
-- 
2.25.1

Re: [PATCH] tracing/kprobes: 'nmissed' not showed correctly for kretprobe

[Steven Rostedt]

On Sat, 11 Dec 2021 23:00:32 +0800
Xiangyang Zhang <xyz.sun.ok@gmail.com> wrote:

> The 'nmissed' column of the 'kprobe_profile' file for kretprobe is
> always zero, because 'nmissed' for kretprobe is maintained in
> 'tk->rp.nmissed' but not in 'tk->rp.kp.nmissed'
> 
> Fixes: c31ffb3ff633 ("tracing/kprobes: Factor out struct trace_probe")
> Signed-off-by: Xiangyang Zhang <xyz.sun.ok@gmail.com>
> ---
>  kernel/trace/trace_kprobe.c | 4 +++-
>  1 file changed, 3 insertions(+), 1 deletion(-)
> 
> diff --git a/kernel/trace/trace_kprobe.c b/kernel/trace/trace_kprobe.c
> index d10c01948e68..2b9de6826e94 100644
> --- a/kernel/trace/trace_kprobe.c
> +++ b/kernel/trace/trace_kprobe.c
> @@ -1175,15 +1175,17 @@ static int probes_profile_seq_show(struct seq_file *m, void *v)
>  {
>  	struct dyn_event *ev = v;
>  	struct trace_kprobe *tk;
> +	unsigned long nmissed = 0;

No need to initialize this to zero, the first use is an assignment.

>  
>  	if (!is_trace_kprobe(ev))
>  		return 0;
>  
>  	tk = to_trace_kprobe(ev);
> +	nmissed = tk->rp.handler ? tk->rp.nmissed : tk->rp.kp.nmissed;
>  	seq_printf(m, "  %-44s %15lu %15lu\n",
>  		   trace_probe_name(&tk->tp),
>  		   trace_kprobe_nhit(tk),
> -		   tk->rp.kp.nmissed);
> +		   nmissed);

Masami, what's your thoughts on this patch?

-- Steve

>  
>  	return 0;
>  }

Re: [PATCH] tracing/kprobes: 'nmissed' not showed correctly for kretprobe

[Steven Rostedt]

Resending again, this time with Masami's working email address.

On Wed, 5 Jan 2022 14:15:56 -0500
Steven Rostedt <rostedt@goodmis.org> wrote:

> On Sat, 11 Dec 2021 23:00:32 +0800
> Xiangyang Zhang <xyz.sun.ok@gmail.com> wrote:
> 
> > The 'nmissed' column of the 'kprobe_profile' file for kretprobe is
> > always zero, because 'nmissed' for kretprobe is maintained in
> > 'tk->rp.nmissed' but not in 'tk->rp.kp.nmissed'
> > 
> > Fixes: c31ffb3ff633 ("tracing/kprobes: Factor out struct trace_probe")
> > Signed-off-by: Xiangyang Zhang <xyz.sun.ok@gmail.com>
> > ---
> >  kernel/trace/trace_kprobe.c | 4 +++-
> >  1 file changed, 3 insertions(+), 1 deletion(-)
> > 
> > diff --git a/kernel/trace/trace_kprobe.c b/kernel/trace/trace_kprobe.c
> > index d10c01948e68..2b9de6826e94 100644
> > --- a/kernel/trace/trace_kprobe.c
> > +++ b/kernel/trace/trace_kprobe.c
> > @@ -1175,15 +1175,17 @@ static int probes_profile_seq_show(struct seq_file *m, void *v)
> >  {
> >  	struct dyn_event *ev = v;
> >  	struct trace_kprobe *tk;
> > +	unsigned long nmissed = 0;  
> 
> No need to initialize this to zero, the first use is an assignment.
> 
> >  
> >  	if (!is_trace_kprobe(ev))
> >  		return 0;
> >  
> >  	tk = to_trace_kprobe(ev);
> > +	nmissed = tk->rp.handler ? tk->rp.nmissed : tk->rp.kp.nmissed;
> >  	seq_printf(m, "  %-44s %15lu %15lu\n",
> >  		   trace_probe_name(&tk->tp),
> >  		   trace_kprobe_nhit(tk),
> > -		   tk->rp.kp.nmissed);
> > +		   nmissed);  
> 
> Masami, what's your thoughts on this patch?
> 
> -- Steve
> 
> >  
> >  	return 0;
> >  }  
> 

Re: [PATCH] tracing/kprobes: 'nmissed' not showed correctly for kretprobe

[Masami Hiramatsu]

On Wed, 5 Jan 2022 14:22:08 -0500
Steven Rostedt <rostedt@goodmis.org> wrote:

> Resending again, this time with Masami's working email address.
> 
> On Wed, 5 Jan 2022 14:15:56 -0500
> Steven Rostedt <rostedt@goodmis.org> wrote:
> 
> > On Sat, 11 Dec 2021 23:00:32 +0800
> > Xiangyang Zhang <xyz.sun.ok@gmail.com> wrote:
> > 
> > > The 'nmissed' column of the 'kprobe_profile' file for kretprobe is
> > > always zero, because 'nmissed' for kretprobe is maintained in
> > > 'tk->rp.nmissed' but not in 'tk->rp.kp.nmissed'
> > > 
> > > Fixes: c31ffb3ff633 ("tracing/kprobes: Factor out struct trace_probe")
> > > Signed-off-by: Xiangyang Zhang <xyz.sun.ok@gmail.com>
> > > ---
> > >  kernel/trace/trace_kprobe.c | 4 +++-
> > >  1 file changed, 3 insertions(+), 1 deletion(-)
> > > 
> > > diff --git a/kernel/trace/trace_kprobe.c b/kernel/trace/trace_kprobe.c
> > > index d10c01948e68..2b9de6826e94 100644
> > > --- a/kernel/trace/trace_kprobe.c
> > > +++ b/kernel/trace/trace_kprobe.c
> > > @@ -1175,15 +1175,17 @@ static int probes_profile_seq_show(struct seq_file *m, void *v)
> > >  {
> > >  	struct dyn_event *ev = v;
> > >  	struct trace_kprobe *tk;
> > > +	unsigned long nmissed = 0;  
> > 
> > No need to initialize this to zero, the first use is an assignment.
> > 
> > >  
> > >  	if (!is_trace_kprobe(ev))
> > >  		return 0;
> > >  
> > >  	tk = to_trace_kprobe(ev);
> > > +	nmissed = tk->rp.handler ? tk->rp.nmissed : tk->rp.kp.nmissed;
> > >  	seq_printf(m, "  %-44s %15lu %15lu\n",
> > >  		   trace_probe_name(&tk->tp),
> > >  		   trace_kprobe_nhit(tk),
> > > -		   tk->rp.kp.nmissed);
> > > +		   nmissed);  
> > 
> > Masami, what's your thoughts on this patch?

OK, this is a good catch :), but there are 2 issues.

1. kretprobe can be skipped by 2 reasons, shortage of kretprobe_instance which
is counted by rp.nmissed, and kprobe itself is missed by some reason (this
can be happen if KPROBE_EVENTS_ON_NOTRACE=n. Thus, better solution is to show
'tk->rp.nmissed + tk->rp.kp.nmissed'.

2. the commit c31ffb3ff633 is not actual commit which introduce this issue.
  this was introduced by 4a846b443b4e ("tracing/kprobes: Cleanup kprobe tracer code.")

'git blame' tells you the commit which changes that line, but that can be just
a refactoring (renaming). I recommend you to search the correct one by 'git log -p'.

Thank you,

> > 
> > -- Steve
> > 
> > >  
> > >  	return 0;
> > >  }  
> > 
> 


-- 
Masami Hiramatsu <mhiramat@kernel.org>

Re: [PATCH] tracing/kprobes: 'nmissed' not showed correctly for kretprobe

[Steven Rostedt]

On Thu, 6 Jan 2022 07:32:03 +0900
Masami Hiramatsu <mhiramat@kernel.org> wrote:

> OK, this is a good catch :), but there are 2 issues.
> 
> 1. kretprobe can be skipped by 2 reasons, shortage of kretprobe_instance which
> is counted by rp.nmissed, and kprobe itself is missed by some reason (this
> can be happen if KPROBE_EVENTS_ON_NOTRACE=n. Thus, better solution is to show
> 'tk->rp.nmissed + tk->rp.kp.nmissed'.
> 
> 2. the commit c31ffb3ff633 is not actual commit which introduce this issue.
>   this was introduced by 4a846b443b4e ("tracing/kprobes: Cleanup kprobe tracer code.")
> 
> 'git blame' tells you the commit which changes that line, but that can be just
> a refactoring (renaming). I recommend you to search the correct one by 'git log -p'.

Masami, thanks for the review.

Xiangyang, can you please send a v2 with Masami's suggestions?

-- Steve

Re: [PATCH] tracing/kprobes: 'nmissed' not showed correctly for kretprobe

[xy zhang]

ok, I will send a v2 patch later

On Thu, Jan 6, 2022 at 7:10 AM Steven Rostedt <rostedt@goodmis.org> wrote:
>
> On Thu, 6 Jan 2022 07:32:03 +0900
> Masami Hiramatsu <mhiramat@kernel.org> wrote:
>
> > OK, this is a good catch :), but there are 2 issues.
> >
> > 1. kretprobe can be skipped by 2 reasons, shortage of kretprobe_instance which
> > is counted by rp.nmissed, and kprobe itself is missed by some reason (this
> > can be happen if KPROBE_EVENTS_ON_NOTRACE=n. Thus, better solution is to show
> > 'tk->rp.nmissed + tk->rp.kp.nmissed'.
> >
> > 2. the commit c31ffb3ff633 is not actual commit which introduce this issue.
> >   this was introduced by 4a846b443b4e ("tracing/kprobes: Cleanup kprobe tracer code.")
> >
> > 'git blame' tells you the commit which changes that line, but that can be just
> > a refactoring (renaming). I recommend you to search the correct one by 'git log -p'.
>
> Masami, thanks for the review.
>
> Xiangyang, can you please send a v2 with Masami's suggestions?
>
> -- Steve