On Sat, May 25, 2013 at 02:20:04PM -0400, Steven Rostedt wrote: > On Sat, 2013-05-25 at 09:59 -0400, Dave Jones wrote: > > On Fri, May 24, 2013 at 03:23:40PM -0400, Steven Rostedt wrote: > > > On Fri, 2013-05-24 at 10:23 -0400, Dave Jones wrote: > > > > > > > .config: http://paste.fedoraproject.org/14281/94052971/raw/ > > > > > > > > trace shows the problem process was 'cc1', so I was likely building a > > kernel > > > > at the time. There was also a trinity run going on in the background. > > > > > > > > cmdline: nothing special.. > > > > > > > > BOOT_IMAGE=/vmlinuz-3.10.0-rc2+ > > root=UUID=bee21cd9-1852-4d1d-9e9d-2e44332b8df1 ro rd.md=0 rd.lvm=0 rd.dm=0 > > vconsole.keymap=us rd.luks=0 vconsole.font=latarcyrheb-sun16 consoleblank=0 > > console=ttyUSB0,115200 console=tty0 pause_on_oops=30 audit=0 > > > > > > > > > > OK, I'm able to reproduce this. Looks like the same issue happens from > > > other ways from userspace into the kernel (the next way was tracing > > > system calls). > > > > > > Forget the other patch. Here's a new patch that is more specific to > > > tracing and context tracking. > > > > > > Can you try this one out, please. > > > > Took a lot longer to hit this.. > > This is a same but different bug ;-) > > Looks like we fixed all the function tracing infrastructure problems, > but this is a function tracer user problem. Namely perf. > > > > > [53693.297516] =============================== > > [53693.298109] [ INFO: suspicious RCU usage. ] > > [53693.298562] 3.10.0-rc2+ #38 Not tainted > > [53693.299017] ------------------------------- > > [53693.299474] include/linux/rcupdate.h:771 rcu_read_lock() used illegally > > while idle! > > [53693.299959] > > other info that might help us debug this: > > > > [53693.301420] > > RCU used illegally from idle CPU! > > rcu_scheduler_active = 1, debug_locks = 0 > > [53693.302918] RCU used illegally from extended quiescent state! > > [53693.303462] 1 lock held by trinity-child1/18786: > > [53693.303966] #0: (rcu_read_lock){.+.+..}, at: [<ffffffff8113dd48>] > > __perf_event_overflow+0x108/0x310 > > [53693.304557] > > stack backtrace: > > [53693.305608] CPU: 3 PID: 18786 Comm: trinity-child1 Not tainted > > 3.10.0-rc2+ #38 > > [53693.306790] 0000000000000000 ffff88020767bac8 ffffffff816e2f6b > > ffff88020767baf8 > > [53693.307408] ffffffff810b5897 ffff88021de92520 0000000000000000 > > ffff88020767bbf8 > > [53693.308035] 0000000000000000 ffff88020767bb78 ffffffff8113ded4 > > ffffffff8113dd48 > > [53693.308671] Call Trace: > > [53693.309301] [<ffffffff816e2f6b>] dump_stack+0x19/0x1b > > [53693.309943] [<ffffffff810b5897>] lockdep_rcu_suspicious+0xe7/0x120 > > [53693.310596] [<ffffffff8113ded4>] __perf_event_overflow+0x294/0x310 > > [53693.311256] [<ffffffff8113dd48>] ? __perf_event_overflow+0x108/0x310 > > [53693.311923] [<ffffffff81309289>] ? __const_udelay+0x29/0x30 > > [53693.312596] [<ffffffff81076054>] ? __rcu_read_unlock+0x54/0xa0 > > [53693.313275] [<ffffffff816f4000>] ? ftrace_call+0x5/0x2f > > [53693.313958] [<ffffffff8113dfa1>] perf_swevent_overflow+0x51/0xe0 > > [53693.314650] [<ffffffff8113e08f>] perf_swevent_event+0x5f/0x90 > > [53693.315347] [<ffffffff8113e1c9>] perf_tp_event+0x109/0x4f0 > > [53693.316059] [<ffffffff8113e36f>] ? perf_tp_event+0x2af/0x4f0 > > [53693.316773] [<ffffffff81074630>] ? __rcu_read_lock+0x20/0x20 > > Ouch! perf function tracing uses rcu_lock(). This should be avoided. > Believe it or not, rcu_lock() is too invasive for function tracing, not > to mention that the function tracer traces rcu_lock(). > > Jiri, > > Is there a way you can make perf not use rcu here? Or we need to > blacklist what perf can trace. It can not trace any rcu calls. Here it > looks like it traced rcu_eqs_enter(). It also wont be able to trace > anything before user_exit() or after user_enter().
ok, I'll check jirka -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
