在一些场景下，对服务的调用观测是很有价值的。笔者最近实践了使用tcp_close对服务主被调信息的观测，在这里作一下记录。
一、tcp close 的一般过程
首先来看一下tcp close的过程。
对tcp涉及操作的分析最权威的自然是RFC文档。依据RFC-793文档中的描述，tcp close时的状态转移信息为如下：
但是涉及到具体的Linux下的tcp close的过程分析，文档就比较少了。笔者找到了一篇介绍Linux下tcp操作相关的介绍文档。Analysis_TCP_in_Linux中描述了主动触发close及被动触发close的socket双方涉及的函数调用，这为后面的验证提供了思路。
二、BPF 来观测 tcp close 过程
依据Analysis_TCP_in_Linux中的描述，笔者使用python构建了如下的验证demo。
# coding=UTF-8
import socket
import time
import getopt
import syssrv_ip = ""
srv_port = 0def server(srv_ip, srv_port):conn = socket.socket(socket.AF_INET, socket.SOCK_STREAM)conn.bind((srv_ip, srv_port))conn.listen(1024)conn.setblocking(1)index = 0while True:connection, address = conn.accept()try:dst = connection.getpeername()while True:request = connection.recv(1024)req_str = str(request.decode())if req_str == 'end':# 这里以客户端传输一个特殊信息作为结束信息# tcp server 和 client 之间的 close 是没有必然联系的# 只能约定一个关闭条件。此时，无法确定客户端是否发起了断联print("rcv end, close...")connection.close()time.sleep(2)break# passprint("conn: %s:%d received: %s" % (dst[0], dst[1], req_str))response = ("client, msg index: %d" % index).encode()connection.send(response)index += 1print("conn: %s:%d closed" % (dst[0], dst[1]))except Exception as e:print("handle exception during dst. %s ..." % e)# pass# passdef client(srv_ip, srv_port):try:server_addr = (srv_ip, srv_port)conn = socket.socket(socket.AF_INET, socket.SOCK_STREAM)conn.connect(server_addr)msg = ("server, msg index: 0").encode()conn.send(msg)data = conn.recv(1024)print("rcv from server: %s" % str(data.decode()))conn.send("end".encode())print("end. close ...")time.sleep(2)conn.close()time.sleep(2)except Exception as e:print("connection with server with error, %s" % e)returnif __name__ == "__main__":work_mode = "s"try:opts, args = getopt.getopt(sys.argv[1:], "i:p:s:c",["srv_ip=", "port=", "server", "client"])if len(opts) == 0:print("unknown opts")sys.exit(0)for opt, arg in opts:if opt in ("-i", "--srv_ip"):srv_ip = argif opt in ("-p", "--port"):srv_port = int(arg)if opt in ("--server"):work_mode = "s"if opt in ("--client"):work_mode = "c"except Exception as e:print("unknown args")sys.exit(0)if work_mode == "s":server(srv_ip, srv_port)else:client(srv_ip, srv_port)
从demo中可以看到，笔者构建的测试代码中，是server端发起的close，而后client端发起close。
同时，笔者使用bpftrace构造了如下的观测代码：
#include <net/sock.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,
TCP_MAX_STATES = 13每个 hook 点关注 进程的 pid, sk_state
*/kprobe:tcp_close
/ comm == "python" /
{$sk = (struct sock*)arg0;printf("[tcp_close] pid: %d, state: %d, sock: %d, sk_max_ack_backlog: %d
",pid, $sk->__sk_common.skc_state,$sk, $sk->sk_max_ack_backlog);
}kprobe:tcp_set_state
/ comm == "python" /
{$sk = (struct sock*)arg0;$ns = arg1;printf("[tcp_set_state] pid: %d, state: %d, ns: %d, sk: %d
",pid, $sk->__sk_common.skc_state,$ns, $sk);
}kprobe:tcp_rcv_established
/ comm == "python" /
{$sk = (struct sock*)arg0;printf("[tcp_rcv_established] pid: %d, state: %d, sk: %d
",pid, $sk->__sk_common.skc_state,$sk);
}kprobe:tcp_fin
/ comm == "python" /
{$sk = (struct sock*)arg0;printf("[tcp_fin] pid: %d, state: %d, sk: %d
",pid, $sk->__sk_common.skc_state, $sk);
}kprobe:tcp_send_fin
/ comm == "python" /
{$sk = (struct sock*)arg0;printf("[tcp_send_fin] pid: %d, state: %d, sk: %d
",pid, $sk->__sk_common.skc_state, $sk);
}kprobe:tcp_timewait_state_process
/ comm == "python" /
{$sk = (struct sock*)arg0;printf("[tcp_timewait_state_process] pid: %d, state: %d, sk: %d
",pid, $sk->__sk_common.skc_state,$sk);
}kprobe:tcp_rcv_state_process
/ comm == "python" /
{$sk = (struct sock*)arg0;printf("[tcp_rcv_state_process] pid: %d, state: %d, sk: %d
",pid, $sk->__sk_common.skc_state,$sk);
}kprobe:tcp_v4_do_rcv
/ comm == "python" /
{$sk = (struct sock*)arg0;printf("[tcp_v4_do_rcv] pid: %d, state: %d, sk: %d
",pid, $sk->__sk_common.skc_state,$sk);
}kprobe:tcp_timewait_state_process
/ comm == "python" /
{$sk = (struct sock*)arg0;printf("[tcp_stream_wait_close] pid: %d, state: %d, sk: %d
",pid, $sk->__sk_common.skc_state,$sk);
}
首先启动bpftrace，然后启动server，使用client进行通信。此时bpftrace端的输出为：
[tcp_close] pid: 2828708, state: 1, sock: -1907214080, sk_max_ack_backlog: 1024
[tcp_set_state] pid: 2828708, state: 1, ns: 4, sk: -1907214080
[tcp_send_fin] pid: 2828708, state: 4, sk: -1907214080
[tcp_v4_do_rcv] pid: 2828708, state: 1, sk: -1907216512
[tcp_rcv_established] pid: 2828708, state: 1, sk: -1907216512
[tcp_fin] pid: 2828708, state: 1, sk: -1907216512
[tcp_set_state] pid: 2828708, state: 1, ns: 8, sk: -1907216512
[tcp_v4_do_rcv] pid: 2855763, state: 1, sk: -1907214080
[tcp_rcv_established] pid: 2855763, state: 1, sk: -1907214080
[tcp_close] pid: 2855763, state: 8, sock: -1907216512, sk_max_ack_backlog: 0
[tcp_set_state] pid: 2855763, state: 8, ns: 9, sk: -1907216512
[tcp_send_fin] pid: 2855763, state: 9, sk: -1907216512
[tcp_timewait_state_process] pid: 2855763, state: 6, sk: -2077492080
[tcp_stream_wait_close] pid: 2855763, state: 6, sk: -2077492080
[tcp_v4_do_rcv] pid: 2855763, state: 9, sk: -1907216512
[tcp_rcv_state_process] pid: 2855763, state: 9, sk: -1907216512
[tcp_set_state] pid: 2855763, state: 9, ns: 7, sk: -1907216512
三、笔者的困惑
这里，笔者观测到的结果和Analysis_TCP_in_Linux存在出入，主动发起close的一方，在第三次挥手时，响应的并不是tcp_rcv_state_process。相反的，被动close的socket在第四次挥手时触发了这个函数。而且，主动close的socket，第二次挥手时，响应的socket看起来发生了变更，而且其状态是TCP_ESTABLISHED。这其中需要继续探索。
以上，作为记录了部分总结。