Android JNI调用OpenCV,长时间运行内存异常,导致闪退的log分析和解决---(ReferenceTable overflow (max=1024)造成的)
浏览数：39 /
时间：2015年06月11日
首先交代下问题背景，前些日子自己在android上搞了个入侵检测玩。就是camera当作监控设备，每隔一定时间检测是否有东西入侵，如果入侵率到一定程度就报警的东西。最近发现，每次运行超过20分钟，app直接挂掉消失。下面附上核心完整log:
01-01 21:17:42.321 I/yan ( 2588): /storage/sdcard0/InvadeDetect/ 1111111111111 01-01 21:17:42.650 E/PowerManagerService( 501): (GYP)enter sleep check_in_PowerMonitorHandler,mScreenIsOff=true;mScreenIsSwitchToOn=false mRequestSleepCount=4 mScreenOffTime=514309 01-01 21:17:43.008 D/NvOsDebugPrintf( 163): NvCamGrinder HAL_camera_device_enable_msg_type 3 01-01 21:17:43.008 D/NvOsDebugPrintf( 163): NvCamGrinder HAL_camera_device_enable_msg_type 3 01-01 21:17:43.057 I/dalvikvm-heap( 2588): Grow heap (frag case) to 18.527MB for 1228816-byte allocation 01-01 21:17:43.057 W/dalvikvm( 2588): JNI: pin count on array 0x410f1fd8 ([I) is now 1019 01-01 21:17:43.063 W/dalvikvm( 2588): JNI: pin count on array 0x410f1fd8 ([I) is now 1019 01-01 21:17:43.066 D/dalvikvm( 2588): GC_CONCURRENT freed 5780K, 45% free 7740K/14060K, paused 2ms+2ms, total 9ms 01-01 21:17:43.324 W/dalvikvm( 2588): ReferenceTable overflow (max=1024) 01-01 21:17:43.324 W/dalvikvm( 2588): JNI pinned array reference table (0x5d4440a8) dump: 01-01 21:17:43.324 W/dalvikvm( 2588): Last 10 entries (of 1024): 01-01 21:17:43.324 W/dalvikvm( 2588): 1023: 0x410f1f70 char[] (3 elements) 01-01 21:17:43.324 W/dalvikvm( 2588): 1022: 0x40c622e8 char[] (1 elements) 01-01 21:17:43.325 W/dalvikvm( 2588): 1021: 0x40c62268 char[] (1 elements) 01-01 21:17:43.325 W/dalvikvm( 2588): 1020: 0x40c61648 char[] (1 elements) 01-01 21:17:43.325 W/dalvikvm( 2588): 1019: 0x40e28ab8 char[] (5 elements) 01-01 21:17:43.325 W/dalvikvm( 2588): 1018: 0x410f1fd8 int[] (307200 elements) 01-01 21:17:43.325 W/dalvikvm( 2588): 1017: 0x410f1fd8 int[] (307200 elements) 01-01 21:17:43.325 W/dalvikvm( 2588): 1016: 0x410f1fd8 int[] (307200 elements) 01-01 21:17:43.325 W/dalvikvm( 2588): 1015: 0x410f1fd8 int[] (307200 elements) 01-01 21:17:43.325 W/dalvikvm( 2588): 1014: 0x410f1fd8 int[] (307200 elements) 01-01 21:17:43.325 W/dalvikvm( 2588): Summary: 01-01 21:17:43.326 W/dalvikvm( 2588): 3 of char[] (1 elements) (3 unique instances) 01-01 21:17:43.326 W/dalvikvm( 2588): 1 of char[] (3 elements) 01-01 21:17:43.326 W/dalvikvm( 2588): 1 of char[] (5 elements) 01-01 21:17:43.326 W/dalvikvm( 2588): 1019 of int[] (307200 elements) (1 unique instances) 01-01 21:17:43.326 E/dalvikvm( 2588): Failed adding to JNI pinned array ref table (1024 entries) 01-01 21:17:43.326 I/dalvikvm( 2588): "Thread-183" prio=5 tid=14 RUNNABLE 01-01 21:17:43.326 I/dalvikvm( 2588): | group="main" sCount=0 dsCount=0 obj=0x40f89e08 self=0x5a6ca710 01-01 21:17:43.327 I/dalvikvm( 2588): | sysTid=3823 nice=0 sched=0/0 cgrp=apps handle=1517075840 01-01 21:17:43.327 I/dalvikvm( 2588): | state=R schedstat=( 967539651465 45738384690 224828 ) utm=95515 stm=1238 core=2 01-01 21:17:43.327 I/dalvikvm( 2588): at libcore.icu.NativeDecimalFormat.open(Native Method) 01-01 21:17:43.327 I/dalvikvm( 2588): at libcore.icu.NativeDecimalFormat.<init>(NativeDecimalFormat.java:123) 01-01 21:17:43.327 I/dalvikvm( 2588): at java.text.DecimalFormat.initNative(DecimalFormat.java:556) 01-01 21:17:43.327 I/dalvikvm( 2588): at java.text.DecimalFormat.<init>(DecimalFormat.java:551) 01-01 21:17:43.327 I/dalvikvm( 2588): at java.text.DecimalFormat.<init>(DecimalFormat.java:529) 01-01 21:17:43.328 I/dalvikvm( 2588): at org.mo.invadedetect.CameraActivity.getRate(CameraActivity.java:513) 01-01 21:17:43.328 I/dalvikvm( 2588): at org.mo.invadedetect.CameraActivity$CheckProcessThread.run(CameraActivity.java:402) 01-01 21:17:43.328 I/dalvikvm( 2588): 01-01 21:17:43.328 E/dalvikvm( 2588): VM aborting 01-01 21:17:43.328 F/libc ( 2588): Fatal signal 11 (SIGSEGV) at 0xdeadd00d (code=1), thread 3823 (Thread-183) 01-01 21:17:43.430 I/DEBUG ( 157): *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** 01-01 21:17:43.430 I/DEBUG ( 157): Build fingerprint: ‘generic/pluto/pluto:4.2.2/JDQ39/eng.ztetd.20131210.002516:eng/release-keys‘ 01-01 21:17:43.430 I/DEBUG ( 157): Revision: ‘0‘ 01-01 21:17:43.431 I/DEBUG ( 157): pid: 2588, tid: 3823, name: Thread-183 >>> org.mo.invadedetect <<< 01-01 21:17:43.431 I/DEBUG ( 157): signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr deadd00d 01-01 21:17:43.553 I/DEBUG ( 157): r0 00000000 r1 00000000 r2 deadd00d r3 00000000 01-01 21:17:43.553 I/DEBUG ( 157): r4 4081cb58 r5 0000020c r6 00000000 r7 4081cec0 01-01 21:17:43.553 I/DEBUG ( 157): r8 5c775c54 r9 5c675e38 sl 5a6ca720 fp 5c775c6c 01-01 21:17:43.553 I/DEBUG ( 157): ip 00004000 sp 5c775598 lr 4004f3f9 pc 407a927c cpsr 600b0030 01-01 21:17:43.554 I/DEBUG ( 157): d0 74726f6261204d56 d1 6a2e79746976696e 01-01 21:17:43.554 I/DEBUG ( 157): d2 656d61432e746375 d3 697669746341616c 01-01 21:17:43.554 I/DEBUG ( 157): d4 7fefffffffffffff d5 7fefffffffffffff 01-01 21:17:43.554 I/DEBUG ( 157): d6 c7efffffe0000000 d7 0000000000000000 01-01 21:17:43.555 I/DEBUG ( 157): d8 3e6041893a83126f d9 c0100000ffffffff 01-01 21:17:43.555 I/DEBUG ( 157): d10 bff3441350a65936 d11 3fd34413509f79fe 01-01 21:17:43.555 I/DEBUG ( 157): d12 3ddb7cdfd9d7bdbb d13 0000000000000000 01-01 21:17:43.555 I/DEBUG ( 157): d14 0000000000000000 d15 0000000000000000 01-01 21:17:43.555 I/DEBUG ( 157): d16 0000000000000000 d17 4330000000000000 01-01 21:17:43.555 I/DEBUG ( 157): d18 3fb0000000000000 d19 fffc0000fffc0000 01-01 21:17:43.555 I/DEBUG ( 157): d20 0000000300000004 d21 0000000100000002 01-01 21:17:43.556 I/DEBUG ( 157): d22 0707070703030303 d23 0000027f0000027f 01-01 21:17:43.556 I/DEBUG ( 157): d24 fffe0000ffff0000 d25 fffc0000fffd0000 01-01 21:17:43.556 I/DEBUG ( 157): d26 0000028000000280 d27 0000028000000280 01-01 21:17:43.556 I/DEBUG ( 157): d28 0000000200000003 d29 0000000000000001 01-01 21:17:43.556 I/DEBUG ( 157): d30 0000000000000000 d31 0000000000000000 01-01 21:17:43.557 I/DEBUG ( 157): scr 60000013 01-01 21:17:43.561 I/DEBUG ( 157): 01-01 21:17:43.561 I/DEBUG ( 157): backtrace: 01-01 21:17:43.562 I/DEBUG ( 157): #00 pc 0004527c /system/lib/libdvm.so (dvmAbort+75) 01-01 21:17:43.562 I/DEBUG ( 157): #01 pc 00048499 /system/lib/libdvm.so 01-01 21:17:43.562 I/DEBUG ( 157): #02 pc 0004a7e5 /system/lib/libdvm.so 01-01 21:17:43.562 I/DEBUG ( 157): #03 pc 0003b87f /system/lib/libdvm.so 01-01 21:17:43.562 I/DEBUG ( 157): #04 pc 00016117 /system/lib/libjavacore.so 01-01 21:17:43.562 I/DEBUG ( 157): #05 pc 00019471 /system/lib/libjavacore.so 01-01 21:17:43.563 I/DEBUG ( 157): #06 pc 0001979b /system/lib/libjavacore.so 01-01 21:17:43.563 I/DEBUG ( 157): #07 pc 0001d850 /system/lib/libdvm.so (dvmPlatformInvoke+112) 01-01 21:17:43.563 I/DEBUG ( 157): #08 pc 0004ca1d /system/lib/libdvm.so (dvmCallJNIMethod(unsigned int const*, JValue*, Method const*, Thread*)+396) 01-01 21:17:43.563 I/DEBUG ( 157): #09 pc 000381d5 /system/lib/libdvm.so (dvmCheckCallJNIMethod(unsigned int const*, JValue*, Method const*, Thread*)+8) 01-01 21:17:43.563 I/DEBUG ( 157): #10 pc 00026c60 /system/lib/libdvm.so 01-01 21:17:43.564 I/DEBUG ( 157): #11 pc 0002ab4c /system/lib/libdvm.so (dvmInterpret(Thread*, Method const*, JValue*)+184) 01-01 21:17:43.564 I/DEBUG ( 157): #12 pc 0005f2b1 /system/lib/libdvm.so (dvmCallMethodV(Thread*, Method const*, Object*, bool, JValue*, std::__va_list)+272) 01-01 21:17:43.564 I/DEBUG ( 157): #13 pc 0005f2db /system/lib/libdvm.so (dvmCallMethod(Thread*, Method const*, Object*, JValue*, ...)+20) 01-01 21:17:43.564 I/DEBUG ( 157): #14 pc 00053e57 /system/lib/libdvm.so 01-01 21:17:43.564 I/DEBUG ( 157): #15 pc 0000e408 /system/lib/libc.so (__thread_entry+72) 01-01 21:17:43.564 I/DEBUG ( 157): #16 pc 0000daf4 /system/lib/libc.so (pthread_create+160) 01-01 21:17:43.565 I/DEBUG ( 157): 01-01 21:17:43.565 I/DEBUG ( 157): stack: 01-01 21:17:43.565 I/DEBUG ( 157): 5c775558 00000001 01-01 21:17:43.565 I/DEBUG ( 157): 5c77555c 4007a1b4 /system/lib/libc.so 01-01 21:17:43.565 I/DEBUG ( 157): 5c775560 4007a1b4 /system/lib/libc.so 01-01 21:17:43.565 I/DEBUG ( 157): 5c775564 4007a1b4 /system/lib/libc.so 01-01 21:17:43.565 I/DEBUG ( 157): 5c775568 4007a1b4 /system/lib/libc.so 01-01 21:17:43.566 I/DEBUG ( 157): 5c77556c 4004f3f9 /system/lib/libc.so (__sflush_locked+36) 01-01 21:17:43.566 I/DEBUG ( 157): 5c775570 4007a254 /system/lib/libc.so 01-01 21:17:43.566 I/DEBUG ( 157): 5c775574 4007a1b4 /system/lib/libc.so 01-01 21:17:43.567 I/DEBUG ( 157): 5c775578 00000000 01-01 21:17:43.567 I/DEBUG ( 157): 5c77557c 400503c9 /system/lib/libc.so (_fwalk+32) 01-01 21:17:43.567 I/DEBUG ( 157): 5c775580 4081cb58 /system/lib/libdvm.so 01-01 21:17:43.567 I/DEBUG ( 157): 5c775584 0000020c 01-01 21:17:43.567 I/DEBUG ( 157): 5c775588 00000000 01-01 21:17:43.567 I/DEBUG ( 157): 5c77558c 4081cec0 /system/lib/libdvm.so 01-01 21:17:43.567 I/DEBUG ( 157): 5c775590 df0027ad 01-01 21:17:43.568 I/DEBUG ( 157): 5c775594 00000000 01-01 21:17:43.568 I/DEBUG ( 157): #00 5c775598 00000000 01-01 21:17:43.568 I/DEBUG ( 157): 5c77559c 6c756e28 01-01 21:17:43.568 I/DEBUG ( 157): 5c7755a0 0000296c 01-01 21:17:43.569 I/DEBUG ( 157): 5c7755a4 00000000 01-01 21:17:43.569 I/DEBUG ( 157): 5c7755a8 00000000 01-01 21:17:43.569 I/DEBUG ( 157): 5c7755ac 00000000 01-01 21:17:43.569 I/DEBUG ( 157): 5c7755b0 00000000 01-01 21:17:43.569 I/DEBUG ( 157): 5c7755b4 00000000 01-01 21:17:43.570 I/DEBUG ( 157): 5c7755b8 00000000 01-01 21:17:43.570 I/DEBUG ( 157): 5c7755bc 00000000 01-01 21:17:43.570 I/DEBUG ( 157): 5c7755c0 00000000 01-01 21:17:43.570 I/DEBUG ( 157): 5c7755c4 00000000 01-01 21:17:43.570 I/DEBUG ( 157): 5c7755c8 00000000 01-01 21:17:43.571 I/DEBUG ( 157): 5c7755cc 00000000 01-01 21:17:43.571 I/DEBUG ( 157): 5c7755d0 00000000 01-01 21:17:43.571 I/DEBUG ( 157): 5c7755d4 00000000 01-01 21:17:43.571 I/DEBUG ( 157): ........ ........ 01-01 21:17:43.571 I/DEBUG ( 157): #01 5c7757b0 40c61bc8 /dev/ashmem/dalvik-heap (deleted) 01-01 21:17:43.572 I/DEBUG ( 157): 5c7757b4 000009b9 01-01 21:17:43.572 I/DEBUG ( 157): 5c7757b8 9b900019 01-01 21:17:43.572 I/DEBUG ( 157): 5c7757bc 40c61ba8 /dev/ashmem/dalvik-heap (deleted) 01-01 21:17:43.572 I/DEBUG ( 157): 5c7757c0 00000000 01-01 21:17:43.572 I/DEBUG ( 157): 5c7757c4 00000000 01-01 21:17:43.572 I/DEBUG ( 157): 5c7757c8 9b900019 01-01 21:17:43.573 I/DEBUG ( 157): 5c7757cc 407ae7e9 /system/lib/libdvm.so 01-01 21:17:43.573 I/DEBUG ( 157): #02 5c7757d0 5b1ed1a8 01-01 21:17:43.573 I/DEBUG ( 157): 5c7757d4 5a6ca710 01-01 21:17:43.574 I/DEBUG ( 157): 5c7757d8 00000000 01-01 21:17:43.574 I/DEBUG ( 157): 5c7757dc 00000001 01-01 21:17:43.574 I/DEBUG ( 157): 5c7757e0 5b1ed1a8
上面log里stack往下还有，我就不贴了。首先交代下，在这之前我并不知道问题是由ReferenceTable overflow (max=1024)造成的。拿到log后搜关键字"fatal"(除此外还可搜fault、error、fail)，很幸运直接定位到了问题:VM aborting虚拟机直接挂掉了，Fatal signal 11 (SIGSEGV) at 0xdeadd00d (code=1), thread 3823 (Thread-183)，第一感觉是内存是不是泄漏或溢出了。顺着这个线索往下找，看到关键字backtrace，凡是backtrace下带pc字样的地址都可以用NDK中或linux下的arm-linux-androideabi-addr2line工具将地址映射成函数名字。
01-01 21:17:43.561 I/DEBUG ( 157): backtrace: 01-01 21:17:43.562 I/DEBUG ( 157): #00 pc 0004527c /system/lib/libdvm.so (dvmAbort+75) 01-01 21:17:43.562 I/DEBUG ( 157): #01 pc 00048499 /system/lib/libdvm.so 01-01 21:17:43.562 I/DEBUG ( 157): #02 pc 0004a7e5 /system/lib/libdvm.so 01-01 21:17:43.562 I/DEBUG ( 157): #03 pc 0003b87f /system/lib/libdvm.so 01-01 21:17:43.562 I/DEBUG ( 157): #04 pc 00016117 /system/lib/libjavacore.so 01-01 21:17:43.562 I/DEBUG ( 157): #05 pc 00019471 /system/lib/libjavacore.so 01-01 21:17:43.563 I/DEBUG ( 157): #06 pc 0001979b /system/lib/libjavacore.so 01-01 21:17:43.563 I/DEBUG ( 157): #07 pc 0001d850 /system/lib/libdvm.so (dvmPlatformInvoke+112) 01-01 21:17:43.563 I/DEBUG ( 157): #08 pc 0004ca1d /system/lib/libdvm.so (dvmCallJNIMethod(unsigned int const*, JValue*, Method const*, Thread*)+396) 01-01 21:17:43.563 I/DEBUG ( 157): #09 pc 000381d5 /system/lib/libdvm.so (dvmCheckCallJNIMethod(unsigned int const*, JValue*, Method const*, Thread*)+8) 01-01 21:17:43.563 I/DEBUG ( 157): #10 pc 00026c60 /system/lib/libdvm.so 01-01 21:17:43.564 I/DEBUG ( 157): #11 pc 0002ab4c /system/lib/libdvm.so (dvmInterpret(Thread*, Method const*, JValue*)+184) 01-01 21:17:43.564 I/DEBUG ( 157): #12 pc 0005f2b1 /system/lib/libdvm.so (dvmCallMethodV(Thread*, Method const*, Object*, bool, JValue*, std::__va_list)+272) 01-01 21:17:43.564 I/DEBUG ( 157): #13 pc 0005f2db /system/lib/libdvm.so (dvmCallMethod(Thread*, Method const*, Object*, JValue*, ...)+20) 01-01 21:17:43.564 I/DEBUG ( 157): #14 pc 00053e57 /system/lib/libdvm.so 01-01 21:17:43.564 I/DEBUG ( 157): #15 pc 0000e408 /system/lib/libc.so (__thread_entry+72) 01-01 21:17:43.564 I/DEBUG ( 157): #16 pc 0000daf4 /system/lib/libc.so (pthread_create+160)
backtrace下面列的从#16到#00，是一个堆栈式调用，#16在栈底所以是最先进栈，即最先调用的，然后是#15依次类推。从上面来看都是libc.so和libdvm.so出的问题，这些都是系统标准的一般不可能出问题。如果是自己生成的so的话，还真可能是自己的so造成的内存异常，稍后我会贡献一个示例，顺便介绍下addr2line的使用。
所以我怀疑找错了方向，那不是在VM挂掉之前log里就有异常了？往上看，看到Failed adding to JNI pinned array ref table (1024 entries)，不能够将jni里指向的数组引用添加。再往上找看到关键的一句:ReferenceTable overflow (max=1024),经查是引用计数器溢出了，最大为1024.即java的内存管理机制是基于引用的，需要计数器来记录引用的次数。在overflow这句话得后面当引用计数达到1024时还dump出了最近的10个引用，Summary了哪些引用有多少个，可以看到有1019个对int[]数组的引用，剩下的是对char[]的引用。我恍然大悟，我在jni里不停的通过下面来接收int数组，将其转为opencv的mat矩阵:
jint *cbuf;
cbuf = env->GetIntArrayElements(buf, false);
if(cbuf == NULL)
{
return ;
}
Mat mat(h, w, CV_8UC4, (unsigned char*)cbuf);却一直没有释放。想到这，又搜了下资料，参考这里 在原有代码基础上增加释放cbuf的语句就ok了:env->ReleaseIntArrayElements(buf, cbuf, 0);参考Android NDK之JNI陷阱 在用到NewByteArray类似方法时一定要DeleteLocalRef()，使用GetByteArrayELement时(本文即使如此)要用ReleaseByteArrayElements来进行释放。
稍后，会介绍Android和JNI层的OpenCV交互时，关于怎么传数据的两种方法，本例中使用的是传int数组的方法，如果有图片需要返回，就再返回一个jnitArray。
结语: 碰到内存泄漏或异常的问题不要怕，寻根探源只要能定位到问题便解决了一大半了。正如六祖曰烦恼即菩提，李小龙说问题即答案，当你真正明白了问题，也就找到了答案！呵呵，漫漫程序路, 何尝不是如此呢。。。
--------------------------------------------------------本文系原创，转载请注明作者:yanzi1225627
郑重声明：本站内容如果来自互联网及其他传播媒体，其版权均属原媒体及文章作者所有。转载目的在于传递更多信息及用于网络分享，并不代表本站赞同其观点和对其真实性负责，也不构成任何其他建议。
