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
[ 32.533496][ T1] ipmr_new_table+0x48/0xa0
[ 32.535002][ T1] ipmr_net_init+0xe8/0x258
[ 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
[ 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
Cheers,
Anders
[1] http://people.linaro.org/~anders.roxell/kernel_config-next-20191108.config
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?
Thanx, Paul
On Mon, 11 Nov 2019 at 14:34, Paul E. McKenney <[email protected]> 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