[L4s-discuss] iperf 2, bounceback, triptimes and clock unsync detections

rjmcmahon <rjmcmahon@rjmcmahon.com> Thu, 19 October 2023 18:26 UTC

Return-Path: <rjmcmahon@rjmcmahon.com>
X-Original-To: l4s-discuss@ietfa.amsl.com
Delivered-To: l4s-discuss@ietfa.amsl.com
Received: from localhost (localhost [127.0.0.1]) by ietfa.amsl.com (Postfix) with ESMTP id C22BDC15155A for <l4s-discuss@ietfa.amsl.com>; Thu, 19 Oct 2023 11:26:43 -0700 (PDT)
X-Virus-Scanned: amavisd-new at amsl.com
X-Spam-Flag: NO
X-Spam-Score: -2.104
X-Spam-Level:
X-Spam-Status: No, score=-2.104 tagged_above=-999 required=5 tests=[BAYES_00=-1.9, DKIM_SIGNED=0.1, DKIM_VALID=-0.1, DKIM_VALID_AU=-0.1, DKIM_VALID_EF=-0.1, HK_RANDOM_ENVFROM=0.001, HK_RANDOM_FROM=0.001, RCVD_IN_ZEN_BLOCKED_OPENDNS=0.001, SPF_HELO_NONE=0.001, SPF_PASS=-0.001, T_SCC_BODY_TEXT_LINE=-0.01, URIBL_BLOCKED=0.001, URIBL_DBL_BLOCKED_OPENDNS=0.001, URIBL_ZEN_BLOCKED_OPENDNS=0.001] autolearn=ham autolearn_force=no
Authentication-Results: ietfa.amsl.com (amavisd-new); dkim=pass (1024-bit key) header.d=rjmcmahon.com
Received: from mail.ietf.org ([50.223.129.194]) by localhost (ietfa.amsl.com [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id qXinPj9Tg3qB for <l4s-discuss@ietfa.amsl.com>; Thu, 19 Oct 2023 11:26:39 -0700 (PDT)
Received: from bobcat.rjmcmahon.com (bobcat.rjmcmahon.com [45.33.58.123]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (2048 bits) server-digest SHA256) (No client certificate requested) by ietfa.amsl.com (Postfix) with ESMTPS id 9C7F0C15152C for <l4s-discuss@ietf.org>; Thu, 19 Oct 2023 11:26:39 -0700 (PDT)
Received: from mail.rjmcmahon.com (bobcat.rjmcmahon.com [45.33.58.123]) by bobcat.rjmcmahon.com (Postfix) with ESMTPA id E23881B26F for <l4s-discuss@ietf.org>; Thu, 19 Oct 2023 11:26:38 -0700 (PDT)
DKIM-Filter: OpenDKIM Filter v2.11.0 bobcat.rjmcmahon.com E23881B26F
DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=rjmcmahon.com; s=bobcat; t=1697739998; bh=anz3GdcdwYCCbMirOOJbq1AR5ipinHF7Lehubt5kigI=; h=Date:From:To:Subject:From; b=FbKtd01ZzQzCnnQs+nPPY5Q7i9NWKc/axxIWj3NqWvzn3J2vG3FTYiiYiwT/i5kHd OcfWt0JMI4njCUbBECLxHqrp/nplZOQxuYbDa1ARaRpqFlAllq+WPxNoLFCKWgchx0 QZyZqHCPiDYT208MQIQFlDJRp6zlwQwXJ3xPRlY8=
MIME-Version: 1.0
Date: Thu, 19 Oct 2023 11:26:38 -0700
From: rjmcmahon <rjmcmahon@rjmcmahon.com>
To: l4s-discuss@ietf.org
Message-ID: <e8434655bf71d54c5ffde94dea5abeec@rjmcmahon.com>
X-Sender: rjmcmahon@rjmcmahon.com
Content-Type: text/plain; charset="US-ASCII"; format="flowed"
Content-Transfer-Encoding: 7bit
Archived-At: <https://mailarchive.ietf.org/arch/msg/l4s-discuss/db134aCeZFL0wo8FdAdKIhrFi1A>
Subject: [L4s-discuss] iperf 2, bounceback, triptimes and clock unsync detections
X-BeenThere: l4s-discuss@ietf.org
X-Mailman-Version: 2.1.39
Precedence: list
List-Id: "Low Latency, Low Loss, Scalable Throughput \(L4S\) " <l4s-discuss.ietf.org>
List-Unsubscribe: <https://www.ietf.org/mailman/options/l4s-discuss>, <mailto:l4s-discuss-request@ietf.org?subject=unsubscribe>
List-Archive: <https://mailarchive.ietf.org/arch/browse/l4s-discuss/>
List-Post: <mailto:l4s-discuss@ietf.org>
List-Help: <mailto:l4s-discuss-request@ietf.org?subject=help>
List-Subscribe: <https://www.ietf.org/mailman/listinfo/l4s-discuss>, <mailto:l4s-discuss-request@ietf.org?subject=subscribe>
X-List-Received-Date: Thu, 19 Oct 2023 18:26:43 -0000

Hi All,

For those who have sync'd your clocks and have installed iperf 2, one 
can use the bounceback test to check if the clock's are not synchronized 
relative to the bb time.  (you'll need to compile the latest iperf from 
master) https://sourceforge.net/projects/iperf2/

Below is an example, look for "[  1] 0.00-10.01 sec  Clock sync error 
count = 92028" at the end of a test to see if there were unsync 
detections.

root@raspberrypi:/usr/local/src/iperf2-code# iperf -c 192.168.1.33 -e -i 
1 --trip-times --bounceback --bounceback-period 0
------------------------------------------------------------
Client connecting to 192.168.1.33, TCP port 5001 with pid 38489 (1/0 
flows/load)
Bounceback test (req/reply size = 100 Byte/ 100 Byte) (server hold req=0 
usecs & tcp_quickack)
TCP congestion control using cubic
TOS set to 0x0 and nodelay (Nagle off)
TCP window size: 85.0 KByte (default)
Event based writes (pending queue watermark at 16384 bytes)
------------------------------------------------------------
[  1] local 192.168.1.32%eth0 port 42258 connected with 192.168.1.33 
port 5001 (prefetch=16384) (bb w/quickack req/reply/hold=100/100/0) 
(trip-times) (sock=3) (icwnd/mss/irtt=14/1448/265) (ct=0.43 ms) on 
2023-10-18 14:49:24.047 (PDT)
[ ID] Interval        Transfer    Bandwidth         BB 
cnt=avg/min/max/stdev         Rtry  Cwnd/RTT    RPS(avg)
[  1] 0.00-1.00 sec   998 KBytes  8.18 Mbits/sec    
10223=0.093/0.078/1.057/0.027 ms    0   14K/62 us    10729 rps
[  1] 1.00-2.00 sec  1.06 MBytes  8.93 Mbits/sec    
11166=0.086/0.077/0.225/0.003 ms    0   14K/61 us    11631 rps
[  1] 2.00-3.00 sec  1.07 MBytes  8.94 Mbits/sec    
11172=0.086/0.077/0.434/0.004 ms    0   14K/60 us    11633 rps
[  1] 3.00-4.00 sec  1.06 MBytes  8.87 Mbits/sec    
11092=0.087/0.079/0.376/0.005 ms    0   14K/62 us    11547 rps
[  1] 4.00-5.00 sec   979 KBytes  8.02 Mbits/sec    
10025=0.096/0.090/0.442/0.004 ms    0   14K/61 us    10402 rps
[  1] 5.00-6.00 sec   960 KBytes  7.86 Mbits/sec    
9831=0.098/0.090/0.413/0.008 ms    0   14K/61 us    10213 rps
[  1] 6.00-7.00 sec   984 KBytes  8.06 Mbits/sec    
10080=0.096/0.090/0.150/0.002 ms    0   14K/61 us    10461 rps
[  1] 7.00-8.00 sec   983 KBytes  8.06 Mbits/sec    
10070=0.096/0.090/0.168/0.002 ms    0   14K/61 us    10452 rps
[  1] 8.00-9.00 sec   984 KBytes  8.06 Mbits/sec    
10074=0.096/0.092/0.149/0.002 ms    0   14K/61 us    10455 rps
[  1] 9.00-10.00 sec   982 KBytes  8.04 Mbits/sec    
10056=0.096/0.087/0.446/0.004 ms    0   14K/64 us    10434 rps
[  1] 0.00-10.01 sec  9.90 MBytes  8.29 Mbits/sec    
103791=0.093/0.077/1.057/0.011 ms    0   14K/1729 us    10795 rps
[  1] 0.00-10.01 sec  OWD (ms) Cnt=103791 TX=0.770/-0.357/4.012/1.683 
RX=-0.678/-3.709/0.789/1.686 Asymmetry=2.299/0.001/7.702/2.857
[  1] 0.00-10.01 sec  OWD-TX-PDF: 
bin(w=100us):cnt(103791)=1:14920,2:263,3:275,4:271,5:273,6:272,7:272,8:272,9:271,10:272,11:270,12:275,13:273,14:272,15:269,16:272,17:272,18:272,19:272,20:273,21:271,22:269,23:273,24:271,25:272,26:273,27:273,28:270,29:272,30:271,31:272,32:271,33:273,34:270,35:271,36:272,37:269,38:20475,39:625,40:2,41:1 
(5.00/95.00/99.7%=1/100000/100000,Outliers=0,obl/obu=57994/0)
[  1] 0.00-10.01 sec  OWD-RX-PDF: 
bin(w=100us):cnt(103791)=1:12175,2:3139,3:3132,4:3136,5:51552,6:5,8:2 
(5.00/95.00/99.7%=1/100000/100000,Outliers=0,obl/obu=30650/0)
[  1] 0.00-10.01 sec  BB8-PDF: 
bin(w=100us):cnt(103791)=1:100388,2:3136,3:258,4:4,5:4,11:1 
(5.00/95.00/99.7%=1/1/2,Outliers=0,obl/obu=0/0)
[  1] 0.00-10.01 sec  Clock sync error count = 92028

Below is an example where the clock are sync'd - there is no Clock sync 
error count message

root@raspberrypi:/usr/local/src/iperf2-code# iperf -c 192.168.1.33 -e -i 
1 --trip-times --bounceback --bounceback-period 0
------------------------------------------------------------
Client connecting to 192.168.1.33, TCP port 5001 with pid 38492 (1/0 
flows/load)
Bounceback test (req/reply size = 100 Byte/ 100 Byte) (server hold req=0 
usecs & tcp_quickack)
TCP congestion control using cubic
TOS set to 0x0 and nodelay (Nagle off)
TCP window size: 85.0 KByte (default)
Event based writes (pending queue watermark at 16384 bytes)
------------------------------------------------------------
[  1] local 192.168.1.32%eth0 port 46112 connected with 192.168.1.33 
port 5001 (prefetch=16384) (bb w/quickack req/reply/hold=100/100/0) 
(trip-times) (sock=3) (icwnd/mss/irtt=14/1448/291) (ct=0.46 ms) on 
2023-10-18 14:51:27.555 (PDT)
[ ID] Interval        Transfer    Bandwidth         BB 
cnt=avg/min/max/stdev         Rtry  Cwnd/RTT    RPS(avg)
[  1] 0.00-1.00 sec  1003 KBytes  8.22 Mbits/sec    
10270=0.093/0.079/1.218/0.025 ms    0   14K/61 us    10775 rps
[  1] 1.00-2.00 sec  1.06 MBytes  8.93 Mbits/sec    
11166=0.086/0.078/0.322/0.005 ms    0   14K/60 us    11628 rps
[  1] 2.00-3.00 sec  1.07 MBytes  8.94 Mbits/sec    
11175=0.086/0.078/0.263/0.003 ms    0   14K/61 us    11635 rps
[  1] 3.00-4.00 sec  1.06 MBytes  8.93 Mbits/sec    
11167=0.086/0.078/0.313/0.004 ms    0   14K/60 us    11630 rps
[  1] 4.00-5.00 sec   998 KBytes  8.18 Mbits/sec    
10224=0.094/0.080/0.410/0.006 ms    0   14K/62 us    10614 rps
[  1] 5.00-6.00 sec   958 KBytes  7.85 Mbits/sec    
9811=0.098/0.088/0.432/0.009 ms    0   14K/61 us    10187 rps
[  1] 6.00-7.00 sec   982 KBytes  8.05 Mbits/sec    
10060=0.096/0.090/0.306/0.003 ms    0   14K/61 us    10437 rps
[  1] 7.00-8.00 sec   980 KBytes  8.03 Mbits/sec    
10035=0.096/0.090/0.927/0.015 ms    0   14K/61 us    10409 rps
[  1] 8.00-9.00 sec   981 KBytes  8.04 Mbits/sec    
10048=0.096/0.090/0.763/0.010 ms    0   14K/61 us    10424 rps
[  1] 9.00-10.00 sec   982 KBytes  8.04 Mbits/sec    
10054=0.096/0.092/0.287/0.003 ms    0   14K/61 us    10432 rps
[  1] 0.00-10.01 sec  9.92 MBytes  8.31 Mbits/sec    
104011=0.092/0.078/1.218/0.012 ms    0   14K/1009 us    10816 rps
[  1] 0.00-10.01 sec  OWD (ms) Cnt=104011 TX=0.040/0.030/0.680/0.005 
RX=0.053/0.045/0.887/0.008 Asymmetry=0.013/0.000/0.847/0.006
[  1] 0.00-10.01 sec  OWD-TX-PDF: 
bin(w=100us):cnt(104011)=1:103967,2:31,3:9,4:2,6:1,7:1 
(5.00/95.00/99.7%=1/1/1,Outliers=0,obl/obu=0/0)
[  1] 0.00-10.01 sec  OWD-RX-PDF: 
bin(w=100us):cnt(104011)=1:103769,2:226,3:13,4:1,8:1,9:1 
(5.00/95.00/99.7%=1/1/1,Outliers=0,obl/obu=0/0)
[  1] 0.00-10.01 sec  BB8-PDF: 
bin(w=100us):cnt(104011)=1:100646,2:3146,3:198,4:10,5:4,6:1,7:1,8:2,10:2,13:1 
(5.00/95.00/99.7%=1/1/2,Outliers=0,obl/obu=0/0)

Bob