[MPTCP] [MPTCP][PATCH v2 mptcp-next] Squash to "bpf:selftests: add MPTCP test base"

[MPTCP] [MPTCP][PATCH v2 mptcp-next] Squash to "bpf:selftests: add MPTCP test base"

[Geliang Tang]

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

When I ran the bpf mptcp test "./test_progs -n 67", I got a "fallback to
TCP" error and a "Attempt to release TCP socket in state 8" error in the
kernel log:

[ 2904.821675] MPTCP: subflow=000000006672aad2
[ 2904.821680] MPTCP: subflow=000000006672aad2, family=2
[ 2904.821682] MPTCP: subflow=000000006672aad2
[ 2904.821719] MPTCP: msk=00000000eaccf64d
[ 2904.821724] MPTCP: msk=00000000eaccf64d
[ 2904.821735] MPTCP: msk=00000000eaccf64d
[ 2904.822786] MPTCP: subflow=000000000003ba05
[ 2904.822789] MPTCP: subflow=000000000003ba05, family=2
[ 2904.822792] MPTCP: subflow=000000000003ba05
[ 2904.822827] MPTCP: msk=000000005818109c
[ 2904.822831] MPTCP: msk=000000005818109c
[ 2904.822868] MPTCP: ssk=00000000729b0de5, local_key=0, token=0, idsn=0
[ 2904.822924] MPTCP: subflow=000000006672aad2
[ 2904.822942] MPTCP: subflow_req=0000000025739d62, listener=000000006672aad2
[ 2904.822944] MPTCP: MP_CAPABLE version=1, flags=1, optlen=4 sndr=18446744072231269184, rcvr=18446744072228608064 len=65535
[ 2904.822949] MPTCP: req=0000000025739d62 local_key=15607636458978417890, token=3995930330, idsn=4151446240254394327
[ 2904.822961] MPTCP: subflow_req=0000000025739d62, local_key=15607636458978417890
[ 2904.822984] MPTCP: subflow=000000000003ba05 synack seq=da2e10fa
[ 2904.822986] MPTCP: MP_CAPABLE version=1, flags=1, optlen=12 sndr=15607636458978417890, rcvr=0 len=1
[ 2904.822989] MPTCP: subflow=000000000003ba05, remote_key=15607636458978417890
[ 2904.822990] MPTCP: msk=000000005818109c, token=3138387826
[ 2904.822993] MPTCP: msk=000000005818109c, token=3138387826 side=0
[ 2904.822997] MPTCP: msk=000000005818109c ssk=00000000729b0de5 data_avail=0 skb=0000000000000000
[ 2904.823000] MPTCP: msk=000000005818109c ssk=00000000729b0de5 status=2
[ 2904.823007] MPTCP: subflow=000000000003ba05, local_key=13360476977887136047, remote_key=15607636458978417890 map_len=0
[ 2904.823018] MPTCP: listener=000000006672aad2, req=0000000025739d62, conn=00000000eaccf64d
[ 2904.823020] MPTCP: MP_CAPABLE version=1, flags=1, optlen=20 sndr=13360476977887136047, rcvr=15607636458978417890 len=65535
[ 2904.823055] MPTCP: subflow=000000002491d623
[ 2904.823064] MPTCP: msk=00000000a0271c19, token=3995930330 side=1
[ 2904.823080] MPTCP: msk=00000000a0271c19 ssk=000000008dd7431f data_avail=0 skb=0000000000000000
[ 2904.823082] MPTCP: msk=00000000a0271c19 ssk=000000008dd7431f status=2
[ 2904.823084] MPTCP: MP_CAPABLE version=1, flags=1, optlen=20 sndr=13360476977887136047, rcvr=15607636458978417890 len=38754
[ 2904.823104] MPTCP: msk=000000005818109c snd_data_fin_enable=0 shutdown=3 state=4 pending=0
[ 2904.823107] MPTCP: msk=000000005818109c snd_data_fin_enable=1 pending=0 snd_nxt=5209280520537872386 write_seq=5209280520537872387
[ 2904.823110] MPTCP: Sending DATA_FIN on subflow 00000000729b0de5
[ 2904.823128] MPTCP: DSS
[ 2904.823131] MPTCP: data_fin=1 dsn64=1 use_map=1 ack64=0 use_ack=1
[ 2904.823133] MPTCP: data_ack=914259928
[ 2904.823134] MPTCP: data_seq=5209280520537872386 subflow_seq=0 data_len=1
[ 2904.823150] MPTCP: msk=000000005818109c state=4
[ 2904.823212] MPTCP: msk=00000000eaccf64d state=7
[ 2904.823214] MPTCP: msk=00000000eaccf64d
[ 2904.823240] MPTCP: subflow_req=0000000025739d62
[ 2904.823250] MPTCP: check_fully_established:fallback to TCP (msk=000000005818109c)
[ 2904.823306] MPTCP: msk=00000000eaccf64d
[ 2904.823526] MPTCP: msk=00000000a0271c19 snd_data_fin_enable=0 pending=0 snd_nxt=4151446240254394328 write_seq=4151446240254394328
[ 2904.823533] MPTCP: msk=00000000a0271c19
[ 2904.823535] IPv4: Attempt to release TCP socket in state 8 00000000a0271c19
[ 2954.415879] MPTCP: msk=00000000474e8657 snd_data_fin_enable=1 pending=0 snd_nxt=14603538848639169953 write_seq=14603538848639169953
[ 2954.415911] MPTCP: msk=00000000474e8657
[ 2954.416151] MPTCP: msk=00000000474e8657
[ 2966.704256] MPTCP: msk=000000005818109c snd_data_fin_enable=1 pending=0 snd_nxt=5209280520537872387 write_seq=5209280520537872387
[ 2966.704279] MPTCP: msk=000000005818109c

This patch fixed them.

For the first error, adding send_byte can fix it. The send_byte function is
copied from tools/testing/selftests/bpf/prog_tests/tcp_rtt.c.

For the second error, we need to close the server fd before closing the
client fd.

With this patch, no error in the kernel log output when raning the bpf test:

[ 2539.428250] MPTCP: msk=00000000d7aad9c1
[ 2558.122417] MPTCP: subflow=0000000045a3636c
[ 2558.122421] MPTCP: subflow=0000000045a3636c, family=2
[ 2558.122424] MPTCP: subflow=0000000045a3636c
[ 2558.122457] MPTCP: msk=00000000474e8657
[ 2558.122461] MPTCP: msk=00000000474e8657
[ 2558.122473] MPTCP: msk=00000000474e8657
[ 2558.123568] MPTCP: subflow=000000000f8d06f6
[ 2558.123571] MPTCP: subflow=000000000f8d06f6, family=2
[ 2558.123573] MPTCP: subflow=000000000f8d06f6
[ 2558.123607] MPTCP: msk=00000000eaccf64d
[ 2558.123611] MPTCP: msk=00000000eaccf64d
[ 2558.123648] MPTCP: ssk=0000000049c4c5ec, local_key=0, token=0, idsn=0
[ 2558.123701] MPTCP: subflow=0000000045a3636c
[ 2558.123718] MPTCP: subflow_req=0000000025739d62, listener=0000000045a3636c
[ 2558.123720] MPTCP: MP_CAPABLE version=1, flags=1, optlen=4 sndr=18446744072231269184, rcvr=18446744072228608064 len=65535
[ 2558.123725] MPTCP: req=0000000025739d62 local_key=833954766036575697, token=1721321063, idsn=15537260029657244048
[ 2558.123735] MPTCP: subflow_req=0000000025739d62, local_key=833954766036575697
[ 2558.123757] MPTCP: subflow=000000000f8d06f6 synack seq=285a036
[ 2558.123759] MPTCP: MP_CAPABLE version=1, flags=1, optlen=12 sndr=833954766036575697, rcvr=0 len=1
[ 2558.123761] MPTCP: subflow=000000000f8d06f6, remote_key=833954766036575697
[ 2558.123763] MPTCP: msk=00000000eaccf64d, token=2492018137
[ 2558.123765] MPTCP: msk=00000000eaccf64d, token=2492018137 side=0
[ 2558.123770] MPTCP: msk=00000000eaccf64d ssk=0000000049c4c5ec data_avail=0 skb=0000000000000000
[ 2558.123772] MPTCP: msk=00000000eaccf64d ssk=0000000049c4c5ec status=2
[ 2558.123779] MPTCP: subflow=000000000f8d06f6, local_key=1088354515732031164, remote_key=833954766036575697 map_len=0
[ 2558.123790] MPTCP: listener=0000000045a3636c, req=0000000025739d62, conn=00000000474e8657
[ 2558.123793] MPTCP: MP_CAPABLE version=1, flags=1, optlen=20 sndr=1088354515732031164, rcvr=833954766036575697 len=65535
[ 2558.123813] MPTCP: subflow=0000000079746efe
[ 2558.123820] MPTCP: msk=000000005818109c, token=1721321063 side=1
[ 2558.123836] MPTCP: msk=000000005818109c ssk=00000000d6227d49 data_avail=0 skb=0000000000000000
[ 2558.123838] MPTCP: msk=000000005818109c ssk=00000000d6227d49 status=2
[ 2558.123840] MPTCP: MP_CAPABLE version=1, flags=1, optlen=20 sndr=1088354515732031164, rcvr=833954766036575697 len=38754
[ 2558.123868] MPTCP: msk=00000000eaccf64d dfrag at seq=7839476820133227673 len=1 sent=0 new=1
[ 2558.123871] MPTCP: msk=00000000eaccf64d nr_active=1 ssk=0000000049c4c5ec:0 backup=0000000000000000:-1
[ 2558.123874] MPTCP: msk=00000000eaccf64d ssk=0000000049c4c5ec sending dfrag at seq=7839476820133227673 len=1 already sent=0
[ 2558.123877] MPTCP: data_seq=7839476820133227673 subflow_seq=1 data_len=1 dsn64=1
[ 2558.123880] MPTCP: subflow=000000000f8d06f6, local_key=1088354515732031164, remote_key=833954766036575697 map_len=1
[ 2558.123892] MPTCP: MP_CAPABLE version=1, flags=1, optlen=22 sndr=1088354515732031164, rcvr=833954766036575697 len=1
[ 2558.123899] MPTCP: msk=000000005818109c ssk=00000000d6227d49 data_avail=0 skb=00000000d6c38daf
[ 2558.123902] MPTCP: seq=7839476820133227673 is64=1 ssn=1 data_len=1 data_fin=0
[ 2558.123904] MPTCP: new map seq=7839476820133227673 subflow_seq=1 data_len=1
[ 2558.123911] MPTCP: msk=000000005818109c ssk=00000000d6227d49 status=0
[ 2558.123912] MPTCP: msk ack_seq=6ccb6aa1f0f32c99 subflow ack_seq=6ccb6aa1f0f32c99
[ 2558.123915] MPTCP: msk=000000005818109c ssk=00000000d6227d49
[ 2558.123917] MPTCP: Done with mapping: seq=1 data_len=1
[ 2558.123919] MPTCP: msk=000000005818109c ssk=00000000d6227d49 data_avail=0 skb=0000000000000000
[ 2558.123921] MPTCP: msk=000000005818109c ssk=00000000d6227d49 status=2
[ 2558.123923] MPTCP: msk=000000005818109c empty=1
[ 2558.123946] MPTCP: DSS
[ 2558.123947] MPTCP: data_fin=0 dsn64=0 use_map=0 ack64=1 use_ack=1
[ 2558.123949] MPTCP: data_ack=7839476820133227674
[ 2558.123951] MPTCP: msk=00000000eaccf64d
[ 2558.123959] MPTCP: msk=00000000eaccf64d snd_data_fin_enable=0 pending=0 snd_nxt=7839476820133227674 write_seq=7839476820133227674
[ 2558.123968] MPTCP: msk=00000000474e8657 state=7
[ 2558.123970] MPTCP: msk=00000000474e8657
[ 2558.123995] MPTCP: msk=000000005818109c
[ 2558.124012] MPTCP: subflow_req=0000000025739d62
[ 2558.124028] MPTCP: msk=00000000eaccf64d ssk=0000000049c4c5ec data_avail=0 skb=0000000000000000
[ 2558.124031] MPTCP: msk=00000000eaccf64d ssk=0000000049c4c5ec status=2
[ 2558.124064] MPTCP: msk=00000000eaccf64d status=10
[ 2558.124066] MPTCP: msk=00000000eaccf64d snd_data_fin_enable=0 pending=0 snd_nxt=7839476820133227674 write_seq=7839476820133227674
[ 2558.124109] MPTCP: msk=00000000474e8657
[ 2558.124133] MPTCP: msk=00000000eaccf64d snd_data_fin_enable=0 shutdown=3 state=4 pending=0
[ 2558.124135] MPTCP: msk=00000000eaccf64d snd_data_fin_enable=1 pending=0 snd_nxt=7839476820133227674 write_seq=7839476820133227675

Signed-off-by: Geliang Tang <geliangtang(a)gmail.com>
---
v2:
 - fix "Attempt to release TCP socket in state 8" error too.
 - add full kernel log in the commit log.
---
 tools/testing/selftests/bpf/prog_tests/mptcp.c | 16 ++++++++++++----
 1 file changed, 12 insertions(+), 4 deletions(-)

diff --git a/tools/testing/selftests/bpf/prog_tests/mptcp.c b/tools/testing/selftests/bpf/prog_tests/mptcp.c
index 0e65d64868e9..79783bf8bf18 100644
--- a/tools/testing/selftests/bpf/prog_tests/mptcp.c
+++ b/tools/testing/selftests/bpf/prog_tests/mptcp.c
@@ -8,6 +8,14 @@ struct mptcp_storage {
 	__u32 is_mptcp;
 };
 
+static void send_byte(int fd)
+{
+	char b = 0x55;
+
+	if (CHECK_FAIL(write(fd, &b, sizeof(b)) != 1))
+		perror("Failed to send single byte");
+}
+
 static int verify_sk(int map_fd, int client_fd, const char *msg, __u32 is_mptcp)
 {
 	int err = 0, cfd = client_fd;
@@ -76,9 +84,13 @@ static int run_test(int cgroup_fd, int server_fd, bool is_mptcp)
 		goto close_client_fd;
 	}
 
+	send_byte(client_fd);
+
 	err += is_mptcp ? verify_sk(map_fd, client_fd, "MPTCP subflow socket", 1) :
 			  verify_sk(map_fd, client_fd, "plain TCP socket", 0);
 
+	close(server_fd);
+
 close_client_fd:
 	close(client_fd);
 
@@ -102,8 +114,6 @@ void test_mptcp(void)
 
 	CHECK_FAIL(run_test(cgroup_fd, server_fd, false));
 
-	close(server_fd);
-
 with_mptcp:
 	/* with MPTCP */
 	server_fd = start_mptcp_server(AF_INET, NULL, 0, 0);
@@ -112,8 +122,6 @@ void test_mptcp(void)
 
 	CHECK_FAIL(run_test(cgroup_fd, server_fd, true));
 
-	close(server_fd);
-
 close_cgroup_fd:
 	close(cgroup_fd);
 }
-- 
2.30.2

Re: [MPTCP] [MPTCP][PATCH v2 mptcp-next] Squash to "bpf:selftests: add MPTCP test base"

[Geliang Tang]

Hi Matt,

Thanks for your review.

Matthieu Baerts <matthieu.baerts@tessares.net> 于2021年3月20日周六 下午7:31写道：

>
> Hi Geliang,
>
> On 18/03/2021 04:47, Geliang Tang wrote:
> > When I ran the bpf mptcp test "./test_progs -n 67", I got a "fallback to
> > TCP" error and a "Attempt to release TCP socket in state 8" error in the
> > kernel log:
>
> (...)
>
> > For the first error, adding send_byte can fix it. The send_byte function is
> > copied from tools/testing/selftests/bpf/prog_tests/tcp_rtt.c.
>
> (maybe better to continue the discussion about that in the v1, I'm not
> sure I understand what is causing this fallback and I'm not able to
> reproduce it with another program)
>
> > For the second error, we need to close the server fd before closing the
> > client fd.
>
> Do you know why we have to do that?
> Do we have the same warning with tcp_rtt.c for example where the server
> is also closed after the client.
>
> Again, I don't think it is normal to have these warnings with simple
> userspace programs except if here, some modifications are done from BPF?

Did you reproduce this issue using the bpf selftest? Did you test my fix?
It's simple and it works.

Do you think it's worth to find out the root cause of this issue? It may
take a lot of time. If so, I'll open a ticket on GitHub to trace it later,
I'll try to fix it after finishing the "checksum support" issue.

Thanks.

-Geliang

>
> Cheers,
> Matt
> --
> Tessares | Belgium | Hybrid Access Solutions
> www.tessares.net

Re: [MPTCP] [MPTCP][PATCH v2 mptcp-next] Squash to "bpf:selftests: add MPTCP test base"

[Matthieu Baerts]

Hi Geliang,

Thank you for your reply!

On 30/03/2021 12:32, Geliang Tang wrote:
> Hi Matt,
> 
> Thanks for your review.
> 
> Matthieu Baerts <matthieu.baerts@tessares.net> 于2021年3月20日周六 下午7:31写道：
> 
>>
>> Hi Geliang,
>>
>> On 18/03/2021 04:47, Geliang Tang wrote:
>>> When I ran the bpf mptcp test "./test_progs -n 67", I got a "fallback to
>>> TCP" error and a "Attempt to release TCP socket in state 8" error in the
>>> kernel log:
>>
>> (...)
>>
>>> For the first error, adding send_byte can fix it. The send_byte function is
>>> copied from tools/testing/selftests/bpf/prog_tests/tcp_rtt.c.
>>
>> (maybe better to continue the discussion about that in the v1, I'm not
>> sure I understand what is causing this fallback and I'm not able to
>> reproduce it with another program)
>>
>>> For the second error, we need to close the server fd before closing the
>>> client fd.
>>
>> Do you know why we have to do that?
>> Do we have the same warning with tcp_rtt.c for example where the server
>> is also closed after the client.
>>
>> Again, I don't think it is normal to have these warnings with simple
>> userspace programs except if here, some modifications are done from BPF?
> 
> Did you reproduce this issue using the bpf selftest? Did you test my fix?
> It's simple and it works.
> 
> Do you think it's worth to find out the root cause of this issue? It may
> take a lot of time. If so, I'll open a ticket on GitHub to trace it later,
> I'll try to fix it after finishing the "checksum support" issue.

I think it is worth finding out the root of this issue. It is not urgent 
at all.

As far as I understand, these two warnings are not blocking, right? In 
this case, maybe better not to "hide" them because the current version 
looks good to me: I mean, I don't see why it would not be OK to close a 
connection where no bytes were transferred nor closing the server fd 
before the client one.

So yes, please open a new ticket on GitHub if you don't mind :)

Cheers,
Matt
-- 
Tessares | Belgium | Hybrid Access Solutions
www.tessares.net