Re: ipv6_addrconf: WARNING about suspicious RCU usage

From: Ido Schimmel <idosch@idosch.org>
To: Eric Dumazet <eric.dumazet@gmail.com>
Cc: Heiner Kallweit <hkallweit1@gmail.com>,
	"netdev@vger.kernel.org" <netdev@vger.kernel.org>
Subject: Re: ipv6_addrconf: WARNING about suspicious RCU usage
Date: Sat, 20 Jan 2018 21:19:59 +0200	[thread overview]
Message-ID: <20180120191959.GA5010@splinter> (raw)
In-Reply-To: <1516474143.3478.2.camel@gmail.com>

On Sat, Jan 20, 2018 at 10:49:03AM -0800, Eric Dumazet wrote:
> On Sat, 2018-01-20 at 15:37 +0200, Ido Schimmel wrote:
> > On Sat, Jan 20, 2018 at 12:57:01PM +0100, Heiner Kallweit wrote:
> > > Since some time (didn't bisect it yet) I get the following warning.
> > > Is it a known issue?
> > 
> > [...]
> > 
> > > [86220.126999] BUG: sleeping function called from invalid context at mm/slab.h:420
> > > [86220.127041] in_atomic(): 1, irqs_disabled(): 0, pid: 1003, name: kworker/0:2
> > > [86220.127082] 4 locks held by kworker/0:2/1003:
> > > [86220.127107]  #0:  ((wq_completion)"%s"("ipv6_addrconf")){+.+.}, at: [<00000000da8e9b73>] process_one_work+0x1de/0x680
> > > [86220.127179]  #1:  ((addr_chk_work).work){+.+.}, at: [<00000000da8e9b73>] process_one_work+0x1de/0x680
> > > [86220.127242]  #2:  (rtnl_mutex){+.+.}, at: [<00000000b06d9510>] rtnl_lock+0x12/0x20
> > > [86220.127300]  #3:  (rcu_read_lock_bh){....}, at: [<00000000aef52299>] addrconf_verify_rtnl+0x1e/0x510 [ipv6]
> > > [86220.127414] CPU: 0 PID: 1003 Comm: kworker/0:2 Not tainted 4.15.0-rc7-next-20180110+ #7
> > > [86220.127463] Hardware name: ZOTAC ZBOX-CI321NANO/ZBOX-CI321NANO, BIOS B246P105 06/01/2015
> > > [86220.127528] Workqueue: ipv6_addrconf addrconf_verify_work [ipv6]
> > > [86220.127568] Call Trace:
> > > [86220.127591]  dump_stack+0x70/0x9e
> > > [86220.127616]  ___might_sleep+0x14d/0x240
> > > [86220.127644]  __might_sleep+0x45/0x80
> > > [86220.127672]  kmem_cache_alloc_trace+0x53/0x250
> > > [86220.127717]  ? ipv6_add_addr+0xfe/0x6e0 [ipv6]
> > > [86220.127762]  ipv6_add_addr+0xfe/0x6e0 [ipv6]
> > > [86220.127807]  ipv6_create_tempaddr+0x24d/0x430 [ipv6]
> > > [86220.127854]  ? ipv6_create_tempaddr+0x24d/0x430 [ipv6]
> > > [86220.127903]  addrconf_verify_rtnl+0x339/0x510 [ipv6]
> > > [86220.127950]  ? addrconf_verify_rtnl+0x339/0x510 [ipv6]
> > > [86220.127998]  addrconf_verify_work+0xe/0x20 [ipv6]
> > > [86220.128032]  process_one_work+0x258/0x680
> > > [86220.128063]  worker_thread+0x35/0x3f0
> > > [86220.128091]  kthread+0x124/0x140
> > > [86220.128117]  ? process_one_work+0x680/0x680
> > > [86220.128146]  ? kthread_create_worker_on_cpu+0x40/0x40
> > > [86220.128180]  ? umh_complete+0x40/0x40
> > > [86220.128207]  ? call_usermodehelper_exec_async+0x12a/0x160
> > > [86220.128243]  ret_from_fork+0x4b/0x60
> > 
> > Can you please try attached patch (untested)?
> 
> 
> 
> I would also/instead break rcu section.

Thanks Eric, this should work. We can continue to block in
ipv6_create_tempaddr().

Heiner, can you try Eric's patch instead?

> 
> Holding RCU (and BH) for whole hash traversal is a recipe for disaster,
> if we have thousands of IPv6 addresses.
> 
> diff --git a/net/ipv6/addrconf.c b/net/ipv6/addrconf.c
> index ab99cb641b7cccdda0ad4ae553c09274d7dbc047..adda73466ae1dd0f3b700b3db5fbf3065e4d3f7f 100644
> --- a/net/ipv6/addrconf.c
> +++ b/net/ipv6/addrconf.c
> @@ -4356,9 +4356,11 @@ static void addrconf_verify_rtnl(void)
>  						spin_lock(&ifpub->lock);
>  						ifpub->regen_count = 0;
>  						spin_unlock(&ifpub->lock);
> +						rcu_read_unlock_bh();
>  						ipv6_create_tempaddr(ifpub, ifp, true);
>  						in6_ifa_put(ifpub);
>  						in6_ifa_put(ifp);
> +						rcu_read_lock_bh();
>  						goto restart;
>  					}
>  				} else if (time_before(ifp->tstamp + ifp->prefered_lft * HZ - regen_advance * HZ, next))
> 
> 
> 
> 