linux-uconsole/kernel/trace
Steven Rostedt 80736c50f9 tracing: Do not record user stack trace from NMI context
commit b6345879cc upstream.

A bug was found with Li Zefan's ftrace_stress_test that caused applications
to segfault during the test.

Placing a tracing_off() in the segfault code, and examining several
traces, I found that the following was always the case. The lock tracer
was enabled (lockdep being required) and userstack was enabled. Testing
this out, I just enabled the two, but that was not good enough. I needed
to run something else that could trigger it. Running a load like hackbench
did not work, but executing a new program would. The following would
trigger the segfault within seconds:

  # echo 1 > /debug/tracing/options/userstacktrace
  # echo 1 > /debug/tracing/events/lock/enable
  # while :; do ls > /dev/null ; done

Enabling the function graph tracer and looking at what was happening
I finally noticed that all cashes happened just after an NMI.

 1)               |    copy_user_handle_tail() {
 1)               |      bad_area_nosemaphore() {
 1)               |        __bad_area_nosemaphore() {
 1)               |          no_context() {
 1)               |            fixup_exception() {
 1)   0.319 us    |              search_exception_tables();
 1)   0.873 us    |            }
[...]
 1)   0.314 us    |  __rcu_read_unlock();
 1)   0.325 us    |    native_apic_mem_write();
 1)   0.943 us    |  }
 1)   0.304 us    |  rcu_nmi_exit();
[...]
 1)   0.479 us    |  find_vma();
 1)               |  bad_area() {
 1)               |    __bad_area() {

After capturing several traces of failures, all of them happened
after an NMI. Curious about this, I added a trace_printk() to the NMI
handler to read the regs->ip to see where the NMI happened. In which I
found out it was here:

ffffffff8135b660 <page_fault>:
ffffffff8135b660:       48 83 ec 78             sub    $0x78,%rsp
ffffffff8135b664:       e8 97 01 00 00          callq  ffffffff8135b800 <error_entry>

What was happening is that the NMI would happen at the place that a page
fault occurred. It would call rcu_read_lock() which was traced by
the lock events, and the user_stack_trace would run. This would trigger
a page fault inside the NMI. I do not see where the CR2 register is
saved or restored in NMI handling. This means that it would corrupt
the page fault handling that the NMI interrupted.

The reason the while loop of ls helped trigger the bug, was that
each execution of ls would cause lots of pages to be faulted in, and
increase the chances of the race happening.

The simple solution is to not allow user stack traces in NMI context.
After this patch, I ran the above "ls" test for a couple of hours
without any issues. Without this patch, the bug would trigger in less
than a minute.

Reported-by: Li Zefan <lizf@cn.fujitsu.com>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
Signed-off-by: Greg Kroah-Hartman <gregkh@suse.de>
2010-04-01 15:58:12 -07:00
..
blktrace.c Add a tracepoint for block request remapping 2009-10-01 21:19:34 +02:00
ftrace.c function-graph: Init curr_ret_stack with ret_stack 2010-04-01 15:58:10 -07:00
Kconfig trivial: Fix duplicated word "options" in comment 2009-09-21 15:14:58 +02:00
kmemtrace.c kmemtrace: Fix up tracer registration 2009-10-01 11:53:44 +02:00
Makefile tracing, perf: Convert the power tracer into an event tracer 2009-09-19 11:42:12 +02:00
power-traces.c tracing, perf: Convert the power tracer into an event tracer 2009-09-19 11:42:12 +02:00
ring_buffer.c ring-buffer: Move disabled check into preempt disable section 2010-04-01 15:58:08 -07:00
ring_buffer_benchmark.c ring-buffer: have benchmark test print to trace buffer 2009-06-17 17:01:09 -04:00
trace.c tracing: Do not record user stack trace from NMI context 2010-04-01 15:58:12 -07:00
trace.h tracing, perf: Convert the power tracer into an event tracer 2009-09-19 11:42:12 +02:00
trace_boot.c tracing: add filter event logic to special, mmiotrace and boot tracers 2009-09-12 23:34:04 -04:00
trace_branch.c tracing: user local buffer variable for trace branch tracer 2009-10-07 21:53:41 -04:00
trace_clock.c tracing: optimize global_trace_clock cachelines 2009-09-15 12:24:22 -04:00
trace_entries.h tracing, perf: Convert the power tracer into an event tracer 2009-09-19 11:42:12 +02:00
trace_event_profile.c tracing: Use free_percpu instead of kfree 2009-10-05 10:57:56 +02:00
trace_events.c tracing: Check the return value of trace_get_user() 2009-09-22 10:28:55 +02:00
trace_events_filter.c tracing/filters: Fix memory leak when setting a filter 2009-10-13 08:05:17 +02:00
trace_export.c tracing: remove some unused macros 2009-09-14 11:43:24 -04:00
trace_functions.c tracing: switch function prints from %pf to %ps 2009-09-17 15:53:40 -04:00
trace_functions_graph.c tracing: switch function prints from %pf to %ps 2009-09-17 15:53:40 -04:00
trace_hw_branches.c tracing: fix warning on kernel/trace/trace_branch.c andtrace_hw_branches.c 2009-10-07 21:52:03 -04:00
trace_irqsoff.c tracing: do not update tracing_max_latency when tracer is stopped 2009-09-12 21:45:17 -04:00
trace_mmiotrace.c tracing: add filter event logic to special, mmiotrace and boot tracers 2009-09-12 23:34:04 -04:00
trace_nop.c tracing/ftrace: make nop-tracer use polling wait for events on pipe 2009-03-23 09:22:15 +01:00
trace_output.c tracing: Fix trace_seq_printf() return value 2009-10-24 11:07:50 +02:00
trace_output.h tracing: consolidate code between trace_output.c and trace_function_graph.c 2009-09-11 14:24:13 -04:00
trace_printk.c tracing: Remove markers 2009-09-18 21:22:08 +02:00
trace_sched_switch.c tracing: pass around ring buffer instead of tracer 2009-09-04 18:59:39 -04:00
trace_sched_wakeup.c tracing: do not update tracing_max_latency when tracer is stopped 2009-09-12 21:45:17 -04:00
trace_selftest.c tracing/function-graph-tracer: Move graph event insertion helpers in the graph tracer file 2009-08-06 07:28:06 +02:00
trace_selftest_dynamic.c ftrace: fix dynamic ftrace selftest 2008-05-23 21:13:23 +02:00
trace_stack.c sysctl: remove "struct file *" argument of ->proc_handler 2009-09-24 07:21:04 -07:00
trace_stat.c trace_stat: Fix missing entry in stat file 2009-08-17 11:25:09 +02:00
trace_stat.h tracing/stat: Add stat_release() callback 2009-07-10 12:14:05 +02:00
trace_syscalls.c tracing/syscalls: Use long for syscall ret format and field definitions 2009-10-06 12:02:34 +02:00
trace_sysprof.c Merge branch 'timers-for-linus-migration' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/linux-2.6-tip 2009-06-15 10:06:19 -07:00
trace_workqueue.c tracing/workqueues: Add refcnt to struct cpu_workqueue_stats 2009-07-10 12:14:07 +02:00