Re: virtio_net: suspicious RCU usage with xdp

[Jesper Dangaard Brouer <brouer@redhat.com>]

On Thu, 25 Apr 2019 20:54:11 +0200
Maciej Fijalkowski <maciejromanfijalkowski@gmail.com> wrote:

> On Thu, 25 Apr 2019 11:44:27 -0600
> David Ahern <dsahern@gmail.com> wrote:
> 
> > On 4/25/19 11:41 AM, Jesper Dangaard Brouer wrote:  
> > > On Thu, 25 Apr 2019 13:03:39 -0400
> > > "Michael S. Tsirkin" <mst@redhat.com> wrote:
> > >     
> > >> On Thu, Apr 25, 2019 at 01:58:48PM +0900, Toshiaki Makita wrote:    
> > >>> On 2019/04/25 2:37, Michael S. Tsirkin wrote:      
> > >>>> On Wed, Apr 24, 2019 at 11:13:42AM -0600, David Ahern wrote:      
> > >>>>> seeing an RCU warning testing xdp with virtio net. net-next as of commit
> > >>>>> b2f97f7de2f6a4df8e431330cf467576486651c5. No obvious changes so hoping
> > >>>>> this rings a bell with someone else.
> > >>>>>
> > >>>>>
> > >>>>> [  121.990304] =============================
> > >>>>> [  121.991488] WARNING: suspicious RCU usage
> > >>>>> [  121.992392] 5.1.0-rc5+ #60 Not tainted
> > >>>>> [  121.993220] -----------------------------
> > >>>>> [  121.994158] /home/dsa/kernel-3.git/drivers/net/virtio_net.c:516
> > >>>>> suspicious rcu_dereference_check() usage!
> > >>>>> [  121.996284]
> > >>>>>                other info that might help us debug this:
> > >>>>>
> > >>>>> [  121.997988]
> > >>>>>                rcu_scheduler_active = 2, debug_locks = 1
> > >>>>> [  121.999321] no locks held by swapper/1/0.
> > >>>>> [  122.000328]
> > >>>>>                stack backtrace:
> > >>>>> [  122.001253] CPU: 1 PID: 0 Comm: swapper/1 Not tainted 5.1.0-rc5+ #60
> > >>>>> [  122.002474] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
> > >>>>> BIOS 1.11.1-1 04/01/2014
> > >>>>> [  122.004141] Call Trace:
> > >>>>> [  122.004651]  <IRQ>
> > >>>>> [  122.005082]  dump_stack+0x7e/0xbb
> > >>>>> [  122.005757]  lockdep_rcu_suspicious+0x102/0x10b
> > >>>>> [  122.006654]  virtnet_xdp_xmit+0x104/0x4fe
> > >>>>> [  122.007447]  ? kasan_check_read+0x11/0x13
> > >>>>> [  122.008267]  ? mergeable_rx_buffer_size_show+0x163/0x163
> > >>>>> [  122.009299]  ? __asan_loadN+0xf/0x11
> > >>>>> [  122.010010]  ? pvclock_clocksource_read+0xfa/0x189
> > >>>>> [  122.010975]  bq_xmit_all+0xdc/0x358
> > >>>>> [  122.011699]  __dev_map_flush+0xc2/0xef
> > >>>>> [  122.012472]  xdp_do_flush_map+0x5b/0x74
> > >>>>> [  122.013238]  virtnet_poll+0x58f/0x679      
> > >>>>
> > >>>> Well virtnet_xdp_xmit seems to be called from .ndo_xdp_xmit
> > >>>> and that isn't in an RCU read-side critical section.
> > >>>>
> > >>>> Looks like we just need to add RCU read lock/unlock.
> > >>>> Like the below perhaps?
> > >>>>
> > >>>> This issue was introduced by 8dcc5b0ab0 however I find it      
> > >>>
> > >>> Probably not 8dcc5b0ab0, but 5d053f9da431 ("bpf: devmap prepare xdp
> > >>> frames for bulking").
> > >>>       
> > >>>> inelegant that we need to do checks in each driver,
> > >>>> and add RCU locks just for a startup initialization issue.
> > >>>> Can't XDP core make sure the callback isn't invoked
> > >>>> at an inappropriate time instead?      
> > >>>
> > >>> Before commit 5d053f9da431, .ndo_xdp_xmit() should have always been
> > >>> called under RCU. After the commit, xdp_do_flush_map() also can trigger
> > >>> .ndo_xdp_xmit() but we forgot to add RCU read lock there?
> > >>> I guess veth has the same problem and I feel like it should be fixed in
> > >>> __dev_map_flush(). dev_map_flush_old() needs to be cared too.      
> > >>
> > >> I don't have a problem either way.  Jesper, what do you think?    
> > > 
> > > It does sound like my commit 5d053f9da431 ("bpf: devmap prepare xdp
> > > frames for bulking") introduced this issue.  I guess we can add the RCU
> > > section to xdp_do_flush_map(), and then also verify that the devmap
> > > (and cpumap) take-down code also have appropriate RCU sections (which
> > > they should have).
> > > 
> > > Another requirement for calling .ndo_xdp_xmit is running under NAPI
> > > protection, is that still satisifed for veth?
> > > (even when invoked via xdp_do_flush_map()).
> > >     
> > 
> > virtio_net hits this because of:
> >    xdp_prog = rcu_dereference(rq->xdp_prog);
> > 
> > in its ndo_xdp_xmit. Scanning ndo_xdp_xmit for other nics does not show
> > this same check. Is it really required? If so, why don't other drivers
> > do it?  
> 
> That was my initial thought as well. Can't we just check that
> vi->xdp_queue_pairs was set in virtnet_xdp_xmit? It is being done
> just before assigning the XDP prog pointers for rqs. Haven't looked
> at veth though.

Ah, I see, the reason virtio_net is doing this is documented in a
comment:

	/* Only allow ndo_xdp_xmit if XDP is loaded on dev, as this
	 * indicate XDP resources have been successfully allocated.
	 */

As we have discussed before, this is a bad assumption. We even have a
TODO[1] in the XDP-project named: Better ndo_xdp_xmit resource management.
This area need to be improved. 

I can see other drivers also end-up checking for if xdp_prog pointer
exist, but they don't need to dereference the pointer.  Even if we find
some other resource management check, then that check also need some
protection that likely want to leverage RCU as well(?).

The mlx5 driver also had issues in this area, and is doing some RCU
sync/barrier tricks, which also indicate a RCU dependency.


[1] https://github.com/xdp-project/xdp-project/blob/master/xdp-project.org#better-ndo_xdp_xmit-resource-management

IHMO this tying XDP ndo_xdp_xmit resources to whether there is a XDP RX
prog loaded is wrong... and cause the very ugly trick of loading dummy
XDP program on TX devices.
Fixing this is a larger effort... a work-around for now would be to do
a RCU read-section in xdp_do_flush_map().
-- 
Best regards,
  Jesper Dangaard Brouer
  MSc.CS, Principal Kernel Engineer at Red Hat
  LinkedIn: http://www.linkedin.com/in/brouer