tcp socket文件句柄泄漏

今天發現有臺redis機器上出現socket個數告警，這是很奇怪的現象。因為一臺redis服務器上就部署了幾個redis實例，打開的端口應該是有限。

1、netstat顯示的tcp連接數正常

netstat -n | awk '/^tcp/ {++state[$NF]} END {for(key in state) print key,"\t",state[key]}'
TIME_WAIT        221
ESTABLISHED      103
 
netstat  -nat |wc -l
368

建立的tcp連接數并不是很多。

2、ss -s顯示大量的closed連接

ss -s
Total: 158211 (kernel 158355)
TCP:   157740 (estab 103, closed 157624, orphaned 0, synrecv 0, timewait 173/0), ports 203
 
Transport Total     IP        IPv6
*         158355    -         -        
RAW       0         0         0        
UDP       9         6         3        
TCP       116       80        36       
INET      125       86        39       
FRAG      0         0         0

closed 157624，很多socket是處于closed狀態。

而我的系統監控取值方法是:

cat /proc/net/sockstat | grep sockets | awk '{print $3}'
158391
 
cat /proc/net/sockstat
sockets: used 158400
TCP: inuse 89 orphan 2 tw 197 alloc 157760 mem 16
UDP: inuse 6 mem 0
UDPLITE: inuse 0
RAW: inuse 0
FRAG: inuse 0 memory 0

很多socket處于alloc狀態，已經分配sk_buffer,而且處于closed。

redis的file discriptes存在泄漏，沒有被內核回收。

3、追查真兇
上面信息說明存在socket fd泄漏，那么用lsof命令檢查系統sock的文件句柄。

lsof | grep sosck
java        4684      apps *280u     sock                0,6       0t0 675441359 can't identify protocol
java        4684      apps *281u     sock                0,6       0t0 675441393 can't identify protocol
java        4684      apps *282u     sock                0,6       0t0 675441405 can't identify protocol
java        4684      apps *283u     sock                0,6       0t0 675441523 can't identify protocol
java        4684      apps *284u     sock                0,6       0t0 675441532 can't identify protocol
java        4684      apps *285u     sock                0,6       0t0 675441566 can't identify protocol

可以發現，Name列的值為“an’t identify protocol”，socket找不到打開的文件，。

這個顯示，是java進程（pid=4684）出現了socket fd泄漏的狀況。

ps auxww | grep 4684

發現是redis機器上日志收集工具flume。

4、解決方案
沒有很好的的方法，簡單粗暴的kill占有scoket fd的進程。
<更新于2015年3月11日 20:05:30>
今天發現，重啟flume agent之后，仍然會出現這種大量的closed socket現象。
strace flume進程，發現flume進程已經掛起了。

sudo strace -p 36111
Process 36111 attached - interrupt to quit
futex(0x2b80e2c2e9d0, FUTEX_WAIT, 36120, NULL

首先，我比較懷疑文件句柄不夠用，因為google查找到的資料也提高了文件fd不夠而導致這種問題。

在我的機器上，最大允許打開的文件數為131072，文件fd個數還有近1/4沒有使用。

  lsof | wc -l 
10201
 
ulimit -a 
ulimit  -n
131072

這時，同事提示我，還有其他大量機器也出現了這種問題（flume已經上線了3個月，之前都很正常）。

這是，我想起了還有flume的日志可以查看。而查看flume的日志，提示flume找不到broker 5。
納尼，不是kafka集群不是只有4個broker（節點）。這時候才想起前幾天的郵件然來spark開發的同事，對kakf集群進行擴容了。
而新的集群節點9092端口對這臺redis所在的機房沒有開放訪問權限。

 [SinkRunner-PollingRunner-DefaultSinkProcessor] (kafka.utils.Logging$class.warn:89)  - Failed to send producer request 
with correlation id 63687539 to broker 5 with data for partitions [titan,4]

5、問題重現

在lsof: can’t identify protocol這篇文章中，用python代碼重現了這種狀況。

：）

在解決問題時，google查找是一種比較快捷的方式。而有時候，google出來的結果反而會影響排查問題的方向。
在我看到google的搜索結果之后，第一感覺是因為操作系統的max open files參數太小導致。在發現不是這個原因之后。我的思路仍然停留在內核參數是否配置合理的思路上。知道其他的機器上部署的flume出現了同種狀況是，我才意識到是flume本身出了問題，才去strace flume進程的狀態和查看flume的日志。

轉自：http://mdba.cn/?p=762