100% CPU usage in "VM Thread" for Hotspot 10/11 on x64 platform within data processing application

Mon Feb 23 16:07:07 PST 2009

We keep pdb files from all our builds but don't normally distribute  
them.  That's an address in MarkSweep::follow_stack and I believe that  
all the other address you were seeing were also in the GC.  If  
jconsole doesn't work then try -verbose:gc which will just spew out  
the information directly.  The fact that jconsole wouldn't start is  
pretty odd.  Is your machine heavily loaded?  You aren't doing  
something silly like specifying heap sizes that are greater than or  
too close to your actual amount of RAM?  64 bit apps usually require  
more heap for the same problem.

tom

On Feb 23, 2009, at 3:49 PM, David Sitsky wrote:

> Hi Tom,
>
> Apologies for the delay in my reply.  I have downloaded the Window  
> kernel symbols so that the stacks from procexp are more reliable.  I  
> don't know where I can obtain the pdb files for jvm.dll.  Are they  
> available anywhere?
>
> Here is another example stack, using 1.6.0_12, jvm.dll is  
> 11.02.0000.0001 Java Hotspot (TM) 64-Bit Server VM:
>
> ntoskrnl.exe!KiSwapContext+0x7f
> ntoskrnl.exe!KiSwapThread+0x2fa
> ntoskrnl.exe!KeWaitForSingleObject+0x2da
> ntoskrnl.exe!KiSuspendThread+0x29
> ntoskrnl.exe!KiDeliverApc+0x420
> ntoskrnl.exe!KiApcInterrupt+0x103
> jvm.dll!JVM_FindSignal+0xe3f45
> jvm.dll!JVM_FindSignal+0x14dcdd
> jvm.dll!JVM_FindSignal+0x14e17c
> jvm.dll!JVM_FindSignal+0x159b80
> jvm.dll!JVM_FindSignal+0x12a5e4
> jvm.dll!JVM_FindSignal+0x216e53
> jvm.dll!JVM_FindSignal+0x219a38
> jvm.dll!JVM_FindSignal+0x2188d4
> jvm.dll!JVM_FindSignal+0x218d2a
> jvm.dll!JVM_FindSignal+0x219332
> jvm.dll!JVM_FindSignal+0x11da99
> msvcrt.dll!endthreadex+0x47
> msvcrt.dll!endthreadex+0x100
> kernel32.dll!BaseThreadInitThunk+0xd
> ntdll.dll!RtlUserThreadStart+0x1d
>
> I expect it is somehow related to GC, as the application is  
> extremely memory intensive.  However, I have found the 32-bit VM  
> seems to cope, where as the 64-bit version seems to end up in these  
> CPU loops in the VM thread.
>
> I can run jstack, but I have waited over 30 minutes for jconsole,  
> and it has still not come up..
>
> Any ideas?  I am hoping now that I have specified the exact version  
> of jvm.dll.. we can at least see what the offsets refer to?
>
> Cheers,
> David
>
> Tom Rodriguez wrote:
>> Have you tried using jconsole or -verbose:gc to watch your app?   
>> Maybe it's running low on heap and spending too much time in GC.
>> tom
>> On Feb 18, 2009, at 4:29 PM, David Sitsky wrote:
>>> I apologise in advance if this is a "breach of protocol".  I have  
>>> submitted a bug through the usual channels, but my experience with  
>>> this approach unfortunately has usually been a dead-end.
>>>
>>> I have a very intensive data application (I/O + CPU + memory) on  
>>> the Windows platform that reliably causes a 100% CPU lockup, but  
>>> only for the x64 distribution (jdk 1.6.0_07, 1.6.0_10 and  
>>> 1.6.0_12).  When using the x32 distribution on the same machines  
>>> it works fine.  It is not machine-specific - I have seen this  
>>> across 7 different machines, and it seems to occur after a few to  
>>> several hours of processing.  The JVM is still responsive, but  
>>> extremely slow.
>>>
>>> Using process explorer, I was able to find the thread in the  
>>> process consuming all the CPU.  The stack traces from procexp have  
>>> the same thread ID as the "VM Thread" from jstack.  The stacks are  
>>> usually something like the following:
>>>
>>> ntoskrnl.exe!ExpInterlockedFlushSList+0x126f
>>> ntoskrnl.exe!RtlNumberOfClearBits+0x5cc
>>> ntoskrnl.exe!ExpInterlockedFlushSList+0x134d
>>> ntoskrnl.exe!IoAcquireCancelSpinLock+0x163
>>> jvm.dll!AsyncGetCallTrace+0x3ac7f
>>> jvm.dll!JVM_FindSignal+0xe4533
>>> jvm.dll!JVM_FindSignal+0x10fa2e
>>> jvm.dll!JVM_FindSignal+0xe3eef
>>> jvm.dll!JVM_FindSignal+0x14d61d
>>> jvm.dll!JVM_FindSignal+0x14dabc
>>> jvm.dll!JVM_FindSignal+0x1593e0
>>> jvm.dll!JVM_FindSignal+0x12a374
>>> jvm.dll!JVM_FindSignal+0x2167d3
>>> jvm.dll!JVM_FindSignal+0x2193e8
>>> jvm.dll!JVM_FindSignal+0x218274
>>> jvm.dll!JVM_FindSignal+0x2186ca
>>> jvm.dll!JVM_FindSignal+0x218cd2
>>> jvm.dll!JVM_FindSignal+0x11d7f9
>>> msvcrt.dll!free_dbg+0x147
>>> msvcrt.dll!beginthreadex+0x131
>>> kernel32.dll!BaseThreadInitThunk+0xd
>>> ntdll.dll!RtlUserThreadStart+0x21
>>>
>>> or
>>>
>>> ntoskrnl.exe!ExpInterlockedFlushSList+0x126f
>>> ntoskrnl.exe!KeWaitForMultipleObjects+0xcca
>>> ntoskrnl.exe!KeWaitForMutexObject+0x2da
>>> ntoskrnl.exe!_misaligned_access+0x35
>>> ntoskrnl.exe!MmUnlockPages+0x1160
>>> ntoskrnl.exe!IoAcquireCancelSpinLock+0x163
>>> jvm.dll!AsyncGetCallTrace+0x3ac7f
>>> jvm.dll!JVM_FindSignal+0xe3eef
>>> jvm.dll!JVM_FindSignal+0x14d61d
>>> jvm.dll!JVM_FindSignal+0x14dabc
>>> jvm.dll!JVM_FindSignal+0x1593e0
>>> jvm.dll!JVM_FindSignal+0x12a374
>>> jvm.dll!JVM_FindSignal+0x2167d3
>>> jvm.dll!JVM_FindSignal+0x2193e8
>>> jvm.dll!JVM_FindSignal+0x218274
>>> jvm.dll!JVM_FindSignal+0x2186ca
>>> jvm.dll!JVM_FindSignal+0x218cd2
>>> jvm.dll!JVM_FindSignal+0x11d7f9
>>> msvcrt.dll!free_dbg+0x147
>>> msvcrt.dll!beginthreadex+0x131
>>> kernel32.dll!BaseThreadInitThunk+0xd
>>> ntdll.dll!RtlUserThreadStart+0x21
>>>
>>> or (without AsyncGetCallTrace):
>>>
>>> ntoskrnl.exe!ExpInterlockedFlushSList+0x14a0
>>> ntoskrnl.exe!IoAcquireCancelSpinLock+0x163
>>> jvm.dll!JVM_EnqueueOperation+0xb19f4
>>> jvm.dll!JVM_FindSignal+0x1b7fcc
>>> jvm.dll!JVM_FindSignal+0x14dcca
>>> jvm.dll!JVM_FindSignal+0x14e17c
>>> jvm.dll!JVM_FindSignal+0x159b80
>>> jvm.dll!JVM_FindSignal+0x12a5e4
>>> jvm.dll!JVM_FindSignal+0x216e53
>>> jvm.dll!JVM_FindSignal+0x219a38
>>> jvm.dll!JVM_FindSignal+0x2188d4
>>> jvm.dll!JVM_FindSignal+0x218d2a
>>> jvm.dll!JVM_FindSignal+0x219332
>>> jvm.dll!JVM_FindSignal+0x11da99
>>> msvcrt.dll!free_dbg+0x147
>>> msvcrt.dll!beginthreadex+0x131
>>> kernel32.dll!BaseThreadInitThunk+0xd
>>> ntdll.dll!RtlUserThreadStart+0x21
>>>
>>> I am more than happy to run test/debug versions in order to assist  
>>> in tracking this down.  I wish I could say, here is a unit test,  
>>> but its a very complex application with complex data processing.   
>>> The only good news is it seems to be quite reproduceable on our  
>>> systems.
>>>
>>> Apologies again in advance if this was an inappropriate place to  
>>> post. But given the severity of this issue, I am hoping somebody  
>>> here will be interested in it..
>>>
>>> -- 
>>> Cheers,
>>> David
>>>
>>> Nuix Pty Ltd
>>> Suite 79, 89 Jones St, Ultimo NSW 2007, Australia    Ph: +61 2  
>>> 9280 0699
>>> Web: http://www.nuix.com                            Fax: +61 2  
>>> 9212 6902
>
>
> -- 
> Cheers,
> David
>
> Nuix Pty Ltd
> Suite 79, 89 Jones St, Ultimo NSW 2007, Australia    Ph: +61 2 9280  
> 0699
> Web: http://www.nuix.com                            Fax: +61 2 9212  
> 6902