Long young generation GC?

[Hi Guava]

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
>>>
>