Tomcat中的backlog參數

　　在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。大約了解其參數代表意義之后，我稍微測試了一番，並抓去了部分數據，首先確認系統默認參數

root@vmware-cnxct:/home/cfc4n# cat /proc/sys/net/core/somaxconn

root@vmware-cnxct:/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的值。

cfc4n@cnxct:~$ 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日志數據如下：

root@vmware-cnxct:/var/log/nginx# cat grep.error.log |wc -l

root@vmware-cnxct:/var/log/nginx# cat grep.access.log |wc -l
0
root@vmware-cnxct:/var/log/nginx# cat grep.access.log |awk '{print $9}'|sort|uniq -c
 200
 502
 504
root@vmware-cnxct:/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來查看：

 root@vmware-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通訊程序研發過程中，包括高性能的互聯網通訊中，想必有很大幫助，希望自己能繼續找些案例來實踐檢驗一下對這些知識的掌握。