[Patch net-next 00/13] net: add more tracepoints to TCP/IP stack

[Patch net-next 00/13] net: add more tracepoints to TCP/IP stack

[Cong Wang]

From: Cong Wang <cong.wang@bytedance.com>

This patchset adds 12 more tracepoints to TCP/IP stack, both
IPv4 and IPv6. The goal is to trace skb in different layers
and to measure the latency of each layer.

We only add information we need to each trace point. If any other
information is needed, it is easy to extend without breaking ABI,
see commit 3dd344ea84e1 ("net: tracepoint: exposing sk_family in all
tcp:tracepoints").

And similar to trace_qdisc_enqueue(), we only intend to trace
success cases, because most (if not all) failure cases can be traced
via kfree_skb() even if they are really interesting.

Lastly, per previous discussion, trace ring buffer is only accessible
to privileged users, it is safe to use a real kernel address with %px.

Qitao Xu (13):
  net: introduce a new header file include/trace/events/ip.h
  ipv4: introduce tracepoint trace_ip_queue_xmit()
  tcp: introduce tracepoint trace_tcp_transmit_skb()
  udp: introduce tracepoint trace_udp_send_skb()
  udp: introduce tracepoint trace_udp_v6_send_skb()
  ipv4: introduce tracepoint trace_ip_rcv()
  ipv6: introduce tracepoint trace_ipv6_rcv()
  ipv4: introduce tracepoint trace_ip_local_deliver_finish()
  udp: introduce tracepoint trace_udp_rcv()
  ipv6: introduce tracepoint trace_udpv6_rcv()
  tcp: introduce tracepoint trace_tcp_v4_rcv()
  ipv6: introduce tracepoint trace_tcp_v6_rcv()
  sock: introduce tracepoint trace_sk_data_ready()

 include/trace/events/ip.h   | 140 ++++++++++++++++++++++++++++++++++++
 include/trace/events/sock.h |  19 +++++
 include/trace/events/tcp.h  |  27 ++++++-
 include/trace/events/udp.h  |  74 +++++++++++++++++++
 net/core/net-traces.c       |   7 ++
 net/ipv4/ip_input.c         |   9 ++-
 net/ipv4/ip_output.c        |  10 ++-
 net/ipv4/tcp_input.c        |   8 ++-
 net/ipv4/tcp_ipv4.c         |   2 +
 net/ipv4/tcp_output.c       |   8 ++-
 net/ipv4/udp.c              |  17 ++++-
 net/ipv6/ip6_input.c        |   5 +-
 net/ipv6/tcp_ipv6.c         |   3 +
 net/ipv6/udp.c              |   9 ++-
 14 files changed, 327 insertions(+), 11 deletions(-)
 create mode 100644 include/trace/events/ip.h

-- 
2.27.0

[Patch net-next 01/13] net: introduce a new header file include/trace/events/ip.h

[Cong Wang]

From: Qitao Xu <qitao.xu@bytedance.com>

Header file include/trace/events/ip.h is introduced to define
IP/IPv6 layer tracepoints.

Reviewed-by: Cong Wang <cong.wang@bytedance.com>
Signed-off-by: Qitao Xu <qitao.xu@bytedance.com>
---
 include/trace/events/ip.h | 47 +++++++++++++++++++++++++++++++++++++++
 net/core/net-traces.c     |  1 +
 2 files changed, 48 insertions(+)
 create mode 100644 include/trace/events/ip.h

diff --git a/include/trace/events/ip.h b/include/trace/events/ip.h
new file mode 100644
index 000000000000..008f821ebc50
--- /dev/null
+++ b/include/trace/events/ip.h
@@ -0,0 +1,47 @@
+/* SPDX-License-Identifier: GPL-2.0 */
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM ip
+
+#if !defined(_TRACE_IP_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_IP_H
+
+#include <linux/ipv6.h>
+#include <linux/tcp.h>
+#include <linux/tracepoint.h>
+#include <net/ipv6.h>
+#include <net/tcp.h>
+#include <linux/sock_diag.h>
+
+#define TP_STORE_V4MAPPED(__entry, saddr, daddr)		\
+	do {							\
+		struct in6_addr *pin6;				\
+								\
+		pin6 = (struct in6_addr *)__entry->saddr_v6;	\
+		ipv6_addr_set_v4mapped(saddr, pin6);		\
+		pin6 = (struct in6_addr *)__entry->daddr_v6;	\
+		ipv6_addr_set_v4mapped(daddr, pin6);		\
+	} while (0)
+
+#if IS_ENABLED(CONFIG_IPV6)
+#define TP_STORE_ADDRS(__entry, saddr, daddr, saddr6, daddr6)		\
+	do {								\
+		if (sk->sk_family == AF_INET6) {			\
+			struct in6_addr *pin6;				\
+									\
+			pin6 = (struct in6_addr *)__entry->saddr_v6;	\
+			*pin6 = saddr6;					\
+			pin6 = (struct in6_addr *)__entry->daddr_v6;	\
+			*pin6 = daddr6;					\
+		} else {						\
+			TP_STORE_V4MAPPED(__entry, saddr, daddr);	\
+		}							\
+	} while (0)
+#else
+#define TP_STORE_ADDRS(__entry, saddr, daddr, saddr6, daddr6)	\
+	TP_STORE_V4MAPPED(__entry, saddr, daddr)
+#endif
+
+#endif /* _TRACE_IP_H */
+
+/* This part must be outside protection */
+#include <trace/define_trace.h>
diff --git a/net/core/net-traces.c b/net/core/net-traces.c
index c40cd8dd75c7..e1bd46076ad0 100644
--- a/net/core/net-traces.c
+++ b/net/core/net-traces.c
@@ -35,6 +35,7 @@
 #include <trace/events/tcp.h>
 #include <trace/events/fib.h>
 #include <trace/events/qdisc.h>
+#include <trace/events/ip.h>
 #if IS_ENABLED(CONFIG_BRIDGE)
 #include <trace/events/bridge.h>
 EXPORT_TRACEPOINT_SYMBOL_GPL(br_fdb_add);
-- 
2.27.0

[Patch net-next 02/13] ipv4: introduce tracepoint trace_ip_queue_xmit()

[Cong Wang]

From: Qitao Xu <qitao.xu@bytedance.com>

Tracepoint trace_ip_queue_xmit() is introduced to trace skb
at the entrance of IP layer on TX side.

Reviewed-by: Cong Wang <cong.wang@bytedance.com>
Signed-off-by: Qitao Xu <qitao.xu@bytedance.com>
---
 include/trace/events/ip.h | 42 +++++++++++++++++++++++++++++++++++++++
 net/ipv4/ip_output.c      | 10 +++++++++-
 2 files changed, 51 insertions(+), 1 deletion(-)

diff --git a/include/trace/events/ip.h b/include/trace/events/ip.h
index 008f821ebc50..553ae7276732 100644
--- a/include/trace/events/ip.h
+++ b/include/trace/events/ip.h
@@ -41,6 +41,48 @@
 	TP_STORE_V4MAPPED(__entry, saddr, daddr)
 #endif
 
+TRACE_EVENT(ip_queue_xmit,
+
+	TP_PROTO(const struct sock *sk, const struct sk_buff *skb),
+
+	TP_ARGS(sk, skb),
+
+	TP_STRUCT__entry(
+		__field(const void *, skbaddr)
+		__field(const void *, skaddr)
+		__field(__u16, sport)
+		__field(__u16, dport)
+		__array(__u8, saddr, 4)
+		__array(__u8, daddr, 4)
+		__array(__u8, saddr_v6, 16)
+		__array(__u8, daddr_v6, 16)
+	),
+
+	TP_fast_assign(
+		struct inet_sock *inet = inet_sk(sk);
+		__be32 *p32;
+
+		__entry->skbaddr = skb;
+		__entry->skaddr = sk;
+
+		__entry->sport = ntohs(inet->inet_sport);
+		__entry->dport = ntohs(inet->inet_dport);
+
+		p32 = (__be32 *) __entry->saddr;
+		*p32 = inet->inet_saddr;
+
+		p32 = (__be32 *) __entry->daddr;
+		*p32 =  inet->inet_daddr;
+
+		TP_STORE_ADDRS(__entry, inet->inet_saddr, inet->inet_daddr,
+			      sk->sk_v6_rcv_saddr, sk->sk_v6_daddr);
+	),
+
+	TP_printk("sport=%hu dport=%hu saddr=%pI4 daddr=%pI4 saddrv6=%pI6c daddrv6=%pI6c skbaddr=%px",
+		  __entry->sport, __entry->dport, __entry->saddr, __entry->daddr,
+		  __entry->saddr_v6, __entry->daddr_v6, __entry->skbaddr)
+);
+
 #endif /* _TRACE_IP_H */
 
 /* This part must be outside protection */
diff --git a/net/ipv4/ip_output.c b/net/ipv4/ip_output.c
index 6b04a88466b2..dcf94059112e 100644
--- a/net/ipv4/ip_output.c
+++ b/net/ipv4/ip_output.c
@@ -82,6 +82,7 @@
 #include <linux/netfilter_bridge.h>
 #include <linux/netlink.h>
 #include <linux/tcp.h>
+#include <trace/events/ip.h>
 
 static int
 ip_fragment(struct net *net, struct sock *sk, struct sk_buff *skb,
@@ -536,7 +537,14 @@ EXPORT_SYMBOL(__ip_queue_xmit);
 
 int ip_queue_xmit(struct sock *sk, struct sk_buff *skb, struct flowi *fl)
 {
-	return __ip_queue_xmit(sk, skb, fl, inet_sk(sk)->tos);
+	int ret;
+
+	ret = __ip_queue_xmit(sk, skb, fl, inet_sk(sk)->tos);
+	if (!ret)
+		trace_ip_queue_xmit(sk, skb);
+
+	return ret;
+
 }
 EXPORT_SYMBOL(ip_queue_xmit);
 
-- 
2.27.0

[Patch net-next 03/13] tcp: introduce tracepoint trace_tcp_transmit_skb()

[Cong Wang]

From: Qitao Xu <qitao.xu@bytedance.com>

Tracepoint trace_tcp_transmit_skb() is introduced to trace skb
at the exit of TCP layer on TX side.

Reviewed-by: Cong Wang <cong.wang@bytedance.com>
Signed-off-by: Qitao Xu <qitao.xu@bytedance.com>
---
 include/trace/events/tcp.h | 11 +++++++++--
 net/ipv4/tcp_output.c      |  8 +++++++-
 2 files changed, 16 insertions(+), 3 deletions(-)

diff --git a/include/trace/events/tcp.h b/include/trace/events/tcp.h
index 521059d8dc0a..6147528d93ba 100644
--- a/include/trace/events/tcp.h
+++ b/include/trace/events/tcp.h
@@ -88,11 +88,18 @@ DECLARE_EVENT_CLASS(tcp_event_sk_skb,
 			      sk->sk_v6_rcv_saddr, sk->sk_v6_daddr);
 	),
 
-	TP_printk("family=%s sport=%hu dport=%hu saddr=%pI4 daddr=%pI4 saddrv6=%pI6c daddrv6=%pI6c state=%s",
+	TP_printk("family=%s sport=%hu dport=%hu saddr=%pI4 daddr=%pI4 saddrv6=%pI6c daddrv6=%pI6c state=%s skbaddr=%px",
 		  show_family_name(__entry->family),
 		  __entry->sport, __entry->dport, __entry->saddr, __entry->daddr,
 		  __entry->saddr_v6, __entry->daddr_v6,
-		  show_tcp_state_name(__entry->state))
+		  show_tcp_state_name(__entry->state), __entry->skbaddr)
+);
+
+DEFINE_EVENT(tcp_event_sk_skb, tcp_transmit_skb,
+
+	TP_PROTO(const struct sock *sk, const struct sk_buff *skb),
+
+	TP_ARGS(sk, skb)
 );
 
 DEFINE_EVENT(tcp_event_sk_skb, tcp_retransmit_skb,
diff --git a/net/ipv4/tcp_output.c b/net/ipv4/tcp_output.c
index 29553fce8502..628b28332851 100644
--- a/net/ipv4/tcp_output.c
+++ b/net/ipv4/tcp_output.c
@@ -1420,8 +1420,14 @@ static int __tcp_transmit_skb(struct sock *sk, struct sk_buff *skb,
 static int tcp_transmit_skb(struct sock *sk, struct sk_buff *skb, int clone_it,
 			    gfp_t gfp_mask)
 {
-	return __tcp_transmit_skb(sk, skb, clone_it, gfp_mask,
+	int ret;
+
+	ret = __tcp_transmit_skb(sk, skb, clone_it, gfp_mask,
 				  tcp_sk(sk)->rcv_nxt);
+	if (!ret)
+		trace_tcp_transmit_skb(sk, skb);
+	return ret;
+
 }
 
 /* This routine just queues the buffer for sending.
-- 
2.27.0

[Patch net-next 04/13] udp: introduce tracepoint trace_udp_send_skb()

[Cong Wang]

From: Qitao Xu <qitao.xu@bytedance.com>

Tracepoint trace_udp_send_skb() is introduced to trace skb
at the exit of UDP layer on TX side.

Reviewed-by: Cong Wang <cong.wang@bytedance.com>
Signed-off-by: Qitao Xu <qitao.xu@bytedance.com>
---
 include/trace/events/udp.h | 19 +++++++++++++++++++
 net/ipv4/udp.c             |  4 +++-
 2 files changed, 22 insertions(+), 1 deletion(-)

diff --git a/include/trace/events/udp.h b/include/trace/events/udp.h
index 336fe272889f..7babc1a11693 100644
--- a/include/trace/events/udp.h
+++ b/include/trace/events/udp.h
@@ -27,6 +27,25 @@ TRACE_EVENT(udp_fail_queue_rcv_skb,
 	TP_printk("rc=%d port=%hu", __entry->rc, __entry->lport)
 );
 
+TRACE_EVENT(udp_send_skb,
+
+	TP_PROTO(const struct sock *sk, const struct sk_buff *skb),
+
+	TP_ARGS(sk, skb),
+
+	TP_STRUCT__entry(
+		__field(const void *, skaddr)
+		__field(const void *, skbaddr)
+	),
+
+	TP_fast_assign(
+		__entry->skaddr = sk;
+		__entry->skbaddr = skb;
+	),
+
+	TP_printk("skaddr=%px, skbaddr=%px", __entry->skaddr, __entry->skbaddr)
+);
+
 #endif /* _TRACE_UDP_H */
 
 /* This part must be outside protection */
diff --git a/net/ipv4/udp.c b/net/ipv4/udp.c
index 1a742b710e54..daa618465a1d 100644
--- a/net/ipv4/udp.c
+++ b/net/ipv4/udp.c
@@ -970,9 +970,11 @@ static int udp_send_skb(struct sk_buff *skb, struct flowi4 *fl4,
 				      UDP_MIB_SNDBUFERRORS, is_udplite);
 			err = 0;
 		}
-	} else
+	} else {
 		UDP_INC_STATS(sock_net(sk),
 			      UDP_MIB_OUTDATAGRAMS, is_udplite);
+		trace_udp_send_skb(sk, skb);
+	}
 	return err;
 }
 
-- 
2.27.0

[Patch net-next 05/13] udp: introduce tracepoint trace_udp_v6_send_skb()

[Cong Wang]

From: Qitao Xu <qitao.xu@bytedance.com>

Tracepoint trace_udp_v6_send_skb() is introduced to trace skb
at the exit of UDPv6 layer on TX side.

Reviewed-by: Cong Wang <cong.wang@bytedance.com>
Signed-off-by: Qitao Xu <qitao.xu@bytedance.com>
---
 include/trace/events/udp.h | 21 +++++++++++++++++++++
 net/core/net-traces.c      |  3 +++
 net/ipv6/udp.c             |  2 ++
 3 files changed, 26 insertions(+)

diff --git a/include/trace/events/udp.h b/include/trace/events/udp.h
index 7babc1a11693..6af4b402237a 100644
--- a/include/trace/events/udp.h
+++ b/include/trace/events/udp.h
@@ -46,6 +46,27 @@ TRACE_EVENT(udp_send_skb,
 	TP_printk("skaddr=%px, skbaddr=%px", __entry->skaddr, __entry->skbaddr)
 );
 
+#if IS_ENABLED(CONFIG_IPV6)
+TRACE_EVENT(udp_v6_send_skb,
+
+	TP_PROTO(const struct sock *sk, const struct sk_buff *skb),
+
+	TP_ARGS(sk, skb),
+
+	TP_STRUCT__entry(
+		__field(const void *, skaddr)
+		__field(const void *, skbaddr)
+	),
+
+	TP_fast_assign(
+		__entry->skaddr = sk;
+		__entry->skbaddr = skb;
+	),
+
+	TP_printk("skaddr=%px, skbaddr=%px", __entry->skaddr, __entry->skbaddr)
+);
+#endif
+
 #endif /* _TRACE_UDP_H */
 
 /* This part must be outside protection */
diff --git a/net/core/net-traces.c b/net/core/net-traces.c
index e1bd46076ad0..0aca299dfb55 100644
--- a/net/core/net-traces.c
+++ b/net/core/net-traces.c
@@ -62,3 +62,6 @@ EXPORT_TRACEPOINT_SYMBOL_GPL(napi_poll);
 
 EXPORT_TRACEPOINT_SYMBOL_GPL(tcp_send_reset);
 EXPORT_TRACEPOINT_SYMBOL_GPL(tcp_bad_csum);
+#if IS_ENABLED(CONFIG_IPV6)
+EXPORT_TRACEPOINT_SYMBOL_GPL(udp_v6_send_skb);
+#endif
diff --git a/net/ipv6/udp.c b/net/ipv6/udp.c
index c5e15e94bb00..84895ca40e5c 100644
--- a/net/ipv6/udp.c
+++ b/net/ipv6/udp.c
@@ -52,6 +52,7 @@
 #include <linux/proc_fs.h>
 #include <linux/seq_file.h>
 #include <trace/events/skb.h>
+#include <trace/events/udp.h>
 #include "udp_impl.h"
 
 static u32 udp6_ehashfn(const struct net *net,
@@ -1255,6 +1256,7 @@ static int udp_v6_send_skb(struct sk_buff *skb, struct flowi6 *fl6,
 	} else {
 		UDP6_INC_STATS(sock_net(sk),
 			       UDP_MIB_OUTDATAGRAMS, is_udplite);
+		trace_udp_v6_send_skb(sk, skb);
 	}
 	return err;
 }
-- 
2.27.0

[Patch net-next 06/13] ipv4: introduce tracepoint trace_ip_rcv()

[Cong Wang]

From: Qitao Xu <qitao.xu@bytedance.com>

Tracepoint trace_ip_rcv() is introduced to trace skb at the
entrance of IP layer on RX side.

Reviewed-by: Cong Wang <cong.wang@bytedance.com>
Signed-off-by: Qitao Xu <qitao.xu@bytedance.com>
---
 include/trace/events/ip.h | 16 ++++++++++++++++
 net/ipv4/ip_input.c       |  2 ++
 2 files changed, 18 insertions(+)

diff --git a/include/trace/events/ip.h b/include/trace/events/ip.h
index 553ae7276732..20ee1a81405c 100644
--- a/include/trace/events/ip.h
+++ b/include/trace/events/ip.h
@@ -83,6 +83,22 @@ TRACE_EVENT(ip_queue_xmit,
 		  __entry->saddr_v6, __entry->daddr_v6, __entry->skbaddr)
 );
 
+TRACE_EVENT(ip_rcv,
+	TP_PROTO(const struct sk_buff *skb),
+
+	TP_ARGS(skb),
+
+	TP_STRUCT__entry(
+		__field(const void *, skbaddr)
+	),
+
+	TP_fast_assign(
+		__entry->skbaddr = skb;
+	),
+
+	TP_printk("skbaddr=%px", __entry->skbaddr)
+);
+
 #endif /* _TRACE_IP_H */
 
 /* This part must be outside protection */
diff --git a/net/ipv4/ip_input.c b/net/ipv4/ip_input.c
index 3a025c011971..2eb7a0cbc0d3 100644
--- a/net/ipv4/ip_input.c
+++ b/net/ipv4/ip_input.c
@@ -141,6 +141,7 @@
 #include <linux/mroute.h>
 #include <linux/netlink.h>
 #include <net/dst_metadata.h>
+#include <trace/events/ip.h>
 
 /*
  *	Process Router Attention IP option (RFC 2113)
@@ -400,6 +401,7 @@ static int ip_rcv_finish_core(struct net *net, struct sock *sk,
 			goto drop;
 	}
 
+	trace_ip_rcv(skb);
 	return NET_RX_SUCCESS;
 
 drop:
-- 
2.27.0

[Patch net-next 07/13] ipv6: introduce tracepoint trace_ipv6_rcv()

[Cong Wang]

From: Qitao Xu <qitao.xu@bytedance.com>

Tracepoint trace_ipv6_rcv() is introduced to trace skb at the
entrance of IPv6 layer on RX side.

Reviewed-by: Cong Wang <cong.wang@bytedance.com>
Signed-off-by: Qitao Xu <qitao.xu@bytedance.com>
---
 include/trace/events/ip.h | 18 ++++++++++++++++++
 net/core/net-traces.c     |  1 +
 net/ipv6/ip6_input.c      |  5 ++++-
 3 files changed, 23 insertions(+), 1 deletion(-)

diff --git a/include/trace/events/ip.h b/include/trace/events/ip.h
index 20ee1a81405c..6cd0907728ce 100644
--- a/include/trace/events/ip.h
+++ b/include/trace/events/ip.h
@@ -99,6 +99,24 @@ TRACE_EVENT(ip_rcv,
 	TP_printk("skbaddr=%px", __entry->skbaddr)
 );
 
+#if IS_ENABLED(CONFIG_IPV6)
+TRACE_EVENT(ipv6_rcv,
+	TP_PROTO(const struct sk_buff *skb),
+
+	TP_ARGS(skb),
+
+	TP_STRUCT__entry(
+		__field(const void *, skbaddr)
+	),
+
+	TP_fast_assign(
+		__entry->skbaddr = skb;
+	),
+
+	TP_printk("skbaddr=%px", __entry->skbaddr)
+);
+#endif
+
 #endif /* _TRACE_IP_H */
 
 /* This part must be outside protection */
diff --git a/net/core/net-traces.c b/net/core/net-traces.c
index 0aca299dfb55..de5a13ae933c 100644
--- a/net/core/net-traces.c
+++ b/net/core/net-traces.c
@@ -64,4 +64,5 @@ EXPORT_TRACEPOINT_SYMBOL_GPL(tcp_send_reset);
 EXPORT_TRACEPOINT_SYMBOL_GPL(tcp_bad_csum);
 #if IS_ENABLED(CONFIG_IPV6)
 EXPORT_TRACEPOINT_SYMBOL_GPL(udp_v6_send_skb);
+EXPORT_TRACEPOINT_SYMBOL_GPL(ipv6_rcv);
 #endif
diff --git a/net/ipv6/ip6_input.c b/net/ipv6/ip6_input.c
index 80256717868e..8ce23ef5f011 100644
--- a/net/ipv6/ip6_input.c
+++ b/net/ipv6/ip6_input.c
@@ -44,6 +44,7 @@
 #include <net/xfrm.h>
 #include <net/inet_ecn.h>
 #include <net/dst_metadata.h>
+#include <trace/events/ip.h>
 
 INDIRECT_CALLABLE_DECLARE(void tcp_v6_early_demux(struct sk_buff *));
 static void ip6_rcv_finish_core(struct net *net, struct sock *sk,
@@ -59,8 +60,10 @@ static void ip6_rcv_finish_core(struct net *net, struct sock *sk,
 			INDIRECT_CALL_2(edemux, tcp_v6_early_demux,
 					udp_v6_early_demux, skb);
 	}
-	if (!skb_valid_dst(skb))
+	if (!skb_valid_dst(skb)) {
+		trace_ipv6_rcv(skb);
 		ip6_route_input(skb);
+	}
 }
 
 int ip6_rcv_finish(struct net *net, struct sock *sk, struct sk_buff *skb)
-- 
2.27.0

[Patch net-next 08/13] ipv4: introduce tracepoint trace_ip_local_deliver_finish()

[Cong Wang]

From: Qitao Xu <qitao.xu@bytedance.com>

Tracepoint trace_ip_local_deliver_finish() is introduced to trace
skb at the exit of IP layer on RX side.

Reviewed-by: Cong Wang <cong.wang@bytedance.com>
Signed-off-by: Qitao Xu <qitao.xu@bytedance.com>
---
 include/trace/events/ip.h | 17 +++++++++++++++++
 net/ipv4/ip_input.c       |  7 ++++++-
 2 files changed, 23 insertions(+), 1 deletion(-)

diff --git a/include/trace/events/ip.h b/include/trace/events/ip.h
index 6cd0907728ce..9653bc3c7fa0 100644
--- a/include/trace/events/ip.h
+++ b/include/trace/events/ip.h
@@ -117,6 +117,23 @@ TRACE_EVENT(ipv6_rcv,
 );
 #endif
 
+TRACE_EVENT(ip_local_deliver_finish,
+
+	TP_PROTO(const struct sk_buff *skb),
+
+	TP_ARGS(skb),
+
+	TP_STRUCT__entry(
+		__field(const void *, skbaddr)
+	),
+
+	TP_fast_assign(
+		__entry->skbaddr = skb;
+	),
+
+	TP_printk("skbaddr=%px", __entry->skbaddr)
+);
+
 #endif /* _TRACE_IP_H */
 
 /* This part must be outside protection */
diff --git a/net/ipv4/ip_input.c b/net/ipv4/ip_input.c
index 2eb7a0cbc0d3..31c5c6903fff 100644
--- a/net/ipv4/ip_input.c
+++ b/net/ipv4/ip_input.c
@@ -244,15 +244,20 @@ int ip_local_deliver(struct sk_buff *skb)
 	 *	Reassemble IP fragments.
 	 */
 	struct net *net = dev_net(skb->dev);
+	int ret;
 
 	if (ip_is_fragment(ip_hdr(skb))) {
 		if (ip_defrag(net, skb, IP_DEFRAG_LOCAL_DELIVER))
 			return 0;
 	}
 
-	return NF_HOOK(NFPROTO_IPV4, NF_INET_LOCAL_IN,
+	ret = NF_HOOK(NFPROTO_IPV4, NF_INET_LOCAL_IN,
 		       net, NULL, skb, skb->dev, NULL,
 		       ip_local_deliver_finish);
+	if (!ret)
+		trace_ip_local_deliver_finish(skb);
+	return ret;
+
 }
 EXPORT_SYMBOL(ip_local_deliver);
 
-- 
2.27.0

[Patch net-next 09/13] udp: introduce tracepoint trace_udp_rcv()

[Cong Wang]

From: Qitao Xu <qitao.xu@bytedance.com>

Tracepoint trace_udp_rcv() is introduced to trace skb at
the entrance of UDP layer on RX side.

Reviewed-by: Cong Wang <cong.wang@bytedance.com>
Signed-off-by: Qitao Xu <qitao.xu@bytedance.com>
---
 include/trace/events/udp.h | 17 +++++++++++++++++
 net/ipv4/udp.c             |  8 +++++++-
 2 files changed, 24 insertions(+), 1 deletion(-)

diff --git a/include/trace/events/udp.h b/include/trace/events/udp.h
index 6af4b402237a..5008bdd546e8 100644
--- a/include/trace/events/udp.h
+++ b/include/trace/events/udp.h
@@ -27,6 +27,23 @@ TRACE_EVENT(udp_fail_queue_rcv_skb,
 	TP_printk("rc=%d port=%hu", __entry->rc, __entry->lport)
 );
 
+TRACE_EVENT(udp_rcv,
+
+	TP_PROTO(const struct sk_buff *skb),
+
+	TP_ARGS(skb),
+
+	TP_STRUCT__entry(
+		__field(const void *, skbaddr)
+	),
+
+	TP_fast_assign(
+		__entry->skbaddr = skb;
+	),
+
+	TP_printk("skbaddr=%px", __entry->skbaddr)
+);
+
 TRACE_EVENT(udp_send_skb,
 
 	TP_PROTO(const struct sock *sk, const struct sk_buff *skb),
diff --git a/net/ipv4/udp.c b/net/ipv4/udp.c
index daa618465a1d..4751a8f9acff 100644
--- a/net/ipv4/udp.c
+++ b/net/ipv4/udp.c
@@ -2617,7 +2617,13 @@ int udp_v4_early_demux(struct sk_buff *skb)
 
 int udp_rcv(struct sk_buff *skb)
 {
-	return __udp4_lib_rcv(skb, &udp_table, IPPROTO_UDP);
+	int ret;
+
+	ret = __udp4_lib_rcv(skb, &udp_table, IPPROTO_UDP);
+	if (!ret)
+		trace_udp_rcv(skb);
+	return ret;
+
 }
 
 void udp_destroy_sock(struct sock *sk)
-- 
2.27.0

[Patch net-next 10/13] ipv6: introduce tracepoint trace_udpv6_rcv()

[Cong Wang]

From: Qitao Xu <qitao.xu@bytedance.com>

Tracepoint trace_udpv6_rcv() is introduced to trace skb at
the entrance of UDPv6 layer on RX side.

Reviewed-by: Cong Wang <cong.wang@bytedance.com>
Signed-off-by: Qitao Xu <qitao.xu@bytedance.com>
---
 include/trace/events/udp.h | 17 +++++++++++++++++
 net/core/net-traces.c      |  1 +
 net/ipv6/udp.c             |  7 ++++++-
 3 files changed, 24 insertions(+), 1 deletion(-)

diff --git a/include/trace/events/udp.h b/include/trace/events/udp.h
index 5008bdd546e8..01e026a3f542 100644
--- a/include/trace/events/udp.h
+++ b/include/trace/events/udp.h
@@ -82,6 +82,23 @@ TRACE_EVENT(udp_v6_send_skb,
 
 	TP_printk("skaddr=%px, skbaddr=%px", __entry->skaddr, __entry->skbaddr)
 );
+
+TRACE_EVENT(udpv6_rcv,
+
+	TP_PROTO(const struct sk_buff *skb),
+
+	TP_ARGS(skb),
+
+	TP_STRUCT__entry(
+		__field(const void *, skbaddr)
+	),
+
+	TP_fast_assign(
+		__entry->skbaddr = skb;
+	),
+
+	TP_printk("skbaddr=%px", __entry->skbaddr)
+);
 #endif
 
 #endif /* _TRACE_UDP_H */
diff --git a/net/core/net-traces.c b/net/core/net-traces.c
index de5a13ae933c..83df315708ba 100644
--- a/net/core/net-traces.c
+++ b/net/core/net-traces.c
@@ -65,4 +65,5 @@ EXPORT_TRACEPOINT_SYMBOL_GPL(tcp_bad_csum);
 #if IS_ENABLED(CONFIG_IPV6)
 EXPORT_TRACEPOINT_SYMBOL_GPL(udp_v6_send_skb);
 EXPORT_TRACEPOINT_SYMBOL_GPL(ipv6_rcv);
+EXPORT_TRACEPOINT_SYMBOL_GPL(udpv6_rcv);
 #endif
diff --git a/net/ipv6/udp.c b/net/ipv6/udp.c
index 84895ca40e5c..1c8b36fe7218 100644
--- a/net/ipv6/udp.c
+++ b/net/ipv6/udp.c
@@ -1085,7 +1085,12 @@ INDIRECT_CALLABLE_SCOPE void udp_v6_early_demux(struct sk_buff *skb)
 
 INDIRECT_CALLABLE_SCOPE int udpv6_rcv(struct sk_buff *skb)
 {
-	return __udp6_lib_rcv(skb, &udp_table, IPPROTO_UDP);
+	int ret;
+
+	ret = __udp6_lib_rcv(skb, &udp_table, IPPROTO_UDP);
+	if (!ret)
+		trace_udpv6_rcv(skb);
+	return ret;
 }
 
 /*
-- 
2.27.0

[Patch net-next 11/13] tcp: introduce tracepoint trace_tcp_v4_rcv()

[Cong Wang]

From: Qitao Xu <qitao.xu@bytedance.com>

Tracepoint trace_tcp_v4_rcv() is introduced to trace skb at
the entrance of TCP layer on RX side.

Reviewed-by: Cong Wang <cong.wang@bytedance.com>
Signed-off-by: Qitao Xu <qitao.xu@bytedance.com>
---
 include/trace/events/tcp.h | 7 +++++++
 net/ipv4/tcp_ipv4.c        | 2 ++
 2 files changed, 9 insertions(+)

diff --git a/include/trace/events/tcp.h b/include/trace/events/tcp.h
index 6147528d93ba..adf84866dee9 100644
--- a/include/trace/events/tcp.h
+++ b/include/trace/events/tcp.h
@@ -109,6 +109,13 @@ DEFINE_EVENT(tcp_event_sk_skb, tcp_retransmit_skb,
 	TP_ARGS(sk, skb)
 );
 
+DEFINE_EVENT(tcp_event_sk_skb, tcp_v4_rcv,
+
+	TP_PROTO(const struct sock *sk, const struct sk_buff *skb),
+
+	TP_ARGS(sk, skb)
+);
+
 /*
  * skb of trace_tcp_send_reset is the skb that caused RST. In case of
  * active reset, skb should be NULL
diff --git a/net/ipv4/tcp_ipv4.c b/net/ipv4/tcp_ipv4.c
index 2e62e0d6373a..a0c4aa488659 100644
--- a/net/ipv4/tcp_ipv4.c
+++ b/net/ipv4/tcp_ipv4.c
@@ -2093,6 +2093,8 @@ int tcp_v4_rcv(struct sk_buff *skb)
 	bh_unlock_sock(sk);
 	if (skb_to_free)
 		__kfree_skb(skb_to_free);
+	if (!ret)
+		trace_tcp_v4_rcv(sk, skb);
 
 put_and_return:
 	if (refcounted)
-- 
2.27.0

[Patch net-next 12/13] ipv6: introduce tracepoint trace_tcp_v6_rcv()

[Cong Wang]

From: Qitao Xu <qitao.xu@bytedance.com>

Tracepoint trace_tcp_v6_rcv() is introduced to trace skb
at the entrance of TCPv6 on RX side.

Reviewed-by: Cong Wang <cong.wang@bytedance.com>
Signed-off-by: Qitao Xu <qitao.xu@bytedance.com>
---
 include/trace/events/tcp.h | 9 +++++++++
 net/core/net-traces.c      | 1 +
 net/ipv6/tcp_ipv6.c        | 3 +++
 3 files changed, 13 insertions(+)

diff --git a/include/trace/events/tcp.h b/include/trace/events/tcp.h
index adf84866dee9..f788ac43c4bf 100644
--- a/include/trace/events/tcp.h
+++ b/include/trace/events/tcp.h
@@ -116,6 +116,15 @@ DEFINE_EVENT(tcp_event_sk_skb, tcp_v4_rcv,
 	TP_ARGS(sk, skb)
 );
 
+#if IS_ENABLED(CONFIG_IPV6)
+DEFINE_EVENT(tcp_event_sk_skb, tcp_v6_rcv,
+
+	TP_PROTO(const struct sock *sk, const struct sk_buff *skb),
+
+	TP_ARGS(sk, skb)
+);
+#endif
+
 /*
  * skb of trace_tcp_send_reset is the skb that caused RST. In case of
  * active reset, skb should be NULL
diff --git a/net/core/net-traces.c b/net/core/net-traces.c
index 83df315708ba..e0840efe479a 100644
--- a/net/core/net-traces.c
+++ b/net/core/net-traces.c
@@ -66,4 +66,5 @@ EXPORT_TRACEPOINT_SYMBOL_GPL(tcp_bad_csum);
 EXPORT_TRACEPOINT_SYMBOL_GPL(udp_v6_send_skb);
 EXPORT_TRACEPOINT_SYMBOL_GPL(ipv6_rcv);
 EXPORT_TRACEPOINT_SYMBOL_GPL(udpv6_rcv);
+EXPORT_TRACEPOINT_SYMBOL_GPL(tcp_v6_rcv);
 #endif
diff --git a/net/ipv6/tcp_ipv6.c b/net/ipv6/tcp_ipv6.c
index 0ce52d46e4f8..eb9586d798b7 100644
--- a/net/ipv6/tcp_ipv6.c
+++ b/net/ipv6/tcp_ipv6.c
@@ -1765,6 +1765,9 @@ INDIRECT_CALLABLE_SCOPE int tcp_v6_rcv(struct sk_buff *skb)
 	bh_unlock_sock(sk);
 	if (skb_to_free)
 		__kfree_skb(skb_to_free);
+	if (!ret)
+		trace_tcp_v6_rcv(sk, skb);
+
 put_and_return:
 	if (refcounted)
 		sock_put(sk);
-- 
2.27.0

[Patch net-next 13/13] sock: introduce tracepoint trace_sk_data_ready()

[Cong Wang]

From: Qitao Xu <qitao.xu@bytedance.com>

Tracepoint trace_sk_data_ready is introduced to trace skb
at exit of socket layer on RX side. Here we only implement
it for UDP and TCP.

Reviewed-by: Cong Wang <cong.wang@bytedance.com>
Signed-off-by: Qitao Xu <qitao.xu@bytedance.com>
---
 include/trace/events/sock.h | 19 +++++++++++++++++++
 net/ipv4/tcp_input.c        |  8 +++++++-
 net/ipv4/udp.c              |  5 ++++-
 3 files changed, 30 insertions(+), 2 deletions(-)

diff --git a/include/trace/events/sock.h b/include/trace/events/sock.h
index 12c315782766..860d8b0f02c5 100644
--- a/include/trace/events/sock.h
+++ b/include/trace/events/sock.h
@@ -261,6 +261,25 @@ TRACE_EVENT(inet_sk_error_report,
 		  __entry->error)
 );
 
+TRACE_EVENT(sk_data_ready,
+
+	TP_PROTO(const struct sock *sk, const struct sk_buff *skb),
+
+	TP_ARGS(sk, skb),
+
+	TP_STRUCT__entry(
+		__field(const void *, skaddr)
+		__field(const void *, skbaddr)
+	),
+
+	TP_fast_assign(
+		__entry->skaddr = sk;
+		__entry->skbaddr = skb;
+	),
+
+	TP_printk("skaddr=%px, skbaddr=%px", __entry->skaddr, __entry->skbaddr)
+);
+
 #endif /* _TRACE_SOCK_H */
 
 /* This part must be outside protection */
diff --git a/net/ipv4/tcp_input.c b/net/ipv4/tcp_input.c
index 3f7bd7ae7d7a..16edb9d37529 100644
--- a/net/ipv4/tcp_input.c
+++ b/net/ipv4/tcp_input.c
@@ -77,6 +77,7 @@
 #include <asm/unaligned.h>
 #include <linux/errqueue.h>
 #include <trace/events/tcp.h>
+#include <trace/events/sock.h>
 #include <linux/jump_label_ratelimit.h>
 #include <net/busy_poll.h>
 #include <net/mptcp.h>
@@ -5034,6 +5035,8 @@ static void tcp_data_queue(struct sock *sk, struct sk_buff *skb)
 
 		tcp_fast_path_check(sk);
 
+		if (!sock_flag(sk, SOCK_DEAD))
+			trace_sk_data_ready(sk, skb);
 		if (eaten > 0)
 			kfree_skb_partial(skb, fragstolen);
 		if (!sock_flag(sk, SOCK_DEAD))
@@ -5601,8 +5604,10 @@ static void tcp_urg(struct sock *sk, struct sk_buff *skb, const struct tcphdr *t
 			if (skb_copy_bits(skb, ptr, &tmp, 1))
 				BUG();
 			tp->urg_data = TCP_URG_VALID | tmp;
-			if (!sock_flag(sk, SOCK_DEAD))
+			if (!sock_flag(sk, SOCK_DEAD)) {
+				trace_sk_data_ready(sk, skb);
 				sk->sk_data_ready(sk);
+			}
 		}
 	}
 }
@@ -5894,6 +5899,7 @@ void tcp_rcv_established(struct sock *sk, struct sk_buff *skb)
 
 			__tcp_ack_snd_check(sk, 0);
 no_ack:
+			trace_sk_data_ready(sk, skb);
 			if (eaten)
 				kfree_skb_partial(skb, fragstolen);
 			tcp_data_ready(sk);
diff --git a/net/ipv4/udp.c b/net/ipv4/udp.c
index 4751a8f9acff..b58cc943a862 100644
--- a/net/ipv4/udp.c
+++ b/net/ipv4/udp.c
@@ -108,6 +108,7 @@
 #include <linux/static_key.h>
 #include <linux/btf_ids.h>
 #include <trace/events/skb.h>
+#include <trace/events/sock.h>
 #include <net/busy_poll.h>
 #include "udp_impl.h"
 #include <net/sock_reuseport.h>
@@ -1579,8 +1580,10 @@ int __udp_enqueue_schedule_skb(struct sock *sk, struct sk_buff *skb)
 	__skb_queue_tail(list, skb);
 	spin_unlock(&list->lock);
 
-	if (!sock_flag(sk, SOCK_DEAD))
+	if (!sock_flag(sk, SOCK_DEAD)) {
+		trace_sk_data_ready(sk, skb);
 		sk->sk_data_ready(sk);
+	}
 
 	busylock_release(busy);
 	return 0;
-- 
2.27.0

Re: [Patch net-next 00/13] net: add more tracepoints to TCP/IP stack

[Cong Wang]

On Thu, Aug 5, 2021 at 11:57 AM Cong Wang <xiyou.wangcong@gmail.com> wrote:
>
> From: Cong Wang <cong.wang@bytedance.com>
>
> This patchset adds 12 more tracepoints to TCP/IP stack, both
> IPv4 and IPv6. The goal is to trace skb in different layers
> and to measure the latency of each layer.

It looks like we should not trace them at the end of each target function,
instead we have to trace them in the beginning, otherwise the ordering
is reversed in the output.

I will send V2 tomorrow.

Thanks.

Re: [Patch net-next 02/13] ipv4: introduce tracepoint trace_ip_queue_xmit()

[Eric Dumazet]

On 8/5/21 8:57 PM, Cong Wang wrote:
> From: Qitao Xu <qitao.xu@bytedance.com>
> 
> Tracepoint trace_ip_queue_xmit() is introduced to trace skb
> at the entrance of IP layer on TX side.
> 
> Reviewed-by: Cong Wang <cong.wang@bytedance.com>
> Signed-off-by: Qitao Xu <qitao.xu@bytedance.com>
> ---
>  include/trace/events/ip.h | 42 +++++++++++++++++++++++++++++++++++++++
>  net/ipv4/ip_output.c      | 10 +++++++++-
>  2 files changed, 51 insertions(+), 1 deletion(-)
> 
> diff --git a/include/trace/events/ip.h b/include/trace/events/ip.h
> index 008f821ebc50..553ae7276732 100644
> --- a/include/trace/events/ip.h
> +++ b/include/trace/events/ip.h
> @@ -41,6 +41,48 @@
>  	TP_STORE_V4MAPPED(__entry, saddr, daddr)
>  #endif
>  
> +TRACE_EVENT(ip_queue_xmit,
> +
> +	TP_PROTO(const struct sock *sk, const struct sk_buff *skb),
> +
> +	TP_ARGS(sk, skb),
> +
> +	TP_STRUCT__entry(
> +		__field(const void *, skbaddr)
> +		__field(const void *, skaddr)
> +		__field(__u16, sport)
> +		__field(__u16, dport)
> +		__array(__u8, saddr, 4)
> +		__array(__u8, daddr, 4)
> +		__array(__u8, saddr_v6, 16)
> +		__array(__u8, daddr_v6, 16)
> +	),
> +
> +	TP_fast_assign(
> +		struct inet_sock *inet = inet_sk(sk);
> +		__be32 *p32;
> +
> +		__entry->skbaddr = skb;
> +		__entry->skaddr = sk;
> +
> +		__entry->sport = ntohs(inet->inet_sport);
> +		__entry->dport = ntohs(inet->inet_dport);
> +
> +		p32 = (__be32 *) __entry->saddr;
> +		*p32 = inet->inet_saddr;
> +
> +		p32 = (__be32 *) __entry->daddr;
> +		*p32 =  inet->inet_daddr;
> +
> +		TP_STORE_ADDRS(__entry, inet->inet_saddr, inet->inet_daddr,
> +			      sk->sk_v6_rcv_saddr, sk->sk_v6_daddr);
> +	),
> +
> +	TP_printk("sport=%hu dport=%hu saddr=%pI4 daddr=%pI4 saddrv6=%pI6c daddrv6=%pI6c skbaddr=%px",
> +		  __entry->sport, __entry->dport, __entry->saddr, __entry->daddr,
> +		  __entry->saddr_v6, __entry->daddr_v6, __entry->skbaddr)
> +);
> +
>  #endif /* _TRACE_IP_H */
>  
>  /* This part must be outside protection */
> diff --git a/net/ipv4/ip_output.c b/net/ipv4/ip_output.c
> index 6b04a88466b2..dcf94059112e 100644
> --- a/net/ipv4/ip_output.c
> +++ b/net/ipv4/ip_output.c
> @@ -82,6 +82,7 @@
>  #include <linux/netfilter_bridge.h>
>  #include <linux/netlink.h>
>  #include <linux/tcp.h>
> +#include <trace/events/ip.h>
>  
>  static int
>  ip_fragment(struct net *net, struct sock *sk, struct sk_buff *skb,
> @@ -536,7 +537,14 @@ EXPORT_SYMBOL(__ip_queue_xmit);
>  
>  int ip_queue_xmit(struct sock *sk, struct sk_buff *skb, struct flowi *fl)
>  {
> -	return __ip_queue_xmit(sk, skb, fl, inet_sk(sk)->tos);
> +	int ret;
> +
> +	ret = __ip_queue_xmit(sk, skb, fl, inet_sk(sk)->tos);
> +	if (!ret)
> +		trace_ip_queue_xmit(sk, skb);
> +
> +	return ret;
> +
>  }
>  EXPORT_SYMBOL(ip_queue_xmit);
>  
> 

While it is useful to have stuff like this,
ddding so many trace points has a certain cost.

I fear that you have not determined this cost
on workloads where we enter these functions with cold caches.

For instance, before this patch, compiler gives us :

2e10 <ip_queue_xmit>:
    2e10:	e8 00 00 00 00       	callq  2e15 <ip_queue_xmit+0x5> (__fentry__-0x4)
    2e15:	0f b6 8f 1c 03 00 00 	movzbl 0x31c(%rdi),%ecx
    2e1c:	e9 ef fb ff ff       	jmpq   2a10 <__ip_queue_xmit>


After patch, we see the compiler had to save/restore registers, and no longer
jumps to __ip_queue_xmit. Code is bigger, even when tracepoint is not enabled.

    2e10:	e8 00 00 00 00       	callq  2e15 <ip_queue_xmit+0x5>
			2e11: R_X86_64_PLT32	__fentry__-0x4
    2e15:	41 55                	push   %r13
    2e17:	49 89 f5             	mov    %rsi,%r13
    2e1a:	41 54                	push   %r12
    2e1c:	55                   	push   %rbp
    2e1d:	0f b6 8f 1c 03 00 00 	movzbl 0x31c(%rdi),%ecx
    2e24:	48 89 fd             	mov    %rdi,%rbp
    2e27:	e8 00 00 00 00       	callq  2e2c <ip_queue_xmit+0x1c>
			2e28: R_X86_64_PLT32	__ip_queue_xmit-0x4
    2e2c:	41 89 c4             	mov    %eax,%r12d
    2e2f:	85 c0                	test   %eax,%eax
    2e31:	74 09                	je     2e3c <ip_queue_xmit+0x2c>
    2e33:	44 89 e0             	mov    %r12d,%eax
    2e36:	5d                   	pop    %rbp
    2e37:	41 5c                	pop    %r12
    2e39:	41 5d                	pop    %r13
    2e3b:	c3                   	retq   
    2e3c:	66 90                	xchg   %ax,%ax
    2e3e:	44 89 e0             	mov    %r12d,%eax
    2e41:	5d                   	pop    %rbp
    2e42:	41 5c                	pop    %r12
    2e44:	41 5d                	pop    %r13
    2e46:	c3                   	retq  
---- tracing code --- 
    2e47:	65 8b 05 00 00 00 00 	mov    %gs:0x0(%rip),%eax        # 2e4e <ip_queue_xmit+0x3e>
			2e4a: R_X86_64_PC32	cpu_number-0x4
    2e4e:	89 c0                	mov    %eax,%eax
    2e50:	48 0f a3 05 00 00 00 	bt     %rax,0x0(%rip)        # 2e58 <ip_queue_xmit+0x48>
    2e57:	00 
			2e54: R_X86_64_PC32	__cpu_online_mask-0x4
    2e58:	73 d9                	jae    2e33 <ip_queue_xmit+0x23>
    2e5a:	48 8b 05 00 00 00 00 	mov    0x0(%rip),%rax        # 2e61 <ip_queue_xmit+0x51>
			2e5d: R_X86_64_PC32	__tracepoint_ip_queue_xmit+0x3c
    2e61:	48 85 c0             	test   %rax,%rax
    2e64:	74 0f                	je     2e75 <ip_queue_xmit+0x65>
    2e66:	48 8b 78 08          	mov    0x8(%rax),%rdi
    2e6a:	4c 89 ea             	mov    %r13,%rdx
    2e6d:	48 89 ee             	mov    %rbp,%rsi
    2e70:	e8 00 00 00 00       	callq  2e75 <ip_queue_xmit+0x65>
			2e71: R_X86_64_PLT32	__SCT__tp_func_ip_queue_xmit-0x4
    2e75:	44 89 e0             	mov    %r12d,%eax
    2e78:	5d                   	pop    %rbp
    2e79:	41 5c                	pop    %r12
    2e7b:	41 5d                	pop    %r13
    2e7d:	c3                   	retq   

Re: [Patch net-next 02/13] ipv4: introduce tracepoint trace_ip_queue_xmit()

[Cong Wang]

On Fri, Aug 6, 2021 at 3:09 AM Eric Dumazet <eric.dumazet@gmail.com> wrote:
> While it is useful to have stuff like this,
> ddding so many trace points has a certain cost.
>
> I fear that you have not determined this cost
> on workloads where we enter these functions with cold caches.
>
> For instance, before this patch, compiler gives us :
>
> 2e10 <ip_queue_xmit>:
>     2e10:       e8 00 00 00 00          callq  2e15 <ip_queue_xmit+0x5> (__fentry__-0x4)
>     2e15:       0f b6 8f 1c 03 00 00    movzbl 0x31c(%rdi),%ecx
>     2e1c:       e9 ef fb ff ff          jmpq   2a10 <__ip_queue_xmit>
>
>
> After patch, we see the compiler had to save/restore registers, and no longer
> jumps to __ip_queue_xmit. Code is bigger, even when tracepoint is not enabled.

Interesting, I didn't pay attention to the binary code generated
by compilers. Let me check it, as I have moved the trace function
before __ip_queue_xmit() (otherwise the order is reversed).

Thanks!

Re: [Patch net-next 02/13] ipv4: introduce tracepoint trace_ip_queue_xmit()

[Martin KaFai Lau]

On Thu, Aug 05, 2021 at 11:57:39AM -0700, Cong Wang wrote:
> From: Qitao Xu <qitao.xu@bytedance.com>
> 
> Tracepoint trace_ip_queue_xmit() is introduced to trace skb
> at the entrance of IP layer on TX side.
> 
> Reviewed-by: Cong Wang <cong.wang@bytedance.com>
> Signed-off-by: Qitao Xu <qitao.xu@bytedance.com>
> ---
>  include/trace/events/ip.h | 42 +++++++++++++++++++++++++++++++++++++++
>  net/ipv4/ip_output.c      | 10 +++++++++-
>  2 files changed, 51 insertions(+), 1 deletion(-)
> 
> diff --git a/include/trace/events/ip.h b/include/trace/events/ip.h
> index 008f821ebc50..553ae7276732 100644
> --- a/include/trace/events/ip.h
> +++ b/include/trace/events/ip.h
> @@ -41,6 +41,48 @@
>  	TP_STORE_V4MAPPED(__entry, saddr, daddr)
>  #endif
>  
> +TRACE_EVENT(ip_queue_xmit,
> +
> +	TP_PROTO(const struct sock *sk, const struct sk_buff *skb),
> +
> +	TP_ARGS(sk, skb),
> +
> +	TP_STRUCT__entry(
> +		__field(const void *, skbaddr)
> +		__field(const void *, skaddr)
> +		__field(__u16, sport)
> +		__field(__u16, dport)
> +		__array(__u8, saddr, 4)
> +		__array(__u8, daddr, 4)
> +		__array(__u8, saddr_v6, 16)
> +		__array(__u8, daddr_v6, 16)
> +	),
> +
> +	TP_fast_assign(
> +		struct inet_sock *inet = inet_sk(sk);
> +		__be32 *p32;
> +
> +		__entry->skbaddr = skb;
> +		__entry->skaddr = sk;
> +
> +		__entry->sport = ntohs(inet->inet_sport);
> +		__entry->dport = ntohs(inet->inet_dport);
> +
> +		p32 = (__be32 *) __entry->saddr;
> +		*p32 = inet->inet_saddr;
> +
> +		p32 = (__be32 *) __entry->daddr;
> +		*p32 =  inet->inet_daddr;
> +
> +		TP_STORE_ADDRS(__entry, inet->inet_saddr, inet->inet_daddr,
> +			      sk->sk_v6_rcv_saddr, sk->sk_v6_daddr);
> +	),
> +
> +	TP_printk("sport=%hu dport=%hu saddr=%pI4 daddr=%pI4 saddrv6=%pI6c daddrv6=%pI6c skbaddr=%px",
> +		  __entry->sport, __entry->dport, __entry->saddr, __entry->daddr,
> +		  __entry->saddr_v6, __entry->daddr_v6, __entry->skbaddr)
> +);
> +
>  #endif /* _TRACE_IP_H */
>  
>  /* This part must be outside protection */
> diff --git a/net/ipv4/ip_output.c b/net/ipv4/ip_output.c
> index 6b04a88466b2..dcf94059112e 100644
> --- a/net/ipv4/ip_output.c
> +++ b/net/ipv4/ip_output.c
> @@ -82,6 +82,7 @@
>  #include <linux/netfilter_bridge.h>
>  #include <linux/netlink.h>
>  #include <linux/tcp.h>
> +#include <trace/events/ip.h>
>  
>  static int
>  ip_fragment(struct net *net, struct sock *sk, struct sk_buff *skb,
> @@ -536,7 +537,14 @@ EXPORT_SYMBOL(__ip_queue_xmit);
>  
>  int ip_queue_xmit(struct sock *sk, struct sk_buff *skb, struct flowi *fl)
>  {
> -	return __ip_queue_xmit(sk, skb, fl, inet_sk(sk)->tos);
> +	int ret;
> +
> +	ret = __ip_queue_xmit(sk, skb, fl, inet_sk(sk)->tos);
> +	if (!ret)
> +		trace_ip_queue_xmit(sk, skb);
Instead of adding tracepoints, the bpf fexit prog can be used here and
the bpf prog will have the sk, skb, and ret available (example in fexit_test.c).
Some tracepoints in this set can also be done with bpf fentry/fexit.
Does bpf fentry/fexit work for your use case?

Re: [Patch net-next 02/13] ipv4: introduce tracepoint trace_ip_queue_xmit()

[Cong Wang]

On Wed, Aug 11, 2021 at 2:23 PM Martin KaFai Lau <kafai@fb.com> wrote:
> Instead of adding tracepoints, the bpf fexit prog can be used here and
> the bpf prog will have the sk, skb, and ret available (example in fexit_test.c).
> Some tracepoints in this set can also be done with bpf fentry/fexit.
> Does bpf fentry/fexit work for your use case?

Well, kprobe works too in this perspective. The problem with kprobe
or fexit is that there is no guarantee the function still exists in kernel
during iteration. Kernel is free to delete or rename it. With tracepoint,
even if ip_queue_xmit() were renamed, the same tracepoint must
remain in the kernel.

Thanks.

Re: [Patch net-next 02/13] ipv4: introduce tracepoint trace_ip_queue_xmit()

[Martin KaFai Lau]

On Wed, Aug 11, 2021 at 03:48:36PM -0700, Cong Wang wrote:
> On Wed, Aug 11, 2021 at 2:23 PM Martin KaFai Lau <kafai@fb.com> wrote:
> > Instead of adding tracepoints, the bpf fexit prog can be used here and
> > the bpf prog will have the sk, skb, and ret available (example in fexit_test.c).
> > Some tracepoints in this set can also be done with bpf fentry/fexit.
> > Does bpf fentry/fexit work for your use case?
> 
> Well, kprobe works too in this perspective. The problem with kprobe
> or fexit is that there is no guarantee the function still exists in kernel
> during iteration. Kernel is free to delete or rename it. With tracepoint,
> even if ip_queue_xmit() were renamed, the same tracepoint must
> remain in the kernel.
Some of the function names are hardly changed.  Considering it is
not always cost free based on another thread, this is not a strong
enough reason to add so many tracepoints while other options
are available.

Re: [Patch net-next 02/13] ipv4: introduce tracepoint trace_ip_queue_xmit()

[Cong Wang]

On Wed, Aug 11, 2021 at 4:08 PM Martin KaFai Lau <kafai@fb.com> wrote:
> Some of the function names are hardly changed.

This is obviously wrong for two reasons:

1. Kernel developers did change them. As a quick example,
tcp_retransmit_skb() has been changed, we do have reasons to only trace
__tcp_retransmit_skb() instead.

2. Even if kernel developers never did, compilers can do inline too. For
example, I see nothing to stop compiler to inline tcp_transmit_skb()
which is static and only calls __tcp_transmit_skb(). You explicitly
mark bpf_fentry_test1() as noinline, don't you?

I understand you are eager to promote ebpf, however, please keep
reasonable on facts.

Thanks.

Re: [Patch net-next 02/13] ipv4: introduce tracepoint trace_ip_queue_xmit()

[Martin KaFai Lau]

On Wed, Aug 11, 2021 at 05:37:35PM -0700, Cong Wang wrote:
> On Wed, Aug 11, 2021 at 4:08 PM Martin KaFai Lau <kafai@fb.com> wrote:
> > Some of the function names are hardly changed.
> 
> This is obviously wrong for two reasons:
> 
> 1. Kernel developers did change them. As a quick example,
> tcp_retransmit_skb() has been changed, we do have reasons to only trace
> __tcp_retransmit_skb() instead.
I did not say it has never changed.  how often?  I don't believe
it changed often enough.

> 2. Even if kernel developers never did, compilers can do inline too. For
> example, I see nothing to stop compiler to inline tcp_transmit_skb()
> which is static and only calls __tcp_transmit_skb(). You explicitly
> mark bpf_fentry_test1() as noinline, don't you?
Yes, correct, inline is a legit reason.

Another one is to track some local variables in the function stack.

However, how many functions that you need here are indeed inlined by
compiler or need to track the local variables?

> I understand you are eager to promote ebpf, however, please keep
> reasonable on facts.
Absolutely not.  There is no need.  There is enough scripts
using bpf that does network tracing doing useful stuff without
adding so many tracepoints in the fast path.

I am only exploring other options and trying to understand
why it does not work in your case before adding all of
them in the fast path.  It is sad that you take it
this way.