Long young generation GC?

Y. S. Ramakrishna y.s.ramakrishna at oracle.com
Tue Oct 26 10:58:44 PDT 2010


"real" is elapsed time too, obtained from the OS via times(2).
So if it's reported so small when users see much more time elapse physically,
it must be the case that it's a bug in times(2) in a virtual setting.
Perhaps if you can boil this down to a small and reproducible test case
you can file a bug with the VM provider and with the JVM as well, the
latter perhaps a shadow of the former.

Over to the runtime team.
-- ramki

On 10/26/10 10:49, Hi Guava wrote:
> I now believe that this phenomenon is caused by the virtual machine.
> It has nothing to do with the garbage collector or JVM. I searched in
> the old logs and found this in all 3 old logs that I have. There are
> multiple virtual machines configured the same way. This problem only
> shows up in one of the virtual machines.
> By the way, the 639 seconds GC is not a perception problem. It is
> real. The users reported stuck process and they found the CPUs of the
> virtual machine was racing during that period.
> Can I understand this discrepancy this way? the user, sys and real
> times are measured in cpu cycles. They are short as they are supposed
> to be. The 439.2720750 time is the elapsed time. Since the virtual
> machine is doing something else or not functioning correctly, GC took
> 439 seconds even though there was only 0.08 seconds of cpu time.
> 
> 72681.425: [GC 72681.426: [ParNew: 38325K->4224K(38336K), 439.2720750
> secs] 3013053K->2979055K(6549376K), 439.2720750 secs] [Times:
> user=0.08 sys=0.00, real=0.08 secs]
> 
> 
> On Tue, Oct 26, 2010 at 12:34 PM, Y. S. Ramakrishna
> <y.s.ramakrishna at oracle.com> wrote:
>>
>> On 10/26/10 07:07, Hi Guava wrote:
>>> Here is additional information about the machine running the JVM. It
>>> is a virtual machine running in a private cloud. Could it be something
>>> like swapping that caused problem?
>> Not swapping, but perhaps the management of "time" perhaps in a virtualized
>> setting (by that i mean that there may be interactions between the
>> host/hypervisor and the guest OS that could cause the JVM to observe
>> time jumps of this sort)? I'd suggest gathering more data on its
>> reproducibility (or otherwise) in both a VM and non-VM setting.
>>
>> Over to the time experts in the runtime team who may have encountered
>> issues in VM settings previously. (I have heard of occasional such reports
>> in
>> virtual settings before but don't know if any of these were definitively
>> chased
>> down.) You might also want to check with the VM provider to see if they
>> might know of such issues.
>>
>> -- ramki
>>
>>
>>> On Mon, Oct 25, 2010 at 8:51 PM, Y. Srinivas Ramakrishna
>>> <y.s.ramakrishna at oracle.com> wrote:
>>>> On 10/25/2010 5:49 PM, Y. Srinivas Ramakrishna wrote:
>>>>> On 10/25/2010 5:32 PM, Hi Guava wrote:
>>>>>> The third young generation GC took 439.2720750 secs but the user and
>>>>>> real time are only 0.08 seconds. What does it mean?
>>>>> The machine may be using NTP, and the time may have been changed?
>>>> Seems a rather large jump, so may not be NTP (which i am told uses
>>>> adjtime() to slowly accelerate the time forward or decelerate it
>>>> backward),
>>>> but rather an abrupt perhaps manual change in TOD.
>>>>
>>>> Over to the experts....
>>>>
>>>>> JVM timestamps on Linux seem still to be based on TOD rather than
>>>>> on TSC. Someone in the runtime team (cc'd) may have more detail on
>>>>> why that might still be so.
>>>>>
>>>>> -- ramki
>>>>>
>>>>>
>>>>>> 72667.213: [GC 72667.213: [ParNew: 38336K->4224K(38336K), 1.2473840
>>>>>> secs]
>>>>>> 3443948K->3420569K(6549376K), 1.2474290 secs] [Times: user=0.64
>>>>>> sys=1.10,
>>>>>> real=1.25 secs]
>>>>>> 72680.531: [GC 72680.532: [ParNew: 38336K->4221K(38336K), 0.2916570
>>>>>> secs]
>>>>>> 3008948K->2979033K(6549376K), 0.2916710 secs] [Times: user=0.26
>>>>>> sys=0.03,
>>>>>> real=0.29 secs]
>>>>>> 72681.425: [GC 72681.426: [ParNew: 38325K->4224K(38336K), 439.2720750
>>>>>> secs] 3013053K->2979055K(6549376K), 439.2720750 secs] [Times: user=0.08
>>>>>> sys=0.00, real=0.08 secs]
>>>>>>
>>>>>> Environment:
>>>>>> Java HotSpot(TM) 64-Bit Server VM Version 1.6.0_20-b02
>>>>>> Linux Version 2.6.18-128.1.1.el5 on amd64
>>>>>> -Xms6400m
>>>>>> -Xmx6400m
>>>>>> -Xss256k
>>>>>> -XX:+UseConcMarkSweepGC
>>>>>> -XX:+PrintGCDetails
>>>>>> -XX:+PrintGCTimeStamps
>>>>>> -XX:+UseCompressedOops
>>>>>> _______________________________________________
>>>>>> hotspot-gc-use mailing list
>>>>>> hotspot-gc-use at openjdk.java.net
>>>>>> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
_______________________________________________
hotspot-gc-use mailing list
hotspot-gc-use at openjdk.java.net
http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use


More information about the hotspot-gc-dev mailing list