For a long time now in the 2.1 series, I've been dismayed at terrible
performance when two linux boxen communicate with each other via ppp.
Using error-correcting 33.6 modems directly connected to 16550A uarts,
I would not expect any dropped or lost packets. Throughput should be
better than 3K bytes/sec; instead, I see 1.6-2.5K/sec, with extended
periods (5 sec or more) where one box awaits an ack it never sees and
then kicks things going again. When logged into the remote box,
character echoing (though usually spritely) sometimes takes a couple
seconds for no obvious reason. Then, this week, I am hearing of
reports of people seeing slowdowns and lockups under Netscape and
dialup connections. Time to investigate.
I ftp'ed a file from the remote ppp client (stock 2.2.0-pre4/UP,
slackware-3.5, pppd-2.3.5) to my home machine (stock 2.2.0-pre5/SMP,
slackware-3.6, pppd-2.3.5), with tcpdump running on both ends.
The first thing I noticed was that each time the receiver sent an ACK
back to the sender, the sender duplicated its most recent packet
verbatim. Either the network layer on the sender, receiver, or
something internal to pppd caught this anomaly; the duplications are
not present on the receiving end. I don't have an easy way to decode
the individual bytes of a verbose pppd debug session, and didn't
enable it, so I can't comment on whether the packet data traversed the
serial line or not.
The next thing I noticed, and this is the real show-stopper and
purpose of my writing all this down, is the dropped packets on the
sending end, confirmed by the tcpdump on the receiving end. The
sender somehow thinks that the byte stream has advanced by some
integral number of max-MTU packets, and continues on its merry way.
The receiver sends back a stream of ACKs for the missed byte stream
pointer, and owing to the large serial buffer in the modems, it takes
awhile before a retransmit puts things right again.
The two tcpdump excerpts are correlated. There are no missed packets
or retransmissions present in the preceeding lines, the ACKs coming
from the receiver all numerically increasing with no duplications.
Though I can't confirm that this is the same mechanism slowing ppp
connections with earlier members of the 2.1 series, the symptoms
remain roughly the same. Using windoze as the receiver yields similar
results.
Oh, almost forgot: there are no error messages in either machine's
syslog; and ifconfig of ppp0 reports a mere 1 error and 1 dropped out
of 13830 packets, but nothing else.
Best regards,
Kris
Tcpdump on the sender's side:
01:25:00.063533 sender > receiver: . 35001:35501(500) ack 1 win 32500 <nop,nop,timestamp 20849411 359989> (DF) [tos 0x8]
01:25:00.063602 sender > receiver: . 35501:36001(500) ack 1 win 32500 <nop,nop,timestamp 20849411 359989> (DF) [tos 0x8]
01:25:00.083830 receiver > sender: . ack 29501 win 32500 <nop,nop,timestamp 360119 20849257> (DF) [tos 0x8]
01:25:00.373838 receiver > sender: . ack 31001 win 31500 <nop,nop,timestamp 360148 20849287> (DF) [tos 0x8]
01:25:00.625074 sender > receiver: . 35501:36001(500) ack 1 win 32500 <nop,nop,timestamp 20849411 359989> (DF) [tos 0x8]
01:25:00.625162 sender > receiver: . 36001:36501(500) ack 1 win 32500 <nop,nop,timestamp 20849411 359989> (DF) [tos 0x8]
01:25:00.625237 sender > receiver: . 36501:37001(500) ack 1 win 32500 <nop,nop,timestamp 20849411 359989> (DF) [tos 0x8]
01:25:00.625310 sender > receiver: . 37001:37501(500) ack 1 win 32500 <nop,nop,timestamp 20849460 360038> (DF) [tos 0x8]
01:25:00.625386 sender > receiver: . 37501:38001(500) ack 1 win 32500 <nop,nop,timestamp 20849460 360038> (DF) [tos 0x8]
01:25:00.625429 sender > receiver: . 38001:38501(500) ack 1 win 32500 <nop,nop,timestamp 20849460 360038> (DF) [tos 0x8]
01:25:00.833832 receiver > sender: . ack 32001 win 32500 <nop,nop,timestamp 360194 20849332> (DF) [tos 0x8]
01:25:01.076173 sender > receiver: . 38001:38501(500) ack 1 win 32500 <nop,nop,timestamp 20849460 360038> (DF) [tos 0x8]
01:25:01.076257 sender > receiver: . 39001:39501(500) ack 1 win 32500 <nop,nop,timestamp 20849505 360083> (DF) [tos 0x8]
01:25:01.076336 sender > receiver: . 39501:40001(500) ack 1 win 32500 <nop,nop,timestamp 20849505 360083> (DF) [tos 0x8]
01:25:01.076375 sender > receiver: P 40501:41001(500) ack 1 win 32500 <nop,nop,timestamp 20849541 360119> (DF) [tos 0x8]
01:25:01.193857 receiver > sender: . ack 33001 win 32500 <nop,nop,timestamp 360230 20849332> (DF) [tos 0x8]
01:25:01.477359 sender > receiver: P 40501:41001(500) ack 1 win 32500 <nop,nop,timestamp 20849541 360119> (DF) [tos 0x8]
01:25:01.477446 sender > receiver: . 41001:41501(500) ack 1 win 32500 <nop,nop,timestamp 20849541 360119> (DF) [tos 0x8]
01:25:01.477525 sender > receiver: . 41501:42001(500) ack 1 win 32500 <nop,nop,timestamp 20849541 360119> (DF) [tos 0x8]
01:25:01.477568 sender > receiver: . 44001:44501(500) ack 1 win 32500 <nop,nop,timestamp 20849616 360194> (DF) [tos 0x8]
01:25:01.503851 receiver > sender: . ack 34501 win 31500 <nop,nop,timestamp 360261 20849365> (DF) [tos 0x8]
01:25:01.849238 sender > receiver: . 44001:44501(500) ack 1 win 32500 <nop,nop,timestamp 20849616 360194> (DF) [tos 0x8]
Corresponding tcpdump on the receiver's side:
02:25:09.959502 sender > receiver: . 35001:35501(500) ack 1 win 32500 <nop,nop,timestamp 20849411 359989> (DF) [tos 0x8]
02:25:10.089497 receiver > sender: . ack 35501 win 32500 <nop,nop,timestamp 360304 20849411> (DF) [tos 0x8]
02:25:10.109527 sender > receiver: . 35501:36001(500) ack 1 win 32500 <nop,nop,timestamp 20849411 359989> (DF) [tos 0x8]
02:25:10.259514 sender > receiver: . 36001:36501(500) ack 1 win 32500 <nop,nop,timestamp 20849411 359989> (DF) [tos 0x8]
02:25:10.409496 receiver > sender: . ack 36501 win 32500 <nop,nop,timestamp 360336 20849411> (DF) [tos 0x8]
02:25:10.419506 sender > receiver: . 36501:37001(500) ack 1 win 32500 <nop,nop,timestamp 20849411 359989> (DF) [tos 0x8]
02:25:10.569504 sender > receiver: . 37001:37501(500) ack 1 win 32500 <nop,nop,timestamp 20849460 360038> (DF) [tos 0x8]
02:25:10.719515 sender > receiver: . 37501:38001(500) ack 1 win 32500 <nop,nop,timestamp 20849460 360038> (DF) [tos 0x8]
02:25:10.729508 receiver > sender: . ack 38001 win 31500 <nop,nop,timestamp 360368 20849460> (DF) [tos 0x8]
02:25:10.869514 sender > receiver: . 38001:38501(500) ack 1 win 32500 <nop,nop,timestamp 20849460 360038> (DF) [tos 0x8]
02:25:11.059496 sender > receiver: . 39001:39501(500) ack 1 win 32500 <nop,nop,timestamp 20849505 360083> (DF) [tos 0x8]
02:25:11.069539 receiver > sender: . ack 38501 win 31500 <nop,nop,timestamp 360402 20849505,nop,nop,opt-5:cf15219ecf152392> (DF) [tos 0x8]
02:25:11.209499 sender > receiver: . 39501:40001(500) ack 1 win 32500 <nop,nop,timestamp 20849505 360083> (DF) [tos 0x8]
02:25:11.219535 receiver > sender: . ack 38501 win 31500 <nop,nop,timestamp 360417 20849505,nop,nop,opt-5:cf15219ecf152586> (DF) [tos 0x8]
02:25:11.359515 sender > receiver: P 40501:41001(500) ack 1 win 32500 <nop,nop,timestamp 20849541 360119> (DF) [tos 0x8]
02:25:11.369530 receiver > sender: . ack 38501 win 31500 <nop,nop,timestamp 360432 20849541,nop,nop,opt-5:cf15277acf15296ecf15219ecf152586> (DF) [tos 0x8]
02:25:11.539503 sender > receiver: . 41001:41501(500) ack 1 win 32500 <nop,nop,timestamp 20849541 360119> (DF) [tos 0x8]
02:25:11.540076 receiver > sender: . ack 38501 win 31500 <nop,nop,timestamp 360449 20849541,nop,nop,opt-5:cf15277acf152b62cf15219ecf152586> (DF) [tos 0x8]
02:25:11.689542 sender > receiver: . 41501:42001(500) ack 1 win 32500 <nop,nop,timestamp 20849541 360119> (DF) [tos 0x8]
02:25:11.690265 receiver > sender: . ack 38501 win 31500 <nop,nop,timestamp 360464 20849541,nop,nop,opt-5:cf15277acf152d56cf15219ecf152586> (DF) [tos 0x8]
02:25:11.849549 sender > receiver: . 44001:44501(500) ack 1 win 32500 <nop,nop,timestamp 20849616 360194> (DF) [tos 0x8]
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.rutgers.edu
Please read the FAQ at http://www.tux.org/lkml/