Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1753186AbbKQJJ7 (ORCPT ); Tue, 17 Nov 2015 04:09:59 -0500 Received: from [123.57.207.116] ([123.57.207.116]:57273 "EHLO enight.me" rhost-flags-FAIL-FAIL-OK-OK) by vger.kernel.org with ESMTP id S1751679AbbKQJJz (ORCPT ); Tue, 17 Nov 2015 04:09:55 -0500 X-Greylist: delayed 501 seconds by postgrey-1.27 at vger.kernel.org; Tue, 17 Nov 2015 04:09:54 EST From: Junjie Mao To: Steven Rostedt Cc: Ingo Molnar , linux-kernel@vger.kernel.org, Junjie Mao Subject: [PATCH] Initialize iter->started in trace_init_global_iter() Date: Tue, 17 Nov 2015 17:01:02 +0800 Message-Id: <1447750862-10595-1-git-send-email-junjie.mao@enight.me> X-Mailer: git-send-email 1.9.3 Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Length: 7067 Lines: 169 iter->started will be used in test_cpu_buff_start() if TRACE_FILE_ANNOTATE is set in iter->iter_flags, which can happen when the ring buffer has overrun at the time trace_init_global_iter() is called. A null pointer is then dereferenced under such circumstances. Here is a call trace of this problem triggered by running RCU torture and ftrace startup test at boot time. [ 123.244095] --------------------------------- [ 123.244670] BUG: unable to handle kernel NULL pointer dereference at (null) [ 123.245668] IP: [] print_trace_line+0x2c3/0x39b [ 123.246450] PGD 12d14067 PUD 138b9067 PMD 0 [ 123.247056] Oops: 0000 [#1] PREEMPT SMP [ 123.247618] CPU: 1 PID: 54 Comm: rcu_torture_sta Not tainted 3.17.0-00001-gd3afe7f99dca-dirty #9 [ 123.248717] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 123.249433] task: ffff880007bc4000 ti: ffff880007bc8000 task.ti: ffff880007bc8000 [ 123.250022] RIP: 0010:[] [] print_trace_line+0x2c3/0x39b [ 123.250022] RSP: 0018:ffff880007bcbc98 EFLAGS: 00010097 [ 123.250022] RAX: 0000000000000001 RBX: ffffffff8fa6acc0 RCX: 0000000000000000 [ 123.250022] RDX: 0000000000000001 RSI: ffffffff8d32d7a8 RDI: 0000000000000001 [ 123.250022] RBP: ffff880007bcbcc8 R08: 000000000000000a R09: 00000000fffffff4 [ 123.250022] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000003bd1201 [ 123.250022] R13: ffff8800122bc014 R14: ffffffff8fa6bdbc R15: 0000000000000000 [ 123.250022] FS: 0000000000000000(0000) GS:ffff880012600000(0000) knlGS:0000000000000000 [ 123.250022] CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b [ 123.250022] CR2: 0000000000000000 CR3: 0000000012cb3000 CR4: 00000000000006a0 [ 123.250022] DR0: 000000000068b000 DR1: 0000000000000000 DR2: 0000000000000000 [ 123.250022] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000600 [ 123.250022] Stack: [ 123.250022] 0000000000000001 0000000000000001 0000000000000282 ffffffff8fa6bdbc [ 123.250022] 0000000000000000 0000000000000000 ffff880007bcbcf8 ffffffff8bba4c30 [ 123.250022] ffff880012e6414c ffffffff8fa4ffec ffff880012e640ac ffff880012e6409e [ 123.250022] Call Trace: [ 123.250022] [] ftrace_dump+0x1a1/0x235 [ 123.250022] [] rcutorture_trace_dump+0x57/0x59 [ 123.250022] [] rcu_torture_printk+0x4af/0x4cd [ 123.250022] [] ? rcu_torture_stats_print+0x83/0x83 [ 123.250022] [] rcu_torture_stats_print+0x65/0x83 [ 123.250022] [] rcu_torture_stats+0x4e/0x73 [ 123.250022] [] kthread+0xe6/0xee [ 123.250022] [] ? __kthread_parkme+0x80/0x80 [ 123.250022] [] ret_from_fork+0x7c/0xb0 [ 123.250022] [] ? __kthread_parkme+0x80/0x80 [ 123.250022] Code: e9 e0 00 00 00 41 f7 c4 00 10 00 00 74 7c f6 83 d8 00 00 00 02 74 73 8b bb 20 21 00 00 4c 8b bb f0 10 00 00 e8 cd b2 ff ff 89 c0 <49> 0f a3 07 19 c0 85 c0 75 55 8b bb 20 21 00 00 48 8b 43 10 48 [ 123.250022] RIP [] print_trace_line+0x2c3/0x39b [ 123.250022] RSP [ 123.250022] CR2: 0000000000000000 [ 123.250022] ---[ end trace 96d7b02518a11e33 ]--- [ 123.250022] Kernel panic - not syncing: Fatal exception [ 123.250022] Kernel Offset: 0xaa00000 from 0xffffffff81000000 (relocation range: 0xffffffff80000000-0xffffffffbfffffff) This bug has been reported in http://lkml.org/lkml/2014/9/2/11. Reported-by: Fengguang Wu Signed-off-by: Junjie Mao --- kernel/trace/trace.c | 23 +++++++++++++++++++++-- kernel/trace/trace.h | 3 ++- kernel/trace/trace_kdb.c | 8 +++++++- 3 files changed, 30 insertions(+), 4 deletions(-) diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c index 6e79408674aa..36c642154758 100644 --- a/kernel/trace/trace.c +++ b/kernel/trace/trace.c @@ -6940,13 +6940,22 @@ trace_printk_seq(struct trace_seq *s) trace_seq_init(s); } -void trace_init_global_iter(struct trace_iterator *iter) +int trace_init_global_iter(struct trace_iterator *iter) { iter->tr = &global_trace; iter->trace = iter->tr->current_trace; iter->cpu_file = RING_BUFFER_ALL_CPUS; iter->trace_buffer = &global_trace.trace_buffer; + /* + * iter->started will be used if the ring buffer has overrun. + * + * We allocate it with GFP_NOWAIT since this function can be called with + * interrupt disabled. + */ + if (!zalloc_cpumask_var(&iter->started, GFP_NOWAIT)) + return -ENOMEM; + if (iter->trace && iter->trace->open) iter->trace->open(iter); @@ -6957,6 +6966,12 @@ void trace_init_global_iter(struct trace_iterator *iter) /* Output in nanoseconds only if we are using a clock in nanoseconds. */ if (trace_clocks[iter->tr->clock_id].in_ns) iter->iter_flags |= TRACE_FILE_TIME_IN_NS; + + return 0; +} + +void trace_finalize_global_iter(struct trace_iterator *iter) { + free_cpumask_var(iter->started); } void ftrace_dump(enum ftrace_dump_mode oops_dump_mode) @@ -6987,7 +7002,10 @@ void ftrace_dump(enum ftrace_dump_mode oops_dump_mode) local_irq_save(flags); /* Simulate the iterator */ - trace_init_global_iter(&iter); + if (trace_init_global_iter(&iter) < 0) { + printk(KERN_WARNING "Global iter initialization fails\n"); + return; + } for_each_tracing_cpu(cpu) { atomic_inc(&per_cpu_ptr(iter.trace_buffer->data, cpu)->disabled); @@ -7066,6 +7084,7 @@ void ftrace_dump(enum ftrace_dump_mode oops_dump_mode) } atomic_dec(&dump_running); local_irq_restore(flags); + trace_finalize_global_iter(&iter); } EXPORT_SYMBOL_GPL(ftrace_dump); diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h index 74bde81601a9..133c43b89b37 100644 --- a/kernel/trace/trace.h +++ b/kernel/trace/trace.h @@ -567,7 +567,8 @@ int trace_empty(struct trace_iterator *iter); void *trace_find_next_entry_inc(struct trace_iterator *iter); -void trace_init_global_iter(struct trace_iterator *iter); +int trace_init_global_iter(struct trace_iterator *iter); +void trace_finalize_global_iter(struct trace_iterator *iter); void tracing_iter_reset(struct trace_iterator *iter, int cpu); diff --git a/kernel/trace/trace_kdb.c b/kernel/trace/trace_kdb.c index 3ccf5c2c1320..3d75e15fccbc 100644 --- a/kernel/trace/trace_kdb.c +++ b/kernel/trace/trace_kdb.c @@ -24,7 +24,11 @@ static void ftrace_dump_buf(int skip_lines, long cpu_file) unsigned int old_userobj; int cnt = 0, cpu; - trace_init_global_iter(&iter); + if (trace_init_global_iter(&iter) < 0) { + kdb_printf("Global iter initialization fails\n"); + return; + } + iter.buffer_iter = buffer_iter; for_each_tracing_cpu(cpu) { @@ -94,6 +98,8 @@ out: iter.buffer_iter[cpu] = NULL; } } + + trace_finalize_global_iter(&iter); } /* -- 1.9.3 -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/