Home Socket句柄泄漏
Post
Cancel

Socket句柄泄漏

参考资料:

  1. tcp-socket文件句柄泄漏
  2. Socket-内存泄漏引起的Tomcat宕机问题分析
  3. 文件描述符(fd)泄漏排查一篇就够了

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命令

  1. strace -f -p 4730 -T -tt -o /home/futi/strace_4730.log –4730位进程id
  2. 从上面似乎我们找不到根本原因,《Linux环境编程:从应用到内核》有这么一段:在多线程下,可能会在fcntl调用前,就已经fork出子进程。从这点出发我们查看tomcat线程ID为4783在执行fcntl前做了哪些操作,可以看出4783线程写入了一条ERROR日志
  3. 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
    

weixin.png

公众号名称:怪味Coding
微信扫码关注或搜索公众号名称
This post is licensed under CC BY 4.0 by the author.