2009-06-03 08:02:26

by walimis

[permalink] [raw]
Subject: [PATCH 1/3] tracing/trace_stack: fix the number of entries in the header

The last entry in the stack_dump_trace is ULONG_MAX, which is not
a valid entry, but max_stack_trace.nr_entries has accounted for it.
So when printing the header, we should decrease it by one.
Before fix, print as following, for example:

Depth Size Location (53 entries) <--- should be 52
----- ---- --------
0) 3264 108 update_wall_time+0x4d5/0x9a0
...
51) 80 80 syscall_call+0x7/0xb
^^^
it's correct.

Signed-off-by: walimis <[email protected]>
---
kernel/trace/trace_stack.c | 2 +-
1 files changed, 1 insertions(+), 1 deletions(-)

diff --git a/kernel/trace/trace_stack.c b/kernel/trace/trace_stack.c
index 1796f00..2d7aebd 100644
--- a/kernel/trace/trace_stack.c
+++ b/kernel/trace/trace_stack.c
@@ -265,7 +265,7 @@ static int t_show(struct seq_file *m, void *v)
seq_printf(m, " Depth Size Location"
" (%d entries)\n"
" ----- ---- --------\n",
- max_stack_trace.nr_entries);
+ max_stack_trace.nr_entries - 1);

if (!stack_tracer_enabled && !max_stack_size)
print_disabled(m);
--
1.6.0.3


2009-06-03 08:03:24

by walimis

[permalink] [raw]
Subject: [PATCH 3/3] tracing/events: fix output format of user stack

According to "events/ftrace/user_stack/format", fix the output of
user stack.

before fix:

sh-1073 [000] 31.137561: <b7f274fe> <- <0804e33c> <- <080835c1>

after fix:

sh-1072 [000] 37.039329:
=> <b7f8a4fe>
=> <0804e33c>
=> <080835c1>

Signed-off-by: walimis <[email protected]>
---
kernel/trace/trace_output.c | 11 +++++++----
1 files changed, 7 insertions(+), 4 deletions(-)

diff --git a/kernel/trace/trace_output.c b/kernel/trace/trace_output.c
index 64596a5..8dadbbb 100644
--- a/kernel/trace/trace_output.c
+++ b/kernel/trace/trace_output.c
@@ -389,17 +389,20 @@ seq_print_userip_objs(const struct userstack_entry *entry, struct trace_seq *s,

if (ip == ULONG_MAX || !ret)
break;
- if (i && ret)
- ret = trace_seq_puts(s, " <- ");
+ if (ret)
+ ret = trace_seq_puts(s, " => ");
if (!ip) {
if (ret)
ret = trace_seq_puts(s, "??");
+ if (ret)
+ ret = trace_seq_puts(s, "\n");
continue;
}
if (!ret)
break;
if (ret)
ret = seq_print_user_ip(s, mm, ip, sym_flags);
+ ret = trace_seq_puts(s, "\n");
}

if (mm)
@@ -1012,10 +1015,10 @@ static enum print_line_t trace_user_stack_print(struct trace_iterator *iter,

trace_assign_type(field, iter->ent);

- if (!seq_print_userip_objs(field, s, flags))
+ if (!trace_seq_putc(s, '\n'))
goto partial;

- if (!trace_seq_putc(s, '\n'))
+ if (!seq_print_userip_objs(field, s, flags))
goto partial;

return TRACE_TYPE_HANDLED;
--
1.6.0.3

2009-06-03 08:10:16

by walimis

[permalink] [raw]
Subject: [PATCH 2/3] tracing/events: fix output format of kernel stack

According to "events/ftrace/kernel_stack/format", output format of
kernel stack should use "=>" instead of "<=".

The second problem is that we shouldn't skip the first entry in the stack,
although it seems to be duplicated when used in the "function" tracer,
but events also use it. If we skip the first one, we will drop the topmost
entry of the stack.

The last problem is that if the last entry is ULONG_MAX(0xffffffff), we should
drop it, otherwise it will print a NULL name line.

before fix:

sh-1072 [000] 26.957239: sched_process_fork: parent sh:1072 child sh:1073
sh-1072 [000] 26.957262:
<= syscall_call
<=
sh-1072 [000] 26.957744: sched_switch: task sh:1072 [120] (R) ==> sh:1073 [120]
sh-1072 [000] 26.957752:
<= preempt_schedule
<= wake_up_new_task
<= do_fork
<= sys_clone
<= syscall_call
<=

After fix:

sh-1075 [000] 39.791848: sched_process_fork: parent sh:1075 child sh:1076
sh-1075 [000] 39.791871:
=> sys_clone
=> syscall_call
sh-1075 [000] 39.792713: sched_switch: task sh:1075 [120] (R) ==> sh:1076 [120]
sh-1075 [000] 39.792722:
=> schedule
=> preempt_schedule
=> wake_up_new_task
=> do_fork
=> sys_clone
=> syscall_call

Signed-off-by: walimis <[email protected]>
---
kernel/trace/trace_output.c | 14 +++++++-------
1 files changed, 7 insertions(+), 7 deletions(-)

diff --git a/kernel/trace/trace_output.c b/kernel/trace/trace_output.c
index 0fe3b22..64596a5 100644
--- a/kernel/trace/trace_output.c
+++ b/kernel/trace/trace_output.c
@@ -975,16 +975,16 @@ static enum print_line_t trace_stack_print(struct trace_iterator *iter,

trace_assign_type(field, iter->ent);

+ if (!trace_seq_puts(s, "\n"))
+ goto partial;
for (i = 0; i < FTRACE_STACK_ENTRIES; i++) {
- if (!field->caller[i])
+ if (!field->caller[i] || (field->caller[i] == ULONG_MAX))
break;
- if (i) {
- if (!trace_seq_puts(s, " <= "))
- goto partial;
+ if (!trace_seq_puts(s, " => "))
+ goto partial;

- if (!seq_print_ip_sym(s, field->caller[i], flags))
- goto partial;
- }
+ if (!seq_print_ip_sym(s, field->caller[i], flags))
+ goto partial;
if (!trace_seq_puts(s, "\n"))
goto partial;
}
--
1.6.0.3

2009-06-03 14:00:09

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH 1/3] tracing/trace_stack: fix the number of entries in the header


On Wed, 3 Jun 2009, walimis wrote:

> The last entry in the stack_dump_trace is ULONG_MAX, which is not
> a valid entry, but max_stack_trace.nr_entries has accounted for it.
> So when printing the header, we should decrease it by one.
> Before fix, print as following, for example:
>
> Depth Size Location (53 entries) <--- should be 52
> ----- ---- --------
> 0) 3264 108 update_wall_time+0x4d5/0x9a0
> ...
> 51) 80 80 syscall_call+0x7/0xb
> ^^^
> it's correct.
>
> Signed-off-by: walimis <[email protected]>

This is one of those bugs I've been meaning to fix for a long time, but
never got around to actually doing it. Thanks!

I'll queue this up.

-- Steve

> ---
> kernel/trace/trace_stack.c | 2 +-
> 1 files changed, 1 insertions(+), 1 deletions(-)
>
> diff --git a/kernel/trace/trace_stack.c b/kernel/trace/trace_stack.c
> index 1796f00..2d7aebd 100644
> --- a/kernel/trace/trace_stack.c
> +++ b/kernel/trace/trace_stack.c
> @@ -265,7 +265,7 @@ static int t_show(struct seq_file *m, void *v)
> seq_printf(m, " Depth Size Location"
> " (%d entries)\n"
> " ----- ---- --------\n",
> - max_stack_trace.nr_entries);
> + max_stack_trace.nr_entries - 1);
>
> if (!stack_tracer_enabled && !max_stack_size)
> print_disabled(m);
> --
> 1.6.0.3
>
>

2009-06-03 14:23:18

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH 2/3] tracing/events: fix output format of kernel stack



On Wed, 3 Jun 2009, walimis wrote:

> According to "events/ftrace/kernel_stack/format", output format of
> kernel stack should use "=>" instead of "<=".
>
> The second problem is that we shouldn't skip the first entry in the stack,
> although it seems to be duplicated when used in the "function" tracer,
> but events also use it. If we skip the first one, we will drop the topmost
> entry of the stack.
>
> The last problem is that if the last entry is ULONG_MAX(0xffffffff), we should
> drop it, otherwise it will print a NULL name line.
>
> before fix:
>
> sh-1072 [000] 26.957239: sched_process_fork: parent sh:1072 child sh:1073
> sh-1072 [000] 26.957262:
> <= syscall_call
> <=
> sh-1072 [000] 26.957744: sched_switch: task sh:1072 [120] (R) ==> sh:1073 [120]
> sh-1072 [000] 26.957752:
> <= preempt_schedule
> <= wake_up_new_task
> <= do_fork
> <= sys_clone
> <= syscall_call
> <=
>
> After fix:
>
> sh-1075 [000] 39.791848: sched_process_fork: parent sh:1075 child sh:1076
> sh-1075 [000] 39.791871:
> => sys_clone
> => syscall_call
> sh-1075 [000] 39.792713: sched_switch: task sh:1075 [120] (R) ==> sh:1076 [120]
> sh-1075 [000] 39.792722:
> => schedule
> => preempt_schedule
> => wake_up_new_task
> => do_fork
> => sys_clone
> => syscall_call
>
> Signed-off-by: walimis <[email protected]>

I'll queue this up. Thanks!

-- Steve

2009-06-03 14:23:46

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH 3/3] tracing/events: fix output format of user stack



On Wed, 3 Jun 2009, walimis wrote:

> According to "events/ftrace/user_stack/format", fix the output of
> user stack.
>
> before fix:
>
> sh-1073 [000] 31.137561: <b7f274fe> <- <0804e33c> <- <080835c1>
>
> after fix:
>
> sh-1072 [000] 37.039329:
> => <b7f8a4fe>
> => <0804e33c>
> => <080835c1>
>
> Signed-off-by: walimis <[email protected]>

I'll queue this too, Thanks!

-- Steve

2009-06-07 10:22:20

by walimis

[permalink] [raw]
Subject: [tip:tracing/core] tracing/trace_stack: fix the number of entries in the header

Commit-ID: 083a63b48e4dd0a6a2d44216720076dc81ebb255
Gitweb: http://git.kernel.org/tip/083a63b48e4dd0a6a2d44216720076dc81ebb255
Author: walimis <[email protected]>
AuthorDate: Wed, 3 Jun 2009 16:01:28 +0800
Committer: Steven Rostedt <[email protected]>
CommitDate: Wed, 3 Jun 2009 10:24:44 -0400

tracing/trace_stack: fix the number of entries in the header

The last entry in the stack_dump_trace is ULONG_MAX, which is not
a valid entry, but max_stack_trace.nr_entries has accounted for it.
So when printing the header, we should decrease it by one.
Before fix, print as following, for example:

Depth Size Location (53 entries) <--- should be 52
----- ---- --------
0) 3264 108 update_wall_time+0x4d5/0x9a0
...
51) 80 80 syscall_call+0x7/0xb
^^^
it's correct.

Signed-off-by: walimis <[email protected]>
LKML-Reference: <[email protected]>
Signed-off-by: Steven Rostedt <[email protected]>


---
kernel/trace/trace_stack.c | 2 +-
1 files changed, 1 insertions(+), 1 deletions(-)

diff --git a/kernel/trace/trace_stack.c b/kernel/trace/trace_stack.c
index 1796f00..2d7aebd 100644
--- a/kernel/trace/trace_stack.c
+++ b/kernel/trace/trace_stack.c
@@ -265,7 +265,7 @@ static int t_show(struct seq_file *m, void *v)
seq_printf(m, " Depth Size Location"
" (%d entries)\n"
" ----- ---- --------\n",
- max_stack_trace.nr_entries);
+ max_stack_trace.nr_entries - 1);

if (!stack_tracer_enabled && !max_stack_size)
print_disabled(m);

2009-06-07 10:22:32

by walimis

[permalink] [raw]
Subject: [tip:tracing/core] tracing/events: fix output format of kernel stack

Commit-ID: f11b3f4e2932bfdcfc458ab8d1ece62724ceabfc
Gitweb: http://git.kernel.org/tip/f11b3f4e2932bfdcfc458ab8d1ece62724ceabfc
Author: walimis <[email protected]>
AuthorDate: Wed, 3 Jun 2009 16:01:29 +0800
Committer: Steven Rostedt <[email protected]>
CommitDate: Wed, 3 Jun 2009 10:25:15 -0400

tracing/events: fix output format of kernel stack

According to "events/ftrace/kernel_stack/format", output format of
kernel stack should use "=>" instead of "<=".

The second problem is that we shouldn't skip the first entry in the stack,
although it seems to be duplicated when used in the "function" tracer,
but events also use it. If we skip the first one, we will drop the topmost
entry of the stack.

The last problem is that if the last entry is ULONG_MAX(0xffffffff), we should
drop it, otherwise it will print a NULL name line.

before fix:

sh-1072 [000] 26.957239: sched_process_fork: parent sh:1072 child sh:1073
sh-1072 [000] 26.957262:
<= syscall_call
<=
sh-1072 [000] 26.957744: sched_switch: task sh:1072 [120] (R) ==> sh:1073 [120]
sh-1072 [000] 26.957752:
<= preempt_schedule
<= wake_up_new_task
<= do_fork
<= sys_clone
<= syscall_call
<=

After fix:

sh-1075 [000] 39.791848: sched_process_fork: parent sh:1075 child sh:1076
sh-1075 [000] 39.791871:
=> sys_clone
=> syscall_call
sh-1075 [000] 39.792713: sched_switch: task sh:1075 [120] (R) ==> sh:1076 [120]
sh-1075 [000] 39.792722:
=> schedule
=> preempt_schedule
=> wake_up_new_task
=> do_fork
=> sys_clone
=> syscall_call

Signed-off-by: walimis <[email protected]>
LKML-Reference: <[email protected]>
Signed-off-by: Steven Rostedt <[email protected]>


---
kernel/trace/trace_output.c | 14 +++++++-------
1 files changed, 7 insertions(+), 7 deletions(-)

diff --git a/kernel/trace/trace_output.c b/kernel/trace/trace_output.c
index 0fe3b22..64596a5 100644
--- a/kernel/trace/trace_output.c
+++ b/kernel/trace/trace_output.c
@@ -975,16 +975,16 @@ static enum print_line_t trace_stack_print(struct trace_iterator *iter,

trace_assign_type(field, iter->ent);

+ if (!trace_seq_puts(s, "\n"))
+ goto partial;
for (i = 0; i < FTRACE_STACK_ENTRIES; i++) {
- if (!field->caller[i])
+ if (!field->caller[i] || (field->caller[i] == ULONG_MAX))
break;
- if (i) {
- if (!trace_seq_puts(s, " <= "))
- goto partial;
+ if (!trace_seq_puts(s, " => "))
+ goto partial;

- if (!seq_print_ip_sym(s, field->caller[i], flags))
- goto partial;
- }
+ if (!seq_print_ip_sym(s, field->caller[i], flags))
+ goto partial;
if (!trace_seq_puts(s, "\n"))
goto partial;
}

2009-06-07 10:22:44

by walimis

[permalink] [raw]
Subject: [tip:tracing/core] tracing/events: fix output format of user stack

Commit-ID: 048dc50c5e7eada19ebabbad70b7966d14283d41
Gitweb: http://git.kernel.org/tip/048dc50c5e7eada19ebabbad70b7966d14283d41
Author: walimis <[email protected]>
AuthorDate: Wed, 3 Jun 2009 16:01:30 +0800
Committer: Steven Rostedt <[email protected]>
CommitDate: Wed, 3 Jun 2009 10:25:30 -0400

tracing/events: fix output format of user stack

According to "events/ftrace/user_stack/format", fix the output of
user stack.

before fix:

sh-1073 [000] 31.137561: <b7f274fe> <- <0804e33c> <- <080835c1>

after fix:

sh-1072 [000] 37.039329:
=> <b7f8a4fe>
=> <0804e33c>
=> <080835c1>

Signed-off-by: walimis <[email protected]>
LKML-Reference: <[email protected]>
Signed-off-by: Steven Rostedt <[email protected]>


---
kernel/trace/trace_output.c | 11 +++++++----
1 files changed, 7 insertions(+), 4 deletions(-)

diff --git a/kernel/trace/trace_output.c b/kernel/trace/trace_output.c
index 64596a5..8dadbbb 100644
--- a/kernel/trace/trace_output.c
+++ b/kernel/trace/trace_output.c
@@ -389,17 +389,20 @@ seq_print_userip_objs(const struct userstack_entry *entry, struct trace_seq *s,

if (ip == ULONG_MAX || !ret)
break;
- if (i && ret)
- ret = trace_seq_puts(s, " <- ");
+ if (ret)
+ ret = trace_seq_puts(s, " => ");
if (!ip) {
if (ret)
ret = trace_seq_puts(s, "??");
+ if (ret)
+ ret = trace_seq_puts(s, "\n");
continue;
}
if (!ret)
break;
if (ret)
ret = seq_print_user_ip(s, mm, ip, sym_flags);
+ ret = trace_seq_puts(s, "\n");
}

if (mm)
@@ -1012,10 +1015,10 @@ static enum print_line_t trace_user_stack_print(struct trace_iterator *iter,

trace_assign_type(field, iter->ent);

- if (!seq_print_userip_objs(field, s, flags))
+ if (!trace_seq_putc(s, '\n'))
goto partial;

- if (!trace_seq_putc(s, '\n'))
+ if (!seq_print_userip_objs(field, s, flags))
goto partial;

return TRACE_TYPE_HANDLED;