Long young generation GC?

[Paul Hohensee]

  The general rule is that you can't guaranteed any particular response time
when running under a hypervisor.  There may be recent developments, but
historically, hypervisors have been unable to provide QOS guarantees.

Paul

On 10/26/10 1:58 PM, Y. S. Ramakrishna wrote:
> "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