[PATCH mptcp-next v5 0/2] display "last time" actions info

[PATCH mptcp-next v5 0/2] display "last time" actions info

[Geliang Tang]

From: Geliang Tang <tanggeliang@kylinos.cn>

v5:
 - merge the squash-to patch
 - rename cnt1/2/3 as Matt suggested. (thanks)

v4:
 - address Mat's comments for v3 (thanks).
 - merge patch 1 and patch 2 into one.

v3:
 - address Matt's comments for patch 3 (thanks)
 - add "dport", "sleep", and mptcp_lib_expect_all_features.

v2:
 - address Mat's comments for v1 (thanks)
 - set msk->last_data_sent only if err > 0
 - set last_data_recv in __mptcp_move_skbs_from_subflow
 - add three reserved bytes after mptcpi_subflows_total
 - move selftests from mptcp_join.sh to diag.sh and check that the
timestamps move forward.

Closes: https://github.com/multipath-tcp/mptcp_net-next/issues/446

Geliang Tang (2):
  mptcp: add last time fields in mptcp_info
  selftests: mptcp: test last time mptcp_info

 include/uapi/linux/mptcp.h                |  4 ++
 net/mptcp/options.c                       |  1 +
 net/mptcp/protocol.c                      |  7 ++++
 net/mptcp/protocol.h                      |  3 ++
 net/mptcp/sockopt.c                       |  4 ++
 tools/testing/selftests/net/mptcp/diag.sh | 51 +++++++++++++++++++++++
 6 files changed, 70 insertions(+)

-- 
2.40.1

[PATCH mptcp-next v5 1/2] mptcp: add last time fields in mptcp_info

[Geliang Tang]

From: Geliang Tang <tanggeliang@kylinos.cn>

This patch adds "last time" fields last_data_sent, last_data_recv and
last_ack_recv in struct mptcp_sock to record the last time data_sent,
data_recv and ack_recv happened. They all are initialized as
tcp_jiffies32 in __mptcp_init_sock(), but updated as tcp_jiffies32 too
when data is sent in __subflow_push_pending(), data is received in
__mptcp_move_skbs_from_subflow(), and ack is received in ack_update_msk().

Similar to tcpi_last_data_sent, tcpi_last_data_recv and tcpi_last_ack_recv
exposed with TCP, this patch exposes the last time "an action happened" for
MPTCP in mptcp_info, named mptcpi_last_data_sent, mptcpi_last_data_recv and
mptcpi_last_ack_recv, calculated in mptcp_diag_fill_info() as the time
deltas between now and the newly added last time fields in mptcp_sock.

Also add three reserved bytes in struct mptcp_info.

Closes: https://github.com/multipath-tcp/mptcp_net-next/issues/446
Signed-off-by: Geliang Tang <tanggeliang@kylinos.cn>
---
 include/uapi/linux/mptcp.h | 4 ++++
 net/mptcp/options.c        | 1 +
 net/mptcp/protocol.c       | 7 +++++++
 net/mptcp/protocol.h       | 3 +++
 net/mptcp/sockopt.c        | 4 ++++
 5 files changed, 19 insertions(+)

diff --git a/include/uapi/linux/mptcp.h b/include/uapi/linux/mptcp.h
index 74cfe496891e..67d015df8893 100644
--- a/include/uapi/linux/mptcp.h
+++ b/include/uapi/linux/mptcp.h
@@ -58,6 +58,10 @@ struct mptcp_info {
 	__u64	mptcpi_bytes_received;
 	__u64	mptcpi_bytes_acked;
 	__u8	mptcpi_subflows_total;
+	__u8	reserved[3];
+	__u32	mptcpi_last_data_sent;
+	__u32	mptcpi_last_data_recv;
+	__u32	mptcpi_last_ack_recv;
 };
 
 /* MPTCP Reset reason codes, rfc8684 */
diff --git a/net/mptcp/options.c b/net/mptcp/options.c
index 5926955625cf..c0832df3b0a3 100644
--- a/net/mptcp/options.c
+++ b/net/mptcp/options.c
@@ -1069,6 +1069,7 @@ static void ack_update_msk(struct mptcp_sock *msk,
 		__mptcp_snd_una_update(msk, new_snd_una);
 		__mptcp_data_acked(sk);
 	}
+	msk->last_ack_recv = tcp_jiffies32;
 	mptcp_data_unlock(sk);
 
 	trace_ack_update_msk(mp_opt->data_ack,
diff --git a/net/mptcp/protocol.c b/net/mptcp/protocol.c
index 556b3b95c537..43318aa5f991 100644
--- a/net/mptcp/protocol.c
+++ b/net/mptcp/protocol.c
@@ -706,6 +706,8 @@ static bool __mptcp_move_skbs_from_subflow(struct mptcp_sock *msk,
 		}
 	} while (more_data_avail);
 
+	if (moved > 0)
+		msk->last_data_recv = tcp_jiffies32;
 	*bytes += moved;
 	return done;
 }
@@ -1556,6 +1558,8 @@ static int __subflow_push_pending(struct sock *sk, struct sock *ssk,
 	err = copied;
 
 out:
+	if (err > 0)
+		msk->last_data_sent = tcp_jiffies32;
 	return err;
 }
 
@@ -2793,6 +2797,9 @@ static void __mptcp_init_sock(struct sock *sk)
 	WRITE_ONCE(msk->allow_infinite_fallback, true);
 	msk->recovery = false;
 	msk->subflow_id = 1;
+	msk->last_data_sent = tcp_jiffies32;
+	msk->last_data_recv = tcp_jiffies32;
+	msk->last_ack_recv = tcp_jiffies32;
 
 	mptcp_pm_data_init(msk);
 
diff --git a/net/mptcp/protocol.h b/net/mptcp/protocol.h
index 81035579425c..2f56e25ee021 100644
--- a/net/mptcp/protocol.h
+++ b/net/mptcp/protocol.h
@@ -282,6 +282,9 @@ struct mptcp_sock {
 	u64		bytes_acked;
 	u64		snd_una;
 	u64		wnd_end;
+	u32		last_data_sent;
+	u32		last_data_recv;
+	u32		last_ack_recv;
 	unsigned long	timer_ival;
 	u32		token;
 	int		rmem_released;
diff --git a/net/mptcp/sockopt.c b/net/mptcp/sockopt.c
index 73fdf423de44..2ec2fdf9f4af 100644
--- a/net/mptcp/sockopt.c
+++ b/net/mptcp/sockopt.c
@@ -896,6 +896,7 @@ static int mptcp_getsockopt_first_sf_only(struct mptcp_sock *msk, int level, int
 void mptcp_diag_fill_info(struct mptcp_sock *msk, struct mptcp_info *info)
 {
 	struct sock *sk = (struct sock *)msk;
+	u32 now = tcp_jiffies32;
 	u32 flags = 0;
 	bool slow;
 
@@ -930,6 +931,7 @@ void mptcp_diag_fill_info(struct mptcp_sock *msk, struct mptcp_info *info)
 	info->mptcpi_snd_una = msk->snd_una;
 	info->mptcpi_rcv_nxt = msk->ack_seq;
 	info->mptcpi_bytes_acked = msk->bytes_acked;
+	info->mptcpi_last_ack_recv = jiffies_to_msecs(now - msk->last_ack_recv);
 	mptcp_data_unlock(sk);
 
 	slow = lock_sock_fast(sk);
@@ -942,6 +944,8 @@ void mptcp_diag_fill_info(struct mptcp_sock *msk, struct mptcp_info *info)
 	info->mptcpi_bytes_retrans = msk->bytes_retrans;
 	info->mptcpi_subflows_total = info->mptcpi_subflows +
 		__mptcp_has_initial_subflow(msk);
+	info->mptcpi_last_data_sent = jiffies_to_msecs(now - msk->last_data_sent);
+	info->mptcpi_last_data_recv = jiffies_to_msecs(now - msk->last_data_recv);
 	unlock_sock_fast(sk, slow);
 }
 EXPORT_SYMBOL_GPL(mptcp_diag_fill_info);
-- 
2.40.1

[PATCH mptcp-next v5 2/2] selftests: mptcp: test last time mptcp_info

[Geliang Tang]

From: Geliang Tang <tanggeliang@kylinos.cn>

This patch adds a new helper chk_msk_info() to show the counters in
mptcp_info of the given info, and check that the timestamps move
forward. Use it to show newly added last_data_sent, last_data_recv
and last_ack_recv in mptcp_info in chk_last_time_info().

Signed-off-by: Geliang Tang <tanggeliang@kylinos.cn>
---
 tools/testing/selftests/net/mptcp/diag.sh | 51 +++++++++++++++++++++++
 1 file changed, 51 insertions(+)

diff --git a/tools/testing/selftests/net/mptcp/diag.sh b/tools/testing/selftests/net/mptcp/diag.sh
index bc97ab33a00e..911920f3edbb 100755
--- a/tools/testing/selftests/net/mptcp/diag.sh
+++ b/tools/testing/selftests/net/mptcp/diag.sh
@@ -200,6 +200,56 @@ chk_msk_cestab()
 		 "${expected}" "${msg}" ""
 }
 
+msk_info_get_value()
+{
+	local port="${1}"
+	local info="${2}"
+
+	ss -N "${ns}" -inHM dport "${port}" | \
+		mptcp_lib_get_info_value "${info}" "${info}"
+}
+
+chk_msk_info()
+{
+	local port="${1}"
+	local info="${2}"
+	local cnt="${3}"
+	local now delta_ms=250
+
+	now=$(msk_info_get_value "${port}" "${info}")
+
+	mptcp_lib_print_title "....chk ${info}"
+	if { [ -z "${cnt}" ] || [ -z "${now}" ]; } &&
+	   ! mptcp_lib_expect_all_features; then
+		mptcp_lib_pr_skip "Feature probably not supported"
+		mptcp_lib_result_skip "${info}"
+	elif [ "$((cnt + delta_ms))" -lt "${now}" ]; then
+		mptcp_lib_pr_ok
+		mptcp_lib_result_pass "${info}"
+	else
+		mptcp_lib_pr_fail "value of ${info} changed by $((now - cnt))ms," \
+				  "expected at least ${delta_ms}ms"
+		mptcp_lib_result_fail "${info}"
+		ret=${KSFT_FAIL}
+	fi
+}
+
+chk_last_time_info()
+{
+	local port="${1}"
+	local data_sent data_recv ack_recv
+
+	data_sent=$(msk_info_get_value "${port}" "last_data_sent")
+	data_recv=$(msk_info_get_value "${port}" "last_data_recv")
+	ack_recv=$(msk_info_get_value "${port}" "last_ack_recv")
+
+	sleep 0.5
+
+	chk_msk_info "${port}" "last_data_sent" "${data_sent}"
+	chk_msk_info "${port}" "last_data_recv" "${data_recv}"
+	chk_msk_info "${port}" "last_ack_recv" "${ack_recv}"
+}
+
 wait_connected()
 {
 	local listener_ns="${1}"
@@ -233,6 +283,7 @@ echo "b" | \
 				127.0.0.1 >/dev/null &
 wait_connected $ns 10000
 chk_msk_nr 2 "after MPC handshake "
+chk_last_time_info 10000
 chk_msk_remote_key_nr 2 "....chk remote_key"
 chk_msk_fallback_nr 0 "....chk no fallback"
 chk_msk_inuse 2
-- 
2.40.1

Re: [PATCH mptcp-next v5 2/2] selftests: mptcp: test last time mptcp_info

[Matthieu Baerts]

Hi Geliang,

On 02/04/2024 14:52, Geliang Tang wrote:
> From: Geliang Tang <tanggeliang@kylinos.cn>
> 
> This patch adds a new helper chk_msk_info() to show the counters in
> mptcp_info of the given info, and check that the timestamps move
> forward. Use it to show newly added last_data_sent, last_data_recv
> and last_ack_recv in mptcp_info in chk_last_time_info().
> 
> Signed-off-by: Geliang Tang <tanggeliang@kylinos.cn>
> ---
>  tools/testing/selftests/net/mptcp/diag.sh | 51 +++++++++++++++++++++++
>  1 file changed, 51 insertions(+)
> 
> diff --git a/tools/testing/selftests/net/mptcp/diag.sh b/tools/testing/selftests/net/mptcp/diag.sh
> index bc97ab33a00e..911920f3edbb 100755
> --- a/tools/testing/selftests/net/mptcp/diag.sh
> +++ b/tools/testing/selftests/net/mptcp/diag.sh
> @@ -200,6 +200,56 @@ chk_msk_cestab()
>  		 "${expected}" "${msg}" ""
>  }
>  
> +msk_info_get_value()
> +{
> +	local port="${1}"
> +	local info="${2}"
> +
> +	ss -N "${ns}" -inHM dport "${port}" | \
> +		mptcp_lib_get_info_value "${info}" "${info}"
> +}
> +
> +chk_msk_info()
> +{
> +	local port="${1}"
> +	local info="${2}"
> +	local cnt="${3}"
> +	local now delta_ms=250
> +
> +	now=$(msk_info_get_value "${port}" "${info}")
> +
> +	mptcp_lib_print_title "....chk ${info}"

One small detail: here the title printed here ...

> +	if { [ -z "${cnt}" ] || [ -z "${now}" ]; } &&
> +	   ! mptcp_lib_expect_all_features; then
> +		mptcp_lib_pr_skip "Feature probably not supported"
> +		mptcp_lib_result_skip "${info}"

... and the title used in the TAP format here ...

> +	elif [ "$((cnt + delta_ms))" -lt "${now}" ]; then
> +		mptcp_lib_pr_ok
> +		mptcp_lib_result_pass "${info}"

... here ...

> +	else
> +		mptcp_lib_pr_fail "value of ${info} changed by $((now - cnt))ms," \
> +				  "expected at least ${delta_ms}ms"
> +		mptcp_lib_result_fail "${info}"

... and here are different:

Output:

  (...)
  # 06 after MPC handshake                               [ OK ]
  # 07 ....chk last_data_sent                            [ OK ]
  # 08 ....chk last_data_recv                            [ OK ]
  # 09 ....chk last_ack_recv                             [ OK ]
  # 10 ....chk remote_key                                [ OK ]
  # 11 ....chk no fallback                               [ OK ]
  # 12 ....chk 2 msk in use                              [ OK ]
  # 13 ....chk 2 cestab                                  [ OK ]
  # 14 ....chk 2->0 msk in use after flush               [ OK ]
  # 15 ....chk 2->0 cestab after flush                   [ OK ]
  (...)

TAP:

  (...)
  # ok 6 - diag: after MPC handshake
  # ok 7 - diag: last_data_sent
  # ok 8 - diag: last_data_recv
  # ok 9 - diag: last_ack_recv
  # ok 10 - diag: ....chk remote_key
  # ok 11 - diag: ....chk no fallback
  # ok 12 - diag: ....chk 2 msk in use
  # ok 13 - diag: ....chk 2 cestab
  # ok 14 - diag: ....chk 2->0 msk in use after flush
  # ok 15 - diag: ....chk 2->0 cestab after flush
  (...)

apart from that, the rest looks good to me.

Reviewed-by: Matthieu Baerts (NGI0) <matttbe@kernel.org>

If there are no other modifications needed after Mat's review, I can
also fix that when applying the patches.

> +		ret=${KSFT_FAIL}
> +	fi
> +}
> +
> +chk_last_time_info()
> +{
> +	local port="${1}"
> +	local data_sent data_recv ack_recv
> +
> +	data_sent=$(msk_info_get_value "${port}" "last_data_sent")
> +	data_recv=$(msk_info_get_value "${port}" "last_data_recv")
> +	ack_recv=$(msk_info_get_value "${port}" "last_ack_recv")
> +
> +	sleep 0.5

(while at it, maybe good to add a comment here)

  sleep 0.5  # wait to check after if the timestamps are bigger

(and above)

  local delta_ms=250  # half what we waited before, just to be sure

> +
> +	chk_msk_info "${port}" "last_data_sent" "${data_sent}"
> +	chk_msk_info "${port}" "last_data_recv" "${data_recv}"
> +	chk_msk_info "${port}" "last_ack_recv" "${ack_recv}"
> +}
> +
>  wait_connected()
>  {
>  	local listener_ns="${1}"
> @@ -233,6 +283,7 @@ echo "b" | \
>  				127.0.0.1 >/dev/null &
>  wait_connected $ns 10000
>  chk_msk_nr 2 "after MPC handshake "
> +chk_last_time_info 10000
>  chk_msk_remote_key_nr 2 "....chk remote_key"
>  chk_msk_fallback_nr 0 "....chk no fallback"
>  chk_msk_inuse 2

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

Re: [PATCH mptcp-next v5 0/2] display "last time" actions info

[MPTCP CI]

Hi Geliang,

Thank you for your modifications, that's great!

Our CI did some validations and here is its report:

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

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


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 v5 0/2] display "last time" actions info

[Mat Martineau]

On Tue, 2 Apr 2024, Geliang Tang wrote:

> From: Geliang Tang <tanggeliang@kylinos.cn>
>
> v5:
> - merge the squash-to patch
> - rename cnt1/2/3 as Matt suggested. (thanks)

v5 LGTM (with Matthieu's suggestions), thanks Geliang!


Reviewed-by: Mat Martineau <martineau@kernel.org>

>
> v4:
> - address Mat's comments for v3 (thanks).
> - merge patch 1 and patch 2 into one.
>
> v3:
> - address Matt's comments for patch 3 (thanks)
> - add "dport", "sleep", and mptcp_lib_expect_all_features.
>
> v2:
> - address Mat's comments for v1 (thanks)
> - set msk->last_data_sent only if err > 0
> - set last_data_recv in __mptcp_move_skbs_from_subflow
> - add three reserved bytes after mptcpi_subflows_total
> - move selftests from mptcp_join.sh to diag.sh and check that the
> timestamps move forward.
>
> Closes: https://github.com/multipath-tcp/mptcp_net-next/issues/446
>
> Geliang Tang (2):
>  mptcp: add last time fields in mptcp_info
>  selftests: mptcp: test last time mptcp_info
>
> include/uapi/linux/mptcp.h                |  4 ++
> net/mptcp/options.c                       |  1 +
> net/mptcp/protocol.c                      |  7 ++++
> net/mptcp/protocol.h                      |  3 ++
> net/mptcp/sockopt.c                       |  4 ++
> tools/testing/selftests/net/mptcp/diag.sh | 51 +++++++++++++++++++++++
> 6 files changed, 70 insertions(+)
>
> -- 
> 2.40.1
>
>
>

Re: [PATCH mptcp-next v5 0/2] display "last time" actions info

[Matthieu Baerts]

Hi Geliang, Mat,

On 02/04/2024 14:52, Geliang Tang wrote:
> From: Geliang Tang <tanggeliang@kylinos.cn>
> 
> v5:
>  - merge the squash-to patch
>  - rename cnt1/2/3 as Matt suggested. (thanks)

Thank you for the last version and the reviews!

New patches for t/upstream:
- 86f4ac812473: mptcp: add last time fields in mptcp_info
- 39e0a5698a69: selftests: mptcp: test last time mptcp_info
- e2a5795fc295: Squash to "selftests: mptcp: test last time mptcp_info"
- Results: f6f31f972b24..5194dc9f4bb2 (export)

Tests are now in progress:

- export:
https://github.com/multipath-tcp/mptcp_net-next/commit/92e1f1e61b8c9332430e4797d5cb1bf6f408c1aa/checks

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