lkml.org 
[lkml]   [2019]   [Nov]   [13]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
From
Date
SubjectRe: next-20191108: qemu arm64: WARNING: suspicious RCU usage
On Mon, 11 Nov 2019 at 14:34, Paul E. McKenney <paulmck@kernel.org> wrote:
>
> On Mon, Nov 11, 2019 at 08:59:25AM +0100, Anders Roxell wrote:
> > Hi,
> >
> > I'm seeing the following warning when I'm booting an arm64 allmodconfig
> > kernel [1] on linux-next tag next-20191108, is this anything you've seen
> > before ?
> >
> >
> > The code seems to have introduced that is f0ad0860d01e ("ipv4: ipmr:
> > support multiple tables") in 2010 and the warning was added reacently
> > 28875945ba98 ("rcu: Add support for consolidated-RCU reader checking").
> >
> >
> > [ 32.496021][ T1] =============================
> > [ 32.497616][ T1] WARNING: suspicious RCU usage
> > [ 32.499614][ T1] 5.4.0-rc6-next-20191108-00003-gf74bac957b5c-dirty #2 Not tainted
> > [ 32.502018][ T1] -----------------------------
> > [ 32.503976][ T1] net/ipv4/ipmr.c:136 RCU-list traversed in non-reader section!!
> > [ 32.506746][ T1]
> > [ 32.506746][ T1] other info that might help us debug this:
> > [ 32.506746][ T1]
> > [ 32.509794][ T1]
> > [ 32.509794][ T1] rcu_scheduler_active = 2, debug_locks = 1
> > [ 32.512661][ T1] 1 lock held by swapper/0/1:
> > [ 32.514169][ T1] #0: ffffa000150dd678 (pernet_ops_rwsem){+.+.}, at: register_pernet_subsys+0x24/0x50
> > [ 32.517621][ T1]
> > [ 32.517621][ T1] stack backtrace:
> > [ 32.519930][ T1] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 5.4.0-rc6-next-20191108-00003-gf74bac957b5c-dirty #2
> > [ 32.523063][ T1] Hardware name: linux,dummy-virt (DT)
> > [ 32.524787][ T1] Call trace:
> > [ 32.525946][ T1] dump_backtrace+0x0/0x2d0
> > [ 32.527433][ T1] show_stack+0x20/0x30
> > [ 32.528811][ T1] dump_stack+0x204/0x2ac
> > [ 32.530258][ T1] lockdep_rcu_suspicious+0xf4/0x108
> > [ 32.531993][ T1] ipmr_get_table+0xc8/0x170
>
> So this one is invoking ipmr_for_each_table(), which in turn invokes
> list_for_each_entry_rcu(), which really does want to be in an
> RCU read-side critical section. (But you can pass it an optional
> additional lockdep expressions.
>
> > [ 32.533496][ T1] ipmr_new_table+0x48/0xa0
>
> And this does look like update-side code...
>
> > [ 32.535002][ T1] ipmr_net_init+0xe8/0x258
>
> And this one is marked with "__net_init", which turns out to be __init.
> So this is being invoked during early boot (see inet_init() below).
> Or with RTNL held when invoked at runtime. So, can we make a lockdep
> expression for this combination?
>
> The RTNL part is easy, something like this in include/linux/rtnetlink.h:
>
> #ifdef CONFIG_PROVE_LOCKING
> extern int lockdep_rtnl_is_held(void);
> #else
> #define lockdep_rtnl_is_held() 1
> #endif
>
> And in net/core/rtnetlink.c:
>
> #ifdef CONFIG_PROVE_LOCKING
> int lockdep_rtnl_is_held(void)
> {
> return lockdep_is_held(&rtnl_mutex);
> }
> #endif
>
> > [ 32.536465][ T1] ops_init+0x280/0x2d8
> > [ 32.537876][ T1] register_pernet_operations+0x210/0x420
> > [ 32.539707][ T1] register_pernet_subsys+0x30/0x50
> > [ 32.541372][ T1] ip_mr_init+0x54/0x180
> > [ 32.542785][ T1] inet_init+0x25c/0x3e8
>
> And this is an fs_initcall(). This is late enough during boot that
> RTNL could conceivably be held, but I don't see evidence of that.
> One approach would be to hold RTNL across this initialization code.
>
> So the other approach would be to have a global variable in net/ipv4/ipmr.c
> whose definition depends on whether lockdep is enabled:
>
> #ifdef CONFIG_PROVE_LOCKING
> int ip_mr_initialized;
> void ip_mr_now_initialized(void) { ip_mr_initialized = 1; }
> #else
> const int ip_mr_initialized = 1;
> void ip_mr_now_initialized(void) { }
> #endif
>
> Then at the end of ip_mr_init():
>
> ip_mr_now_initialized();
>
> And finally change the CONFIG_IP_MROUTE_MULTIPLE_TABLES definition
> of ipmr_for_each_table() to be something like:
>
> #define ipmr_for_each_table(mrt, net) \
> list_for_each_entry_rcu(mrt, &net->ipv4.mr_tables, list, \
> lockdep_rtnl_is_held() || !ip_mr_initialized)
>
> > [ 32.544186][ T1] do_one_initcall+0x4c0/0xad8
> > [ 32.545757][ T1] kernel_init_freeable+0x3e0/0x500
> > [ 32.547443][ T1] kernel_init+0x14/0x1f0
> > [ 32.548875][ T1] ret_from_fork+0x10/0x18
>
> Does that work for you?

Yes, that made the "suspicious RCU usage" warning go away.

Cheers,
Anders

\
 
 \ /
  Last update: 2019-11-13 10:12    [W:0.053 / U:0.404 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site