Improved DTrace tcp acknowledgement RTT latency script

In the previous post, I concluded with a rough script that measures mean acknowledgement latency averaged across remote host. Acknowledgement latency or round-trip time (RTT) is the time spent waiting between when a TCP segment is sent and an acknowledgement for that data is received. Acknowledgment round-trip time is an important measure as it relates how much data a TCP connection can send - if data is acknowledged quickly, TCP's sliding window can progress. As noted here, for the highest possible throughput, it is important that the transmitter is not forced to stop sending by the sliding window protocol earlier than one round-trip delay time (RTT) - in other words, the window should not fill up before the earliest data is acknowledged, otherwise the sender cannot send any more data until that acknowledgement is received. A number of factors may contribute to these kinds of delays - small advertised windows, slow protocol processing etc - but the important point is we can now use DTrace to measure both RTT and examine how the sliding window evolves over time. Here's a better version of the previous script, breaking down RTT by host and port.

#!/usr/sbin/dtrace -s

#pragma D option quiet

tcp:::send
{
	snxt[args[1]->cs_cid, args[3]->tcps_snxt] = timestamp;
	bytesrttttmp[args[1]->cs_cid, args[3]->tcps_snxt] =
	    args[2]->ip_plength - args[4]->tcp_offset;
}

tcp:::receive
/ snxt[args[1]->cs_cid, args[4]->tcp_ack] /
{
	@bytesrtt[args[2]->ip_saddr, args[4]->tcp_sport] =
	    sum(bytesrttttmp[args[1]->cs_cid, args[4]->tcp_ack]);
	@meanrtt[args[2]->ip_saddr, args[4]->tcp_sport] = 
	    avg(timestamp - snxt[args[1]->cs_cid, args[4]->tcp_ack]);
	@stddevrtt[args[2]->ip_saddr, args[4]->tcp_sport] =
            stddev(timestamp - snxt[args[1]->cs_cid, args[4]->tcp_ack]);
	@countrtt[args[2]->ip_saddr, args[4]->tcp_sport] = count();
	snxt[args[1]->cs_cid, args[4]->tcp_ack] = 0;
	bytesrttttmp[args[1]->cs_cid, args[4]->tcp_ack] = 0;
}

END
{
	printf("%-20s %-8s %-15s %-15s %-10s %-7s\\n",
	    "Remote host", "Port", "TCP Avg RTT(ns)", "StdDev", "NumBytes",
	    "NumSegs");
	printa("%-20s %-8d %@-15d %@-15d %@-10d %@-7d\\n", @meanrtt,
	    @stddevrtt, @bytesrtt, @countrtt);
}

And here's some sample output:

# dtrace -s tcp_rtt2.d
\^C
Remote host          Port     TCP Avg RTT(ns) StdDev          NumBytes   NumSegs
127.0.0.1            9010     109074          79551           0          15     
127.0.0.1            59571    204945          0               0          1      
127.0.0.1            35748    205471          0               0          1      
127.0.0.1            39697    206126          0               0          1      
127.0.0.1            58889    207170          0               0          1      
127.0.0.1            57647    208967          0               0          1      
127.0.0.1            53502    215569          0               0          1      
127.0.0.1            41038    221163          0               0          1      
127.0.0.1            36777    226006          0               0          1      
::1                  9010     233492          186640          0          15     
127.0.0.1            41241    256225          0               0          1      
127.0.0.1            57388    297646          0               0          1      
127.0.0.1            55260    424590          0               0          1      
127.0.0.1            60660    445139          0               0          1      
127.0.0.1            56460    620226          0               0          1      
127.0.0.1            55449    670529          0               0          1      
127.0.0.1            56877    772734          0               0          1      
::1                  62343    1532445         0               0          1      
::1                  51756    1538747         0               0          1      
::1                  41825    1627673         0               0          1      
::1                  56580    1965449         0               0          1      
::1                  65061    2412497         0               0          1      
::1                  50031    2726626         0               0          1      
159.134.196.178      80       2788676         1773030         0          6      
::1                  43043    3465254         0               0          1      
::1                  57685    4454573         0               0          1      
::1                  55854    4490483         0               0          1      
92.123.196.20        80       19855492        0               0          1      
::1                  50972    20481704        0               0          1      
::1                  48172    53565332        0               0          1      
66.235.139.54        80       81219406        80478253        0          2      
::1                  37341    95086544        0               0          1      
::1                  32770    1512858144      0               0          1      
::1                  49710    4197402456      0               0          1      

Next time, we'll look at TCP's sliding window behaviour.

Comments:

Post a Comment:
Comments are closed for this entry.
About

user12820842

Search

Archives
« April 2014
SunMonTueWedThuFriSat
  
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
   
       
Today