selftests: `simult_flows`: "unbalanced bwidth with opposed, unbalanced delay" is unstable

[matttbe]

simult_flows's "unbalanced bwidth with opposed, unbalanced delay" test is unstable on NIPA, e.g.

# 09 unbalanced bwidth with opposed, unbalanced delay            transfer slower than expected! runtime 11948 ms, expected 11921 ms[FAIL] client exit code 1, server 0
# 
# netns ns3-YzkKvC (listener) socket stat for 10009:
# Netid State     Recv-Q Send-Q Local Address:Port  Peer Address:Port 
# tcp   TIME-WAIT 0      0           10.0.3.3:10009     10.0.1.1:34976 timer:(timewait,59sec,0) ino:0 sk:f
# 
# TcpPassiveOpens                 2                  0.0
# TcpInSegs                       5122               0.0
# TcpOutSegs                      12257              0.0
# TcpExtTCPPureAcks               5094               0.0
# TcpExtTCPLossProbes             2                  0.0
# TcpExtTCPAutoCorking            1                  0.0
# TcpExtTCPOrigDataSent           12230              0.0
# TcpExtTCPHystartDelayDetect     2                  0.0
# TcpExtTCPHystartDelayCwnd       229                0.0
# TcpExtTCPDelivered              12229              0.0
# MPTcpExtMPCapableSYNRX          1                  0.0
# MPTcpExtMPCapableACKRX          1                  0.0
# MPTcpExtMPJoinSynRx             1                  0.0
# MPTcpExtMPJoinAckRx             1                  0.0
# MPTcpExtOFOQueueTail            4                  0.0
# MPTcpExtOFOQueue                6                  0.0
# MPTcpExtOFOMerge                4                  0.0
# MPTcpExtRcvWndShared            10                 0.0
# 
# netns ns1-9dwbGK (connector) socket stat for 10009:
# Netid State     Recv-Q Send-Q    Local Address:Port  Peer Address:Port                                        
# tcp   TIME-WAIT 0      0              10.0.1.1:34976     10.0.3.3:10009 timer:(timewait,59sec,0) ino:0 sk:10
# 
# tcp   TIME-WAIT 0      0      10.0.2.1%ns1eth2:52413     10.0.3.3:10009 timer:(timewait,59sec,0) ino:0 sk:11
# 
# TcpActiveOpens                  2                  0.0
# TcpInSegs                       5434               0.0
# TcpOutSegs                      5161               0.0
# TcpExtTW                        1                  0.0
# TcpExtDelayedACKs               2                  0.0
# TcpExtTCPPureAcks               25                 0.0
# TcpExtTCPLossProbes             1                  0.0
# TcpExtTCPSpuriousRtxHostQueues  1                  0.0
# TcpExtTCPOrigDataSent           63                 0.0
# TcpExtTCPDelivered              64                 0.0
# MPTcpExtMPCapableSYNTX          1                  0.0
# MPTcpExtMPCapableSYNACKRX       1                  0.0
# MPTcpExtMPJoinSynAckRx          1                  0.0
# MPTcpExtMPJoinSynTx             1                  0.0
# MPTcpExtOFOQueueTail            4757               0.0
# MPTcpExtOFOQueue                4761               0.0
# MPTcpExtOFOMerge                4258               0.0
# MPTcpExtSndWndShared            1                  0.0
# MPTcpExtRcvWndShared            151                0.0
# -rw------- 1 root root 16777216 Sep 30 20:22 /tmp/tmp.x6viSf1glx
# -rw------- 1 root root 16777216 Sep 30 20:24 /tmp/tmp.zjYew7k3TV
# -rw------- 1 root root 81920 Sep 30 20:24 /tmp/tmp.7mUsDk9Lnk
# -rw------- 1 root root 81920 Sep 30 20:22 /tmp/tmp.StdQMhk7zQ

Checklist:

• Reproduce locally
• Bisect
• Fix

[matttbe]

Note from Paolo (I still didn't have the opportunity to look at that)

I have a very wild guess here: possibly the rcvbuf autotuning changes allow the receiver rx buf to grow so much that increases the burstiness to the point that the rcvbuf spooling time is visible (under significant load and/or in VM env) in the self-tests. Possibly monitoring the (average/max) mptcp level rcvbuf size with/without such series could help ruling that out.

If so, assuming the rcvbuf grow is not tragic, I think slightly increase target time (possibly proportionally to the delay introduced) should be enough.

Judging by the frequency of the issue on NIPA, we should be careful when changing the target time (or only do that in specific conditions, when some counters are set, etc.)

[geliangtang]

I have identified through testing that this issue is linked to the commit e118cdc ("mptcp: rcvbuf auto-tuning improvement"). The simult_flows tests pass successfully when this commit is reverted.

To monitor the (average/max) MPTCP level rcvbuf size, I have added the following print statements in __mptcp_recvmsg_mskq:

@@ -1993,6 +1993,7 @@ static int __mptcp_recvmsg_mskq(struct sock *sk,
        }
 
        mptcp_rcv_space_adjust(msk, copied);
+       pr_info("%s sk_rcvbuf=%d\n", __func__, sk->sk_rcvbuf);
        return copied;
 }

Without rcvbuf auto-tuning, the output is:

[  567.273495] MPTCP: __mptcp_recvmsg_mskq sk_rcvbuf=12514148

With rcvbuf auto-tuning, the output is:

[  125.961363] MPTCP: __mptcp_recvmsg_mskq sk_rcvbuf=4782523

It appears that the rcvbuf auto-tuning is causing the rcvbuf size to decrease, which in turn slows down the transmission and leads to simult_flows test failures.

If that's the case, do you think it would be sufficient if we only adjust the maximum threshold of the simult_flows test?

[matttbe]

@geliangtang thank you for having checked that!

It appears that the rcvbuf auto-tuning is causing the rcvbuf size to decrease

Do you mean that the rcvbuf it is lower before @pabeni's patch, or it decreases over time?

If it is lower than before, I guess some adjustments are needed if it is too low?

If it decreases over time, I don't think it is supposed to do that if it is similar to TCP: it should only increase over time, no?

I don't think we should modify the threshold, and I wonder if this patch doesn't cause some regressions shown there: #592 (comment) ; this part ↓

I took latest linux kernel and merged mptcp-next on top, but benchmark results (i refered to them with "6.17 + mptcp-next" above), but actually saw throughput regression

[matttbe]

@geliangtang : do you mind checking if we still have the regression with Eric's series please? → tcp: fix receive autotune again

[geliangtang]

Eric's series, "tcp: fix receive autotune again", along with Paolo's correction (changing msk->rcvq_space.copied to msk->rcvq_space.space in mptcp_rcvbuf_grow()), does fix the issue. Without Paolo's correction, a division by zero error would occur.