Re: Issue: Networking performance in Xen VM on Arm64

[Leo Yan <leo.yan@xxxxxxxxxx>]

Hi Stefano,

Sorry for late response.  Please see below comments.

On Tue, Oct 11, 2022 at 02:47:00PM -0700, Stefano Stabellini wrote:
> On Tue, 11 Oct 2022, Leo Yan wrote:
> > > > The second question is how to mitigate the long latency when send data
> > > > from DomU.  A possible solution is the Xen network forend driver copies
> > > > skb into mediate (bounce) buffer, just like what does in Xen net
> > > > backend driver with gnttab_batch_copy(), in this way the forend driver
> > > > doesn't need to wait for backend driver response and directly return
> > > > back.
> > > 
> > > About this, I am not super familiar with drivers/net/xen-netfront.c but
> > > I take you are referring to xennet_tx_buf_gc? Is that the function that
> > > is causing xennet_start_xmit to wait?
> > 
> > No.  We can take the whole flow in xen-netfront.c as:
> > 
> >   xennet_start_xmit()
> >              ----------> notify Xen Dom0 to process skb
> >              <---------  Dom0 copies skb and notify back to DomU
> >   xennet_tx_buf_gc()
> >   softirq/NET_TX : __kfree_skb()
> 
> Let me premise again that I am not an expert in PV netfront/netback.
> However, I think the above is only true if DomU and Dom0 are running on
> the same physical CPU. If you use sched=null as I suggested above,
> you'll get domU and dom0 running at the same time on different physical
> CPUs and the workflow doesn't work as described.
> 
> It should be:
> 
> CPU1: xennet_start_xmit()             ||  CPU2: doing something else
> CPU1: notify Xen Dom0 to process skb  ||  CPU2: receive notification
> CPU1: return from xennet_start_xmit() ||  CPU2: Dom0 copies skb
> CPU1: do something else               ||  CPU2: notify back to DomU
> CPU1: receive irq, xennet_tx_buf_gc() ||  CPU2: do something else

Yes, I agree this is ideal case.  I tried to set option "sched=null" but
I can observe the latency in the second step when CPU1 notify Xen Dom0,
Dom0 takes 500us+ to receive the notification.

Please see below detailed log:

DomU log:

4989078512              pub-321   [003]   101.150966: bprint:               
xennet_start_xmit: xennet_start_xmit: TSC: 4989078512
4989078573              pub-321   [003]   101.150968: bprint:               
xennet_tx_setup_grant: id=24 ref=1816 offset=2 len=1514 TSC: 4989078573
4989078592              pub-321   [003]   101.150969: bprint:               
xennet_start_xmit: xennet_notify_tx_irq: TSC: 4989078592

Dom0 log:

4989092169           <idle>-0     [013]   140.121667: bprint:               
xenvif_tx_interrupt: xenvif_tx_interrupt: TSC: 4989092169
4989092331           <idle>-0     [013]   140.121673: bprint:               
xenvif_tx_build_gops.constprop.0: id=24 ref=1816 offset=2 len=1514 TSC: 
4989092331

We can see DomU sends notification with timestamp (raw counter) is
4989078592 and Dom0 receives the interrupt with timestamp 4989092169.
Since Dom0 and DomU use the same time counter and the counter
frequency is 25MHz, so we can get the delta value (in macroseconds):

    (4989092169 - 4989078592) / 25000000 * 1000 * 1000
  = 543us

Which means it takes 543us to let Dom0 to receive the notification.
You could see DomU runs in CPU3 and Dom0 runs on CPU13, there should
not have contention for CPU resources.  Seems to me, it's likely Xen
hypervisor takes long time to deliver the interrupt, note, it's not
take so long time for every skb transferring, sometimes the time for
response a notification is short (about ~10us).

> > > I didn't think that waiting for the backend is actually required. I
> > > mean, in theory xennet_start_xmit could return without calling
> > > xennet_tx_buf_gc, it is just an optimization. But I am not sure about
> > > this.
> > 
> > The function xennet_start_xmit() will not wait and directly return
> > back, but if we review the whole flow we can see the skb is freed until
> > the softirq NET_TX.
> 
> Is it an issue that the skb is not freed until later? Is that affecting
> the latency results? It shouldn't, right?

I did an extra experiment in Xen net forend driver, I enabled the flag
"info->bounce = true" so the forend driver will use bounce buffer to
store data and release the skb immediately to network core layer.

The throughput can be boosted significantly for this: the netperf
result can be improved from 107.73 Mbits/s to 300+ Mbits/s.

> What matters is when dom0 is
> getting those packets on the physical network interface and that happens
> before the skb is freed. I am just trying to figure out if we are
> focusing on the right problem.

Good point.  I agree that releasing skb earlier only can benefit for
throughput, but we still cannot resolve the latency issue if Dom0
takes long time to relay packets to phusical network interface.

> > In this whole flow, it needs DomU and Dom0 to work
> > together (includes two context switches) to process skb.
> 
> There are not necessarily 2 context switches as things should run in
> parallel.
> 
> > Here I mean the optimization is to allow Dom0 and DomU to work in
> > parallel.  It could be something like blow, the key point is DomU
> > doesn't need to wait for Dom0's notification.
> 
> I think it is already the case that domU doesn't need to wait for dom0's
> notification?

Agree.  domU doesn't need to wait for dom0's notification until it uses
out the skb can be allocated by the network core layer.  This is why I
also can tweak core layer's parameters for buffer size (see
/proc/sys/net/core/wmem_default and /proc/sys/net/core/wmem_max).

> It is true that domU is waiting for dom0's notification to
> free the skb but that shouldn't affect latency?

Yeah.  I will focus on the elaberated issue above that Dom0 takes long
time to receive the notification.

Will keep posted if have any new finding.

Thanks,
Leo