selftests: join: signal invalid addresses is unstable

[matttbe]

On my side, using https://github.com/multipath-tcp/mptcp-upstream-virtme-docker and:

cd <kernel source code>
docker run -v "${PWD}:${PWD}:rw" -w "${PWD}" --privileged --rm -it \
  --pull always mptcp/mptcp-upstream-virtme-docker:latest \
  normal

... it is quite easy to reproduce it.

When I isolate this specific test to run only this one, I cannot reproduce it.
But when running mptcp_join.sh -s, it is quite easy:

Capturing traffic for test 6 into mp_join-06-ns1-0-SGfe8N.pcap
tcpdump: data link type LINUX_SLL2
tcpdump: listening on any, link-type LINUX_SLL2 (Linux cooked v2), snapshot length 65535 bytes
64 packets captured
64 packets received by filter
0 packets dropped by kernel
06 signal invalid addresses             syn[ ok ] - synack[ ok ] - ack[ ok ]
                                        add[ ok ] - echo  [ ok ]
[  404.034521] IPv6: ADDRCONF(NETDEV_CHANGE): ns1eth1: link becomes ready
[  404.321236] IPv6: ADDRCONF(NETDEV_CHANGE): ns1eth2: link becomes ready
[  404.585659] IPv6: ADDRCONF(NETDEV_CHANGE): ns1eth3: link becomes ready
[  404.849963] IPv6: ADDRCONF(NETDEV_CHANGE): ns1eth4: link becomes ready
[  405.300746] IPv6: ADDRCONF(NETDEV_CHANGE): ns2eth2: link becomes ready
                                        add[fail] got 2 ADD_ADDR[s] expected 3
 - echo  [fail] got 2 ADD_ADDR echo[s] expected 3

Server ns stats
TcpActiveOpens                  2                  0.0
TcpPassiveOpens                 3                  0.0
TcpAttemptFails                 2                  0.0
TcpInSegs                       26                 0.0
TcpOutSegs                      28                 0.0
TcpExtTCPPureAcks               16                 0.0
TcpExtTCPOrigDataSent           5                  0.0
TcpExtTCPDelivered              5                  0.0
MPTcpExtMPCapableSYNRX          1                  0.0
MPTcpExtMPCapableACKRX          1                  0.0
MPTcpExtMPJoinSynRx             2                  0.0
MPTcpExtMPJoinAckRx             2                  0.0
MPTcpExtAddAddr                 3                  0.0
MPTcpExtEchoAdd                 2                  0.0
Client ns stats
TcpActiveOpens                  3                  0.0
TcpInSegs                       28                 0.0
TcpOutSegs                      26                 0.0
TcpOutRsts                      2                  0.0
TcpExtDelayedACKLocked          1                  0.0
TcpExtTCPPureAcks               18                 0.0
TcpExtTCPOrigDataSent           5                  0.0
TcpExtTCPDelivered              8                  0.0
MPTcpExtMPCapableSYNTX          1                  0.0
MPTcpExtMPCapableSYNACKRX       1                  0.0
MPTcpExtMPJoinSynAckRx          2                  0.0
MPTcpExtAddAddr                 2                  0.0
MPTcpExtEchoAdd                 3                  0.0

Capture:
mp_join-06-ns1-0-SGfe8N.pcap.gz

We can see the last Echo ADD-ADDR (38th packet) is sent after an MPJ

[matttbe]

Here is a capture when the test is OK:
mp_join-06-ns1-0-aIqOIG-OK.pcap.gz

Also here, the last Echo ADD-ADDR is sent after an MPJ (33th packet)

[matttbe]

As pointed by @pabeni on IRC: be careful with the previous output: it looks like the test after signal invalid addresses has no name, hence the corruption with nstat → we can see ADD_ADDR and ECHO in both the client and server.

[matttbe]

In some cases, TCP Pure ACK might not reach the MPTCP stack even if it contains new MPTCP signalling. As mentioned by @pabeni on IRC, we can have that if the relevant socket is a in "post-established" status (half-closing)

tcp_ack() return code is checked differently in tcp_rcv_state_process() and in tcp_rcv_established() slowpath

This selftest seems to proove that:

        06 signal invalid addresses             syn[ ok ] - synack[ ok ] - ack[ ok ]
                                                add[ ok ] - echo  [fail] got 2 ADD_ADDR echo[s] expected 3
         
        Server ns stats
        TcpPassiveOpens                 2                  0.0
        TcpInSegs                       21                 0.0
        TcpOutSegs                      22                 0.0
        TcpExtTCPPureAcks               15                 0.0
        TcpExtTCPOrigDataSent           4                  0.0
        TcpExtTCPDelivered              4                  0.0
        MPTcpExtMPCapableSYNRX          1                  0.0
        MPTcpExtMPCapableACKRX          1                  0.0
        MPTcpExtMPJoinSynRx             1                  0.0
        MPTcpExtMPJoinAckRx             1                  0.0
        MPTcpExtEchoAdd                 2                  0.0
        TcpExt: SyncookiesSent SyncookiesRecv SyncookiesFailed EmbryonicRsts PruneCalled RcvPruned OfoPruned OutOfWindowIcmps LockDroppedIcmps ArpFilter TW TWRecycled TWKilled PAWSActive PAWSEstab DelayedACKs DelayedACKLocked DelayedACKLost ListenOverflows ListenDrops TCPHPHits TCPPureAcks TCPHPAcks TCPRenoRecovery TCPSackRecovery TCPSACKReneging TCPSACKReorder TCPRenoReorder TCPTSReorder TCPFullUndo TCPPartialUndo TCPDSACKUndo TCPLossUndo TCPLostRetransmit TCPRenoFailures TCPSackFailures TCPLossFailures TCPFastRetrans TCPSlowStar
        tRetrans TCPTimeouts TCPLossProbes TCPLossProbeRecovery TCPRenoRecoveryFail TCPSackRecoveryFail TCPRcvCollapsed TCPBacklogCoalesce TCPDSACKOldSent TCPDSACKOfoSent TCPDSACKRecv TCPDSACKOfoRecv TCPAbortOnData TCPAbortOnClose TCPAbortOnMemory TCPAbortOnTimeout TCPAbo
        rtOnLinger TCPAbortFailed TCPMemoryPressures TCPMemoryPressuresChrono TCPSACKDiscard TCPDSACKIgnoredOld TCPDSACKIgnoredNoUndo TCPSpuriousRTOs TCPMD5NotFound TCPMD5Unexpected TCPMD5Failure TCPSackShifted TCPSackMerged TCPSackShiftFallback TCPBacklogDrop PFMemallocD
        rop TCPMinTTLDrop TCPDeferAcceptDrop IPReversePathFilter TCPTimeWaitOverflow TCPReqQFullDoCookies TCPReqQFullDrop TCPRetransFail TCPRcvCoalesce TCPOFOQueue TCPOFODrop TCPOFOMerge TCPChallengeACK TCPSYNChallenge TCPFastOpenActive TCPFastOpenActiveFail TCPFastOpenPa
        ssive TCPFastOpenPassiveFail TCPFastOpenListenOverflow TCPFastOpenCookieReqd TCPFastOpenBlackhole TCPSpuriousRtxHostQueues BusyPollRxPackets TCPAutoCorking TCPFromZeroWindowAdv TCPToZeroWindowAdv TCPWantZeroWindowAdv TCPSynRetrans TCPOrigDataSent TCPHystartTrainDe
        tect TCPHystartTrainCwnd TCPHystartDelayDetect TCPHystartDelayCwnd TCPACKSkippedSynRecv TCPACKSkippedPAWS TCPACKSkippedSeq TCPACKSkippedFinWait2 TCPACKSkippedTimeWait TCPACKSkippedChallenge TCPWinProbe TCPKeepAlive TCPMTUPFail TCPMTUPSuccess TCPDelivered TCPDelive
        redCE TCPAckCompressed TCPZeroWindowDrop TCPRcvQDrop TCPWqueueTooBig TCPFastOpenPassiveAltKey TcpTimeoutRehash TcpDuplicateDataRehash TCPDSACKRecvSegs TCPDSACKIgnoredDubious TCPMigrateReqSuccess TCPMigrateReqFailure
        TcpExt: 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 15 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 4 0 0 0 0 0 0 0 0 0 0 0 0 0 0 4 0 0 0 0 0 0 0 0 0 0 0 0
        IpExt: InNoRoutes InTruncatedPkts InMcastPkts OutMcastPkts InBcastPkts OutBcastPkts InOctets OutOctets InMcastOctets OutMcastOctets InBcastOctets OutBcastOctets InCsumErrors InNoECTPkts InECT1Pkts InECT0Pkts InCEPkts ReasmOverlaps
        IpExt: 0 0 0 0 0 0 2608 2620 0 0 0 0 0 22 0 0 0 0
        MPTcpExt: MPCapableSYNRX MPCapableSYNTX MPCapableSYNACKRX MPCapableACKRX MPCapableFallbackACK MPCapableFallbackSYNACK MPFallbackTokenInit MPTCPRetrans MPJoinNoTokenFound MPJoinSynRx MPJoinSynAckRx MPJoinSynAckHMacFailure MPJoinAckRx MPJoinAckHMacFailure DSSNotMatc
        hing InfiniteMapTx InfiniteMapRx DSSNoMatchTCP DataCsumErr OFOQueueTail OFOQueue OFOMerge NoDSSInWindow DuplicateData AddAddr EchoAdd PortAdd MPJoinPortSynRx MPJoinPortSynAckRx MPJoinPortAckRx MismatchPortSynRx MismatchPortAckRx RmAddr RmSubflow MPPrioTx MPPrioRx
        MPFailTx MPFailRx RcvPruned SubflowStale SubflowRecover
        MPTcpExt: 1 0 0 1 0 0 0 0 0 1 0 0 1 0 0 0 0 0 0 0 0 0 0 0 0 2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
        Client ns stats
        TcpActiveOpens                  3                  0.0
        TcpInSegs                       22                 0.0
        TcpOutSegs                      22                 0.0
        TcpExtDelayedACKLocked          1                  0.0
        TcpExtTCPPureAcks               16                 0.0
        TcpExtTCPOrigDataSent           4                  0.0
        TcpExtTCPDelivered              6                  0.0
        MPTcpExtMPCapableSYNTX          1                  0.0
        MPTcpExtMPCapableSYNACKRX       1                  0.0
        MPTcpExtMPJoinSynAckRx          1                  0.0
        MPTcpExtAddAddr                 3                  0.0
        TcpExt: SyncookiesSent SyncookiesRecv SyncookiesFailed EmbryonicRsts PruneCalled RcvPruned OfoPruned OutOfWindowIcmps LockDroppedIcmps ArpFilter TW TWRecycled TWKilled PAWSActive PAWSEstab DelayedACKs DelayedACKLocked DelayedACKLost ListenOverflows ListenDrops TCP
        HPHits TCPPureAcks TCPHPAcks TCPRenoRecovery TCPSackRecovery TCPSACKReneging TCPSACKReorder TCPRenoReorder TCPTSReorder TCPFullUndo TCPPartialUndo TCPDSACKUndo TCPLossUndo TCPLostRetransmit TCPRenoFailures TCPSackFailures TCPLossFailures TCPFastRetrans TCPSlowStar
        tRetrans TCPTimeouts TCPLossProbes TCPLossProbeRecovery TCPRenoRecoveryFail TCPSackRecoveryFail TCPRcvCollapsed TCPBacklogCoalesce TCPDSACKOldSent TCPDSACKOfoSent TCPDSACKRecv TCPDSACKOfoRecv TCPAbortOnData TCPAbortOnClose TCPAbortOnMemory TCPAbortOnTimeout TCPAbo
        rtOnLinger TCPAbortFailed TCPMemoryPressures TCPMemoryPressuresChrono TCPSACKDiscard TCPDSACKIgnoredOld TCPDSACKIgnoredNoUndo TCPSpuriousRTOs TCPMD5NotFound TCPMD5Unexpected TCPMD5Failure TCPSackShifted TCPSackMerged TCPSackShiftFallback TCPBacklogDrop PFMemallocD
        rop TCPMinTTLDrop TCPDeferAcceptDrop IPReversePathFilter TCPTimeWaitOverflow TCPReqQFullDoCookies TCPReqQFullDrop TCPRetransFail TCPRcvCoalesce TCPOFOQueue TCPOFODrop TCPOFOMerge TCPChallengeACK TCPSYNChallenge TCPFastOpenActive TCPFastOpenActiveFail TCPFastOpenPassive TCPFastOpenPassiveFail TCPFastOpenListenOverflow TCPFastOpenCookieReqd TCPFastOpenBlackhole TCPSpuriousRtxHostQueues BusyPollRxPackets TCPAutoCorking TCPFromZeroWindowAdv TCPToZeroWindowAdv TCPWantZeroWindowAdv TCPSynRetrans TCPOrigDataSent TCPHystartTrainDe
        tect TCPHystartTrainCwnd TCPHystartDelayDetect TCPHystartDelayCwnd TCPACKSkippedSynRecv TCPACKSkippedPAWS TCPACKSkippedSeq TCPACKSkippedFinWait2 TCPACKSkippedTimeWait TCPACKSkippedChallenge TCPWinProbe TCPKeepAlive TCPMTUPFail TCPMTUPSuccess TCPDelivered TCPDelive
        redCE TCPAckCompressed TCPZeroWindowDrop TCPRcvQDrop TCPWqueueTooBig TCPFastOpenPassiveAltKey TcpTimeoutRehash TcpDuplicateDataRehash TCPDSACKRecvSegs TCPDSACKIgnoredDubious TCPMigrateReqSuccess TCPMigrateReqFailure
        TcpExt: 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1 0 0 0 0 16 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 4 0 0 0 0 0 0 0 0 0 0 0 0 0 0 6 0 0 0 0 0 0 0 0 0 0 0 0
        IpExt: InNoRoutes InTruncatedPkts InMcastPkts OutMcastPkts InBcastPkts OutBcastPkts InOctets OutOctets InMcastOctets OutMcastOctets InBcastOctets OutBcastOctets InCsumErrors InNoECTPkts InECT1Pkts InECT0Pkts InCEPkts ReasmOverlaps
        IpExt: 0 0 0 0 0 0 2620 2608 0 0 0 0 0 22 0 0 0 0
        MPTcpExt: MPCapableSYNRX MPCapableSYNTX MPCapableSYNACKRX MPCapableACKRX MPCapableFallbackACK MPCapableFallbackSYNACK MPFallbackTokenInit MPTCPRetrans MPJoinNoTokenFound MPJoinSynRx MPJoinSynAckRx MPJoinSynAckHMacFailure MPJoinAckRx MPJoinAckHMacFailure DSSNotMatching InfiniteMapTx InfiniteMapRx DSSNoMatchTCP DataCsumErr OFOQueueTail OFOQueue OFOMerge NoDSSInWindow DuplicateData AddAddr EchoAdd PortAdd MPJoinPortSynRx MPJoinPortSynAckRx MPJoinPortAckRx MismatchPortSynRx MismatchPortAckRx RmAddr RmSubflow MPPrioTx MPPrioRx
        MPFailTx MPFailRx RcvPruned SubflowStale SubflowRecover
        MPTcpExt: 0 1 1 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0 3 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0

Here, a "return" was added after signal invalid addresses test.

Please also note that this test was running with echo "file net/mptcp/options.c +fmp" > /sys/kernel/debug/dynamic_debug/control which didn't print anything for the 3rd ECHO ADD_ADDR.

[matttbe]

@pabeni here is a trace with the issue when using the "slow" mode thanks to your patch:

mp_join-07-ns1-0-moG7wT.pcap.gz

The patch:

diff --git a/tools/testing/selftests/net/mptcp/mptcp_join.sh b/tools/testing/selftests/net/mptcp/mptcp_join.sh
index 76c45c845d3b..80694e2b31ab 100755
--- a/tools/testing/selftests/net/mptcp/mptcp_join.sh
+++ b/tools/testing/selftests/net/mptcp/mptcp_join.sh
@@ -1325,7 +1325,7 @@ signal_address_tests()
        pm_nl_add_endpoint $ns1 10.0.3.1 flags signal
        pm_nl_add_endpoint $ns1 10.0.14.1 flags signal
        pm_nl_set_limits $ns2 3 3
-       run_tests $ns1 $ns2 10.0.1.1
+       run_tests $ns1 $ns2 10.0.1.1 0 0 0 slow
        chk_join_nr "signal invalid addresses" 1 1 1
        chk_add_nr 3 3
 
@@ -1341,7 +1341,7 @@ signal_address_tests()
        pm_nl_add_endpoint $ns2 10.0.2.2 flags signal
        pm_nl_add_endpoint $ns2 10.0.3.2 flags signal
        pm_nl_add_endpoint $ns2 10.0.4.2 flags signal
-       run_tests $ns1 $ns2 10.0.1.1
+       run_tests $ns1 $ns2 10.0.1.1 0 0 0 slow
 
        # the server will not signal the address terminating
        # the MPC subflow