From: Slava Kritov (Slava.kritov@veritas.com)
Date: 08/04/04
Message-ID: <B78ECA1C29CAD4119E0C0008C7866678096225B1@mtvxch08.veritas.com> From: Slava Kritov <Slava.kritov@veritas.com> Subject: tcptrace-bugs Potential rexmit undercount Date: Wed, 4 Aug 2004 19:16:06 -0700
Hello,
I've been using tcptrace to analyze captures of the following environment:
[sun240, solaris8]-[1G eth]-[Compaq 2xPIII, linux kernel v. 2.4.18 +
NIST]-[1G eth]-[sun240, solaris8]
Nist was set to 100 Mbps, 10 ms and 1% packet loss
I was capturing either on linux or on sun boxes, and I see the following
irregularity:
For all packets coming from remote machine (as opposite to a segment where I
capture) I would see dups - but not rexmits. The numbers also are too varied
Please consider results of analyzing iperf dualtest below (my comments are
marked by ***):
1 arg remaining, starting with 'eth2100-1loss10msdump-iperf.dmp'
Ostermann's tcptrace -- version 6.6.1 -- Wed Nov 19, 2003
80648 packets seen, 80648 TCP packets traced
elapsed wallclock time: 0:00:00.368683, 218746 pkts/sec analyzed
trace file elapsed time: 0:01:00.232135
TCP connection info:
2 TCP connections traced:
TCP connection 1:
host a: 192.168.10.4:45084
host b: 192.168.20.4:5001
complete conn: yes
first packet: Wed Aug 4 11:41:15.796775 2004
last packet: Wed Aug 4 11:42:16.028910 2004
elapsed time: 0:01:00.232135
total packets: 33985
filename: eth2100-1loss10msdump-iperf.dmp
a->b: b->a:
total packets: 17615 total packets: 16370
ack pkts sent: 17614 ack pkts sent: 16370
pure acks sent: 2 pure acks sent: 16366
sack pkts sent: 0 sack pkts sent: 3109
dsack pkts sent: 0 dsack pkts sent: 0
max sack blks/ack: 0 max sack blks/ack: 2
unique bytes sent: 24043544 unique bytes sent: 0
actual data pkts: 17612 actual data pkts: 0
actual data bytes: 24045004 actual data bytes: 0
rexmt data pkts: 1 rexmt data pkts: 2
rexmt data bytes: 1460 rexmt data bytes: 2
zwnd probe pkts: 0 zwnd probe pkts: 0
zwnd probe bytes: 0 zwnd probe bytes: 0
outoforder pkts: 186 outoforder pkts: 0
pushed data pkts: 1216 pushed data pkts: 0
SYN/FIN pkts sent: 1/1 SYN/FIN pkts sent: 2/2
req sack: Y req sack: Y
sacks sent: 0 sacks sent: 3109
urgent data pkts: 0 pkts urgent data pkts: 0
pkts
urgent data bytes: 0 bytes urgent data bytes: 0
bytes
mss requested: 1460 bytes mss requested: 1460
bytes
max segm size: 1460 bytes max segm size: 0
bytes
min segm size: 24 bytes min segm size: 0
bytes
avg segm size: 1365 bytes avg segm size: 0
bytes
max win adv: 24820 bytes max win adv: 64240
bytes
min win adv: 24820 bytes min win adv: 64240
bytes
zero win adv: 0 times zero win adv: 0
times
avg win adv: 24820 bytes avg win adv: 64240
bytes
initial window: 24 bytes initial window: 0
bytes
initial window: 1 pkts initial window: 0
pkts
ttl stream length: 24043544 bytes ttl stream length: 0
bytes
missed data: 0 bytes missed data: 0
bytes
truncated data: 22178214 bytes truncated data: 0
bytes
truncated packets: 17611 pkts truncated packets: 0
pkts
data xmit time: 60.187 secs data xmit time: 0.000
secs
idletime max: 410.1 ms idletime max: 410.2 ms
hardware dups: 0 segs hardware dups: 7590
segs
*** even if I use no_hw_dups option there should be much more rexmits in the
left column ***
** WARNING: presence of hardware duplicates makes these figures
suspect!
throughput: 399181 Bps throughput: 0 Bps
RTT samples: 6582 RTT samples: 0
RTT min: 0.1 ms RTT min: 0.0 ms
RTT max: 99.8 ms RTT max: 0.0 ms
RTT avg: 1.3 ms RTT avg: 0.0 ms
RTT stdev: 5.8 ms RTT stdev: 0.0 ms
RTT from 3WHS: 3.8 ms RTT from 3WHS: 0.0 ms
RTT full_sz smpls: 6546 RTT full_sz smpls: 0
RTT full_sz min: 0.2 ms RTT full_sz min: 0.0 ms
RTT full_sz max: 99.8 ms RTT full_sz max: 0.0 ms
RTT full_sz avg: 1.2 ms RTT full_sz avg: 0.0 ms
RTT full_sz stdev: 5.3 ms RTT full_sz stdev: 0.0 ms
post-loss acks: 181 post-loss acks: 0
For the following 5 RTT statistics, only ACKs for
multiply-transmitted segments (ambiguous ACKs) were
considered. Times are taken from the last instance
of a segment.
ambiguous acks: 0 ambiguous acks: 2
RTT min (last): 0.0 ms RTT min (last): 20.2 ms
RTT max (last): 0.0 ms RTT max (last): 20.4 ms
RTT avg (last): 0.0 ms RTT avg (last): 20.3 ms
RTT sdv (last): 0.0 ms RTT sdv (last): 0.0 ms
segs cum acked: 10849 segs cum acked: 0
duplicate acks: 3123 duplicate acks: 0
triple dupacks: 212 triple dupacks: 0
max # retrans: 1 max # retrans: 1
min retr time: 431.0 ms min retr time: 0.0 ms
max retr time: 431.0 ms max retr time: 0.0 ms
avg retr time: 430.9 ms avg retr time: 0.0 ms
sdv retr time: 0.0 ms sdv retr time: 0.0 ms
================================
TCP connection 2:
host c: 192.168.20.4:33514
host d: 192.168.10.4:5001
complete conn: yes
first packet: Wed Aug 4 11:41:15.823068 2004
last packet: Wed Aug 4 11:42:15.946688 2004
elapsed time: 0:01:00.123620
total packets: 46663
filename: eth2100-1loss10msdump-iperf.dmp
c->d: d->c:
total packets: 37910 total packets: 8753
ack pkts sent: 37908 ack pkts sent: 8753
pure acks sent: 4 pure acks sent: 8751
sack pkts sent: 0 sack pkts sent: 1547
dsack pkts sent: 0 dsack pkts sent: 0
max sack blks/ack: 0 max sack blks/ack: 2
unique bytes sent: 25747456 unique bytes sent: 0
actual data pkts: 37904 actual data pkts: 0
actual data bytes: 51754056 actual data bytes: 0
rexmt data pkts: 19047 rexmt data pkts: 0
*** This seems to be way more than expected on 1% loss ***
rexmt data bytes: 26006602 rexmt data bytes: 0
zwnd probe pkts: 0 zwnd probe pkts: 0
zwnd probe bytes: 0 zwnd probe bytes: 0
outoforder pkts: 0 outoforder pkts: 0
pushed data pkts: 2345 pushed data pkts: 0
SYN/FIN pkts sent: 2/2 SYN/FIN pkts sent: 1/1
req sack: Y req sack: Y
sacks sent: 0 sacks sent: 1547
urgent data pkts: 0 pkts urgent data pkts: 0
pkts
urgent data bytes: 0 bytes urgent data bytes: 0
bytes
mss requested: 1460 bytes mss requested: 1460
bytes
max segm size: 1460 bytes max segm size: 0
bytes
min segm size: 892 bytes min segm size: 0
bytes
avg segm size: 1365 bytes avg segm size: 0
bytes
max win adv: 24820 bytes max win adv: 64240
bytes
min win adv: 24820 bytes min win adv: 64240
bytes
zero win adv: 0 times zero win adv: 0
times
avg win adv: 24820 bytes avg win adv: 64240
bytes
initial window: 4380 bytes initial window: 0
bytes
initial window: 3 pkts initial window: 0
pkts
ttl stream length: 25747456 bytes ttl stream length: 0
bytes
missed data: 0 bytes missed data: 0
bytes
truncated data: 47736232 bytes truncated data: 0
bytes
truncated packets: 37904 pkts truncated packets: 0
pkts
data xmit time: 60.082 secs data xmit time: 0.000
secs
idletime max: 428.6 ms idletime max: 428.5 ms
hardware dups: 11138 segs hardware dups: 0
segs
*** again - very strange stats above
** WARNING: presence of hardware duplicates makes these figures
suspect!
throughput: 428242 Bps throughput: 0 Bps
RTT samples: 0 RTT samples: 2
RTT min: 0.0 ms RTT min: 0.1 ms
RTT max: 0.0 ms RTT max: 0.1 ms
RTT avg: 0.0 ms RTT avg: 0.1 ms
RTT stdev: 0.0 ms RTT stdev: 0.0 ms
RTT from 3WHS: 0.0 ms RTT from 3WHS: 0.1 ms
RTT full_sz smpls: 0 RTT full_sz smpls: 1
RTT full_sz min: 0.0 ms RTT full_sz min: 0.1 ms
RTT full_sz max: 0.0 ms RTT full_sz max: 0.1 ms
RTT full_sz avg: 0.0 ms RTT full_sz avg: 0.1 ms
RTT full_sz stdev: 0.0 ms RTT full_sz stdev: 0.0 ms
post-loss acks: 184 post-loss acks: 0
For the following 5 RTT statistics, only ACKs for
multiply-transmitted segments (ambiguous ACKs) were
considered. Times are taken from the last instance
of a segment.
ambiguous acks: 7133 ambiguous acks: 0
RTT min (last): 20.3 ms RTT min (last): 0.0 ms
RTT max (last): 120.2 ms RTT max (last): 0.0 ms
RTT avg (last): 21.3 ms RTT avg (last): 0.0 ms
RTT sdv (last): 3.8 ms RTT sdv (last): 0.0 ms
segs cum acked: 11542 segs cum acked: 0
duplicate acks: 1436 duplicate acks: 1
triple dupacks: 175 triple dupacks: 0
max # retrans: 2 max # retrans: 0
min retr time: 0.0 ms min retr time: 0.0 ms
max retr time: 440.3 ms max retr time: 0.0 ms
avg retr time: 0.5 ms avg retr time: 0.0 ms
sdv retr time: 8.8 ms sdv retr time: 0.0 ms
Thanks a lot
Slava
This archive was generated by hypermail 2.1.7 : 08/05/04 EDT