diff mbox series

[v2,-tip,1/6] net: tcp: Add trace events for TCP congestion window tracing

Message ID 151358467535.28850.8937168919346099524.stgit@devbox
State Superseded, archived
Delegated to: David Miller
Headers show
Series net: tcp: sctp: dccp: Replace jprobe usage with trace events | expand

Commit Message

Masami Hiramatsu (Google) Dec. 18, 2017, 8:11 a.m. UTC 
This adds an event to trace TCP stat variables with
slightly intrusive trace-event. This uses ftrace/perf
event log buffer to trace those state, no needs to
prepare own ring-buffer, nor custom user apps.

User can use ftrace to trace this event as below;

  # cd /sys/kernel/debug/tracing
  # echo 1 > events/tcp/tcp_probe/enable
  (run workloads)
  # cat trace

Signed-off-by: Masami Hiramatsu <mhiramat@kernel.org>
---
 include/trace/events/tcp.h |   86 ++++++++++++++++++++++++++++++++++++++++++++
 net/core/net-traces.c      |    1 +
 net/ipv4/tcp_input.c       |    3 ++
 3 files changed, 90 insertions(+)

Comments

kernel test robot Dec. 20, 2017, 1:44 a.m. UTC | #1 
Hi Masami,

I love your patch! Yet something to improve:

[auto build test ERROR on net/master]
[also build test ERROR on v4.15-rc4 next-20171219]
[if your patch is applied to the wrong git tree, please drop us a note to help improve the system]

url:    https://github.com/0day-ci/linux/commits/Masami-Hiramatsu/net-tcp-sctp-dccp-Replace-jprobe-usage-with-trace-events/20171220-081035
config: sh-allmodconfig (attached as .config)
compiler: sh4-linux-gnu-gcc (Debian 7.2.0-11) 7.2.0
reproduce:
        wget https://raw.githubusercontent.com/intel/lkp-tests/master/sbin/make.cross -O ~/bin/make.cross
        chmod +x ~/bin/make.cross
        # save the attached .config to linux build tree
        make.cross ARCH=sh 

All error/warnings (new ones prefixed by >>):

   In file included from include/trace/events/udp.h:9:0,
                    from net//core/net-traces.c:35:
>> include/trace/events/tcp.h:37:11: error: expected ')' before 'const'
     TP_PROTO(const struct sock *sk, const struct sk_buff *skb),
              ^
   include/linux/tracepoint.h:105:27: note: in definition of macro 'TP_PROTO'
    #define TP_PROTO(args...) args
                              ^~~~
>> include/linux/tracepoint.h:237:20: error: redefinition of '__tpstrtab_tcp_retransmit_skb'
     static const char __tpstrtab_##name[]     \
                       ^
>> include/linux/tracepoint.h:247:2: note: in expansion of macro 'DEFINE_TRACE_FN'
     DEFINE_TRACE_FN(name, NULL, NULL);
     ^~~~~~~~~~~~~~~
>> include/trace/define_trace.h:51:2: note: in expansion of macro 'DEFINE_TRACE'
     DEFINE_TRACE(name)
     ^~~~~~~~~~~~
>> include/trace/events/tcp.h:90:1: note: in expansion of macro 'DEFINE_EVENT'
    DEFINE_EVENT(tcp_event_sk_skb, tcp_retransmit_skb,
    ^~~~~~~~~~~~
   In file included from include/trace/events/tcp.h:10:0,
                    from net//core/net-traces.c:34:
   include/linux/tracepoint.h:237:20: note: previous definition of '__tpstrtab_tcp_retransmit_skb' was here
     static const char __tpstrtab_##name[]     \
                       ^
>> include/linux/tracepoint.h:247:2: note: in expansion of macro 'DEFINE_TRACE_FN'
     DEFINE_TRACE_FN(name, NULL, NULL);
     ^~~~~~~~~~~~~~~
>> include/trace/define_trace.h:51:2: note: in expansion of macro 'DEFINE_TRACE'
     DEFINE_TRACE(name)
     ^~~~~~~~~~~~
>> include/trace/events/tcp.h:90:1: note: in expansion of macro 'DEFINE_EVENT'
    DEFINE_EVENT(tcp_event_sk_skb, tcp_retransmit_skb,
    ^~~~~~~~~~~~
   In file included from include/trace/events/udp.h:9:0,
                    from net//core/net-traces.c:35:
   include/linux/tracepoint.h:239:20: error: redefinition of '__tracepoint_tcp_retransmit_skb'
     struct tracepoint __tracepoint_##name     \
                       ^
>> include/linux/tracepoint.h:247:2: note: in expansion of macro 'DEFINE_TRACE_FN'
     DEFINE_TRACE_FN(name, NULL, NULL);
     ^~~~~~~~~~~~~~~
>> include/trace/define_trace.h:51:2: note: in expansion of macro 'DEFINE_TRACE'
     DEFINE_TRACE(name)
     ^~~~~~~~~~~~
>> include/trace/events/tcp.h:90:1: note: in expansion of macro 'DEFINE_EVENT'
    DEFINE_EVENT(tcp_event_sk_skb, tcp_retransmit_skb,
    ^~~~~~~~~~~~
   In file included from include/trace/events/tcp.h:10:0,
                    from net//core/net-traces.c:34:
   include/linux/tracepoint.h:239:20: note: previous definition of '__tracepoint_tcp_retransmit_skb' was here
     struct tracepoint __tracepoint_##name     \
                       ^
>> include/linux/tracepoint.h:247:2: note: in expansion of macro 'DEFINE_TRACE_FN'
     DEFINE_TRACE_FN(name, NULL, NULL);
     ^~~~~~~~~~~~~~~
>> include/trace/define_trace.h:51:2: note: in expansion of macro 'DEFINE_TRACE'
     DEFINE_TRACE(name)
     ^~~~~~~~~~~~
>> include/trace/events/tcp.h:90:1: note: in expansion of macro 'DEFINE_EVENT'
    DEFINE_EVENT(tcp_event_sk_skb, tcp_retransmit_skb,
    ^~~~~~~~~~~~
   In file included from include/trace/events/udp.h:9:0,
                    from net//core/net-traces.c:35:
>> include/linux/tracepoint.h:242:35: error: redefinition of '__tracepoint_ptr_tcp_retransmit_skb'
     static struct tracepoint * const __tracepoint_ptr_##name __used  \
                                      ^
>> include/linux/tracepoint.h:247:2: note: in expansion of macro 'DEFINE_TRACE_FN'
     DEFINE_TRACE_FN(name, NULL, NULL);
     ^~~~~~~~~~~~~~~
>> include/trace/define_trace.h:51:2: note: in expansion of macro 'DEFINE_TRACE'
     DEFINE_TRACE(name)
     ^~~~~~~~~~~~
>> include/trace/events/tcp.h:90:1: note: in expansion of macro 'DEFINE_EVENT'
    DEFINE_EVENT(tcp_event_sk_skb, tcp_retransmit_skb,
    ^~~~~~~~~~~~
   In file included from include/trace/events/tcp.h:10:0,
                    from net//core/net-traces.c:34:
   include/linux/tracepoint.h:242:35: note: previous definition of '__tracepoint_ptr_tcp_retransmit_skb' was here
     static struct tracepoint * const __tracepoint_ptr_##name __used  \
                                      ^
>> include/linux/tracepoint.h:247:2: note: in expansion of macro 'DEFINE_TRACE_FN'
     DEFINE_TRACE_FN(name, NULL, NULL);
     ^~~~~~~~~~~~~~~
>> include/trace/define_trace.h:51:2: note: in expansion of macro 'DEFINE_TRACE'
     DEFINE_TRACE(name)
     ^~~~~~~~~~~~

vim +37 include/trace/events/tcp.h

e086101b Cong Wang   2017-10-13  12  
e8fce239 Song Liu    2017-10-23  13  #define tcp_state_name(state)	{ state, #state }
e8fce239 Song Liu    2017-10-23  14  #define show_tcp_state_name(val)			\
e8fce239 Song Liu    2017-10-23  15  	__print_symbolic(val,				\
e8fce239 Song Liu    2017-10-23  16  		tcp_state_name(TCP_ESTABLISHED),	\
e8fce239 Song Liu    2017-10-23  17  		tcp_state_name(TCP_SYN_SENT),		\
e8fce239 Song Liu    2017-10-23  18  		tcp_state_name(TCP_SYN_RECV),		\
e8fce239 Song Liu    2017-10-23  19  		tcp_state_name(TCP_FIN_WAIT1),		\
e8fce239 Song Liu    2017-10-23  20  		tcp_state_name(TCP_FIN_WAIT2),		\
e8fce239 Song Liu    2017-10-23  21  		tcp_state_name(TCP_TIME_WAIT),		\
e8fce239 Song Liu    2017-10-23  22  		tcp_state_name(TCP_CLOSE),		\
e8fce239 Song Liu    2017-10-23  23  		tcp_state_name(TCP_CLOSE_WAIT),		\
e8fce239 Song Liu    2017-10-23  24  		tcp_state_name(TCP_LAST_ACK),		\
e8fce239 Song Liu    2017-10-23  25  		tcp_state_name(TCP_LISTEN),		\
e8fce239 Song Liu    2017-10-23  26  		tcp_state_name(TCP_CLOSING),		\
e8fce239 Song Liu    2017-10-23  27  		tcp_state_name(TCP_NEW_SYN_RECV))
e8fce239 Song Liu    2017-10-23  28  
f6e37b25 Song Liu    2017-10-23  29  /*
f6e37b25 Song Liu    2017-10-23  30   * tcp event with arguments sk and skb
f6e37b25 Song Liu    2017-10-23  31   *
f6e37b25 Song Liu    2017-10-23  32   * Note: this class requires a valid sk pointer; while skb pointer could
f6e37b25 Song Liu    2017-10-23  33   *       be NULL.
f6e37b25 Song Liu    2017-10-23  34   */
f6e37b25 Song Liu    2017-10-23 @35  DECLARE_EVENT_CLASS(tcp_event_sk_skb,
e086101b Cong Wang   2017-10-13  36  
7344e29f Song Liu    2017-10-23 @37  	TP_PROTO(const struct sock *sk, const struct sk_buff *skb),
e086101b Cong Wang   2017-10-13  38  
e086101b Cong Wang   2017-10-13  39  	TP_ARGS(sk, skb),
e086101b Cong Wang   2017-10-13  40  
e086101b Cong Wang   2017-10-13  41  	TP_STRUCT__entry(
7344e29f Song Liu    2017-10-23  42  		__field(const void *, skbaddr)
7344e29f Song Liu    2017-10-23  43  		__field(const void *, skaddr)
e086101b Cong Wang   2017-10-13  44  		__field(__u16, sport)
e086101b Cong Wang   2017-10-13  45  		__field(__u16, dport)
e086101b Cong Wang   2017-10-13  46  		__array(__u8, saddr, 4)
e086101b Cong Wang   2017-10-13  47  		__array(__u8, daddr, 4)
e086101b Cong Wang   2017-10-13  48  		__array(__u8, saddr_v6, 16)
e086101b Cong Wang   2017-10-13  49  		__array(__u8, daddr_v6, 16)
e086101b Cong Wang   2017-10-13  50  	),
e086101b Cong Wang   2017-10-13  51  
e086101b Cong Wang   2017-10-13  52  	TP_fast_assign(
e086101b Cong Wang   2017-10-13  53  		struct inet_sock *inet = inet_sk(sk);
e086101b Cong Wang   2017-10-13  54  		struct in6_addr *pin6;
e086101b Cong Wang   2017-10-13  55  		__be32 *p32;
e086101b Cong Wang   2017-10-13  56  
e086101b Cong Wang   2017-10-13  57  		__entry->skbaddr = skb;
e086101b Cong Wang   2017-10-13  58  		__entry->skaddr = sk;
e086101b Cong Wang   2017-10-13  59  
e086101b Cong Wang   2017-10-13  60  		__entry->sport = ntohs(inet->inet_sport);
e086101b Cong Wang   2017-10-13  61  		__entry->dport = ntohs(inet->inet_dport);
e086101b Cong Wang   2017-10-13  62  
e086101b Cong Wang   2017-10-13  63  		p32 = (__be32 *) __entry->saddr;
e086101b Cong Wang   2017-10-13  64  		*p32 = inet->inet_saddr;
e086101b Cong Wang   2017-10-13  65  
e086101b Cong Wang   2017-10-13  66  		p32 = (__be32 *) __entry->daddr;
e086101b Cong Wang   2017-10-13  67  		*p32 =  inet->inet_daddr;
e086101b Cong Wang   2017-10-13  68  
89005678 David Ahern 2017-10-18  69  #if IS_ENABLED(CONFIG_IPV6)
89005678 David Ahern 2017-10-18  70  		if (sk->sk_family == AF_INET6) {
e086101b Cong Wang   2017-10-13  71  			pin6 = (struct in6_addr *)__entry->saddr_v6;
386fd5da David Ahern 2017-10-16  72  			*pin6 = sk->sk_v6_rcv_saddr;
e086101b Cong Wang   2017-10-13  73  			pin6 = (struct in6_addr *)__entry->daddr_v6;
386fd5da David Ahern 2017-10-16  74  			*pin6 = sk->sk_v6_daddr;
89005678 David Ahern 2017-10-18  75  		} else
89005678 David Ahern 2017-10-18  76  #endif
89005678 David Ahern 2017-10-18  77  		{
e086101b Cong Wang   2017-10-13  78  			pin6 = (struct in6_addr *)__entry->saddr_v6;
e086101b Cong Wang   2017-10-13  79  			ipv6_addr_set_v4mapped(inet->inet_saddr, pin6);
e086101b Cong Wang   2017-10-13  80  			pin6 = (struct in6_addr *)__entry->daddr_v6;
e086101b Cong Wang   2017-10-13  81  			ipv6_addr_set_v4mapped(inet->inet_daddr, pin6);
e086101b Cong Wang   2017-10-13  82  		}
e086101b Cong Wang   2017-10-13  83  	),
e086101b Cong Wang   2017-10-13  84  
fb6ff75e David Ahern 2017-10-16  85  	TP_printk("sport=%hu dport=%hu saddr=%pI4 daddr=%pI4 saddrv6=%pI6c daddrv6=%pI6c",
e086101b Cong Wang   2017-10-13  86  		  __entry->sport, __entry->dport, __entry->saddr, __entry->daddr,
e086101b Cong Wang   2017-10-13  87  		  __entry->saddr_v6, __entry->daddr_v6)
e086101b Cong Wang   2017-10-13  88  );
e086101b Cong Wang   2017-10-13  89  
f6e37b25 Song Liu    2017-10-23 @90  DEFINE_EVENT(tcp_event_sk_skb, tcp_retransmit_skb,
f6e37b25 Song Liu    2017-10-23  91  
7344e29f Song Liu    2017-10-23  92  	TP_PROTO(const struct sock *sk, const struct sk_buff *skb),
f6e37b25 Song Liu    2017-10-23  93  
f6e37b25 Song Liu    2017-10-23  94  	TP_ARGS(sk, skb)
f6e37b25 Song Liu    2017-10-23  95  );
f6e37b25 Song Liu    2017-10-23  96  

:::::: The code at line 37 was first introduced by commit
:::::: 7344e29f285a94b965075599731811c352f3ab40 tcp: mark trace event arguments sk and skb as const

:::::: TO: Song Liu <songliubraving@fb.com>
:::::: CC: David S. Miller <davem@davemloft.net>

---
0-DAY kernel test infrastructure                Open Source Technology Center
https://lists.01.org/pipermail/kbuild-all                   Intel Corporation
diff mbox series

Patch

diff --git a/include/trace/events/tcp.h b/include/trace/events/tcp.h
index 07cccca6cbf1..77c26a37d5ce 100644
--- a/include/trace/events/tcp.h
+++ b/include/trace/events/tcp.h
@@ -1,3 +1,4 @@ 
+/* SPDX-License-Identifier: GPL-2.0 */
 #undef TRACE_SYSTEM
 #define TRACE_SYSTEM tcp
 
@@ -293,6 +294,91 @@  TRACE_EVENT(tcp_retransmit_synack,
 		  __entry->saddr_v6, __entry->daddr_v6)
 );
 
+#include <net/tcp.h>
+#include <linux/tcp.h>
+#include <linux/ipv6.h>
+#include <uapi/linux/in.h>
+#include <uapi/linux/in6.h>
+#include <linux/tracepoint.h>
+
+TRACE_EVENT(tcp_probe,
+
+	TP_PROTO(struct sock *sk, struct sk_buff *skb),
+
+	TP_ARGS(sk, skb),
+
+	TP_STRUCT__entry(
+		/* sockaddr_in6 is always bigger than sockaddr_in */
+		__array(__u8, saddr, sizeof(struct sockaddr_in6))
+		__array(__u8, daddr, sizeof(struct sockaddr_in6))
+		__field(__u16, sport)
+		__field(__u16, dport)
+		__field(__u32, mark)
+		__field(__u16, length)
+		__field(__u32, snd_nxt)
+		__field(__u32, snd_una)
+		__field(__u32, snd_cwnd)
+		__field(__u32, ssthresh)
+		__field(__u32, snd_wnd)
+		__field(__u32, srtt)
+		__field(__u32, rcv_wnd)
+	),
+
+	TP_fast_assign(
+		const struct tcp_sock *tp = tcp_sk(sk);
+		const struct inet_sock *inet = inet_sk(sk);
+
+		memset(__entry->saddr, 0, sizeof(struct sockaddr_in6));
+		memset(__entry->daddr, 0, sizeof(struct sockaddr_in6));
+
+		if (sk->sk_family == AF_INET) {
+			struct sockaddr_in *v4 = (void *)__entry->saddr;
+
+			v4->sin_family = AF_INET;
+			v4->sin_port = inet->inet_sport;
+			v4->sin_addr.s_addr = inet->inet_saddr;
+			v4 = (void *)__entry->daddr;
+			v4->sin_family = AF_INET;
+			v4->sin_port = inet->inet_dport;
+			v4->sin_addr.s_addr = inet->inet_daddr;
+#if IS_ENABLED(CONFIG_IPV6)
+		} else if (sk->sk_family == AF_INET6) {
+			struct sockaddr_in6 *v6 = (void *)__entry->saddr;
+
+			v6->sin6_family = AF_INET6;
+			v6->sin6_port = inet->inet_sport;
+			v6->sin6_addr = inet6_sk(sk)->saddr;
+			v6 = (void *)__entry->daddr;
+			v6->sin6_family = AF_INET6;
+			v6->sin6_port = inet->inet_dport;
+			v6->sin6_addr = sk->sk_v6_daddr;
+#endif
+		}
+
+		/* For filtering use */
+		__entry->sport = ntohs(inet->inet_sport);
+		__entry->dport = ntohs(inet->inet_dport);
+		__entry->mark = skb->mark;
+
+		__entry->length = skb->len;
+		__entry->snd_nxt = tp->snd_nxt;
+		__entry->snd_una = tp->snd_una;
+		__entry->snd_cwnd = tp->snd_cwnd;
+		__entry->snd_wnd = tp->snd_wnd;
+		__entry->rcv_wnd = tp->rcv_wnd;
+		__entry->ssthresh = tcp_current_ssthresh(sk);
+		__entry->srtt = tp->srtt_us >> 3;
+	),
+
+	TP_printk("src=%pISpc dest=%pISpc mark=%#x length=%d snd_nxt=%#x "
+		  "snd_una=%#x snd_cwnd=%u ssthresh=%u snd_wnd=%u srtt=%u "
+		  "rcv_wnd=%u",
+		  __entry->saddr, __entry->daddr, __entry->mark,
+		  __entry->length, __entry->snd_nxt, __entry->snd_una,
+		  __entry->snd_cwnd, __entry->ssthresh, __entry->snd_wnd,
+		  __entry->srtt, __entry->rcv_wnd)
+);
+
 #endif /* _TRACE_TCP_H */
 
 /* This part must be outside protection */
diff --git a/net/core/net-traces.c b/net/core/net-traces.c
index 380934580fa1..25b9334ef065 100644
--- a/net/core/net-traces.c
+++ b/net/core/net-traces.c
@@ -31,6 +31,7 @@ 
 #include <trace/events/net.h>
 #include <trace/events/napi.h>
 #include <trace/events/sock.h>
+#include <trace/events/tcp.h>
 #include <trace/events/udp.h>
 #include <trace/events/tcp.h>
 #include <trace/events/fib.h>
diff --git a/net/ipv4/tcp_input.c b/net/ipv4/tcp_input.c
index 45f750e85714..fa19cc86b2ad 100644
--- a/net/ipv4/tcp_input.c
+++ b/net/ipv4/tcp_input.c
@@ -5306,6 +5306,9 @@  void tcp_rcv_established(struct sock *sk, struct sk_buff *skb,
 	unsigned int len = skb->len;
 	struct tcp_sock *tp = tcp_sk(sk);
 
+	/* TCP congestion window tracking */
+	trace_tcp_probe(sk, skb);
+
 	tcp_mstamp_refresh(tp);
 	if (unlikely(!sk->sk_rx_dst))
 		inet_csk(sk)->icsk_af_ops->sk_rx_dst_set(sk, skb);