2018 September 14

Java Jna崩溃分析

问题

windows上java的程序崩溃，生成了hs_err_pid文件，查看事件管理器，application中有level为error的事件，都是由java的jna调用的一个videoLib.dll引起的，exception code是0xc0000005。

环境java6 update17，win732位，i7，4G物理内存

hs_err_pid文件很多，大多数如下：

A fatal error has been detected by the Java Runtime Environment:

java.lang.OutOfMemoryError: requested 1048576 bytes for jbyte in C: \BUILD_AREA\jdk6_17\hotspot\src\share\vm\prims\jni.cpp. Out of swap space?

Internal Error (allocation.inline.hpp: 39), pid=4104, tid=5144 Error: jbyte in C: \BUILD_AREA\jdk6_17\hotspot\src\share\vm\prims\jni.cpp

JRE version: 6.0_17-b04 Java VM: Java HotSpot(TM) Client VM (14.3-b01 mixed mode windows-x86 ) If you would like to submit a bug report, please visit: http: //java.sun.com/webapps/bugreport/crash.jsp

————— T H R E A D ————— …

————— P R O C E S S —————

Java Threads: ( =current thread ) … Other Threads: 0x01a8d000 VMThread [stack: 0x2bda0000,0x2bea0000] [id=5932] 0x01adbc00 WatcherThread [stack: 0x2c4a0000,0x2c5a0000] [id=4876]

VM state: not at safepoint (normal execution)

VM Mutex/Monitor currently owned by a thread: None

Heap def new generation total 4288K, used 1353K [0x03b60000, 0x04000000, 0x062c0000) eden space 3840K, 35% used [0x03b60000, 0x03cb0b60, 0x03f20000) from space 448K, 1% used [0x03f20000, 0x03f21ab8, 0x03f90000) to space 448K, 0% used [0x03f90000, 0x03f90000, 0x04000000) tenured generation total 56100K, used 47174K [0x062c0000, 0x09989000, 0x23b60000) the space 56100K, 84% used [0x062c0000, 0x090d18a8, 0x090d1a00, 0x09989000) compacting perm gen total 65536K, used 44388K [0x23b60000, 0x27b60000, 0x2bb60000) the space 65536K, 67% used [0x23b60000, 0x266b91c0, 0x266b9200, 0x27b60000) No shared spaces configured.

Dynamic libraries: …

VM Arguments: jvm_args: -Dosgi.requiredJavaVersion=1.5 -XX: PermSize=64M -XX: MaxPermSize=128m -Xms40m -Xmx512m -Dfile.encoding=UTF-8 -Din.eclipse=false -NL en_US java_command: Launcher Type: generic

Environment Variables: …

————— S Y S T E M —————

OS: Windows 7 Build 7601 Service Pack 1

CPU: total 8 (8 cores per cpu, 2 threads per core) family 6 model 58 stepping 9, cmov, cx8, fxsr, mmx, sse, sse2, sse3, ssse3, sse4.1, sse4.2, ht

Memory: 4k page, physical 2097151k(1046204k free), swap 4194303k(3631272k free)

vm_info: Java HotSpot(TM) Client VM (14.3-b01) for windows-x86 JRE (1.6.0_17-b04), built on Oct 11 2009 00: 52: 06 by “java_re” with MS VC++ 7.1

time: Fri May 11 17: 44: 26 2018 elapsed time: 26428 seconds

还有一个文件如下：

java.lang.OutOfMemoryError: requested 1024000 bytes for GrET in C:\BUILD_AREA\jdk6_17\hotspot\src\share\vm\utilities\growableArray.cpp. Out of swap space?

分析

内存溢出？

因为很多OutOfMemoryError的问题，开始怀疑是内存不足导致的。看堆内存：

Heap def new generation total 4288K, used 1353K [0x03b60000, 0x04000000, 0x062c0000)

tenured generation total 56100K, used 47174K [0x062c0000, 0x09989000, 0x23b60000)

compacting perm gen total 65536K, used 44388K [0x23b60000, 0x27b60000, 0x2bb60000)

新生代才4M用了1M多，老年代56M用了47M，永久代65M用了44M，这才4 + 56 + 65 也就120M+，其他的有java 虚拟机栈、本地方法栈、jvm、NIO、PC计数器等，程序中连接不多NIO也用不了多少内存。那很可能是jna调用的本地方法占用了大量内存。

写个demo复现下问题，java 6(java 8不会生成hs_err_pid.log文件，只是打出个异常栈然后就jvm退出了，不是崩溃)使用jna调用一个c的dll，这个c的dll一直new出内存来。代码如下：

int __stdcall add( int a, int b )
{
#if 1
	printf("out of memory error.\r\n");
	for (int i=0; i<1000*1000*10; i++)
	{
		printf("%dM\r\n", i*10);
		char *p = new char[1024*1024*10]();
	}
#endif
	return a + b;
}

java调用主要代码如下：

import com.sun.jna.*;

public class Add {
    public interface CAdd extends Library {
        CAdd INSTANCE = (CAdd) Native.loadLibrary(("DebugTest"), CAdd.class);
        int add(int a, int b);
    }

    public static void test() {
        System.out.println(CAdd.INSTANCE.add(1, 2));
    }
}

生成的err文件头如下，说是个EXCEPTION_UNCAUGHT_CXX_EXCEPTION异常，并不是OutOfMemoryError异常。

A fatal error has been detected by the Java Runtime Environment:

EXCEPTION_UNCAUGHT_CXX_EXCEPTION (0xe06d7363) at pc=0x77c63f12, pid=4740, tid=19416

JRE version: 6.0_38-b05 Java VM: Java HotSpot(TM) Client VM (20.13-b02 mixed mode windows-x86 ) Problematic frame: C [KERNELBASE.dll+0x103f12]

If you would like to submit a bug report, please visit: http://java.sun.com/webapps/bugreport/crash.jsp The crash happened outside the Java Virtual Machine in native code. See problematic frame for where to report the bug.

进一步分析，在出问题的时候，操作系统的内存情况

Memory: 4k page, physical 2097151k(1046204k free), swap 4194303k(3631272k free)

还有1G的空闲，而且交换分区也没有满。虽然32位系统上进程地址用户空间最大只有2G，但是系统也就用了1个G，即使全部给java的进程也没有超出这个限制。

在jna调用本地方法导致内存溢出错误日志的类型与系统使用内存上看，并不像是内存溢出。

JVM bug

然后搜索了下，发现了Fatal JVM Crash - ‘java.lang.OutOfMemoryError .. Out of Swap Space?’ 和 JVM crash in 6u20 with Internal Error (allocation.inline.hpp:39) 两篇，虽然第二篇是openjdk的，但很有可能是jvm的bug。解决方式就是升级jav6 到最新的update38。

内存非法访问

在windows的事件中有很多0xc0000005的错误，但是jvm的崩溃日志里面没有。做个demo验证下，dll的代码：

int __stdcall add( int a, int b )
{
#if 1
	printf("access error.\r\n");
	char *p = NULL;
	*p = 'a';
#endif
	return a + b;
}

his_err日志的头：

A fatal error has been detected by the Java Runtime Environment:

EXCEPTION_ACCESS_VIOLATION (0xc0000005) at pc=0x1b89d775, pid=6248, tid=13848

JRE version: 6.0_38-b05 Java VM: Java HotSpot(TM) Client VM (20.13-b02 mixed mode windows-x86 ) Problematic frame: C [DebugTest.dll+0x2d775]

If you would like to submit a bug report, please visit: http://java.sun.com/webapps/bugreport/crash.jsp The crash happened outside the Java Virtual Machine in native code. See problematic frame for where to report the bug.

说的很明确，就是EXCEPTION_ACCESS_VIOLATION，但是在windows的事件产生的时候，没有对应的jvm的崩溃日志，暂时不知道什么情况。

而且崩溃的日志中，堆栈信息也很全：

Stack: [0x026b0000,0x02700000], sp=0x026ff740, free space=317k Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code) C [DebugTest.dll+0x2d775] add+0x35 C [jna6882049194379198956.dll+0xcb77] Java_com_sun_jna_Native_initialize_1ffi_1type+0x37d7 C [jna6882049194379198956.dll+0xc7c2] Java_com_sun_jna_Native_initialize_1ffi_1type+0x3422 C [jna6882049194379198956.dll+0x4561] Java_com_sun_jna_Pointer__1getString+0xa31 C [jna6882049194379198956.dll+0x4d2e] Java_com_sun_jna_Function_invokeInt+0x2e j com.sun.jna.Function.invokeInt(I[Ljava/lang/Object;)I+0 j com.sun.jna.Function.invoke([Ljava/lang/Object;Ljava/lang/Class;Z)Ljava/lang/Object;+315 j com.sun.jna.Function.invoke(Ljava/lang/Class;[Ljava/lang/Object;Ljava/util/Map;)Ljava/lang/Object;+214 j com.sun.jna.Library$Handler.invoke(Ljava/lang/Object;Ljava/lang/reflect/Method;[Ljava/lang/Object;)Ljava/lang/Object;+341 j $Proxy0.add(II)I+26 j Add.test()V+8 j Main.main([Ljava/lang/String;)V+8 v ~StubRoutines::call_stub V [jvm.dll+0xfb86b] V [jvm.dll+0x18d531]

第三行，[DebugTest.dll+0x2d775] add+0x35，在调用DebugTest.dll的add方法时候导致的。

代码的地址

java-jna-crash-debug

参考

JVM crash in 6u20 with Internal Error (allocation.inline.hpp:39)
Fatal JVM Crash - ‘java.lang.OutOfMemoryError .. Out of Swap Space?’
Application Error (0xc0000005)