一个黑盒程序奇怪行为的分析

问题描述：

从银行金主baba手里拿到一个区块链程序，监听4000，在我们的环境中4000端口上很快就全连接队列溢出了，导致整个程序不响应了。这个程序是黑盒子，没有源代码，但是在金主baba自己的环境运行正常（一样的OS）

如下图所示：

ss -lnt 看到全连接队列增长到了39，但是netstat -ant找不到这39个连接，本来是想看看队列堆了这么多连接，都是哪些ip连过来的，实际看不到这就奇怪了

同时验证过程发现我们的环境4000端口上开了slb，也就是slb会不停滴探活4000端口，关掉slb探活后一切正常了。

所以总结下来问题就是：

为什么全连接队列里面的连接netstat看不到这些连接，但是ss能看到总数
为什么关掉slb就正常了
为什么应用不accept连接,也不close（应用是个黑盒子）

分析

为什么全连接队列里面的连接netstat/ss都看不到(ss能看到总数)

这是因为这些连接都是探活连接，三次握手后很快被slb reset了，在OS层面这个连接已经被释放，所以肯定看不见。反过来想要是netstat能看见这个连接，那么它的状态是什么？ reset吗？tcp连接状态里肯定是没有reset状态的。

ss看到的总数是指只要这个连接没有被accept，那么连接队列里就还有这个连接，通过ss也能看到连接队列数量。

为什么会产生这个错误理解–全连接队列里面的连接netstat一定要能看到？

那是因为正常情况都是能看到的，从没有考虑过握手后很快reset的情况。也没反问过如果能看到这个连接该是什么状态呢？

这个连接被reset后，kernel会将全连接队列数量减1吗？

不会，按照我们的理解连接被reset释放后，那么kernel要释放全连接队列里面的这个连接，因为这些动作都是kernel负责，上层没法处理这个reset。实际上内核认为所有 listen 到的连接, 必须要 accept 走, 用户有权利知道存在过这么一个连接。

也就是reset后，连接在内核层面释放了，所以netstat/ss看不到，但是全连接队列里面的应用数不会减1，只有应用accept后队列才会减1，accept这个空连接后读写会报错。基本可以认为全连接队列溢出了，主要是应用accept太慢导致的。

当应用从accept队列读取到已经被reset了的连接的时候应用层会得到一个报错信息。

什么时候连接状态变成 ESTABLISHED

三次握手成功就变成 ESTABLISHED 了，三次握手成功的第一是收到第三步的ack并且全连接队列没有满，不需要用户态来accept，如果握手第三步的时候OS发现全连接队列满了，这时OS会扔掉这个第三次握手ack，并重传握手第二步的syn+ack, 在OS端这个连接还是 SYN_RECV 状态的，但是client端是 ESTABLISHED状态的了。

下面是在4000（tearbase）端口上全连接队列没满，但是应用不再accept了，nc用12346端口去连4000（tearbase）端口的结果

# netstat -at |grep ":12346 "
tcp   0      0 dcep-blockchain-1:12346 dcep-blockchai:terabase ESTABLISHED //server
tcp   0      0 dcep-blockchai:terabase dcep-blockchain-1:12346 ESTABLISHED //client
[root@dcep-blockchain-1 cfl-sm2-sm3]# ss -lt
State       Recv-Q Send-Q      Local Address:Port         Peer Address:Port   
LISTEN      73     1024            *:terabase                 *:*

这是在4000（tearbase）端口上全连接队列满掉后，nc用12346端口去连4000（tearbase）端口的结果

# netstat -at |grep ":12346 "  
tcp   0      0 dcep-blockchai:terabase dcep-blockchain-1:12346 SYN_RECV    //server
tcp   0      0 dcep-blockchain-1:12346 dcep-blockchai:terabase ESTABLISHED //client
# ss -lt
State       Recv-Q Send-Q      Local Address:Port       Peer Address:Port   
LISTEN      1025   1024             *:terabase              *:*

为什么关掉slb就正常了

slb探活逻辑是向监听端口发起三次握手，握手成功后立即发送一个reset断开连接

这是一个完整的探活过程：

关掉就正常后要结合第三个问题来讲

为什么应用不accept连接,也不close（应用是个黑盒子）

因为应用是个黑盒子，看不到源代码，只能从行为来分析了

从行为来看，这个应用在三次握手后，会主动给client发送一个12字节的数据，但是这个逻辑写在了accept主逻辑内部，一旦主动给client发12字节数据失败（比如这个连接reset了）那么一直卡在这里导致应用不再accept也不再close。

正确的实现逻辑是，accept在一个单独的线程里，一旦accept到一个新连接，那么就开启一个新的线程来处理这个新连接的读写。accept线程专注accept。

关掉slb后应用有机会发出这12个字节，然后accept就能继续了，否则就卡死了。

一些验证

nc测试连接4000端口

# nc -p 12346 dcep-blockchain-1 4000
 //握手后4000返回的内容
抓包：
11:03:16.762547 IP dcep-blockchain-1.12346 > dcep-blockchain-1.terabase: Flags [S], seq 397659761, win 43690, options [mss 65495,sackOK,TS val 2329725964 ecr 0,nop,wscale 7], length 0
04:42:24.466211 IP dcep-blockchain-1.terabase > dcep-blockchain-1.12346: Flags [S.], seq 4239354556, ack 397659762, win 43690, options [mss 65495,sackOK,TS val 2329725964 ecr 2329725964,nop,wscale 7], length 0
11:03:16.762571 IP dcep-blockchain-1.12346 > dcep-blockchain-1.terabase: Flags [.], ack 1, win 342, options [nop,nop,TS val 2329725964 ecr 2329725964], length 0
----到这三次握手完毕，下面是隔了大概1.5ms，4000发了12字节给nc
11:03:16.763893 IP dcep-blockchain-1.terabase > dcep-blockchain-1.12346: Flags [P.], seq 1:13, ack 1, win 342, options [nop,nop,TS val 2329725966 ecr 2329725964], length 12
11:03:16.763904 IP dcep-blockchain-1.12346 > dcep-blockchain-1.terabase: Flags [.], ack 13, win 342, options [nop,nop,TS val 2329725966 ecr 2329725966], length 0

如果在上面的1.5ms之间nc reset了这个连接，那么这12字节就发不出来了

握手后Server主动发数据的行为非常像MySQL Server

MySQL Server在收到mysql client连接后会主动发送 Server Greeting、版本号、认证方式等给client

#nc -p 12345 127.0.0.1 3306
J
5.6.29�CuaV9v0xo�!
                  qCHRrGRIJqvzmysql_native_password  
                  
#tcpdump -i any port 12345 -ennt
tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
listening on any, link-type LINUX_SLL (Linux cooked), capture size 262144 bytes
 In 00:00:00:00:00:00 ethertype IPv4 (0x0800), length 76: 127.0.0.1.12345 > 127.0.0.1.3306: Flags [S], seq 3186409724, win 43690, options [mss 65495,sackOK,TS val 3967896050 ecr 0,nop,wscale 7], length 0
 In 00:00:00:00:00:00 ethertype IPv4 (0x0800), length 76: 127.0.0.1.3306 > 127.0.0.1.12345: Flags [S.], seq 4188709983, ack 3186409725, win 43690, options [mss 65495,sackOK,TS val 3967896051 ecr 3967896050,nop,wscale 7], length 0
 In 00:00:00:00:00:00 ethertype IPv4 (0x0800), length 68: 127.0.0.1.12345 > 127.0.0.1.3306: Flags [.], ack 1, win 342, options [nop,nop,TS val 3967896051 ecr 3967896051], length 0 // 握手完毕
 In 00:00:00:00:00:00 ethertype IPv4 (0x0800), length 146: 127.0.0.1.3306 > 127.0.0.1.12345: Flags [P.], seq 1:79, ack 1, win 342, options [nop,nop,TS val 3967896051 ecr 3967896051], length 78 //Server 发出Greeting
 In 00:00:00:00:00:00 ethertype IPv4 (0x0800), length 68: 127.0.0.1.12345 > 127.0.0.1.3306: Flags [.], ack 79, win 342, options [nop,nop,TS val 3967896051 ecr 3967896051], length 0
 In 00:00:00:00:00:00 ethertype IPv4 (0x0800), length 68: 127.0.0.1.3306 > 127.0.0.1.12345: Flags [F.], seq 79, ack 1, win 342, options [nop,nop,TS val 3967913551 ecr 3967896051], length 0
 In 00:00:00:00:00:00 ethertype IPv4 (0x0800), length 68: 127.0.0.1.12345 > 127.0.0.1.3306: Flags [.], ack 80, win 342, options [nop,nop,TS val 3967913591 ecr 3967913551], length 0

如下是Server发出的长度为 78 的 Server Greeting信息内容

理论上如果slb探活连接检查MySQL Server的状态的时候也是很快reset了，如果MySQL Server程序写得烂的话也会出现同样的情况。

但是比如我们有实验验证MySQL Server 是否正常的时候会用 nc 去测试，一般以能看到

5.6.29�CuaV9v0xo�!
qCHRrGRIJqvzmysql_native_password

就认为MySQL Server是正常的。但是真的是这样吗？我们看看 nc 的如下案例

nc 6.4 快速fin

#nc –version
Ncat: Version 6.40 ( http://nmap.org/ncat )

用 nc 测试发现有一定的概率没有出现上面的Server Greeting信息，那么这是因为MySQL Server服务不正常了吗？

nc -i 3 10.97.170.11 3306 -w 4 -p 1234

-i 3 表示握手成功后等三秒钟nc退出（发fin）

nc 6.4 握手后立即发fin断开连接，导致可能收不到Greeting，换成7.5或者mysql client就OK了

nc 7.5的抓包，明显可以看到nc在发fin前会先等4秒钟：

tcpping 模拟slb 探活

1	python tcpping.py -R -i 0.1 -t 1 dcep-blockchain-1 4000

-i 间隔0.1秒

-R reset断开连接

-t 超时时间1秒

执行如上代码，跟4000端口握手，然后立即发出reset断开连接（完全模拟slb探活行为），很快重现了问题

增加延时

-D 0.01表示握手成功后10ms后再发出reset（让应用有机会成功发出那12个字节），应用工作正常

1	python tcpping.py -R -i 0.1 -t 1 -D 0.01 dcep-blockchain-1 4000

总结

最大的错误认知就是 ss 看到的全连接队列数量，netstat也能看到。实际是不一定，而这个快速reset+应用不accept就导致了看不到这个现象