参考资料:
tcp socket文件句柄泄漏
1、netstat显示的tcp连接数正常
1
2
3
4
5
6
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
2、ss -s显示大量的closed连接
1
2
3
4
5
6
7
8
9
10
11
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状态。 而我的系统监控取值方法是:
1
2
3
4
5
6
7
8
9
10
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的文件句柄。
1
2
3
4
5
6
7
lsof | grep sock
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泄漏的状况。
1
ps auxww | grep 4684
发现是redis机器上日志收集工具flume。
3、解决思路
系统层面的在:/proc/sys/fs/file-max里设置
1
2
cat /proc/sys/fs/file-max
2442976
用户层面
用户层面的限制在:/etc/security/limits.conf里设定。通过ulimit -a 查看系统允许 单个进程打开的最大文件数:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
ulimit -a
core file size (blocks, -c) 0
data seg size (kbytes, -d) unlimited
scheduling priority (-e) 0
file size (blocks, -f) unlimited
pending signals (-i) 192059
max locked memory (kbytes, -l) 64
max memory size (kbytes, -m) unlimited
open files (-n) 65536
pipe size (512 bytes, -p) 8
POSIX message queues (bytes, -q) 819200
real-time priority (-r) 0
stack size (kbytes, -s) 10240
cpu time (seconds, -t) unlimited
max user processes (-u) 65535
virtual memory (kbytes, -v) unlimited
file locks (-x) unlimited
单个进程可以打开的最大文件数是 65536
lsof 显示大量open file
按照Tomcat 给出的报错信息,登录87 这台服务器检查打开的文件数,发现打开的文件超过70000:
1
2
lsof |wc -l
75924
然后找出打开文件数最多的进程,按文件数降序排列,左边是 open file 的数量,右边是进程ID:
1
2
3
4
5
6
7
8
9
10
11
lsof -n|awk '{print $2}'| sort | uniq -c | sort -nr | head
65966 25204
5374 20179
184 27275
65 5361
61 29421
16 22177
14 19751
12 22181
12 22179
12 22178
发现 25204 这个进程打开了大量的文件,已经超过了单个进程的最大文件数限制。而这 个进程就是部署的java 应用对应的进程。打开的文件句柄数量已经超过Linux 限制, Tomcat 无法创建新的socket 连接。
用 lsof 查看 java 应用打开的文件的时候,发现有非常多奇怪的输出:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
java 25204 nemo *516u sock 0,6 0t0 215137625 can't identify protocol
java 25204 nemo *517u sock 0,6 0t0 215137626 can't identify protocol
java 25204 nemo *518u sock 0,6 0t0 215137627 can't identify protocol
java 25204 nemo *519u sock 0,6 0t0 215137628 can't identify protocol
java 25204 nemo *520u sock 0,6 0t0 215137629 can't identify protocol
java 25204 nemo *521u sock 0,6 0t0 215137630 can't identify protocol
java 25204 nemo *522u sock 0,6 0t0 215137631 can't identify protocol
java 25204 nemo *523u sock 0,6 0t0 215137634 can't identify protocol
java 25204 nemo *524u sock 0,6 0t0 215137635 can't identify protocol
java 25204 nemo *525u sock 0,6 0t0 215137636 can't identify protocol
java 25204 nemo *526u sock 0,6 0t0 215137637 can't identify protocol
java 25204 nemo *527u sock 0,6 0t0 215137638 can't identify protocol
java 25204 nemo *528u sock 0,6 0t0 215137639 can't identify protocol
java 25204 nemo *529u sock 0,6 0t0 215137640 can't identify protocol
java 25204 nemo *530u sock 0,6 0t0 215137641 can't identify protocol
java 25204 nemo *531u sock 0,6 0t0 215137642 can't identify protocol
java 25204 nemo *532u sock 0,6 0t0 215137644 can't identify protocol
java 25204 nemo *533u sock 0,6 0t0 215137646 can't identify protocol
统计之后发现, can’t identify protocol 这样的文件数量非常多:
1
2
lsof -p 25204|grep "can't identify protocol"|wc -l
64214
也就是大部份打开的文件都是属于 cant’ identify protocol 的文件。
问题定位
Google 搜索之后发现,这个 cant’ identify protocol 的东东出现的原因是因为 这些 sockets 处于 CLOSED 的状态,但是却没有真正close 掉,正处于 half-close 状态。因 此,如果使用 netstat 来查看socket 状态,是不会显示这些 half-close的 socket 的:
1
2
netstat -nat |wc -l
881
使用 netstat 的改进版本 ss 就能发现大量处于 Closed 状态的 socket:
1
2
3
4
5
6
7
8
9
10
11
ss -s
Total: 76052 (kernel 76254)
TCP: 75924 (estab 123, closed 75524, orphaned 0, synrecv 0, timewait 173/0), ports 104
Transport Total IP IPv6
* 76254 - -
RAW 0 0 0
UDP 9 6 3
TCP 116 80 36
INET 125 86 39
FRAG 0 0 0
接着查看内核的 socket 情况:
1
2
3
4
5
6
7
cat /proc/net/sockstat
sockets: used 75724
TCP: inuse 886 orphan 0 tw 0 alloc 72134 mem 222
UDP: inuse 5 mem 0
UDPLITE: inuse 0
RAW: inuse 0
FRAG: inuse 0 memory 0
利用strace命令
- strace -f -p 4730 -T -tt -o /home/futi/strace_4730.log –4730位进程id
- 从上面似乎我们找不到根本原因,《Linux环境编程:从应用到内核》有这么一段:在多线程下,可能会在fcntl调用前,就已经fork出子进程。从这点出发我们查看tomcat线程ID为4783在执行fcntl前做了哪些操作,可以看出4783线程写入了一条ERROR日志
- lsof -d 369 可以找到fd为369对应打开的文件:/data/applogs/cat/cat_20190722.log查看具体log 如下,由于连接Cat失败导致fd泄漏(由于cat上线很久了,忽略了查看cat 日志)
1
[07-21 23:13:21.204] [ERROR] [ChannelManager] Error when try connecting to /host:2280
