第一次看到HotSpot挂在JIT线程上……

多谢某同学发log给我看，让我第一次见识到HotSpot在编译器线程挂掉是啥样。可惜他跑的不是debug的HotSpot，看不到挂的时候在jvm.dll的什么函数，只能看到偏移量。

log如下：

#
# An unexpected error has been detected by HotSpot Virtual Machine:
#
#  EXCEPTION_ACCESS_VIOLATION (0xc0000005) at pc=0x6dad11ee, pid=4060, tid=1068
#
# Java VM: Java HotSpot(TM) Server VM (1.5.0_20-b02 mixed mode)
# Problematic frame:
# V  [jvm.dll+0x1f11ee]
#

---------------  T H R E A D  ---------------

Current thread (0x458142d8):  JavaThread "CompilerThread0" daemon [_thread_in_native, id=1068]

siginfo: ExceptionCode=0xc0000005, reading address 0x00000004

Registers:
EAX=0x00000000, EBX=0x46485578, ECX=0x45d3f3a8, EDX=0x00000000
ESP=0x45d3f0e8, EBP=0x00000000, ESI=0x45d3f3b8, EDI=0x45d3f3a8
EIP=0x6dad11ee, EFLAGS=0x00010216

Top of Stack: (sp=0x45d3f0e8)
0x45d3f0e8:   45d3f3b8 6dad310d 46485578 48120e00
0x45d3f0f8:   45d3f16c 4a96eeb4 45d3f17c 4a969fb0
0x45d3f108:   49f2dfd8 46485578 4a96e560 6dad2ecd
0x45d3f118:   4a96eeb4 00000000 45d3f3a8 464855c0
0x45d3f128:   00000000 00000001 00000050 00000050
0x45d3f138:   45d3f3a8 000001c3 6dad1759 45d3f17c
0x45d3f148:   45d3f16c 45d3f18c 00000000 0000002b
0x45d3f158:   45d3f818 45d3f6cc 00000000 4c1f1da0 

Instructions: (pc=0x6dad11ee)
0x6dad11de:   00 90 8b 44 24 04 56 8b 50 1c 8b 41 58 8b 04 90
0x6dad11ee:   8b 50 04 83 3a 00 75 1e 8b 51 14 8b 40 1c 3b c2 


Stack: [0x45d00000,0x45d40000),  sp=0x45d3f0e8,  free space=252k
Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
V  [jvm.dll+0x1f11ee]

[error occurred during error reporting, step 120, id 0xc0000005]


Current CompileTask:
opto: 20% !   org.jboss.deployment.JARDeployer.accepts(Lorg/jboss/deployment/DeploymentInfo;)Z @ 354 (665 bytes)


---------------  P R O C E S S  ---------------

Java Threads: ( => current thread )
  0x4bbb7ea8 JavaThread "IndexMerger" daemon [_thread_blocked, id=3872]
  0x4bbb7b98 JavaThread "Timer-3" daemon [_thread_blocked, id=4828]
  0x4bbb7a10 JavaThread "IndexMerger" daemon [_thread_blocked, id=4912]
  0x4bbb7700 JavaThread "ObservationManager" daemon [_thread_blocked, id=4372]
  0x4bbb7888 JavaThread "Transient File Reaper" daemon [_thread_blocked, id=1216]
  0x4bbb7578 JavaThread "jbm-response-executor" [_thread_blocked, id=4196]
  0x4bbb73f0 JavaThread "jbm-reply-executor" [_thread_blocked, id=2440]
  0x4bbb7268 JavaThread "Thread-11" daemon [_thread_blocked, id=3680]
  0x4bbb6dd0 JavaThread "jbm-cf-jndimapper" [_thread_blocked, id=3372]
  0x4bbb70e0 JavaThread "JCA PoolFiller" [_thread_blocked, id=3212]
  0x4bbb6f58 JavaThread "HSQLDB Timer @8aaed5" daemon [_thread_blocked, id=4484]
  0x4bbb6c48 JavaThread "DefaultQuartzScheduler_QuartzSchedulerThread" [_thread_blocked, id=376]
  0x4bbb6ac0 JavaThread "DefaultQuartzScheduler_Worker-9" [_thread_blocked, id=3488]
  0x4bbb6938 JavaThread "DefaultQuartzScheduler_Worker-8" [_thread_blocked, id=4280]
  0x4732a7c0 JavaThread "DefaultQuartzScheduler_Worker-7" [_thread_blocked, id=316]
  0x49f8ade8 JavaThread "DefaultQuartzScheduler_Worker-6" [_thread_blocked, id=3312]
  0x49f8ac60 JavaThread "DefaultQuartzScheduler_Worker-5" [_thread_blocked, id=3144]
  0x49f8aad8 JavaThread "DefaultQuartzScheduler_Worker-4" [_thread_blocked, id=4824]
  0x49f8a950 JavaThread "DefaultQuartzScheduler_Worker-3" [_thread_blocked, id=2980]
  0x49f8a7c8 JavaThread "DefaultQuartzScheduler_Worker-2" [_thread_blocked, id=4132]
  0x49f8a640 JavaThread "DefaultQuartzScheduler_Worker-1" [_thread_blocked, id=3184]
  0x49f8a330 JavaThread "DefaultQuartzScheduler_Worker-0" [_thread_blocked, id=3656]
  0x49f8a1a8 JavaThread "WorkManager(2)-1" daemon [_thread_blocked, id=4428]
  0x4732a638 JavaThread "Thread-9" daemon [_thread_blocked, id=3112]
  0x4732a4b0 JavaThread "Timer-2" daemon [_thread_blocked, id=2948]
  0x4732a1a0 JavaThread "ContainerBackgroundProcessor[StandardEngine[jboss.web]]" daemon [_thread_blocked, id=2844]
  0x4732a018 JavaThread "SubscriptionWatchDog" [_thread_blocked, id=4240]
  0x47329d08 JavaThread "secondaryServerSocketThread" daemon [_thread_in_native, id=1020]
  0x473299f8 JavaThread "ServerSocketRefresh" daemon [_thread_blocked, id=4304]
  0x47329b80 JavaThread "AcceptorThread#0:4457" [_thread_in_native, id=4252]
  0x473296e8 JavaThread "ServerSocketRefresh" daemon [_thread_blocked, id=4152]
  0x47329560 JavaThread "AcceptorThread#0:3873" [_thread_in_native, id=2620]
  0x47329250 JavaThread "ServerSocketRefresh" daemon [_thread_blocked, id=3808]
  0x473290c8 JavaThread "AcceptorThread#0:4446" [_thread_in_native, id=1552]
  0x47328f40 JavaThread "PooledInvokerAcceptor#0-4445" [_thread_in_native, id=2236]
  0x47328aa8 JavaThread "RMI TCP Accept-4444" daemon [_thread_in_native, id=5068]
  0x47328c30 JavaThread "Listener:60539" daemon [_thread_in_native, id=4148]
  0x463c4e78 JavaThread "Thread-5" daemon [_thread_blocked, id=3120]
  0x463c4cf0 JavaThread "Thread-4" daemon [_thread_blocked, id=3732]
  0x463c4b68 JavaThread "Listener:60536" daemon [_thread_in_native, id=172]
  0x463c49e0 JavaThread "JBoss System Threads(1)-2" daemon [_thread_in_native, id=1660]
  0x463c4858 JavaThread "GC Daemon" daemon [_thread_blocked, id=3900]
  0x463c46d0 JavaThread "RMI Reaper" [_thread_blocked, id=1344]
  0x463c4548 JavaThread "Timer-1" daemon [_thread_blocked, id=2244]
  0x463c43c0 JavaThread "RMI TCP Accept-1098" daemon [_thread_in_native, id=3688]
  0x463c4238 JavaThread "JBoss System Threads(1)-1" daemon [_thread_in_native, id=3988]
  0x463c40b0 JavaThread "ScannerThread" daemon [_thread_blocked, id=3376]
  0x463c3f28 JavaThread "Timer-0" daemon [_thread_blocked, id=1332]
  0x0021a8b8 JavaThread "DestroyJavaVM" [_thread_blocked, id=4056]
  0x458b9348 JavaThread "main" [_thread_in_native, id=3712]
  0x458148a8 JavaThread "Low Memory Detector" daemon [_thread_blocked, id=640]
  0x45814468 JavaThread "CompilerThread1" daemon [_thread_blocked, id=2212]
=>0x458142d8 JavaThread "CompilerThread0" daemon [_thread_in_native, id=1068]
  0x45809ed8 JavaThread "AdapterThread" daemon [_thread_blocked, id=3444]
  0x45807f30 JavaThread "Signal Dispatcher" daemon [_thread_blocked, id=4684]
  0x45806f80 JavaThread "JDWP Event Helper Thread" daemon [_thread_blocked, id=468]
  0x457ffdf8 JavaThread "JDWP Transport Listener: dt_socket" daemon [_thread_in_native, id=3240]
  0x0050ef90 JavaThread "Finalizer" daemon [_thread_blocked, id=3980]
  0x0050d3d8 JavaThread "Reference Handler" daemon [_thread_blocked, id=3420]

Other Threads:
  0x457f0d50 VMThread [id=944]
  0x45807af8 WatcherThread [id=4796]

VM state:not at safepoint (normal execution)

VM Mutex/Monitor currently owned by a thread: None

Heap
 def new generation   total 13120K, used 11233K [0x053d0000, 0x06200000, 0x08cb0000)
  eden space 11712K,  93% used [0x053d0000, 0x05e895a0, 0x05f40000)
  from space 1408K,  17% used [0x060a0000, 0x060df050, 0x06200000)
  to   space 1408K,   0% used [0x05f40000, 0x05f40000, 0x060a0000)
 tenured generation   total 116544K, used 40681K [0x08cb0000, 0x0fe80000, 0x253d0000)
   the space 116544K,  34% used [0x08cb0000, 0x0b46a640, 0x0b46a800, 0x0fe80000)
 compacting perm gen  total 65536K, used 33657K [0x253d0000, 0x293d0000, 0x453d0000)
   the space 65536K,  51% used [0x253d0000, 0x274ae5a0, 0x274ae600, 0x293d0000)
No shared spaces configured.

Dynamic libraries:
0x00400000 - 0x0040d000 	C:\Program Files (x86)\Java\jdk1.5.0_20\bin\java.exe
0x776f0000 - 0x77870000 	C:\Windows\SysWOW64\ntdll.dll
0x752c0000 - 0x753c0000 	C:\Windows\syswow64\kernel32.dll
0x75470000 - 0x754b6000 	C:\Windows\syswow64\KERNELBASE.dll
0x76c50000 - 0x76cf0000 	C:\Windows\syswow64\ADVAPI32.dll
0x75680000 - 0x7572c000 	C:\Windows\syswow64\msvcrt.dll
0x76cf0000 - 0x76d09000 	C:\Windows\SysWOW64\sechost.dll
0x76410000 - 0x76500000 	C:\Windows\syswow64\RPCRT4.dll
0x75260000 - 0x752c0000 	C:\Windows\syswow64\SspiCli.dll
0x75250000 - 0x7525c000 	C:\Windows\syswow64\CRYPTBASE.dll
0x6d8e0000 - 0x6dc89000 	C:\Program Files (x86)\Java\jdk1.5.0_20\jre\bin\server\jvm.dll
0x76590000 - 0x76690000 	C:\Windows\syswow64\USER32.dll
0x76930000 - 0x769c0000 	C:\Windows\syswow64\GDI32.dll
0x776c0000 - 0x776ca000 	C:\Windows\syswow64\LPK.dll
0x77250000 - 0x772ed000 	C:\Windows\syswow64\USP10.dll
0x74bc0000 - 0x74bf2000 	C:\Windows\system32\WINMM.dll
0x77110000 - 0x77170000 	C:\Windows\system32\IMM32.DLL
0x77170000 - 0x7723c000 	C:\Windows\syswow64\MSCTF.dll
0x74c80000 - 0x74ccb000 	C:\Windows\system32\apphelp.dll
0x6d300000 - 0x6d308000 	C:\Program Files (x86)\Java\jdk1.5.0_20\jre\bin\hpi.dll
0x754c0000 - 0x754c5000 	C:\Windows\syswow64\PSAPI.DLL
0x6d400000 - 0x6d435000 	C:\Program Files (x86)\Java\jdk1.5.0_20\jre\bin\jdwp.dll
0x6d710000 - 0x6d71c000 	C:\Program Files (x86)\Java\jdk1.5.0_20\jre\bin\verify.dll
0x6d380000 - 0x6d39d000 	C:\Program Files (x86)\Java\jdk1.5.0_20\jre\bin\java.dll
0x6d730000 - 0x6d73f000 	C:\Program Files (x86)\Java\jdk1.5.0_20\jre\bin\zip.dll
0x6d290000 - 0x6d297000 	C:\Program Files (x86)\Java\jdk1.5.0_20\jre\bin\dt_socket.dll
0x76d90000 - 0x76dc5000 	C:\Windows\syswow64\WS2_32.dll
0x755f0000 - 0x755f6000 	C:\Windows\syswow64\NSI.dll
0x74f10000 - 0x74f4c000 	C:\Windows\system32\mswsock.dll
0x74f90000 - 0x74f95000 	C:\Windows\System32\wshtcpip.dll
0x6d540000 - 0x6d553000 	C:\Program Files (x86)\Java\jdk1.5.0_20\jre\bin\net.dll
0x72880000 - 0x72886000 	C:\Windows\System32\wship6.dll
0x74f50000 - 0x74f60000 	C:\Windows\system32\NLAapi.dll
0x74ec0000 - 0x74f04000 	C:\Windows\system32\DNSAPI.dll
0x74eb0000 - 0x74eb8000 	C:\Windows\System32\winrnr.dll
0x74ea0000 - 0x74eb0000 	C:\Windows\system32\napinsp.dll
0x74e80000 - 0x74e92000 	C:\Windows\system32\pnrpnsp.dll
0x74f70000 - 0x74f8c000 	C:\Windows\system32\IPHLPAPI.DLL
0x74f60000 - 0x74f67000 	C:\Windows\system32\WINNSI.DLL
0x74e30000 - 0x74e36000 	C:\Windows\system32\rasadhlp.dll
0x74e40000 - 0x74e78000 	C:\Windows\System32\fwpuclnt.dll
0x6d530000 - 0x6d538000 	C:\Program Files (x86)\Java\jdk1.5.0_20\jre\bin\management.dll
0x71a90000 - 0x71aa6000 	C:\Windows\system32\CRYPTSP.dll
0x71a50000 - 0x71a8b000 	C:\Windows\system32\rsaenh.dll
0x74b50000 - 0x74b67000 	C:\Windows\system32\USERENV.dll
0x74b40000 - 0x74b4b000 	C:\Windows\system32\profapi.dll
0x6d560000 - 0x6d569000 	C:\Program Files (x86)\Java\jdk1.5.0_20\jre\bin\nio.dll

VM Arguments:
jvm_args: -Xdebug -Xrunjdwp:transport=dt_socket,address=8787,server=y,suspend=n -Dprogram.name=run.bat -Xms128m -Xmx512m -XX:PermSize=64M -XX:MaxPermSize=512M -XX:+UseSerialGC -Dorg.eclipse.emf.ecore.EPackage.Registry.INSTANCE=org.eclipse.emf.ecore.impl.EPackageRegistryImpl -Dsun.rmi.dgc.client.gcInterval=3600000 -Dsun.rmi.dgc.server.gcInterval=3600000 -Ddrools.compiler.dump.path=D:/rule-engine-dump/ -Djava.endorsed.dirs=D:\yoda\export\home\jboss\lib\endorsed
java_command: org.jboss.Main -c vtba -b 0.0.0.0
Launcher Type: SUN_STANDARD

Environment Variables:
JAVA_HOME=C:\Program Files (x86)\Java\jdk1.5.0_20
PATH=D:\yoda\export\home\bin;d:\Program Files\CollabNet Subversion Client;D:\Program Files\apache-ant-1.7.1\bin;C:\Program Files (x86)\Java\jdk1.5.0_20\bin;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Windows\System32\WindowsPowerShell\v1.0\;C:\Program Files (x86)\Common Files\Thunder Network\KanKan\Codecs;D:\Program Files\TortoiseSVN\bin
USERNAME=wyang
OS=Windows_NT
PROCESSOR_IDENTIFIER=Intel64 Family 15 Model 6 Stepping 5, GenuineIntel



---------------  S Y S T E M  ---------------

OS: Windows 7 Build 7600 

CPU:total 2 (cores per cpu 2, threads per core 1) family 15 model 6 stepping 5, cmov, cx8, fxsr, mmx, sse, sse2, sse3

Memory: 4k page, physical 4126324k(1248652k free), swap 4194303k(4194303k free)

vm_info: Java HotSpot(TM) Server VM (1.5.0_20-b02) for windows-x86, built on Jul 25 2009 01:36:20 by "java_re" with MS VC++ 6.0

time: Mon Aug 24 15:02:21 2009
elapsed time: 49 seconds

根据log的信息，HotSpot是挂在了C2编译器里。挂的时候EIP指向的指令所在函数是：

6DAD11E0  /$  8B4424 04         mov eax,dword ptr ss:[esp+4]
6DAD11E4  |.  56                push esi
6DAD11E5  |.  8B50 1C           mov edx,dword ptr ds:[eax+1C]
6DAD11E8  |.  8B41 58           mov eax,dword ptr ds:[ecx+58]
6DAD11EB  |.  8B0490            mov eax,dword ptr ds:[eax+edx*4]
6DAD11EE  |.  8B50 04           mov edx,dword ptr ds:[eax+4]     ; 在这里挂了
6DAD11F1  |.  833A 00           cmp dword ptr ds:[edx],0
6DAD11F4  |.  75 1E             jnz short jvm.6DAD1214
6DAD11F6  |.  8B51 14           mov edx,dword ptr ds:[ecx+14]
6DAD11F9  |>  8B40 1C           /mov eax,dword ptr ds:[eax+1C]
6DAD11FC  |.  3BC2              |cmp eax,edx
6DAD11FE  |.  73 08             |jnb short jvm.6DAD1208
6DAD1200  |.  8B71 18           |mov esi,dword ptr ds:[ecx+18]
6DAD1203  |.  8B0486            |mov eax,dword ptr ds:[esi+eax*4]
6DAD1206  |.  EB 02             |jmp short jvm.6DAD120A
6DAD1208  |>  33C0              |xor eax,eax
6DAD120A  |>  24 FE             |and al,0FE
6DAD120C  |.  8B70 04           |mov esi,dword ptr ds:[eax+4]
6DAD120F  |.  833E 00           |cmp dword ptr ds:[esi],0
6DAD1212  |.^ 74 E5             \je short jvm.6DAD11F9
6DAD1214  |>  5E                pop esi
6DAD1215  \.  C2 0400           retn 4

挂的时候代码想从EAX（==0x00000000）+4，也就是从地址0x00000004读取数据，引发了AV。这个函数到底是在干吗呢？……没看出来。从栈顶附近的数据可以看到该函数是从0x6DAD310D之前的一条指令调用过来的，也就是：

6DAD30FE  |> /8B5424 18         /mov edx,dword ptr ss:[esp+18]
6DAD3102  |> |8B6A 1C            mov ebp,dword ptr ds:[edx+1C]
6DAD3105  |. |52                |push edx
6DAD3106  |. |8BCF              |mov ecx,edi
6DAD3108  |. |E8 D3E0FFFF       |call jvm.6DAD11E0

有一点奇怪的：这个调用序列看起来像是用了VC的calling convention中的__fastcall，ECX和EDX都有被赋值然后才call的；但是被调用的函数无视了EDX的内容，然后也没有保护它……这个确实是__fastcall吧？我有点不确定。


诶……要是我在现场的话能挂个调试器进去看看就好了，爽一把 TvT

把log贴出来记着。同学说重启JBoss之后又好了，说不定只是Sun JRE 1.5.0u20的HotSpot的什么RPWT吧 =v=

P.S. 关于crash log信息的阅读方法，可以参考官方文档：Troubleshooting System Crashes