[PATCH net-next v2 0/3] tcp: make trace of reset logic complete

[PATCH net-next v2 0/3] tcp: make trace of reset logic complete

[Jason Xing]

From: Jason Xing <kernelxing@tencent.com>

Before this, we miss some cases where the TCP layer could send rst but
we cannot trace it. So I decided to complete it :)

v2
1. fix spelling mistakes

Jason Xing (3):
  trace: adjust TP_STORE_ADDR_PORTS_SKB() parameters
  trace: tcp: fully support trace_tcp_send_reset
  tcp: add location into reset trace process

 include/trace/events/tcp.h | 68 ++++++++++++++++++++++++++++++--------
 net/ipv4/tcp_ipv4.c        |  4 +--
 net/ipv4/tcp_output.c      |  2 +-
 net/ipv6/tcp_ipv6.c        |  3 +-
 4 files changed, 60 insertions(+), 17 deletions(-)

-- 
2.37.3

[PATCH net-next v2 1/3] trace: adjust TP_STORE_ADDR_PORTS_SKB() parameters

[Jason Xing]

From: Jason Xing <kernelxing@tencent.com>

Introducing entry_saddr and entry_daddr parameters in this macro
for later use can help us record the reverse 4-tuple by analyzing
the 4-tuple of the incoming skb when receiving.

Signed-off-by: Jason Xing <kernelxing@tencent.com>
---
 include/trace/events/tcp.h | 21 +++++++++++----------
 1 file changed, 11 insertions(+), 10 deletions(-)

diff --git a/include/trace/events/tcp.h b/include/trace/events/tcp.h
index 699dafd204ea..2495a1d579be 100644
--- a/include/trace/events/tcp.h
+++ b/include/trace/events/tcp.h
@@ -302,15 +302,15 @@ TRACE_EVENT(tcp_probe,
 		  __entry->skbaddr, __entry->skaddr)
 );
 
-#define TP_STORE_ADDR_PORTS_SKB_V4(__entry, skb)			\
+#define TP_STORE_ADDR_PORTS_SKB_V4(skb, entry_saddr, entry_daddr)	\
 	do {								\
 		const struct tcphdr *th = (const struct tcphdr *)skb->data; \
-		struct sockaddr_in *v4 = (void *)__entry->saddr;	\
+		struct sockaddr_in *v4 = (void *)entry_saddr;		\
 									\
 		v4->sin_family = AF_INET;				\
 		v4->sin_port = th->source;				\
 		v4->sin_addr.s_addr = ip_hdr(skb)->saddr;		\
-		v4 = (void *)__entry->daddr;				\
+		v4 = (void *)entry_daddr;				\
 		v4->sin_family = AF_INET;				\
 		v4->sin_port = th->dest;				\
 		v4->sin_addr.s_addr = ip_hdr(skb)->daddr;		\
@@ -318,29 +318,30 @@ TRACE_EVENT(tcp_probe,
 
 #if IS_ENABLED(CONFIG_IPV6)
 
-#define TP_STORE_ADDR_PORTS_SKB(__entry, skb)				\
+#define TP_STORE_ADDR_PORTS_SKB(skb, entry_saddr, entry_daddr)		\
 	do {								\
 		const struct iphdr *iph = ip_hdr(skb);			\
 									\
 		if (iph->version == 6) {				\
 			const struct tcphdr *th = (const struct tcphdr *)skb->data; \
-			struct sockaddr_in6 *v6 = (void *)__entry->saddr; \
+			struct sockaddr_in6 *v6 = (void *)entry_saddr;	\
 									\
 			v6->sin6_family = AF_INET6;			\
 			v6->sin6_port = th->source;			\
 			v6->sin6_addr = ipv6_hdr(skb)->saddr;		\
-			v6 = (void *)__entry->daddr;			\
+			v6 = (void *)entry_daddr;			\
 			v6->sin6_family = AF_INET6;			\
 			v6->sin6_port = th->dest;			\
 			v6->sin6_addr = ipv6_hdr(skb)->daddr;		\
 		} else							\
-			TP_STORE_ADDR_PORTS_SKB_V4(__entry, skb);	\
+			TP_STORE_ADDR_PORTS_SKB_V4(skb, entry_saddr,	\
+						   entry_daddr); \
 	} while (0)
 
 #else
 
-#define TP_STORE_ADDR_PORTS_SKB(__entry, skb)		\
-	TP_STORE_ADDR_PORTS_SKB_V4(__entry, skb)
+#define TP_STORE_ADDR_PORTS_SKB(skb, entry_saddr, entry_daddr)		\
+	TP_STORE_ADDR_PORTS_SKB_V4(skb, entry_saddr, entry_daddr)
 
 #endif
 
@@ -365,7 +366,7 @@ DECLARE_EVENT_CLASS(tcp_event_skb,
 		memset(__entry->saddr, 0, sizeof(struct sockaddr_in6));
 		memset(__entry->daddr, 0, sizeof(struct sockaddr_in6));
 
-		TP_STORE_ADDR_PORTS_SKB(__entry, skb);
+		TP_STORE_ADDR_PORTS_SKB(skb, __entry->saddr, __entry->daddr);
 	),
 
 	TP_printk("skbaddr=%p src=%pISpc dest=%pISpc",
-- 
2.37.3

[PATCH net-next v2 2/3] trace: tcp: fully support trace_tcp_send_reset

[Jason Xing]

From: Jason Xing <kernelxing@tencent.com>

Prior to this patch, what we can see by enabling trace_tcp_send is
only happening under two circumstances:
1) active rst mode
2) non-active rst mode and based on the full socket

That means the inconsistency occurs if we use tcpdump and trace
simultaneously to see how rst happens.

It's necessary that we should take into other cases into considerations,
say:
1) time-wait socket
2) no socket
...

By parsing the incoming skb and reversing its 4-tuple can
we know the exact 'flow' which might not exist.

Samples after applied this patch:
1. tcp_send_reset: skbaddr=XXX skaddr=XXX src=ip:port dest=ip:port
state=TCP_ESTABLISHED
2. tcp_send_reset: skbaddr=000...000 skaddr=XXX src=ip:port dest=ip:port
state=UNKNOWN
Note:
1) UNKNOWN means we cannot extract the right information from skb.
2) skbaddr/skaddr could be 0

Signed-off-by: Jason Xing <kernelxing@tencent.com>
---
 include/trace/events/tcp.h | 39 ++++++++++++++++++++++++++++++++++++--
 net/ipv4/tcp_ipv4.c        |  4 ++--
 net/ipv6/tcp_ipv6.c        |  3 ++-
 3 files changed, 41 insertions(+), 5 deletions(-)

diff --git a/include/trace/events/tcp.h b/include/trace/events/tcp.h
index 2495a1d579be..a13eb2147a02 100644
--- a/include/trace/events/tcp.h
+++ b/include/trace/events/tcp.h
@@ -107,11 +107,46 @@ DEFINE_EVENT(tcp_event_sk_skb, tcp_retransmit_skb,
  * skb of trace_tcp_send_reset is the skb that caused RST. In case of
  * active reset, skb should be NULL
  */
-DEFINE_EVENT(tcp_event_sk_skb, tcp_send_reset,
+TRACE_EVENT(tcp_send_reset,
 
 	TP_PROTO(const struct sock *sk, const struct sk_buff *skb),
 
-	TP_ARGS(sk, skb)
+	TP_ARGS(sk, skb),
+
+	TP_STRUCT__entry(
+		__field(const void *, skbaddr)
+		__field(const void *, skaddr)
+		__field(int, state)
+		__array(__u8, saddr, sizeof(struct sockaddr_in6))
+		__array(__u8, daddr, sizeof(struct sockaddr_in6))
+	),
+
+	TP_fast_assign(
+		__entry->skbaddr = skb;
+		__entry->skaddr = sk;
+		/* Zero means unknown state. */
+		__entry->state = sk ? sk->sk_state : 0;
+
+		memset(__entry->saddr, 0, sizeof(struct sockaddr_in6));
+		memset(__entry->daddr, 0, sizeof(struct sockaddr_in6));
+
+		if (sk && sk_fullsock(sk)) {
+			const struct inet_sock *inet = inet_sk(sk);
+
+			TP_STORE_ADDR_PORTS(__entry, inet, sk);
+		} else {
+			/*
+			 * We should reverse the 4-tuple of skb, so later
+			 * it can print the right flow direction of rst.
+			 */
+			TP_STORE_ADDR_PORTS_SKB(skb, entry->daddr, entry->saddr);
+		}
+	),
+
+	TP_printk("skbaddr=%p skaddr=%p src=%pISpc dest=%pISpc state=%s",
+		  __entry->skbaddr, __entry->skaddr,
+		  __entry->saddr, __entry->daddr,
+		  __entry->state ? show_tcp_state_name(__entry->state) : "UNKNOWN")
 );
 
 /*
diff --git a/net/ipv4/tcp_ipv4.c b/net/ipv4/tcp_ipv4.c
index a22ee5838751..d5c4a969c066 100644
--- a/net/ipv4/tcp_ipv4.c
+++ b/net/ipv4/tcp_ipv4.c
@@ -868,10 +868,10 @@ static void tcp_v4_send_reset(const struct sock *sk, struct sk_buff *skb)
 	 */
 	if (sk) {
 		arg.bound_dev_if = sk->sk_bound_dev_if;
-		if (sk_fullsock(sk))
-			trace_tcp_send_reset(sk, skb);
 	}
 
+	trace_tcp_send_reset(sk, skb);
+
 	BUILD_BUG_ON(offsetof(struct sock, sk_bound_dev_if) !=
 		     offsetof(struct inet_timewait_sock, tw_bound_dev_if));
 
diff --git a/net/ipv6/tcp_ipv6.c b/net/ipv6/tcp_ipv6.c
index 3f4cba49e9ee..8e9c59b6c00c 100644
--- a/net/ipv6/tcp_ipv6.c
+++ b/net/ipv6/tcp_ipv6.c
@@ -1113,7 +1113,6 @@ static void tcp_v6_send_reset(const struct sock *sk, struct sk_buff *skb)
 	if (sk) {
 		oif = sk->sk_bound_dev_if;
 		if (sk_fullsock(sk)) {
-			trace_tcp_send_reset(sk, skb);
 			if (inet6_test_bit(REPFLOW, sk))
 				label = ip6_flowlabel(ipv6h);
 			priority = READ_ONCE(sk->sk_priority);
@@ -1129,6 +1128,8 @@ static void tcp_v6_send_reset(const struct sock *sk, struct sk_buff *skb)
 			label = ip6_flowlabel(ipv6h);
 	}
 
+	trace_tcp_send_reset(sk, skb);
+
 	tcp_v6_send_response(sk, skb, seq, ack_seq, 0, 0, 0, oif, 1,
 			     ipv6_get_dsfield(ipv6h), label, priority, txhash,
 			     &key);
-- 
2.37.3

[PATCH net-next v2 3/3] tcp: add location into reset trace process

[Jason Xing]

From: Jason Xing <kernelxing@tencent.com>

In addition to knowing the 4-tuple of the flow which generates RST,
the reason why it does so is very important because we have some
cases where the RST should be sent and have no clue which one
exactly.

Adding location of reset process can help us more, like what
trace_kfree_skb does.

Signed-off-by: Jason Xing <kernelxing@tencent.com>
---
 include/trace/events/tcp.h | 14 ++++++++++----
 net/ipv4/tcp_ipv4.c        |  2 +-
 net/ipv4/tcp_output.c      |  2 +-
 net/ipv6/tcp_ipv6.c        |  2 +-
 4 files changed, 13 insertions(+), 7 deletions(-)

diff --git a/include/trace/events/tcp.h b/include/trace/events/tcp.h
index a13eb2147a02..8f6c1a07503c 100644
--- a/include/trace/events/tcp.h
+++ b/include/trace/events/tcp.h
@@ -109,13 +109,17 @@ DEFINE_EVENT(tcp_event_sk_skb, tcp_retransmit_skb,
  */
 TRACE_EVENT(tcp_send_reset,
 
-	TP_PROTO(const struct sock *sk, const struct sk_buff *skb),
+	TP_PROTO(
+		const struct sock *sk,
+		const struct sk_buff *skb,
+		void *location),
 
-	TP_ARGS(sk, skb),
+	TP_ARGS(sk, skb, location),
 
 	TP_STRUCT__entry(
 		__field(const void *, skbaddr)
 		__field(const void *, skaddr)
+		__field(void *, location)
 		__field(int, state)
 		__array(__u8, saddr, sizeof(struct sockaddr_in6))
 		__array(__u8, daddr, sizeof(struct sockaddr_in6))
@@ -141,12 +145,14 @@ TRACE_EVENT(tcp_send_reset,
 			 */
 			TP_STORE_ADDR_PORTS_SKB(skb, entry->daddr, entry->saddr);
 		}
+		__entry->location = location;
 	),
 
-	TP_printk("skbaddr=%p skaddr=%p src=%pISpc dest=%pISpc state=%s",
+	TP_printk("skbaddr=%p skaddr=%p src=%pISpc dest=%pISpc state=%s location=%pS",
 		  __entry->skbaddr, __entry->skaddr,
 		  __entry->saddr, __entry->daddr,
-		  __entry->state ? show_tcp_state_name(__entry->state) : "UNKNOWN")
+		  __entry->state ? show_tcp_state_name(__entry->state) : "UNKNOWN",
+		  __entry->location)
 );
 
 /*
diff --git a/net/ipv4/tcp_ipv4.c b/net/ipv4/tcp_ipv4.c
index d5c4a969c066..fec54cfc4fb3 100644
--- a/net/ipv4/tcp_ipv4.c
+++ b/net/ipv4/tcp_ipv4.c
@@ -870,7 +870,7 @@ static void tcp_v4_send_reset(const struct sock *sk, struct sk_buff *skb)
 		arg.bound_dev_if = sk->sk_bound_dev_if;
 	}
 
-	trace_tcp_send_reset(sk, skb);
+	trace_tcp_send_reset(sk, skb,  __builtin_return_address(0));
 
 	BUILD_BUG_ON(offsetof(struct sock, sk_bound_dev_if) !=
 		     offsetof(struct inet_timewait_sock, tw_bound_dev_if));
diff --git a/net/ipv4/tcp_output.c b/net/ipv4/tcp_output.c
index e3167ad96567..fb613582817e 100644
--- a/net/ipv4/tcp_output.c
+++ b/net/ipv4/tcp_output.c
@@ -3608,7 +3608,7 @@ void tcp_send_active_reset(struct sock *sk, gfp_t priority)
 	/* skb of trace_tcp_send_reset() keeps the skb that caused RST,
 	 * skb here is different to the troublesome skb, so use NULL
 	 */
-	trace_tcp_send_reset(sk, NULL);
+	trace_tcp_send_reset(sk, NULL,  __builtin_return_address(0));
 }
 
 /* Send a crossed SYN-ACK during socket establishment.
diff --git a/net/ipv6/tcp_ipv6.c b/net/ipv6/tcp_ipv6.c
index 8e9c59b6c00c..7eba9c3d69f1 100644
--- a/net/ipv6/tcp_ipv6.c
+++ b/net/ipv6/tcp_ipv6.c
@@ -1128,7 +1128,7 @@ static void tcp_v6_send_reset(const struct sock *sk, struct sk_buff *skb)
 			label = ip6_flowlabel(ipv6h);
 	}
 
-	trace_tcp_send_reset(sk, skb);
+	trace_tcp_send_reset(sk, skb,  __builtin_return_address(0));
 
 	tcp_v6_send_response(sk, skb, seq, ack_seq, 0, 0, 0, oif, 1,
 			     ipv6_get_dsfield(ipv6h), label, priority, txhash,
-- 
2.37.3

Re: [PATCH net-next v2 0/3] tcp: make trace of reset logic complete

[Jakub Kicinski]

On Mon, 25 Mar 2024 14:28:28 +0800 Jason Xing wrote:
> Before this, we miss some cases where the TCP layer could send rst but
> we cannot trace it. So I decided to complete it :)
> 
> v2
> 1. fix spelling mistakes

Not only do you post it before we "officially" open net-next but
also ignoring the 24h wait period.

https://www.kernel.org/doc/html/next/process/maintainer-netdev.html#tl-dr

The main goal of the 24h rule is to stop people from bombarding us with
new versions for silly reasons.

You show know better than this, it's hardly your first contribution :(
-- 
pv-bot: 24h

Re: [PATCH net-next v2 0/3] tcp: make trace of reset logic complete

[Jason Xing]

On Tue, Mar 26, 2024 at 9:30 AM Jakub Kicinski <kuba@kernel.org> wrote:
>
> On Mon, 25 Mar 2024 14:28:28 +0800 Jason Xing wrote:
> > Before this, we miss some cases where the TCP layer could send rst but
> > we cannot trace it. So I decided to complete it :)
> >
> > v2
> > 1. fix spelling mistakes
>
> Not only do you post it before we "officially" open net-next but
> also ignoring the 24h wait period.
>
> https://www.kernel.org/doc/html/next/process/maintainer-netdev.html#tl-dr
>
> The main goal of the 24h rule is to stop people from bombarding us with
> new versions for silly reasons.

Sorry, I don't understand what you mean. I definitely know the rules.
But the first version of this patch series was sent about two weeks
ago (see link [1])

Yesterday, I posted two series to do two kinds of things. They are not
the same. Maybe you get me wrong :S

link [1]: https://patchwork.kernel.org/project/netdevbpf/list/?series=834178&state=*

Thanks,
Jason

>
> You show know better than this, it's hardly your first contribution :(
> --
> pv-bot: 24h

Re: [PATCH net-next v2 0/3] tcp: make trace of reset logic complete

[Jakub Kicinski]

On Tue, 26 Mar 2024 10:13:55 +0800 Jason Xing wrote:
> Yesterday, I posted two series to do two kinds of things. They are not
> the same. Maybe you get me wrong :S

Ah, my bad, sorry about that. I see that they are different now.
One is v1 the other v2, both targeting tcp tracing... Easy to miss
in the post merge window rush :(

Re: [PATCH net-next v2 0/3] tcp: make trace of reset logic complete

[Jason Xing]

On Tue, Mar 26, 2024 at 10:23 AM Jakub Kicinski <kuba@kernel.org> wrote:
>
> On Tue, 26 Mar 2024 10:13:55 +0800 Jason Xing wrote:
> > Yesterday, I posted two series to do two kinds of things. They are not
> > the same. Maybe you get me wrong :S
>
> Ah, my bad, sorry about that. I see that they are different now.

That's all right :)

> One is v1 the other v2, both targeting tcp tracing... Easy to miss
> in the post merge window rush :(

Yes, and thanks for the check :)

Re: [PATCH net-next v2 3/3] tcp: add location into reset trace process

[Paolo Abeni]

On Mon, 2024-03-25 at 14:28 +0800, Jason Xing wrote:
> From: Jason Xing <kernelxing@tencent.com>
> 
> In addition to knowing the 4-tuple of the flow which generates RST,
> the reason why it does so is very important because we have some
> cases where the RST should be sent and have no clue which one
> exactly.
> 
> Adding location of reset process can help us more, like what
> trace_kfree_skb does.
> 
> Signed-off-by: Jason Xing <kernelxing@tencent.com>
> ---
>  include/trace/events/tcp.h | 14 ++++++++++----
>  net/ipv4/tcp_ipv4.c        |  2 +-
>  net/ipv4/tcp_output.c      |  2 +-
>  net/ipv6/tcp_ipv6.c        |  2 +-
>  4 files changed, 13 insertions(+), 7 deletions(-)
> 
> diff --git a/include/trace/events/tcp.h b/include/trace/events/tcp.h
> index a13eb2147a02..8f6c1a07503c 100644
> --- a/include/trace/events/tcp.h
> +++ b/include/trace/events/tcp.h
> @@ -109,13 +109,17 @@ DEFINE_EVENT(tcp_event_sk_skb, tcp_retransmit_skb,
>   */
>  TRACE_EVENT(tcp_send_reset,
>  
> -	TP_PROTO(const struct sock *sk, const struct sk_buff *skb),
> +	TP_PROTO(
> +		const struct sock *sk,
> +		const struct sk_buff *skb,
> +		void *location),

Very minor nit: the above lines should be aligned with the open
bracket.

No need to repost just for this, but let's wait for Eric's feedback.

Cheers,

Paolo

Re: [PATCH net-next v2 3/3] tcp: add location into reset trace process

[Jakub Kicinski]

On Tue, 26 Mar 2024 12:08:01 +0100 Paolo Abeni wrote:
> > -	TP_PROTO(const struct sock *sk, const struct sk_buff *skb),
> > +	TP_PROTO(
> > +		const struct sock *sk,
> > +		const struct sk_buff *skb,
> > +		void *location),  
> 
> Very minor nit: the above lines should be aligned with the open
> bracket.

Yes, and a very odd way of breaking it up. Empty line after ( but
) not on a separate line.

> No need to repost just for this, but let's wait for Eric's feedback.

Erring on the side of caution I'd read this:
https://lore.kernel.org/all/CANn89iKK-qPhQ91Sq8rR_=KDWajnY2=Et2bUjDsgoQK4wxFOHw@mail.gmail.com/
as lukewarm towards tp changes. Please repost if you think otherwise
(with the formatting fixed)
-- 
pw-bot: cr

Re: [PATCH net-next v2 3/3] tcp: add location into reset trace process

[Jason Xing]

On Fri, Mar 29, 2024 at 9:15 AM Jakub Kicinski <kuba@kernel.org> wrote:
>
> On Tue, 26 Mar 2024 12:08:01 +0100 Paolo Abeni wrote:
> > > -   TP_PROTO(const struct sock *sk, const struct sk_buff *skb),
> > > +   TP_PROTO(
> > > +           const struct sock *sk,
> > > +           const struct sk_buff *skb,
> > > +           void *location),
> >
> > Very minor nit: the above lines should be aligned with the open
> > bracket.
>
> Yes, and a very odd way of breaking it up. Empty line after ( but
> ) not on a separate line.

After I blamed the history, maybe I should follow the format like
TRACE_EVENT(netfs_read)?

>
> > No need to repost just for this, but let's wait for Eric's feedback.
>
> Erring on the side of caution I'd read this:
> https://lore.kernel.org/all/CANn89iKK-qPhQ91Sq8rR_=KDWajnY2=Et2bUjDsgoQK4wxFOHw@mail.gmail.com/
> as lukewarm towards tp changes. Please repost if you think otherwise
> (with the formatting fixed)

Yes, I will repost it. I'm not introducing a controversial new tracepoint.

This patch is not only about whether we should use 'old-way' tracing
but about the tracepoint of this tcp reset that is not complete. Some
admins could use bpf to capture RST behaviours through hooking this
tracepoint which is not right currently apparently.

Besides, I simply tested the performance between using tracing and bpf
to monitor the fast path (like __tcp_transmit_skb()) on my loopback. I
saw at least 12% degradation with BPF used. So the advantage of trace
is obvious even though nowadays it is considered as an old school
method.

Thanks,
Jason

> --
> pw-bot: cr