Re: [PATCH mptcp-next v3 0/3] send() fails with EAGAIN in blocking IO mode #487

[Geliang Tang <geliang@kernel.org>]

[-- Attachment #1: Type: text/plain, Size: 3398 bytes --]

Hi Matt, Mat,

On Sun, 2025-06-15 at 23:29 +0200, Matthieu Baerts wrote:
> Hi Mat, Geliang,
> 
> On 14/06/2025 01:11, Mat Martineau wrote:
> > On Thu, 29 May 2025, Geliang Tang wrote:
> > 
> > > From: Geliang Tang <tanggeliang@kylinos.cn>
> > > 
> > > Good news! I finally solved the unstable issue of MPTCP BPF sched
> > > selftests
> > > I reported a year ago, #487 "send() fails with EAGAIN in blocking
> > > IO
> > > mode".
> > > 
> > > The fix is simple, it can be solved by explicitly setting
> > > SO_SNDBUF
> > > sockopt, but be sure not to set SO_RCVBUF at the same time
> > > (see sk->sk_userlocks & SOCK_RCVBUF_LOCK in
> > > mptcp_rcv_space_adjust()).
> > > 
> > > With this fix, BPF sched selftests are now very stable, I run
> > > loop
> > > testing
> > > using mptcp-upstream-virtme-docker (run_loop run_bpftest_all),
> > > and can
> > > run
> > > it normally for hundreds of times without error:
> > > 
> > 
> > Hi Geliang -
> > 
> > I can see how changing SO_SNDBUF on the sending socket side would
> > shift
> > timing behavior in a way that affect the test outcome, but it
> > doesn't
> > address the root issue with bug #487:
> > 
> > It is either OK to get an EAGAIN from a blocking send(), or it's
> > not OK.
> > 
> > 
> > If it's not ok to ever return EAGAIN from a blocking send, the
> > existing
> > test code is a reproducer for a bug, and changing the test is
> > hiding
> > that bug.
> > 
> > If EAGAIN is ok, then we should change the code in
> > send_recv_server() to
> > allow it.

I did try to handle EAGAIN in send_recv_server() but it didn't work.
MPTCP BPF sched selftests still fail. Test code and results are
attached.

I added this in send_recv_server():

	if (errno == EAGAIN && again < 5) {
		again++;
		continue;
	}

And still got the EAGAIN error:

# (network_helpers.c:728: errno: Resource temporarily unavailable) send
7867500 expected 10485760
# (network_helpers.c:782: errno: Resource temporarily unavailable) recv
3469500 ​​expected 10485760
# (network_helpers.c:790: errno: Resource temporarily unavailable)
Failed in thread_ret -11
# send_data_and_verify:FAIL:send_recv_data unexpected error: -11 (errno
11)

In addition, BPF selftests adds a new mechanism that does not allow any
test item to run for more than 10 seconds. Otherwise, the following
error will be reported:

# WATCHDOG: test case mptcp/default executes for 10 seconds...

In my testing, I have not found any other solution besides limiting the
send buffer. This allows data to be sent at a constant rate, which
ensures the stability of MPTCP BPF sched selftests.

In order to avoid hiding this bug, we can add a test item for this in
mptcp selftest in the future, like in [1].

WDYT?

Thanks,
-Geliang

[1]
https://patchwork.kernel.org/project/mptcp/cover/cover.1722502941.git.tanggeliang@kylinos.cn/

> 
> It is now a bit hidden in the middle of #487, but if I'm not
> mistaken,
> it is OK to get EAGAIN with a blocking send() **if** SO_SNDTIMEO is
> used, and in case of timeout.
> 
> See:
> https://github.com/multipath-tcp/mptcp_net-next/issues/487#issuecomment-2485577676
> 
> So I think the question should be: is it normal to block for longer
> than
> the timeout period (which is a "long" period, no?)? If yes, then
> limiting the send buffer might be a solution, but as Mat said, it
> looks
> better to understand the root cause than hiding a bug :)
> 
> Cheers,
> Matt

[-- Attachment #2: bpf-sched-selftests-eagain-err.diff --]
[-- Type: text/x-patch, Size: 1693 bytes --]

diff --git a/tools/testing/selftests/bpf/network_helpers.c b/tools/testing/selftests/bpf/network_helpers.c
index 9cdb80127804..e9966282b664 100644
--- a/tools/testing/selftests/bpf/network_helpers.c
+++ b/tools/testing/selftests/bpf/network_helpers.c
@@ -94,11 +94,11 @@ int settimeo(int fd, int timeout_ms)
 
 static int setsndbuf(int fd, uint32_t sndbuf)
 {
-	if (sndbuf > 0 &&
-	    setsockopt(fd, SOL_SOCKET, SO_SNDBUF, &sndbuf, sizeof(sndbuf))) {
-		log_err("Failed to set SO_SNDBUF");
-		return -1;
-	}
+	//if (sndbuf > 0 &&
+	//    setsockopt(fd, SOL_SOCKET, SO_SNDBUF, &sndbuf, sizeof(sndbuf))) {
+	//	log_err("Failed to set SO_SNDBUF");
+	//	return -1;
+	//}
 
 	return 0;
 }
@@ -688,6 +688,7 @@ static void *send_recv_server(void *arg)
 	ssize_t nr_sent = 0, bytes = 0;
 	char batch[1500];
 	int err = 0, fd;
+	int again = 0;
 
 	fd = accept(a->fd, NULL, NULL);
 	while (fd == -1) {
@@ -713,6 +714,10 @@ static void *send_recv_server(void *arg)
 		if (nr_sent == -1 && errno == EINTR)
 			continue;
 		if (nr_sent == -1) {
+			if (errno == EAGAIN && again < 5) {
+				again++;
+				continue;
+			}
 			err = -errno;
 			break;
 		}
@@ -747,6 +752,7 @@ int send_recv_data(int lfd, int fd, uint32_t total_bytes, uint32_t sndbuf)
 	pthread_t srv_thread;
 	void *thread_ret;
 	char batch[1500];
+	int again = 0;
 	int err = 0;
 
 	err = pthread_create(&srv_thread, NULL, send_recv_server, (void *)&arg);
@@ -762,6 +768,10 @@ int send_recv_data(int lfd, int fd, uint32_t total_bytes, uint32_t sndbuf)
 		if (nr_recv == -1 && errno == EINTR)
 			continue;
 		if (nr_recv == -1) {
+			if (errno == EAGAIN && again < 5) {
+				again++;
+				continue;
+			}
 			err = -errno;
 			break;
 		}

[-- Attachment #3: bpf-sched-selftests-eagain-err.log --]
[-- Type: text/x-log, Size: 4834 bytes --]


	=== Attempt: 28 (Sat, 14 Jun 2025 12:31:17 +0000) ===


BPF Test: test_progs -t mptcp
TAP version 13
1..1
# WATCHDOG: test case mptcp/default executes for 10 seconds...
# #203/1   mptcp/base:OK
# #203/2   mptcp/mptcpify:OK
# #203/3   mptcp/subflow:OK
# address_init:PASS:ip -net mptcp_ns link add veth1 type veth peer name veth2 0 nsec
# address_init:PASS:ip -net mptcp_ns addr add 10.0.1.1/24 dev veth1 0 nsec
# address_init:PASS:ip -net mptcp_ns addr add dead:beef:1::1/64 dev veth1 nodad 0 nsec
# address_init:PASS:ip -net mptcp_ns link set dev veth1 up 0 nsec
# address_init:PASS:ip -net mptcp_ns addr add 10.0.2.1/24 dev veth2 0 nsec
# address_init:PASS:ip -net mptcp_ns addr add dead:beef:2::1/64 dev veth2 nodad 0 nsec
# address_init:PASS:ip -net mptcp_ns link set dev veth2 up 0 nsec
# address_init:PASS:ip -net mptcp_ns link add veth3 type veth peer name veth4 0 nsec
# address_init:PASS:ip -net mptcp_ns addr add 10.0.3.1/24 dev veth3 0 nsec
# address_init:PASS:ip -net mptcp_ns addr add dead:beef:3::1/64 dev veth3 nodad 0 nsec
# address_init:PASS:ip -net mptcp_ns link set dev veth3 up 0 nsec
# address_init:PASS:ip -net mptcp_ns addr add 10.0.4.1/24 dev veth4 0 nsec
# address_init:PASS:ip -net mptcp_ns addr add dead:beef:4::1/64 dev veth4 nodad 0 nsec
# address_init:PASS:ip -net mptcp_ns link set dev veth4 up 0 nsec
# sched_init:PASS:ip netns exec mptcp_ns sysctl -qw net.mptcp.scheduler=default 0 nsec
# test_default:PASS:sched_init 0 nsec
# send_data_and_verify:PASS:start_mptcp_server 0 nsec
# send_data_and_verify:PASS:connect_to_fd 0 nsec
# (network_helpers.c:728: errno: Resource temporarily unavailable) send 7867500 expected 10485760
# (network_helpers.c:782: errno: Resource temporarily unavailable) recv 3469500 expected 10485760
# (network_helpers.c:790: errno: Resource temporarily unavailable) Failed in thread_ret -11
# send_data_and_verify:FAIL:send_recv_data unexpected error: -11 (errno 11)
# #203/4   mptcp/default:FAIL
# #203/5   mptcp/first:OK
# #203/6   mptcp/bkup:OK
# #203/7   mptcp/rr:OK
# #203/8   mptcp/red:OK
# #203/9   mptcp/burst:OK
# #203     mptcp:FAIL
# 
# All error logs:
# address_init:PASS:ip -net mptcp_ns link add veth1 type veth peer name veth2 0 nsec
# address_init:PASS:ip -net mptcp_ns addr add 10.0.1.1/24 dev veth1 0 nsec
# address_init:PASS:ip -net mptcp_ns addr add dead:beef:1::1/64 dev veth1 nodad 0 nsec
# address_init:PASS:ip -net mptcp_ns link set dev veth1 up 0 nsec
# address_init:PASS:ip -net mptcp_ns addr add 10.0.2.1/24 dev veth2 0 nsec
# address_init:PASS:ip -net mptcp_ns addr add dead:beef:2::1/64 dev veth2 nodad 0 nsec
# address_init:PASS:ip -net mptcp_ns link set dev veth2 up 0 nsec
# address_init:PASS:ip -net mptcp_ns link add veth3 type veth peer name veth4 0 nsec
# address_init:PASS:ip -net mptcp_ns addr add 10.0.3.1/24 dev veth3 0 nsec
# address_init:PASS:ip -net mptcp_ns addr add dead:beef:3::1/64 dev veth3 nodad 0 nsec
# address_init:PASS:ip -net mptcp_ns link set dev veth3 up 0 nsec
# address_init:PASS:ip -net mptcp_ns addr add 10.0.4.1/24 dev veth4 0 nsec
# address_init:PASS:ip -net mptcp_ns addr add dead:beef:4::1/64 dev veth4 nodad 0 nsec
# address_init:PASS:ip -net mptcp_ns link set dev veth4 up 0 nsec
# sched_init:PASS:ip netns exec mptcp_ns sysctl -qw net.mptcp.scheduler=default 0 nsec
# test_default:PASS:sched_init 0 nsec
# send_data_and_verify:PASS:start_mptcp_server 0 nsec
# send_data_and_verify:PASS:connect_to_fd 0 nsec
# (network_helpers.c:728: errno: Resource temporarily unavailable) send 7867500 expected 10485760
# (network_helpers.c:782: errno: Resource temporarily unavailable) recv 3469500 expected 10485760
# (network_helpers.c:790: errno: Resource temporarily unavailable) Failed in thread_ret -11
# send_data_and_verify:FAIL:send_recv_data unexpected error: -11 (errno 11)
# #203/4   mptcp/default:FAIL
# #203     mptcp:FAIL
# Summary: 0/8 PASSED, 0 SKIPPED, 1 FAILED
not ok 1 test: bpftest_test_progs_mptcp # FAIL
# time=21
BPF Test: test_progs-cpuv4 -t mptcp
TAP version 13
1..1
# #203/1   mptcp/base:OK
# #203/2   mptcp/mptcpify:OK
# #203/3   mptcp/subflow:OK
# #203/4   mptcp/default:OK
# #203/5   mptcp/first:OK
# #203/6   mptcp/bkup:OK
# #203/7   mptcp/rr:OK
# #203/8   mptcp/red:OK
# #203/9   mptcp/burst:OK
# #203     mptcp:OK
# Summary: 1/9 PASSED, 0 SKIPPED, 0 FAILED
ok 1 test: bpftest_test_progs-cpuv4_mptcp
# time=4
BPF Test: test_progs-no_alu32 -t mptcp
TAP version 13
1..1
# #203/1   mptcp/base:OK
# #203/2   mptcp/mptcpify:OK
# #203/3   mptcp/subflow:OK
# #203/4   mptcp/default:OK
# #203/5   mptcp/first:OK
# #203/6   mptcp/bkup:OK
# #203/7   mptcp/rr:OK
# #203/8   mptcp/red:OK
# #203/9   mptcp/burst:OK
# #203     mptcp:OK
# Summary: 1/9 PASSED, 0 SKIPPED, 0 FAILED
ok 1 test: bpftest_test_progs-no_alu32_mptcp
# time=4


	=== ERROR after 28 attempts (Sat, 14 Jun 2025 12:31:46 +0000) ===