Re: [PATCH] net/tcp: introduce TRACE_EVENT for TCP/IPv4 state transition

Song Liu
2017-11-09T23:40:13Z

> On Nov 9, 2017, at 10:34 AM, Song Liu <songliubraving@fb.com> wrote:
>
>>
>> On Nov 9, 2017, at 10:18 AM, Steven Rostedt <rostedt@goodmis.org> wrote:
>>
>> On Thu, 9 Nov 2017 15:43:29 +0900
>> Alexei Starovoitov <alexei.starovoitov@gmail.com> wrote:
>>
>>>> +TRACE_EVENT(tcp_set_state,
>>>> + TP_PROTO(struct sock *sk, int oldstate, int newstate),
>>>> + TP_ARGS(sk, oldstate, newstate),
>>>> +
>>>> + TP_STRUCT__entry(
>>>> + __field(__be32, dst)
>>>> + __field(__be32, src)
>>>> + __field(__u16, dport)
>>>> + __field(__u16, sport)
>>>> + __field(int, oldstate)
>>>> + __field(int, newstate)
>>>> + ),
>>>> +
>>>> + TP_fast_assign(
>>>> + if (oldstate == TCP_TIME_WAIT) {
>>>> + __entry->dst = inet_twsk(sk)->tw_daddr;
>>>> + __entry->src = inet_twsk(sk)->tw_rcv_saddr;
>>>> + __entry->dport = ntohs(inet_twsk(sk)->tw_dport);
>>>> + __entry->sport = ntohs(inet_twsk(sk)->tw_sport);
>>>> + } else if (oldstate == TCP_NEW_SYN_RECV) {
>>>> + __entry->dst = inet_rsk(inet_reqsk(sk))->ir_rmt_addr;
>>>> + __entry->src = inet_rsk(inet_reqsk(sk))->ir_loc_addr;
>>>> + __entry->dport =
>>>> + ntohs(inet_rsk(inet_reqsk(sk))->ir_rmt_port);
>>>> + __entry->sport = inet_rsk(inet_reqsk(sk))->ir_num;
>>>> + } else {
>>>> + __entry->dst = inet_sk(sk)->inet_daddr;
>>>> + __entry->src = inet_sk(sk)->inet_rcv_saddr;
>>>> + __entry->dport = ntohs(inet_sk(sk)->inet_dport);
>>>> + __entry->sport = ntohs(inet_sk(sk)->inet_sport);
>>>> + }
>>>> +
>>>> + __entry->oldstate = oldstate;
>>>> + __entry->newstate = newstate;
>>>> + ),
>>>> +
>>>> + TP_printk("%08X:%04X %08X:%04X, %02x %02x",
>>>> + __entry->src, __entry->sport, __entry->dst, __entry->dport,
>>>> + __entry->oldstate, __entry->newstate)
>>>
>>> direct %x of state is not allowed.
>>> This has to use show_tcp_state_name() like it's done in trace_tcp_set_state
>>
>> Hmm, I need to look at trace_tcp_set_state. I'm guessing it is in
>> net-next too?
>
> Yes, in net-next. There are 6 tracepoints under tcp group:
>
> tcp_destroy_sock
> tcp_receive_reset
> tcp_retransmit_skb
> tcp_retransmit_synack
> tcp_send_reset
> tcp_set_state
>
> They are all added recently.
>
>>
>>>
>>> Also I'm missing the reason to introduce another tracepoint
>>> that looks just like trace_tcp_set_state.
>>
>> I want to make sure that perf and trace-cmd can parse the TP_printk(),
>> if it is having helper functions like that in the TP_printk() part,
>> then the libtraceevent needs to be aware of that.
>>
>
> tcp_set_state uses __print_symbolic to show state in text format. I found
> trace-cmd cannot parse that part:
>
> [011] 147338.660560: tcp_set_state: sport=16262 dport=48346 \
> saddr=127.0.0.6 daddr=127.0.0.6 saddrv6=2401:db00:30:317e:face:0:1f:0 \
> daddrv6=2401:db00:30:31e5:face:0:7f:0 oldstate= newstate=
>
> Other parts of the output looks good to me.
>
> Thanks,
> Song

I am not sure whether this is the best approach, but the following patch
fixes the output of perf:

0.44% sport=16262 dport=39362 saddr=127.0.0.6 daddr=127.0.0.6 \
saddrv6=2401:db00:30:317e:face:0:1f:0 daddrv6=2401:db00:30:31e5:face:0:7f:0 \
oldstate=TCP_CLOSE_WAIT newstate=TCP_LAST_ACK

Thanks,
Song

>From 4b7e27631a4c7df96a38223a95ee3ede2f5f2d19 Mon Sep 17 00:00:00 2001
From: Song Liu <songliubraving@fb.com>
Date: Thu, 9 Nov 2017 15:30:07 -0800
Subject: [PATCH] libtraceevent: add flags for tcp state names

Names of TCP states are added to flags in event-parse.c.

The names are used to print symbolic names in tracepoint:
tcp/tcp_set_state.

Signed-off-by: Song Liu <songliubraving@fb.com>
---
tools/lib/traceevent/event-parse.c | 14 ++++++++++++++
1 file changed, 14 insertions(+)

diff --git a/tools/lib/traceevent/event-parse.c b/tools/lib/traceevent/event-parse.c
index 7ce724f..4972dc2 100644
--- a/tools/lib/traceevent/event-parse.c
+++ b/tools/lib/traceevent/event-parse.c
@@ -3790,6 +3790,20 @@ static const struct flag flags[] = {

{ "HRTIMER_NORESTART", 0 },
{ "HRTIMER_RESTART", 1 },
+
+ /* tcp state names, see include/net/tcp_states.h */
+ { "TCP_ESTABLISHED", 1 },
+ { "TCP_SYN_SENT", 2 },
+ { "TCP_SYN_RECV", 3 },
+ { "TCP_FIN_WAIT1", 4 },
+ { "TCP_FIN_WAIT2", 5 },
+ { "TCP_TIME_WAIT", 6 },
+ { "TCP_CLOSE", 7 },
+ { "TCP_CLOSE_WAIT", 8 },
+ { "TCP_LAST_ACK", 9 },
+ { "TCP_LISTEN", 10 },
+ { "TCP_CLOSING", 11 },
+ { "TCP_NEW_SYN_RECV", 12 },
};

static long long eval_flag(const char *flag)
--
2.9.5