bug现象
一个后台进程在跑了1000多分钟后,不再写日志,同时进程还有每分钟发送的一个网络请求,在服务端也没看到日志。
排查过程
首先怀疑是进程死锁了。于是ps aux查看进程id为12260,再通过gdb attach 12260到进程,发现并没有进程没有停止在lock函数。再用gdb在网络请求函数打断点,发现仍然是正常的每分钟执行一次curl请求,但是会报server connect failed错误。说明进程仍在正常执行,只是写日志和网络请求都是失败了。
因此怀疑是进程的fd满了。执行ll /proc/12260/fd打印进程的fd信息,发现socket数量达到了1006多个,再加上一些管道,刚好是1024个。
再用ulimit -a查看系统的进程最大fd数open files的值,正好为1024,说明是因为进程的fd满了,导致写日志和发送网络请求都失败了。
接下来就是排查出现fd泄露的位置。通过lsof -p 12260查看进程占用socket fd的类型,发现是UDP类型。排查程序代码,发现创建UDP套接字的只有一个位置,是通过socket+ioctl获取本机ip的函数,发现该函数最后没有close掉fd,造成了进程fd资源泄露;并且该函数也是一分钟调用一次,与出现问题的周期刚好对应。
结论
系统设置了进程最大的fd数量,创建socket会消耗fd,并且当fd到达最大值时无法再创建。使用linux原生的socket函数时一定要记得close fd,否则会出现fd泄露问题。使用RAII手法封装socket操作不失为更加明智的做法。