Subject: Anomalous TCP behaviour?

From: Anupama Sundaresan <[email-masked]>
Date: Thu, 10 Feb 2000 16:57:36 -0600 (CST)

Hello,

	A few days back I had voiced a few doubts about whether TCP was
transmitting packets outoforder. Thanks to all the replies I carried out
some tests which proved that it was indeed tcpdump which was missing out
packets presumably because of limited buffering and because it is swamped
by a huge volume of packets.

The starting sequence number is 1577980427. The following is a printk output
at the transmitter.

Feb  9 21:13:24 testbed5 kernel:  Seq # in send: 1578416928
Feb  9 21:13:24 testbed5 kernel:  Seq # in Eth 1578416928    ---> 1st Txion
Feb  9 21:13:24 testbed5 kernel:  Seq # in send: 1578418376
Feb  9 21:13:24 testbed5 kernel:  Seq # in Eth 1578418376
Feb  9 21:13:24 testbed5 kernel:  Seq # in send: 1578419824
Feb  9 21:13:24 testbed5 kernel:  Seq # in Eth 1578419824
Feb  9 21:13:24 testbed5 kernel:  Seq # in send: 1578421272
Feb  9 21:13:24 testbed5 kernel:  Seq # in send: 1578422720
Feb  9 21:13:24 testbed5 kernel:  Seq # in send: 1578424168
Feb  9 21:13:24 testbed5 kernel:  Seq # in send: 1578425616
Feb  9 21:13:24 testbed5 kernel:  Seq # in Eth 1578421272
Feb  9 21:13:24 testbed5 kernel:  Seq # in Eth 1578422720
Feb  9 21:13:24 testbed5 kernel:  Seq # in Eth 1578424168
Feb  9 21:13:24 testbed5 kernel:  Seq # in send: 1578427064
Feb  9 21:13:24 testbed5 kernel:  Seq # in send: 1578428512
Feb  9 21:13:24 testbed5 kernel:  Seq # in send: 1578429960
Feb  9 21:13:24 testbed5 kernel:  Seq # in Eth 1578425616
Feb  9 21:13:24 testbed5 kernel:  Seq # in Eth 1578427064
Feb  9 21:13:24 testbed5 kernel:  Seq # in Eth 1578428512
Feb  9 21:13:24 testbed5 kernel:  Seq # in send: 1578431408
Feb  9 21:13:24 testbed5 kernel:  Seq # in send: 1578432856
Feb  9 21:13:24 testbed5 kernel:  Seq # in send: 1578434304
Feb  9 21:13:24 testbed5 kernel:  Seq # in Eth 1578429960
Feb  9 21:13:24 testbed5 kernel:  Seq # in Eth 1578431408
Feb  9 21:13:24 testbed5 kernel:  Seq # in Eth 1578432856
Feb  9 21:13:24 testbed5 kernel:  Seq # in send: 1578435752
Feb  9 21:13:24 testbed5 kernel:  Seq # in send: 1578437200
Feb  9 21:13:24 testbed5 kernel:  Seq # in send: 1578438648
Feb  9 21:13:24 testbed5 kernel:  Seq # in Eth 1578434304
Feb  9 21:13:24 testbed5 kernel:  Seq # in Eth 1578435752
Feb  9 21:13:24 testbed5 kernel:  Seq # in Eth 1578437200
Feb  9 21:13:24 testbed5 kernel:  Seq # in Eth 1578438648
Feb  9 21:13:24 testbed5 kernel:  Seq # in send: 1578439428
Feb  9 21:13:24 testbed5 kernel:  Seq # in Eth 1578439428
Feb  9 21:13:24 testbed5 kernel:  Seq # in send: 1578440876
Feb  9 21:13:24 testbed5 kernel:  Seq # in Eth 1578440876
Feb  9 21:13:24 testbed5 kernel:  Seq # in send: 1578442324
Feb  9 21:13:24 testbed5 kernel:  Seq # in Eth 1578442324
Feb  9 21:13:24 testbed5 kernel:  Seq # in send: 1578443772
Feb  9 21:13:24 testbed5 kernel:  Seq # in send: 1578445220
Feb  9 21:13:24 testbed5 kernel:  Seq # in send: 1578446668
Feb  9 21:13:24 testbed5 kernel:  Seq # in Eth 1578443772
Feb  9 21:13:24 testbed5 kernel:  Seq # in Eth 1578445220
Feb  9 21:13:24 testbed5 kernel:  Seq # in Eth 1578446668
Feb  9 21:13:24 testbed5 kernel:  Seq # in Eth 1578416928   ---> ReTxion
Feb  9 21:13:24 testbed5 kernel:  tp->total_rexmits 1 sk->daddr 561900929
sk->prot->retransmits 1

The seq# 1578416928 is retransmitted. But tcpdump output at the transmitter
shows that this packet was not transmitted for the first time. The very same
packet is denoted by the seq# 436501 
(1578416928 - 1577980427(starting seq#) = 436501)

testbed5.ittc.ukans.edu.1028 testbed4.ittc.ukans.edu.5001: 422689:424137(1448)
testbed5.ittc.ukans.edu.1028 testbed4.ittc.ukans.edu.5001: 424137:425585(1448)
testbed5.ittc.ukans.edu.1028 testbed4.ittc.ukans.edu.5001: 425585:427033(1448)
testbed5.ittc.ukans.edu.1028 testbed4.ittc.ukans.edu.5001: 427033:428481(1448)
testbed5.ittc.ukans.edu.1028 testbed4.ittc.ukans.edu.5001: 428481:429929(1448)
testbed5.ittc.ukans.edu.1028 testbed4.ittc.ukans.edu.5001: 429929:431377(1448)
testbed4.ittc.ukans.edu.5001 testbed5.ittc.ukans.edu.1028: ack 424137
testbed4.ittc.ukans.edu.5001 testbed5.ittc.ukans.edu.1028: ack 427033
testbed4.ittc.ukans.edu.5001 testbed5.ittc.ukans.edu.1028: ack 429929
testbed4.ittc.ukans.edu.5001 testbed5.ittc.ukans.edu.1028: ack 432825
testbed4.ittc.ukans.edu.5001 testbed5.ittc.ukans.edu.1028: ack 435721
## The first transmission is not recorded by tcpdump. Infact the transmission
of 18156 bytes (between 431377 and 449553) is not recorded by tcpdump
testbed5.ittc.ukans.edu.1028 testbed4.ittc.ukans.edu.5001: 449533:450981(1448)
testbed5.ittc.ukans.edu.1028 testbed4.ittc.ukans.edu.5001: 450981:452429(1448)
testbed5.ittc.ukans.edu.1028 testbed4.ittc.ukans.edu.5001: 452429:453877(1448)
testbed4.ittc.ukans.edu.5001 testbed5.ittc.ukans.edu.1028: ack 436501
testbed4.ittc.ukans.edu.5001 testbed5.ittc.ukans.edu.1028: ack 436501
testbed4.ittc.ukans.edu.5001 testbed5.ittc.ukans.edu.1028: ack 436501
testbed5.ittc.ukans.edu.1028 testbed4.ittc.ukans.edu.5001: 453877:455325(1448)
testbed5.ittc.ukans.edu.1028 testbed4.ittc.ukans.edu.5001: 455325:456773(1448)
testbed5.ittc.ukans.edu.1028 testbed4.ittc.ukans.edu.5001: 456773:458221(1448)
testbed5.ittc.ukans.edu.1028 testbed4.ittc.ukans.edu.5001: 459001:460449(1448)
testbed5.ittc.ukans.edu.1028 testbed4.ittc.ukans.edu.5001: 460449:461897(1448)
testbed5.ittc.ukans.edu.1028 testbed4.ittc.ukans.edu.5001: 461897:463345(1448)
testbed4.ittc.ukans.edu.5001 testbed5.ittc.ukans.edu.1028: ack 436501
testbed4.ittc.ukans.edu.5001 testbed5.ittc.ukans.edu.1028: ack 436501
testbed4.ittc.ukans.edu.5001 testbed5.ittc.ukans.edu.1028: ack 436501
testbed5.ittc.ukans.edu.1028 testbed4.ittc.ukans.edu.5001: 463345:464793(1448)
testbed5.ittc.ukans.edu.1028 testbed4.ittc.ukans.edu.5001: 466241:467689(1448)
## the retransmission occurs here which looks like an outoforder packet since
the first transmission was not recorded by tcpdump
testbed5.ittc.ukans.edu.1028 testbed4.ittc.ukans.edu.5001: 436501:437949(1448)

Whereas the dump output at the receiver shows that the transmitter has indeed
transmitted all the packets (that too in order and NOT out of order) but it is
tcpdump at the Txr which is missing out some packets

Dump o/p at Rxr:

We can see that the packets between 431377 and 449553 are received except for a
loss starting from 436501

testbed5.ittc.ukans.edu.1028 testbed4.ittc.ukans.edu.5001: 429929:431377(1448)
testbed5.ittc.ukans.edu.1028 testbed4.ittc.ukans.edu.5001: 431377:432825(1448)
testbed4.ittc.ukans.edu.5001 testbed5.ittc.ukans.edu.1028: ack 432825
testbed5.ittc.ukans.edu.1028 testbed4.ittc.ukans.edu.5001: 432825:434273(1448)
testbed5.ittc.ukans.edu.1028 testbed4.ittc.ukans.edu.5001: 434273:435721(1448)
testbed4.ittc.ukans.edu.5001 testbed5.ittc.ukans.edu.1028: ack 435721
testbed5.ittc.ukans.edu.1028 testbed4.ittc.ukans.edu.5001: 435721:436501(780)
#loss of a segment between 436501 and 437949
testbed5.ittc.ukans.edu.1028 testbed4.ittc.ukans.edu.5001: 437949:439397(1448)
testbed4.ittc.ukans.edu.5001 testbed5.ittc.ukans.edu.1028: ack 436501
testbed5.ittc.ukans.edu.1028 testbed4.ittc.ukans.edu.5001: 439397:440845(1448)
testbed4.ittc.ukans.edu.5001 testbed5.ittc.ukans.edu.1028: ack 436501
testbed5.ittc.ukans.edu.1028 testbed4.ittc.ukans.edu.5001: 440845:442293(1448)
testbed4.ittc.ukans.edu.5001 testbed5.ittc.ukans.edu.1028: ack 436501
testbed5.ittc.ukans.edu.1028 testbed4.ittc.ukans.edu.5001: 442293:443741(1448)
testbed4.ittc.ukans.edu.5001 testbed5.ittc.ukans.edu.1028: ack 436501
testbed5.ittc.ukans.edu.1028 testbed4.ittc.ukans.edu.5001: 443741:445189(1448)
testbed4.ittc.ukans.edu.5001 testbed5.ittc.ukans.edu.1028: ack 436501
testbed5.ittc.ukans.edu.1028 testbed4.ittc.ukans.edu.5001: 445189:446637(1448)
testbed4.ittc.ukans.edu.5001 testbed5.ittc.ukans.edu.1028: ack 436501
testbed5.ittc.ukans.edu.1028 testbed4.ittc.ukans.edu.5001: 446637:448085(1448)
testbed4.ittc.ukans.edu.5001 testbed5.ittc.ukans.edu.1028: ack 436501
testbed5.ittc.ukans.edu.1028 testbed4.ittc.ukans.edu.5001: 448085:449533(1448)
testbed4.ittc.ukans.edu.5001 testbed5.ittc.ukans.edu.1028: ack 436501
testbed5.ittc.ukans.edu.1028 testbed4.ittc.ukans.edu.5001: 449533:450981(1448)
testbed4.ittc.ukans.edu.5001 testbed5.ittc.ukans.edu.1028: ack 436501
testbed5.ittc.ukans.edu.1028 testbed4.ittc.ukans.edu.5001: 450981:452429(1448)
testbed4.ittc.ukans.edu.5001 testbed5.ittc.ukans.edu.1028: ack 436501
testbed5.ittc.ukans.edu.1028 testbed4.ittc.ukans.edu.5001: 452429:453877(1448)
testbed4.ittc.ukans.edu.5001 testbed5.ittc.ukans.edu.1028: ack 436501

Thanks,
Anu.