[Bloat] 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/bloat/attachments/20211021/6beecd6b/attachment.html>
More information about the Bloat
mailing list