TCP_NOTSENT_LOWAT applied to e2e TCP msg latency

Bob McMahon bob.mcmahon at broadcom.com
Thu Oct 21 20:51:42 EDT 2021


Hi All,

Sorry for the spam. I'm trying to support a meaningful TCP message latency
w/iperf 2 from the sender side w/o requiring e2e clock synchronization. I
thought I'd try to use the TCP_NOTSENT_LOWAT event to help with this. It
seems that this event goes off when the bytes are in flight vs have reached
the destination network stack. If that's the case, then iperf 2
<https://sourceforge.net/projects/iperf2/>client (sender) may be able to
produce the message latency by adding the drain time (write start to
TCP_NOTSENT_LOWAT) and the sampled RTT.

Does this seem reasonable?

Below are some sample outputs of a 10G wired sending to a 1G wired. These
systems do have e2e clock sync so the server side message latency is
correct. The RTT + Drain does approximately equal the server side e2e msg
latency

First with BBR

[root at ryzen3950 iperf2-code]# iperf -c 192.168.1.156 -i 1 -e --tcp-drain
--realtime -Z bbr --trip-times -l 1M
------------------------------------------------------------
Client connecting to 192.168.1.156, TCP port 5001 with pid 206299 (1 flows)
Write buffer size: 1048576 Byte (drain-enabled)
TCP congestion control set to bbr
TCP window size:  128 KByte (default)
------------------------------------------------------------
[  1] local 192.168.1.133%enp4s0 port 60684 connected with 192.168.1.156
port 5001 (MSS=1448) (trip-times) (sock=3) (ct=0.26 ms) on 2021-10-21
17:44:10 (PDT)
[ ID] Interval        Transfer    Bandwidth       Write/Err  Rtry
Cwnd/RTT        NetPwr  Drain avg/min/max/stdev (cnt)
[  1] 0.00-1.00 sec   112 MBytes   940 Mbits/sec  113/0          0
 263K/1906 us  61616  8.947/8.322/13.465/0.478 ms (112)
[  1] 1.00-2.00 sec   112 MBytes   940 Mbits/sec  112/0          0
 260K/1987 us  59104  8.911/8.229/9.569/0.229 ms (112)
[  1] 2.00-3.00 sec   113 MBytes   948 Mbits/sec  113/0          0
 254K/2087 us  56775  8.910/8.311/9.564/0.221 ms (113)
[  1] 3.00-4.00 sec   112 MBytes   940 Mbits/sec  112/0          0
 263K/1710 us  68679  8.911/8.297/9.618/0.217 ms (112)
[  1] 4.00-5.00 sec   112 MBytes   940 Mbits/sec  112/0          0
 254K/2024 us  58024  8.907/8.470/9.641/0.197 ms (112)
[  1] 5.00-6.00 sec   112 MBytes   940 Mbits/sec  112/0          0
 263K/2124 us  55292  8.911/8.291/9.325/0.198 ms (112)
[  1] 6.00-7.00 sec   113 MBytes   948 Mbits/sec  113/0          0
 265K/2012 us  58891  8.913/8.226/9.569/0.229 ms (113)
[  1] 7.00-8.00 sec   112 MBytes   940 Mbits/sec  112/0          0
 265K/1989 us  59045  8.908/8.313/9.366/0.194 ms (112)
[  1] 8.00-9.00 sec   112 MBytes   940 Mbits/sec  112/0          0
 263K/1999 us  58750  8.908/8.212/9.402/0.211 ms (112)
[  1] 9.00-10.00 sec   112 MBytes   940 Mbits/sec  112/0          0
 5K/242 us  485291  8.947/8.319/12.754/0.414 ms (112)
[  1] 0.00-10.06 sec  1.10 GBytes   937 Mbits/sec  1125/0          0
 5K/242 us  483764  8.950/8.212/45.293/1.120 ms (1123)

[root at localhost rjmcmahon]# iperf -s -e -B 192.168.1.156%enp4s0f0 -i 1
--realtime
------------------------------------------------------------
Server listening on TCP port 5001 with pid 53099
Binding to local address 192.168.1.156 and iface enp4s0f0
Read buffer size:  128 KByte (Dist bin width=16.0 KByte)
TCP window size:  128 KByte (default)
------------------------------------------------------------
[  1] local 192.168.1.156%enp4s0f0 port 5001 connected with 192.168.1.133
port 60684 (MSS=1448) (trip-times) (sock=4) (peer 2.1.4-master) on
2021-10-21 20:44:10 (EDT)
[ ID] Interval        Transfer    Bandwidth    Burst Latency
avg/min/max/stdev (cnt/size) inP NetPwr  Reads=Dist
[  1] 0.00-1.00 sec   112 MBytes   936 Mbits/sec  10.629/9.890/14.998/1.507
ms (111/1053964) 1.20 MByte 11007  4347=412:3927:7:0:1:0:0:0
[  1] 1.00-2.00 sec   112 MBytes   942 Mbits/sec  10.449/9.736/10.740/0.237
ms (112/1050799) 1.18 MByte 11263  4403=465:3938:0:0:0:0:0:0
[  1] 2.00-3.00 sec   112 MBytes   942 Mbits/sec  10.426/9.873/10.698/0.246
ms (113/1041489) 1.16 MByte 11288  4382=420:3962:0:0:0:0:0:0
[  1] 3.00-4.00 sec   112 MBytes   941 Mbits/sec  10.485/9.724/10.716/0.208
ms (112/1050541) 1.18 MByte 11221  4393=446:3946:1:0:0:0:0:0
[  1] 4.00-5.00 sec   112 MBytes   942 Mbits/sec  10.487/9.902/10.736/0.216
ms (112/1050786) 1.18 MByte 11222  4392=448:3944:0:0:0:0:0:0
[  1] 5.00-6.00 sec   112 MBytes   942 Mbits/sec  10.484/9.758/10.748/0.236
ms (112/1050799) 1.18 MByte 11226  4397=456:3940:0:1:0:0:0:0
[  1] 6.00-7.00 sec   112 MBytes   941 Mbits/sec  10.475/9.756/10.753/0.248
ms (112/1050515) 1.18 MByte 11232  4403=473:3930:0:0:0:0:0:0
[  1] 7.00-8.00 sec   112 MBytes   942 Mbits/sec  10.435/9.759/10.757/0.288
ms (113/1041502) 1.16 MByte 11278  4414=480:3934:0:0:0:0:0:0
[  1] 8.00-9.00 sec   112 MBytes   942 Mbits/sec  10.485/9.762/10.759/0.277
ms (112/1050799) 1.18 MByte 11225  4409=470:3939:0:0:0:0:0:0
[  1] 9.00-10.00 sec   112 MBytes   942 Mbits/sec
 10.550/10.000/10.759/0.191 ms (112/1050786) 1.19 MByte 11155
 4399=455:3944:0:0:0:0:0:0
[  1] 0.00-10.05 sec  1.10 GBytes   937 Mbits/sec
 10.524/9.724/45.519/1.173 ms (1123/1048576) 1.18 MByte 11132
 44149=4725:39414:8:1:1:0:0:0

Now with CUBIC

[root at ryzen3950 iperf2-code]# iperf -c 192.168.1.156 -i 1 -e --tcp-drain
--realtime -Z cubic --trip-times -l 1M
------------------------------------------------------------
Client connecting to 192.168.1.156, TCP port 5001 with pid 206487 (1 flows)
Write buffer size: 1048576 Byte (drain-enabled)
TCP congestion control set to cubic
TCP window size: 85.0 KByte (default)
------------------------------------------------------------
[  1] local 192.168.1.133%enp4s0 port 60686 connected with 192.168.1.156
port 5001 (MSS=1448) (trip-times) (sock=3) (ct=0.49 ms) on 2021-10-21
17:47:02 (PDT)
[ ID] Interval        Transfer    Bandwidth       Write/Err  Rtry
Cwnd/RTT        NetPwr  Drain avg/min/max/stdev (cnt)
[  1] 0.00-1.00 sec   113 MBytes   948 Mbits/sec  114/0         66
1527K/13168 us  8998  8.855/4.757/15.949/0.995 ms (113)
[  1] 1.00-2.00 sec   113 MBytes   948 Mbits/sec  113/0          0
1668K/14380 us  8240  8.899/8.450/9.425/0.270 ms (113)
[  1] 2.00-3.00 sec   112 MBytes   940 Mbits/sec  112/0          0
1781K/15335 us  7658  8.904/8.446/9.314/0.258 ms (112)
[  1] 3.00-4.00 sec   112 MBytes   940 Mbits/sec  112/0          0
1867K/16127 us  7282  8.900/8.570/9.313/0.252 ms (112)
[  1] 4.00-5.00 sec   113 MBytes   948 Mbits/sec  113/0          0
1931K/16537 us  7165  8.908/8.330/9.431/0.290 ms (113)
[  1] 5.00-6.00 sec   111 MBytes   931 Mbits/sec  111/0          1
1439K/12342 us  9431  8.945/4.303/18.970/1.091 ms (111)
[  1] 6.00-7.00 sec   113 MBytes   948 Mbits/sec  113/0          0
1515K/12845 us  9225  8.904/8.451/9.432/0.298 ms (113)
[  1] 7.00-8.00 sec   112 MBytes   940 Mbits/sec  112/0          0
1569K/13353 us  8795  8.907/8.569/9.314/0.283 ms (112)
[  1] 8.00-9.00 sec   112 MBytes   940 Mbits/sec  112/0          0
1606K/13718 us  8561  8.909/8.571/9.312/0.275 ms (112)
[  1] 9.00-10.00 sec   113 MBytes   948 Mbits/sec  113/0          0
1630K/13930 us  8506  8.906/8.569/9.316/0.298 ms (113)
[  1] 0.00-10.04 sec  1.10 GBytes   940 Mbits/sec  1127/0         67
1630K/13930 us  8431  8.904/4.303/18.970/0.526 ms (1125)

[root at localhost rjmcmahon]# iperf -s -e -B 192.168.1.156%enp4s0f0 -i 1
--realtime
------------------------------------------------------------
Server listening on TCP port 5001 with pid 53121
Binding to local address 192.168.1.156 and iface enp4s0f0
Read buffer size:  128 KByte (Dist bin width=16.0 KByte)
TCP window size:  128 KByte (default)
------------------------------------------------------------
[  1] local 192.168.1.156%enp4s0f0 port 5001 connected with 192.168.1.133
port 60686 (MSS=1448) (trip-times) (sock=4) (peer 2.1.4-master) on
2021-10-21 20:47:02 (EDT)
[ ID] Interval        Transfer    Bandwidth    Burst Latency
avg/min/max/stdev (cnt/size) inP NetPwr  Reads=Dist
[  1] 0.00-1.00 sec   111 MBytes   935 Mbits/sec
 20.327/10.445/39.920/4.341 ms (111/1053090) 2.33 MByte 5751
 4344=521:3791:7:2:1:9:0:11
[  1] 1.00-2.00 sec   112 MBytes   942 Mbits/sec
 22.492/21.768/23.254/0.397 ms (112/1050799) 2.53 MByte 5233
 4487=594:3893:0:0:0:0:0:0
[  1] 2.00-3.00 sec   112 MBytes   941 Mbits/sec
 23.624/22.987/24.248/0.327 ms (112/1050502) 2.66 MByte 4980
 4462=548:3912:1:1:0:0:0:0
[  1] 3.00-4.00 sec   112 MBytes   941 Mbits/sec
 24.475/23.741/24.971/0.287 ms (113/1041476) 2.73 MByte 4808
 4483=575:3908:0:0:0:0:0:0
[  1] 4.00-5.00 sec   112 MBytes   942 Mbits/sec
 25.146/24.597/25.459/0.254 ms (112/1050799) 2.83 MByte 4680
 4523=642:3880:0:1:0:0:0:0
[  1] 5.00-6.00 sec   112 MBytes   942 Mbits/sec
 21.592/15.549/36.567/2.358 ms (112/1050786) 2.42 MByte 5450
 4373=489:3868:0:1:0:0:1:12
[  1] 6.00-7.00 sec   112 MBytes   941 Mbits/sec
 21.447/20.800/22.024/0.275 ms (112/1050528) 2.41 MByte 5486
 4464=559:3904:0:1:0:0:0:0
[  1] 7.00-8.00 sec   112 MBytes   942 Mbits/sec
 22.021/21.536/22.519/0.216 ms (113/1041502) 2.46 MByte 5344
 4475=557:3918:0:0:0:0:0:0
[  1] 8.00-9.00 sec   112 MBytes   942 Mbits/sec
 22.445/22.023/22.774/0.209 ms (112/1050799) 2.53 MByte 5243
 4407=474:3932:0:1:0:0:0:0
[  1] 9.00-10.00 sec   112 MBytes   941 Mbits/sec
 22.680/22.269/23.024/0.184 ms (112/1050541) 2.55 MByte 5188
 4511=635:3875:1:0:0:0:0:0
[  1] 0.00-10.03 sec  1.10 GBytes   941 Mbits/sec
 22.629/10.445/39.920/2.083 ms (1125/1048576) 2.54 MByte 5197
 44659=5598:39007:9:7:1:9:1:23

Thanks,
Bob

-- 
This electronic communication and the information and any files transmitted 
with it, or attached to it, are confidential and are intended solely for 
the use of the individual or entity to whom it is addressed and may contain 
information that is confidential, legally privileged, protected by privacy 
laws, or otherwise restricted from disclosure to anyone else. If you are 
not the intended recipient or the person responsible for delivering the 
e-mail to the intended recipient, you are hereby notified that any use, 
copying, distributing, dissemination, forwarding, printing, or copying of 
this e-mail is strictly prohibited. If you received this e-mail in error, 
please return the e-mail to the sender, delete it from your computer, and 
destroy any printed copy of it.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.bufferbloat.net/pipermail/cerowrt-devel/attachments/20211021/6beecd6b/attachment.html>


More information about the Cerowrt-devel mailing list