Android JNI调用OpenCV,长时间运行内存异常,导致闪退的log分析和解决---(ReferenceTable overflow (max=1024)造成的)

首先交代下问题背景，前些日子自己在android上搞了个入侵检测玩。就是camera当作监控设备，每隔一定时间检测是否有东西入侵，如果入侵率到一定程度就报警的东西。最近发现，每次运行超过20分钟，app直接挂掉消失。下面附上核心完整log:

01-01 21:17:42.321 I/yan     ( 2588): /storage/sdcard0/InvadeDetect/ 111111111111101-01 21:17:42.650 E/PowerManagerService(  501): (GYP)enter sleep check_in_PowerMonitorHandler,mScreenIsOff=true;mScreenIsSwitchToOn=false mRequestSleepCount=4 mScreenOffTime=51430901-01 21:17:43.008 D/NvOsDebugPrintf(  163): NvCamGrinder HAL_camera_device_enable_msg_type 301-01 21:17:43.008 D/NvOsDebugPrintf(  163): NvCamGrinder HAL_camera_device_enable_msg_type 301-01 21:17:43.057 I/dalvikvm-heap( 2588): Grow heap (frag case) to 18.527MB for 1228816-byte allocation01-01 21:17:43.057 W/dalvikvm( 2588): JNI: pin count on array 0x410f1fd8 ([I) is now 101901-01 21:17:43.063 W/dalvikvm( 2588): JNI: pin count on array 0x410f1fd8 ([I) is now 101901-01 21:17:43.066 D/dalvikvm( 2588): GC_CONCURRENT freed 5780K, 45% free 7740K/14060K, paused 2ms+2ms, total 9ms01-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 RUNNABLE01-01 21:17:43.326 I/dalvikvm( 2588):   | group="main" sCount=0 dsCount=0 obj=0x40f89e08 self=0x5a6ca71001-01 21:17:43.327 I/dalvikvm( 2588):   | sysTid=3823 nice=0 sched=0/0 cgrp=apps handle=151707584001-01 21:17:43.327 I/dalvikvm( 2588):   | state=R schedstat=( 967539651465 45738384690 224828 ) utm=95515 stm=1238 core=201-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 aborting01-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 deadd00d01-01 21:17:43.553 I/DEBUG   (  157):     r0 00000000  r1 00000000  r2 deadd00d  r3 0000000001-01 21:17:43.553 I/DEBUG   (  157):     r4 4081cb58  r5 0000020c  r6 00000000  r7 4081cec001-01 21:17:43.553 I/DEBUG   (  157):     r8 5c775c54  r9 5c675e38  sl 5a6ca720  fp 5c775c6c01-01 21:17:43.553 I/DEBUG   (  157):     ip 00004000  sp 5c775598  lr 4004f3f9  pc 407a927c  cpsr 600b003001-01 21:17:43.554 I/DEBUG   (  157):     d0  74726f6261204d56  d1  6a2e79746976696e01-01 21:17:43.554 I/DEBUG   (  157):     d2  656d61432e746375  d3  697669746341616c01-01 21:17:43.554 I/DEBUG   (  157):     d4  7fefffffffffffff  d5  7fefffffffffffff01-01 21:17:43.554 I/DEBUG   (  157):     d6  c7efffffe0000000  d7  000000000000000001-01 21:17:43.555 I/DEBUG   (  157):     d8  3e6041893a83126f  d9  c0100000ffffffff01-01 21:17:43.555 I/DEBUG   (  157):     d10 bff3441350a65936  d11 3fd34413509f79fe01-01 21:17:43.555 I/DEBUG   (  157):     d12 3ddb7cdfd9d7bdbb  d13 000000000000000001-01 21:17:43.555 I/DEBUG   (  157):     d14 0000000000000000  d15 000000000000000001-01 21:17:43.555 I/DEBUG   (  157):     d16 0000000000000000  d17 433000000000000001-01 21:17:43.555 I/DEBUG   (  157):     d18 3fb0000000000000  d19 fffc0000fffc000001-01 21:17:43.555 I/DEBUG   (  157):     d20 0000000300000004  d21 000000010000000201-01 21:17:43.556 I/DEBUG   (  157):     d22 0707070703030303  d23 0000027f0000027f01-01 21:17:43.556 I/DEBUG   (  157):     d24 fffe0000ffff0000  d25 fffc0000fffd000001-01 21:17:43.556 I/DEBUG   (  157):     d26 0000028000000280  d27 000002800000028001-01 21:17:43.556 I/DEBUG   (  157):     d28 0000000200000003  d29 000000000000000101-01 21:17:43.556 I/DEBUG   (  157):     d30 0000000000000000  d31 000000000000000001-01 21:17:43.557 I/DEBUG   (  157):     scr 6000001301-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.so01-01 21:17:43.562 I/DEBUG   (  157):     #02  pc 0004a7e5  /system/lib/libdvm.so01-01 21:17:43.562 I/DEBUG   (  157):     #03  pc 0003b87f  /system/lib/libdvm.so01-01 21:17:43.562 I/DEBUG   (  157):     #04  pc 00016117  /system/lib/libjavacore.so01-01 21:17:43.562 I/DEBUG   (  157):     #05  pc 00019471  /system/lib/libjavacore.so01-01 21:17:43.563 I/DEBUG   (  157):     #06  pc 0001979b  /system/lib/libjavacore.so01-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*)[phone]: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.so01-01 21:17:43.564 I/DEBUG   (  157):     #11  pc 0002ab4c  /system/lib/libdvm.so (dvmInterpret(Thread*, Method const*, JValue*)[phone]:17:43.564 I/DEBUG   (  157):     #12  pc 0005f2b1  /system/lib/libdvm.so (dvmCallMethodV(Thread*, Method const*, Object*, bool, JValue*, std::__va_list)[phone]:17:43.564 I/DEBUG   (  157):     #13  pc 0005f2db  /system/lib/libdvm.so (dvmCallMethod(Thread*, Method const*, Object*, JValue*, ...)[phone]:17:43.564 I/DEBUG   (  157):     #14  pc 00053e57  /system/lib/libdvm.so01-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.so01-01 21:17:43.565 I/DEBUG   (  157):          5c775560  4007a1b4  /system/lib/libc.so01-01 21:17:43.565 I/DEBUG   (  157):          5c775564  4007a1b4  /system/lib/libc.so01-01 21:17:43.565 I/DEBUG   (  157):          5c775568  4007a1b4  /system/lib/libc.so01-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.so01-01 21:17:43.566 I/DEBUG   (  157):          5c775574  4007a1b4  /system/lib/libc.so01-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.so01-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.so01-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.so01-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.so01-01 21:17:43.562 I/DEBUG   (  157):     #02  pc 0004a7e5  /system/lib/libdvm.so01-01 21:17:43.562 I/DEBUG   (  157):     #03  pc 0003b87f  /system/lib/libdvm.so01-01 21:17:43.562 I/DEBUG   (  157):     #04  pc 00016117  /system/lib/libjavacore.so01-01 21:17:43.562 I/DEBUG   (  157):     #05  pc 00019471  /system/lib/libjavacore.so01-01 21:17:43.563 I/DEBUG   (  157):     #06  pc 0001979b  /system/lib/libjavacore.so01-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*)[phone]: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.so01-01 21:17:43.564 I/DEBUG   (  157):     #11  pc 0002ab4c  /system/lib/libdvm.so (dvmInterpret(Thread*, Method const*, JValue*)[phone]:17:43.564 I/DEBUG   (  157):     #12  pc 0005f2b1  /system/lib/libdvm.so (dvmCallMethodV(Thread*, Method const*, Object*, bool, JValue*, std::__va_list)[phone]:17:43.564 I/DEBUG   (  157):     #13  pc 0005f2db  /system/lib/libdvm.so (dvmCallMethod(Thread*, Method const*, Object*, JValue*, ...)[phone]:17:43.564 I/DEBUG   (  157):     #14  pc 00053e57  /system/lib/libdvm.so01-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