Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Intermittent copyfd_io_poll: poll timed out in mptcp_join.sh #165

Closed
mjmartineau opened this issue Feb 18, 2021 · 7 comments
Closed

Intermittent copyfd_io_poll: poll timed out in mptcp_join.sh #165

mjmartineau opened this issue Feb 18, 2021 · 7 comments
Assignees
Labels
Projects

Comments

@mjmartineau
Copy link
Member

kbuild is showing an intermittent error in mptcp_join.sh, with the 'multiple subflows and signal' test:

user  :notice: [  147.672316] # 10 multiple subflows and signal         syn[ ok ] - synack[ ok ] - ack[ ok ]

user  :notice: [  147.701125] #                                         add[ ok ] - echo  [ ok ]

kern  :info  : [  147.850623] IPv6: ADDRCONF(NETDEV_CHANGE): ns1eth1: link becomes ready
kern  :info  : [  147.896473] IPv6: ADDRCONF(NETDEV_CHANGE): ns1eth2: link becomes ready
kern  :info  : [  147.941835] IPv6: ADDRCONF(NETDEV_CHANGE): ns1eth3: link becomes ready
kern  :info  : [  147.987184] IPv6: ADDRCONF(NETDEV_CHANGE): ns1eth4: link becomes ready
kern  :info  : [  148.862942] IPv6: ADDRCONF(NETDEV_CHANGE): ns2eth1: link becomes ready
user  :notice: [  150.065427] # Created /tmp/tmp.3Hzulf2hlr (size 66944 KB) containing data sent by client

user  :notice: [  185.195558] # copyfd_io_poll: poll timed out (events: POLLIN 1, POLLOUT 0)

user  :notice: [  279.128256] # copyfd_io_poll: poll timed out (events: POLLIN 0, POLLOUT 4)

user  :notice: [  279.141171] #  client exit code 2, server 2

user  :notice: [  279.148188] # 

user  :notice: [  279.153432] # netns ns1-0-i7L2UK socket stat for 10010:

user  :notice: [  279.172532] # State      Recv-Q Send-Q Local Address:Port  Peer Address:Port Process

user  :notice: [  279.184828] # FIN-WAIT-1 0      1           10.0.1.1:10010     10.0.3.2:38141 timer:(persist,22sec,7)

kern  :info  : [  279.435236] IPv6: ADDRCONF(NETDEV_CHANGE): ns1eth1: link becomes ready
kern  :info  : [  279.480590] IPv6: ADDRCONF(NETDEV_CHANGE): ns1eth2: link becomes ready
kern  :info  : [  279.526631] IPv6: ADDRCONF(NETDEV_CHANGE): ns1eth3: link becomes ready
kern  :info  : [  279.572450] IPv6: ADDRCONF(NETDEV_CHANGE): ns1eth4: link becomes ready
kern  :info  : [  280.446997] IPv6: ADDRCONF(NETDEV_CHANGE): ns2eth1: link becomes ready
user  :notice: [  281.171782] # 	 ts sack cubic wscale:7,7 rto:201 backoff:7 rtt:1/0.5 ato:40 mss:1448 pmtu:1500 rcvmss:1420 advmss:1448 cwnd:10 bytes_received:3160825 segs_out:469 segs_in:2365 data_segs_in:2362 send 115840000bps lastsnd:128088 lastrcv:124789 lastack:124789 pacing_rate 231680000bps delivered:1 busy:30081ms rcv_rtt:253.124 rcv_space:14600 rcv_ssthresh:3144378 notsent:1 minrtt:1 tcp-ulp-mptcp flags:Jecv token:0000(id:1)/4a668eb6(id:0) seq:4cee5798c6898ca3 sfseq:301f3e ssnoff:7ae85813 maplen:2000

user  :notice: [  281.220296] # 

user  :notice: [  281.225694] # netns ns2-0-i7L2UK socket stat for 10010:

user  :notice: [  281.235129] # State Recv-Q Send-Q Local Address:Port  Peer Address:Port Process

user  :notice: [  281.247040] # ESTAB 0      253952      10.0.3.2:38141     10.0.1.1:10010 timer:(on,1min28sec,9)

user  :notice: [  281.934542] # 	 ts sack cubic wscale:7,7 rto:105984 backoff:9 rtt:6.646/12.282 mss:1448 pmtu:1500 rcvmss:536 advmss:1448 cwnd:1 ssthresh:7 bytes_sent:3174953 bytes_retrans:14128 bytes_acked:3145534 segs_out:2365 segs_in:449 data_segs_out:2362 send 1743003bps lastsnd:17811 lastrcv:128105 lastack:126839 pacing_rate 52287144bps delivery_rate 286272bps delivered:2343 busy:125336ms unacked:11 retrans:1/10 lost:11 dsack_dups:1 rcv_space:14480 rcv_ssthresh:64088 notsent:238660 minrtt:0.015 tcp-ulp-mptcp flags:Jjec token:4a668eb6(id:0)/2e321b57(id:1) seq:0 sfseq:0 ssnoff:fa8b984f maplen:0

<...>

user  :notice: [  492.010146] not ok 3 selftests: net/mptcp: mptcp_join.sh # exit=1

This has "copyfd_io_poll: poll timed out" like #147, but the sockets are in different states and this is with mptcp_join.sh rather than mptcp_connect.sh. I haven't reproduced this locally to see why both sockets have data in their send-qs.

@pabeni
Copy link

pabeni commented Feb 18, 2021

is this a dbg build? do you know the relevant kernel config?

@mjmartineau
Copy link
Member Author

The kernel config isn't copied to the build artifacts - I'll ask the kbuild team to start doing that, and see if they can provide a copy some other way. I will probably get a response before the end of (my) day.

What I can see now is that they copy a 'kconfig/x86_64-rhel-8.3' file to .config, and then run 'make olddefconfig' on our export branch. Not sure if that is the stock RHEL config or a modified one.

@mjmartineau
Copy link
Member Author

Here's the .config:

kbuild-config-5.11.0-rc7-02074-gb118cc0dfad9.txt

@pabeni
Copy link

pabeni commented Feb 19, 2021

note to self: "desktop" config:

no KASAN, no KMEMLEAK,
PREEMPT=y
PREEMPT_RCU=y

@matttbe matttbe added the bug label Feb 20, 2021
@matttbe matttbe added this to Needs triage in MPTCP Bugs via automation Feb 20, 2021
@matttbe
Copy link
Member

matttbe commented Feb 23, 2021

My CI just reported the same issue with a debug kernel:

(...)
00:19:59.213 # 10 multiple subflows and signal         syn[ ok ] - synack[ ok ] - ack[ ok ]
00:20:01.891 #                                         add[ ok ] - echo  [ ok ]
00:20:05.485 # Created /tmp/tmp.3SoUqnYysU (size 75520 KB) containing data sent by client
00:20:09.037 # copyfd_io_poll: poll timed out (events: POLLIN 1, POLLOUT 0)
00:20:47.915 # copyfd_io_poll: poll timed out (events: POLLIN 0, POLLOUT 4)
00:21:34.020 #  client exit code 2, server 2
00:21:34.028 # 
00:21:34.029 # netns ns1-0-FaoLQ7 socket stat for 10010:
00:21:34.030 # State Recv-Q Send-Q Local Address:Port  Peer Address:Port Process                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                             
00:21:35.014 # ESTAB 0      0           10.0.1.1:10010     10.0.3.2:55183
00:21:35.015 # 	 ts sack cubic wscale:7,7 rto:201 rtt:1/0.5 ato:80 mss:1448 pmtu:1500 rcvmss:1420 advmss:1448 cwnd:10 bytes_received:44433576 segs_out:5922 segs_in:33001 data_segs_in:32998 send 115840000bps lastsnd:84835 lastrcv:80153 lastack:80153 pacing_rate 231680000bps delivered:1 rcv_rtt:1.519 rcv_space:14600 rcv_ssthresh:3144447 minrtt:1 tcp-ulp-mptcp flags:Jec token:0000(id:1)/44b8b0d6(id:0) seq:8fcef83387d9c588 sfseq:2a5e0a9 ssnoff:aab8e9a maplen:2000                                                                                   
00:21:35.023 # ESTAB 0      0           10.0.1.1:10010     10.0.1.2:49296
00:21:35.024 # 	 ts sack cubic wscale:7,7 rto:201 rtt:0.291/0.125 ato:80 mss:1448 pmtu:1500 rcvmss:1420 advmss:1448 cwnd:10 bytes_sent:1052 bytes_acked:1052 bytes_received:11846096 segs_out:1792 segs_in:8812 data_segs_out:2 data_segs_in:8806 send 398075601bps lastsnd:84637 lastrcv:80147 lastack:80147 pacing_rate 795809360bps delivery_rate 51256632bps delivered:3 rcv_rtt:1.879 rcv_space:14600 rcv_ssthresh:3144441 minrtt:0.226 tcp-ulp-mptcp flags:Mec token:0000(id:0)/44b8b0d6(id:0) seq:8fcef83387dac588 sfseq:b4a1d1 ssnoff:6658c5ef maplen:2000
00:21:35.030 # ESTAB 0      0           10.0.1.1:10010     10.0.4.2:39159
00:21:35.031 # 	 ts sack cubic wscale:7,7 rto:201 rtt:1/0.5 ato:80 mss:1448 pmtu:1500 rcvmss:1420 advmss:1448 cwnd:10 bytes_received:12468352 segs_out:1839 segs_in:9297 data_segs_in:9294 send 115840000bps lastsnd:84834 lastrcv:80145 lastack:80145 pacing_rate 231680000bps delivered:1 rcv_rtt:2.169 rcv_space:14600 rcv_ssthresh:3144446 minrtt:1 tcp-ulp-mptcp flags:Jec token:0000(id:2)/44b8b0d6(id:0) seq:8fcef83387db2588 sfseq:be4065 ssnoff:13d9fb58 maplen:1c                                                                                       
00:21:35.039 # ESTAB 188188 0           10.0.2.1:10010     10.0.2.2:55301
00:21:35.040 # 	 ts sack cubic wscale:7,7 rto:201 rtt:1/0.5 ato:40 mss:1448 pmtu:1500 rcvmss:1372 advmss:1448 cwnd:10 bytes_received:33331140 segs_out:6854 segs_in:24632 data_segs_in:24628 send 115840000bps lastsnd:84836 lastrcv:974 lastack:974 pacing_rate 231680000bps delivered:1 rcv_rtt:7.454 rcv_space:14600 rcv_ssthresh:407440 minrtt:1 tcp-ulp-mptcp flags:Jecv token:0000(id:0)/44b8b0d6(id:1) seq:8fcef83387e345a4 sfseq:1f9a805 ssnoff:cb4ec179 maplen:1ac0                                                                                      
00:21:35.044 # 
00:21:35.044 # netns ns2-0-FaoLQ7 socket stat for 10010:
00:21:35.045 # State Recv-Q Send-Q Local Address:Port  Peer Address:Port Process                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                            
00:21:35.143 # ESTAB 0      65536       10.0.3.2:55183     10.0.1.1:10010 timer:(on,1.909ms,19)
00:21:35.143 # 	 ts sack cubic wscale:7,7 rto:3296 backoff:4 rtt:5.813/10.526 mss:1448 pmtu:1500 rcvmss:536 advmss:1448 cwnd:1 ssthresh:7 bytes_sent:44468748 bytes_retrans:21300 bytes_acked:44433577 segs_out:33027 segs_in:5923 data_segs_out:33023 send 1992775bps lastsnd:1387 lastrcv:84966 lastack:80242 pacing_rate 95653184bps delivery_rate 280824bps delivered:32999 busy:50700ms unacked:10 retrans:1/15 lost:10 rcv_space:14480 rcv_ssthresh:64088 notsent:51664 minrtt:0.098 tcp-ulp-mptcp flags:Jjec token:44b8b0d6(id:0)/7a51d1ae(id:1) seq:0 sfseq:0 ssnoff:da4416f6 maplen:0                                                                             
00:21:35.156 # ESTAB 0      65536       10.0.1.2:49296     10.0.1.1:10010 timer:(on,1.925ms,29)
00:21:35.158 # 	 ts sack cubic wscale:7,7 rto:3312 backoff:4 rtt:6.879/11.987 ato:40 mss:1448 pmtu:1500 rcvmss:952 advmss:1448 cwnd:1 ssthresh:7 bytes_sent:11894048 bytes_retrans:35500 bytes_acked:11846097 bytes_received:1052 segs_out:8847 segs_in:1793 data_segs_out:8840 data_segs_in:2 send 1683966bps lastsnd:1387 lastrcv:84768 lastack:80237 pacing_rate 40413704bps delivery_rate 286088bps delivered:8807 busy:81819ms sndbuf_limited:83ms(0.1%) unacked:9 retrans:1/25 lost:9 rcv_space:14480 rcv_ssthresh:64088 notsent:53084 minrtt:0.098 tcp-ulp-mptcp flags:Mmec token:0000(id:0)/7a51d1ae(id:0) seq:f35ef88cc2a67369 sfseq:65 ssnoff:8a77d75c maplen:3b8
00:21:35.169 # ESTAB 0      0           10.0.2.2:55301     10.0.2.1:10010
00:21:35.170 # 	 ts sack cubic wscale:7,7 rto:201 rtt:0.183/0.074 mss:1448 pmtu:1500 rcvmss:536 advmss:1448 cwnd:4 ssthresh:4 bytes_sent:33355768 bytes_retrans:24628 bytes_acked:33331141 segs_out:24632 segs_in:6855 data_segs_out:24628 send 253202186bps lastsnd:1105 lastrcv:84967 lastack:1105 pacing_rate 302602448bps delivery_rate 32267408bps delivered:24611 busy:8182ms rwnd_limited:1ms(0.0%) sndbuf_limited:4529ms(55.4%) retrans:0/19 dsack_dups:1 rcv_space:14480 rcv_ssthresh:64088 minrtt:0.082 tcp-ulp-mptcp flags:Jjec token:44b8b0d6(id:1)/7a51d1ae(id:0) seq:0 sfseq:0 ssnoff:1963c2ee maplen:0                                                                            
00:21:35.179 # ESTAB 0      49152       10.0.4.2:39159     10.0.1.1:10010 timer:(on,1.973ms,29)
00:21:37.497 # 	 ts sack cubic wscale:7,7 rto:3360 backoff:4 rtt:9.44/15.255 mss:1448 pmtu:1500 rcvmss:536 advmss:1448 cwnd:1 ssthresh:7 bytes_sent:12516304 bytes_retrans:35500 bytes_acked:12468353 segs_out:9332 segs_in:1840 data_segs_out:9328 send 1227119bps lastsnd:1387 lastrcv:84965 lastack:80235 pacing_rate 36810632bps delivery_rate 286200bps delivered:9295 busy:81451ms sndbuf_limited:41ms(0.1%) unacked:9 retrans:1/25 lost:9 rcv_space:14480 rcv_ssthresh:64088 notsent:36700 minrtt:0.098 tcp-ulp-mptcp flags:Jjec token:44b8b0d6(id:0)/7a51d1ae(id:2) seq:0 sfseq:0 ssnoff:34a5cf7b maplen:0                                                         
00:21:37.497 # 11 multiple flows, signal, link failure syn[ ok ] - synack[ ok ] - ack[ ok ]
00:21:37.497 #                                         add[ ok ] - echo  [ ok ]
(...)
00:28:15.264 not ok 3 selftests: net/mptcp: mptcp_join.sh # exit=1

Debug kernel means having these config enabled:

KASAN
KASAN_OUTLINE
PROVE_LOCKING
DEBUG_LOCKDEP
PREEMPT
DEBUG_PREEMPT
DEBUG_SLAVE
DEBUG_PAGEALLOC
DEBUG_MUTEXES
DEBUG_SPINLOCK
DEBUG_ATOMIC_SLEEP
PROVE_RCU
DEBUG_OBJECTS_RCU_HEAD

@matttbe
Copy link
Member

matttbe commented Feb 23, 2021

Here is the same error but now with more details (nstat + more options with ss) asked by @pabeni :

# 10 multiple subflows and signal         syn[ ok ] - synack[ ok ] - ack[ ok ]
#                                         add[ ok ] - echo  [ ok ]
[  142.381254] IPv6: ADDRCONF(NETDEV_CHANGE): ns1eth1: link becomes ready
[  142.691011] IPv6: ADDRCONF(NETDEV_CHANGE): ns2eth1: link becomes ready
[  143.350017] IPv6: ADDRCONF(NETDEV_CHANGE): ns1eth2: link becomes ready
[  143.698972] IPv6: ADDRCONF(NETDEV_CHANGE): ns2eth2: link becomes ready
[  144.299593] IPv6: ADDRCONF(NETDEV_CHANGE): ns1eth3: link becomes ready
[  144.706969] IPv6: ADDRCONF(NETDEV_CHANGE): ns2eth3: link becomes ready
[  145.270555] IPv6: ADDRCONF(NETDEV_CHANGE): ns1eth4: link becomes ready
[  145.714846] IPv6: ADDRCONF(NETDEV_CHANGE): ns2eth4: link becomes ready
# Created /tmp/tmp.FDrEfpqUaZ (size 91904 KB) containing data sent by client
#  client exit code 124, server 124
#
# netns ns1-0-VdLfY5 socket stat for 10010:
# Netid State      Recv-Q Send-Q Local Address:Port  Peer Address:Port Process
# tcp   FIN-WAIT-1 0      1           10.0.1.1:10010     10.0.1.2:50668 timer:(persist,212ms,2) ino:0 sk:1 ---
#        ts sack cubic wscale:7,7 rto:201 backoff:2 rtt:0.716/0.374 ato:162 mss:1448 pmtu:1500 rcvmss:1420 advmss:1448 cwnd:10 bytes_sent:1052 bytes_acked:1052 bytes_received:46538829 segs_out:6198 segs_in:34567 data_segs_out:2 data_segs_in:34561 send 161787709bps
 lastsnd:61862 lastrcv:53272 lastack:53272 pacing_rate 323349616bps delivery_rate 32539320bps delivered:3 busy:1209ms rcv_rtt:1.013 rcv_space:14600 rcv_ssthresh:3144446 notsent:1 minrtt:0.356 tcp-ulp-mptcp flags:Mec token:0000(id:0)/4a283c64(id:0) seq:3408eac6ad21
945b sfseq:2c62032 ssnoff:238b6ba6 maplen:1c
# tcp   FIN-WAIT-1 0      1           10.0.1.1:10010     10.0.3.2:52847 timer:(on,419ms,2) ino:0 sk:2 ---
#        ts sack cubic wscale:7,7 rto:804 backoff:2 rtt:1/0.5 ato:80 mss:1448 pmtu:1500 rcvmss:1420 advmss:1448 cwnd:1 ssthresh:7 bytes_received:15726401 segs_out:2351 segs_in:11692 data_segs_in:11689 send 11584000bps lastsnd:62059 lastrcv:53324 lastack:53324 paci
ng_rate 231680000bps delivered:1 busy:1208ms unacked:1 retrans:1/3 lost:1 rcv_rtt:1.572 rcv_space:14600 rcv_ssthresh:3144442 minrtt:1 tcp-ulp-mptcp flags:Jec token:0000(id:1)/4a283c64(id:0) seq:3408eac6ad20145b sfseq:efd742 ssnoff:5fe85e15 maplen:2000
# tcp   TIME-WAIT  0      0           10.0.2.1:10010     10.0.2.2:39643 timer:(timewait,58sec,0) ino:0 sk:3
#
# tcp   FIN-WAIT-1 0      1           10.0.1.1:10010     10.0.4.2:55159 timer:(on,419ms,2) ino:0 sk:4 ---
#        ts sack cubic wscale:7,7 rto:804 backoff:2 rtt:1/0.5 ato:80 mss:1448 pmtu:1500 rcvmss:1420 advmss:1448 cwnd:1 ssthresh:7 bytes_received:17824904 segs_out:2659 segs_in:13268 data_segs_in:13265 send 11584000bps lastsnd:62057 lastrcv:53317 lastack:53317 paci
ng_rate 231680000bps delivered:1 busy:1208ms unacked:1 retrans:1/3 lost:1 rcv_rtt:1.45 rcv_space:14600 rcv_ssthresh:3144448 minrtt:1 tcp-ulp-mptcp flags:Jec token:0000(id:2)/4a283c64(id:0) seq:3408eac6ad21145b sfseq:10fdc89 ssnoff:8f517d09 maplen:2000
# TcpPassiveOpens                 4                  0.0
# TcpInSegs                       21512              0.0
# TcpOutSegs                      13753              0.0
# TcpExtDelayedACKs               458                0.0
# TcpExtDelayedACKLost            1                  0.0
# TcpExtTCPPureAcks               12                 0.0
# TcpExtTCPDSACKOldSent           1                  0.0
# TcpExtTCPRcvCoalesce            5                  0.0
# TcpExtTCPFromZeroWindowAdv      2                  0.0
# TcpExtTCPToZeroWindowAdv        2                  0.0
# TcpExtTCPWantZeroWindowAdv      9                  0.0
# TcpExtTCPOrigDataSent           5                  0.0
# TcpExtTCPDelivered              3                  0.0
# MPTcpExtMPCapableSYNRX          1                  0.0
# MPTcpExtMPCapableACKRX          1                  0.0
# MPTcpExtMPJoinSynRx             3                  0.0
# MPTcpExtMPJoinAckRx             3                  0.0
# MPTcpExtOFOQueueTail            1346               0.0
# MPTcpExtOFOQueue                1361               0.0
# MPTcpExtOFOMerge                1213               0.0
# MPTcpExtDuplicateData           7                  0.0
# MPTcpExtEchoAdd                 1                  0.0
#
# netns ns2-0-VdLfY5 socket stat for 10010:
# Netid State      Recv-Q Send-Q Local Address:Port  Peer Address:Port Process
# tcp   LAST-ACK   1      65537       10.0.4.2:55159     10.0.1.1:10010 timer:(on,620ms,11) ino:0 sk:5 ---
#        ts sack cubic wscale:7,7 rto:3328 backoff:4 rtt:7.455/12.398 ato:40 mss:1448 pmtu:1500 rcvmss:536 advmss:1448 cwnd:1 ssthresh:7 bytes_sent:17842325 bytes_retrans:9940 bytes_acked:17824905 bytes_received:1 segs_out:13287 segs_in:2661 data_segs_out:13278 se
nd 1553856bps lastsnd:2708 lastrcv:62773 lastack:274 pacing_rate 18644088bps delivery_rate 286184bps delivered:13266 busy:27853ms unacked:6 retrans:1/7 lost:6 rcv_space:14480 rcv_ssthresh:64088 notsent:58056 minrtt:0.161 tcp-ulp-mptcp flags:Jjec token:4a283c64(id:
0)/b5e343ce(id:2) seq:0 sfseq:0 ssnoff:be363f63 maplen:0
# tcp   LAST-ACK   1      65537       10.0.3.2:52847     10.0.1.1:10010 timer:(on,636ms,11) ino:0 sk:6 ---
#        ts sack cubic wscale:7,7 rto:3344 backoff:4 rtt:8.829/13.788 ato:40 mss:1448 pmtu:1500 rcvmss:536 advmss:1448 cwnd:1 ssthresh:7 bytes_sent:15748793 bytes_retrans:9940 bytes_acked:15726402 bytes_received:1 segs_out:11714 segs_in:2353 data_segs_out:11705 se
nd 1312040bps lastsnd:2708 lastrcv:62774 lastack:274 pacing_rate 23614704bps delivery_rate 284784bps delivered:11690 busy:28492ms sndbuf_limited:41ms(0.1%) unacked:9 retrans:1/7 lost:9 rcv_space:14480 rcv_ssthresh:64088 notsent:53085 minrtt:0.156 tcp-ulp-mptcp fla
gs:Jjec token:4a283c64(id:0)/b5e343ce(id:1) seq:0 sfseq:0 ssnoff:3b4cbec7 maplen:0
# tcp   FIN-WAIT-1 0      40961       10.0.1.2:50668     10.0.1.1:10010 timer:(on,700ms,20) ino:0 sk:7 ---
#        ts sack cubic wscale:7,7 rto:3408 backoff:4 rtt:12.698/18.747 ato:40 mss:1448 pmtu:1500 rcvmss:952 advmss:1448 cwnd:1 ssthresh:7 bytes_sent:46577485 bytes_retrans:23364 bytes_acked:46538830 bytes_received:1052 segs_out:34595 segs_in:6195 data_segs_out:345
88 data_segs_in:2 send 912270bps lastsnd:2708 lastrcv:62578 lastack:53947 pacing_rate 178797808bps delivery_rate 280352bps delivered:34562 busy:59892ms rwnd_limited:2ms(0.0%) sndbuf_limited:2ms(0.0%) unacked:11 retrans:1/17 lost:11 dsack_dups:1 rcv_rtt:200 rcv_spa
ce:14480 rcv_ssthresh:64088 notsent:25669 minrtt:0.157 tcp-ulp-mptcp flags:Mmec token:0000(id:0)/b5e343ce(id:0) seq:8fd1779d0d108ddf sfseq:65 ssnoff:62b89192 maplen:3b8
# TcpActiveOpens                  4                  0.0
# TcpInSegs                       13753              0.0
# TcpOutSegs                      71107              0.0
# TcpRetransSegs                  31                 0.0
# TcpExtDelayedACKs               2                  0.0
# TcpExtDelayedACKLocked          2                  0.0
# TcpExtDelayedACKLost            2                  0.0
# TcpExtTCPPureAcks               13713              0.0
# TcpExtTCPLostRetransmit         27                 0.0
# TcpExtTCPTimeouts               42                 0.0
# TcpExtTCPLossProbes             3                  0.0
# TcpExtTCPBacklogCoalesce        29                 0.0
# TcpExtTCPDSACKOldSent           2                  0.0
# TcpExtTCPDSACKRecv              1                  0.0
# TcpExtTCPDSACKIgnoredNoUndo     1                  0.0
# TcpExtTCPSpuriousRtxHostQueues  12                 0.0
# TcpExtTCPAutoCorking            3                  0.0
# TcpExtTCPOrigDataSent           71084              0.0
# TcpExtTCPHystartTrainDetect     2                  0.0
# TcpExtTCPHystartTrainCwnd       72                 0.0
# TcpExtTCPDelivered              71063              0.0
# TcpExtTcpTimeoutRehash          42                 0.0
# TcpExtTCPDSACKRecvSegs          1                  0.0
# MPTcpExtMPTCPRetrans            33                 0.0
# MPTcpExtMPJoinSynAckRx          3                  0.0
# MPTcpExtAddAddr                 1                  0.0
# 11 multiple flows, signal, link failure syn[ ok ] - synack[ ok ] - ack[ ok ]
#                                         add[ ok ] - echo  [ ok ]

@pabeni
Copy link

pabeni commented Feb 23, 2021

kbuild is showing an intermittent error in mptcp_join.sh, with the 'multiple subflows and signal' test:

The test output is quite misleading: the failing test is actually the next one, that is:

11 multiple flows, signal, link failure

note: you can double check looking at the amount of transferred data, which is 1K in both direction except fot link failure tests, which will use much more data on the client side.

Looks like we are not doing mptcp level retransmissions for some reasons...

@pabeni pabeni self-assigned this Feb 24, 2021
matttbe pushed a commit that referenced this issue Feb 25, 2021
__mptcp_clean_una() can free write memory and should wake-up
user-space processes when needed.

When such function is invoked by the MPTCP receive path, the wakeup
is not needed, as the TCP stack will later trigger subflow_write_space
which will do the wakeup as needed.

Other __mptcp_clean_una() call sites need an additional wakeup check
Let's bundle the relevant code in a new helper and use it.

Closes: #165
Fixes: 6e628cd ("mptcp: use mptcp release_cb for delayed tasks")
Fixes: 64b9cea ("mptcp: fix spurious retransmissions")
Tested-by: Matthieu Baerts <matthieu.baerts@tessares.net>
Reviewed-by: Mat Martineau <mathew.j.martineau@linux.intel.com>
Signed-off-by: Paolo Abeni <pabeni@redhat.com>
MPTCP Bugs automation moved this from Needs triage to Closed Feb 25, 2021
jenkins-tessares pushed a commit that referenced this issue Feb 25, 2021
__mptcp_clean_una() can free write memory and should wake-up
user-space processes when needed.

When such function is invoked by the MPTCP receive path, the wakeup
is not needed, as the TCP stack will later trigger subflow_write_space
which will do the wakeup as needed.

Other __mptcp_clean_una() call sites need an additional wakeup check
Let's bundle the relevant code in a new helper and use it.

Closes: #165
Fixes: 6e628cd ("mptcp: use mptcp release_cb for delayed tasks")
Fixes: 64b9cea ("mptcp: fix spurious retransmissions")
Tested-by: Matthieu Baerts <matthieu.baerts@tessares.net>
Reviewed-by: Mat Martineau <mathew.j.martineau@linux.intel.com>
Signed-off-by: Paolo Abeni <pabeni@redhat.com>
jenkins-tessares pushed a commit that referenced this issue Feb 25, 2021
__mptcp_clean_una() can free write memory and should wake-up
user-space processes when needed.

When such function is invoked by the MPTCP receive path, the wakeup
is not needed, as the TCP stack will later trigger subflow_write_space
which will do the wakeup as needed.

Other __mptcp_clean_una() call sites need an additional wakeup check
Let's bundle the relevant code in a new helper and use it.

Closes: #165
Fixes: 6e628cd ("mptcp: use mptcp release_cb for delayed tasks")
Fixes: 64b9cea ("mptcp: fix spurious retransmissions")
Tested-by: Matthieu Baerts <matthieu.baerts@tessares.net>
Reviewed-by: Mat Martineau <mathew.j.martineau@linux.intel.com>
Signed-off-by: Paolo Abeni <pabeni@redhat.com>
jenkins-tessares pushed a commit that referenced this issue Feb 26, 2021
__mptcp_clean_una() can free write memory and should wake-up
user-space processes when needed.

When such function is invoked by the MPTCP receive path, the wakeup
is not needed, as the TCP stack will later trigger subflow_write_space
which will do the wakeup as needed.

Other __mptcp_clean_una() call sites need an additional wakeup check
Let's bundle the relevant code in a new helper and use it.

Closes: #165
Fixes: 6e628cd ("mptcp: use mptcp release_cb for delayed tasks")
Fixes: 64b9cea ("mptcp: fix spurious retransmissions")
Tested-by: Matthieu Baerts <matthieu.baerts@tessares.net>
Reviewed-by: Mat Martineau <mathew.j.martineau@linux.intel.com>
Signed-off-by: Paolo Abeni <pabeni@redhat.com>
github-actions bot pushed a commit to matttbe/mptcp_net-next that referenced this issue Mar 2, 2021
__mptcp_clean_una() can free write memory and should wake-up
user-space processes when needed.

When such function is invoked by the MPTCP receive path, the wakeup
is not needed, as the TCP stack will later trigger subflow_write_space
which will do the wakeup as needed.

Other __mptcp_clean_una() call sites need an additional wakeup check
Let's bundle the relevant code in a new helper and use it.

Closes: multipath-tcp#165
Fixes: 6e628cd ("mptcp: use mptcp release_cb for delayed tasks")
Fixes: 64b9cea ("mptcp: fix spurious retransmissions")
Tested-by: Matthieu Baerts <matthieu.baerts@tessares.net>
Reviewed-by: Mat Martineau <mathew.j.martineau@linux.intel.com>
Signed-off-by: Paolo Abeni <pabeni@redhat.com>
github-actions bot pushed a commit to matttbe/mptcp_net-next that referenced this issue Mar 3, 2021
__mptcp_clean_una() can free write memory and should wake-up
user-space processes when needed.

When such function is invoked by the MPTCP receive path, the wakeup
is not needed, as the TCP stack will later trigger subflow_write_space
which will do the wakeup as needed.

Other __mptcp_clean_una() call sites need an additional wakeup check
Let's bundle the relevant code in a new helper and use it.

Closes: multipath-tcp#165
Fixes: 6e628cd ("mptcp: use mptcp release_cb for delayed tasks")
Fixes: 64b9cea ("mptcp: fix spurious retransmissions")
Tested-by: Matthieu Baerts <matthieu.baerts@tessares.net>
Reviewed-by: Mat Martineau <mathew.j.martineau@linux.intel.com>
Signed-off-by: Paolo Abeni <pabeni@redhat.com>
github-actions bot pushed a commit to matttbe/mptcp_net-next that referenced this issue Mar 3, 2021
__mptcp_clean_una() can free write memory and should wake-up
user-space processes when needed.

When such function is invoked by the MPTCP receive path, the wakeup
is not needed, as the TCP stack will later trigger subflow_write_space
which will do the wakeup as needed.

Other __mptcp_clean_una() call sites need an additional wakeup check
Let's bundle the relevant code in a new helper and use it.

Closes: multipath-tcp#165
Fixes: 6e628cd ("mptcp: use mptcp release_cb for delayed tasks")
Fixes: 64b9cea ("mptcp: fix spurious retransmissions")
Tested-by: Matthieu Baerts <matthieu.baerts@tessares.net>
Reviewed-by: Mat Martineau <mathew.j.martineau@linux.intel.com>
Signed-off-by: Paolo Abeni <pabeni@redhat.com>
github-actions bot pushed a commit to matttbe/mptcp_net-next that referenced this issue Mar 3, 2021
__mptcp_clean_una() can free write memory and should wake-up
user-space processes when needed.

When such function is invoked by the MPTCP receive path, the wakeup
is not needed, as the TCP stack will later trigger subflow_write_space
which will do the wakeup as needed.

Other __mptcp_clean_una() call sites need an additional wakeup check
Let's bundle the relevant code in a new helper and use it.

Closes: multipath-tcp#165
Fixes: 6e628cd ("mptcp: use mptcp release_cb for delayed tasks")
Fixes: 64b9cea ("mptcp: fix spurious retransmissions")
Tested-by: Matthieu Baerts <matthieu.baerts@tessares.net>
Reviewed-by: Mat Martineau <mathew.j.martineau@linux.intel.com>
Signed-off-by: Paolo Abeni <pabeni@redhat.com>
github-actions bot pushed a commit to matttbe/mptcp_net-next that referenced this issue Mar 3, 2021
__mptcp_clean_una() can free write memory and should wake-up
user-space processes when needed.

When such function is invoked by the MPTCP receive path, the wakeup
is not needed, as the TCP stack will later trigger subflow_write_space
which will do the wakeup as needed.

Other __mptcp_clean_una() call sites need an additional wakeup check
Let's bundle the relevant code in a new helper and use it.

Closes: multipath-tcp#165
Fixes: 6e628cd ("mptcp: use mptcp release_cb for delayed tasks")
Fixes: 64b9cea ("mptcp: fix spurious retransmissions")
Tested-by: Matthieu Baerts <matthieu.baerts@tessares.net>
Reviewed-by: Mat Martineau <mathew.j.martineau@linux.intel.com>
Signed-off-by: Paolo Abeni <pabeni@redhat.com>
github-actions bot pushed a commit to matttbe/mptcp_net-next that referenced this issue Mar 3, 2021
__mptcp_clean_una() can free write memory and should wake-up
user-space processes when needed.

When such function is invoked by the MPTCP receive path, the wakeup
is not needed, as the TCP stack will later trigger subflow_write_space
which will do the wakeup as needed.

Other __mptcp_clean_una() call sites need an additional wakeup check
Let's bundle the relevant code in a new helper and use it.

Closes: multipath-tcp#165
Fixes: 6e628cd ("mptcp: use mptcp release_cb for delayed tasks")
Fixes: 64b9cea ("mptcp: fix spurious retransmissions")
Tested-by: Matthieu Baerts <matthieu.baerts@tessares.net>
Reviewed-by: Mat Martineau <mathew.j.martineau@linux.intel.com>
Signed-off-by: Paolo Abeni <pabeni@redhat.com>
fengguang pushed a commit to 0day-ci/linux that referenced this issue Mar 4, 2021
__mptcp_clean_una() can free write memory and should wake-up
user-space processes when needed.

When such function is invoked by the MPTCP receive path, the wakeup
is not needed, as the TCP stack will later trigger subflow_write_space
which will do the wakeup as needed.

Other __mptcp_clean_una() call sites need an additional wakeup check
Let's bundle the relevant code in a new helper and use it.

Closes: multipath-tcp/mptcp_net-next#165
Fixes: 6e628cd ("mptcp: use mptcp release_cb for delayed tasks")
Fixes: 64b9cea ("mptcp: fix spurious retransmissions")
Tested-by: Matthieu Baerts <matthieu.baerts@tessares.net>
Signed-off-by: Paolo Abeni <pabeni@redhat.com>
Signed-off-by: Mat Martineau <mathew.j.martineau@linux.intel.com>
fengguang pushed a commit to 0day-ci/linux that referenced this issue Mar 5, 2021
__mptcp_clean_una() can free write memory and should wake-up
user-space processes when needed.

When such function is invoked by the MPTCP receive path, the wakeup
is not needed, as the TCP stack will later trigger subflow_write_space
which will do the wakeup as needed.

Other __mptcp_clean_una() call sites need an additional wakeup check
Let's bundle the relevant code in a new helper and use it.

Closes: multipath-tcp/mptcp_net-next#165
Fixes: 6e628cd ("mptcp: use mptcp release_cb for delayed tasks")
Fixes: 64b9cea ("mptcp: fix spurious retransmissions")
Tested-by: Matthieu Baerts <matthieu.baerts@tessares.net>
Signed-off-by: Paolo Abeni <pabeni@redhat.com>
Signed-off-by: Mat Martineau <mathew.j.martineau@linux.intel.com>
Signed-off-by: David S. Miller <davem@davemloft.net>
jenkins-tessares pushed a commit that referenced this issue Mar 6, 2021
__mptcp_clean_una() can free write memory and should wake-up
user-space processes when needed.

When such function is invoked by the MPTCP receive path, the wakeup
is not needed, as the TCP stack will later trigger subflow_write_space
which will do the wakeup as needed.

Other __mptcp_clean_una() call sites need an additional wakeup check
Let's bundle the relevant code in a new helper and use it.

Closes: #165
Fixes: 6e628cd ("mptcp: use mptcp release_cb for delayed tasks")
Fixes: 64b9cea ("mptcp: fix spurious retransmissions")
Tested-by: Matthieu Baerts <matthieu.baerts@tessares.net>
Reviewed-by: Mat Martineau <mathew.j.martineau@linux.intel.com>
Signed-off-by: Paolo Abeni <pabeni@redhat.com>
jenkins-tessares pushed a commit that referenced this issue Mar 6, 2021
__mptcp_clean_una() can free write memory and should wake-up
user-space processes when needed.

When such function is invoked by the MPTCP receive path, the wakeup
is not needed, as the TCP stack will later trigger subflow_write_space
which will do the wakeup as needed.

Other __mptcp_clean_una() call sites need an additional wakeup check
Let's bundle the relevant code in a new helper and use it.

Closes: #165
Fixes: 6e628cd ("mptcp: use mptcp release_cb for delayed tasks")
Fixes: 64b9cea ("mptcp: fix spurious retransmissions")
Tested-by: Matthieu Baerts <matthieu.baerts@tessares.net>
Reviewed-by: Mat Martineau <mathew.j.martineau@linux.intel.com>
Signed-off-by: Paolo Abeni <pabeni@redhat.com>
jenkins-tessares pushed a commit that referenced this issue Mar 8, 2021
__mptcp_clean_una() can free write memory and should wake-up
user-space processes when needed.

When such function is invoked by the MPTCP receive path, the wakeup
is not needed, as the TCP stack will later trigger subflow_write_space
which will do the wakeup as needed.

Other __mptcp_clean_una() call sites need an additional wakeup check
Let's bundle the relevant code in a new helper and use it.

Closes: #165
Fixes: 6e628cd ("mptcp: use mptcp release_cb for delayed tasks")
Fixes: 64b9cea ("mptcp: fix spurious retransmissions")
Tested-by: Matthieu Baerts <matthieu.baerts@tessares.net>
Reviewed-by: Mat Martineau <mathew.j.martineau@linux.intel.com>
Signed-off-by: Paolo Abeni <pabeni@redhat.com>
jenkins-tessares pushed a commit that referenced this issue Mar 10, 2021
__mptcp_clean_una() can free write memory and should wake-up
user-space processes when needed.

When such function is invoked by the MPTCP receive path, the wakeup
is not needed, as the TCP stack will later trigger subflow_write_space
which will do the wakeup as needed.

Other __mptcp_clean_una() call sites need an additional wakeup check
Let's bundle the relevant code in a new helper and use it.

Closes: #165
Fixes: 6e628cd ("mptcp: use mptcp release_cb for delayed tasks")
Fixes: 64b9cea ("mptcp: fix spurious retransmissions")
Tested-by: Matthieu Baerts <matthieu.baerts@tessares.net>
Reviewed-by: Mat Martineau <mathew.j.martineau@linux.intel.com>
Signed-off-by: Paolo Abeni <pabeni@redhat.com>
matttbe pushed a commit that referenced this issue Mar 28, 2024
Add a cgroup bpf program test where the bpf program is running
in a pid namespace. The test is successfully:
  #165/3   ns_current_pid_tgid/new_ns_cgrp:OK

Signed-off-by: Yonghong Song <yonghong.song@linux.dev>
Signed-off-by: Andrii Nakryiko <andrii@kernel.org>
Link: https://lore.kernel.org/bpf/20240315184910.2976522-1-yonghong.song@linux.dev
matttbe pushed a commit that referenced this issue Mar 28, 2024
Add a sk_msg bpf program test where the program is running in a pid
namespace. The test is successful:
  #165/4   ns_current_pid_tgid/new_ns_sk_msg:OK

Signed-off-by: Yonghong Song <yonghong.song@linux.dev>
Signed-off-by: Andrii Nakryiko <andrii@kernel.org>
Link: https://lore.kernel.org/bpf/20240315184915.2976718-1-yonghong.song@linux.dev
matttbe pushed a commit that referenced this issue May 20, 2024
Recent additions in BPF like cpu v4 instructions, test_bpf module
exhibits the following failures:

  test_bpf: #82 ALU_MOVSX | BPF_B jited:1 ret 2 != 1 (0x2 != 0x1)FAIL (1 times)
  test_bpf: #83 ALU_MOVSX | BPF_H jited:1 ret 2 != 1 (0x2 != 0x1)FAIL (1 times)
  test_bpf: #84 ALU64_MOVSX | BPF_B jited:1 ret 2 != 1 (0x2 != 0x1)FAIL (1 times)
  test_bpf: #85 ALU64_MOVSX | BPF_H jited:1 ret 2 != 1 (0x2 != 0x1)FAIL (1 times)
  test_bpf: #86 ALU64_MOVSX | BPF_W jited:1 ret 2 != 1 (0x2 != 0x1)FAIL (1 times)

  test_bpf: #165 ALU_SDIV_X: -6 / 2 = -3 jited:1 ret 2147483645 != -3 (0x7ffffffd != 0xfffffffd)FAIL (1 times)
  test_bpf: #166 ALU_SDIV_K: -6 / 2 = -3 jited:1 ret 2147483645 != -3 (0x7ffffffd != 0xfffffffd)FAIL (1 times)

  test_bpf: #169 ALU_SMOD_X: -7 % 2 = -1 jited:1 ret 1 != -1 (0x1 != 0xffffffff)FAIL (1 times)
  test_bpf: #170 ALU_SMOD_K: -7 % 2 = -1 jited:1 ret 1 != -1 (0x1 != 0xffffffff)FAIL (1 times)

  test_bpf: #172 ALU64_SMOD_K: -7 % 2 = -1 jited:1 ret 1 != -1 (0x1 != 0xffffffff)FAIL (1 times)

  test_bpf: #313 BSWAP 16: 0x0123456789abcdef -> 0xefcd
  eBPF filter opcode 00d7 (@2) unsupported
  jited:0 301 PASS
  test_bpf: #314 BSWAP 32: 0x0123456789abcdef -> 0xefcdab89
  eBPF filter opcode 00d7 (@2) unsupported
  jited:0 555 PASS
  test_bpf: #315 BSWAP 64: 0x0123456789abcdef -> 0x67452301
  eBPF filter opcode 00d7 (@2) unsupported
  jited:0 268 PASS
  test_bpf: #316 BSWAP 64: 0x0123456789abcdef >> 32 -> 0xefcdab89
  eBPF filter opcode 00d7 (@2) unsupported
  jited:0 269 PASS
  test_bpf: #317 BSWAP 16: 0xfedcba9876543210 -> 0x1032
  eBPF filter opcode 00d7 (@2) unsupported
  jited:0 460 PASS
  test_bpf: #318 BSWAP 32: 0xfedcba9876543210 -> 0x10325476
  eBPF filter opcode 00d7 (@2) unsupported
  jited:0 320 PASS
  test_bpf: #319 BSWAP 64: 0xfedcba9876543210 -> 0x98badcfe
  eBPF filter opcode 00d7 (@2) unsupported
  jited:0 222 PASS
  test_bpf: #320 BSWAP 64: 0xfedcba9876543210 >> 32 -> 0x10325476
  eBPF filter opcode 00d7 (@2) unsupported
  jited:0 273 PASS

  test_bpf: #344 BPF_LDX_MEMSX | BPF_B
  eBPF filter opcode 0091 (@5) unsupported
  jited:0 432 PASS
  test_bpf: #345 BPF_LDX_MEMSX | BPF_H
  eBPF filter opcode 0089 (@5) unsupported
  jited:0 381 PASS
  test_bpf: #346 BPF_LDX_MEMSX | BPF_W
  eBPF filter opcode 0081 (@5) unsupported
  jited:0 505 PASS

  test_bpf: #490 JMP32_JA: Unconditional jump: if (true) return 1
  eBPF filter opcode 0006 (@1) unsupported
  jited:0 261 PASS

  test_bpf: Summary: 1040 PASSED, 10 FAILED, [924/1038 JIT'ed]

Fix them by adding missing processing.

Fixes: daabb2b ("bpf/tests: add tests for cpuv4 instructions")
Signed-off-by: Christophe Leroy <christophe.leroy@csgroup.eu>
Signed-off-by: Michael Ellerman <mpe@ellerman.id.au>
Link: https://msgid.link/91de862dda99d170697eb79ffb478678af7e0b27.1709652689.git.christophe.leroy@csgroup.eu
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
No open projects
MPTCP Bugs
  
Closed
Development

No branches or pull requests

3 participants