本篇文章翻译自 Brendan Gregg 的 TCP Tracepoints

TCP tracepoints 来到了 Linux! Linux 4.15 新增了5个 tracepoints,4.16 至少新增了2个(tcp:tcp_probe 和 sock:inet_sock_set_state 可以用来分析 TCP 的 socket tracepoint)。现在已经有了这些 tracepoints:

# perf list 'tcp:*' 'sock:inet*'

List of pre-defined events (to be used in -e):

  tcp:tcp_destroy_sock                               [Tracepoint event]
  tcp:tcp_probe                                      [Tracepoint event]
  tcp:tcp_receive_reset                              [Tracepoint event]
  tcp:tcp_retransmit_skb                             [Tracepoint event]
  tcp:tcp_retransmit_synack                          [Tracepoint event]
  tcp:tcp_send_reset                                 [Tracepoint event]

  sock:inet_sock_set_state                           [Tracepoint event]

这其中也包括了一个“多才多艺”的 tracepoint: sock:inet_sock_set_state。它可以用来跟踪内核 TCP 会话状态的变化,例如从 TCP_SYN_SEND 到 TCP_ESTABLISHED。其中一个例子是笔者开发的 tcplife 工具,包含在开源的 bcc 工具集中:

# tcplife
PID   COMM       LADDR           LPORT RADDR           RPORT TX_KB RX_KB MS
22597 recordProg 127.0.0.1       46644 127.0.0.1       28527     0     0 0.23
3277  redis-serv 127.0.0.1       28527 127.0.0.1       46644     0     0 0.28
22598 curl       100.66.3.172    61620 52.205.89.26    80        0     1 91.79
22604 curl       100.66.3.172    44400 52.204.43.121   80        0     1 121.38
22624 recordProg 127.0.0.1       46648 127.0.0.1       28527     0     0 0.22
3277  redis-serv 127.0.0.1       28527 127.0.0.1       46648     0     0 0.27
[...]

在这个 tracepoint 存在之前,笔者已经开发了 tcplife,所以不得不用 kprobe(内核动态跟踪) 来跟踪 tcp_set_state() 内核函数。这样也可以行得通,但是会依赖于不同内核版本的实现细节,可能会随着内核版本而发生变化。要让 tcplife 运行的话,将需要包含不同的内核代码变化,这样会很难去维护和增强。想象一下,需要在多个不同的内核上去测试这些修改,因为 tcplife 每个内核都是对应特定的代码。

Tracepoints 被认为是一个 “稳定的 API”,所以它们的细节不应该随着内核的迭代而发生变化,这样可以让程序更容易去维护。笔者特意说到“不应该”,是因为笔者认为它们是尽量保持不变,而不是一成不变。如果它们被认为是一成不变的,那么说服内核维护者去接受新的 tracepoint 就会更困难(出于好的理由)。例如:在 4.15 内核中新增了 tcp:tcp_set_state,然后在 4.16 内核新增了 sock:inet_sock_set_state。因为 sock 那个是超集,因此 tcp 那个在 4.16 内核中禁用,接下来会被移除。我们尽量去避免像这样去修改 tracepoint,但是在这个情况下,它只存在了很短的时间并在人们开始使用它之前被移除了。

tcplife 不是运用 tracepoint 极好的例子,因为它在三个地方超出了 tracepoint API(tx 和 rx 字节数,以及在 tracepoint 上尽最大努力在处理上下文),所以它仍需要一些修改。但是它比 kprobe 版本有了一个很大的进步,其他工具可以只使用 tracepoints API。

另一种方式演示 sock:inet_sock_set_state 是对比它和 Sasha Goldshtein 的 bcc 跟踪工具中的 tcp_set_state() kprobes。下面的第一个命令使用了 kprobes,第二个使用了 tracepoint:

# trace -t -I net/sock.h 'p::tcp_set_state(struct sock *sk) "%llx: %d -> %d", sk, sk->sk_state, arg2'
TIME     PID     TID     COMM            FUNC             -
2.583525 17320   17320   curl            tcp_set_state    ffff9fd7db588000: 7 -> 2
2.584449 0       0       swapper/5       tcp_set_state    ffff9fd7db588000: 2 -> 1
2.623158 17320   17320   curl            tcp_set_state    ffff9fd7db588000: 1 -> 4
2.623540 0       0       swapper/5       tcp_set_state    ffff9fd7db588000: 4 -> 5
2.623552 0       0       swapper/5       tcp_set_state    ffff9fd7db588000: 5 -> 7
^C
# trace -t 't:sock:inet_sock_set_state "%llx: %d -> %d", args->skaddr, args->oldstate, args->newstate'
TIME     PID     TID     COMM            FUNC             -
1.690191 17308   17308   curl            inet_sock_set_state ffff9fd7db589800: 7 -> 2
1.690798 0       0       swapper/24      inet_sock_set_state ffff9fd7db589800: 2 -> 1
1.727750 17308   17308   curl            inet_sock_set_state ffff9fd7db589800: 1 -> 4
1.728041 0       0       swapper/24      inet_sock_set_state ffff9fd7db589800: 4 -> 5
1.728063 0       0       swapper/24      inet_sock_set_state ffff9fd7db589800: 5 -> 7
^C

二者都有同样的输出。结果可参考如下:

  • 1: TCP_ESTABLISHED
  • 2: TCP_SYN_SENT
  • 3: TCP_SYN_RECV
  • 4: TCP_FIN_WAIT1
  • 5: TCP_FIN_WAIT2
  • 6: TCP_TIME_WAIT
  • 7: TCP_CLOSE
  • 8: TCP_CLOSE_WAIT

应该把上面的值作为一个查找哈希表并且。。。只需一小会,这儿就有了一个新的工具 tcpstate,笔者刚刚贡献给 bcc,它可以映射,并可以显示每个状态的持续时长:

# tcpstates
SKADDR           C-PID C-COMM     LADDR           LPORT RADDR         RPORT OLDSTATE    -> NEWSTATE    MS
ffff9fd7e8192000 22384 curl       100.66.100.185  0     52.33.159.26  80    CLOSE       -> SYN_SENT    0.000
ffff9fd7e8192000 0     swapper/5  100.66.100.185  63446 52.33.159.26  80    SYN_SENT    -> ESTABLISHED 1.373
ffff9fd7e8192000 22384 curl       100.66.100.185  63446 52.33.159.26  80    ESTABLISHED -> FIN_WAIT1   176.042
ffff9fd7e8192000 0     swapper/5  100.66.100.185  63446 52.33.159.26  80    FIN_WAIT1   -> FIN_WAIT2   0.536
ffff9fd7e8192000 0     swapper/5  100.66.100.185  63446 52.33.159.26  80    FIN_WAIT2   -> CLOSE       0.006
^C

笔者在 Linux 4.16 上演示了上面这个工具,之后 Yafang Shao 开发了一个增强版本来展示所有的状态变化,而不仅仅是内核实现的那些。这是在它在 4.15 上的输出:

# trace -I net/sock.h -t 'p::tcp_set_state(struct sock *sk) "%llx: %d -> %d", sk, sk->sk_state, arg2'
TIME     PID    TID    COMM         FUNC             -
3.275865 29039  29039  curl         tcp_set_state    ffff8803a8213800: 7 -> 2
3.277447 0      0      swapper/1    tcp_set_state    ffff8803a8213800: 2 -> 1
3.786203 29039  29039  curl         tcp_set_state    ffff8803a8213800: 1 -> 8
3.794016 29039  29039  curl         tcp_set_state    ffff8803a8213800: 8 -> 7
^C
# trace -t 't:tcp:tcp_set_state "%llx: %d -> %d", args->skaddr, args->oldstate, args->newstate'
TIME     PID    TID    COMM         FUNC             -
2.031911 29042  29042  curl         tcp_set_state    ffff8803a8213000: 7 -> 2
2.035019 0      0      swapper/1    tcp_set_state    ffff8803a8213000: 2 -> 1
2.746864 29042  29042  curl         tcp_set_state    ffff8803a8213000: 1 -> 8
2.754193 29042  29042  curl         tcp_set_state    ffff8803a8213000: 8 -> 7

让我们回到 4.16,这是当前 tracepoints 的列表,并且包含了参数,它们是通过 bcc 的 tplist 工具获取:

# tplist -v 'tcp:*'
tcp:tcp_retransmit_skb
    const void * skbaddr;
    const void * skaddr;
    __u16 sport;
    __u16 dport;
    __u8 saddr[4];
    __u8 daddr[4];
    __u8 saddr_v6[16];
    __u8 daddr_v6[16];
tcp:tcp_send_reset
    const void * skbaddr;
    const void * skaddr;
    __u16 sport;
    __u16 dport;
    __u8 saddr[4];
    __u8 daddr[4];
    __u8 saddr_v6[16];
    __u8 daddr_v6[16];
tcp:tcp_receive_reset
    const void * skaddr;
    __u16 sport;
    __u16 dport;
    __u8 saddr[4];
    __u8 daddr[4];
    __u8 saddr_v6[16];
    __u8 daddr_v6[16];
tcp:tcp_destroy_sock
    const void * skaddr;
    __u16 sport;
    __u16 dport;
    __u8 saddr[4];
    __u8 daddr[4];
    __u8 saddr_v6[16];
    __u8 daddr_v6[16];
tcp:tcp_retransmit_synack
    const void * skaddr;
    const void * req;
    __u16 sport;
    __u16 dport;
    __u8 saddr[4];
    __u8 daddr[4];
    __u8 saddr_v6[16];
    __u8 daddr_v6[16];
tcp:tcp_probe
    __u8 saddr[sizeof(struct sockaddr_in6)];
    __u8 daddr[sizeof(struct sockaddr_in6)];
    __u16 sport;
    __u16 dport;
    __u32 mark;
    __u16 length;
    __u32 snd_nxt;
    __u32 snd_una;
    __u32 snd_cwnd;
    __u32 ssthresh;
    __u32 snd_wnd;
    __u32 srtt;
    __u32 rcv_wnd;
# tplist -v sock:inet_sock_set_state
sock:inet_sock_set_state
    const void * skaddr;
    int oldstate;
    int newstate;
    __u16 sport;
    __u16 dport;
    __u16 family;
    __u8 protocol;
    __u8 saddr[4];
    __u8 daddr[4];
    __u8 saddr_v6[16];
    __u8 daddr_v6[16];

第一个 TCP tracepoint 是 Cong Wang 提交的 tcp:tcp_retransmit_skb。他引用了来自 perf-tools 中笔者基于 kprobe 开发的 tcpretrans 工具作为例子。Song Liu 增加了5个以上的 tracepoints,包括现在已经是 sock:inet_sock_set_state 的 tcp:tcp_set_state。感谢 Cong 和 Song,也感谢 David S. Miller (网络的维护者) 接受这些 tracepoint,并为正在开发中的 tcp tracepoint 工作提供了反馈。

在开发期间,笔者和 Song(也包括 Alexei Starovoitov) 沟通过关于最近新增的 tracepoint,所以已经知道了它们存在的意义和如何使用。下面是关于当前 TCP tracepoint 的一些简单笔记:

  • tcp:tcp_retransmit_skb: 跟踪重传。对于理解包括拥塞在内的网络问题很有用。将会在笔者的 tcpretrans 工具中替换 kprobes。
  • tcp:tcp_retransmit_synack: 跟踪 SYN 和 SYN/ACK 重传。将它们剥离出来很有趣,是因为它们可以表明服务器的饱和度(listen backlog 丢包)而不是网络拥塞。它对应着 LINUX_MIB_TCPSYNRETRANS。
  • tcp:tcp_destroy_sock: 对于需要统计汇总 TCP 会话的内存详情的程序是需要的,它可以通过 sock 地址来作为主键索引。这个探测点可以得知会话是否已经结束,因此接下来sock 地址将会被复用,任何截止到现在的统计信息都应该被使用然后删除。
  • tcp:tcp_send_reset: 这个会跟踪一个有效 socket 下的 RST 发送,用以诊断相关类型的问题。
  • tcp:tcp_receive_reset: 跟踪 RST 接受。
  • tcp:tcp_probe: 用以跟踪 TCP 拥塞窗口,这也让一个更老的 TCP probe 模块废弃并移除。这个是 Masami Hiramatsu 提交并在 4.16 合入。
  • sock:inet_sock_set_state: 可以用来做很多事情。tcplife 工具就是其中一个,并且笔者的 tcpconnect 和 tcpaccept bcc 工具也可以转换为使用这个 tracepoint。我们可以添加单独的 tcp:tcp_connect 和 tcp:tcp_accept tracepoints (或者 tcp:tcp_active_open 和 tcp:tcp_passive_open), 但是可以直接使用 sock:inet_sock_set_state。

使用这些 tracepoints 比抓包的方法更好,因为 tracepoint 的开销更小,并且可以暴露出来有用的内核状态。

能想象到这些 TCP tracepoint 会非常有用,就像笔者多年前设计了并使用了类似的 tracepoint:笔者在 CEC2006 演示的 DTrace TCP provider。原本将 TCP 状态变化分成为每个状态一个探测点,但当合入时,已经成为了一个单独的 tcp:::state-change 探测点,正如当前在 Linux 中的 sock tracepoint。

接下来呢?tcp:tcp_send 和 tcp:tcp_receive tracepoint 会很方便,但也要注意到它们会带来一些很小的的开销(开启或显式关闭),因为收发包是一个很频繁的操作。针对错误场景下的 tracepoints 也很好用,例如对于拒绝连接的路径下,它们对于分析 DoS 攻击很有用。

如果你对于增加 TCP tracepoint 很感兴趣,建议首先编写一个 kprobe 的方案作为概念证明,得到一些在生产环境上的实践经验。这也是之前 kprobes 工具的作用。kprobe 方案将验证这个 tracepoint 是否那样有用,如果有用的话,帮助 Linux 内核的维护者说明它所包含的场景。