深入学习fd泄露问题

最近遇到一个应用闪退的问题,开始发现问题时没有找到明显的问题复现步骤,单独操作应用里的所有功能都没有发生该问题,而一旦进行煲机测试半小时后出现了。光从应用层的log也分析不出问题的原因来,这个问题拖了很长一段时间,真是惭愧!煲机的业务逻辑是通过PC程序循环发送指令到车机板子上,控制车机上的测试程序,调起测试case执行硬件模块的测试。

问题分析

分析该问题发生时的log文件,与我的应用有关的log内容主要是正常的业务打印,直到在crash log部分最后有一段包含了我的进程名的内容,这些log信息甚是可疑!

03-03 17:22:16.053  9320  9320 D TestCaseManager: enqueueCase: {mTitle:GPS, mID:GPS, mTestQueueType:OTHER}
03-03 17:22:16.053  9320  9320 D TestCase: secureStart() mStatus=PASS, mID=GPS
03-03 17:22:16.053  9320  9320 V TestCaseManager: onTestResult id:GPS, status:TESTING
03-03 17:22:16.053  9320  9320 D TestCase: secureStart()->invoke the start() of testcase GPS
03-03 17:22:16.055  9320  9320 W zygote64: ashmem_create_region failed for 'indirect ref table': Too many open files
03-03 17:22:16.056  9320 10862 F Looper  : Could not make wake event fd: Too many open files
03-03 17:22:16.057  9320  9320 I GpsUtils: isProviderEnabled:true
03-03 17:22:16.057   598   676 D SocketMoudle: connect: bind failed, try
03-03 17:22:16.138   598   676 D SocketMoudle: connect: bind failed, try
03-03 17:22:16.205   888   961 W DCS_SocketMoudle: connect: accept() error, mCurSockFd=-1, errno=11
03-03 17:22:16.205   888   961 W CanDataProc: rxThread: socket connect retVal: -1
03-03 17:22:16.218   598   676 D SocketMoudle: connect: bind failed, try
03-03 17:22:16.275 10865 10865 I crash_dump64: obtaining output fd from tombstoned, type: kDebuggerdTombstone
03-03 17:22:16.276   936   936 I /system/bin/tombstoned: received crash request for pid 9320
03-03 17:22:16.277 10865 10865 I crash_dump64: performing dump of process 9320 (target tid = 10862)
03-03 17:22:16.277 10865 10865 I crash_dump64: engrave_tombstone
03-03 17:22:16.277 10865 10865 D DEBUG   : enter engrave_tombstone
03-03 17:22:16.278 10865 10865 F DEBUG   : *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
03-03 17:22:16.278 10865 10865 F DEBUG   : Build fingerprint: 'M01_AE-userdebug-M01.CHJ.A81.M.200225.205'
03-03 17:22:16.278 10865 10865 F DEBUG   : Revision: '0'
03-03 17:22:16.278 10865 10865 F DEBUG   : ABI: 'arm64'
03-03 17:22:16.278 10865 10865 F DEBUG   : pid: 9320, tid: 10862, name: Gps-Handler  >>> com.xxx.car.vehicleeol <<<
03-03 17:22:16.278 10865 10865 F DEBUG   : signal 6 (SIGABRT), code -6 (SI_TKILL), fault addr --------
03-03 17:22:16.295 10865 10865 F DEBUG   : Abort message: 'Could not make wake event fd: Too many open files'
03-03 17:22:16.295 10865 10865 F DEBUG   :     x0   0000000000000000  x1   0000000000002a6e  x2   0000000000000006  x3   0000000000000008
03-03 17:22:16.295 10865 10865 F DEBUG   :     x4   fefeff7c6fd54487  x5   fefeff7c6fd54487  x6   fefeff7c6fd54487  x7   7f7f7f7f7fff7fff
03-03 17:22:16.295 10865 10865 F DEBUG   :     x8   0000000000000083  x9   8d9b2e0bd9a2bbef  x10  0000000000000000  x11  ffffffffffffffff
03-03 17:22:16.295 10865 10865 F DEBUG   :     x12  0000000000000018  x13  ffffffffffffffff  x14  ffffffffff000000  x15  ffffffffffffffff
03-03 17:22:16.295 10865 10865 F DEBUG   :     x16  000000635aa7cfa8  x17  0000007e0d70b5d8  x18  000000000000001a  x19  0000000000002468
03-03 17:22:16.295 10865 10865 F DEBUG   :     x20  0000000000002a6e  x21  0000000000000083  x22  0000007d70d64588  x23  0000000013640100
03-03 17:22:16.295 10865 10865 F DEBUG   :     x24  0000000000000008  x25  0000007d70d64588  x26  0000007d5f2f6ea0  x27  0000000000000002
03-03 17:22:16.295 10865 10865 F DEBUG   :     x28  0000000000000002  x29  0000007d70d63090  x30  0000007e0d6bebbc
03-03 17:22:16.295 10865 10865 F DEBUG   :     sp   0000007d70d63050  pc   0000007e0d6bebdc  pstate 0000000060000000
03-03 17:22:16.299   598   676 D SocketMoudle: connect: bind failed, try
03-03 17:22:16.379   598   676 D SocketMoudle: connect: bind failed, try

看到这样的log,对于年幼无知的我,感到一脸蒙逼啊!在百度上谷歌一下Too many open files,这个问题涉及到Linux系统文件句柄超限,是Linux进程的fd泄露问题,这是什么鬼?得好好研究一下了!
继续分析上面问题发生的原因,上面的log中打印 Could not make wake event fd: Too many open files这句log之前有一句打印是

pid: 9320, tid: 10862, name: Gps-Handler >>> com.xxx.car.vehicleeol <<<

可以发现是进程com.xxx.car.vehicleeol里的线程Gps-Handler引起了fd泄露的问题,搜索代码,在我的工程里发现了如下创建这个线程的方法:

init()这个方法会在每次执行GPS检测项时调用,GPS检测结束后会将mLocateOn设置为false,所以每次执行这个方法均会执行创建HandlerThread的代码,前文说的煲机测试就是一遍一遍地执行这些测试项。上面问题发生的原因应该就在这里了,应用进程在不断地创建HandlerThread对象,并执行start()。

为什么HandlerThread与fd泄露有关系?fd究竟在Linux OS中是什么?发生fd泄露的问题应该如何解决呢?借着解决这个问题的机会,我带着这些疑惑深入学习一下fd泄露的问题。

fd真相揭秘

Fd的全称是File descriptor,在Linux OS里,所有都可以抽象成文件,比如普通的文件、目录、块设备、字符设备、socket、管道等等。当通过一些系统调用(如open/socket等),会返回一个fd(一个数字),然后根据这个fd对应的文件进行操作,比如读、写。在内核进程结构体task_struct中为每个进程维护了一个数组,数组下标就是fd,里面存储的是对这个文件的描述。

Linux默认每个进程能打开的fd数最大值是1024,当应用进程打开的文件数超过这个限制值后就无法再打开文件了,系统会报相关的错误,Too many open files是Linux系统中程序打开的文件数过多的常见错误。

对于HandlerThread,我知道它实际上是一个Thread加上了一个Looper,在其run()方法中调用Looper.prepare()和Looper.loop()方法,这样就可以在子线程中运行Handler的handlerMessage方法进行消息处理了,这是之前对HandlerThread的浅显的认识。继续跟踪源码发现每一个Looper在创建的时候会打开两个fd,一个是eventfd,另外一个是mEpolled。上面问题中报的就是创建wake event fd时异常了。


fd是系统底层逻辑创建的,要修复这个问题应该控制上层应用逻辑,避免引起fd创建过多。对上面由HandlerThread引起的fd泄露问题如下修改,最终解决了问题。

搜索网上对这个问题的分析和解决,产生Too many open files问题主要有四种可能:
1、单个进程打开文件句柄数过多
2、操作系统打开的文件句柄数过多
3、systemd对该进程进行了限制
4、inotify达到上限

上面四种产生fd泄露的情况我归纳为两方面的原因,一是系统本身限制了可操作的文件句柄数,二是应用的逻辑问题导致文件句柄超出了系统设定的限制。要解决fd泄露的问题,一方面可以通过修改系统参数,增大允许操作的文件句柄数;另一方面修改应用程序内部逻辑,使得程序在运行时不会超过系统允许的最大文件句柄数。

fd泄露其他案例

可能引起fd泄露问题的情况有多种,fd泄露问题的主要特点是:
1、同一个问题可能出现在不同的堆栈
2、fd发生泄露时可能不存在内存不足的问题,触发GC不一定能回收创建的文件句柄

fd泄露问题的关键日志:

"Too many open files"
"Could not allocate JNI Env"
"Could not allocate dup blob fd"
"Could not read input channel file descriptors from parcel"
"pthread_create"
"InputChannel is not initialized"
"Could not open input channel pair"

容易引起fd泄露的常见情况:
1、HandlerThread
如前文分析,HandlerThread引发的fd泄露是由于频繁地创建HandlerThread对象,内部的Looper创建会导致fd超限。
2、Thread.start()
调用Thread.start()启动线程后,在native层调用open方法创建ashmem rigions,这会产生fd,如果循环地创建启动过多的线程就会产生fd泄露。
3、Resource相关
使用输入输出流没有关闭可能会出问题,FileInputStream、FileOutputStream、FileReader、FileWriter 等每打开一个文件需要fd,一些输入流也提供了基于fd的构造方法。文件流在finally块中调close方法,或者使用Java 7 编译器和运行环境支持的 try-with-resources 语句可以避免fd泄露。
4、InputChannel
对于system server,,如果有大量的socket 打开,可能是因为Input Channel没有关闭,抓取hprof查看system server中WindowState的情况进行分析。
5、Bitmap
创建Bitmap在native层会产生fd,如果使用完后不关闭,可能引发fd的泄露。

Thanks To

Too many open files的四种解决办法
too many open files(打开的文件过多)解决方法
Linux中Too many open files 问题分析和解决
应用与系统稳定性第三篇---FD泄露问题漫谈

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

推荐阅读更多精彩内容