selftests: simult_flows.sh: unbalanced bwidth tests are unstable

[matttbe]

I noticed that after having applied 13a9499 ("mptcp: fix locking in mptcp_disconnect()") my CI reports instabilities with simult_flows.sh selftests with unbalanced bwidth tests, e.g.:

• unbalanced bwidth, unbalanced delay
• unbalanced bwidth with opposed, unbalanced delay
• unbalanced bwidth with opposed, unbalanced delay - reverse direction

Mainly with the last one with both debug and non debug kernel configs.

# unbalanced bwidth with opposed, unbalanced delay 3408 max 3245 [ fail ]
# client exit code 0, server 0
#
# netns ns3-0-VxsqRF socket stat for 10009:
# State Recv-Q Send-Q Local Address:Port Peer Address:Port Process
# TIME-WAIT 0 0 10.0.3.3:10009 10.0.1.1:55602 timer:(timewait,59sec,0)
#
# TIME-WAIT 0 0 10.0.3.3:10009 10.0.2.1:37425 timer:(timewait,59sec,0)
#
#
# netns ns1-0-VxsqRF socket stat for 10009:
# State Recv-Q Send-Q Local Address:Port Peer Address:PortProcess
# -rw------- 1 root root 8388608 Jan 14 17:57 /tmp/tmp.VLIfxBoNRi
# -rw------- 1 root root 8388608 Jan 14 17:58 /tmp/tmp.bqj6pDxgap
# -rw------- 1 root root 81920 Jan 14 17:58 /tmp/tmp.pXbmYOeFBb
# -rw------- 1 root root 81920 Jan 14 17:57 /tmp/tmp.rJduZf5gt0
# unbalanced bwidth with opposed, unbalanced delay - reverse direction 3271 max 3245 [ fail ]
# client exit code 0, server 0
#
# netns ns3-0-VxsqRF socket stat for 10010:
# State Recv-Q Send-Q Local Address:Port Peer Address:PortProcess
#
# netns ns1-0-VxsqRF socket stat for 10010:
# State Recv-Q Send-Q Local Address:Port Peer Address:Port Process
# TIME-WAIT 0 0 10.0.2.1%ns1eth2:59907 10.0.3.3:10010 timer:(timewait,59sec,0)
#
# TIME-WAIT 0 0 10.0.1.1:55726 10.0.3.3:10010 timer:(timewait,59sec,0)
#
# -rw------- 1 root root 81920 Jan 14 17:58 /tmp/tmp.bqj6pDxgap
# -rw------- 1 root root 81920 Jan 14 17:57 /tmp/tmp.rJduZf5gt0
# -rw------- 1 root root 8388608 Jan 14 17:57 /tmp/tmp.VLIfxBoNRi
# -rw------- 1 root root 8388608 Jan 14 17:58 /tmp/tmp.pXbmYOeFBb

When looking at results from my CI, since yesterday -- after having applied the commit 13a9499: https://github.com/multipath-tcp/mptcp_net-next/compare/export/20210114T060000..export/20210114T172607 -- I have it all the time.

Before, I only got it once in total and it was on the 15th of December.

So it looks like a regression introduced by 13a9499.

[matttbe]

FYI: this week-end, there were two builds which were unstable because simult_flows.sh reported these errors:

unbalanced bwidth with opposed, unbalanced delay - reverse direction 3316 max 3245 [ fail ]
unbalanced bwidth with unbalanced delay - reverse direction  3294 max 3245  [ fail ]

Both with a debug kernel. Without the debug kernel, everything was OK, e.g.

  | # balanced bwidth                                     4576 max 5005 [ OK ]
  | # balanced bwidth - reverse direction                 4584 max 5005 [ OK ]
  | # balanced bwidth with unbalanced delay               4576 max 5005 [ OK ]
  | # balanced bwidth with unbalanced delay - reverse direction  4576 max 5005 [ OK ]
  | # unbalanced bwidth                                   2961 max 3245 [ OK ]
  | # unbalanced bwidth - reverse direction               2934 max 3245 [ OK ]
  | # unbalanced bwidth with unbalanced delay             2944 max 3245 [ OK ]
  | # unbalanced bwidth with unbalanced delay - reverse direction  2928 max 3245 [ OK ]
  | # unbalanced bwidth with opposed, unbalanced delay    2938 max 3245 [ OK ]
  | # unbalanced bwidth with opposed, unbalanced delay - reverse direction  2998 max 3245 [ OK ]

  | # balanced bwidth                                     4589 max 5005 [ OK ]
  | # balanced bwidth - reverse direction                 4603 max 5005 [ OK ]
  | # balanced bwidth with unbalanced delay               4589 max 5005 [ OK ]
  | # balanced bwidth with unbalanced delay - reverse direction  4606 max 5005 [ OK ]
  | # unbalanced bwidth                                   2985 max 3245 [ OK ]
  | # unbalanced bwidth - reverse direction               2948 max 3245 [ OK ]
  | # unbalanced bwidth with unbalanced delay             2953 max 3245 [ OK ]
  | # unbalanced bwidth with unbalanced delay - reverse direction  2931 max 3245 [ OK ]
  | # unbalanced bwidth with opposed, unbalanced delay    2991 max 3245 [ OK ]
  | # unbalanced bwidth with opposed, unbalanced delay - reverse direction  2931 max 3245 [ OK ]

[matttbe]

Just to track the frequency, my CI reported an issue related to this one (I got a few I didn't report)

# selftests: net/mptcp: simult_flows.sh
--
  | # balanced bwidth                                     4710 max 5005 [ OK ]
  | # balanced bwidth - reverse direction                 4740 max 5005 [ OK ]
  | # balanced bwidth with unbalanced delay               4718 max 5005 [ OK ]
  | # balanced bwidth with unbalanced delay - reverse direction  4722 max 5005 [ OK ]
  | # unbalanced bwidth                                   3057 max 3245 [ OK ]
  | # unbalanced bwidth - reverse direction               3317 max 3245  [ fail ]
  | # client exit code 0, server 0
  | #
  | # netns ns3-0-M9w5b8 socket stat for 10006:
  | # State Recv-Q Send-Q Local Address:Port Peer Address:PortProcess
  | #
  | # netns ns1-0-M9w5b8 socket stat for 10006:
  | # State     Recv-Q Send-Q    Local Address:Port  Peer Address:Port Process
  | # TIME-WAIT 0      0      10.0.2.1%ns1eth2:49039     10.0.3.3:10006 timer:(timewait,59sec,0)
  | #
  | # TIME-WAIT 0      0              10.0.1.1:58034     10.0.3.3:10006 timer:(timewait,59sec,0)
  | #
  | # -rw------- 1 root root 81920 Mar 20 07:25 /tmp/tmp.9ZcRsEw0wa
  | # -rw------- 1 root root 81920 Mar 20 07:25 /tmp/tmp.g0U6WlP4cK
  | # -rw------- 1 root root 8388608 Mar 20 07:25 /tmp/tmp.Ro5hEpAAi7
  | # -rw------- 1 root root 8388608 Mar 20 07:25 /tmp/tmp.hq2PtYgzIT
  | # unbalanced bwidth with unbalanced delay             3138 max 3245 [ OK ]
  | # unbalanced bwidth with unbalanced delay - reverse direction  3144 max 3245 [ OK ]
  | # unbalanced bwidth with opposed, unbalanced delay    3053 max 3245 [ OK ]
  | # unbalanced bwidth with opposed, unbalanced delay - reverse direction  3094 max 3245 [ OK ]

Should we be more tolerant with this one?

[matttbe]

@pabeni Here are some captures captures.zip

For this output (I stripped tcpdump's output, no packets have been dropped by kernel):

10001: balanced bwidth                                     4845 max 5005 [ OK ]
10002: balanced bwidth - reverse direction                 4841 max 5005 [ OK ]
10003: balanced bwidth with unbalanced delay               4823 max 5005 [ OK ]
10004: balanced bwidth with unbalanced delay - reverse direction  4866 max 5005 [ OK ]
10005: unbalanced bwidth                                   3100 max 3245 [ OK ]
10006: unbalanced bwidth - reverse direction               3412 max 3245  [ fail ]
client exit code 0, server 0
netns ns3-0-YUItiE socket stat for 10006:
State       Recv-Q       Send-Q             Local Address:Port             Peer Address:Port       Process
netns ns1-0-YUItiE socket stat for 10006:
State       Recv-Q   Send-Q         Local Address:Port        Peer Address:Port    Process
TIME-WAIT   0        0           10.0.2.1%ns1eth2:52117           10.0.3.3:10006    timer:(timewait,57sec,0)
TIME-WAIT   0        0                   10.0.1.1:39534           10.0.3.3:10006    timer:(timewait,57sec,0)
-rw------- 1 root root 81920 Aug 31 19:22 /tmp/tmp.fDGja90ohq
-rw------- 1 root root 81920 Aug 31 19:23 /tmp/tmp.moeid9Udot
-rw------- 1 root root 8388608 Aug 31 19:23 /tmp/tmp.bv2vSaWBdK
-rw------- 1 root root 8388608 Aug 31 19:22 /tmp/tmp.zOWCj1JnVT

10007: unbalanced bwidth with unbalanced delay             3332 max 3245  [ fail ]
client exit code 0, server 0
netns ns3-0-YUItiE socket stat for 10007:
State        Recv-Q    Send-Q       Local Address:Port        Peer Address:Port    Process
TIME-WAIT    0         0                 10.0.3.3:10007           10.0.2.1:48961    timer:(timewait,58sec,0)
TIME-WAIT    0         0                 10.0.3.3:10007           10.0.1.1:48018    timer:(timewait,58sec,0)
netns ns1-0-YUItiE socket stat for 10007:
State       Recv-Q       Send-Q             Local Address:Port             Peer Address:Port       Process
-rw------- 1 root root 8388608 Aug 31 19:23 /tmp/tmp.moeid9Udot
-rw------- 1 root root 8388608 Aug 31 19:22 /tmp/tmp.zOWCj1JnVT
-rw------- 1 root root 81920 Aug 31 19:23 /tmp/tmp.bv2vSaWBdK
-rw------- 1 root root 81920 Aug 31 19:22 /tmp/tmp.fDGja90ohq

10008: unbalanced bwidth with unbalanced delay - reverse direction  3197 max 3245 [ OK ]
10009: unbalanced bwidth with opposed, unbalanced delay    3324 max 3245  [ fail ]
client exit code 0, server 0
netns ns3-0-YUItiE socket stat for 10009:
State        Recv-Q    Send-Q       Local Address:Port        Peer Address:Port    Process
TIME-WAIT    0         0                 10.0.3.3:10009           10.0.2.1:47499    timer:(timewait,58sec,0)
TIME-WAIT    0         0                 10.0.3.3:10009           10.0.1.1:48380    timer:(timewait,58sec,0)
netns ns1-0-YUItiE socket stat for 10009:
State       Recv-Q       Send-Q             Local Address:Port             Peer Address:Port       Process
-rw------- 1 root root 8388608 Aug 31 19:24 /tmp/tmp.moeid9Udot
-rw------- 1 root root 8388608 Aug 31 19:22 /tmp/tmp.zOWCj1JnVT
-rw------- 1 root root 81920 Aug 31 19:24 /tmp/tmp.bv2vSaWBdK
-rw------- 1 root root 81920 Aug 31 19:22 /tmp/tmp.fDGja90ohq

10010: unbalanced bwidth with opposed, unbalanced delay - reverse direction  3207 max 3245 [ OK ]

Do you also need capture when "everything is OK"?

EDIT: this was with a "debug" kernel.