[MPTCP][PATCH v3 mptcp-next 0/4] add tracepoints

[MPTCP][PATCH v3 mptcp-next 0/4] add tracepoints

[Geliang Tang]

v3:
 - update the patch set as Paolo suggested.
 - drop the patch "mptcp: export mptcp_subflow_active".

v2:
 - add two new patches.

This patchset addressed issues 131, replace some/most pr_debug with trace
events. As Paolo suggested, we should add the tracepoints at "the packet
scheduler and the mapping status" first.

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

Geliang Tang (4):
  mptcp: add tracepoint in mptcp_subflow_get_send
  mptcp: add tracepoint in get_mapping_status
  mptcp: add tracepoint in ack_update_msk
  mptcp: add tracepoint in subflow_check_data_avail

 include/trace/events/mptcp.h | 158 +++++++++++++++++++++++++++++++++++
 net/mptcp/options.c          |   6 ++
 net/mptcp/protocol.c         |   7 ++
 net/mptcp/subflow.c          |  10 +--
 4 files changed, 175 insertions(+), 6 deletions(-)
 create mode 100644 include/trace/events/mptcp.h

-- 
2.30.2

[MPTCP][PATCH v3 mptcp-next 1/4] mptcp: add tracepoint in mptcp_subflow_get_send

[Geliang Tang]

This patch added a tracepoint in the packet scheduler function
mptcp_subflow_get_send().

Suggested-by: Paolo Abeni <pabeni@redhat.com>
Signed-off-by: Geliang Tang <geliangtang@gmail.com>
---
 include/trace/events/mptcp.h | 45 ++++++++++++++++++++++++++++++++++++
 net/mptcp/protocol.c         |  7 ++++++
 2 files changed, 52 insertions(+)
 create mode 100644 include/trace/events/mptcp.h

diff --git a/include/trace/events/mptcp.h b/include/trace/events/mptcp.h
new file mode 100644
index 000000000000..80c9498b4ad9
--- /dev/null
+++ b/include/trace/events/mptcp.h
@@ -0,0 +1,45 @@
+/* SPDX-License-Identifier: GPL-2.0 */
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM mptcp
+
+#if !defined(_TRACE_MPTCP_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_MPTCP_H
+
+#include <linux/tracepoint.h>
+
+TRACE_EVENT(mptcp_subflow_get_send,
+
+	TP_PROTO(bool active, bool free, u32 snd_wnd,
+		 u32 pace, u8 backup, u64 ratio),
+
+	TP_ARGS(active, free, snd_wnd,
+		pace, backup, ratio),
+
+	TP_STRUCT__entry(
+		__field(bool, active)
+		__field(bool, free)
+		__field(u32, snd_wnd)
+		__field(u32, pace)
+		__field(u8, backup)
+		__field(u64, ratio)
+	),
+
+	TP_fast_assign(
+		__entry->active = active;
+		__entry->free = free;
+		__entry->snd_wnd = snd_wnd;
+		__entry->pace = pace;
+		__entry->backup = backup;
+		__entry->ratio = ratio;
+	),
+
+	TP_printk("active=%d free=%d snd_wnd=%u pace=%u backup=%u ratio=%llu",
+		  __entry->active, __entry->free, __entry->snd_wnd,
+		  __entry->pace, __entry->backup,
+		  __entry->ratio)
+);
+
+#endif /* _TRACE_MPTCP_H */
+
+/* This part must be outside protection */
+#include <trace/define_trace.h>
diff --git a/net/mptcp/protocol.c b/net/mptcp/protocol.c
index 9d7e7e13fba8..eb64d373a7ee 100644
--- a/net/mptcp/protocol.c
+++ b/net/mptcp/protocol.c
@@ -25,6 +25,9 @@
 #include "protocol.h"
 #include "mib.h"
 
+#define CREATE_TRACE_POINTS
+#include <trace/events/mptcp.h>
+
 #if IS_ENABLED(CONFIG_MPTCP_IPV6)
 struct mptcp6_sock {
 	struct mptcp_sock msk;
@@ -1411,6 +1414,10 @@ static struct sock *mptcp_subflow_get_send(struct mptcp_sock *msk)
 			send_info[subflow->backup].ssk = ssk;
 			send_info[subflow->backup].ratio = ratio;
 		}
+		trace_mptcp_subflow_get_send(mptcp_subflow_active(subflow),
+					     sk_stream_memory_free(subflow->tcp_sock),
+					     tcp_sk(ssk)->snd_wnd, pace,
+					     subflow->backup, ratio);
 	}
 
 	pr_debug("msk=%p nr_active=%d ssk=%p:%lld backup=%p:%lld",
-- 
2.30.2

[MPTCP][PATCH v3 mptcp-next 2/4] mptcp: add tracepoint in get_mapping_status

[Geliang Tang]

This patch added a tracepoint in the mapping status function
get_mapping_status() to dump every mpext field.

Suggested-by: Paolo Abeni <pabeni@redhat.com>
Signed-off-by: Geliang Tang <geliangtang@gmail.com>
---
 include/trace/events/mptcp.h | 52 ++++++++++++++++++++++++++++++++++++
 net/mptcp/subflow.c          |  6 ++---
 2 files changed, 55 insertions(+), 3 deletions(-)

diff --git a/include/trace/events/mptcp.h b/include/trace/events/mptcp.h
index 80c9498b4ad9..02b80cc662f9 100644
--- a/include/trace/events/mptcp.h
+++ b/include/trace/events/mptcp.h
@@ -39,6 +39,58 @@ TRACE_EVENT(mptcp_subflow_get_send,
 		  __entry->ratio)
 );
 
+DECLARE_EVENT_CLASS(mptcp_dump_mpext,
+
+	TP_PROTO(struct mptcp_ext *mpext),
+
+	TP_ARGS(mpext),
+
+	TP_STRUCT__entry(
+		__field(u64, data_ack)
+		__field(u64, data_seq)
+		__field(u32, subflow_seq)
+		__field(u16, data_len)
+		__field(u8, use_map)
+		__field(u8, dsn64)
+		__field(u8, data_fin)
+		__field(u8, use_ack)
+		__field(u8, ack64)
+		__field(u8, mpc_map)
+		__field(u8, frozen)
+		__field(u8, reset_transient)
+		__field(u8, reset_reason)
+	),
+
+	TP_fast_assign(
+		__entry->data_ack = mpext->ack64 ? mpext->data_ack : mpext->data_ack32;
+		__entry->data_seq = mpext->data_seq;
+		__entry->subflow_seq = mpext->subflow_seq;
+		__entry->data_len = mpext->data_len;
+		__entry->use_map = mpext->use_map;
+		__entry->dsn64 = mpext->dsn64;
+		__entry->data_fin = mpext->data_fin;
+		__entry->use_ack = mpext->use_ack;
+		__entry->ack64 = mpext->ack64;
+		__entry->mpc_map = mpext->mpc_map;
+		__entry->frozen = mpext->frozen;
+		__entry->reset_transient = mpext->reset_transient;
+		__entry->reset_reason = mpext->reset_reason;
+	),
+
+	TP_printk("data_ack=%llu data_seq=%llu subflow_seq=%u data_len=%u use_map=%u dsn64=%u data_fin=%u use_ack=%u ack64=%u mpc_map=%u frozen=%u reset_transient=%u reset_reason=%u",
+		  __entry->data_ack, __entry->data_seq,
+		  __entry->subflow_seq, __entry->data_len,
+		  __entry->use_map, __entry->dsn64,
+		  __entry->data_fin, __entry->use_ack,
+		  __entry->ack64, __entry->mpc_map,
+		  __entry->frozen, __entry->reset_transient,
+		  __entry->reset_reason)
+);
+
+DEFINE_EVENT(mptcp_dump_mpext, get_mapping_status,
+	TP_PROTO(struct mptcp_ext *mpext),
+	TP_ARGS(mpext));
+
 #endif /* _TRACE_MPTCP_H */
 
 /* This part must be outside protection */
diff --git a/net/mptcp/subflow.c b/net/mptcp/subflow.c
index 3c19a5265a0f..a88c2b1e5410 100644
--- a/net/mptcp/subflow.c
+++ b/net/mptcp/subflow.c
@@ -25,6 +25,8 @@
 #include "protocol.h"
 #include "mib.h"
 
+#include <trace/events/mptcp.h>
+
 static void mptcp_subflow_ops_undo_override(struct sock *ssk);
 
 static void SUBFLOW_REQ_INC_STATS(struct request_sock *req,
@@ -858,9 +860,7 @@ static enum mapping_status get_mapping_status(struct sock *ssk,
 		goto validate_seq;
 	}
 
-	pr_debug("seq=%llu is64=%d ssn=%u data_len=%u data_fin=%d",
-		 mpext->data_seq, mpext->dsn64, mpext->subflow_seq,
-		 mpext->data_len, mpext->data_fin);
+	trace_get_mapping_status(mpext);
 
 	data_len = mpext->data_len;
 	if (data_len == 0) {
-- 
2.30.2

[MPTCP][PATCH v3 mptcp-next 3/4] mptcp: add tracepoint in ack_update_msk

[Geliang Tang]

This patch added a tracepoint in ack_update_msk() to track the
incoming data_ack and window/snd_una updates.

Suggested-by: Paolo Abeni <pabeni@redhat.com>
Signed-off-by: Geliang Tang <geliangtang@gmail.com>
---
 include/trace/events/mptcp.h | 32 ++++++++++++++++++++++++++++++++
 net/mptcp/options.c          |  6 ++++++
 2 files changed, 38 insertions(+)

diff --git a/include/trace/events/mptcp.h b/include/trace/events/mptcp.h
index 02b80cc662f9..b390317bd98a 100644
--- a/include/trace/events/mptcp.h
+++ b/include/trace/events/mptcp.h
@@ -91,6 +91,38 @@ DEFINE_EVENT(mptcp_dump_mpext, get_mapping_status,
 	TP_PROTO(struct mptcp_ext *mpext),
 	TP_ARGS(mpext));
 
+TRACE_EVENT(ack_update_msk,
+
+	TP_PROTO(u64 data_ack, u64 old_snd_una,
+		 u64 new_snd_una, u64 new_wnd_end,
+		 u64 msk_wnd_end),
+
+	TP_ARGS(data_ack, old_snd_una,
+		new_snd_una, new_wnd_end,
+		msk_wnd_end),
+
+	TP_STRUCT__entry(
+		__field(u64, data_ack)
+		__field(u64, old_snd_una)
+		__field(u64, new_snd_una)
+		__field(u64, new_wnd_end)
+		__field(u64, msk_wnd_end)
+	),
+
+	TP_fast_assign(
+		__entry->data_ack = data_ack;
+		__entry->old_snd_una = old_snd_una;
+		__entry->new_snd_una = new_snd_una;
+		__entry->new_wnd_end = new_wnd_end;
+		__entry->msk_wnd_end = msk_wnd_end;
+	),
+
+	TP_printk("data_ack=%llu old_snd_una=%llu new_snd_una=%llu new_wnd_end=%llu msk_wnd_end=%llu",
+		  __entry->data_ack, __entry->old_snd_una,
+		  __entry->new_snd_una, __entry->new_wnd_end,
+		  __entry->msk_wnd_end)
+);
+
 #endif /* _TRACE_MPTCP_H */
 
 /* This part must be outside protection */
diff --git a/net/mptcp/options.c b/net/mptcp/options.c
index c7eb61d0564c..81db91dd1b84 100644
--- a/net/mptcp/options.c
+++ b/net/mptcp/options.c
@@ -13,6 +13,8 @@
 #include "protocol.h"
 #include "mib.h"
 
+#include <trace/events/mptcp.h>
+
 static bool mptcp_cap_flag_sha256(u8 flags)
 {
 	return (flags & MPTCP_CAP_FLAG_MASK) == MPTCP_CAP_HMAC_SHA256;
@@ -942,6 +944,10 @@ static void ack_update_msk(struct mptcp_sock *msk,
 		__mptcp_data_acked(sk);
 	}
 	mptcp_data_unlock(sk);
+
+	trace_ack_update_msk(mp_opt->data_ack,
+			     old_snd_una, new_snd_una,
+			     new_wnd_end, msk->wnd_end);
 }
 
 bool mptcp_update_rcv_data_fin(struct mptcp_sock *msk, u64 data_fin_seq, bool use_64bit)
-- 
2.30.2

[MPTCP][PATCH v3 mptcp-next 4/4] mptcp: add tracepoint in subflow_check_data_avail

[Geliang Tang]

This patch added a tracepoint in subflow_check_data_avail() to show the
mapping status.

Suggested-by: Paolo Abeni <pabeni@redhat.com>
Signed-off-by: Geliang Tang <geliangtang@gmail.com>
---
 include/trace/events/mptcp.h | 29 +++++++++++++++++++++++++++++
 net/mptcp/subflow.c          |  4 +---
 2 files changed, 30 insertions(+), 3 deletions(-)

diff --git a/include/trace/events/mptcp.h b/include/trace/events/mptcp.h
index b390317bd98a..0cfbb236d44c 100644
--- a/include/trace/events/mptcp.h
+++ b/include/trace/events/mptcp.h
@@ -7,6 +7,14 @@
 
 #include <linux/tracepoint.h>
 
+#define show_mapping_status(status)					\
+	__print_symbolic(status,					\
+		{ 0, "MAPPING_OK" },					\
+		{ 1, "MAPPING_INVALID" },				\
+		{ 2, "MAPPING_EMPTY" },					\
+		{ 3, "MAPPING_DATA_FIN" },				\
+		{ 4, "MAPPING_DUMMY" })
+
 TRACE_EVENT(mptcp_subflow_get_send,
 
 	TP_PROTO(bool active, bool free, u32 snd_wnd,
@@ -123,6 +131,27 @@ TRACE_EVENT(ack_update_msk,
 		  __entry->msk_wnd_end)
 );
 
+TRACE_EVENT(subflow_check_data_avail,
+
+	TP_PROTO(__u8 status, struct sk_buff *skb),
+
+	TP_ARGS(status, skb),
+
+	TP_STRUCT__entry(
+		__field(u8, status)
+		__field(const void *, skb)
+	),
+
+	TP_fast_assign(
+		__entry->status = status;
+		__entry->skb = skb;
+	),
+
+	TP_printk("mapping_status=%s, skb=%p",
+		  show_mapping_status(__entry->status),
+		  __entry->skb)
+);
+
 #endif /* _TRACE_MPTCP_H */
 
 /* This part must be outside protection */
diff --git a/net/mptcp/subflow.c b/net/mptcp/subflow.c
index a88c2b1e5410..d79a99c2bfc4 100644
--- a/net/mptcp/subflow.c
+++ b/net/mptcp/subflow.c
@@ -998,8 +998,6 @@ static bool subflow_check_data_avail(struct sock *ssk)
 	struct mptcp_sock *msk;
 	struct sk_buff *skb;
 
-	pr_debug("msk=%p ssk=%p data_avail=%d skb=%p", subflow->conn, ssk,
-		 subflow->data_avail, skb_peek(&ssk->sk_receive_queue));
 	if (!skb_peek(&ssk->sk_receive_queue))
 		subflow->data_avail = 0;
 	if (subflow->data_avail)
@@ -1011,7 +1009,7 @@ static bool subflow_check_data_avail(struct sock *ssk)
 		u64 old_ack;
 
 		status = get_mapping_status(ssk, msk);
-		pr_debug("msk=%p ssk=%p status=%d", msk, ssk, status);
+		trace_subflow_check_data_avail(status, skb_peek(&ssk->sk_receive_queue));
 		if (status == MAPPING_INVALID) {
 			ssk->sk_err = EBADMSG;
 			goto fatal;
-- 
2.30.2

Re: [MPTCP][PATCH v3 mptcp-next 1/4] mptcp: add tracepoint in mptcp_subflow_get_send

[Paolo Abeni]

On Tue, 2021-03-30 at 17:16 +0800, Geliang Tang wrote:
> This patch added a tracepoint in the packet scheduler function
> mptcp_subflow_get_send().
> 
> Suggested-by: Paolo Abeni <pabeni@redhat.com>
> Signed-off-by: Geliang Tang <geliangtang@gmail.com>
> ---
>  include/trace/events/mptcp.h | 45 ++++++++++++++++++++++++++++++++++++
>  net/mptcp/protocol.c         |  7 ++++++
>  2 files changed, 52 insertions(+)
>  create mode 100644 include/trace/events/mptcp.h
> 
> diff --git a/include/trace/events/mptcp.h b/include/trace/events/mptcp.h
> new file mode 100644
> index 000000000000..80c9498b4ad9
> --- /dev/null
> +++ b/include/trace/events/mptcp.h
> @@ -0,0 +1,45 @@
> +/* SPDX-License-Identifier: GPL-2.0 */
> +#undef TRACE_SYSTEM
> +#define TRACE_SYSTEM mptcp
> +
> +#if !defined(_TRACE_MPTCP_H) || defined(TRACE_HEADER_MULTI_READ)
> +#define _TRACE_MPTCP_H
> +
> +#include <linux/tracepoint.h>
> +
> +TRACE_EVENT(mptcp_subflow_get_send,
> +
> +	TP_PROTO(bool active, bool free, u32 snd_wnd,
> +		 u32 pace, u8 backup, u64 ratio),
> +
> +	TP_ARGS(active, free, snd_wnd,
> +		pace, backup, ratio),
> +
> +	TP_STRUCT__entry(
> +		__field(bool, active)
> +		__field(bool, free)
> +		__field(u32, snd_wnd)
> +		__field(u32, pace)
> +		__field(u8, backup)
> +		__field(u64, ratio)
> +	),
> +
> +	TP_fast_assign(
> +		__entry->active = active;
> +		__entry->free = free;
> +		__entry->snd_wnd = snd_wnd;
> +		__entry->pace = pace;
> +		__entry->backup = backup;
> +		__entry->ratio = ratio;
> +	),
> +
> +	TP_printk("active=%d free=%d snd_wnd=%u pace=%u backup=%u ratio=%llu",
> +		  __entry->active, __entry->free, __entry->snd_wnd,
> +		  __entry->pace, __entry->backup,
> +		  __entry->ratio)
> +);
> +
> +#endif /* _TRACE_MPTCP_H */
> +
> +/* This part must be outside protection */
> +#include <trace/define_trace.h>
> diff --git a/net/mptcp/protocol.c b/net/mptcp/protocol.c
> index 9d7e7e13fba8..eb64d373a7ee 100644
> --- a/net/mptcp/protocol.c
> +++ b/net/mptcp/protocol.c
> @@ -25,6 +25,9 @@
>  #include "protocol.h"
>  #include "mib.h"
>  
> +#define CREATE_TRACE_POINTS
> +#include <trace/events/mptcp.h>
> +
>  #if IS_ENABLED(CONFIG_MPTCP_IPV6)
>  struct mptcp6_sock {
>  	struct mptcp_sock msk;
> @@ -1411,6 +1414,10 @@ static struct sock *mptcp_subflow_get_send(struct mptcp_sock *msk)
>  			send_info[subflow->backup].ssk = ssk;
>  			send_info[subflow->backup].ratio = ratio;
>  		}
> +		trace_mptcp_subflow_get_send(mptcp_subflow_active(subflow),
> +					     sk_stream_memory_free(subflow->tcp_sock),
> +					     tcp_sk(ssk)->snd_wnd, pace,
> +					     subflow->backup, ratio);

If I read correctly, here 'mptcp_subflow_active(subflow)' should be
always true. That means we actually don't trace some data: we don'
trace not active subflows, subflows with 0 pacing_rate etc.

We should instead get the info even for them.

I think it would be better move the tracepoint just after the loop
start, move mptcp_subflow_active() to the header file, and do the
relevant check inside the tracepoint.

Thanks!

Side note: the other patches LGTM, thanks !

Paolo

Re: [MPTCP][PATCH v3 mptcp-next 1/4] mptcp: add tracepoint in mptcp_subflow_get_send

[Paolo Abeni]

On Tue, 2021-03-30 at 17:16 +0800, Geliang Tang wrote:
> This patch added a tracepoint in the packet scheduler function
> mptcp_subflow_get_send().
> 
> Suggested-by: Paolo Abeni <pabeni@redhat.com>
> Signed-off-by: Geliang Tang <geliangtang@gmail.com>
> ---
>  include/trace/events/mptcp.h | 45 ++++++++++++++++++++++++++++++++++++
>  net/mptcp/protocol.c         |  7 ++++++
>  2 files changed, 52 insertions(+)
>  create mode 100644 include/trace/events/mptcp.h
> 
> diff --git a/include/trace/events/mptcp.h b/include/trace/events/mptcp.h
> new file mode 100644
> index 000000000000..80c9498b4ad9
> --- /dev/null
> +++ b/include/trace/events/mptcp.h
> @@ -0,0 +1,45 @@
> +/* SPDX-License-Identifier: GPL-2.0 */
> +#undef TRACE_SYSTEM
> +#define TRACE_SYSTEM mptcp
> +
> +#if !defined(_TRACE_MPTCP_H) || defined(TRACE_HEADER_MULTI_READ)
> +#define _TRACE_MPTCP_H
> +
> +#include <linux/tracepoint.h>
> +
> +TRACE_EVENT(mptcp_subflow_get_send,
> +
> +	TP_PROTO(bool active, bool free, u32 snd_wnd,
> +		 u32 pace, u8 backup, u64 ratio),
> +
> +	TP_ARGS(active, free, snd_wnd,
> +		pace, backup, ratio),
> +
> +	TP_STRUCT__entry(
> +		__field(bool, active)
> +		__field(bool, free)
> +		__field(u32, snd_wnd)
> +		__field(u32, pace)
> +		__field(u8, backup)
> +		__field(u64, ratio)
> +	),
> +
> +	TP_fast_assign(
> +		__entry->active = active;
> +		__entry->free = free;
> +		__entry->snd_wnd = snd_wnd;
> +		__entry->pace = pace;
> +		__entry->backup = backup;
> +		__entry->ratio = ratio;
> +	),
> +
> +	TP_printk("active=%d free=%d snd_wnd=%u pace=%u backup=%u ratio=%llu",
> +		  __entry->active, __entry->free, __entry->snd_wnd,
> +		  __entry->pace, __entry->backup,
> +		  __entry->ratio)
> +);
> +
> +#endif /* _TRACE_MPTCP_H */
> +
> +/* This part must be outside protection */
> +#include <trace/define_trace.h>
> diff --git a/net/mptcp/protocol.c b/net/mptcp/protocol.c
> index 9d7e7e13fba8..eb64d373a7ee 100644
> --- a/net/mptcp/protocol.c
> +++ b/net/mptcp/protocol.c
> @@ -25,6 +25,9 @@
>  #include "protocol.h"
>  #include "mib.h"
>  
> +#define CREATE_TRACE_POINTS
> +#include <trace/events/mptcp.h>
> +
>  #if IS_ENABLED(CONFIG_MPTCP_IPV6)
>  struct mptcp6_sock {
>  	struct mptcp_sock msk;
> @@ -1411,6 +1414,10 @@ static struct sock *mptcp_subflow_get_send(struct mptcp_sock *msk)
>  			send_info[subflow->backup].ssk = ssk;
>  			send_info[subflow->backup].ratio = ratio;
>  		}
> +		trace_mptcp_subflow_get_send(mptcp_subflow_active(subflow),
> +					     sk_stream_memory_free(subflow->tcp_sock),
> +					     tcp_sk(ssk)->snd_wnd, pace,
> +					     subflow->backup, ratio);
>  	}
>  
>  	pr_debug("msk=%p nr_active=%d ssk=%p:%lld backup=%p:%lld",

I almost forgot! With the newly added tracepoint, we can drop this
printk and the later one - still in mptcp_subflow_get_send().

Thanks!

Paolo