Debugging TCP problems can be difficult and time consuming, especially when the connection end-points lack tools to observe connection behavior. One such tool that should be on every system is tcptrace(1). This awesome utility can assist with pinpointing network issues, and can help with debugging TCP performance and reliability problems.
tcptrace(1) operates on tcpdump and snoop binary files, and provides numerous statistics and connection details for each capture file passed as an argument. To get started with tcptrace(1), tcpdump(1) or snoop(1m) needs to be run to collect raw packet information. This information can be saved to a file with tcpdump(1)‘s “-w” option, and complex filters can be applied to limit which hosts and ports data is collected from.
The following example shows how to capture connections to TCP port 80 on the prefetch.net web server, and save the captured contents to a file named “tcpdump.out”:
$ tcpdump -i hme1 -w tcpdump.out -s 1520 port 80
tcpdump: listening on hme1, link-type EN10MB
^C
259 packets received by filter
0 packets dropped by kernel
Once data is collected with snoop(1m) or tcpdump(1m), tcptrace(1m) can be run to display the TCP connections that were captured:
$ tcptrace tcpdump.out
1 arg remaining, starting with 'tcpdump.out'
Ostermann's tcptrace -- version 6.2.0 -- Fri Jul 26, 2002
44 packets seen, 44 TCP packets traced
elapsed wallclock time: 0:00:00.025033, 1757 pkts/sec analyzed
trace file elapsed time: 0:00:00.435121
TCP connection info:
1: c-24-98-83-96.hsd1.ga.comcast.net:63807 - prefetch.net:www (a2b) 7> 6<
2: c-24-98-83-96.hsd1.ga.comcast.net:62941 - prefetch.net:www (c2d) 6> 4<
3: c-24-98-83-96.hsd1.ga.comcast.net:57312 - prefetch.net:www (e2f) 6> 5<
4: c-24-98-83-96.hsd1.ga.comcast.net:55792 - prefetch.net:www (g2h) 6> 4<
Each connection will contain a unique connection number, the SRC and DST IP address or hostname, a unique descriptor to identify the connection, an integer value with directional brackets to indicate how many segments were sent in each direction, and an optional value to indicate if the connection was reset (RST), or closed normally (FIN). To print information specific to the first TCP connection (e.g., connection number 1), the connection number can be passed to tcptrace(1m)‘s “-o” option:
$ tcptrace -o1 tcpdump.out
1 arg remaining, starting with 'tcpdump.out'
Ostermann's tcptrace -- version 6.2.0 -- Fri Jul 26, 2002
44 packets seen, 44 TCP packets traced
elapsed wallclock time: 0:00:00.023074, 1906 pkts/sec analyzed
trace file elapsed time: 0:00:00.435121
TCP connection info:
1: c-24-98-83-96.hsd1.ga.comcast.net:63807 - prefetch.net:www (a2b) 7> 6<
If you are debugging problematic TCP connections, tcptrace(1m)‘s “-l” (long output) option can be used to summarize connection details, and pinpoint connection problems. The following example shows how to display detailed connection data for TCP connection 1:
$ tcptrace -l -o1 tcpdump.out
1 arg remaining, starting with 'tcpdump.out'
Ostermann's tcptrace -- version 6.2.0 -- Fri Jul 26, 2002
44 packets seen, 44 TCP packets traced
elapsed wallclock time: 0:00:00.022843, 1926 pkts/sec analyzed
trace file elapsed time: 0:00:00.435121
TCP connection info:
4 TCP connections traced:
TCP connection 1:
host a: c-1-2-3-4.hsd1.ga.comcast.net:63807
host b: prefetch.net:www
complete conn: no (SYNs: 2) (FINs: 0)
first packet: Wed Dec 31 19:00:00.362901 1969
last packet: Wed Dec 31 19:00:00.798022 1969
elapsed time: 0:00:00.435121
total packets: 13
filename: tcpdump.out
a->b: b->a:
total packets: 7 total packets: 6
ack pkts sent: 6 ack pkts sent: 6
pure acks sent: 2 pure acks sent: 0
sack pkts sent: 0 sack pkts sent: 0
max sack blks/ack: 0 max sack blks/ack: 0
unique bytes sent: 1097 unique bytes sent: 4609
actual data pkts: 4 actual data pkts: 5
actual data bytes: 1097 actual data bytes: 4609
rexmt data pkts: 0 rexmt data pkts: 0
rexmt data bytes: 0 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: 4 pushed data pkts: 4
SYN/FIN pkts sent: 1/0 SYN/FIN pkts sent: 1/0
req 1323 ws/ts: Y/Y req 1323 ws/ts: Y/Y
adv wind scale: 0 adv wind scale: 1
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: 288 bytes max segm size: 1448 bytes
min segm size: 236 bytes min segm size: 418 bytes
avg segm size: 274 bytes avg segm size: 921 bytes
max win adv: 65535 bytes max win adv: 66608 bytes
min win adv: 65535 bytes min win adv: 66608 bytes
zero win adv: 0 times zero win adv: 0 times
avg win adv: 65535 bytes avg win adv: 66429 bytes
initial window: 236 bytes initial window: 2594 bytes
initial window: 1 pkts initial window: 2 pkts
ttl stream length: NA ttl stream length: NA
missed data: NA missed data: NA
truncated data: 0 bytes truncated data: 0 bytes
truncated packets: 0 pkts truncated packets: 0 pkts
data xmit time: 0.197 secs data xmit time: 0.195 secs
idletime max: 212.8 ms idletime max: 181.2 ms
throughput: 2521 Bps throughput: 10592 Bps
Each value listed in the tcptrace(1) long output is described in the tcptrace(1) “-houtput” screen:
$ tcptrace -houtput
OK, here's a sample output (using -l) and what each line means:
1 connection traced:
#### how many distinct TCP connections did I see pieces of
13 packets seen, 13 TCP packets traced
#### how many packets did I see, how many did I trace
connection 1:
#### I'll give you a separate block for each connection,
#### here's the first one
host a: 132.235.3.133:1084
host b: 132.235.1.2:79
#### Each connection has two hosts. To shorten output
#### and file names, I just give them letters.
#### Connection 1 has hosts 'a' and 'b', connection 2
#### has hosts 'c' and 'd', etc.
complete conn: yes
#### Did I see the starting FINs and closing SYNs? Was it reset?
first packet: Wed Jul 20 16:40:30.688114
#### At what time did I see the first packet from this connection?
last packet: Wed Jul 20 16:40:41.126372
#### At what time did I see the last packet from this connection?
elapsed time: 0:00:10.438257
#### Elapsed time, first packet to last packet
total packets: 13
#### total packets this connection
#### ... Now, there's two columns of output (TCP is
#### duplex) one for each direction of packets.
#### I'll just explain one column...
a->b: b->a:
total packets: 7 total packets: 6
#### packets sent in each direction
ack pkts sent: 6 ack pkts sent: 6
#### how many of the packets contained a valid ACK
unique bytes sent: 11 unique bytes sent: 1152
#### how many data bytes were sent (not counting retransmissions)
actual data pkts: 2 actual data pkts: 1
#### how many packets did I see that contained any amount of data
actual data bytes: 11 actual data bytes: 1152
#### how many data bytes did I see (including retransmissions)
rexmt data pkts: 0 rexmt data pkts: 0
#### how many data packets were retransmissions
rexmt data bytes: 0 rexmt data bytes: 0
#### how many bytes were retransmissions
outoforder pkts: 0 outoforder pkts: 0
#### how many packets were out of order (or I didn't see the first transmit!)
SYN/FIN pkts sent: 1/1 SYN/FIN pkts sent: 1/1
#### how many SYNs and FINs were sent in each direction
mss requested: 1460 bytes mss requested: 1460 bytes
#### What what the requested Maximum Segment Size
max segm size: 9 bytes max segm size: 1152 bytes
#### What was the largest segment that I saw
min segm size: 2 bytes min segm size: 1152 bytes
#### What was the smallest segment that I saw
avg segm size: 5 bytes avg segm size: 1150 bytes
#### What was the average segment that I saw
max win adv: 4096 bytes max win adv: 4096 bytes
#### What was the largest window advertisement that I sent
min win adv: 4096 bytes min win adv: 4085 bytes
#### What was the smallest window advertisement that I sent
zero win adv: 0 times zero win adv: 0 times
#### How many times did I sent a zero-sized window advertisement
avg win adv: 4096 bytes avg win adv: 4092 bytes
#### What was the average window advertisement that I sent
initial window: 9 bytes initial window: 1152 bytes
#### How many bytes in the first window (before the first ACK)
initial window: 1 pkts initial window: 1 pkts
#### How many packets in the first window (before the first ACK)
throughput: 1 Bps throughput: 110 Bps
#### What was the data throughput (Bytes/second)
ttl stream length: 11 bytes ttl stream length: 1152 bytes
#### What was the total length of the stream (from FIN to SYN)
#### Note that this might be larger than unique data bytes because
#### I might not have captured every segment!!!
missed data: 0 bytes missed data: 0 bytes
#### How many bytes of data were in the stream that I didn't see?
RTT samples: 2 RTT samples: 1
#### How many ACK's could I use to get an RTT sample
RTT min: 45.9 ms RTT min: 19.4 ms
#### What was the smallest RTT that I saw
RTT max: 199.0 ms RTT max: 19.4 ms
#### What was the largest RTT that I saw
RTT avg: 122.5 ms RTT avg: 19.4 ms
#### What was the average RTT that I saw
RTT stdev: 0.0 ms RTT stdev: 0.0 ms
#### What was the standard deviation of the RTT that I saw
segs cum acked: 0 segs cum acked: 0
#### How many segments were cumulatively ACKed (the ACK that I saw
#### was for a later segment. Might be a lost ACK or a delayed ACK
duplicate acks: 2 duplicate acks: 0
#### How many duplicate ACKs did I see
max # retrans: 0 max # retrans: 0
#### What was the most number of times that a single segment
#### was retransmitted
min retr time: 0.0 ms min retr time: 0.0 ms
#### What was the minimum time between retransmissions of a
#### single segment
max retr time: 0.0 ms max retr time: 0.0 ms
#### What was the maximum time between retransmissions of a
#### single segment
avg retr time: 0.0 ms avg retr time: 0.0 ms
#### What was the average time between retransmissions of a
#### single segment
sdv retr time: 0.0 ms sdv retr time: 0.0 ms
#### What was the stdev between retransmissions of a
#### single segment
Version: Ostermann's tcptrace -- version 6.2.0 -- Fri Jul 26, 2002
Compiled by 'root' at 'Thu Oct 6 00:53:41 EDT 2005' on machine 'oscar.matty.com'
I regularly use the retransmission, mss, bytes transmitted, segment size., window advertisement and duplicate ACK values to debug problematic TCP connections. In addition to printing connection statistics, tcptrace(1) can display RTT (round trip times) values when invoked with the “-r” (print rtt statistics) option:
$ tcptrace -r -l -o1 tcpdump.out
1 arg remaining, starting with 'tcpdump.out'
Ostermann's tcptrace -- version 6.2.0 -- Fri Jul 26, 2002
44 packets seen, 44 TCP packets traced
elapsed wallclock time: 0:00:00.023206, 1896 pkts/sec analyzed
trace file elapsed time: 0:00:00.435121
TCP connection info:
4 TCP connections traced:
TCP connection 1:
host a: c-1-2-3-4.hsd1.ga.comcast.net:63807
host b: prefetch.net:www
complete conn: no (SYNs: 2) (FINs: 0)
first packet: Wed Dec 31 19:00:00.362901 1969
last packet: Wed Dec 31 19:00:00.798022 1969
elapsed time: 0:00:00.435121
total packets: 13
filename: tcpdump.out
a->b: b->a:
total packets: 7 total packets: 6
ack pkts sent: 6 ack pkts sent: 6
pure acks sent: 2 pure acks sent: 0
sack pkts sent: 0 sack pkts sent: 0
max sack blks/ack: 0 max sack blks/ack: 0
unique bytes sent: 1097 unique bytes sent: 4609
actual data pkts: 4 actual data pkts: 5
actual data bytes: 1097 actual data bytes: 4609
rexmt data pkts: 0 rexmt data pkts: 0
rexmt data bytes: 0 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: 4 pushed data pkts: 4
SYN/FIN pkts sent: 1/0 SYN/FIN pkts sent: 1/0
req 1323 ws/ts: Y/Y req 1323 ws/ts: Y/Y
adv wind scale: 0 adv wind scale: 1
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: 288 bytes max segm size: 1448 bytes
min segm size: 236 bytes min segm size: 418 bytes
avg segm size: 274 bytes avg segm size: 921 bytes
max win adv: 65535 bytes max win adv: 66608 bytes
min win adv: 65535 bytes min win adv: 66608 bytes
zero win adv: 0 times zero win adv: 0 times
avg win adv: 65535 bytes avg win adv: 66429 bytes
initial window: 236 bytes initial window: 2594 bytes
initial window: 1 pkts initial window: 2 pkts
ttl stream length: NA ttl stream length: NA
missed data: NA missed data: NA
truncated data: 0 bytes truncated data: 0 bytes
truncated packets: 0 pkts truncated packets: 0 pkts
data xmit time: 0.197 secs data xmit time: 0.195 secs
idletime max: 212.8 ms idletime max: 181.2 ms
throughput: 2521 Bps throughput: 10592 Bps
RTT samples: 5 RTT samples: 5
RTT min: 24.6 ms RTT min: 0.4 ms
RTT max: 43.4 ms RTT max: 181.2 ms
RTT avg: 33.3 ms RTT avg: 53.4 ms
RTT stdev: 6.7 ms RTT stdev: 79.6 ms
RTT from 3WHS: 24.6 ms RTT from 3WHS: 0.4 ms
RTT full_sz smpls: 1 RTT full_sz smpls: 1
RTT full_sz min: 24.6 ms RTT full_sz min: 0.4 ms
RTT full_sz max: 24.6 ms RTT full_sz max: 0.4 ms
RTT full_sz avg: 24.6 ms RTT full_sz avg: 0.4 ms
RTT full_sz stdev: 0.0 ms RTT full_sz stdev: 0.0 ms
post-loss acks: 0 post-loss acks: 0
segs cum acked: 0 segs cum acked: 1
duplicate acks: 1 duplicate acks: 1
triple dupacks: 0 triple dupacks: 0
max # retrans: 0 max # retrans: 0
min retr time: 0.0 ms min retr time: 0.0 ms
max retr time: 0.0 ms max retr time: 0.0 ms
avg retr time: 0.0 ms avg retr time: 0.0 ms
sdv retr time: 0.0 ms sdv retr time: 0.0 ms
The round trip metrics are invaluable for debugging long haul connection problems, especially connection problems caused by retransmissions and misconfigured window avertisement sizes. Since the RTT measurements are provided in each direction, this can also be used to measure the impact of routing problems. tcptrace(1) provides dozens of useful options, and comes with an awesome manual page to describe the meaning and purpose of each tcptrace(1m) option.