diff options
author | Steven Rostedt (Red Hat) <rostedt@goodmis.org> | 2013-03-15 13:10:35 -0400 |
---|---|---|
committer | Steven Rostedt <rostedt@goodmis.org> | 2013-03-15 19:24:56 -0400 |
commit | 7fe70b579c9e3daba71635e31b6189394e7b79d3 (patch) | |
tree | 742f410da0aa17257e7d2c4aebe538729e27338f | |
parent | 52f6ad6dc3f4c6de598fe7cc9b629888d624aa52 (diff) |
tracing: Fix ftrace_dump()
ftrace_dump() had a lot of issues. What ftrace_dump() does, is when
ftrace_dump_on_oops is set (via a kernel parameter or sysctl), it
will dump out the ftrace buffers to the console when either a oops,
panic, or a sysrq-z occurs.
This was written a long time ago when ftrace was fragile to recursion.
But it wasn't written well even for that.
There's a possible deadlock that can occur if a ftrace_dump() is happening
and an NMI triggers another dump. This is because it grabs a lock
before checking if the dump ran.
It also totally disables ftrace, and tracing for no good reasons.
As the ring_buffer now checks if it is read via a oops or NMI, where
there's a chance that the buffer gets corrupted, it will disable
itself. No need to have ftrace_dump() do the same.
ftrace_dump() is now cleaned up where it uses an atomic counter to
make sure only one dump happens at a time. A simple atomic_inc_return()
is enough that is needed for both other CPUs and NMIs. No need for
a spinlock, as if one CPU is running the dump, no other CPU needs
to do it too.
The tracing_on variable is turned off and not turned on. The original
code did this, but it wasn't pretty. By just disabling this variable
we get the result of not seeing traces that happen between crashes.
For sysrq-z, it doesn't get turned on, but the user can always write
a '1' to the tracing_on file. If they are using sysrq-z, then they should
know about tracing_on.
The new code is much easier to read and less error prone. No more
deadlock possibility when an NMI triggers here.
Reported-by: zhangwei(Jovi) <jovi.zhangwei@huawei.com>
Cc: stable@vger.kernel.org
Cc: Thomas Gleixner <tglx@linutronix.de>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
-rw-r--r-- | kernel/trace/trace.c | 62 | ||||
-rw-r--r-- | kernel/trace/trace_selftest.c | 9 |
2 files changed, 31 insertions, 40 deletions
diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c index 848625674752..3dc7999594e1 100644 --- a/kernel/trace/trace.c +++ b/kernel/trace/trace.c | |||
@@ -5997,36 +5997,32 @@ void trace_init_global_iter(struct trace_iterator *iter) | |||
5997 | iter->trace_buffer = &global_trace.trace_buffer; | 5997 | iter->trace_buffer = &global_trace.trace_buffer; |
5998 | } | 5998 | } |
5999 | 5999 | ||
6000 | static void | 6000 | void ftrace_dump(enum ftrace_dump_mode oops_dump_mode) |
6001 | __ftrace_dump(bool disable_tracing, enum ftrace_dump_mode oops_dump_mode) | ||
6002 | { | 6001 | { |
6003 | static arch_spinlock_t ftrace_dump_lock = | ||
6004 | (arch_spinlock_t)__ARCH_SPIN_LOCK_UNLOCKED; | ||
6005 | /* use static because iter can be a bit big for the stack */ | 6002 | /* use static because iter can be a bit big for the stack */ |
6006 | static struct trace_iterator iter; | 6003 | static struct trace_iterator iter; |
6004 | static atomic_t dump_running; | ||
6007 | unsigned int old_userobj; | 6005 | unsigned int old_userobj; |
6008 | static int dump_ran; | ||
6009 | unsigned long flags; | 6006 | unsigned long flags; |
6010 | int cnt = 0, cpu; | 6007 | int cnt = 0, cpu; |
6011 | 6008 | ||
6012 | /* only one dump */ | 6009 | /* Only allow one dump user at a time. */ |
6013 | local_irq_save(flags); | 6010 | if (atomic_inc_return(&dump_running) != 1) { |
6014 | arch_spin_lock(&ftrace_dump_lock); | 6011 | atomic_dec(&dump_running); |
6015 | if (dump_ran) | 6012 | return; |
6016 | goto out; | 6013 | } |
6017 | |||
6018 | dump_ran = 1; | ||
6019 | 6014 | ||
6015 | /* | ||
6016 | * Always turn off tracing when we dump. | ||
6017 | * We don't need to show trace output of what happens | ||
6018 | * between multiple crashes. | ||
6019 | * | ||
6020 | * If the user does a sysrq-z, then they can re-enable | ||
6021 | * tracing with echo 1 > tracing_on. | ||
6022 | */ | ||
6020 | tracing_off(); | 6023 | tracing_off(); |
6021 | 6024 | ||
6022 | /* Did function tracer already get disabled? */ | 6025 | local_irq_save(flags); |
6023 | if (ftrace_is_dead()) { | ||
6024 | printk("# WARNING: FUNCTION TRACING IS CORRUPTED\n"); | ||
6025 | printk("# MAY BE MISSING FUNCTION EVENTS\n"); | ||
6026 | } | ||
6027 | |||
6028 | if (disable_tracing) | ||
6029 | ftrace_kill(); | ||
6030 | 6026 | ||
6031 | /* Simulate the iterator */ | 6027 | /* Simulate the iterator */ |
6032 | trace_init_global_iter(&iter); | 6028 | trace_init_global_iter(&iter); |
@@ -6056,6 +6052,12 @@ __ftrace_dump(bool disable_tracing, enum ftrace_dump_mode oops_dump_mode) | |||
6056 | 6052 | ||
6057 | printk(KERN_TRACE "Dumping ftrace buffer:\n"); | 6053 | printk(KERN_TRACE "Dumping ftrace buffer:\n"); |
6058 | 6054 | ||
6055 | /* Did function tracer already get disabled? */ | ||
6056 | if (ftrace_is_dead()) { | ||
6057 | printk("# WARNING: FUNCTION TRACING IS CORRUPTED\n"); | ||
6058 | printk("# MAY BE MISSING FUNCTION EVENTS\n"); | ||
6059 | } | ||
6060 | |||
6059 | /* | 6061 | /* |
6060 | * We need to stop all tracing on all CPUS to read the | 6062 | * We need to stop all tracing on all CPUS to read the |
6061 | * the next buffer. This is a bit expensive, but is | 6063 | * the next buffer. This is a bit expensive, but is |
@@ -6095,26 +6097,14 @@ __ftrace_dump(bool disable_tracing, enum ftrace_dump_mode oops_dump_mode) | |||
6095 | printk(KERN_TRACE "---------------------------------\n"); | 6097 | printk(KERN_TRACE "---------------------------------\n"); |
6096 | 6098 | ||
6097 | out_enable: | 6099 | out_enable: |
6098 | /* Re-enable tracing if requested */ | 6100 | trace_flags |= old_userobj; |
6099 | if (!disable_tracing) { | ||
6100 | trace_flags |= old_userobj; | ||
6101 | 6101 | ||
6102 | for_each_tracing_cpu(cpu) { | 6102 | for_each_tracing_cpu(cpu) { |
6103 | atomic_dec(&per_cpu_ptr(iter.trace_buffer->data, cpu)->disabled); | 6103 | atomic_dec(&per_cpu_ptr(iter.trace_buffer->data, cpu)->disabled); |
6104 | } | ||
6105 | tracing_on(); | ||
6106 | } | 6104 | } |
6107 | 6105 | atomic_dec(&dump_running); | |
6108 | out: | ||
6109 | arch_spin_unlock(&ftrace_dump_lock); | ||
6110 | local_irq_restore(flags); | 6106 | local_irq_restore(flags); |
6111 | } | 6107 | } |
6112 | |||
6113 | /* By default: disable tracing after the dump */ | ||
6114 | void ftrace_dump(enum ftrace_dump_mode oops_dump_mode) | ||
6115 | { | ||
6116 | __ftrace_dump(true, oops_dump_mode); | ||
6117 | } | ||
6118 | EXPORT_SYMBOL_GPL(ftrace_dump); | 6108 | EXPORT_SYMBOL_GPL(ftrace_dump); |
6119 | 6109 | ||
6120 | __init static int tracer_alloc_buffers(void) | 6110 | __init static int tracer_alloc_buffers(void) |
diff --git a/kernel/trace/trace_selftest.c b/kernel/trace/trace_selftest.c index 8672c40cb153..55e2cf66967b 100644 --- a/kernel/trace/trace_selftest.c +++ b/kernel/trace/trace_selftest.c | |||
@@ -703,8 +703,6 @@ trace_selftest_startup_function(struct tracer *trace, struct trace_array *tr) | |||
703 | /* Maximum number of functions to trace before diagnosing a hang */ | 703 | /* Maximum number of functions to trace before diagnosing a hang */ |
704 | #define GRAPH_MAX_FUNC_TEST 100000000 | 704 | #define GRAPH_MAX_FUNC_TEST 100000000 |
705 | 705 | ||
706 | static void | ||
707 | __ftrace_dump(bool disable_tracing, enum ftrace_dump_mode oops_dump_mode); | ||
708 | static unsigned int graph_hang_thresh; | 706 | static unsigned int graph_hang_thresh; |
709 | 707 | ||
710 | /* Wrap the real function entry probe to avoid possible hanging */ | 708 | /* Wrap the real function entry probe to avoid possible hanging */ |
@@ -714,8 +712,11 @@ static int trace_graph_entry_watchdog(struct ftrace_graph_ent *trace) | |||
714 | if (unlikely(++graph_hang_thresh > GRAPH_MAX_FUNC_TEST)) { | 712 | if (unlikely(++graph_hang_thresh > GRAPH_MAX_FUNC_TEST)) { |
715 | ftrace_graph_stop(); | 713 | ftrace_graph_stop(); |
716 | printk(KERN_WARNING "BUG: Function graph tracer hang!\n"); | 714 | printk(KERN_WARNING "BUG: Function graph tracer hang!\n"); |
717 | if (ftrace_dump_on_oops) | 715 | if (ftrace_dump_on_oops) { |
718 | __ftrace_dump(false, DUMP_ALL); | 716 | ftrace_dump(DUMP_ALL); |
717 | /* ftrace_dump() disables tracing */ | ||
718 | tracing_on(); | ||
719 | } | ||
719 | return 0; | 720 | return 0; |
720 | } | 721 | } |
721 | 722 | ||