[PATCH mptcp-next v3] selftests: mptcp: print stats before socket closure

[PATCH mptcp-next v3] selftests: mptcp: print stats before socket closure

[Matthieu Baerts (NGI0)]

In case of poll timeout, it might be too late to print the stats after
the socket closure.

Now, in case of poll timeout, 'ss' and 'nstat' are invoked from
mptcp_connect to print the stats before exiting. This should help
debugging poll timeout issues.

Note: for this "workaround", system() is used for debugging purposes
only. The returned result can then be safely ignored, hence the (void)!
to avoid unused-result warnings.

Also, 'nstat *Tcp*' will print '#kernel' at the top, but that's OK, and
it seems better to avoid using a pipe here.

Signed-off-by: Matthieu Baerts (NGI0) <matttbe@kernel.org>
---
Changes in v3:
- use double quotes instead of single ones (Sashiko)
- Link to v2: https://patch.msgid.link/20260814-sft-mptcp-stats-b4-close-v2-1-b7a8ab3ddae8@kernel.org

Changes in v2:
- use 'ip netns identify' to avoid a warning from AI reviews
- use 'nstat -s *Tcp*' instead of using grep
- add a note about (void)!
- Link to v1: https://patch.msgid.link/20260814-sft-mptcp-stats-b4-close-v1-1-2945a591be7e@kernel.org
---
 tools/testing/selftests/net/mptcp/mptcp_connect.c | 15 +++++++++++++++
 1 file changed, 15 insertions(+)

diff --git a/tools/testing/selftests/net/mptcp/mptcp_connect.c b/tools/testing/selftests/net/mptcp/mptcp_connect.c
index ea4cb6c1bd5e..d6c2237bdba0 100644
--- a/tools/testing/selftests/net/mptcp/mptcp_connect.c
+++ b/tools/testing/selftests/net/mptcp/mptcp_connect.c
@@ -210,6 +210,19 @@ static void xgetaddrinfo(const char *node, const char *service,
 	}
 }
 
+static void print_err_stats(void)
+{
+	char cmd[128];
+
+	snprintf(cmd, sizeof(cmd), "ss -Menitam -o '%cport = :%s' >&2",
+		 listen_mode ? 's' : 'd', cfg_port);
+
+	fprintf(stderr, "socket stats before socket closure:\n");
+	(void)!system(cmd);
+	(void)!system("NSTAT_HISTORY=\"/tmp/$(ip netns identify).nstat\" "
+		      "nstat -s '*Tcp*' >&2");
+}
+
 static void set_rcvbuf(int fd, unsigned int size)
 {
 	int err;
@@ -656,6 +669,7 @@ static int copyfd_io_poll(int infd, int peerfd, int outfd,
 			fprintf(stderr, "%s: poll timed out (events: "
 				"POLLIN %u, POLLOUT %u)\n", __func__,
 				fds.events & POLLIN, fds.events & POLLOUT);
+			print_err_stats();
 			return 2;
 		}
 
@@ -1194,6 +1208,7 @@ int main_loop_s(int listensock)
 		return 1;
 	case 0:
 		fprintf(stderr, "%s: timed out\n", __func__);
+		print_err_stats();
 		close(listensock);
 		return 2;
 	}

---
base-commit: d536472a82d18356d323227213acb5603bb9050c
change-id: 20260814-sft-mptcp-stats-b4-close-20964ff6a6ba

Best regards,
--  
Matthieu Baerts (NGI0) <matttbe@kernel.org>

Re: [PATCH mptcp-next v3] selftests: mptcp: print stats before socket closure

[MPTCP CI]

Hi Matthieu,

Thank you for your modifications, that's great!

Our CI did some validations and here is its report:

- KVM Validation: normal (except selftest_mptcp_join): Success! ✅
- KVM Validation: normal (only selftest_mptcp_join): Success! ✅
- KVM Validation: debug (except selftest_mptcp_join): Success! ✅
- KVM Validation: debug (only selftest_mptcp_join): Success! ✅
- KVM Validation: btf-normal (only bpftest_all): Success! ✅
- KVM Validation: btf-debug (only bpftest_all): Success! ✅
- Task: https://github.com/multipath-tcp/mptcp_net-next/actions/runs/31847744292

Initiator: Patchew Applier
Commits: https://github.com/multipath-tcp/mptcp_net-next/commits/2da643328f05
Patchwork: https://patchwork.kernel.org/project/mptcp/list/?series=1146325


If there are some issues, you can reproduce them using the same environment as
the one used by the CI thanks to a docker image, e.g.:

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

For more details:

    https://github.com/multipath-tcp/mptcp-upstream-virtme-docker


Please note that despite all the efforts that have been already done to have a
stable tests suite when executed on a public CI like here, it is possible some
reported issues are not due to your modifications. Still, do not hesitate to
help us improve that ;-)

Cheers,
MPTCP GH Action bot
Bot operated by Matthieu Baerts (NGI0 Core)

Re: [PATCH mptcp-next v3] selftests: mptcp: print stats before socket closure

[Geliang Tang]

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

Hi Matt,

On Sat, 2026-08-15 at 00:28 +0200, Matthieu Baerts (NGI0) wrote:
> In case of poll timeout, it might be too late to print the stats
> after
> the socket closure.
> 
> Now, in case of poll timeout, 'ss' and 'nstat' are invoked from
> mptcp_connect to print the stats before exiting. This should help
> debugging poll timeout issues.
> 
> Note: for this "workaround", system() is used for debugging purposes

This print_err_stats() implementation is basically the same as
mptcp_lib_pr_err_stats() in the shell, right?

I think it's better to use mptcp_lib_pr_err_stats() in the shell to
print the information. In mptcp_connect.c, when a poll timeout occurs,
we send a signal to the shell and don't close the socket immediately -
we wait for the shell to finish printing the information before closing
it. What do you think of this approach? There's a reference
implementation in the attachment, but I haven't tested it.

Thanks,
-Geliang

> only. The returned result can then be safely ignored, hence the
> (void)!
> to avoid unused-result warnings.
> 
> Also, 'nstat *Tcp*' will print '#kernel' at the top, but that's OK,
> and
> it seems better to avoid using a pipe here.
> 
> Signed-off-by: Matthieu Baerts (NGI0) <matttbe@kernel.org>
> ---
> Changes in v3:
> - use double quotes instead of single ones (Sashiko)
> - Link to v2:
> https://patch.msgid.link/20260814-sft-mptcp-stats-b4-close-v2-1-b7a8ab3ddae8@kernel.org
> 
> Changes in v2:
> - use 'ip netns identify' to avoid a warning from AI reviews
> - use 'nstat -s *Tcp*' instead of using grep
> - add a note about (void)!
> - Link to v1:
> https://patch.msgid.link/20260814-sft-mptcp-stats-b4-close-v1-1-2945a591be7e@kernel.org
> ---
>  tools/testing/selftests/net/mptcp/mptcp_connect.c | 15
> +++++++++++++++
>  1 file changed, 15 insertions(+)
> 
> diff --git a/tools/testing/selftests/net/mptcp/mptcp_connect.c
> b/tools/testing/selftests/net/mptcp/mptcp_connect.c
> index ea4cb6c1bd5e..d6c2237bdba0 100644
> --- a/tools/testing/selftests/net/mptcp/mptcp_connect.c
> +++ b/tools/testing/selftests/net/mptcp/mptcp_connect.c
> @@ -210,6 +210,19 @@ static void xgetaddrinfo(const char *node, const
> char *service,
>  	}
>  }
>  
> +static void print_err_stats(void)
> +{
> +	char cmd[128];
> +
> +	snprintf(cmd, sizeof(cmd), "ss -Menitam -o '%cport = :%s'
> >&2",
> +		 listen_mode ? 's' : 'd', cfg_port);
> +
> +	fprintf(stderr, "socket stats before socket closure:\n");
> +	(void)!system(cmd);
> +	(void)!system("NSTAT_HISTORY=\"/tmp/$(ip netns
> identify).nstat\" "
> +		      "nstat -s '*Tcp*' >&2");
> +}
> +
>  static void set_rcvbuf(int fd, unsigned int size)
>  {
>  	int err;
> @@ -656,6 +669,7 @@ static int copyfd_io_poll(int infd, int peerfd,
> int outfd,
>  			fprintf(stderr, "%s: poll timed out (events:
> "
>  				"POLLIN %u, POLLOUT %u)\n",
> __func__,
>  				fds.events & POLLIN, fds.events &
> POLLOUT);
> +			print_err_stats();
>  			return 2;
>  		}
>  
> @@ -1194,6 +1208,7 @@ int main_loop_s(int listensock)
>  		return 1;
>  	case 0:
>  		fprintf(stderr, "%s: timed out\n", __func__);
> +		print_err_stats();
>  		close(listensock);
>  		return 2;
>  	}
> 
> ---
> base-commit: d536472a82d18356d323227213acb5603bb9050c
> change-id: 20260814-sft-mptcp-stats-b4-close-20964ff6a6ba
> 
> Best regards,
> --  
> Matthieu Baerts (NGI0) <matttbe@kernel.org>
> 

[-- Attachment #2: 0001-Squash-to-selftests-mptcp-print-stats-before-socket-.patch --]
[-- Type: text/x-patch, Size: 4632 bytes --]

From 2791eb0c86efc8990bcc79c6af08e2e49dd620cd Mon Sep 17 00:00:00 2001
Message-ID: <2791eb0c86efc8990bcc79c6af08e2e49dd620cd.1788596400.git.tanggeliang@kylinos.cn>
From: Geliang Tang <tanggeliang@kylinos.cn>
Date: Sat, 5 Sep 2026 16:12:46 +0800
Subject: [PATCH] Squash to "selftests: mptcp: print stats before socket
 closure"

Signed-off-by: Geliang Tang <tanggeliang@kylinos.cn>
---
 .../selftests/net/mptcp/mptcp_connect.c       | 37 +++++++++++++------
 .../selftests/net/mptcp/mptcp_connect.sh      | 16 +++++++-
 2 files changed, 40 insertions(+), 13 deletions(-)

diff --git a/tools/testing/selftests/net/mptcp/mptcp_connect.c b/tools/testing/selftests/net/mptcp/mptcp_connect.c
index 8c788977e594..3217d320648e 100644
--- a/tools/testing/selftests/net/mptcp/mptcp_connect.c
+++ b/tools/testing/selftests/net/mptcp/mptcp_connect.c
@@ -47,6 +47,7 @@ extern int optind;
 static int  poll_timeout = 10 * 1000;
 static bool listen_mode;
 static bool quit;
+static pid_t shell_pid;
 
 enum cfg_mode {
 	CFG_MODE_POLL,
@@ -210,17 +211,28 @@ static void xgetaddrinfo(const char *node, const char *service,
 	}
 }
 
-static void print_err_stats(void)
+static volatile int shell_woken;
+
+static void wake_handler(int sig)
 {
-	char cmd[128];
+	shell_woken = 1;
+}
 
-	snprintf(cmd, sizeof(cmd), "ss -Menitam -o '%cport = :%s' >&2",
-		 listen_mode ? 's' : 'd', cfg_port);
+/* Notify the shell script that a poll timeout occurred, then pause with the
+ * socket still open. The shell collects socket stats via ss/nstat while the
+ * fd is still alive, then sends us SIGUSR1 to wake us up so we can exit.
+ */
+static void notify_shell(void)
+{
+	if (!shell_pid)
+		return;
+
+	shell_woken = 0;
+	signal(SIGUSR1, wake_handler);
+	kill(shell_pid, SIGUSR1);
 
-	fprintf(stderr, "socket stats before socket closure:\n");
-	(void)!system(cmd);
-	(void)!system("NSTAT_HISTORY=\"/tmp/$(ip netns identify).nstat\" "
-		      "nstat -s '*Tcp*' >&2");
+	while (!shell_woken)
+		pause();
 }
 
 static void set_rcvbuf(int fd, unsigned int size)
@@ -671,7 +683,7 @@ static int copyfd_io_poll(int infd, int peerfd, int outfd,
 			fprintf(stderr, "%s: poll timed out (events: "
 				"POLLIN %u, POLLOUT %u)\n", __func__,
 				fds.events & POLLIN, fds.events & POLLOUT);
-			print_err_stats();
+			notify_shell();
 			return 2;
 		}
 
@@ -1210,7 +1222,7 @@ int main_loop_s(int listensock)
 		return 1;
 	case 0:
 		fprintf(stderr, "%s: timed out\n", __func__);
-		print_err_stats();
+		notify_shell();
 		close(listensock);
 		return 2;
 	}
@@ -1531,7 +1543,7 @@ static void parse_opts(int argc, char **argv)
 {
 	int c;
 
-	while ((c = getopt(argc, argv, "6c:f:hi:I:jlm:M:o:p:P:r:R:s:S:t:T:w:")) != -1) {
+	while ((c = getopt(argc, argv, "6c:f:hi:I:jlm:M:o:p:P:r:R:s:S:t:T:w:W:")) != -1) {
 		switch (c) {
 		case 'f':
 			cfg_truncate = atoi(optarg);
@@ -1597,6 +1609,9 @@ static void parse_opts(int argc, char **argv)
 		case 'w':
 			cfg_wait = atoi(optarg)*1000000;
 			break;
+		case 'W':
+			shell_pid = atoi(optarg);
+			break;
 		case 'M':
 			cfg_mark = strtol(optarg, NULL, 0);
 			break;
diff --git a/tools/testing/selftests/net/mptcp/mptcp_connect.sh b/tools/testing/selftests/net/mptcp/mptcp_connect.sh
index 7a2a851fa0ad..61d7031acd41 100755
--- a/tools/testing/selftests/net/mptcp/mptcp_connect.sh
+++ b/tools/testing/selftests/net/mptcp/mptcp_connect.sh
@@ -394,7 +394,7 @@ do_transfer()
 	fi
 
 	ip netns exec ${listener_ns} \
-		./mptcp_connect -t ${timeout_poll} -l -p $port -s ${srv_proto} \
+		./mptcp_connect -t ${timeout_poll} -W $$ -l -p $port -s ${srv_proto} \
 			$extra_args $local_addr < "$sin" > "$sout" &
 	local spid=$!
 
@@ -403,7 +403,7 @@ do_transfer()
 	local start
 	start=$(date +%s%N)
 	ip netns exec ${connector_ns} \
-		./mptcp_connect -t ${timeout_poll} -p $port -s ${cl_proto} \
+		./mptcp_connect -t ${timeout_poll} -W $$ -p $port -s ${cl_proto} \
 			$extra_args $connect_addr < "$cin" > "$cout" &
 	local cpid=$!
 
@@ -411,11 +411,23 @@ do_transfer()
 		"${connector_ns}" "${port}" "${cpid}" "${spid}" &
 	local timeout_pid=$!
 
+	local timed_out=0
+	trap 'timed_out=1' USR1
+
 	wait $cpid
 	local retc=$?
 	wait $spid
 	local rets=$?
 
+	if [ ${timed_out} -eq 1 ]; then
+		# mptcp_connect paused on poll timeout, socket still open -
+		# collect stats now while the fd is alive, then wake them up
+		mptcp_lib_pr_err_stats "${listener_ns}" "${connector_ns}" "${port}"
+		kill -USR1 $cpid $spid 2>/dev/null
+		wait $cpid; retc=$?
+		wait $spid; rets=$?
+	fi
+
 	if kill -0 $timeout_pid; then
 		# Finished before the timeout: kill the background job
 		mptcp_lib_kill_group_wait $timeout_pid
-- 
2.53.0

Re: [PATCH mptcp-next v3] selftests: mptcp: print stats before socket closure

[Matthieu Baerts]

Hi Geliang,

On 05/09/2026 10:26, Geliang Tang wrote:
> Hi Matt,
> 
> On Sat, 2026-08-15 at 00:28 +0200, Matthieu Baerts (NGI0) wrote:
>> In case of poll timeout, it might be too late to print the stats
>> after
>> the socket closure.
>>
>> Now, in case of poll timeout, 'ss' and 'nstat' are invoked from
>> mptcp_connect to print the stats before exiting. This should help
>> debugging poll timeout issues.
>>
>> Note: for this "workaround", system() is used for debugging purposes
> 
> This print_err_stats() implementation is basically the same as
> mptcp_lib_pr_err_stats() in the shell, right?

Correct.

> I think it's better to use mptcp_lib_pr_err_stats() in the shell to
> print the information. In mptcp_connect.c, when a poll timeout occurs,
> we send a signal to the shell and don't close the socket immediately -
> we wait for the shell to finish printing the information before closing
> it. What do you think of this approach? There's a reference
> implementation in the attachment, but I haven't tested it.
Thank you for your review. I agree that what you suggested is better for
a tool that would be used in production. But here with the selftests, I
don't think we need your long patch with a higher complexity, just for
the selftests. I think it is fine to have some "system()" calls with the
same ss/nstat commands compared to a patch of 50+ lines to get the same
result. No?

Cheers,
Matt
-- 
Sponsored by the NGI0 Core fund.