Re: PPTPD upload speed bottleneck

On Mon, Nov 18, 2013 at 09:36:56AM -0000, Gustavo Homem wrote:
> Here is an updated paste:
> 
> http://pastebin.com/9hnsyD8e
> 
> You can see both 534403 and 534404 leaving the client and arriving
> to the server.

Agreed.

> > pptpctrl will be in a select(2) call at the time, or it will be
> > busy processing a control connection packet or a previous GRE
> > packet.  If it is busy, there will be a delay before it gets
> > around the event loop to read(2) from the raw socket.  The delay
> > could be something as simple as a write(2) waiting for kernel
> > resources.  It would vary each time.
> 
> Hard to imagine if the server is idle most of the time.

I can imagine it, as I've been debugging a kernel driver problem in
mwifiex for the past two weeks, OLPC #12694, and the kernel there is
declaring an out of memory condition during an interrupt handler,
despite there being apparently ample memory in other areas.  This has
long since been fixed; we're using an old kernel, 3.5.

The kernel has the right to delay any of these syscalls in order to
marshall resources, even if you think the system is idle.  The socket
isn't configured to be non-blocking; perhaps it should be.

Therefore I won't exclude it until I've evidence to the contrary.
strace timings can be that evidence.

> > pptpctrl will call read(2) in decaps_gre to pull the packet up
> > from the raw socket, then it will strip the GRE encapsulation,
> > check the sequence number, and will encapsulate in HDLC and send
> > it down to the PTY for kernel PPP to handle.
> >
> > Exactly when it will send it down will depend on the sequence
> > number in relation to previous sequence numbers.  If the sequence
> > number is the next expected, the packet will be sent down
> > immediately.  If not, there will be a delay of _at least_ 300ms.
> > This delay is of the same order of magnitude as what you observe.
> >
> 
> Why does it wait 300ms instead of sending it even if it is out of
> order?

It is in the code.  DEFAULT_PACKET_TIMEOUT.

The most common reordering only lasts a few packets, then the missing
packet arrives a small time later.

If pptpd were to send the arriving packets down immediately, the late
out of sequence packet causes confusion in PPP.  PPP depends on strict
ordering or simple loss.  That's my memory of the history of the
design change, but it was driven by others on this mailing list some
years ago.

> In the pastebin I provided there is no evidence of reordering,
> unless I am missing something.

Yes, no evidence of network level reordering.  I doubt there is
reordering before the packet reaches pptpd, but the only way to be
sure is to test.

> > Some suggestions:
> >
> > - look at the packet counters maintained by pptpd.  Any
> >   rx_buffered may represent a 300ms delay injection.
> >
> > - try changing the DEFAULT_PACKET_TIMEOUT in pqueue.h from 0.3 to
> >   0.1 and see if the problem is changed.
> >
> > - try commenting out the first "if (pptpctrl_debug)" in
> >   dequeue_gre and watch the logs.
> >
> > Another suggestion; do an strace with precise timings (-tt), and
> > focus on the select(2) in pptp_handle_ctrl_connection pptpctrl.c
> > or the read(2) in decaps_gre pptpgre.c.
> 
> Thanks. I will look see what I can do with this.

Good.

> > Lastly, although I've looked at the code just now, I can't see how
> > it goes back to process the out of order packet queue in the
> > absence of network activity.  Perhaps you are hitting that.  It
> > looks like a bug.  Needs more eyes.
> 
> Would this explain the cosine or sawteeth like latency pattern I am
> seeing?

Not alone, there would also have to be an out of sequence arrival.

-- 
James Cameron
http://quozl.linux.org.au/

------------------------------------------------------------------------------
Shape the Mobile Experience: Free Subscription
Software experts and developers: Be at the forefront of tech innovation.
Intel(R) Software Adrenaline delivers strategic insight and game-changing 
conversations that shape the rapidly evolving mobile landscape. Sign up now. 
http://pubads.g.doubleclick.net/gampad/clk?id=63431311&iu=/4140/ostg.clktrk