Maven服務瓶頸分析

用戶反饋maven@osc沒法訪問了。並且是頻繁沒法中止服務，因此決定花些時間，好好找下緣由。做爲運維方面的菜鳥，花了一週多的時間，走了不少彎路，也學到很多東西，最後仍是找到的緣由：沒有啓用持久鏈接（persistent connetion）（我認爲是，一個用戶每每是一次下載不少個jar文件，而頻繁的創建鏈接，關閉鏈接，訪問速度慢，服務器壓力也大）。感謝@化境 http://my.oschina.net/cnhuqing 和@陳紹榕 http://my.oschina.net/u/2511364 過程當中提供的幫助。

####1. 問題就是：搜索頁面加載慢、文件下載慢，而且時常中止服務。

首先，查看了一下mrtg日誌的80端口鏈接數，挺多的。

能夠看出來，出問題的week50和week51，鏈接數平均有500多（後面39鏈接數，是解決以後的數量）

當時，猜想會不會是有人惡意請求，就去查看nginx和tomcat日誌

####2. 接着查看nginx的日誌文件了，統計日誌文件中每種http status的數

perl -e 'while(<>){if(/\s([2345]\d\d)\s+\d/){$status{$1}++;}} while(($key,$value)=each %status){print "$key:$value\n"}' maven.oschina.log ; wc -l maven.oschina.log

499狀態的特別多，http協議中沒有該狀態碼，這是nginx的定義的。

ngx_string(ngx_http_error_495_page), /* 495, https certificate error / ngx_string(ngx_http_error_496_page), / 496, https no certificate / ngx_string(ngx_http_error_497_page), / 497, http to https / ngx_string(ngx_http_error_404_page), / 498, canceled / ngx_null_string, / 499, client has closed connection */ 意思是客戶端已經關閉了鏈接。 proxy_ignore_client_abort on; http://nginx.org/en/docs/http/ngx_http_proxy_module.html#proxy_ignore_client_abort Determines whether the connection with a proxied server should be closed when a client closes the connection without waiting for a response. 當客戶端關閉鏈接後，是否須要等代理服務器作了響應後，才關閉與代理服務器的鏈接。 默認值是off，當客戶端提早關閉了鏈接，nginx就會記錄499狀態的日誌。啓用後,再次統計日誌再也不出現499。 但仍是沒有解決問題，爲何用戶會提早關閉鏈接呢，沒有解決。

####3. 不是懷疑有人惡意請求麼，那就繼續統計nginx日誌中請求數最多的50個ip，命令以下：

awk '{print $1}' ./maven.oschina.log | sort | uniq -c | sort -n -k 1 -r | head -n 50

統計全部的日誌，請求數量最多的50個ip tail -n 2000 ./maven.oschina.log |awk '{print $1}' | sort | uniq -c | sort -n -k 1 -r | head -n 10
統計最後2000行日誌，請求數量最多的10個ip 簡單粗暴，將請求不少的一些ip，查看下請求內容，重複特別多的直接block掉，@陳紹榕 還幫忙謝了一個簡單粗暴的腳本，最新請求的last_num_lines行日誌中，請求數量超過max_requires_num閥值的ip，直接block掉。這樣處理後仍是沒法解決問題。後來也證實這樣是過於無腦粗暴。腳本以下：

#!/bin/bash
# Author: csr
# Date 2015-12-152
# Email: chenshaorong@oschina.cn
# Version: v1.0

max_requires_num=200
last_num_lines=1200
now=`date`
dir='/mnt/raid/nginx-logs/'

if [ ! -d $dir ]; then
        echo -e "\033[31mDirectory no exists.\033[0m"
        exit 1
fi
cd $dir

while getopts ":m:l:h" value; do
        case $value in
                h)
                        echo -e "\033[36mm: max requests number.\nl: last number lines.\033[0m"
                        exit 0
                        ;;
                m)
                        max_requires_num=$OPTARG
                        ;;
                l)
                        last_num_lines=$OPTARG
                        ;;
                ?)
                        echo -e "\033[31mInvalid arg: -h to help\033[0m"
                        exit 2
                        ;;
        esac
done

for num_ip in `tail -n $last_num_lines ./maven.oschina.log |awk '{print $1}' |sort |uniq -c |sort -nr |awk '{if($1>='$max_requires_num'){print $1":"$2}}'`; do
        ip=${num_ip#*:}
        num=${num_ip%:*}
        #/usr/sbin/ufw insert 1 deny from $ip
        echo "$num $ip $now $last_num_lines $max_requires_num" >> deny_ip.txt
done

####4. 統計每種鏈接狀態的數量

netstat -n | awk '/^tcp/ {++y[$NF]} END {for(w in y) print w, y[w]}'

統計結果舉例： FIN_WAIT2 2 CLOSING 1 SYN_RECV 1 CLOSE_WAIT 3986 TIME_WAIT 481 ESTABLISHED 2331 LAST_ACK 24 FIN_WAIT1 10

開始，我是不太清楚這些數據的正常狀況下的值的，可是我仍是猜想了下，ESTABLISHED(創建鏈接的)，TIME_WAIT(等待的)，就衝着這個方向去了，查看創建鏈接數多的ip，而後「大(yu)膽(chun)」的屏蔽了這些ip。可想而知，沒什麼做用。

請教@化境 ，他看了數據後，說CLOSE_WAIT值是根本緣由，而致使CLOSE_WAIT值過大的緣由，應該是應用自己的問題。 由於應用升級也好，優化也好，這是一個費時費力的事情，因此仍是先從其餘方面找突破口。我就去查資料，同時也找了一些運維羣去請教CLOSE_WAIT的問題。 資料裏面講述了CLOSE_WAIT的生成緣由： http://blog.whyun.com/posts/socket/

當客戶端主動關閉socket，就會出現大量CLOSE_WAIT；當服務器端主動關閉socket，就會出現大量TIME_WAIT。 根據找到的博客，試着修改了/etc/sysctl.conf文件：

表示開啓重用。容許將TIME-WAIT sockets從新用於新的TCP鏈接，默認爲0，表示關閉 net.ipv4.tcp_tw_reuse = 1 #表示開啓TCP鏈接中TIME-WAIT sockets的快速回收，默認爲0，表示關閉 net.ipv4.tcp_tw_recycle = 1 #表示系統同時保持TIME_WAIT的最大數量，若是超過這個數字， #TIME_WAIT將馬上被清除並打印警告信息。默認爲180000，改成5000。 net.ipv4.tcp_max_tw_buckets = 5000

並看不出什麼效果。

####5. 而後，想會不會有機器一直鏈接服務器，佔用不少的鏈接數。因此統計80端口，鏈接數最多的ip和鏈接數，命令以下：

netstat -pntu | grep :80 | awk '{print $5}' | cut -d: -f1 | awk '{++ip[$1]} END {for(i in ip) print ip[i],"\t",i}' | sort -nr|less

127.0.0.1本地鏈接確定沒問題了。其餘ip的鏈接數特別大的，就直接使用ufw屏蔽掉了。可是發現nginx日誌中，仍是有對應ip的請求，以爲是否是ufw無效啊，打算換用iptables。@陳紹榕 說已經establish的鏈接能夠繼續請求，若是斷開了就沒法創建鏈接。可是過了好久那些屏蔽掉的ip，仍是能夠請求，果斷拋棄ufw，換成iptables，依然屏蔽不掉，見鬼了。 後來發現，這裏的鏈接數多的ip是maven代理的上游maven服務器的ip，那些屏蔽不掉的請求，應該是咱們的maven服務器對out的請求。屏蔽上游ip後，上游服務器沒法響應maven@osc請求了，發現後，立刻清空了全部屏蔽ip。愚不可及。

####6. 最後從新捋了一遍上面的事情，以爲使用持久鏈接，減小鏈接創建次數，可讓請求更快。 通過幾天折騰，各類嘗試，仍是沒有解決，已經淡然了。我就挨着看Tomcat8官方文檔配置： https://tomcat.apache.org/tomcat-8.0-doc/config/http.html keepAliveTimeout 鏈接不關閉，保持開啓的時間。 而後去nginx官網配置找了下： http://nginx.org/en/docs/http/ngx_http_core_module.html#keepalive_timeout 果真有，對應的配置。 再聯想到這張圖：

tomcat配置已經配置了keepAliveTimeout="120000"(單位是毫秒) nginx配置居然設置爲keepalive_timeout 0;（ The zero value disables keep-alive client connections。）居然沒有啓用。 速度改爲keepalive_timeout 120s; 懷着試試看的態度，reload了nginx，哇塞，哇塞塞，除了第一次訪問頁面時候，有些慢，第二次，第三次查詢都很是快。

最終解決的方法很是簡單，可是過程是煎熬的，在小夥伴的幫助下，學到了很是多的知識。