2011-06-09 17:29:24

by Steven Rostedt

[permalink] [raw]
Subject: [PATCH 15/15] tracing/kprobes: Fix kprobe-tracer to support stack trace

From: Masami Hiramatsu <[email protected]>

Fix to support kernel stack trace correctly on kprobe-tracer.
Since the execution path of kprobe-based dynamic events is different
from other tracepoint-based events, normal ftrace_trace_stack() doesn't
work correctly. To fix that, this introduces ftrace_trace_stack_regs()
which traces stack via pt_regs instead of current stack register.

e.g.

# echo p schedule+4 > /sys/kernel/debug/tracing/kprobe_events
# echo 1 > /sys/kernel/debug/tracing/options/stacktrace
# echo 1 > /sys/kernel/debug/tracing/events/kprobes/enable
# head -n 20 /sys/kernel/debug/tracing/trace
# tracer: nop
#
# TASK-PID CPU# TIMESTAMP FUNCTION
# | | | | |
bash-2968 [000] 10297.050245: p_schedule_4: (schedule+0x4/0x4ca)
bash-2968 [000] 10297.050247: <stack trace>
=> schedule_timeout
=> n_tty_read
=> tty_read
=> vfs_read
=> sys_read
=> system_call_fastpath
kworker/0:1-2940 [000] 10297.050265: p_schedule_4: (schedule+0x4/0x4ca)
kworker/0:1-2940 [000] 10297.050266: <stack trace>
=> worker_thread
=> kthread
=> kernel_thread_helper
sshd-1132 [000] 10297.050365: p_schedule_4: (schedule+0x4/0x4ca)
sshd-1132 [000] 10297.050365: <stack trace>
=> sysret_careful

Note: Even with this fix, the first entry will be skipped
if the probe is put on the function entry area before
the frame pointer is set up (usually, that is 4 bytes
(push %bp; mov %sp %bp) on x86), because stack unwinder
depends on the frame pointer.

Cc: Ingo Molnar <[email protected]>
Cc: [email protected]
Signed-off-by: Masami Hiramatsu <[email protected]>
Cc: Frederic Weisbecker <[email protected]>
Cc: Ingo Molnar <[email protected]>
Cc: Peter Zijlstra <[email protected]>
Cc: Namhyung Kim <[email protected]>
Cc: [email protected]
Link: http://lkml.kernel.org/r/20110608070934.17777.17116.stgit@fedora15
Signed-off-by: Steven Rostedt <[email protected]>
---
include/linux/ftrace_event.h | 4 ++++
kernel/trace/trace.c | 35 ++++++++++++++++++++++++++++++-----
kernel/trace/trace.h | 9 +++++++++
kernel/trace/trace_kprobe.c | 6 ++++--
4 files changed, 47 insertions(+), 7 deletions(-)

diff --git a/include/linux/ftrace_event.h b/include/linux/ftrace_event.h
index 59d3ef1..b1e69ee 100644
--- a/include/linux/ftrace_event.h
+++ b/include/linux/ftrace_event.h
@@ -129,6 +129,10 @@ void trace_current_buffer_unlock_commit(struct ring_buffer *buffer,
void trace_nowake_buffer_unlock_commit(struct ring_buffer *buffer,
struct ring_buffer_event *event,
unsigned long flags, int pc);
+void trace_nowake_buffer_unlock_commit_regs(struct ring_buffer *buffer,
+ struct ring_buffer_event *event,
+ unsigned long flags, int pc,
+ struct pt_regs *regs);
void trace_current_buffer_discard_commit(struct ring_buffer *buffer,
struct ring_buffer_event *event);

diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index b05eb28..db62cda 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -1192,6 +1192,18 @@ void trace_nowake_buffer_unlock_commit(struct ring_buffer *buffer,
}
EXPORT_SYMBOL_GPL(trace_nowake_buffer_unlock_commit);

+void trace_nowake_buffer_unlock_commit_regs(struct ring_buffer *buffer,
+ struct ring_buffer_event *event,
+ unsigned long flags, int pc,
+ struct pt_regs *regs)
+{
+ ring_buffer_unlock_commit(buffer, event);
+
+ ftrace_trace_stack_regs(buffer, flags, 0, pc, regs);
+ ftrace_trace_userstack(buffer, flags, pc);
+}
+EXPORT_SYMBOL_GPL(trace_nowake_buffer_unlock_commit_regs);
+
void trace_current_buffer_discard_commit(struct ring_buffer *buffer,
struct ring_buffer_event *event)
{
@@ -1237,7 +1249,7 @@ ftrace(struct trace_array *tr, struct trace_array_cpu *data,
#ifdef CONFIG_STACKTRACE
static void __ftrace_trace_stack(struct ring_buffer *buffer,
unsigned long flags,
- int skip, int pc)
+ int skip, int pc, struct pt_regs *regs)
{
struct ftrace_event_call *call = &event_kernel_stack;
struct ring_buffer_event *event;
@@ -1256,24 +1268,36 @@ static void __ftrace_trace_stack(struct ring_buffer *buffer,
trace.skip = skip;
trace.entries = entry->caller;

- save_stack_trace(&trace);
+ if (regs)
+ save_stack_trace_regs(regs, &trace);
+ else
+ save_stack_trace(&trace);
if (!filter_check_discard(call, entry, buffer, event))
ring_buffer_unlock_commit(buffer, event);
}

+void ftrace_trace_stack_regs(struct ring_buffer *buffer, unsigned long flags,
+ int skip, int pc, struct pt_regs *regs)
+{
+ if (!(trace_flags & TRACE_ITER_STACKTRACE))
+ return;
+
+ __ftrace_trace_stack(buffer, flags, skip, pc, regs);
+}
+
void ftrace_trace_stack(struct ring_buffer *buffer, unsigned long flags,
int skip, int pc)
{
if (!(trace_flags & TRACE_ITER_STACKTRACE))
return;

- __ftrace_trace_stack(buffer, flags, skip, pc);
+ __ftrace_trace_stack(buffer, flags, skip, pc, NULL);
}

void __trace_stack(struct trace_array *tr, unsigned long flags, int skip,
int pc)
{
- __ftrace_trace_stack(tr->buffer, flags, skip, pc);
+ __ftrace_trace_stack(tr->buffer, flags, skip, pc, NULL);
}

/**
@@ -1289,7 +1313,8 @@ void trace_dump_stack(void)
local_save_flags(flags);

/* skipping 3 traces, seems to get us at the caller of this function */
- __ftrace_trace_stack(global_trace.buffer, flags, 3, preempt_count());
+ __ftrace_trace_stack(global_trace.buffer, flags, 3, preempt_count(),
+ NULL);
}

static DEFINE_PER_CPU(int, user_stack_count);
diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
index 229f859..caee141 100644
--- a/kernel/trace/trace.h
+++ b/kernel/trace/trace.h
@@ -389,6 +389,9 @@ void update_max_tr_single(struct trace_array *tr,
void ftrace_trace_stack(struct ring_buffer *buffer, unsigned long flags,
int skip, int pc);

+void ftrace_trace_stack_regs(struct ring_buffer *buffer, unsigned long flags,
+ int skip, int pc, struct pt_regs *regs);
+
void ftrace_trace_userstack(struct ring_buffer *buffer, unsigned long flags,
int pc);

@@ -400,6 +403,12 @@ static inline void ftrace_trace_stack(struct ring_buffer *buffer,
{
}

+static inline void ftrace_trace_stack_regs(struct ring_buffer *buffer,
+ unsigned long flags, int skip,
+ int pc, struct pt_regs *regs)
+{
+}
+
static inline void ftrace_trace_userstack(struct ring_buffer *buffer,
unsigned long flags, int pc)
{
diff --git a/kernel/trace/trace_kprobe.c b/kernel/trace/trace_kprobe.c
index f925c45..7053ef3 100644
--- a/kernel/trace/trace_kprobe.c
+++ b/kernel/trace/trace_kprobe.c
@@ -1397,7 +1397,8 @@ static __kprobes void kprobe_trace_func(struct kprobe *kp, struct pt_regs *regs)
store_trace_args(sizeof(*entry), tp, regs, (u8 *)&entry[1], dsize);

if (!filter_current_check_discard(buffer, call, entry, event))
- trace_nowake_buffer_unlock_commit(buffer, event, irq_flags, pc);
+ trace_nowake_buffer_unlock_commit_regs(buffer, event,
+ irq_flags, pc, regs);
}

/* Kretprobe handler */
@@ -1429,7 +1430,8 @@ static __kprobes void kretprobe_trace_func(struct kretprobe_instance *ri,
store_trace_args(sizeof(*entry), tp, regs, (u8 *)&entry[1], dsize);

if (!filter_current_check_discard(buffer, call, entry, event))
- trace_nowake_buffer_unlock_commit(buffer, event, irq_flags, pc);
+ trace_nowake_buffer_unlock_commit_regs(buffer, event,
+ irq_flags, pc, regs);
}

/* Event entry printers */
--
1.7.4.4


2011-06-13 10:21:37

by Ingo Molnar

[permalink] [raw]
Subject: Re: [PATCH 15/15] tracing/kprobes: Fix kprobe-tracer to support stack trace


* Steven Rostedt <[email protected]> wrote:

> Cc: Ingo Molnar <[email protected]>
> Cc: [email protected]
> Signed-off-by: Masami Hiramatsu <[email protected]>
> Cc: Frederic Weisbecker <[email protected]>
> Cc: Ingo Molnar <[email protected]>
> Cc: Peter Zijlstra <[email protected]>
> Cc: Namhyung Kim <[email protected]>
> Cc: [email protected]
> Link: http://lkml.kernel.org/r/20110608070934.17777.17116.stgit@fedora15
> Signed-off-by: Steven Rostedt <[email protected]>

Very sloppy tags section as well, see previous mail.

> + __ftrace_trace_stack(global_trace.buffer, flags, 3, preempt_count(),
> + NULL);

pointless linebreak.

Thanks,

Ingo

2011-06-13 11:44:47

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH 15/15] tracing/kprobes: Fix kprobe-tracer to support stack trace

On Mon, 2011-06-13 at 12:21 +0200, Ingo Molnar wrote:
> * Steven Rostedt <[email protected]> wrote:
>
> > Cc: Ingo Molnar <[email protected]>
> > Cc: [email protected]
> > Signed-off-by: Masami Hiramatsu <[email protected]>
> > Cc: Frederic Weisbecker <[email protected]>
> > Cc: Ingo Molnar <[email protected]>
> > Cc: Peter Zijlstra <[email protected]>
> > Cc: Namhyung Kim <[email protected]>
> > Cc: [email protected]
> > Link: http://lkml.kernel.org/r/20110608070934.17777.17116.stgit@fedora15
> > Signed-off-by: Steven Rostedt <[email protected]>
>
> Very sloppy tags section as well, see previous mail.

Same cause as in previous email.

>
> > + __ftrace_trace_stack(global_trace.buffer, flags, 3, preempt_count(),
> > + NULL);
>
> pointless linebreak.

Again, probably to do with the 80 char limit.

-- Steve

>
> Thanks,
>
> Ingo

2011-06-13 11:51:09

by Ingo Molnar

[permalink] [raw]
Subject: Re: [PATCH 15/15] tracing/kprobes: Fix kprobe-tracer to support stack trace


* Steven Rostedt <[email protected]> wrote:

> > > + __ftrace_trace_stack(global_trace.buffer, flags, 3, preempt_count(),
> > > + NULL);
> >
> > pointless linebreak.
>
> Again, probably to do with the 80 char limit.

Well, the point of the 80 char limit warning these days is to force a
cleanup of the code. Breaking the line mindlessly *uglifies* the code
so it's pointless to do it.

In terms of terminal readability line length up to 90-100 cols is
acceptable for code that is otherwise not ugly.

Thanks,

Ingo

2011-06-13 12:14:51

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH 15/15] tracing/kprobes: Fix kprobe-tracer to support stack trace

On Mon, 2011-06-13 at 13:50 +0200, Ingo Molnar wrote:
> * Steven Rostedt <[email protected]> wrote:
>
> > > > + __ftrace_trace_stack(global_trace.buffer, flags, 3, preempt_count(),
> > > > + NULL);
> > >
> > > pointless linebreak.
> >
> > Again, probably to do with the 80 char limit.
>
> Well, the point of the 80 char limit warning these days is to force a
> cleanup of the code. Breaking the line mindlessly *uglifies* the code
> so it's pointless to do it.
>
> In terms of terminal readability line length up to 90-100 cols is
> acceptable for code that is otherwise not ugly.

I totally agree. I've just had arguments with others that are more 80
character nazi than I am. ;)

-- Steve

Subject: Re: [PATCH 15/15] tracing/kprobes: Fix kprobe-tracer to support stack trace

(2011/06/13 21:14), Steven Rostedt wrote:
> On Mon, 2011-06-13 at 13:50 +0200, Ingo Molnar wrote:
>> * Steven Rostedt <[email protected]> wrote:
>>
>>>>> + __ftrace_trace_stack(global_trace.buffer, flags, 3, preempt_count(),
>>>>> + NULL);
>>>>
>>>> pointless linebreak.
>>>
>>> Again, probably to do with the 80 char limit.
>>
>> Well, the point of the 80 char limit warning these days is to force a
>> cleanup of the code. Breaking the line mindlessly *uglifies* the code
>> so it's pointless to do it.
>>
>> In terms of terminal readability line length up to 90-100 cols is
>> acceptable for code that is otherwise not ugly.
>
> I totally agree. I've just had arguments with others that are more 80
> character nazi than I am. ;)

I see, nowadays most of laptops has a wide screen (16:9) :P


--
Masami HIRAMATSU
Software Platform Research Dept. Linux Technology Center
Hitachi, Ltd., Yokohama Research Laboratory
E-mail: [email protected]

2011-06-14 02:08:50

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH 15/15] tracing/kprobes: Fix kprobe-tracer to support stack trace

On Tue, 2011-06-14 at 10:25 +0900, Masami Hiramatsu wrote:

> I see, nowadays most of laptops has a wide screen (16:9) :P

<offtopic rant>

I totally hate this trend! I don't use computers to watch wide screen
movies! I use computers to do work. Who can get anything done with one
of these wide screen monitors?

I had to get my old LCD monitor restored, because I couldn't stand the
stupid wide screen I used to replace it. I find vertical space more high
valued real-estate than horizontal space.

The world is designed by idiots!

</offtopic rant>

-- Steve

2011-06-14 11:23:23

by Peter Zijlstra

[permalink] [raw]
Subject: Re: [PATCH 15/15] tracing/kprobes: Fix kprobe-tracer to support stack trace

On Mon, 2011-06-13 at 22:08 -0400, Steven Rostedt wrote:
> On Tue, 2011-06-14 at 10:25 +0900, Masami Hiramatsu wrote:
>
> > I see, nowadays most of laptops has a wide screen (16:9) :P
>
> <offtopic rant>
>
> I totally hate this trend! I don't use computers to watch wide screen
> movies! I use computers to do work. Who can get anything done with one
> of these wide screen monitors?

I've got 2 16:10 screens, yielding 8 columns of text ~90 chars wide.

> I had to get my old LCD monitor restored, because I couldn't stand the
> stupid wide screen I used to replace it. I find vertical space more high
> valued real-estate than horizontal space.
>
> The world is designed by idiots!

*grin*, I fully concur though, this 16:9 craze is totally annoying. The
worst part is that you cannot even vote with your wallet, its impossible
to buy a laptop without 16:9 screen these days.

fwiw, I didn't mind the 1600x1200 -> 1920x1200 step, that was same
height yet more pixels, yay!

But 16:9 is utter crap, the other totally annoying thing is that people
are forced to use these totally insane low-res screens. Most 12-15"
laptops come with a resolution about equal to the latest iPhone, fsck
that. I want a 12-13" with that same 300ppi ;-)

Screen resolution used to go up, but ever since this HD-tv crap
(720p/1080i should be shot in the head) got popular screen res went
down! /me can't wait for this 4K format to become popular.

> </offtopic rant>