流水账-使用strace调试解决Pistache中Too Many Open Files

Too Many Open Files这个问题一般是由于fd未关闭导致的,当项目足够庞大且依赖大量第三方库的时候,依靠gdb调试的手段几乎不可能找的到未关闭的fd。我们实验室的某个存储项目在开发的时候就出现了这个故障:

E0421 02:43:45.960949164   31575 ev_epollex_linux.cc:1450]   pollset_set_add_pollset: 
{"created":"@1587408225.960932685","description":"Too many open files","errno":24,"file":
"XXXXXXXXXX/third-party/grpc/src/core/lib/iomgr/ev_epollex_linux.cc","file_line":560,
"os_error":"Too many open files","syscall":"epoll_create1"}

其中涉及fd的创建的有如下组件:

  • grpc: RPC框架
  • pistache: REST框架
  • libCouchBase: 数据库连接客户端
  • libuv: 事件驱动框架
  • 项目本身调用的open以及opendir等
  • 可能存在的其他依赖组件

从代码角度去人工找出未调用close(fd)的部分几乎不可能,因为close(fd)本身已经经过多层复杂的封装以及复杂的多线程调用关系(例如往ASIO框架中塞lambda函数的方式),并且fd过多,难以追踪每一个fd涉及的代码。在解决复杂项目的file descriptor leaking问题上,gdb帮助很小,而需要strace等工具。

使用strace抓取系统调用记录

strace的教程网上有很多,成熟的linux使用者也基本都掌握了自己看man page的能力,man strace告诉我们如果想要调试一个

  • 正在运行的进程的: -p pid Attach to the process with the process ID pid and begin tracing.
  • 所有子线程的: -f Trace child processes as they are created by currently traced processes as a result of the fork(2), vfork(2) and clone(2) system calls.
  • 关于fd的系统调用: -e trace=%desc Trace all file descriptor related system calls.
  • 最好能够像gdb一样打印call stack: -k Print the execution stack trace of the traced processes after each system call (experimental).
  • 出错的fd很可能和网络有关: -yy Print protocol specific information associated with socket file descriptors. -y Print paths associated with file descriptor arguments.

所以了解自己的需求然后带着需求去看man page的能力真的很重要,CSDN或者简书根本不会告诉你这么多。最终组合起来的命令就是:
strace -k -y -yy -e trace=%desc -o gc.strace.log -fp [The Running Process's PID]

分析系统调用记录

fd相关的系统调用记录以及记录到了gc.strace.log中,使用less或者vscode进行肉眼分析。分析过程比较朴素:

  1. 找出所有的close调用,可以很清楚的知道哪些fd被关闭了,哪些没有。
    例如
close(19<TCP:[127.0.0.1:40624->127.0.0.1:7090]>  = 0
close(22<TCP:[127.0.0.1:40686->127.0.0.1:7090]>  = 0
...

可以很清楚的发现fd=20fd=21并没有关闭

  1. 找出未关闭的fd相关的创建的系统调用。
    例如可以找到fd=20是由epoll_create(128) = 20<anon_inode:[eventpoll]> 创建的;fd=21是由eventfd2(0, EFD_CLOEXEC|EFD_NONBLOCK) = 21<anon_inode:[eventfd]>创建的。
  2. 找到系统调用对应的代码位置:
    由于我在strace中使用-k打印了调用栈,因此可以很清楚地找到系统调用的调用代码位置
 > /lib/x86_64-linux-gnu/libc-2.27.so(epoll_create+0x7) [0x1221e7]
 > XXXXXX/lib/libpistache.so.0.0(Pistache::Polling::Epoll::Epoll(unsigned long)::{lambda()#1
}::operator()() const+0x38) [0x2ea616]
 > XXXXXX/lib/libpistache.so.0.0(Pistache::Polling::Epoll::Epoll(unsigned long)+0x33) [0x2ea
7df]
 > XXXXXX/lib/libpistache.so.0.0(Pistache::Aio::SyncImpl::SyncImpl(Pistache::Aio::Reactor*)+
0x7a) [0x2eff52]
 > XXXXXX/lib/libpistache.so.0.0(Pistache::Aio::AsyncImpl::Worker::Worker(Pistache::Aio::Rea
ctor*)+0x53) [0x2f1a31]
 > XXXXXX/lib/libpistache.so.0.0(Pistache::Aio::AsyncImpl::AsyncImpl(Pistache::Aio::Reactor*
, unsigned long)+0x8d) [0x2f10c9]
 > XXXXXX/lib/libpistache.so.0.0(Pistache::Aio::AsyncContext::makeImpl(Pistache::Aio::Reacto
r*) const+0x37) [0x2ef84d]
 > XXXXXX/lib/libpistache.so.0.0(Pistache::Aio::Reactor::init(Pistache::Aio::ExecutionContex
t const&)+0x37) [0x2ef33d]
 > XXXXXX/lib/libpistache.so.0.0(Pistache::Http::Client::init(Pistache::Http::Client::Option
s const&)+0x74) [0x35e520]

bug已经很明显了,Pistache这个第三方库的HTTP Client在使用完epoll之后没有关闭epoll的fd。因此如果在某个函数中不断创建与销毁新的Pistache的Http Client(栈对象),就会导致leaking epoll fd耗完所有fd。因此只需要在Pistache::Polling::Epoll::~Epoll()中加入对epoll fd的close逻辑即可。

eventfd的处理方式同理。

回过头来检查

在代码修改完成后需要检查Too Many Open Files的问题是否解决,使用watch /proc/[Running Proc's PID]/fd即可看到进程占用的fd的实时变化情况,果然没有无限增长了,问题解决。

©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 196,099评论 5 462
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 82,473评论 2 373
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 143,229评论 0 325
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 52,570评论 1 267
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 61,427评论 5 358
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 46,335评论 1 273
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 36,737评论 3 386
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 35,392评论 0 254
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 39,693评论 1 294
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 34,730评论 2 312
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 36,512评论 1 326
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 32,349评论 3 314
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 37,750评论 3 299
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 29,017评论 0 19
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 30,290评论 1 251
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 41,706评论 2 342
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 40,904评论 2 335

推荐阅读更多精彩内容