E IMemory : cannot dup fd=988, size=4968448, err=0 (Too many open files)

Posted 2022-12-02 小筱萌

错误日志

 E IMemory : cannot dup fd=988, size=4968448, err=0 (Too many open files)
 E IMemory : cannot map BpMemoryHeap (binder=0x72af762820), size=4968448, fd=-1 (Bad file descriptor)

背景：自主研发的虹膜识别一体机，从硬件-系统-算法-软件都是我们自己研发的，现在就是在android应用层调用相机实现识别的过程中每隔半个小时就会崩溃一次，log日志如下：

01-18 17:45:18.749  1460  2817 E IMemory : cannot dup fd=988, size=4968448, err=0 (Too many open files)
01-18 17:45:18.749  1460  2817 E IMemory : cannot map BpMemoryHeap (binder=0x72af762820), size=4968448, fd=-1 (Bad file descriptor)
--------- beginning of crash
01-18 17:45:19.075  8272  8272 F DEBUG   : *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
01-18 17:45:19.075  8272  8272 F DEBUG   : Build fingerprint: 'Android/nanopc_t4/nanopc-t4:7.1.2/NHG47K/root01222110:userdebug/test-keys'
01-18 17:45:19.075  8272  8272 F DEBUG   : Revision: '0'
01-18 17:45:19.075  8272  8272 F DEBUG   : ABI: 'arm64'
01-18 17:45:19.075  8272  8272 F DEBUG   : pid: 1460, tid: 2817, name: Binder:1460_9  >>> cn.com.iristar.smartas <<<
01-18 17:45:19.076  8272  8272 F DEBUG   : signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 0x0
01-18 17:45:19.076  8272  8272 F DEBUG   :     x0   0000000000000000  x1   000000763cb2ef10  x2   000000763ca00000  x3   0000000000000005
01-18 17:45:19.076  8272  8272 F DEBUG   :     x4   000000000000012e  x5   0000000000000000  x6   0000000000000000  x7   00000000001e5a76
01-18 17:45:19.076  8272  8272 F DEBUG   :     x8   0000000000000000  x9   00000079c07f3b48  x10  000000000000012e  x11  00000079cce0d4e8
01-18 17:45:19.076  8272  8272 F DEBUG   :     x12  0000000000000018  x13  0000000050f919ae  x14  002c864f77af3653  x15  00002b2f56f39014
01-18 17:45:19.076  8272  8272 F DEBUG   :     x16  0000007a16c2c5b0  x17  0000007a16bd3e68  x18  0000000000000000  x19  00000079f81ec640
01-18 17:45:19.076  8272  8272 F DEBUG   :     x20  0000007a16f1d000  x21  0000000000000010  x22  0000007a0a6d4b60  x23  0000000000000010
01-18 17:45:19.076  8272  8272 F DEBUG   :     x24  00000079cce0cfa0  x25  000000000000275d  x26  00000000000005b4  x27  0000007a19779d00
01-18 17:45:19.076  8272  8272 F DEBUG   :     x28  0000000000000001  x29  00000079cce0cf40  x30  0000007a16e866dc
01-18 17:45:19.076  8272  8272 F DEBUG   :     sp   00000079cce0cf40  pc   0000007a16e866e4  pstate 0000000020000000
01-18 17:45:19.086  8272  8272 F DEBUG   : 
01-18 17:45:19.086  8272  8272 F DEBUG   : backtrace:
01-18 17:45:19.086  8272  8272 F DEBUG   :     #00 pc 000000000012d6e4  /system/lib64/libandroid_runtime.so (_ZN16JNICameraContext11copyAndPostEP7_JNIEnvRKN7android2spINS2_7IMemoryEEEi+96)
01-18 17:45:19.086  8272  8272 F DEBUG   :     #01 pc 000000000012ddac  /system/lib64/libandroid_runtime.so (_ZN16JNICameraContext8postDataEiRKN7android2spINS0_7IMemoryEEEP21camera_frame_metadata+104)
01-18 17:45:19.086  8272  8272 F DEBUG   :     #02 pc 000000000003bc1c  /system/lib64/libcamera_client.so (_ZN7android6Camera12dataCallbackEiRKNS_2spINS_7IMemoryEEEP21camera_frame_metadata+168)
01-18 17:45:19.086  8272  8272 F DEBUG   :     #03 pc 00000000000446a8  /system/lib64/libcamera_client.so (_ZN7android8hardware14BnCameraClient10onTransactEjRKNS_6ParcelEPS2_j+624)
01-18 17:45:19.086  8272  8272 F DEBUG   :     #04 pc 0000000000049e74  /system/lib64/libbinder.so (_ZN7android7BBinder8transactEjRKNS_6ParcelEPS1_j+132)
01-18 17:45:19.086  8272  8272 F DEBUG   :     #05 pc 0000000000055c34  /system/lib64/libbinder.so (_ZN7android14IPCThreadState14executeCommandEi+992)
01-18 17:45:19.086  8272  8272 F DEBUG   :     #06 pc 0000000000055798  /system/lib64/libbinder.so (_ZN7android14IPCThreadState20getAndExecuteCommandEv+156)
01-18 17:45:19.086  8272  8272 F DEBUG   :     #07 pc 0000000000055e4c  /system/lib64/libbinder.so (_ZN7android14IPCThreadState14joinThreadPoolEb+72)
01-18 17:45:19.087  8272  8272 F DEBUG   :     #08 pc 0000000000072d94  /system/lib64/libbinder.so
01-18 17:45:19.087  8272  8272 F DEBUG   :     #09 pc 000000000001245c  /system/lib64/libutils.so (_ZN7android6Thread11_threadLoopEPv+272)
01-18 17:45:19.087  8272  8272 F DEBUG   :     #10 pc 000000000009f1b0  /system/lib64/libandroid_runtime.so (_ZN7android14AndroidRuntime15javaThreadShellEPv+116)
01-18 17:45:19.087  8272  8272 F DEBUG   :     #11 pc 0000000000068748  /system/lib64/libc.so (_ZL15__pthread_startPv+208)
01-18 17:45:19.087  8272  8272 F DEBUG   :     #12 pc 000000000001da7c  /system/lib64/libc.so (__start_thread+16)

最开始出现这个错误的时候一直以为是系统崩溃了，但是抓到的log多了之后就会发现每次崩溃之前都会有(Too many open files)的IMemory错误级别的日志出现，从字面意思上可以看出是打开的文件太多导致的崩溃，首先想到的第一个思路就是用adb shell查看当前进程中所有打开的文件，步骤如下：
1.ps | grep XXX
查看当前工程的进程ID
2. lsof -p 17419 | wc -l
能看见打开的文件一直在涨，并没有下降，这就是问题的所在了
3. lsof -p 进程id >/sdcard/openfiles.log
这一步主要是将所有打开的文件列表保存下来，多保存几次然后比对差别，看是哪些文件在重复的打开，我这里有个 /data/app/XX.XX.XX.XX-1/base.apk一直在刷,可以看出来是apk内部文件打开的问题，于是经过代码复盘找到了一处问题：SoundPool在使用过程中有两个问题：

soundId = soundPool.load(context, R.raw.right, 1);

使用完之后并没有unload操作，于是在页面销毁的时候添加unload方法，查看当前打开文件数基本保持在570左右，并没有持续上涨，由此搞定。

nanopc-t4:/ # lsof -p 3703 | wc -l
582
nanopc-t4:/ # lsof -p 3703 | wc -l
578
nanopc-t4:/ # lsof -p 3703 | wc -l
580
nanopc-t4:/ # lsof -p 3703 | wc -l
560
nanopc-t4:/ # lsof -p 3703 | wc -l
554
nanopc-t4:/ # lsof -p 3703 | wc -l
554
nanopc-t4:/ # lsof -p 3703 | wc -l
579
nanopc-t4:/ # lsof -p 3703 | wc -l
575
nanopc-t4:/ # lsof -p 3703 | wc -l
575
nanopc-t4:/ # lsof -p 3703 | wc -l
575

注意：我这边把音频文件放入了raw文件夹下，如果你放在assect中的话需要使用AssetFileDescriptor，切记使用完毕之后需要释放调用close。