2018-01-31 17:08:15

by Du, Changbin

[permalink] [raw]
Subject: [PATCH] tracing/fgraph: Missed irq return mark for leaf entry

From: Changbin Du <[email protected]>

The fgraph forget to print irq return mark for leaf entry. Then we can see
unbalanced irq mark in the trace. This patch fix this.

Before:
1) | SyS_write() {
1) | __fdget_pos() {
1) 0.061 us | __fget_light();
1) 0.289 us | }
1) | vfs_write() {
1) 0.049 us | rw_verify_area();
1) + 15.424 us | __vfs_write();
1) ==========> |
1) 6.003 us | smp_apic_timer_interrupt();
1) 0.055 us | __fsnotify_parent();
1) 0.073 us | fsnotify();
1) + 23.665 us | }
1) + 24.501 us | }

After:
0) | SyS_write() {
0) | __fdget_pos() {
0) 0.052 us | __fget_light();
0) 0.328 us | }
0) | vfs_write() {
0) 0.057 us | rw_verify_area();
0) | __vfs_write() {
0) ==========> |
0) 8.548 us | smp_apic_timer_interrupt();
0) <========== |
0) + 36.507 us | } /* __vfs_write */
0) 0.049 us | __fsnotify_parent();
0) 0.066 us | fsnotify();
0) + 50.064 us | }
0) + 50.952 us | }

Signed-off-by: Changbin Du <[email protected]>
---
kernel/trace/trace_functions_graph.c | 5 ++++-
1 file changed, 4 insertions(+), 1 deletion(-)

diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c
index 23c0b0c..169b3c4 100644
--- a/kernel/trace/trace_functions_graph.c
+++ b/kernel/trace/trace_functions_graph.c
@@ -831,6 +831,7 @@ print_graph_entry_leaf(struct trace_iterator *iter,
struct ftrace_graph_ret *graph_ret;
struct ftrace_graph_ent *call;
unsigned long long duration;
+ int cpu = iter->cpu;
int i;

graph_ret = &ret_entry->ret;
@@ -839,7 +840,6 @@ print_graph_entry_leaf(struct trace_iterator *iter,

if (data) {
struct fgraph_cpu_data *cpu_data;
- int cpu = iter->cpu;

cpu_data = per_cpu_ptr(data->cpu_data, cpu);

@@ -869,6 +869,9 @@ print_graph_entry_leaf(struct trace_iterator *iter,

trace_seq_printf(s, "%ps();\n", (void *)call->func);

+ print_graph_irq(iter, graph_ret->func, TRACE_GRAPH_RET,
+ cpu, iter->ent->pid, flags);
+
return trace_handle_return(s);
}

--
2.7.4



2018-02-11 11:01:14

by Du, Changbin

[permalink] [raw]
Subject: Re: [PATCH] tracing/fgraph: Missed irq return mark for leaf entry

Hi Rostedt,
What abount this fix? Thanks!

On Wed, Jan 31, 2018 at 11:48:49PM +0800, [email protected] wrote:
> From: Changbin Du <[email protected]>
>
> The fgraph forget to print irq return mark for leaf entry. Then we can see
> unbalanced irq mark in the trace. This patch fix this.
>
> Before:
> 1) | SyS_write() {
> 1) | __fdget_pos() {
> 1) 0.061 us | __fget_light();
> 1) 0.289 us | }
> 1) | vfs_write() {
> 1) 0.049 us | rw_verify_area();
> 1) + 15.424 us | __vfs_write();
> 1) ==========> |
> 1) 6.003 us | smp_apic_timer_interrupt();
> 1) 0.055 us | __fsnotify_parent();
> 1) 0.073 us | fsnotify();
> 1) + 23.665 us | }
> 1) + 24.501 us | }
>
> After:
> 0) | SyS_write() {
> 0) | __fdget_pos() {
> 0) 0.052 us | __fget_light();
> 0) 0.328 us | }
> 0) | vfs_write() {
> 0) 0.057 us | rw_verify_area();
> 0) | __vfs_write() {
> 0) ==========> |
> 0) 8.548 us | smp_apic_timer_interrupt();
> 0) <========== |
> 0) + 36.507 us | } /* __vfs_write */
> 0) 0.049 us | __fsnotify_parent();
> 0) 0.066 us | fsnotify();
> 0) + 50.064 us | }
> 0) + 50.952 us | }
>
> Signed-off-by: Changbin Du <[email protected]>
> ---
> kernel/trace/trace_functions_graph.c | 5 ++++-
> 1 file changed, 4 insertions(+), 1 deletion(-)
>
> diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c
> index 23c0b0c..169b3c4 100644
> --- a/kernel/trace/trace_functions_graph.c
> +++ b/kernel/trace/trace_functions_graph.c
> @@ -831,6 +831,7 @@ print_graph_entry_leaf(struct trace_iterator *iter,
> struct ftrace_graph_ret *graph_ret;
> struct ftrace_graph_ent *call;
> unsigned long long duration;
> + int cpu = iter->cpu;
> int i;
>
> graph_ret = &ret_entry->ret;
> @@ -839,7 +840,6 @@ print_graph_entry_leaf(struct trace_iterator *iter,
>
> if (data) {
> struct fgraph_cpu_data *cpu_data;
> - int cpu = iter->cpu;
>
> cpu_data = per_cpu_ptr(data->cpu_data, cpu);
>
> @@ -869,6 +869,9 @@ print_graph_entry_leaf(struct trace_iterator *iter,
>
> trace_seq_printf(s, "%ps();\n", (void *)call->func);
>
> + print_graph_irq(iter, graph_ret->func, TRACE_GRAPH_RET,
> + cpu, iter->ent->pid, flags);
> +
> return trace_handle_return(s);
> }
>
> --
> 2.7.4
>

--
Thanks,
Changbin Du

2018-02-12 01:58:01

by Namhyung Kim

[permalink] [raw]
Subject: Re: [PATCH] tracing/fgraph: Missed irq return mark for leaf entry

On Wed, Jan 31, 2018 at 11:48:49PM +0800, [email protected] wrote:
> From: Changbin Du <[email protected]>
>
> The fgraph forget to print irq return mark for leaf entry. Then we can see
> unbalanced irq mark in the trace. This patch fix this.
>
> Before:
> 1) | SyS_write() {
> 1) | __fdget_pos() {
> 1) 0.061 us | __fget_light();
> 1) 0.289 us | }
> 1) | vfs_write() {
> 1) 0.049 us | rw_verify_area();
> 1) + 15.424 us | __vfs_write();
> 1) ==========> |
> 1) 6.003 us | smp_apic_timer_interrupt();
> 1) 0.055 us | __fsnotify_parent();
> 1) 0.073 us | fsnotify();
> 1) + 23.665 us | }
> 1) + 24.501 us | }
>
> After:
> 0) | SyS_write() {
> 0) | __fdget_pos() {
> 0) 0.052 us | __fget_light();
> 0) 0.328 us | }
> 0) | vfs_write() {
> 0) 0.057 us | rw_verify_area();
> 0) | __vfs_write() {
> 0) ==========> |
> 0) 8.548 us | smp_apic_timer_interrupt();
> 0) <========== |
> 0) + 36.507 us | } /* __vfs_write */
> 0) 0.049 us | __fsnotify_parent();
> 0) 0.066 us | fsnotify();
> 0) + 50.064 us | }
> 0) + 50.952 us | }
>
> Signed-off-by: Changbin Du <[email protected]>

Acked-by: Namhyung Kim <[email protected]>

Thanks,
Namhyung


> ---
> kernel/trace/trace_functions_graph.c | 5 ++++-
> 1 file changed, 4 insertions(+), 1 deletion(-)
>
> diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c
> index 23c0b0c..169b3c4 100644
> --- a/kernel/trace/trace_functions_graph.c
> +++ b/kernel/trace/trace_functions_graph.c
> @@ -831,6 +831,7 @@ print_graph_entry_leaf(struct trace_iterator *iter,
> struct ftrace_graph_ret *graph_ret;
> struct ftrace_graph_ent *call;
> unsigned long long duration;
> + int cpu = iter->cpu;
> int i;
>
> graph_ret = &ret_entry->ret;
> @@ -839,7 +840,6 @@ print_graph_entry_leaf(struct trace_iterator *iter,
>
> if (data) {
> struct fgraph_cpu_data *cpu_data;
> - int cpu = iter->cpu;
>
> cpu_data = per_cpu_ptr(data->cpu_data, cpu);
>
> @@ -869,6 +869,9 @@ print_graph_entry_leaf(struct trace_iterator *iter,
>
> trace_seq_printf(s, "%ps();\n", (void *)call->func);
>
> + print_graph_irq(iter, graph_ret->func, TRACE_GRAPH_RET,
> + cpu, iter->ent->pid, flags);
> +
> return trace_handle_return(s);
> }
>
> --
> 2.7.4
>
> --
> To unsubscribe from this list: send the line "unsubscribe linux-perf-users" in
> the body of a message to [email protected]
> More majordomo info at http://vger.kernel.org/majordomo-info.html

2018-02-12 17:09:09

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH] tracing/fgraph: Missed irq return mark for leaf entry

On Sun, 11 Feb 2018 18:51:36 +0800
"Du, Changbin" <[email protected]> wrote:

> Hi Rostedt,
> What abount this fix? Thanks!
>

Thanks for pointing this out, it was lost in my INBOX.

-- Steve