Tomcat中的backlog参数

Posted 2020-10-06 读书使人进步

　　在linux 2.2以前，backlog大小包括了半连接状态和全连接状态两种队列大小。linux 2.2以后，分离为两个backlog来分别限制半连接SYN_RCVD状态的未完成连接队列大小跟全连接ESTABLISHED状态的已完成连接队列大小。互联网上常见的TCP SYN FLOOD恶意DOS攻击方式就是用/proc/sys/net/ipv4/tcp_max_syn_backlog来控制的。在使用listen函数时，内核会根据传入参数的backlog跟系统配置参数/proc/sys/net/core/somaxconn中，二者取最小值，作为“ESTABLISHED状态之后，完成TCP连接，等待服务程序ACCEPT”的队列大小。在kernel 2.4.25之前，是写死在代码常量SOMAXCONN，默认值是128。在kernel 2.4.25之后，在配置文件/proc/sys/net/core/somaxconn (即 /etc/sysctl.conf 之类 )中可以修改。我稍微整理了流程图，如下： 

 
　　如图，服务端收到客户端的syn请求后，将这个请求放入syns queue中，然后服务器端回复syn+ack给客户端，等收到客户端的ack后，将此连接放入accept queue。大约了解其参数代表意义之后，我稍微测试了一番，并抓去了部分数据，首先确认系统默认参数

[email protected]:/home/cfc4n# cat /proc/sys/net/core/somaxconn

[email protected]:/home/cfc4n# ss -lt
State      Recv-Q Send-Q         Local Address:Port                    Peer Address:Port
LISTEN     0      128                        *:ssh                           *:*
LISTEN     0      128                 0.0.0.0:9000                           *:*
LISTEN     0      128                       *:http                           *:*
LISTEN     0      128                       :::ssh                           :::*
LISTEN     0      128                      :::http                           :::*

在FPM的配置中，listen.backlog值默认为511，而如上结果中看到的Send-Q却是128，可见确实是以/proc/sys/net/core/somaxconn跟listen参数的最小值作为backlog的值。

[email protected]:~$ ab -n 10000 -c 300 http://172.16.218.128/3.php
This is ApacheBench, Version 2.3 <$Revision: 1604373 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Licensed to The Apache Software Foundation, http://www.apache.org/

Benchmarking 172.16.218.128 (be patient)
Completed 1000 requests
Completed 2000 requests
Completed 3000 requests
Completed 4000 requests
Completed 5000 requests
Completed 6000 requests
Completed 7000 requests
Completed 8000 requests
Completed 9000 requests
Completed 10000 requests
Finished 10000 requests


Server Software:        nginx/1.4.6
Server Hostname:        172.16.218.128
Server Port:            80

Document Path:          /3.php
Document Length:        55757 bytes

Concurrency Level:      300
Time taken for tests:   96.503 seconds
Complete requests:      10000
Failed requests:        7405
   (Connect: 0, Receive: 0, Length: 7405, Exceptions: 0)
Non-2xx responses:      271
Total transferred:      544236003 bytes
html transferred:       542499372 bytes
Requests per second:    103.62 [#/sec] (mean)
Time per request:       2895.097 [ms] (mean)
Time per request:       9.650 [ms] (mean, across all concurrent requests)
Transfer rate:          5507.38 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    9  96.7      0    1147
Processing:     8 2147 6139.2    981   60363
Waiting:        8 2137 6140.1    970   60363
Total:          8 2156 6162.8    981   61179

Percentage of the requests served within a certain time (ms)
%    981
%   1074
%   1192
%   1283
%   2578
%   5352
%  13534
%  42346
%  61179 (longest request)

　　apache ab这边的结果中，非2xx的http响应有271个，在NGINX日志数据如下：

[email protected]:/var/log/nginx# cat grep.error.log |wc -l

[email protected]:/var/log/nginx# cat grep.access.log |wc -l
0
[email protected]:/var/log/nginx# cat grep.access.log |awk ‘{print $9}‘|sort|uniq -c
 200
 502
 504
[email protected]:/var/log/nginx# cat grep.error.log |awk ‘{print $8  $9  $10 $11}‘|sort |uniq -c
 (111: Connection refused) while
 out (110: Connection timed

　　从nginx结果中看出，本次压测总请求数为10000。http 200响应数量9729个；http 502 响应数量186个；http 504响应数量未85个；即非2xx响应总数为502+504总数，为271个。同时，也跟error.log中数据吻合。同时，也跟TCP数据包中的RST包数量吻合。 

　　在nginx error中，错误号为111，错误信息为“Connection refused”的有186条，对应着所有http 502响应错误的请求；错误号为110，错误信息为“Connection timed out”的有85条,对应着所有http 504响应错误的请求。在linux errno.h头文件定义中，错误号111对应着ECONNREFUSED；错误号110对应着ETIMEDOUT。linux man手册里，对listen参数的说明中，也提到，若client连不上server时，会报告ECONNREFUSED的错。

Nginx error日志中的详细错误如下:

//backlog  过大,fpm处理不过来，导致队列等待时间超过NGINX的proxy
4#0: *24135 upstream timed out (110: Connection timed out) while connecting to upstream, client: 172.16.218.1, server: localhost, request: "GET /3.php HTTP/1.0", upstream: "fastcgi://192.168.122.66:9999", host: "172.16.218.128"

//backlog 过小
[error] 54416#0: *38728 connect() failed (111: Connection refused) while connecting to upstream, client: 172.16.218.1, server: localhost, request: "GET /3.php HTTP/1.0", upstream: "fastcgi://192.168.122.66:9999", host: "172.16.218.128"

　　在压测的时候，我用tcpdump抓了通讯包，配合通信包的数据，也可以看出，当backlog为某128时，accept queue队列塞满后，TCP建立的三次握手完成，连接进入ESTABLISHED状态，客户端（nginx）发送给PHP-FPM的数据，FPM处理不过来，没有调用accept将其从accept quque队列取出时，那么就没有ACK包返回给客户端nginx，nginx那边根据TCP 重传机制会再次发从尝试…报了“111: Connection refused”错。当SYNS QUEUE满了时，TCPDUMP的结果如下，不停重传SYN包。 
 
　　对于已经调用accept函数，从accept queue取出，读取其数据的TCP连接，由于FPM本身处理较慢，以至于NGINX等待时间过久，直接终止了该fastcgi请求，返回“110: Connection timed out”。当FPM处理完成后，往FD里写数据时，发现前端的nginx已经断开连接了，就报了“Write broken pipe”。当ACCEPT QUEUE满了时，TCPDUMP的结果如下，不停重传PSH SCK包。（别问我TCP RTO重传的机制，太复杂了，太深奥了 、 TCP的定时器系列 — 超时重传定时器 ） 
 
对于这些结论，我尝试搜了很多资料，后来在360公司的「基础架构快报」中也看到了他们的研究资料《 TCP三次握手之backlog 》，也验证了我的结论。

关于ACCEPT QUEUE满了之后的表现问题，早上 IM鑫爷 给我指出几个错误，感谢批评及指导，在这里，我把这个问题再详细描述一下。如上图所示

• NO.515 client发SYN到server，我的seq是0，消息包内容长度为0. （这里的seq并非真正的0，而是wireshark为了显示更好阅读，使用了Relative SeqNum相对序号）
• NO.516 server回SYN ACK给client，我的seq是0，消息包内容长度是0，已经收到你发的seq 1 之前的TCP包。(请发后面的)
• NO.641 client发ACK给server，我是seq 1 ，消息包内容长度是0，已经收到你发的seq 1 之前的TCP包。
• NO.992 client发PSH给server，我是seq 1 ，消息包内容长度是496，已经收到你发的seq 1 之前的TCP包。
• ………..等了一段时间之后（这里约0.2s左右）
• NO.4796 client没等到对方的ACK包，开始TCP retransmission这个包，我是seq 1，消息包长度496，已经收到你发的seq 1 之前的TCP包。
• ……….又…等了一段时间
• NO.9669 client还是没等到对方的ACK包，又开始TCP retransmission这个包，我是seq 1，消息包长度496，已经收到你发的seq 1 之前的TCP包。
• NO.13434 server发了SYN ACK给client，这里是tcp spurious retransmission 伪重传，我的seq是0，消息包内容长度是0，已经收到你发的seq 1 之前的TCP包。距离其上次发包给client是NO.516 已1秒左右了，因为没有收到NO.641 包ACK。这时，client收到过server的SYN,ACK包，将此TCP 连接状态改为ESTABLISHED,而server那边没有收到client的ACK包，则其TCP连接状态是SYN_RCVD状态。（感谢IM鑫爷指正）也可能是因为accept queue满了，暂时不能将此TCP连接从syns queue拉到accept queue，导致这情况，这需要翻阅内核源码才能确认。
• NO.13467 client发TCP DUP ACK包给server，其实是重发了N0.641 ,只是seq变化了，因为要包括它之前发送过的seq的序列号总和。即..我的seq 497 ，消息包内容长度是0，已经收到你发的seq 1 之前的TCP包。
• NO.16573 client继续重新发消息数据给server，包的内容还是NO.992的内容，因为之前发的几次，都没收到确认。
• NO.25813 client继续重新发消息数据给server，包的内容还还是NO.992的内容，仍没收到确认。（参见下图中绿色框内标识）
• NO.29733 server又重复了NO.13434包的流程，原因也一样，参见NO.13434包注释
• NO.29765 client只好跟NO.13467一样，重发ACK包给server。
• NO.44507 重复NO.16573的步骤
• NO.79195 继续重复NO.16573的步骤
• NO.79195 server立刻直接回了RST包，结束会话

详细的包内容备注在后面，需要关注的不光是包发送顺序，包的seq重传之类，还有一个重要的，TCP retransmission timeout，即TCP超时重传。对于这里已经抓到的数据包，wireshark可以看下每次超时重传的时间间隔，如下图： 
 
RTO的重传次数是系统可配置的，见/proc/sys/net/ipv4/tcp_retries1 ，而重传时间间隔，间隔增长频率等，是比较复杂的方式计算出来的，见《 TCP/IP重传超时–RTO 》。

backlog大小设置为多少合适？ 
从上面的结论中可以看出，这跟FPM的处理能力有关，backlog太大了，导致FPM处理不过来，nginx那边等待超时，断开连接，报504 gateway timeout错。同时FPM处理完准备write 数据给nginx时，发现TCP连接断开了，报“Broken pipe”。backlog太小的话，NGINX之类client，根本进入不了FPM的accept queue，报“502 Bad Gateway”错。所以，这还得去根据FPM的QPS来决定backlog的大小。计算方式最好为QPS=backlog。对了这里的QPS是正常业务下的QPS，千万别用echo hello world这种结果的QPS去欺骗自己。当然，backlog的数值，如果指定在FPM中的话，记得把操作系统的net.core.somaxconn设置的起码比它大。另外，ubuntu server 1404上/proc/sys/net/core/somaxconn 跟/proc/sys/net/ipv4/tcp_max_syn_backlog 默认值都是128，这个问题，我为了抓数据，测了好几遍才发现。 
对于测试时，TCP数据包已经drop掉的未进入syns queue，以及未进入accept queue的数据包，可以用netstat -s来查看：

[email protected]-cnxct:/# netstat -s
TcpExt:
	//...
5 times the listen queue of a socket overflowed
24 SYNs to LISTEN sockets dropped	//未进入syns queue的数据包数量
 packets directly queued to recvmsg prequeue.
8 bytes directly in process context from backlog
    //...
    TCPSackShiftFallback: 27
    TCPBacklogDrop: 2334	//未进入accept queue的数据包数量
    TCPTimeWaitOverflow: 229347
    TCPReqQFullDoCookies: 11591
    TCPRcvCoalesce: 29062
    //...

经过相关资料查阅，技术点研究，再做一番测试之后，又加深了我对TCP通讯知识点的记忆，以及对sync queue、accept queue所处环节知识点薄弱的补充，也是蛮有收获，这些知识，在以后的纯TCP通讯程序研发过程中，包括高性能的互联网通讯中，想必有很大帮助，希望自己能继续找些案例来实践检验一下对这些知识的掌握。