记一次排查socket fd泄漏

1 故障表现

先说下系统架构，非常简单。本机nginx做接入，beego做后端，MySQL做存储，除了MySQL，外端还有少量的http接口对外调用。故障表现是，系统在测试环境运行一段时间后，beego接受新请求报错， http: Accept error: accept tcp [::]:8080: accept4: too many open files; retrying in 1s 。查看文件描述符限制 ulimit -n 得65535，查看 ls -l /proc/<pid>/fd | wc -l 得到65536且都是socket标记的，说明文件描述符的确耗尽了。查看 netstat -anp | wc -l ，并没有这么多连接。只能有一种解释，beego没有响应socket被动关闭，关闭文件描述符（fd）。

2 排查过程

2.1 查找哪些连接beego没有关闭

因为tcp被动关闭连接是不需要应用干涉的，虽然应用没有关闭fd，但是连接确实关闭了。因为故障时netstat已经看不到连接情况，所以需要记录故障前的连接快照。如果知道是连接哪个地址出的问题，就能找到相关代码，所以这步很关键。为此 1. 配置了cron，每分钟调用netstat，记录连接情况。 2. 配置监控，打开的网络描述符大于1000时报警。

从趋势图看，描述符的个数很稳定，并没有出现逐渐增大的情况。只能等报警时再排查。由于是测试环境，所以处理报警不及时，每次报警后查看现场，描述符都耗尽了。排查连接情况。

# 获取fd对应连接的inode
ls -l /proc/<pid>/fd | grep -Po 'socket:\[\d+' | cut -d'[' -f2 > /tmp/inodes.txt
# 获取cron记录的连接，并根据inode字段排序，排重，这里tcpstat.*是使用我们的内部工具记录的连接情况，可以用netstat代替
grep <pid> tcpstat.* | sort -k3,3 -u > /tmp/tcp.txt
# 查看inode对应的连接
for inode in $(cat /tmp/inodes.txt); do grep $inode /tmp/tcp.txt; done

结果大大出乎意料，全是nginx连beego的请求，beego没有断开连接。查看beego的相关代码，我确定beego也没问题。查看beego的goroutine，发现都停在了sql获取连接上，（beego的sql自带连接池），由此判断因为没有文件描述符可用，所以无法获取连接。

2.2 现场很重要

beego没问题，泄漏的连接又没有提供有用线索，根据目前的掌握的信息无法判断问题的原因。前面说了，由于是测试环境（同样的代码线上环境没事儿），所以处理报警不及时，每次查看现场时文件描述符都已经耗尽了。结合趋势图，描述符个数一直很稳定，直到某个时点，开始不断往上增，直到耗尽。基于某个时点之后，fd就开始快速增加，我判断是某个内部状态出了问题所致，所以看到耗尽前的现场至关重要。

机会很快来了，在描述符升到1000的时候，我切断了所有测试请求，手动模拟用户请求，结果发现请求超时，beego阻塞在了sql获取连接上，进一步查看所有goroutine（pperf提供了查看函数，beego基于此提供了http接口，使用起来非常方便），发现都停在了sql获取连接上。

事情清楚了，不是因为没有描述符可用导致sql无法获取连接，而是因为sql无法获取连接，导致所有的请求都卡住了，nginx主动关闭了连接，导致beego积攒了大量未关闭描述符的连接。