关于ebpf:实时跟踪内核-TCP-连接失败与重试-基于-BPF

7次阅读

共计 4530 个字符，预计需要花费 12 分钟才能阅读完成。

生产环境的问题，按呈现频率，大体能够分为两类：

高频问题
低频问题
- 周期性低频问题
- 无周期随机产生问题
  - 单例产生
  - 多例产生

个别，遇到 无周期随机产生问题 且 单例产生 的状况，是最难定位问题本源的。

前不久，我就遇到利用对外发动连贯 无周期随机产生 且 单例产生 的状况。你不可能在大流量的状况下，做 tcpdump 去剖析连贯状况的。而能透视内核状态的 eBPF/BPF 可能是个更适合的抉择。

eBPF 能够在以下 事件 产生时，抓取到 连贯信息：

利用发动 connect()，连贯进入 SYN_SENT 状态时
在发送 SYN 肯定工夫后，无收到响应而重传 SYN 时
connect timeout 后，利用 close() socket。连贯从 SYN_SENT 状态变为 CLOSE 状态时

这里说的 连贯信息，包含：

连贯 4 元组：source_IP: local_port <-> destination_IP:dest_port
事发时的连贯状态

而这些 事件 + 连贯信息 能够为进一步研判问题的方向，提供一个主观的事实证据。

之前，我了一篇：特定条件下 Istio 产生 half-close 连贯透露与出站连贯失败。其中模仿了一个场景：

应用程序出站 outbound 连贯超时因为应用程序抉择了一个与 -15001outboundlistener- 上的现有套接字抵触的长期端口
App invoke syscall connect(sockfd, peer_addr) , kernel allocation a ephemeral port(44410 in this case) , bind the new socket to that ephemeral port and sent SYN packet to peer.
SYN packet reach conntrack and it create a track entry in conntrack table:
$ conntrack -L
tcp  6 108 SYN_SENT src=172.29.73.7 dst=172.21.206.198 sport=44410 dport=7777 src=127.0.0.1 dst=172.29.73.7 sport=15001 dport=44410
SYN packet DNAT to 127.0.0.1:15001

SYN packet reach the already existing FIN-WAIT-2 127.0.0.1:15001 172.29.73.7:44410 socket, then sidecar reply a TCP Challenge ACK (TCP seq-no is from the old FIN-WAIT-2) packet to App

大体意思是，如果利用在发动出站连贯时，内核主动抉择的长期本地端口如果与“Envoy 在 15001 上的 FIN-WAIT-2 状态的 socket 的对端端口”雷同时，就会有问题。为了进步问题产生机率，我过后用 nc -p $ 长期本地端口号 的办法指定 长期本地端口号，而不是让内核主动抉择，模仿端口号抵触的。

但理论利用是让内核主动抉择 长期本地端口号 的。那么问题来了，如果要证实在问题产生时，内核主动抉择的 长期本地端口号 就是我构想的状况？

咱们晓得，TCP 连贯超时的处理过程，大略会有发下几个事件 (函数) 点：

利用调用 connect()。连贯进入 SYN_SENT 状态
- 对应内核的 tcp_connect()
在发送 SYN 肯定工夫后，因无收到响应而间歇重传 SYN
- 对应内核的tcp_retransmit_skb()
connect timeout 后，利用 close() socket。连贯从 SYN_SENT 状态变为 CLOSE 状态时
- 对应内核的inet_sk_state_store()

Talk is cheap, show you the code :

#!/usr/local/bin/bpftrace
#include <asm-generic/errno.h>
#include <linux/in.h>
#include <net/tcp_states.h>
#include <net/sock.h>
#include <net/inet_sock.h>
#include <linux/socket.h>

// trace-poll-timeout.bt file

BEGIN
{printf("Tracing IP TCP connect latency and SYN retry with stacks. Ctrl-C to end.\n");

    @tcp_states[1] = "ESTABLISHED";
    @tcp_states[2] = "SYN_SENT";
    @tcp_states[3] = "SYN_RECV";
    @tcp_states[4] = "FIN_WAIT1";
    @tcp_states[5] = "FIN_WAIT2";
    @tcp_states[6] = "TIME_WAIT";
    @tcp_states[7] = "CLOSE";
    @tcp_states[8] = "CLOSE_WAIT";
    @tcp_states[9] = "LAST_ACK";
    @tcp_states[10] = "LISTEN";
    @tcp_states[11] = "CLOSING";
    @tcp_states[12] = "NEW_SYN_RECV";    
}

kprobe:tcp_connect
{$sk = (struct sock *)arg0;
    $inet = (struct inet_sock *)arg0;

    @sk2connectUS[$sk] = nsecs;
}



kprobe:inet_sk_state_store
{$sk = (struct sock *)arg0;
    $inet = (struct inet_sock *)arg0;
    $newstate = arg1;
    if($newstate == TCP_CLOSE) {if( $sk->__sk_common.skc_state == TCP_SYN_SENT && @sk2connectUS[$sk] ) {

            $dport = $sk->__sk_common.skc_dport;
            $dport = ($dport >> 8) | (($dport << 8) & 0x00FF00);

            $sport = $inet->inet_sport;
            $sport = ($sport >> 8) | (($sport << 8) & 0x00FF00);

            $sk_family = $sk->__sk_common.skc_family;


            time("%H:%M:%S");
            printf("TCP_SYN_SENT to CLOSE: %-6d %-16s %d ms %-3d", 
                pid, comm, (nsecs - @sk2connectUS[$sk])/1000000,
                $sk_family == AF_INET ? 4 : 6);
            printf("%-15s:%-5d  -->  %-15s:%-5d\n", ntop($sk_family , $inet->inet_saddr), $sport,
                ntop($sk_family, $sk->__sk_common.skc_daddr), $dport);
            printf("kstack: %s\n", kstack);
            printf("ustack: %s\n", ustack);
        }
        else { }
        delete(@sk2connectUS[$sk]);
    }

}

kprobe:tcp_retransmit_skb
{$sk = (struct sock *)arg0;
    $inet_family = $sk->__sk_common.skc_family;
    if ($inet_family == AF_INET || $inet_family == AF_INET6)
    {
        $state = $sk->__sk_common.skc_state;
        if($state == 2/*SYN_SENT*/) {$daddr = ntop(0);
            $saddr = ntop(0);
            if ($inet_family == AF_INET)
            {$daddr = ntop($sk->__sk_common.skc_daddr);
                $saddr = ntop($sk->__sk_common.skc_rcv_saddr);
            }
            else
            {
                $daddr = ntop($sk->__sk_common.skc_v6_daddr.in6_u.u6_addr8);
                $saddr = ntop($sk->__sk_common.skc_v6_rcv_saddr.in6_u.u6_addr8);
            }
            $lport = $sk->__sk_common.skc_num;
            $dport = $sk->__sk_common.skc_dport;
            // Destination port is big endian, it must be flipped
            $dport = ($dport >> 8) | (($dport << 8) & 0x00FF00);
            $statestr = @tcp_states[$state];
            time("%H:%M:%S");
            printf("%-8d %14s:%-6d %14s:%-6d %6s\n", pid, $saddr, $lport,
                $daddr, $dport, $statestr);
        }
    }
}


END
{clear(@tcp_states);
}

运行 bpftrace，执行下面脚本：

bpftrace trace-poll-timeout.bt

向一个不会回复的 ip 发送连贯申请。且指定 10s 超时时长：

nc -w 10 1.1.1.146 22

这时，bpftrace 会呈现跟踪信息：

$ bpftrace trace-poll-timeout.bt

Attaching 5 probes...
Tracing IP TCP connect latency and SYN retry with stacks. Ctrl-C to end.
21:47:55 0          192.168.1.14:42636       1.1.1.146:22     SYN_SENT
21:47:57 0          192.168.1.14:42636       1.1.1.146:22     SYN_SENT
21:48:01 0          192.168.1.14:42636       1.1.1.146:22     SYN_SENT
21:48:04 TCP_SYN_SENT to CLOSE: 23023  nc 10009ms（尝试连贯用时）4   192.168.1.14:42636（内核主动调配的本地长期端口号）-->  1.1.1.146:22   
kstack: 
        inet_sk_state_store+1
        __tcp_close+678
        tcp_close+37
        inet_release+69
        __sock_release+63
        sock_close+21
        __fput+156
        ____fput+14
        task_work_run+106
        exit_to_user_mode_loop+343
        exit_to_user_mode_prepare+160
        syscall_exit_to_user_mode+39
        do_syscall_64+105
        entry_SYSCALL_64_after_hwframe+97

ustack: 
        0x7f1b1c6f8117
        0x600000001

^C

就这样，利用对外发动连贯 无周期随机产生 且 单例产生 的连贯问题，就能够找到证据了。

谢谢浏览！

正文完