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

Mon Feb 23 17:17:46 PST 2009

On Feb 23, 2009, at 4:54 PM, David Sitsky wrote:

> The machine is heavily loaded.  Its a quad-core machine with 8 gigs  
> of memory, however each Java process has a 1g heap size set.  I can  
> see from the task manager I still have free/unused memory on my  
> system, but of course that is not really relevant for the 4  
> individual JVMs which are running.
>
> When I say jconsole won't start - this is when I specify the  
> specific process ID.  I can still run other applications on the  
> machine, albeit slowly.
>
> If I set a 1 gig heap size for a 32-bit process, what would be a  
> very rough rule of thumb that I should set for a 64-bit process?   
> Another 200 megs or so?

It's very data dependent but 20% probably isn't a bad starting place.   
jmap -histo could give you a more detailed picture.

tom

>
>
> I'll try it again with more memory, and also set the -verbose:gc flag.
>
> Cheers,
> David
>
> Tom Rodriguez wrote:
>> 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
>
>
> -- 
> 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